On Thu, Jun 20, 2013 at 11:53 AM, David Lang <[email protected]> wrote: > The messages you are showing below appear to all be related with parsing > the message. This is the step after the receiving of the message, which is > where the frame delimiter comes into play. > > Is this something that happens erratically, or is this something that you > can reproduce at will? >
Yes, there is one particular sender that's causing these issues and I can reproduce at will. It is an Arcsight collector that's sending logs in "syslog" format (supposedly). I have confirmed that the messages aren't actually in BSD Syslog format but then worse is that it is sending this garbage. But I want to build my syslog infrastructure to not assume that apps will send it good/clean streams of syslog so it may not process/parse the messages but it shouldn't crash when bad data is sent. > > what are you using for the frame delimiter? > I did not set anything explicitly so rsyslog was set to default frame delimiter. I have upgraded to 7.4.1 but not before I had the errant sender shutdown. I will re-point that sender to a test rsyslog instance and try to reproduce the crash. Might be a few days though because the guy who controls that Arcsight collector is OOO. Thanks :) > > David Lang > > > > > On Thu, 20 Jun 2013, Xuri Nagarin wrote: > > Reading through older threads I realize that if an application uses a >> non-standard frame delimiter then Rsyslog will have issues parsing the >> message but I am running 7.4.0 and bad delimiters are causing rsyslog to >> crash. >> >> rsyslogd -v >> rsyslogd 7.4.0, compiled with: >> FEATURE_REGEXP: Yes >> FEATURE_LARGEFILE: No >> GSSAPI Kerberos 5 support: Yes >> FEATURE_DEBUG (debug build, slow code): No >> 32bit Atomic operations supported: Yes >> 64bit Atomic operations supported: Yes >> Runtime Instrumentation (slow code): No >> uuid support: Yes >> >> >> I don't think a crash is the expected behaviour if the input is bad. >> Right? >> >> Here's the snippet from debug log just before crash. Oddly, I don't see a >> coredump or error causing the crash. >> >> 2367.362924601:7f4981e46700: parse using parser list 0x7f4987d93ed0 (the >> default list). >> 2367.362927457:7f4981e46700: Parser 'rsyslog.rfc5424' returned -2160 >> 2367.362930309:7f4981e46700: Message will now be parsed by the legacy >> syslog parser (one size fits all... ;)). >> 2367.362932512:7f4981e46700: Parser 'rsyslog.rfc3164' returned 0 >> 2367.362934756:7f4981e46700: msg parser: flags 30, from '192.168.1.100', >> msg '06/20/13,10:47:32,DNS Update Suc' >> 2367.362936776:7f4981e46700: parse using parser list 0x7f4987d93ed0 (the >> default list). >> 2367.362938676:7f4981e46700: Parser 'rsyslog.rfc5424' returned -2160 >> 2367.362940448:7f4981e46700: Message will now be parsed by the legacy >> syslog parser (one size fits all... ;)). >> 2367.362943712:7f4981e46700: Parser 'rsyslog.rfc3164' returned 0 >> 2367.362945989:7f4981e46700: msg parser: flags 30, from '192.1.35.77', msg >> 'cessful,192.1.236.14,**mydesktop.internal >> .acme.com,,^M' >> 2367.362948017:7f4981e46700: parse using parser list 0x7f4987d93ed0 (the >> default list). >> 2367.362950143:7f4981e46700: Parser 'rsyslog.rfc5424' returned -2160 >> 2367.362957428:7f4981e46700: Message will now be parsed by the legacy >> syslog parser (one size fits all... ;)). >> 2367.362960059:7f4981e46700: Parser 'rsyslog.rfc3164' returned 0 >> 2367.362962370:7f4981e46700: processBatch: batch of 32 elements must be >> processed >> 2367.362969230:7f4981e46700: processBatch: batch of 31 elements must be >> processed >> 2367.362971685:7f4981e46700: scriptExec: batch of 31 elements, active >> (nil), active[0]:1 >> 2367.362973524:7f4981e46700: SET $!vendor = >> 2367.362979077:7f4981e46700: function 'field' (id:9, params:3) >> 2367.362987082:7f4981e46700: var '$msg' >> 2367.362995144:7f4981e46700: 124 >> 2367.363002241:7f4981e46700: 2 >> 2367.363010228:7f4981e46700: END SET >> 2367.363015200:7f4981e46700: eval expr 0x7f4987da4770, type 'F[70]' >> 2367.363018158:7f4981e46700: rainerscript: executing function id 9 >> 2367.363020318:7f4981e46700: eval expr 0x7f4987da4870, type 'V[86]' >> 2367.363022988:7f4981e46700: rainerscript: var '$msg': >> '58:55,Renew,192.168.24.114,,**A46706750769,#015' >> 2367.363025227:7f4981e46700: eval expr 0x7f4987da4810, type 'N[78]' >> 2367.363028220:7f4981e46700: eval expr 0x7f4987da4cc0, type 'N[78]' >> 2367.363030789:7f4981e46700: field() field requested 2, field found 1 >> 2367.363034649:7f4981e46700: eval expr 0x7f4987da4770, type 'F[70]' >> 2367.363036629:7f4981e46700: rainerscript: executing function id 9 >> 2367.363038628:7f4981e46700: eval expr 0x7f4987da4870, type 'V[86]' >> 2367.363042128:7f4981e46700: rainerscript: var '$msg': '58:56,DNS Update >> R' >> 2367.363044246:7f4981e46700: eval expr 0x7f4987da4810, type 'N[78]' >> 2367.363046355:7f4981e46700: eval expr 0x7f4987da4cc0, type 'N[78]' >> 2367.363048399:7f4981e46700: field() field requested 2, field found 1 >> 2367.363052521:7f4981e46700: eval expr 0x7f4987da4770, type 'F[70]' >> 2367.363054698:7f4981e46700: rainerscript: executing function id 9 >> 2367.363056733:7f4981e46700: eval expr 0x7f4987da4870, type 'V[86]' >> 2367.363059297:7f4981e46700: rainerscript: var '$msg': '' >> 2367.363061436:7f4981e46700: eval expr 0x7f4987da4810, type 'N[78]' >> 2367.363064501:7f4981e46700: eval expr 0x7f4987da4cc0, type 'N[78]' >> 2367.363066812:7f4981e46700: field() field requested 2, field found 1 >> 2367.363070008:7f4981e46700: eval expr 0x7f4987da4770, type 'F[70]' >> 2367.363071969:7f4981e46700: rainerscript: executing function id 9 >> 2367.363073964:7f4981e46700: eval expr 0x7f4987da4870, type 'V[86]' >> 2367.363076230:7f4981e46700: rainerscript: var '$msg': '' >> 2367.363079524:7f4981e46700: eval expr 0x7f4987da4810, type 'N[78]' >> 2367.363081625:7f4981e46700: eval expr 0x7f4987da4cc0, type 'N[78]' >> 2367.363083776:7f4981e46700: field() field requested 2, field found 1 >> 2367.363086818:7f4981e46700: eval expr 0x7f4987da4770, type 'F[70]' >> 2367.363088738:7f4981e46700: rainerscript: executing function id 9 >> 2367.363091847:7f4981e46700: eval expr 0x7f4987da4870, type 'V[86]' >> 2367.363094538:7f4981e46700: rainerscript: var '$msg': >> '58:56,Renew,192.168.1.5,xxx00**152B2xxxxx.internal.acme.com<http://xxx00152B2xxxxx.internal.acme.com> >> ,00152B2xxxxx,#015' >> 2367.363096786:7f4981e46700: eval expr 0x7f4987da4810, type 'N[78]' >> 2367.363098757:7f4981e46700: eval expr 0x7f4987da4cc0, type 'N[78]' >> 2367.363100873:7f4981e46700: field() field requested 2, field found 1 >> 2367.363105195:7f4981e46700: eval expr 0x7f4987da4770, type 'F[70]' >> 2367.363107179:7f4981e46700: rainerscript: executing function id 9 >> 2367.363109144:7f4981e46700: eval expr 0x7f4987da4870, type 'V[86]' >> 2367.363111404:7f4981e46700: rainerscript: var '$msg': '58:56,DNS Update >> Suc' >> 2367.363114652:7f4981e46700: eval expr 0x7f4987da4810, type 'N[78]' >> 2367.363116788:7f4981e46700: eval expr 0x7f4987da4cc0, type 'N[78]' >> 2367.363118820:7f4981e46700: field() field requested 2, field found 1 >> 2367.363121742:7f4981e46700: eval expr 0x7f4987da4770, type 'F[70]' >> 2367.363124771:7f4981e46700: rainerscript: executing function id 9 >> 2367.363126849:7f4981e46700: eval expr 0x7f4987da4870, type 'V[86]' >> 2367.363129227:7f4981e46700: rainerscript: var '$msg': '' >> 2367.363131414:7f4981e46700: eval expr 0x7f4987da4810, type 'N[78]' >> 2367.363133378:7f4981e46700: eval expr 0x7f4987da4cc0, type 'N[78]' >> 2367.363141411:7f4981e46700: field() field requested 2, field found 1 >> 2367.363144986:7f4981e46700: eval expr 0x7f4987da4770, type 'F[70]' >> 2367.363147022:7f4981e46700: rainerscript: executing function id 9 >> 2367.363148985:7f4981e46700: eval expr 0x7f4987da4870, type 'V[86]' >> 2367.363152448:7f4981e46700: rainerscript: var '$msg': '47:28,DNS Update >> R' >> 2367.363154621:7f4981e46700: eval expr 0x7f4987da4810, type 'N[78]' >> 2367.363156703:7f4981e46700: eval expr 0x7f4987da4cc0, type 'N[78]' >> 2367.363158679:7f4981e46700: field() field requested 2, field found 1 >> 2367.363161735:7f4981e46700: eval expr 0x7f4987da4770, type 'F[70]' >> 2367.363164816:7f4981e46700: rainerscript: executing function id 9 >> 2367.363166929:7f4981e46700: eval expr 0x7f4987da4870, type 'V[86]' >> 2367.363169277:7f4981e46700: rainerscript: var '$msg': '' >> 2367.363171380:7f4981e46700: eval expr 0x7f4987da4810, type 'N[78]' >> 2367.363173383:7f4981e46700: eval expr 0x7f4987da4cc0, type 'N[78]' >> 2367.363176540:7f4981e46700: field() field requested 2, field found 1 >> 2367.363179769:7f4981e46700: eval expr 0x7f4987da4770, type 'F[70]' >> 2367.363181745:7f4981e46700: rainerscript: executing function id 9 >> 2367.363183836:7f4981e46700: eval expr 0x7f4987da4870, type 'V[86]' >> >> >> TIA >> ______________________________**_________________ >> rsyslog mailing list >> http://lists.adiscon.net/**mailman/listinfo/rsyslog<http://lists.adiscon.net/mailman/listinfo/rsyslog> >> http://www.rsyslog.com/**professional-services/<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://lists.adiscon.net/mailman/listinfo/rsyslog> > http://www.rsyslog.com/**professional-services/<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.
