[syslog-ng] [Bug 208] Memory leak when enabling debug logging

[bugzilla at bugzilla.balabit.com]

https://bugzilla.balabit.com/show_bug.cgi?id=208


Anton <koldaevav at gmail.com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
         Resolution|FIXED                       |
             Status|RESOLVED                    |REOPENED




--- Comment #14 from Anton <koldaevav at gmail.com>  2012-10-31 14:33:19 ---
Unfortunately I'm seeing almost the same problem even with updated version(3.3.7).
Looks like I'm not able to reproduce it this time on my test server but in production I see syslog-ng consumes all the memory again.

It stops writing any logs right after enabling debug. The process of memory consumption about 3x slower than without this bugfix.
Oct 31 11:37:27 syslog-01 syslog-ng[28181]: Verbosity changed; type='DEBUG', on='1'
Oct 31 11:37:27 syslog-01 syslog-ng[28181]: syslog-ng internal() messages are looping back, preventing loop by suppressing further messages; recurse_count='2'
Oct 31 11:39:23 syslog-01 syslog-ng[28181]: syslog-ng internal() messages are looping back, preventing loop by suppressing further messages; recurse_count='2'

Strace:
...
30135 mprotect(0x7f6025b09000, 4096, PROT_READ|PROT_WRITE <unfinished ...>
30126 mprotect(0x7f60013aa000, 4096, PROT_READ|PROT_WRITE <unfinished ...>
30131 mprotect(0x7f6010db5000, 4096, PROT_READ|PROT_WRITE <unfinished ...>
30117 <... futex resumed> )             = 0
30135 <... mprotect resumed> )          = 0
30131 <... mprotect resumed> )          = 0
30126 <... mprotect resumed> )          = 0
30135 futex(0x7f602df81148, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
30131 futex(0x7f602df81148, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
30135 <... futex resumed> )             = -1 EAGAIN (Resource temporarily unavailable)
30131 <... futex resumed> )             = 0
30135 futex(0x7f602df81148, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
30126 mprotect(0x7f60013ab000, 4096, PROT_READ|PROT_WRITE <unfinished ...>
30135 <... futex resumed> )             = 0
30131 mprotect(0x7f6010db6000, 4096, PROT_READ|PROT_WRITE <unfinished ...>
30117 mprotect(0x7f60156a3000, 4096, PROT_READ|PROT_WRITE <unfinished ...>
30135 mprotect(0x7f6025b0a000, 4096, PROT_READ|PROT_WRITE <unfinished ...>
30126 <... mprotect resumed> )          = 0
30131 <... mprotect resumed> )          = 0
30135 <... mprotect resumed> )          = 0
....
30117 futex(0x7f602df81148, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
30131 mprotect(0x7f6010e6f000, 4096, PROT_READ|PROT_WRITE <unfinished ...>
30117 <... futex resumed> )             = 0
30131 <... mprotect resumed> )          = 0
30117 mprotect(0x7f60156ba000, 4096, PROT_READ|PROT_WRITE) = 0
30131 mprotect(0x7f6010e70000, 4096, PROT_READ|PROT_WRITE) = 0
30117 mprotect(0x7f60156bb000, 4096, PROT_READ|PROT_WRITE) = 0
30131 mprotect(0x7f6010e71000, 4096, PROT_READ|PROT_WRITE) = 0
30117 mprotect(0x7f60156bc000, 4096, PROT_READ|PROT_WRITE) = 0
[skipped tons of mprotect]

Memory consumption:
% for i in {1..1000}; do date; free -m; sleep 2; done
Wed Oct 31 13:24:35 UTC 2012
             total       used       free     shared    buffers     cached
Mem:          7990       7955         34          0        181       6640
-/+ buffers/cache:       1133       6857
Swap:         2047        135       1912
Wed Oct 31 13:24:37 UTC 2012
             total       used       free     shared    buffers     cached
Mem:          7990       7942         47          0        180       6521
-/+ buffers/cache:       1240       6749
Swap:         2047        135       1912
Wed Oct 31 13:24:39 UTC 2012
             total       used       free     shared    buffers     cached
Mem:          7990       7943         46          0        179       6398
-/+ buffers/cache:       1366       6623
Swap:         2047        135       1912
Wed Oct 31 13:24:41 UTC 2012
             total       used       free     shared    buffers     cached
Mem:          7990       7948         41          0        178       6301
-/+ buffers/cache:       1467       6522
Swap:         2047        135       1912
Wed Oct 31 13:24:43 UTC 2012
             total       used       free     shared    buffers     cached
Mem:          7990       7944         45          0        178       6207
-/+ buffers/cache:       1559       6430
Swap:         2047        135       1912
Wed Oct 31 13:24:45 UTC 2012
             total       used       free     shared    buffers     cached
Mem:          7990       7946         43          0        177       6112
-/+ buffers/cache:       1656       6333
Swap:         2047        135       1912
Wed Oct 31 13:24:47 UTC 2012
             total       used       free     shared    buffers     cached
Mem:          7990       7947         42          0        176       5993
-/+ buffers/cache:       1777       6213
Swap:         2047        135       1912
Wed Oct 31 13:24:49 UTC 2012
             total       used       free     shared    buffers     cached
Mem:          7990       7955         35          0        174       5831
-/+ buffers/cache:       1948       6041
Swap:         2047        135       1912
Wed Oct 31 13:24:52 UTC 2012
             total       used       free     shared    buffers     cached
Mem:          7990       7950         39          0        173       5707
-/+ buffers/cache:       2068       5921
Swap:         2047        135       1912
Wed Oct 31 13:24:54 UTC 2012
             total       used       free     shared    buffers     cached
Mem:          7990       7948         41          0        172       5589
-/+ buffers/cache:       2186       5803
Swap:         2047        135       1912

You can see my production configuration here:
https://gist.github.com/c4688693f8b9851c6a41

I'll be happy to provide any additional info you need.


-- 
Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching all bug changes.