Bug 1103287
| Summary: | logconv.pl memory continually grows | |||
|---|---|---|---|---|
| Product: | Red Hat Enterprise Linux 6 | Reporter: | mreynolds | |
| Component: | 389-ds-base | Assignee: | mreynolds | |
| Status: | CLOSED ERRATA | QA Contact: | Sankar Ramalingam <sramling> | |
| Severity: | unspecified | Docs Contact: | ||
| Priority: | unspecified | |||
| Version: | 6.6 | CC: | jgalipea, nhosoi, nkinder, rmeggins, srkrishn | |
| Target Milestone: | rc | |||
| Target Release: | --- | |||
| Hardware: | Unspecified | |||
| OS: | Unspecified | |||
| Whiteboard: | ||||
| Fixed In Version: | 389-ds-base-1.2.11.15-34.el6 389-ds-base-1.2.11.15-40.el6 | Doc Type: | Bug Fix | |
| Doc Text: |
Cause: Processing a large amount of access logs without using any "verbose" options.
Consequence: Memory continues to grow until the system is exhausted of available memory, or logs are completely processed.
Fix: An old/unused feature was partially implemented,and it only consumed memory without a purpose. This partial feature was removed.
Result: Memory remains stable regardless of the amount of logging that is being processed
|
Story Points: | --- | |
| Clone Of: | ||||
| : | 1108874 (view as bug list) | Environment: | ||
| Last Closed: | 2014-10-14 07:55:09 UTC | Type: | --- | |
| Regression: | --- | Mount Type: | --- | |
| Documentation: | --- | CRM: | ||
| Verified Versions: | Category: | --- | ||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | ||
| Cloudforms Team: | --- | Target Upstream Version: | ||
| Embargoed: | ||||
| Bug Depends On: | ||||
| Bug Blocks: | 1108874 | |||
|
Description
mreynolds
2014-05-30 15:27:34 UTC
Fixed upstream Verification steps [1] Use a access log with at least 1 million lines of logging, and place in /tmp [2] ./logconv.pl /tmp/access [3] Wait a few seconds, and start monitoring the process size It should remain stable and not grow linearly. bug has been verified as seen below.
build tested 389-ds-base-1.2.11.15-33
logconv.pl /var/tmp/dirsr/access
1350000 Lines Processed
1375000 Lines Processed
1400000 Lines Processed
1425000 Lines Processed
13988 root 20 0 132m 11m 2228 R 99.7 0.2 0:06.50 perl
13991 root 20 0 15036 1240 928 R 0.3 0.0 0:00.03 top
13984 root 20 0 277m 156m 2228 R 99.7 2.0 2:55.93 perl
61 root 39 19 0 0 0 S 1.0 0.0 0:02.18 khugepaged
13984 root 20 0 311m 189m 2228 R 100.0 2.4 3:26.02 perl
13987 root 20 0 15036 1248 928 R 1.0 0.0 0:01.26 top
build tested 389-ds-base-1.2.11.15-38
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
14227 root 20 0 143m 16m 2788 R 100.0 0.2 0:43.13 perl
14229 root 20 0 15036 1244 928 R 1.0 0.0 0:00.33 top
825000 Lines Processed 74138502 of 282013304 bytes (26.289%)
850000 Lines Processed 76387957 of 282013304 bytes (27.087%)
875000 Lines Processed 78637972 of 282013304 bytes (27.884%)
14227 root 20 0 143m 16m 2788 R 99.5 0.2 1:46.45 perl
1250000 Lines Processed 112335692 of 282013304 bytes (39.833%)
1275000 Lines Processed 114585829 of 282013304 bytes (40.631%)
1300000 Lines Processed 116830507 of 282013304 bytes (41.427%)
As mentioned above, the memory utilization does not grow linearly with the latest build of 389-ds-base-1.2.11.15-38
hence, marking the bug as verified.
Marking the bug as Verified as per previous comment The patch introduced a problem when using all of the following flags:
using logconv.pl -efcibaltnxrgjuyp accesslog
I got the following errors:
Use of uninitialized value $1 in string ne at /usr/bin/logconv.pl line 2135, <LOG> line 113254.
Use of uninitialized value $1 in array element at /usr/bin/logconv.pl line 2134, <LOG> line 113256.
Use of uninitialized value $1 in string ne at /usr/bin/logconv.pl line 2135, <LOG> line 113256.
Use of uninitialized value $1 in hash element at /usr/bin/logconv.pl line 2146, <LOG> line 113256.
Use of uninitialized value $1 in array element at /usr/bin/logconv.pl line 2134, <LOG> line 113258.
tested on version:1.2.11.15 38.el6
hi,
i tested verified logconv.pl script with a customer sourced access log file for testing its performance.
got the following output
Processing 1 Access Log(s)...
[00] /RHEL7/data/DS/6.0/logfile/en/access.20120131-000045 size (bytes): 58138502
25000 Lines Processed 2279028 of 58138502 bytes (3.920%)
50000 Lines Processed 4655574 of 58138502 bytes (8.008%)
75000 Lines Processed 6953209 of 58138502 bytes (11.960%)
100000 Lines Processed 9317693 of 58138502 bytes (16.027%)
125000 Lines Processed 11813913 of 58138502 bytes (20.320%)
150000 Lines Processed 14523110 of 58138502 bytes (24.980%)
175000 Lines Processed 17138508 of 58138502 bytes (29.479%)
200000 Lines Processed 19735952 of 58138502 bytes (33.946%)
225000 Lines Processed 22297554 of 58138502 bytes (38.352%)
250000 Lines Processed 24853780 of 58138502 bytes (42.749%)
275000 Lines Processed 27495940 of 58138502 bytes (47.294%)
300000 Lines Processed 30053026 of 58138502 bytes (51.692%)
325000 Lines Processed 32682936 of 58138502 bytes (56.216%)
350000 Lines Processed 35219682 of 58138502 bytes (60.579%)
375000 Lines Processed 37772853 of 58138502 bytes (64.970%)
400000 Lines Processed 40402948 of 58138502 bytes (69.494%)
425000 Lines Processed 42998390 of 58138502 bytes (73.959%)
450000 Lines Processed 45621276 of 58138502 bytes (78.470%)
475000 Lines Processed 48071364 of 58138502 bytes (82.684%)
500000 Lines Processed 50481556 of 58138502 bytes (86.830%)
525000 Lines Processed 53007518 of 58138502 bytes (91.175%)
550000 Lines Processed 55440476 of 58138502 bytes (95.359%)
575000 Lines Processed 57790092 of 58138502 bytes (99.401%)
Total Log Lines Analysed: 578797
----------- Access Log Output ------------
Start of Logs: 31/Jan/2012:00:00:16
End of Logs: 01/Feb/2012:00:00:45
Processed Log Time: 0 Hours, 0 Minutes, 29 Seconds
Restarts: 0
Total Connections: 146088
- StartTLS Connections: 1
- LDAPS Connections: 80491
- LDAPI Connections: 0
Peak Concurrent Connections: 6
Total Operations: 127884
Total Results: 127884
Overall Performance: 100.0%
Searches: 18224 (628.41/sec) (37704.83/min)
Modifications: 37441 (1291.07/sec) (77464.14/min)
Adds: 1843 (63.55/sec) (3813.10/min)
Deletes: 1179 (40.66/sec) (2439.31/min)
Mod RDNs: 0 (0.00/sec) (0.00/min)
Compares: 0 (0.00/sec) (0.00/min)
Binds: 15622 (538.69/sec) (32321.38/min)
Proxied Auth Operations: 0
Persistent Searches: 0
Internal Operations: 0
Entry Operations: 0
Extended Operations: 53575
real 0m40.950s
user 0m37.044s
sys 0m3.751s
tested this on the latest build.1.2.11.15.40
[root@hp-dl360g4-01 ~]# logconv.pl -efcibaltnxrgjuyp access.20120131-000045
Access Log Analyzer 8.0
Command: logconv.pl access.20120131-000045
Processing 1 Access Log(s)...
[001] access.20120131-000045 size (bytes): 813938384
25000 Lines Processed 2279028 of 813938384 bytes (0.280%)
50000 Lines Processed 4655574 of 813938384 bytes (0.572%)
75000 Lines Processed 6953209 of 813938384 bytes (0.854%)
100000 Lines Processed 9317622 of 813938384 bytes (1.145%)
this command is not throwing any errors as mentioned in comment #5
hence marking the bug as verified
Based on previous comment from Sriram, marking it as Verified. Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. http://rhn.redhat.com/errata/RHBA-2014-1385.html |