The UBID Suite provides many debugging facilities to help in the diagnosis of issues through low level inspection. This article will cover the most popular and useful of these.
Documentation for debug logging
Our documentation covers many of the topics discussed in this article, and should be consulted first for in depth knowledege of general trouble shooting and debugging options. Here are some of the documentation sections available:
Creating File-Based Debug Log Publishers
Troubleshooting the Server
Working with the Collect Support Data Tool
Data Store Troubleshooting Information
LDAP SDK Debug Log
Troubleshooting ACI Evaluation
Configuring Debug Logging
Collect Support Data
The collect-support-data tool captures of wealth of information about the current state of the server by collecting a snapshot of the server's monitor data, log, OS level information, and much more. Our documentation section "Working with the Collect Support Data Tool" goes into detail about all of the things that are captured. This should be your first reaction whenever a problem occurs on the system since the collect support data (CSD) tool will capture what's happening in the moment and can be analyzed later to discover root cause.
Class-based Debug Logging
Some issues require low level debugging to get a better understanding of how the systems are working at the code level. In these instances we can leverage a File-Based Debug Log Publisher in conjunction with Debug Targets to capture debug logging associated with specific classes.
For example, to debug SSL traffic you would need to first create a Debug Target like this:
Debug targets are based on the code used to implement the various systems, and require internal knowledge to determine which targets to use for what types of issues. Often these targets will be given by support or published in a support article.
Next you will want to enable the Filed-Based Debug Logger that we ship with, or you can create a new one if desired:
Once the logger is enabled, the debug traces will go into "logs/debug" by default, and you can view the logging there. The default-debug-level seen above is set to "disabled" in order to prevent any debug logging from other classes beyond the currently defined Debug Targets.
WARNING: There can be a performance cost associated with any verbose logging system. We reccommend disabling any file-based debug loggers when you are not actively diagnosising an issue.
You can disable the debug logger when you are done like this:
The LDAP SDK is used internally for communication between the Proxy and Directory servers, but it is also used by many LDAP tools, plugins and extensions that you may be using in your environment. When trouble shooting an issue related to the LDAP SDK you can enable the LDAP SDK Debug Logger:
This will enable logging to the "logs/server-sdk-extension-debug" file. This will enable the capturing for debug traces from Server SDK extension code, however you will need to add debug trace statement to the code your self. For more information about how to debug extensions using the Server SDK please look in the distribution archive at "docs/index.html"; Click on "Getting Started with the UnboundID Server SDK"; Then select the "Logging, Debugging, and Alerting" link to learn more.
Expensive Operation Logging
Expensive or "slow" operations can cause overall system performance issues. It's important to track these types of operations to better understand what types of requests are causing performance issues, or identify problematic areas in configuration, plugins or third-party code. There are two outlets for logging expensive operations provided out-of-the-box. First is the expensive operation logger which can be enabled like this:
This uses the "Expensive Operations" result criteria, which by default matches all operations with a processing time greater than or equal to one second. The contents of "logs/expensive-ops" will be similiar to those of a normal access log, but will only contain lines for the matching expensive operations.
To get a much deeper understanding of what was happening on the system when an expensive operation occurs you should enable the Work Queue settings to create expensive operation dumps:
The example above will result in the server checking every second to see if any operation in the work queue is still active. This means that it will catch any operation that has been active for more than one second. When this situation is detected a thread dump of the server will be taken and included with a list of all the matching active operations and put into the logs directory with a name like "expensive-operation-dump-*.log" where the astricks is a unique timestamp. These dumps can provide very valuable insight into the system state, but may require the assistance of services of support staff to fully understand.
Sub-operation performance timing
There is a global configuration setting available for tracking the phase time associated with every operation processed by the server. This can be used to profile operations to see where they are spending the most time, and can be enabled like this:
The amount of data collected for each operation is quite large, so we strongly reccommend that you only log the phase time information for specific operations using a request or connection criteria. For example, here is a request criteria targeting only searches for a specific admin entry:
dsconfig create-request-criteria --criteria-name "Searches for the Admin entry" --type simple --set operation-type:search --set included-target-entry-dn:uid=admin,dc=example,dc=com
Next you can create a Sub-operation timing access logger to capture timing data for requests matching that criteria:
Now any search requests for the entry in the request criteria will log phase time data into the subop.log we created above. The data included will be quite verbose and detail all the of phases the operation went through as well as the time spent in each phases. The longest time spent in a phase will be called out as well as the aggregate time for the longest phase type. You may wish to get help analyzing the results of this tracing from the services or support teams.
WARNING: Enabling the sub-operation-timer is known to cause a measurable performance degredation, and as such should only be enabled for small periods of time while collecting phase time logging data.
To prevent any further perfromance impact when you are doing collecting the trace data, you can just disable the sub operation timer in the global config:
One of the more challenging systems to diagnose when an issue arises is the access control instruction (ACI) processing. However, we do provide a special logger that can be used in order to trace the evaluations associated with operations and the ACIs that affect them. The documentation for this debugging facility is covered in depth in our admin guide in the "Troubleshooting ACI Evaluation" section. Please read that for much more information about how to enable and use this logging facility.