On Thu, Jun 20, 2013 at 11:36 PM, Xuri Nagarin <[email protected]> wrote:
> 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. > > could you provide me a sample of such a malformed message as seen on the wire? That would definitely help me troubleshoot this issue. You can mail me privately if that's better for you. Rainer > > > > > 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. > _______________________________________________ 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.
