On Thu, Mar 5, 2015 at 11:38 AM, David Lang <[email protected]> wrote: > What do you mean when you say it's getting corrupted? > > What is the log message that's being delivered, and what does it look like > after the corruption? > > David Lang > > > On Thu, 5 Mar 2015, Andrew Ruch wrote: > >> Hello, >> >> I'm using Rsyslog 8.8.0 on RHEL 6.6 on the sender and receiver. >> >> I'm experiencing an issue where my disk queue is getting corrupted, >> even just sending one message. The Rsyslog server is configured to >> receive messages over TCP. The message is then put into a disk queue >> before being sent to another local application. When I comment out the >> 4 “queue” lines on the action, everything works fine. The remote logs >> are received and written to “/var/log/remote.log” successfully. Is >> there something else I need to configure for the disk queue to work? >> >> >> Below is a simple configuration file created for debugging this >> problem. Also included are some relevant lines from the Rsyslog debug >> log. >> >> >> ########################################################################## >> >> SERVER CONFIG FILE >> >> ########################################################################## >> >> # rsyslog v8 configuration file (server) >> >> #### GLOBAL DIRECTIVES #### >> >> $DebugLevel 2 >> $DebugFile /var/log/rsyslog-debug.log >> >> $umask 0000 >> >> # Working directory for spooling and file monitoring >> $WorkDirectory /var/lib/rsyslog >> >> # Set the message size to 32k (up from 2k default) >> $MaxMessageSize 32768 >> >> #### MODULES #### >> >> # Configure file output defaults >> module( load="builtin:omfile" >> template="RSYSLOG_TraditionalFileFormat" >> fileCreateMode="0600" >> ) >> >> # provides input for tcp connections >> module( load="imtcp" >> NotifyOnConnectionClose="on" >> ) >> >> #### NETSTREAM DRIVER #### >> $DefaultNetstreamDriver ptcp >> >> #### RULESETS #### >> >> ruleset(name="remote"){ >> >> # To file >> *.* /var/log/remote.log >> >> # To local process >> action( template="RSYSLOG_SyslogProtocol23Format" >> name="remotefwd" >> type="omfwd" >> action.resumeRetryCount="-1" >> target="127.0.0.1" >> port="7871" >> protocol="tcp" >> TCP_Framing="octet-counted" >> queue.filename="remotefwd" >> queue.size="1000000" >> queue.type="Disk" >> queue.saveonshutdown="on" >> StreamDriver="ptcp" >> ) >> >> } >> >> #### INPUTS #### >> input(type="imtcp" port="10514" ruleset="remote") >> >> >> #### LOCAL RULES #### >> >> *.* /var/log/messages >> >> >> >> >> ########################################################################## >> >> DEBUG LOG >> >> ########################################################################## >> >> 2608.731281300:main Q:Reg/w0 : processBATCH: next msg 0: <166>1 >> 2015-03-05T16:23:28.729746+00:00 localci-hdf dev - - - test 4d >> 2608.731286050:main Q:Reg/w0 : ACTION 0 >> [builtin:omfile:/var/log/remote.log] >> 2608.731296440:main Q:Reg/w0 : executing action 0 >> 2608.731300781:main Q:Reg/w0 : Called action, logging to builtin:omfile >> 2608.731321713:main Q:Reg/w0 : action 0 is transactional - executing >> in commit phase >> 2608.731327093:main Q:Reg/w0 : wti 0x7f697aa7e200: we need to create >> a new action worker instance for action 0 >> 2608.731331936:main Q:Reg/w0 : Action 0 transitioned to state: itx >> 2608.731336015:main Q:Reg/w0 : ACTION 1 >> [builtin:omfwd:action(type="builtin:omfwd" ...)] >> 2608.731345835:main Q:Reg/w0 : executing action 1 >> 2608.731349861:main Q:Reg/w0 : Called action, logging to builtin:omfwd >> 2608.731373560:main Q:Reg/w0 : strm 0x7f697aa79d70: file >> -1(remotefwd) flush, buflen 575 >> 2608.731378696:main Q:Reg/w0 : strmPhysWrite, stream 0x7f697aa79d70, len >> 575 >> 2608.731440218:main Q:Reg/w0 : file >> '/var/lib/rsyslog/remotefwd.00000001' opened as #2 with mode 384 >> 2608.731447636:main Q:Reg/w0 : strm 0x7f697aa79d70: opened file >> '/var/lib/rsyslog/remotefwd.00000001' for WRITE as 2 >> 2608.731457063:main Q:Reg/w0 : strm 0x7f697aa79d70: file 2 write >> wrote 575 bytes >> 2608.731462184:main Q:Reg/w0 : remotefwd queue: write wrote 575 >> octets to disk, queue disk size now 575 octets, EnqOnly:0 >> 2608.731466581:main Q:Reg/w0 : remotefwd queue: qqueueAdd: entry >> added, size now log 1, phys 1 entries >> 2608.731471191:main Q:Reg/w0 : remotefwd queue:Reg: high activity - >> starting 1 additional worker thread(s). >> 2608.731525047:main Q:Reg/w0 : remotefwd queue:Reg: started with >> state 0, num workers now 1 >> 2608.731534075:main Q:Reg/w0 : remotefwd queue: EnqueueMsg advised worker >> start >> 2608.731540956:main Q:Reg/w0 : END batch execution phase, entering to >> commit phase >> 2608.731553966:main Q:Reg/w0 : actionCommitAll: action 0, state 1, >> nbr to commit 1 isTransactional 1 >> 2608.731567908:main Q:Reg/w0 : doTransaction: have commitTransaction >> IF, using that, pWrkrInfo 0x7f697aa7e2d0 >> 2608.731580406:main Q:Reg/w0 : entering >> actionCallCommitTransaction(), state: itx, actionNbr 0, nMsgs 1 >> 2608.731598707:7f69754f4700: thread created, tid 3379, name >> 'rs:remotefwd queue:Reg' >> 2608.731642781:remotefwd queue:Reg/w0: wti 0x7f697aa7d4f0: worker starting >> 2608.731656561:remotefwd queue:Reg/w0: DeleteProcessedBatch: we >> deleted 0 objects and enqueued 0 objects >> 2608.731669096:remotefwd queue:Reg/w0: doDeleteBatch: delete batch >> from store, new sizes: log 1, phys 1 >> 2608.731685925:main Q:Reg/w0 : file stream remote.log params: flush >> interval 0, async write 0 >> 2608.731711325:main Q:Reg/w0 : omfile: write to stream, pData->pStrm >> 0x7f6968003980, lenBuf 40, strt data Mar 5 16:23:28 localci-hdf dev >> test 4d >> 2608.731720487:main Q:Reg/w0 : strm 0x7f6968003980: file >> -1(remote.log) flush, buflen 40 >> 2608.731726623:main Q:Reg/w0 : strmPhysWrite, stream 0x7f6968003980, len >> 40 >> 2608.731743671:main Q:Reg/w0 : file '/var/log/remote.log' opened as >> #7 with mode 420 >> 2608.731756634:main Q:Reg/w0 : strm 0x7f6968003980: opened file >> '/var/log/remote.log' for WRITE as 7 >> 2608.731768282:main Q:Reg/w0 : strm 0x7f6968003980: file 7 write wrote 40 >> bytes >> 2608.731774441:main Q:Reg/w0 : Action 0 transitioned to state: rdy >> 2608.731781078:main Q:Reg/w0 : Action 0 transitioned to state: itx >> 2608.731786633:main Q:Reg/w0 : Action 0 transitioned to state: rdy >> 2608.731791771:main Q:Reg/w0 : actionCommit, in retry loop, iRet 0 >> 2608.731797654:main Q:Reg/w0 : actionCommitAll: action 2, state 0, >> nbr to commit 0 isTransactional 1 >> 2608.731807120:main Q:Reg/w0 : processBATCH: batch of 1 elements has >> been processed >> 2608.731812961:main Q:Reg/w0 : regular consumer finished, iret=0, >> szlog 0 sz phys 1 >> 2608.731820159:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 1 >> objects and enqueued 0 objects >> 2608.731825717:main Q:Reg/w0 : doDeleteBatch: delete batch from >> store, new sizes: log 0, phys 0 >> 2608.731831642:main Q:Reg/w0 : regular consumer finished, iret=4, >> szlog 0 sz phys 0 >> 2608.731837955:main Q:Reg/w0 : main Q:Reg/w0: worker IDLE, waiting for >> work. >> 2608.731967228:remotefwd queue:Reg/w0: file >> '/var/lib/rsyslog/remotefwd.00000001' opened as #6 with mode 384 >> 2608.731981761:remotefwd queue:Reg/w0: strm 0x7f697aa7aff0: opened >> file '/var/lib/rsyslog/remotefwd.00000001' for READ as 6 >> 2608.731989606:remotefwd queue:Reg/w0: strm 0x7f697aa7aff0: file 6 >> read 575 bytes >> 2608.732006243:remotefwd queue:Reg/w0: remotefwd queue: error -2308 >> dequeueing element - ignoring, but strange things may happen >> 2608.732011036:remotefwd queue:Reg/w0: regular consumer finished, >> iret=-2308, szlog 0 sz phys 1 >> 2608.732015422:remotefwd queue:Reg/w0: DeleteProcessedBatch: we >> deleted 0 objects and enqueued 0 objects >> 2608.732019638:remotefwd queue:Reg/w0: doDeleteBatch: delete batch >> from store, new sizes: log 0, phys 1 >> 2608.732024016:remotefwd queue:Reg/w0: regular consumer finished, >> iret=4, szlog 0 sz phys 1 >> 2608.732028228:remotefwd queue:Reg/w0: remotefwd queue:Reg/w0: worker >> IDLE, waiting for work. >> >> >> Thanks, >> Andrew >> _______________________________________________ >> 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. > > > _______________________________________________ > 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.
By corrupt I mean the log never leaves the queue. The text of the log message that corresponds to the debug log I included is "test 4d". The debug log shows this error message towards the bottom: 2608.732006243:remotefwd queue:Reg/w0: remotefwd queue: error -2308 dequeueing element - ignoring, but strange things may happen Something bad is happening when the message is read from the queue. Thanks, Andrew _______________________________________________ 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.
