Sun ONE Directory Server Resource Kit 5.2 Tools Reference |
Chapter 24
The Log Analyzer ToolThe logconv.pl tool analyzes the access logs of Sun ONE Directory Server. It extracts usage statistics and counts the occurrences of significant events. This chapter provides instructions on how to use logconv.pl. It contains the following sections:
Overviewlogconv.pl is a Perl script that analyzes the access logs of Sun ONE Directory Server in order to extract usage statistics and count the occurrences of significant events. It is compatible with log formats from Directory Server 3.x, 4.x, and 5.x.
Note
Some information extracted by the logconv.pl script is available only in Sun ONE Directory Server 5.x logs thus, the corresponding values will be zero when analyzing logs from other versions. In addition, some information will only be present in the logs if verbose logging is enabled in your directory server. For more information, see “nsslapd-accesslog-level” in Chapter 4 of the Sun ONE Directory Server Reference Manual.
The DSRK includes the tool in the DSRK_base/perl directory.
Note
This script requires Perl version 5.005_03 or later. See Third-Party Sources of Information for links to Perl resources.
Statistics for Display
The logconv.pl tool displays three types of statistics that administrators will find useful for monitoring and optimizing directory usage. They are:
- Simple counts of events such as the total number of binds and the total number of searches.
- Lists of the most frequently occurring parameters in LDAP requests. For example, lists of the top ten bind DNs, base DNs, filter strings, and attributes returned. Because they are computation intensive, these lists are optional; specify only the command-line options for those you need.
- A count of occurrences of any given error code, along with a listing of the corresponding error messages in the log file.
Tool Performance
The following issues will affect the output and performance of this tool:
- Some data extracted from logs depends on connection and operation numbers that are reset and no longer unique after a server restarts. Therefore, to obtain the most accurate counts, the logs to be analyzed should not span the restart of the directory server.
- Due to changes in access logs formats in Directory Server 5.0 that also affect operation numbers, the tool will be more accurate on 5.x logs when processing large amounts of access logs.
- For performance reasons, it is not recommended to run more than one gigabyte of access logs through the script at any one time.
Customizing the Script
If you customize the ldiffer.pl script for added functionality, we encourage you to share your work with other LDAP users. Please post a message to the iplanet.server.idsrk public newsgroup with your ideas or your code.
Command Usagelogconv.pl analyzes access logs by extracting usage statistics and counting the occurrences of significant events. The tool will extract the following information from access logs:
- Number of restarts
- Total number of connections
- Total operations requested
- Total results returned
- Results to requests ratio
- Number of searches, modifications, adds, deletes, and modified RDNs
- Virtual list view (VLV) operations
- VLV unindexed searches
- Server-side sorting operations
- SSL connections
- Performance lowering operations such as entire database searches or unindexed searches (details optional)
- File descriptors taken and returned
- Highest file descriptor taken
- Disruptions such as broken pipes, connections reset by peer or unavailable resources (and detail)
- Bind information such as total binds, types of binds, expired password logins, and failed binds
- Most frequent occurrence lists (optional) for error and return codes, failed logins, connection codes, client IP addresses and connection codes, bind DNs, base DNs for searching, search filters, etimes (elapsed operation time) and longest etimes, nentries (number of entries in result) and largest nentries, extended operations (DS 5.x only), most requested attributes (DS 5.x only), and abandoned operation details (DS 4.15)
- Recommendations (optional)
Syntax
The syntax of logconv.pl on the command-line takes the following form:
logconv.pl [options] [-efcibaltnxgju | -E errorCode ] accessLog ...
Where:
- options and [-efcibaltnxgju] are the command-line options described in Options.
- errorCode will display a report only on occurrences of the given error number.
- accessLog is the name of a file that contains the access log of your Directory Server. You may use wildcards in the filename or specify multiple filenames. However, the statistics are computed over the set of all logs, so all logs should pertain to the same directory server. The tool will ignore any file with the name access.rotationinfo.
Options
The logconv.pl command-line options are described in Table 24-1. Regardless of the order of options on the command-line, the lists will appear in the output in the order they are listed in this table. Use the -V option to display all optional output. Also, use the -s number option to control the length of these lists. The logconv.pl -h command will display the usage help text that briefly describes all options.
Command-Line ExamplesFollowing are two examples showing how the logconv.pl tool can be used.
Error Code Listing
The following command shows how to track error code listings. It defines error code 49 as the one to track.
$ perl logconv.pl -N -E 49 logs/access
Code Example 24-1 shows the output of the specific error code (-E 49), corresponding to a failed login with a bad password. The listing contains machine names (-N) instead of IP addresses to make it more readable. The number in the first column is the number of repeated occurrences of the same error message.
Verbose Output
The following command shows how to record a verbose output. The logconv.pl tool will read all access logs in the logs directory (ignoring access.rotationinfo files). After processing the log files, it displays all access statistics and event counters and shows the lists of most frequent connection and operation values, with the top 10 in each category (-s 10). It ends with a set of general recommendations triggered by certain values or events.
Note
There are many possible recommendations depending on the statistics and occurrences of certain events. The recommendations are based on general administration guidelines and should be adapted to fit the actual usage of your directory server.
$ perl logconv.pl -V -s 10 \
/usr/iplanet/servers/slapd-serverID/logs/access*
Code Example 24-2 Sample Verbose Output for logconv.pl
verbose output enabled
Log Analyzer 4.11
Initializing Variables...
Processing 3 Access Log(s)...
access (Total Lines: 5870)
1000 Lines Processed
2000 Lines Processed
3000 Lines Processed
4000 Lines Processed
5000 Lines Processed
* 5870 Lines Processed Total Lines Processed: 5870
access.20010713-130613 (Total Lines: 7912)
1000 Lines Processed
2000 Lines Processed
3000 Lines Processed
4000 Lines Processed
5000 Lines Processed
6000 Lines Processed
7000 Lines Processed
* 7912 Lines Processed Total Lines Processed: 13782
access.20010714-150617 (Total Lines: 6338)
1000 Lines Processed
2000 Lines Processed
3000 Lines Processed
4000 Lines Processed
5000 Lines Processed
6000 Lines Processed
* 6338 Lines Processed Total Lines Processed: 20120
* Total Lines Analyzed: 20120
----------- Access Log Output ------------
Start of Log: 18/Jul/2001:13:08:18
End of Log: 18/Jul/2001:17:05:07
Restarts: 1
Total Connections: 4002
Total Operations: 14818
Total Results: 14908
Overall Performance: 100.6%
Searches: 4354
Modifications: 27
Adds: 26
Deletes: 30
Mod RDNs: 0
5.x Stats
Persistent Searches: 1
Internal Operations: 0
Entry Operations: 0
Extended Operations: 6935
Abandoned Requests: 29
Smart Referrals Received: 0
VLV Operations: 49
VLV Unindexed Searches: 49
SORT Operations: 44
SSL Connections: 0
Entire Search Base Queries: 3912
Unindexed Searches: 1
Unindexed Search #1
- Date/Time: 18/Jul/2001:13:33:19
- Connection Number: 2926
- Operation Number: 1
- Etime: 0
- Nentries: 4001
- IP Address: 192.18.122.229
- Bind DN: cn=directory manager
- Search Filter: (objectclass=*)
FDs Taken: 3448
FDs Returned: 3446
Highest FD Taken: 89
Broken Pipes: 0
Connections Reset By Peer: 0
Resource Unavailable: 1
- 1 (T1) Idle Timeout Exceeded
Binds: 3446
Unbinds: 3438
LDAP v2 Binds: 1
LDAP v3 Binds: 3445
Expired Password Logins: 0
SSL Client Binds: 0
Failed SSL Client Binds: 0
SASL Binds: 1
1 DIGEST-MD5
Directory Manager Binds: 16
Anonymous Binds: 1
Other Binds: 3429
----- Errors -----
err=0 14737 Successful Operations
err=32 75 No Such Object
err=12 62 Unavailable Critical Extension
err=10 3 Referral Received
err=49 1 Invalid Credentials (Bad Password)
err=65 1 Objectclass Violation
----- Top 10 Failed Logins ------
1 uid=rmanager,cn=config
----- Total Connection Codes -----
U1 3437 Cleanly Closed Connections
B1 8 Bad Ber Tag Encountered
T1 1 Idle Timeout Exceeded
----- Top 10 Clients -----
Number of Clients: 2
3440 123.456.789.001
3429 - U1 Cleanly Closed Connections
8 - B1 Bad Ber Tag Encountered
1 - T1 Idle Timeout Exceeded
8 127.0.0.1
8 - U1 Cleanly Closed Connections
----- Top 10 Bind DN’s -----
Number of Unique Bind DN’s: 8
3422 uid=rmanager,cn=config
14 cn=dm
5 uid=aa,cn=config
1 Anonymous Binds
1 uid=rmanager
1 cn=dma,cn=config
1 dc=dm
1 cn=dma
----- Top 10 Search Bases -----
Number of Unique Search Bases: 73
3519 root dse
256 ou=people,dc=example,dc=com
82 cn=ldbm database, cn=plugins, cn=config
57 cn=monitor
51 dc=example,dc=com
48 cn=config
30 cn=mapping tree,cn=config
28 cn=Babs Jensen,ou=peopled,c=example,dc=com
22 cn=plugins,cn=config
20 cn=features,cn=config
----- Top 10 Search Filters -----
Number of Unique Search Filters: 31
3502 (objectclass=*)
408 (|(objectclass=*)(objectclass=ldapsubentry))
119 (uid=*)
88 (objectclass=nsbackendinstance)
6 (nsslapd-backend=userroot)
6 (nsslapd-plugintype=database)
4 (uid=bjensen)
4 (objectclass=subschema)
4 (objectclass=nsindex)
3 (cn=config)
----- Top 10 Most Frequent etimes -----
14634 etime=0
229 etime=1
9 etime=2
3 etime=7
1 etime=8
1 etime=3
1 etime=4
1 etime=5
----- Top 10 Longest etimes -----
etime=8 1
etime=7 3
etime=5 1
etime=4 1
etime=3 1
etime=2 9
etime=1 229
etime=0 14634
----- Top 10 Largest nentries -----
nentries=25 5
nentries=11 2
nentries=10 2
nentries=9 2
nentries=8 1
nentries=5 1
nentries=4 16
nentries=3 62
nentries=2 37
nentries=1 3986
nentries=0 239
----- Top 10 Most returned nentries -----
3986 nentries=1
239 nentries=0
62 nentries=3
37 nentries=2
16 nentries=4
5 nentries=25
2 nentries=10
2 nentries=11
2 nentries=9
1 nentries=5
----- 5.x Extended Operations -----
3454 2.16.840.1.113730.3.5.3 Start Replication Request
(incremental update)
3438 2.16.840.1.113730.3.5.5 End Replication Request
(incremental update)
43 2.16.840.1.113730.3.5.6 Replication Entry Request
----- Top 10 Most Requested Attributes -----
3420 supportedControl
3420 supportedExtension
360 All Attributes
341 numSubordinates
328 objectClass
315 nsAccountLock
144 nsBackendSuffix
104 nsslapd-suffix
36 dn
32 cn
----- Abandon Request Stats -----
- SRCH conn=2 op=10 msgid=1092 client=127.0.0.1
- BIND conn=2 op=0 msgid=1119 client=127.0.0.1
----- Recommendations -----
1. You have unindexed searches, this can be caused from a search on a unindexed attribute, or your returned results exceeded the allidsthreshold. Unindexed searches are not acceptable, please make any configuration changes necessary to resolve these searches!
2. You have some connections that are are being closed by the idletimeout setting. You may want to increase the idletimeout if it is set low.
3. You have a high number of searches that query the entire search base. Although this is not necessarily bad, it could be resource intensive if the search base contains many entries.