> Is it the most important part from debug log? > > 8870.027784718:7f0553c1d700: Terminating input threads... > 8870.027792719:7f0553c1d700: logging exit message... > 8870.027810744:7f0553c1d700: ELSE , iminternalAddMsg() wasn't callled > 8870.027821748:7f0553c1d700: main Q: EnqueueMsg advised worker start > 8870.027831546:7f0553c1d700: srSleep: enter, sec=2, usec=50 > 8872.028852499:7f0553c1d700: srSleep: end, sec=0, usec=0 (was sec=2, > usec=50) > 8872.028888842:7f0553c1d700: Terminating main queue..
Even after reviewing the full debug log, this keeps being mysterious. It somehow intends to submit the message, but it is never actually enqueued. As we have small debug logs, we can probably go the extra length and include very precise program flow information. IMPORTANT: you need to run ./configure with --enable-rtinst, else we will not get any additional information. Then set export RSYSLOG_DEBUG="debug logfuncflow" in addition to any other debug settings you use. This will generate function control flow information (*very verbose*) and looks like this: 2053.722105925:41ddd10: logging exit message... 2053.724640373:41ddd10: syslogd.c:540: logmsgInternal: enter 2053.725042004:41ddd10: msg.c:765: msgConstruct: enter 2053.725454384:41ddd10: msg.c:676: msgBaseConstruct: enter 2053.725872168:41ddd10: msg.c:676: msgBaseConstruct: exit: 0 2053.726408524:41ddd10: msg.c:765: msgConstruct: exit: 0 2053.726854546:41ddd10: msg.c:2075: MsgSetRcvFromIP: enter 2053.727382801:41ddd10: msg.c:2075: MsgSetRcvFromIP: exit: (no iRet) 2053.727774105:41ddd10: syslogd.c:724: submitMsg: enter 2053.728181630:41ddd10: queue.c:2439: qqueueEnqObj: enter 2053.728651750:41ddd10: queue.c:2246: doEnqSingleObj: enter 2053.729023495:41ddd10: queue.c:1303: qqueueChkDiscardMsg: enter 2053.729453987:41ddd10: queue.c:1303: qqueueChkDiscardMsg: exit: 0 2053.729818091:41ddd10: queue.c:925: qqueueAdd: enter 2053.730269065:41ddd10: queue.c:460: qAddFixedArray: enter 2053.730654544:41ddd10: queue.c:460: qAddFixedArray: exit: 0 2053.731186796:41ddd10: obj.c:972: GetName: enter 2053.731578581:41ddd10: obj.c:972: GetName: exit: (no iRet) 2053.731883265:41ddd10: main Q: entry added, size now log 1, phys 1 entries 2053.732387501:41ddd10: queue.c:925: qqueueAdd: exit: 0 2053.732849029:41ddd10: queue.c:2246: doEnqSingleObj: exit: 0 2053.733454216:41ddd10: queue.c:2055: qqueueChkPersist: enter 2053.733839852:41ddd10: queue.c:2055: qqueueChkPersist: exit: 0 2053.734254913:41ddd10: queue.c:251: qqueueAdviseMaxWorkers: enter 2053.734627997:41ddd10: wtp.c:455: wtpAdviseMaxWorkers: enter 2053.735218157:41ddd10: wtp.c:455: wtpAdviseMaxWorkers: exit: 0 2053.735659690:41ddd10: queue.c:251: qqueueAdviseMaxWorkers: exit: 0 2053.736182792:4ed0b70: obj.c:972: GetName: enter 2053.736558097:4ed0b70: obj.c:972: GetName: exit: (no iRet) 2053.736860179:4ed0b70: wti 0x4233628: worker awoke from idle processing (this is an excerpt from the shutdown message processing on my machine). Note that not 100% of all function calls are covered, but the vast majority is. So the debug log with these settings should provide very precise information - let's hope for the best... (at least it should provide clues where further instrumentation would be beneficial). Please give it a spin. Note that the debug log is 3..5 times larger than what you are used to. *Never* try this on a production system ;) Thanks, Rainer _______________________________________________ rsyslog mailing list http://lists.adiscon.net/mailman/listinfo/rsyslog http://www.rsyslog.com/professional-services/ What's up with rsyslog? Follow https://twitter.com/rgerhards
