Hello, here's some more information regarding this bug. I had been running my client which had previously crashed almost once a day for several days in debug mode. Suddenly I noticed that rsyslog was running but no log entries were written to any log files. I started to investigate the case and I noticed that rsyslog process was running but it was in some kind of deadlock state and it was doing nothing. I think this happened also doing rsyslog reload from a cron job.
I attached the last lines of debug output when I terminated the process by pressing ctrl-c several times. Too bad that I didn't realize to check the memory usage of the process. I have also noticed that if I put $AllowedSender directive in config file allowing my local subnet to send log messages to the server the server after a while (say next day or something) somehow forgets this directive and doesn't allow any client to send log messages. It just writes log entries like "TCP message from disallowed sender ... discarded" although this sender has been allowed using the $AllowedSender directive. I tried using both host names and IP addresses. Syntax of the directive I used was simply: $AllowedSender TCP, 127.0.0.0/8, 192.168.1.0/24 Regards, Juha
2603.017994588:imuxsock.c: Message has legacy syslog format. 2603.018007204:imuxsock.c: main queue: entry added, size now 1 entries 2603.018019520:imuxsock.c: main queue: EnqueueMsg signaled condition (0) 2603.018025193:imuxsock.c: wtpAdviseMaxWorkers signals busy 2603.018030379:imuxsock.c: --------imuxsock calling select, active file descriptors (max 22): 3 22 2603.018043013:main queue:Reg/w0: main queue: entering rate limiter 2603.018074949:main queue:Reg/w0: main queue: entry deleted, state 0, size now 0 entries 2603.018086294:main queue:Reg/w0: Called action, logging to builtin-fwd2603.018094788:main queue:Reg/w0: action 73 queue: entry added, size now 77 entries 2603.018099915:main queue:Reg/w0: action 73 queue: EnqueueMsg signaled condition (0) wtpAdviseMaxWorkers signals busy 2603.018109714:main queue:Reg/w0: Called action, logging to builtin-file (/var/log/auth.log) 2603.018142741:main queue:Reg/w0: Called action, logging to builtin-file (/dev/xconsole) 2603.018172315:main queue:Reg/w0: main queue: entering rate limiter 2603.018178607:main queue:Reg/w0: main queue:Reg/w0: worker IDLE, waiting for work. 2627.182129173:action 73 queue[DA]:Reg/w0: actionTryResume: iRet: 0, next retry (if applicable): 1230192597 [now 1230192627] 2627.182158676:action 73 queue[DA]:Reg/w0: log-server:514/tcp 2627.182451825:action 73 queue[DA]:Reg/w0: create tcp connection failed, reason Connection refusedno working socket could be obtainederror forwarding via tcp, suspending 2627.182472073:action 73 queue[DA]:Reg/w0: Action requested to be suspended, done that. DoDie called. 2640.673542516:main thread: exiting on signal 2 2640.673567617:main thread: Terminating input threads... 2640.673628218:imuxsock.c: destructor for debug call stack 0x19a34b0 called 2640.673760137:imklog.c: destructor for debug call stack 0x1959ba0 called 2640.673818375:main thread: main queue: entry added, size now 1 entries 2640.673832332:main thread: main queue: EnqueueMsg signaled condition (0) 2640.673838373:main thread: wtpAdviseMaxWorkers signals busy 2640.673842050:main queue:Reg/w0: main queue: entering rate limiter 2640.673852291:main thread: 2640.673853895:main queue:Reg/w0: main queue: logmsg: flags 5, from 'log-client', msg [origin software="rsyslogd" swVersion="3.18.6" x-pid="7435" x-info="http://www.rsyslog.com";] exiting on signal 2. 2640.673863899:main thread: entry deleted, state 0, size now 0 entries Message has legacy syslog format. 2640.673878612:main queue:Reg/w0: 2640.673879763:Called action, logging to builtin-fwdmain thread: main queue: entry added, size now 1 entries 2640.673897945:main thread: main queue: EnqueueMsg signaled condition (0) 2640.673905926:main thread: wtpAdviseMaxWorkers signals busy 2640.673913111:main thread: Terminating main queue... 2640.673907302:main queue:Reg/w0: action 73 queue: entry added, size now 78 entries 2640.673934371:main queue:Reg/w0: action 73 queue: EnqueueMsg signaled condition (0) 2640.673942080:main queue:Reg/w0: wtpAdviseMaxWorkers signals busy 2640.673943090:main thread: main queue: initiating worker thread shutdown sequence 2640.673955517:main thread: main queue: trying shutdown of regular workers 2640.673958583:main queue:Reg/w0: Called action, logging to builtin-file 2640.673975151:main thread: main queue:Reg: waiting 0ms on worker thread termination, 1 still running 2640.673983458:main thread: main queue:Reg: timeout waiting on worker thread termination 2640.673990663:main thread: main queue: regular shutdown timed out on primary queue (this is OK) 2640.673992158:main queue:Reg/w0: (/var/log/syslog) 2640.673998270:main thread: main queue: trying immediate shutdown of regular workers 2640.674038288:main thread: main queue:Reg: waiting 1000ms on worker thread termination, 1 still running 2640.674052064:main queue:Reg/w0: Called action, logging to builtin-file (/var/log/kern.log) 2640.674075215:main queue:Reg/w0: Called action, logging to builtin-file (/var/log/messages) 2640.674092562:main queue:Reg/w0: Called action, logging to builtin-file (/dev/xconsole) 2640.674108573:main queue:Reg/w0: main queue: entering rate limiter 2640.674114172:main queue:Reg/w0: main queue:Reg/w0: receiving command 1 2640.674118592:main queue:Reg/w0: main queue:Reg/w0: worker terminating 2640.674126056:main queue:Reg/w0: main queue:Reg: Worker thread 199a3a0, terminated, num workers now 0 2640.674136297:main thread: waiting for worker main queue:Reg/w0 termination, current state 1 2640.674148128:main queue:Reg/w0: destructor for debug call stack 0x1986720 called 2640.674162159:main thread: main queue:Reg/w0: receiving command 0 2640.674168978:main thread: worker main queue:Reg/w0 has stopped 2640.674174301:main thread: main queue: checking to see if we need to cancel any worker threads of the primary queue 2640.674179092:main thread: main queue:Reg: try canceling worker thread 0 2640.674183392:main thread: main queue: worker threads terminated, remaining queue size 1. 2640.674190177:main thread: main queue: error -7 persisting queue - data lost! 2640.674197689:main thread: Terminating outputs... 2640.674201874:main thread: Freeing log structures. 2640.674210005:main thread: action 73 queue: initiating worker thread shutdown sequence 2640.674214630:main thread: action 73 queue: trying shutdown of regular workers 2640.674219017:main thread: action 73 queue:Reg: waiting 0ms on worker thread termination, 1 still running 2640.674224003:main thread: action 73 queue:Reg: timeout waiting on worker thread termination 2640.674228274:main thread: action 73 queue: regular shutdown timed out on primary queue (this is OK) 2640.674232498:main thread: wtpAdviseMaxWorkers signals busy 2640.674236903:main thread: action 73 queue: bSaveOnShutdown configured, eternal timeout set 2640.674241461:main thread: action 73 queue:DA: waiting 86400000ms on worker thread termination, 1 still running DoDie called. DoDie called. DoDie called. DoDie called. DoDie called 5 times - unconditional exit 2643.473540099:main thread: Signal 6 (SIGABRT) occured, execution must be terminated. 2643.473547576:main thread: 2643.473551679:main thread: Recorded Call Order for Thread 'main thread (7fcd000b16e0)': 2643.473555983:main thread: maximum number of nested calls for this thread: 0. 2643.473559991:main thread: NOTE: not all calls may have been recorded, code does not currently guarantee that! 2643.473564928:main thread: 2643.473570394:main thread: Recorded Call Order for Thread 'action 73 queue:DA/w0 (41049950)': 2643.473574503:main thread: maximum number of nested calls for this thread: 0. 2643.473578486:main thread: NOTE: not all calls may have been recorded, code does not currently guarantee that! 2643.473583133:main thread: 2643.473586761:main thread: Recorded Call Order for Thread 'action 73 queue[DA]:Reg/w0 (41af8950)': 2643.473590654:main thread: maximum number of nested calls for this thread: 0. 2643.473594421:main thread: NOTE: not all calls may have been recorded, code does not currently guarantee that! 2643.473599016:main thread: 2643.473602533:main thread: Recorded Call Order for Thread 'action 73 queue:Reg/w0 (43afc950)': 2643.473606468:main thread: maximum number of nested calls for this thread: 0. 2643.473610233:main thread: NOTE: not all calls may have been recorded, code does not currently guarantee that! 2643.473614120:main thread: Mutex log for all known mutex operations: 2643.473618538:main thread: If the call trace is empty, you may want to ./configure --enable-rtinst 2643.473622387:main thread: To submit bug reports, visit http://www.rsyslog.com/bugs 2643.473626466:main thread: To submit bug reports, visit http://www.rsyslog.com/bugs
