Are actions in the queue executed in parallel or sequentially? If batch can't be finalized until all output modules succeeded I don't see reason not to block current batch until they all succeed.
On Thu, Apr 21, 2016 at 12:00 AM, David Lang <[email protected]> wrote: > If I am understanding Rainer's description of the current code correctly: > > During the batch processing the output strings are created, but then the > batch is finalized before any of the output modules try to deliver the > strings. So if there is a problem, they can't recover. > > If the batch does not get finalized until after all of the output modules > attempt to deliver the messages, then the error is detectable, but all the > messages of actions that succeeded before the action that fails will end up > getting retransmitted when the batch is run again at some point in the > future. (or a partial batch as I noted below) > > The retry logic here can be interesting. How long should it retry within > the batch before it gives up and marks everything in the batch 'not yet > delievered'. > > I'd say that for the first pass, no retries within the batch context. If > an output module can't deliver the full batch for any reason, abort the > entire batch and try again (either with a partial batch, or by grabbing > messages fresh from the queue if it's a type 1 failure) > > Yes, this will duplicate messages to one output if a different one has > problems that would be satisfied with a simple retry/reconnect, but I think > we should get things correct first, and then look to optimize it. > > David Lang > > On Wed, 20 Apr 2016, David Lang wrote: > > Date: Wed, 20 Apr 2016 23:44:51 -0700 (PDT) >> From: David Lang <[email protected]> >> Reply-To: rsyslog-users <[email protected]> >> To: rsyslog-users <[email protected]> >> Subject: Re: [rsyslog] retry if output module returns RS_RET_SUSPENDED >> >> The original discussion when we created the batch mode was that there >> were two possible ways for a batch commit to fail. >> >> 1. a temporary problem (can't reach the server, it doesn't respond, etc) >> >> In this case, a delay and retry is the correct thing to do. >> >> I believe this is what a suspended action is (I say this in case I am >> misunderstanding terms) >> >> The output module can usually detect this sort of problem, but if in >> doubt (or after enough retries), it may have to give up and decide that the >> problem is really the second type. A failure to establish a connection to >> the destination should never be in doubt, it's always this first type of >> problem. >> >> 2. a data driven problem (no matter what, this particular data cannot be >> delivered, even if we retried for 100 years) >> >> This is problems like data elements having embedded quotes that aren't >> escaped, a timestamp isn't valid by the definition of the database you are >> inserting data into, etc. >> >> In this case, retries do no good. But what we can do is abort the batch >> and try again with a batch half the size. >> >> If any messages did get delivered as part of the batch processing, they >> will be duplicated when the rest of the batch is processed. >> >> If the problem was not in the half of the batch that was delivered, good, >> revert to normal processing for anything else in the queue (which probably >> means that the next batch will fail as well) >> >> If the problem is in the half size batch, try again with a batch half >> that size. >> >> If the batch that you are trying to process is a single message, assume >> it is fatally flawed and count it as an error. >> >> In an ideal situation you can write such messages somewhere or otherwise >> detect the error. But you end up only loosing one message that has >> something corrupt in it, not an entire batch. >> >> David Lang >> >> >> On Wed, 20 Apr 2016, Kane Kim wrote: >> >> What would happen if it will be retried forever at this point? Would it >>> affect any other queues or only current action queue. If it will not >>> affect >>> anything else I'd really prefer it to block there until successfully >>> committed. >>> >>> On Wed, Apr 20, 2016 at 11:16 PM, Rainer Gerhards < >>> [email protected]> >>> wrote: >>> >>> 2016-04-21 3:22 GMT+02:00 David Lang <[email protected]>: >>>> >>>>> Thanks, I didn't know that you had been able to take any time to think >>>>> >>>> about >>>> >>>>> this issue yet. >>>>> >>>> >>>> Sorry for not being more explicit about it. But there was not yet >>>> anything that could be posted. I did this as a side-activity all since >>>> this opened. The plan acutally is: >>>> >>>> 1. get a testbench test to expose that problem -- this greatly eases >>>> debugging >>>> line of thought is to update omfile, which is needed anyhow, so >>>> that we can induce errors via it >>>> 2. add missing functionality to write error file >>>> this does not directly address the issue, but is useful and >>>> ensures we are on the right path >>>> 3. check the end transaction endpoint. After review of old notes and >>>> some thinking, I think that >>>> part of the "not yet implemented" comment is actually right. It's >>>> not as easy as suggested by it, >>>> but we probably can do better. >>>> >>>> >>>>> It sounds like you are tenitively agreeing with my speculation that the >>>>> >>>> end >>>> >>>>> of the block processing is happening just a little sooner than it >>>>> should, >>>>> preventing the chance to detect output errors. >>>>> >>>> >>>> No, I don't think so. I think it happens as it should, but we are not >>>> handling the full situation. Originally, it was planned to write an >>>> error file (point 2 above) when we cannot commit at end of >>>> transaction. But we probably can give it some retries at that point as >>>> well. In v8, we **need** to buffer transactional data until the end of >>>> batch. If we wouldn't do that, we would always need to commit after >>>> each and every transaction (because we need processing "completed" >>>> when we advance to the next action). The, at end of batch, the >>>> transaction commit processing happens. Right now, we have one try, and >>>> then give up (unfortunately without any error indication). So we need >>>> to go into that part of processing and enhance/fix it. >>>> >>>> I hope this clarifies. >>>> Rainer >>>> >>>> >>>>> David Lang >>>>> >>>>> >>>>> On Wed, 20 Apr 2016, Rainer Gerhards wrote: >>>>> >>>>> I should also say that it had a release goal, so it is on my active >>>>>> >>>>> to-do >>>> >>>>> list. >>>>>> >>>>>> Sent from phone, thus brief. >>>>>> Am 20.04.2016 19:40 schrieb "Rainer Gerhards" < >>>>>> [email protected] >>>>>> >>>>> : >>>>> >>>>>> >>>>>> Yup... Look aty work Log - still no time... Was meant for last release >>>>>>> but >>>>>>> then came libfastjson work. >>>>>>> >>>>>>> Sent from phone, thus brief. >>>>>>> Am 20.04.2016 19:39 schrieb "David Lang" <[email protected]>: >>>>>>> >>>>>>> Rainer, ping on this issue. >>>>>>>> >>>>>>>> David Lang >>>>>>>> >>>>>>>> On Tue, 29 Mar 2016, Kane Kim wrote: >>>>>>>> >>>>>>>> Date: Tue, 29 Mar 2016 10:46:49 -0700 >>>>>>>> >>>>>>>>> >>>>>>>>> From: Kane Kim <[email protected]> >>>>>>>>> Reply-To: rsyslog-users <[email protected]> >>>>>>>>> To: rsyslog-users <[email protected]> >>>>>>>>> Subject: Re: [rsyslog] retry if output module returns >>>>>>>>> >>>>>>>> RS_RET_SUSPENDED >>>> >>>>> >>>>>>>>> Updated config to: >>>>>>>>> module(load="omrelp") >>>>>>>>> local0.* action(type="omrelp" >>>>>>>>> target="10.0.0.1" >>>>>>>>> port="2514" >>>>>>>>> name="debug_relp" >>>>>>>>> queue.filename="relp_queue" >>>>>>>>> queue.maxdiskspace="1G" >>>>>>>>> queue.saveonshutdown="on" >>>>>>>>> queue.spoolDirectory="/var/spool/rsyslog" >>>>>>>>> queue.type="Disk" >>>>>>>>> action.resumeRetryCount="-1" >>>>>>>>> action.resumeInterval="1" >>>>>>>>> ) >>>>>>>>> >>>>>>>>> Still message is lost: >>>>>>>>> >>>>>>>>> 3489.658349703:imuxsock.c : Message from UNIX socket: #3 >>>>>>>>> 3489.658367582:imuxsock.c : main Q: qqueueAdd: entry added, >>>>>>>>> size >>>>>>>>> now >>>>>>>>> log 1, phys 1 entries >>>>>>>>> 3489.658372561:imuxsock.c : main Q: EnqueueMsg advised worker >>>>>>>>> >>>>>>>> start >>>> >>>>> 3489.658374985:imuxsock.c : --------imuxsock calling select, >>>>>>>>> >>>>>>>> active >>>> >>>>> file descriptors (max 3): 3 >>>>>>>>> 3489.658384201:main Q:Reg/w0 : wti 0x23c8ba0: worker awoke from >>>>>>>>> idle >>>>>>>>> processing >>>>>>>>> 3489.658386792:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 0 >>>>>>>>> objects >>>>>>>>> and enqueued 0 objects >>>>>>>>> 3489.658388548:main Q:Reg/w0 : doDeleteBatch: delete batch from >>>>>>>>> >>>>>>>> store, >>>> >>>>> new >>>>>>>>> sizes: log 1, phys 1 >>>>>>>>> 3489.658391356:main Q:Reg/w0 : processBATCH: batch of 1 elements >>>>>>>>> >>>>>>>> must >>>> >>>>> be >>>>>>>>> processed >>>>>>>>> 3489.658392786:main Q:Reg/w0 : processBATCH: next msg 0: <134>Mar >>>>>>>>> 29 >>>>>>>>> 17:44:49 logger: test >>>>>>>>> 3489.658395027:main Q:Reg/w0 : PRIFILT 'local0.*' >>>>>>>>> 3489.658397540:main Q:Reg/w0 : pmask: X X X X X X X >>>>>>>>> X X >>>>>>>>> X X >>>>>>>>> X X X X X FF X X X X X X X X X >>>>>>>>> 3489.658413235:main Q:Reg/w0 : PRIFILT condition result is 1 >>>>>>>>> 3489.658414686:main Q:Reg/w0 : ACTION 0 >>>>>>>>> [omrelp:action(type="omrelp" >>>>>>>>> ...)] >>>>>>>>> 3489.658417648:main Q:Reg/w0 : executing action 0 >>>>>>>>> 3489.658419520:main Q:Reg/w0 : action 'debug_relp': called, >>>>>>>>> logging >>>>>>>>> >>>>>>>> to >>>> >>>>> omrelp (susp 0/0, direct q 0) >>>>>>>>> 3489.658433462:main Q:Reg/w0 : strm 0x23b74c0: file -1(relp_queue) >>>>>>>>> flush, >>>>>>>>> buflen 410 >>>>>>>>> 3489.658435496:main Q:Reg/w0 : strmPhysWrite, stream 0x23b74c0, >>>>>>>>> len >>>>>>>>> 410 >>>>>>>>> 3489.658484243:main Q:Reg/w0 : file >>>>>>>>> '/var/spool/rsyslog/relp_queue.00000001' opened as #5 with mode 384 >>>>>>>>> 3489.658487347:main Q:Reg/w0 : strm 0x23b74c0: opened file >>>>>>>>> '/var/spool/rsyslog/relp_queue.00000001' for WRITE as 5 >>>>>>>>> 3489.658500498:main Q:Reg/w0 : strm 0x23b74c0: file 5 write wrote >>>>>>>>> >>>>>>>> 410 >>>> >>>>> bytes >>>>>>>>> 3489.658502751:main Q:Reg/w0 : debug_relp queue: write wrote 410 >>>>>>>>> octets >>>>>>>>> to >>>>>>>>> disk, queue disk size now 410 octets, EnqOnly:0 >>>>>>>>> 3489.658504568:main Q:Reg/w0 : debug_relp queue: qqueueAdd: entry >>>>>>>>> added, >>>>>>>>> size now log 1, phys 1 entries >>>>>>>>> 3489.658506705:main Q:Reg/w0 : debug_relp queue:Reg: high >>>>>>>>> activity - >>>>>>>>> starting 1 additional worker thread(s). >>>>>>>>> 3489.658528951:main Q:Reg/w0 : debug_relp queue:Reg: started with >>>>>>>>> state >>>>>>>>> 0, >>>>>>>>> num workers now 1 >>>>>>>>> 3489.658530689:main Q:Reg/w0 : debug_relp queue: EnqueueMsg >>>>>>>>> advised >>>>>>>>> worker >>>>>>>>> start >>>>>>>>> 3489.658532183:main Q:Reg/w0 : action 'debug_relp': set suspended >>>>>>>>> state >>>>>>>>> to >>>>>>>>> 0 >>>>>>>>> 3489.658533672:main Q:Reg/w0 : PRIFILT >>>>>>>>> '*.info;mail.none;authpriv.none;cron.none' >>>>>>>>> 3489.658536164:main Q:Reg/w0 : pmask: 7F 7F X 7F 7F 7F 7F 7F >>>>>>>>> 7F >>>>>>>>> X X >>>>>>>>> 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F >>>>>>>>> 3489.658552240:main Q:Reg/w0 : PRIFILT condition result is 1 >>>>>>>>> 3489.658553393:main Q:Reg/w0 : ACTION 1 >>>>>>>>> [builtin:omfile:/var/log/messages] >>>>>>>>> 3489.658556301:main Q:Reg/w0 : executing action 1 >>>>>>>>> 3489.658557878:main Q:Reg/w0 : action 'action 1': called, logging >>>>>>>>> to >>>>>>>>> builtin:omfile (susp 0/0, direct q 1) >>>>>>>>> 3489.658561265:main Q:Reg/w0 : action 'action 1': is >>>>>>>>> transactional - >>>>>>>>> executing in commit phase >>>>>>>>> 3489.658563696:main Q:Reg/w0 : Action 1 transitioned to state: itx >>>>>>>>> 3489.658564902:main Q:Reg/w0 : action 'action 1': set suspended >>>>>>>>> >>>>>>>> state >>>> >>>>> to 0 >>>>>>>>> 3489.658566053:main Q:Reg/w0 : PRIFILT 'authpriv.*' >>>>>>>>> 3489.658568233:main Q:Reg/w0 : pmask: X X X X X X X >>>>>>>>> X X >>>>>>>>> X >>>>>>>>> FF >>>>>>>>> X X X X X X X X X X X X X X X >>>>>>>>> 3489.658582888:main Q:Reg/w0 : PRIFILT condition result is 0 >>>>>>>>> 3489.658584058:main Q:Reg/w0 : PRIFILT 'mail.*' >>>>>>>>> 3489.658586243:main Q:Reg/w0 : pmask: X X FF X X X X >>>>>>>>> X X >>>>>>>>> X X >>>>>>>>> X X X X X X X X X X X X X X X >>>>>>>>> 3489.658600961:main Q:Reg/w0 : PRIFILT condition result is 0 >>>>>>>>> 3489.658602136:main Q:Reg/w0 : PRIFILT 'cron.*' >>>>>>>>> 3489.658604562:main Q:Reg/w0 : pmask: X X X X X X X >>>>>>>>> X X >>>>>>>>> FF X >>>>>>>>> X X X X X X X X X X X X X X X >>>>>>>>> 3489.658619159:main Q:Reg/w0 : PRIFILT condition result is 0 >>>>>>>>> 3489.658620352:main Q:Reg/w0 : PRIFILT '*.emerg' >>>>>>>>> 3489.658622551:main Q:Reg/w0 : pmask: 1 1 1 1 1 1 1 >>>>>>>>> 1 1 >>>>>>>>> 1 1 >>>>>>>>> 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 >>>>>>>>> 3489.658638435:main Q:Reg/w0 : PRIFILT condition result is 0 >>>>>>>>> 3489.658639529:main Q:Reg/w0 : PRIFILT 'uucp,news.crit' >>>>>>>>> 3489.658641711:main Q:Reg/w0 : pmask: X X X X X X X >>>>>>>>> 7 7 >>>>>>>>> X X >>>>>>>>> X X X X X X X X X X X X X X X >>>>>>>>> 3489.658656380:main Q:Reg/w0 : PRIFILT condition result is 0 >>>>>>>>> 3489.658657532:main Q:Reg/w0 : PRIFILT 'local7.*' >>>>>>>>> 3489.658659794:main Q:Reg/w0 : pmask: X X X X X X X >>>>>>>>> X X >>>>>>>>> X X >>>>>>>>> X X X X X X X X X X X X FF X X >>>>>>>>> 3489.658674346:main Q:Reg/w0 : PRIFILT condition result is 0 >>>>>>>>> 3489.658675686:main Q:Reg/w0 : END batch execution phase, entering >>>>>>>>> >>>>>>>> to >>>> >>>>> commit phase [processed 1 of 1 messages] >>>>>>>>> 3489.658677400:main Q:Reg/w0 : actionCommitAll: action 1, state 1, >>>>>>>>> >>>>>>>> nbr >>>> >>>>> to >>>>>>>>> commit 0 isTransactional 1 >>>>>>>>> 3489.658679044:main Q:Reg/w0 : doTransaction: have >>>>>>>>> commitTransaction >>>>>>>>> IF, >>>>>>>>> using that, pWrkrInfo 0x23c8ce0 >>>>>>>>> 3489.658680668:main Q:Reg/w0 : entering >>>>>>>>> >>>>>>>> actionCallCommitTransaction(), >>>> >>>>> state: itx, actionNbr 1, nMsgs 1 >>>>>>>>> 3489.658682704:main Q:Reg/w0 : omfile: write to stream, >>>>>>>>> pData->pStrm >>>>>>>>> 0x7f1ef4002480, lenBuf 42, strt data Mar 29 17:44:49 314959ac8cb0 >>>>>>>>> logger: >>>>>>>>> test >>>>>>>>> >>>>>>>>> 3489.658685296:main Q:Reg/w0 : strm 0x7f1ef4002480: file >>>>>>>>> 4(messages) >>>>>>>>> flush, buflen 42 >>>>>>>>> 3489.658686866:main Q:Reg/w0 : strmPhysWrite, stream >>>>>>>>> 0x7f1ef4002480, >>>>>>>>> len 42 >>>>>>>>> 3489.658696046:main Q:Reg/w0 : strm 0x7f1ef4002480: file 4 write >>>>>>>>> >>>>>>>> wrote >>>> >>>>> 42 >>>>>>>>> bytes >>>>>>>>> 3489.658697884:main Q:Reg/w0 : Action 1 transitioned to state: rdy >>>>>>>>> 3489.658699301:main Q:Reg/w0 : Action 1 transitioned to state: itx >>>>>>>>> 3489.658700575:main Q:Reg/w0 : Action 1 transitioned to state: rdy >>>>>>>>> 3489.658701773:main Q:Reg/w0 : actionCommit, in retry loop, iRet 0 >>>>>>>>> 3489.658703176:main Q:Reg/w0 : processBATCH: batch of 1 elements >>>>>>>>> has >>>>>>>>> been >>>>>>>>> processed >>>>>>>>> 3489.658704989:main Q:Reg/w0 : regular consumer finished, iret=0, >>>>>>>>> szlog >>>>>>>>> 0 >>>>>>>>> sz phys 1 >>>>>>>>> 3489.658707214:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 1 >>>>>>>>> objects >>>>>>>>> and enqueued 0 objects >>>>>>>>> 3489.658708626:main Q:Reg/w0 : doDeleteBatch: delete batch from >>>>>>>>> >>>>>>>> store, >>>> >>>>> new >>>>>>>>> sizes: log 0, phys 0 >>>>>>>>> 3489.658710186:main Q:Reg/w0 : regular consumer finished, iret=4, >>>>>>>>> szlog >>>>>>>>> 0 >>>>>>>>> sz phys 0 >>>>>>>>> 3489.658711550:main Q:Reg/w0 : main Q:Reg/w0: worker IDLE, waiting >>>>>>>>> >>>>>>>> for >>>> >>>>> work. >>>>>>>>> 3489.660013052:7f1efbb14700: thread created, tid 30310, name >>>>>>>>> 'rs:debug_relp >>>>>>>>> queue:Reg' >>>>>>>>> 3489.660298870:debug_relp queue:Reg/w0: wti 0x23c78b0: worker >>>>>>>>> >>>>>>>> starting >>>> >>>>> 3489.660645336:debug_relp queue:Reg/w0: DeleteProcessedBatch: we >>>>>>>>> deleted >>>>>>>>> 0 >>>>>>>>> objects and enqueued 0 objects >>>>>>>>> 3489.660922752:debug_relp queue:Reg/w0: doDeleteBatch: delete batch >>>>>>>>> from >>>>>>>>> store, new sizes: log 1, phys 1 >>>>>>>>> 3489.660947418:debug_relp queue:Reg/w0: file >>>>>>>>> '/var/spool/rsyslog/relp_queue.00000001' opened as #6 with mode 384 >>>>>>>>> 3489.660959920:debug_relp queue:Reg/w0: strm 0x23b7760: opened file >>>>>>>>> '/var/spool/rsyslog/relp_queue.00000001' for READ as 6 >>>>>>>>> 3489.660967370:debug_relp queue:Reg/w0: strm 0x23b7760: file 6 read >>>>>>>>> >>>>>>>> 410 >>>> >>>>> bytes >>>>>>>>> 3489.661768120:debug_relp queue:Reg/w0: action 'debug_relp': is >>>>>>>>> transactional - executing in commit phase >>>>>>>>> 3489.661782408:debug_relp queue:Reg/w0: wti 0x23c78b0: we need to >>>>>>>>> create >>>>>>>>> a >>>>>>>>> new action worker instance for action 0 >>>>>>>>> 3489.661789583:debug_relp queue:Reg/w0: relp engine created new >>>>>>>>> >>>>>>>> client >>>> >>>>> 0x7f1ef00027e0 >>>>>>>>> 3489.661794073:debug_relp queue:Reg/w0: wti 0x23c78b0: created >>>>>>>>> action >>>>>>>>> worker instance 1 for action 0 >>>>>>>>> 3489.661798129:debug_relp queue:Reg/w0: omrelp: beginTransaction >>>>>>>>> ^C3497.710058579:main thread : DoDie called. >>>>>>>>> 3497.710272055:main thread : exiting on signal 2 >>>>>>>>> 3497.710576430:main thread : Terminating input threads... >>>>>>>>> 3497.710765753:main thread : request term via SIGTTIN for input >>>>>>>>> thread >>>>>>>>> 'imuxsock' 0xfcb16700 >>>>>>>>> 3497.711033925:imuxsock.c : thrdStarter: usrThrdMain imuxsock - >>>>>>>>> 0x7f1efcb16700 returned with iRet 0, exiting now. >>>>>>>>> 3497.711447372:main thread : non-cancel input thread termination >>>>>>>>> succeeded for thread imuxsock 0xfcb16700 >>>>>>>>> 3497.713028584:imuxsock.c : destructor for debug call stack >>>>>>>>> 0x7f1eec0008c0 called >>>>>>>>> 3497.713390963:main thread : imuxsock: unlinking unix socket >>>>>>>>> >>>>>>>> file[0] >>>> >>>>> /dev/log >>>>>>>>> 3497.713734513:main thread : main Q: qqueueAdd: entry added, >>>>>>>>> size >>>>>>>>> now >>>>>>>>> log 1, phys 1 entries >>>>>>>>> 3497.713906635:main thread : main Q: EnqueueMsg advised worker >>>>>>>>> >>>>>>>> start >>>> >>>>> 3497.714257550:main Q:Reg/w0 : wti 0x23c8ba0: worker awoke from idle >>>>>>>>> processing >>>>>>>>> 3497.714544345:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 0 >>>>>>>>> objects >>>>>>>>> and enqueued 0 objects >>>>>>>>> 3497.715372923:main Q:Reg/w0 : doDeleteBatch: delete batch from >>>>>>>>> >>>>>>>> store, >>>> >>>>> new >>>>>>>>> sizes: log 1, phys 1 >>>>>>>>> 3497.715611163:main Q:Reg/w0 : processBATCH: batch of 1 elements >>>>>>>>> >>>>>>>> must >>>> >>>>> be >>>>>>>>> processed >>>>>>>>> 3497.715762447:main Q:Reg/w0 : processBATCH: next msg 0: [origin >>>>>>>>> software="rsyslogd" swVersion="8.18.0.master" x-pid="30306" >>>>>>>>> x-info=" >>>>>>>>> http://www.rsyslog.com";] exiting on signal 2. >>>>>>>>> 3497.715965911:main Q:Reg/w0 : PRIFILT 'local0.*' >>>>>>>>> 3497.715976154:main Q:Reg/w0 : pmask: X X X X X X X >>>>>>>>> X X >>>>>>>>> X X >>>>>>>>> X X X X X FF X X X X X X X X X >>>>>>>>> 3497.716332698:main Q:Reg/w0 : PRIFILT condition result is 0 >>>>>>>>> 3497.716337713:main Q:Reg/w0 : PRIFILT >>>>>>>>> '*.info;mail.none;authpriv.none;cron.none' >>>>>>>>> 3497.716347729:main Q:Reg/w0 : pmask: 7F 7F X 7F 7F 7F 7F 7F >>>>>>>>> 7F >>>>>>>>> X X >>>>>>>>> 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F >>>>>>>>> 3497.716424684:main Q:Reg/w0 : PRIFILT condition result is 1 >>>>>>>>> 3497.716429241:main Q:Reg/w0 : ACTION 1 >>>>>>>>> [builtin:omfile:/var/log/messages] >>>>>>>>> 3497.716439928:main Q:Reg/w0 : executing action 1 >>>>>>>>> 3497.716445132:main Q:Reg/w0 : action 'action 1': called, logging >>>>>>>>> to >>>>>>>>> builtin:omfile (susp 0/0, direct q 1) >>>>>>>>> 3497.716452142:main Q:Reg/w0 : action 'action 1': is >>>>>>>>> transactional - >>>>>>>>> executing in commit phase >>>>>>>>> 3497.716457817:main Q:Reg/w0 : Action 1 transitioned to state: itx >>>>>>>>> 3497.716462371:main Q:Reg/w0 : action 'action 1': set suspended >>>>>>>>> >>>>>>>> state >>>> >>>>> to 0 >>>>>>>>> 3497.716466771:main Q:Reg/w0 : PRIFILT 'authpriv.*' >>>>>>>>> 3497.716476330:main Q:Reg/w0 : pmask: X X X X X X X >>>>>>>>> X X >>>>>>>>> X >>>>>>>>> FF >>>>>>>>> X X X X X X X X X X X X X X X >>>>>>>>> 3497.716796250:main Q:Reg/w0 : PRIFILT condition result is 0 >>>>>>>>> 3497.716802372:main Q:Reg/w0 : PRIFILT 'mail.*' >>>>>>>>> 3497.716811926:main Q:Reg/w0 : pmask: X X FF X X X X >>>>>>>>> X X >>>>>>>>> X X >>>>>>>>> X X X X X X X X X X X X X X X >>>>>>>>> 3497.717436983:main Q:Reg/w0 : PRIFILT condition result is 0 >>>>>>>>> 3497.717444114:main Q:Reg/w0 : PRIFILT 'cron.*' >>>>>>>>> 3497.717454023:main Q:Reg/w0 : pmask: X X X X X X X >>>>>>>>> X X >>>>>>>>> FF X >>>>>>>>> X X X X X X X X X X X X X X X >>>>>>>>> 3497.717823841:main Q:Reg/w0 : PRIFILT condition result is 0 >>>>>>>>> 3497.717829094:main Q:Reg/w0 : PRIFILT '*.emerg' >>>>>>>>> 3497.717838767:main Q:Reg/w0 : pmask: 1 1 1 1 1 1 1 >>>>>>>>> 1 1 >>>>>>>>> 1 1 >>>>>>>>> 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 >>>>>>>>> 3497.717916499:main Q:Reg/w0 : PRIFILT condition result is 0 >>>>>>>>> 3497.717920817:main Q:Reg/w0 : PRIFILT 'uucp,news.crit' >>>>>>>>> 3497.717930304:main Q:Reg/w0 : pmask: X X X X X X X >>>>>>>>> 7 7 >>>>>>>>> X X >>>>>>>>> X X X X X X X X X X X X X X X >>>>>>>>> 3497.718043828:main Q:Reg/w0 : PRIFILT condition result is 0 >>>>>>>>> 3497.718044097:main Q:Reg/w0 : PRIFILT 'local7.*' >>>>>>>>> 3497.718055458:main Q:Reg/w0 : pmask: X X X X X X X >>>>>>>>> X X >>>>>>>>> X X >>>>>>>>> X X X X X X X X X X X X FF X X >>>>>>>>> 3497.718838257:main Q:Reg/w0 : PRIFILT condition result is 0 >>>>>>>>> 3497.718842803:main Q:Reg/w0 : END batch execution phase, entering >>>>>>>>> >>>>>>>> to >>>> >>>>> commit phase [processed 1 of 1 messages] >>>>>>>>> 3497.718847686:main Q:Reg/w0 : actionCommitAll: action 1, state 1, >>>>>>>>> >>>>>>>> nbr >>>> >>>>> to >>>>>>>>> commit 0 isTransactional 1 >>>>>>>>> 3497.718852750:main Q:Reg/w0 : doTransaction: have >>>>>>>>> commitTransaction >>>>>>>>> IF, >>>>>>>>> using that, pWrkrInfo 0x23c8ce0 >>>>>>>>> 3497.718857172:main Q:Reg/w0 : entering >>>>>>>>> >>>>>>>> actionCallCommitTransaction(), >>>> >>>>> state: itx, actionNbr 1, nMsgs 1 >>>>>>>>> 3497.718862516:main Q:Reg/w0 : omfile: write to stream, >>>>>>>>> pData->pStrm >>>>>>>>> 0x7f1ef4002480, lenBuf 161, strt data Mar 29 17:44:57 314959ac8cb0 >>>>>>>>> rsyslogd: [origin software="rsyslogd" swVersion="8.18.0.master" >>>>>>>>> x-pid="30306" x-info="http://www.rs >>>>>>>>> 3497.718868427:main Q:Reg/w0 : strm 0x7f1ef4002480: file >>>>>>>>> 4(messages) >>>>>>>>> flush, buflen 161 >>>>>>>>> 3497.718873173:main Q:Reg/w0 : strmPhysWrite, stream >>>>>>>>> 0x7f1ef4002480, >>>>>>>>> len >>>>>>>>> 161 >>>>>>>>> 3497.718890732:main Q:Reg/w0 : strm 0x7f1ef4002480: file 4 write >>>>>>>>> >>>>>>>> wrote >>>> >>>>> 161 >>>>>>>>> bytes >>>>>>>>> 3497.718896519:main Q:Reg/w0 : Action 1 transitioned to state: rdy >>>>>>>>> 3497.718901151:main Q:Reg/w0 : Action 1 transitioned to state: itx >>>>>>>>> 3497.718905316:main Q:Reg/w0 : Action 1 transitioned to state: rdy >>>>>>>>> 3497.718909316:main Q:Reg/w0 : actionCommit, in retry loop, iRet 0 >>>>>>>>> 3497.718913541:main Q:Reg/w0 : processBATCH: batch of 1 elements >>>>>>>>> has >>>>>>>>> been >>>>>>>>> processed >>>>>>>>> 3497.718918158:main Q:Reg/w0 : regular consumer finished, iret=0, >>>>>>>>> szlog >>>>>>>>> 0 >>>>>>>>> sz phys 1 >>>>>>>>> 3497.718923739:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 1 >>>>>>>>> objects >>>>>>>>> and enqueued 0 objects >>>>>>>>> 3497.718928090:main Q:Reg/w0 : doDeleteBatch: delete batch from >>>>>>>>> >>>>>>>> store, >>>> >>>>> new >>>>>>>>> sizes: log 0, phys 0 >>>>>>>>> 3497.718932606:main Q:Reg/w0 : regular consumer finished, iret=4, >>>>>>>>> szlog >>>>>>>>> 0 >>>>>>>>> sz phys 0 >>>>>>>>> 3497.718936888:main Q:Reg/w0 : main Q:Reg/w0: worker IDLE, waiting >>>>>>>>> >>>>>>>> for >>>> >>>>> work. >>>>>>>>> 3497.718942403:main thread : Terminating main queue... >>>>>>>>> 3497.718946280:main thread : main Q: initiating worker thread >>>>>>>>> shutdown >>>>>>>>> sequence >>>>>>>>> 3497.718950170:main thread : main Q: trying shutdown of regular >>>>>>>>> workers >>>>>>>>> 3497.718957067:main thread : sent SIGTTIN to worker thread >>>>>>>>> 0xfc315700 >>>>>>>>> 3497.718961130:main thread : main Q:Reg: waiting 1500ms on >>>>>>>>> worker >>>>>>>>> thread >>>>>>>>> termination, 1 still running >>>>>>>>> 3497.718968288:main Q:Reg/w0 : wti 0x23c8ba0: worker awoke from >>>>>>>>> idle >>>>>>>>> processing >>>>>>>>> 3497.718972108:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 0 >>>>>>>>> objects >>>>>>>>> and enqueued 0 objects >>>>>>>>> 3497.718975498:main Q:Reg/w0 : doDeleteBatch: delete batch from >>>>>>>>> >>>>>>>> store, >>>> >>>>> new >>>>>>>>> sizes: log 0, phys 0 >>>>>>>>> 3497.718979083:main Q:Reg/w0 : regular consumer finished, iret=4, >>>>>>>>> szlog >>>>>>>>> 0 >>>>>>>>> sz phys 0 >>>>>>>>> 3497.718982620:main Q:Reg/w0 : wti 0x23c8ba0: terminating worker >>>>>>>>> terminateRet=5, bInactivityTOOccured=0 >>>>>>>>> 3497.718986378:main Q:Reg/w0 : DDDD: wti 0x23c8ba0: worker cleanup >>>>>>>>> action >>>>>>>>> instances >>>>>>>>> 3497.718990027:main Q:Reg/w0 : wti 0x23c8ba0, action 0, ptr (nil) >>>>>>>>> 3497.718993327:main Q:Reg/w0 : wti 0x23c8ba0, action 1, ptr >>>>>>>>> 0x7f1ef40022a0 >>>>>>>>> 3497.718997548:main Q:Reg/w0 : wti 0x23c8ba0, action 2, ptr (nil) >>>>>>>>> 3497.719000789:main Q:Reg/w0 : wti 0x23c8ba0, action 3, ptr (nil) >>>>>>>>> 3497.719003996:main Q:Reg/w0 : wti 0x23c8ba0, action 4, ptr (nil) >>>>>>>>> 3497.719007201:main Q:Reg/w0 : wti 0x23c8ba0, action 5, ptr (nil) >>>>>>>>> 3497.719010409:main Q:Reg/w0 : wti 0x23c8ba0, action 6, ptr (nil) >>>>>>>>> 3497.719013604:main Q:Reg/w0 : wti 0x23c8ba0, action 7, ptr (nil) >>>>>>>>> 3497.719016916:main Q:Reg/w0 : wti 0x23c8ba0: worker exiting >>>>>>>>> 3497.719020757:main Q:Reg/w0 : main Q:Reg: Worker thread 23c8ba0, >>>>>>>>> terminated, num workers now 0 >>>>>>>>> 3497.719090631:main thread : main Q: regular queue workers shut >>>>>>>>> down. >>>>>>>>> 3497.719097597:main thread : main Q: checking to see if we need >>>>>>>>> to >>>>>>>>> cancel any worker threads of the primary queue >>>>>>>>> 3497.719101335:main thread : main Q: worker threads terminated, >>>>>>>>> remaining queue size log 0, phys 0. >>>>>>>>> 3497.719111115:main thread : main Q: queue (type 0) will lose 0 >>>>>>>>> messages, destroying... >>>>>>>>> 3497.719501847:main Q:Reg/w0 : destructor for debug call stack >>>>>>>>> 0x7f1ef40008c0 called >>>>>>>>> 3497.719547524:main thread : Terminating outputs... >>>>>>>>> 3497.719553777:main thread : destructing ruleset 0x23ab150, name >>>>>>>>> 0x23ab190 >>>>>>>>> 3497.719558276:main thread : debug_relp queue: initiating worker >>>>>>>>> thread >>>>>>>>> shutdown sequence >>>>>>>>> 3497.719561940:main thread : debug_relp queue: trying shutdown >>>>>>>>> of >>>>>>>>> regular workers >>>>>>>>> 3497.719568068:main thread : sent SIGTTIN to worker thread >>>>>>>>> 0xfbb14700 >>>>>>>>> 3497.719587478:main thread : debug_relp queue:Reg: waiting 0ms >>>>>>>>> on >>>>>>>>> worker >>>>>>>>> thread termination, 1 still running >>>>>>>>> 3497.719593945:debug_relp queue:Reg/w0: end relpSessConnect, iRet >>>>>>>>> >>>>>>>> 10014 >>>> >>>>> 3497.719599684:debug_relp queue:Reg/w0: Action 0 transitioned to >>>>>>>>> >>>>>>>> state: >>>> >>>>> rtry >>>>>>>>> 3497.719603211:debug_relp queue:Reg/w0: doTransaction: action 0, >>>>>>>>> currIParam >>>>>>>>> 1 >>>>>>>>> 3497.719607186:debug_relp queue:Reg/w0: actionDoRetry: debug_relp >>>>>>>>> >>>>>>>> enter >>>> >>>>> loop, iRetries=0 >>>>>>>>> 3497.719677407:main thread : debug_relp queue:Reg: timeout >>>>>>>>> waiting >>>>>>>>> on >>>>>>>>> worker thread termination >>>>>>>>> 3497.719677554:main thread : sent SIGTTIN to worker thread >>>>>>>>> 0xfbb14700 >>>>>>>>> 3497.719677725:main thread : debug_relp queue: regular shutdown >>>>>>>>> timed >>>>>>>>> out on primary queue (this is OK) >>>>>>>>> 3497.719677897:main thread : debug_relp queue: trying to >>>>>>>>> shutdown >>>>>>>>> workers within Action Timeoutsetting EnqOnly mode >>>>>>>>> 3497.719678191:main thread : debug_relp queue: trying immediate >>>>>>>>> shutdown >>>>>>>>> of regular workers (if any) >>>>>>>>> 3497.719678362:main thread : sent SIGTTIN to worker thread >>>>>>>>> 0xfbb14700 >>>>>>>>> 3497.719678558:main thread : debug_relp queue:Reg: waiting >>>>>>>>> 1000ms >>>>>>>>> >>>>>>>> on >>>> >>>>> worker thread termination, 1 still running >>>>>>>>> 3497.719678754:debug_relp queue:Reg/w0: end relpSessConnect, iRet >>>>>>>>> >>>>>>>> 10014 >>>> >>>>> 3497.719678877:debug_relp queue:Reg/w0: actionDoRetry: debug_relp >>>>>>>>> action->tryResume returned -2007 >>>>>>>>> 3497.719678999:debug_relp queue:Reg/w0: actionDoRetry: debug_relp >>>>>>>>> >>>>>>>> check >>>> >>>>> for >>>>>>>>> max retries, iResumeRetryCount -1, iRetries 0 >>>>>>>>> 3498.720321005:debug_relp queue:Reg/w0: actionTryResume: action >>>>>>>>> 0x23bebf0 >>>>>>>>> state: rtry, next retry (if applicable): 0 [now 1459273498] >>>>>>>>> 3498.720769277:debug_relp queue:Reg/w0: actionCommit, in retry >>>>>>>>> loop, >>>>>>>>> iRet >>>>>>>>> -2007 >>>>>>>>> 3498.721034552:debug_relp queue:Reg/w0: regular consumer finished, >>>>>>>>> iret=-2007, szlog 0 sz phys 1 >>>>>>>>> 3498.721240322:debug_relp queue:Reg/w0: DeleteProcessedBatch: we >>>>>>>>> deleted >>>>>>>>> 1 >>>>>>>>> objects and enqueued 0 objects >>>>>>>>> 3498.721396664:debug_relp queue:Reg/w0: doDeleteBatch: delete batch >>>>>>>>> from >>>>>>>>> store, new sizes: log 0, phys 0 >>>>>>>>> 3498.721831840:debug_relp queue:Reg/w0: wti 0x23c78b0: terminating >>>>>>>>> worker >>>>>>>>> because of TERMINATE_NOW mode, del iRet 0 >>>>>>>>> 3498.721991265:debug_relp queue:Reg/w0: DDDD: wti 0x23c78b0: worker >>>>>>>>> cleanup >>>>>>>>> action instances >>>>>>>>> 3498.722274489:debug_relp queue:Reg/w0: wti 0x23c78b0, action 0, >>>>>>>>> ptr >>>>>>>>> 0x7f1ef00020d0 >>>>>>>>> 3498.722431811:debug_relp queue:Reg/w0: relp engine destructing >>>>>>>>> >>>>>>>> client >>>> >>>>> 0x7f1ef00027e0 >>>>>>>>> 3498.723389457:debug_relp queue:Reg/w0: wti 0x23c78b0, action 1, >>>>>>>>> ptr >>>>>>>>> (nil) >>>>>>>>> 3498.723559462:debug_relp queue:Reg/w0: wti 0x23c78b0, action 2, >>>>>>>>> ptr >>>>>>>>> (nil) >>>>>>>>> 3498.723794716:debug_relp queue:Reg/w0: wti 0x23c78b0, action 3, >>>>>>>>> ptr >>>>>>>>> (nil) >>>>>>>>> 3498.723972736:debug_relp queue:Reg/w0: wti 0x23c78b0, action 4, >>>>>>>>> ptr >>>>>>>>> (nil) >>>>>>>>> 3498.724207978:debug_relp queue:Reg/w0: wti 0x23c78b0, action 5, >>>>>>>>> ptr >>>>>>>>> (nil) >>>>>>>>> 3498.724215660:debug_relp queue:Reg/w0: wti 0x23c78b0, action 6, >>>>>>>>> ptr >>>>>>>>> (nil) >>>>>>>>> 3498.724219766:debug_relp queue:Reg/w0: wti 0x23c78b0, action 7, >>>>>>>>> ptr >>>>>>>>> (nil) >>>>>>>>> 3498.724223775:debug_relp queue:Reg/w0: wti 0x23c78b0: worker >>>>>>>>> exiting >>>>>>>>> 3498.724228430:debug_relp queue:Reg/w0: debug_relp queue:Reg: >>>>>>>>> Worker >>>>>>>>> thread >>>>>>>>> 23c78b0, terminated, num workers now 0 >>>>>>>>> 3498.724243673:debug_relp queue:Reg/w0: destructor for debug call >>>>>>>>> >>>>>>>> stack >>>> >>>>> 0x7f1ef00008c0 called >>>>>>>>> 3498.724371931:main thread : debug_relp queue: checking to see >>>>>>>>> if >>>>>>>>> >>>>>>>> we >>>> >>>>> need to cancel any worker threads of the primary queue >>>>>>>>> 3498.724379712:main thread : debug_relp queue: worker threads >>>>>>>>> terminated, remaining queue size log 0, phys 0. >>>>>>>>> 3498.724386288:main thread : debug_relp queue: persisting queue >>>>>>>>> to >>>>>>>>> disk, >>>>>>>>> 0 entries... >>>>>>>>> 3498.724391611:main thread : strm 0x23b74c0: file 5(relp_queue) >>>>>>>>> closing >>>>>>>>> 3498.724396110:main thread : strm 0x23b74c0: file 5(relp_queue) >>>>>>>>> flush, >>>>>>>>> buflen 0 (no need to flush) >>>>>>>>> 3498.724411574:main thread : strm 0x23b7760: file 6(relp_queue) >>>>>>>>> closing >>>>>>>>> 3498.724418797:main thread : strm 0x23b7a00: file -1(relp_queue) >>>>>>>>> closing >>>>>>>>> 3498.724423956:main thread : strmCloseFile: deleting >>>>>>>>> '/var/spool/rsyslog/relp_queue.00000001' >>>>>>>>> 3498.724490018:main thread : strm 0x7f1ef4002480: file >>>>>>>>> 4(messages) >>>>>>>>> closing >>>>>>>>> 3498.724607874:main thread : strm 0x7f1ef4002480: file >>>>>>>>> 4(messages) >>>>>>>>> flush, buflen 0 (no need to flush) >>>>>>>>> 3498.724731690:main thread : all primary multi-thread sources >>>>>>>>> have >>>>>>>>> been >>>>>>>>> terminated - now doing aux cleanup... >>>>>>>>> 3498.724737248:main thread : destructing current config... >>>>>>>>> 3498.724741760:main thread : calling freeCnf(0x23a91e0) for >>>>>>>>> module >>>>>>>>> 'builtin:omfile' >>>>>>>>> 3498.724745773:main thread : calling freeCnf(0x23a93a0) for >>>>>>>>> module >>>>>>>>> 'builtin:ompipe' >>>>>>>>> 3498.724749977:main thread : calling freeCnf(0x23aa3a0) for >>>>>>>>> module >>>>>>>>> 'builtin:omfwd' >>>>>>>>> 3498.724754588:main thread : calling freeCnf(0x23b9b00) for >>>>>>>>> module >>>>>>>>> 'imuxsock' >>>>>>>>> 3498.724758956:main thread : calling freeCnf(0x23bac70) for >>>>>>>>> module >>>>>>>>> 'imklog' >>>>>>>>> 3498.724807014:main thread : destructing parser >>>>>>>>> 'rsyslog.rfc5424' >>>>>>>>> 3498.724871141:main thread : destructing parser >>>>>>>>> 'rsyslog.rfc3164' >>>>>>>>> 3498.724876440:main thread : pmrfc3164: free parser instance >>>>>>>>> 0x23aa8b0 >>>>>>>>> 3498.724887558:main thread : file rsyslogd.c released module >>>>>>>>> 'lmnet', >>>>>>>>> reference count now 2 >>>>>>>>> 3498.724892004:main thread : module lmnet NOT unloaded because >>>>>>>>> it >>>>>>>>> still >>>>>>>>> has a refcount of 2 >>>>>>>>> 3498.724895745:main thread : Unloading module builtin:omfile >>>>>>>>> 3498.724900191:main thread : module lmnet NOT unloaded because >>>>>>>>> it >>>>>>>>> still >>>>>>>>> has a refcount of 2 >>>>>>>>> 3498.724904194:main thread : Unloading module builtin:ompipe >>>>>>>>> 3498.724908035:main thread : module lmnet NOT unloaded because >>>>>>>>> it >>>>>>>>> still >>>>>>>>> has a refcount of 2 >>>>>>>>> 3498.724911707:main thread : Unloading module builtin-shell >>>>>>>>> 3498.725044125:main thread : module lmnet NOT unloaded because >>>>>>>>> it >>>>>>>>> still >>>>>>>>> has a refcount of 2 >>>>>>>>> 3498.725050401:main thread : Unloading module builtin:omdiscard >>>>>>>>> 3498.725054843:main thread : module lmnet NOT unloaded because >>>>>>>>> it >>>>>>>>> still >>>>>>>>> has a refcount of 2 >>>>>>>>> 3498.725058772:main thread : Unloading module builtin:omfwd >>>>>>>>> 3498.725064464:main thread : file omfwd.c released module >>>>>>>>> 'lmnet', >>>>>>>>> reference count now 1 >>>>>>>>> 3498.725068747:main thread : module lmnet NOT unloaded because >>>>>>>>> it >>>>>>>>> still >>>>>>>>> has a refcount of 1 >>>>>>>>> 3498.725072460:main thread : Unloading module builtin:omusrmsg >>>>>>>>> 3498.725076324:main thread : module lmnet NOT unloaded because >>>>>>>>> it >>>>>>>>> still >>>>>>>>> has a refcount of 1 >>>>>>>>> 3498.725080023:main thread : Unloading module builtin:pmrfc5424 >>>>>>>>> 3498.725084039:main thread : module lmnet NOT unloaded because >>>>>>>>> it >>>>>>>>> still >>>>>>>>> has a refcount of 1 >>>>>>>>> 3498.725087646:main thread : Unloading module builtin:pmrfc3164 >>>>>>>>> 3498.725091651:main thread : module lmnet NOT unloaded because >>>>>>>>> it >>>>>>>>> still >>>>>>>>> has a refcount of 1 >>>>>>>>> 3498.725095255:main thread : Unloading module builtin:smfile >>>>>>>>> 3498.725099010:main thread : module lmnet NOT unloaded because >>>>>>>>> it >>>>>>>>> still >>>>>>>>> has a refcount of 1 >>>>>>>>> 3498.725102601:main thread : Unloading module builtin:smtradfile >>>>>>>>> 3498.725106419:main thread : module lmnet NOT unloaded because >>>>>>>>> it >>>>>>>>> still >>>>>>>>> has a refcount of 1 >>>>>>>>> 3498.725110003:main thread : Unloading module builtin:smfwd >>>>>>>>> 3498.725113689:main thread : module lmnet NOT unloaded because >>>>>>>>> it >>>>>>>>> still >>>>>>>>> has a refcount of 1 >>>>>>>>> 3498.725117357:main thread : Unloading module builtin:smtradfwd >>>>>>>>> 3498.725121132:main thread : module lmnet NOT unloaded because >>>>>>>>> it >>>>>>>>> still >>>>>>>>> has a refcount of 1 >>>>>>>>> 3498.725124782:main thread : Unloading module imuxsock >>>>>>>>> 3498.725157459:main thread : module lmnet NOT unloaded because >>>>>>>>> it >>>>>>>>> still >>>>>>>>> has a refcount of 1 >>>>>>>>> 3498.725162797:main thread : Unloading module imklog >>>>>>>>> 3498.725179208:main thread : module lmnet NOT unloaded because >>>>>>>>> it >>>>>>>>> still >>>>>>>>> has a refcount of 1 >>>>>>>>> 3498.726112994:main thread : Unloading module omrelp >>>>>>>>> 3498.726184405:main thread : module lmnet NOT unloaded because >>>>>>>>> it >>>>>>>>> still >>>>>>>>> has a refcount of 1 >>>>>>>>> 3498.726189821:main thread : module lmregexp NOT unloaded >>>>>>>>> because >>>>>>>>> >>>>>>>> it >>>> >>>>> still has a refcount of 1 >>>>>>>>> 3498.726195161:main thread : file conf.c released module >>>>>>>>> 'lmnet', >>>>>>>>> reference count now 0 >>>>>>>>> 3498.726198620:main thread : module 'lmnet' has zero reference >>>>>>>>> count, >>>>>>>>> unloading... >>>>>>>>> 3498.726201936:main thread : Unloading module lmnet >>>>>>>>> 3498.726218655:main thread : rsyslog runtime de-initialized, >>>>>>>>> >>>>>>>> current >>>> >>>>> users 0 >>>>>>>>> 3498.726222660:main thread : Clean shutdown completed, bye >>>>>>>>> >>>>>>>>> >>>>>>>>> On Mon, Mar 28, 2016 at 4:41 PM, Kane Kim <[email protected]> >>>>>>>>> wrote: >>>>>>>>> >>>>>>>>> Hello Reiner, >>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> I'm seeing the same behavior with omrelp module. I've configured >>>>>>>>>> omrelp >>>>>>>>>> to >>>>>>>>>> non-routable ip address: >>>>>>>>>> module(load="omrelp") >>>>>>>>>> local0.* action(type="omrelp" >>>>>>>>>> target="10.0.0.1" >>>>>>>>>> port="2514" >>>>>>>>>> name="debug_relp" >>>>>>>>>> queue.filename="relp_queue" >>>>>>>>>> queue.maxdiskspace="1G" >>>>>>>>>> queue.saveonshutdown="on" >>>>>>>>>> queue.spoolDirectory="/var/spool/rsyslog" >>>>>>>>>> queue.type="Disk" >>>>>>>>>> ) >>>>>>>>>> Then I try to log a line: >>>>>>>>>> [root@314959ac8cb0 prism]# logger -p local0.info test >>>>>>>>>> [root@314959ac8cb0 prism]# ls /var/spool/rsyslog/ >>>>>>>>>> relp_queue.00000001 >>>>>>>>>> # I shutdown rsyslog at this point >>>>>>>>>> [root@314959ac8cb0 prism]# ls /var/spool/rsyslog/ >>>>>>>>>> # after shutdown queue is deleted and message is lost >>>>>>>>>> [root@314959ac8cb0 prism]# >>>>>>>>>> >>>>>>>>>> Here is rsyslog log, so omrelp starts transaction and then I >>>>>>>>>> >>>>>>>>> shutdown >>>> >>>>> rsyslog, it seems at some point queue is deleted: >>>>>>>>>> >>>>>>>>>> 8184.798028612:debug_relp queue:Reg/w0: omrelp: beginTransaction >>>>>>>>>> ^C8194.245122305:main thread : DoDie called. >>>>>>>>>> 8194.245301525:main thread : exiting on signal 2 >>>>>>>>>> 8194.245532709:main thread : Terminating input threads... >>>>>>>>>> 8194.245873683:main thread : request term via SIGTTIN for input >>>>>>>>>> thread >>>>>>>>>> 'imuxsock' 0xcb767700 >>>>>>>>>> 8194.246079748:imuxsock.c : thrdStarter: usrThrdMain imuxsock >>>>>>>>>> - >>>>>>>>>> 0x7f9bcb767700 returned with iRet 0, exiting now. >>>>>>>>>> 8194.247556671:main thread : non-cancel input thread >>>>>>>>>> termination >>>>>>>>>> succeeded for thread imuxsock 0xcb767700 >>>>>>>>>> 8194.249357547:imuxsock.c : destructor for debug call stack >>>>>>>>>> 0x7f9bbc0008c0 called >>>>>>>>>> 8194.249784271:main thread : imuxsock: unlinking unix socket >>>>>>>>>> file[0] >>>>>>>>>> /dev/log >>>>>>>>>> 8194.250043368:main thread : main Q: qqueueAdd: entry added, >>>>>>>>>> size >>>>>>>>>> now >>>>>>>>>> log 1, phys 1 entries >>>>>>>>>> 8194.250321193:main thread : main Q: EnqueueMsg advised worker >>>>>>>>>> start >>>>>>>>>> 8194.250493505:main Q:Reg/w0 : wti 0x1c13bb0: worker awoke from >>>>>>>>>> >>>>>>>>> idle >>>> >>>>> processing >>>>>>>>>> 8194.250735988:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 0 >>>>>>>>>> objects >>>>>>>>>> and enqueued 0 objects >>>>>>>>>> 8194.250959294:main Q:Reg/w0 : doDeleteBatch: delete batch from >>>>>>>>>> store, >>>>>>>>>> new sizes: log 1, phys 1 >>>>>>>>>> 8194.251913535:main Q:Reg/w0 : processBATCH: batch of 1 elements >>>>>>>>>> >>>>>>>>> must >>>> >>>>> be >>>>>>>>>> processed >>>>>>>>>> 8194.252193683:main Q:Reg/w0 : processBATCH: next msg 0: [origin >>>>>>>>>> software="rsyslogd" swVersion="8.18.0.master" x-pid="30298" >>>>>>>>>> x-info=" >>>>>>>>>> http://www.rsyslog.com";] exiting on signal 2. >>>>>>>>>> 8194.252377044:main Q:Reg/w0 : PRIFILT 'local0.*' >>>>>>>>>> 8194.252669683:main Q:Reg/w0 : pmask: X X X X X X X X >>>>>>>>>> >>>>>>>>> X >>>> >>>>> X >>>>>>>>>> X X X X X X FF X X X X X X X X X >>>>>>>>>> 8194.252898063:main Q:Reg/w0 : PRIFILT condition result is 0 >>>>>>>>>> 8194.252902083:main Q:Reg/w0 : PRIFILT >>>>>>>>>> '*.info;mail.none;authpriv.none;cron.none' >>>>>>>>>> 8194.252908847:main Q:Reg/w0 : pmask: 7F 7F X 7F 7F 7F 7F 7F >>>>>>>>>> >>>>>>>>> 7F >>>> >>>>> X >>>>>>>>>> X 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F >>>>>>>>>> 8194.252956209:main Q:Reg/w0 : PRIFILT condition result is 1 >>>>>>>>>> 8194.252959849:main Q:Reg/w0 : ACTION 1 >>>>>>>>>> [builtin:omfile:/var/log/messages] >>>>>>>>>> 8194.252967510:main Q:Reg/w0 : executing action 1 >>>>>>>>>> 8194.252971541:main Q:Reg/w0 : action 'action 1': called, logging >>>>>>>>>> >>>>>>>>> to >>>> >>>>> builtin:omfile (susp 0/0, direct q 1) >>>>>>>>>> 8194.252977583:main Q:Reg/w0 : action 'action 1': is >>>>>>>>>> transactional >>>>>>>>>> >>>>>>>>> - >>>> >>>>> executing in commit phase >>>>>>>>>> 8194.252982638:main Q:Reg/w0 : Action 1 transitioned to state: >>>>>>>>>> itx >>>>>>>>>> 8194.252986300:main Q:Reg/w0 : action 'action 1': set suspended >>>>>>>>>> >>>>>>>>> state >>>> >>>>> to 0 >>>>>>>>>> 8194.252989729:main Q:Reg/w0 : PRIFILT 'authpriv.*' >>>>>>>>>> 8194.252996951:main Q:Reg/w0 : pmask: X X X X X X X X >>>>>>>>>> >>>>>>>>> X >>>> >>>>> X >>>>>>>>>> FF X X X X X X X X X X X X X X X >>>>>>>>>> 8194.253051858:main Q:Reg/w0 : PRIFILT condition result is 0 >>>>>>>>>> 8194.253056228:main Q:Reg/w0 : PRIFILT 'mail.*' >>>>>>>>>> 8194.253065299:main Q:Reg/w0 : pmask: X X FF X X X X X >>>>>>>>>> >>>>>>>>> X >>>> >>>>> X >>>>>>>>>> X X X X X X X X X X X X X X X X >>>>>>>>>> 8194.253407472:main Q:Reg/w0 : PRIFILT condition result is 0 >>>>>>>>>> 8194.253412679:main Q:Reg/w0 : PRIFILT 'cron.*' >>>>>>>>>> 8194.253422055:main Q:Reg/w0 : pmask: X X X X X X X X >>>>>>>>>> >>>>>>>>> X >>>> >>>>> FF >>>>>>>>>> X X X X X X X X X X X X X X X X >>>>>>>>>> 8194.253493551:main Q:Reg/w0 : PRIFILT condition result is 0 >>>>>>>>>> 8194.253498038:main Q:Reg/w0 : PRIFILT '*.emerg' >>>>>>>>>> 8194.253507065:main Q:Reg/w0 : pmask: 1 1 1 1 1 1 1 1 >>>>>>>>>> >>>>>>>>> 1 >>>> >>>>> 1 >>>>>>>>>> 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 >>>>>>>>>> 8194.253580307:main Q:Reg/w0 : PRIFILT condition result is 0 >>>>>>>>>> 8194.253584400:main Q:Reg/w0 : PRIFILT 'uucp,news.crit' >>>>>>>>>> 8194.253593442:main Q:Reg/w0 : pmask: X X X X X X X 7 >>>>>>>>>> >>>>>>>>> 7 >>>> >>>>> X >>>>>>>>>> X X X X X X X X X X X X X X X X >>>>>>>>>> 8194.253664984:main Q:Reg/w0 : PRIFILT condition result is 0 >>>>>>>>>> 8194.253669184:main Q:Reg/w0 : PRIFILT 'local7.*' >>>>>>>>>> 8194.253678130:main Q:Reg/w0 : pmask: X X X X X X X X >>>>>>>>>> >>>>>>>>> X >>>> >>>>> X >>>>>>>>>> X X X X X X X X X X X X X FF X X >>>>>>>>>> 8194.254445021:main Q:Reg/w0 : PRIFILT condition result is 0 >>>>>>>>>> 8194.254450651:main Q:Reg/w0 : END batch execution phase, >>>>>>>>>> entering >>>>>>>>>> >>>>>>>>> to >>>> >>>>> commit phase [processed 1 of 1 messages] >>>>>>>>>> 8194.254456257:main Q:Reg/w0 : actionCommitAll: action 1, state >>>>>>>>>> 1, >>>>>>>>>> nbr >>>>>>>>>> to >>>>>>>>>> commit 0 isTransactional 1 >>>>>>>>>> 8194.254461646:main Q:Reg/w0 : doTransaction: have >>>>>>>>>> >>>>>>>>> commitTransaction >>>> >>>>> IF, >>>>>>>>>> using that, pWrkrInfo 0x1c13cf0 >>>>>>>>>> 8194.254466238:main Q:Reg/w0 : entering >>>>>>>>>> actionCallCommitTransaction(), >>>>>>>>>> state: itx, actionNbr 1, nMsgs 1 >>>>>>>>>> 8194.254471876:main Q:Reg/w0 : omfile: write to stream, >>>>>>>>>> >>>>>>>>> pData->pStrm >>>> >>>>> 0x7f9bc4002480, lenBuf 161, strt data Mar 28 23:36:34 314959ac8cb0 >>>>>>>>>> rsyslogd: [origin software="rsyslogd" swVersion="8.18.0.master" >>>>>>>>>> x-pid="30298" x-info="http://www.rs >>>>>>>>>> 8194.254478237:main Q:Reg/w0 : strm 0x7f9bc4002480: file >>>>>>>>>> >>>>>>>>> 4(messages) >>>> >>>>> flush, buflen 161 >>>>>>>>>> 8194.254483210:main Q:Reg/w0 : strmPhysWrite, stream >>>>>>>>>> >>>>>>>>> 0x7f9bc4002480, >>>> >>>>> len >>>>>>>>>> 161 >>>>>>>>>> 8194.254500329:main Q:Reg/w0 : strm 0x7f9bc4002480: file 4 write >>>>>>>>>> wrote >>>>>>>>>> 161 bytes >>>>>>>>>> 8194.254506254:main Q:Reg/w0 : Action 1 transitioned to state: >>>>>>>>>> rdy >>>>>>>>>> 8194.254511506:main Q:Reg/w0 : Action 1 transitioned to state: >>>>>>>>>> itx >>>>>>>>>> 8194.254515961:main Q:Reg/w0 : Action 1 transitioned to state: >>>>>>>>>> rdy >>>>>>>>>> 8194.254520243:main Q:Reg/w0 : actionCommit, in retry loop, iRet >>>>>>>>>> 0 >>>>>>>>>> 8194.254524679:main Q:Reg/w0 : processBATCH: batch of 1 elements >>>>>>>>>> >>>>>>>>> has >>>> >>>>> been >>>>>>>>>> processed >>>>>>>>>> 8194.254529731:main Q:Reg/w0 : regular consumer finished, iret=0, >>>>>>>>>> szlog 0 >>>>>>>>>> sz phys 1 >>>>>>>>>> 8194.254536104:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 1 >>>>>>>>>> objects >>>>>>>>>> and enqueued 0 objects >>>>>>>>>> 8194.254540861:main Q:Reg/w0 : doDeleteBatch: delete batch from >>>>>>>>>> store, >>>>>>>>>> new sizes: log 0, phys 0 >>>>>>>>>> 8194.254545792:main Q:Reg/w0 : regular consumer finished, iret=4, >>>>>>>>>> szlog 0 >>>>>>>>>> sz phys 0 >>>>>>>>>> 8194.254550314:main Q:Reg/w0 : main Q:Reg/w0: worker IDLE, >>>>>>>>>> waiting >>>>>>>>>> for >>>>>>>>>> work. >>>>>>>>>> 8194.254556418:main thread : Terminating main queue... >>>>>>>>>> 8194.254560776:main thread : main Q: initiating worker thread >>>>>>>>>> shutdown >>>>>>>>>> sequence >>>>>>>>>> 8194.254564653:main thread : main Q: trying shutdown of regular >>>>>>>>>> workers >>>>>>>>>> 8194.254572961:main thread : sent SIGTTIN to worker thread >>>>>>>>>> 0xcaf66700 >>>>>>>>>> 8194.254577260:main thread : main Q:Reg: waiting 1499ms on >>>>>>>>>> worker >>>>>>>>>> thread termination, 1 still running >>>>>>>>>> 8194.254585507:main Q:Reg/w0 : wti 0x1c13bb0: worker awoke from >>>>>>>>>> >>>>>>>>> idle >>>> >>>>> processing >>>>>>>>>> 8194.254589465:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 0 >>>>>>>>>> objects >>>>>>>>>> and enqueued 0 objects >>>>>>>>>> 8194.254593070:main Q:Reg/w0 : doDeleteBatch: delete batch from >>>>>>>>>> store, >>>>>>>>>> new sizes: log 0, phys 0 >>>>>>>>>> 8194.254596813:main Q:Reg/w0 : regular consumer finished, iret=4, >>>>>>>>>> szlog 0 >>>>>>>>>> sz phys 0 >>>>>>>>>> 8194.254600412:main Q:Reg/w0 : wti 0x1c13bb0: terminating worker >>>>>>>>>> terminateRet=5, bInactivityTOOccured=0 >>>>>>>>>> 8194.254604469:main Q:Reg/w0 : DDDD: wti 0x1c13bb0: worker >>>>>>>>>> cleanup >>>>>>>>>> action >>>>>>>>>> instances >>>>>>>>>> 8194.254608268:main Q:Reg/w0 : wti 0x1c13bb0, action 0, ptr (nil) >>>>>>>>>> 8194.254611752:main Q:Reg/w0 : wti 0x1c13bb0, action 1, ptr >>>>>>>>>> 0x7f9bc40022a0 >>>>>>>>>> 8194.254616114:main Q:Reg/w0 : wti 0x1c13bb0, action 2, ptr (nil) >>>>>>>>>> 8194.254619450:main Q:Reg/w0 : wti 0x1c13bb0, action 3, ptr (nil) >>>>>>>>>> 8194.254622767:main Q:Reg/w0 : wti 0x1c13bb0, action 4, ptr (nil) >>>>>>>>>> 8194.254626075:main Q:Reg/w0 : wti 0x1c13bb0, action 5, ptr (nil) >>>>>>>>>> 8194.254629392:main Q:Reg/w0 : wti 0x1c13bb0, action 6, ptr (nil) >>>>>>>>>> 8194.254632707:main Q:Reg/w0 : wti 0x1c13bb0, action 7, ptr (nil) >>>>>>>>>> 8194.254636124:main Q:Reg/w0 : wti 0x1c13bb0: worker exiting >>>>>>>>>> 8194.254639920:main Q:Reg/w0 : main Q:Reg: Worker thread 1c13bb0, >>>>>>>>>> terminated, num workers now 0 >>>>>>>>>> 8194.254656279:main thread : main Q: regular queue workers shut >>>>>>>>>> down. >>>>>>>>>> 8194.254656402:main thread : main Q: checking to see if we need >>>>>>>>>> >>>>>>>>> to >>>> >>>>> cancel any worker threads of the primary queue >>>>>>>>>> 8194.254656524:main thread : main Q: worker threads terminated, >>>>>>>>>> remaining queue size log 0, phys 0. >>>>>>>>>> 8194.254656647:main thread : main Q: queue (type 0) will lose 0 >>>>>>>>>> messages, destroying... >>>>>>>>>> 8194.255021761:main Q:Reg/w0 : destructor for debug call stack >>>>>>>>>> 0x7f9bc40008c0 called >>>>>>>>>> 8194.255069521:main thread : Terminating outputs... >>>>>>>>>> 8194.255084818:main thread : destructing ruleset 0x1bf6150, >>>>>>>>>> name >>>>>>>>>> 0x1bf6190 >>>>>>>>>> 8194.255089525:main thread : debug_relp queue: initiating >>>>>>>>>> worker >>>>>>>>>> thread >>>>>>>>>> shutdown sequence >>>>>>>>>> 8194.255093230:main thread : debug_relp queue: trying shutdown >>>>>>>>>> of >>>>>>>>>> regular workers >>>>>>>>>> 8194.255099210:main thread : sent SIGTTIN to worker thread >>>>>>>>>> 0xca765700 >>>>>>>>>> 8194.255119598:main thread : debug_relp queue:Reg: waiting 0ms >>>>>>>>>> on >>>>>>>>>> worker thread termination, 1 still running >>>>>>>>>> 8194.255126357:debug_relp queue:Reg/w0: end relpSessConnect, iRet >>>>>>>>>> 10014 >>>>>>>>>> 8194.255132022:debug_relp queue:Reg/w0: Action 0 transitioned to >>>>>>>>>> state: >>>>>>>>>> rtry >>>>>>>>>> 8194.255135551:debug_relp queue:Reg/w0: doTransaction: action 0, >>>>>>>>>> currIParam 1 >>>>>>>>>> 8194.255139603:debug_relp queue:Reg/w0: actionDoRetry: debug_relp >>>>>>>>>> enter >>>>>>>>>> loop, iRetries=0 >>>>>>>>>> 8194.255210939:main thread : debug_relp queue:Reg: timeout >>>>>>>>>> >>>>>>>>> waiting >>>> >>>>> on >>>>>>>>>> worker thread termination >>>>>>>>>> 8194.255211086:main thread : sent SIGTTIN to worker thread >>>>>>>>>> 0xca765700 >>>>>>>>>> 8194.255211257:main thread : debug_relp queue: regular shutdown >>>>>>>>>> timed >>>>>>>>>> out on primary queue (this is OK) >>>>>>>>>> 8194.255211429:main thread : debug_relp queue: trying to >>>>>>>>>> shutdown >>>>>>>>>> workers within Action Timeoutsetting EnqOnly mode >>>>>>>>>> 8194.255215492:main thread : debug_relp queue: trying immediate >>>>>>>>>> shutdown of regular workers (if any) >>>>>>>>>> 8194.255221059:main thread : sent SIGTTIN to worker thread >>>>>>>>>> 0xca765700 >>>>>>>>>> 8194.255226792:main thread : debug_relp queue:Reg: waiting >>>>>>>>>> 1000ms >>>>>>>>>> on >>>>>>>>>> worker thread termination, 1 still running >>>>>>>>>> 8194.255232713:debug_relp queue:Reg/w0: end relpSessConnect, iRet >>>>>>>>>> 10014 >>>>>>>>>> 8194.255237080:debug_relp queue:Reg/w0: actionDoRetry: debug_relp >>>>>>>>>> action->tryResume returned -2007 >>>>>>>>>> 8194.255240684:debug_relp queue:Reg/w0: actionDoRetry: debug_relp >>>>>>>>>> check >>>>>>>>>> for max retries, iResumeRetryCount 0, iRetries 0 >>>>>>>>>> 8194.255244459:debug_relp queue:Reg/w0: Action 0 transitioned to >>>>>>>>>> state: >>>>>>>>>> susp >>>>>>>>>> 8194.255257975:debug_relp queue:Reg/w0: Called LogMsg, msg: action >>>>>>>>>> 'debug_relp' suspended, next retry is Mon Mar 28 23:37:04 2016 >>>>>>>>>> 8194.255266857:debug_relp queue:Reg/w0: submitMsg2() could not >>>>>>>>>> >>>>>>>>> submit >>>> >>>>> message - queue does (no longer?) exist - ignored >>>>>>>>>> 8194.255271065:debug_relp queue:Reg/w0: action 'debug_relp' >>>>>>>>>> >>>>>>>>> suspended, >>>> >>>>> earliest retry=1459208224 (now 1459208194), iNbrResRtry 0, duration >>>>>>>>>> >>>>>>>>> 30 >>>> >>>>> 8194.255275244:debug_relp queue:Reg/w0: actionTryResume: action >>>>>>>>>> 0x1c09af0 >>>>>>>>>> state: susp, next retry (if applicable): 1459208224 [now >>>>>>>>>> 1459208194] >>>>>>>>>> 8194.255278825:debug_relp queue:Reg/w0: actionCommit, in retry >>>>>>>>>> loop, >>>>>>>>>> iRet >>>>>>>>>> -2123 >>>>>>>>>> 8194.255282409:debug_relp queue:Reg/w0: regular consumer finished, >>>>>>>>>> iret=-2123, szlog 0 sz phys 1 >>>>>>>>>> 8194.255287286:debug_relp queue:Reg/w0: DeleteProcessedBatch: we >>>>>>>>>> deleted 1 >>>>>>>>>> objects and enqueued 0 objects >>>>>>>>>> 8194.255290952:debug_relp queue:Reg/w0: doDeleteBatch: delete >>>>>>>>>> batch >>>>>>>>>> from >>>>>>>>>> store, new sizes: log 0, phys 0 >>>>>>>>>> 8194.255295204:debug_relp queue:Reg/w0: wti 0x1c12880: terminating >>>>>>>>>> worker >>>>>>>>>> because of TERMINATE_NOW mode, del iRet 0 >>>>>>>>>> 8194.255298822:debug_relp queue:Reg/w0: DDDD: wti 0x1c12880: >>>>>>>>>> worker >>>>>>>>>> cleanup action instances >>>>>>>>>> 8194.255302306:debug_relp queue:Reg/w0: wti 0x1c12880, action 0, >>>>>>>>>> ptr >>>>>>>>>> 0x7f9bc00020d0 >>>>>>>>>> 8194.255305929:debug_relp queue:Reg/w0: relp engine destructing >>>>>>>>>> >>>>>>>>> client >>>> >>>>> 0x7f9bc00027e0 >>>>>>>>>> 8194.255309843:debug_relp queue:Reg/w0: wti 0x1c12880, action 1, >>>>>>>>>> ptr >>>>>>>>>> (nil) >>>>>>>>>> 8194.255313226:debug_relp queue:Reg/w0: wti 0x1c12880, action 2, >>>>>>>>>> ptr >>>>>>>>>> (nil) >>>>>>>>>> 8194.255316479:debug_relp queue:Reg/w0: wti 0x1c12880, action 3, >>>>>>>>>> ptr >>>>>>>>>> (nil) >>>>>>>>>> 8194.255319704:debug_relp queue:Reg/w0: wti 0x1c12880, action 4, >>>>>>>>>> ptr >>>>>>>>>> (nil) >>>>>>>>>> 8194.255322934:debug_relp queue:Reg/w0: wti 0x1c12880, action 5, >>>>>>>>>> ptr >>>>>>>>>> (nil) >>>>>>>>>> 8194.255326175:debug_relp queue:Reg/w0: wti 0x1c12880, action 6, >>>>>>>>>> ptr >>>>>>>>>> (nil) >>>>>>>>>> 8194.255329409:debug_relp queue:Reg/w0: wti 0x1c12880, action 7, >>>>>>>>>> ptr >>>>>>>>>> (nil) >>>>>>>>>> 8194.255332655:debug_relp queue:Reg/w0: wti 0x1c12880: worker >>>>>>>>>> >>>>>>>>> exiting >>>> >>>>> 8194.255336231:debug_relp queue:Reg/w0: debug_relp queue:Reg: Worker >>>>>>>>>> thread 1c12880, terminated, num workers now 0 >>>>>>>>>> 8194.255344540:debug_relp queue:Reg/w0: destructor for debug call >>>>>>>>>> stack >>>>>>>>>> 0x7f9bc00008c0 called >>>>>>>>>> 8194.255371534:main thread : debug_relp queue: checking to see >>>>>>>>>> if >>>>>>>>>> we >>>>>>>>>> need to cancel any worker threads of the primary queue >>>>>>>>>> 8194.255376798:main thread : debug_relp queue: worker threads >>>>>>>>>> terminated, remaining queue size log 0, phys 0. >>>>>>>>>> 8194.255381256:main thread : debug_relp queue: persisting queue >>>>>>>>>> >>>>>>>>> to >>>> >>>>> disk, 0 entries... >>>>>>>>>> 8194.255385525:main thread : strm 0x1c024c0: file 5(relp_queue) >>>>>>>>>> closing >>>>>>>>>> 8194.255389222:main thread : strm 0x1c024c0: file 5(relp_queue) >>>>>>>>>> flush, >>>>>>>>>> buflen 0 (no need to flush) >>>>>>>>>> 8194.255398716:main thread : strm 0x1c02760: file 6(relp_queue) >>>>>>>>>> closing >>>>>>>>>> 8194.255404785:main thread : strm 0x1c02a00: file >>>>>>>>>> -1(relp_queue) >>>>>>>>>> closing >>>>>>>>>> 8194.255409145:main thread : strmCloseFile: deleting >>>>>>>>>> '/var/spool/rsyslog/relp_queue.00000001' >>>>>>>>>> 8194.255460812:main thread : strm 0x7f9bc4002480: file >>>>>>>>>> >>>>>>>>> 4(messages) >>>> >>>>> closing >>>>>>>>>> 8194.255466309:main thread : strm 0x7f9bc4002480: file >>>>>>>>>> >>>>>>>>> 4(messages) >>>> >>>>> flush, buflen 0 (no need to flush) >>>>>>>>> >>>>>>>>> _______________________________________________ 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 NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE THAT.
