On Fri, 11 Apr 2014, Steve Dainard wrote:
That's quite a bit of debugging info.
I was mostly meaning for you to look for errors at startup, try doing grep ERROR on the output and see what happens at startup before any logs are processed (looking for config parsign errors)
It looks like there is a difference in how rsyslog determines what is a message field (properly formatted in my logs):
Ok, the way to see what's happening with the parsing is to log the messages with the format RSYSLOG_DebugFormat
that will show you the raw log that rsyslog received and the way it filled out the other variables.
If you can post some samples from the debugformat output it would probably help a lot.
David Lang
3285.432866644:7f92d75fe700: main Q: entry added, size now log 114, phys 114 entries 3285.432893131:7f92d75fe700: main Q: MultiEnqObj advised worker start 3285.432930232:7f92ddab0700: wti 0x7f92e1b80910: worker awoke from idle processing 3285.432953400:7f92ddab0700: we deleted 0 objects and enqueued 0 objects 3285.432969305:7f92ddab0700: delete batch from store, new sizes: log 114, phys 114 3285.432984921:7f92ddab0700: msg parser: flags 30, from '10.0.250.4', msg '<191>: Contact: <sip:[email protected]:5060;transport=tcp' 3285.432991518:7f92ddab0700: parse using parser list 0x7f92e1b56460 (the default list). 3285.432999864:7f92ddab0700: Parser 'rsyslog.rfc5424' returned -2160 3285.433006130:7f92ddab0700: Message will now be parsed by the legacy syslog parser (one size fits all... ;)). 3285.433013052:7f92ddab0700: MsgSetTAG in: len 1, pszBuf: : 3285.433017613:7f92ddab0700: MsgSetTAG exit: pMsg->iLenTAG 1, pMsg->TAG.szBuf: : 3285.433022380:7f92ddab0700: Parser 'rsyslog.rfc3164' returned 0 '285.433027720:7f92ddab0700: msg parser: flags 30, from '10.0.250.4', msg '<191>: Max-Forwards: 70 3285.433032352:7f92ddab0700: parse using parser list 0x7f92e1b56460 (the default list). 3285.433037262:7f92ddab0700: Parser 'rsyslog.rfc5424' returned -2160 3285.433053992:7f92ddab0700: Message will now be parsed by the legacy syslog parser (one size fits all... ;)). 3285.433059286:7f92ddab0700: MsgSetTAG in: len 1, pszBuf: : 3285.433064148:7f92ddab0700: MsgSetTAG exit: pMsg->iLenTAG 1, pMsg->TAG.szBuf: : 3285.433068913:7f92ddab0700: Parser 'rsyslog.rfc3164' returned 0 '285.433074186:7f92ddab0700: msg parser: flags 30, from '10.0.250.4', msg '<191>: Content-Length: 0 3285.433078962:7f92ddab0700: parse using parser list 0x7f92e1b56460 (the default list). 3285.433083934:7f92ddab0700: Parser 'rsyslog.rfc5424' returned -2160 3285.433088123:7f92ddab0700: Message will now be parsed by the legacy syslog parser (one size fits all... ;)). 3285.433093132:7f92ddab0700: MsgSetTAG in: len 1, pszBuf: : 3285.433097685:7f92ddab0700: MsgSetTAG exit: pMsg->iLenTAG 1, pMsg->TAG.szBuf: : 3285.433113976:7f92ddab0700: Parser 'rsyslog.rfc3164' returned 0 '285.433118723:7f92ddab0700: msg parser: flags 30, from '10.0.250.4', msg '<191>: 3285.433123197:7f92ddab0700: parse using parser list 0x7f92e1b56460 (the default list). 3285.433128085:7f92ddab0700: Parser 'rsyslog.rfc5424' returned -2160 3285.433132516:7f92ddab0700: Message will now be parsed by the legacy syslog parser (one size fits all... ;)). 3285.433137277:7f92ddab0700: MsgSetTAG in: len 1, pszBuf: : 3285.433141410:7f92ddab0700: MsgSetTAG exit: pMsg->iLenTAG 1, pMsg->TAG.szBuf: : 3285.433146150:7f92ddab0700: Parser 'rsyslog.rfc3164' returned 0 and what it doesn't determine is a msg field (which is being prefixed with date/timestamp/hostname in my logs): 4073.163607734:7f92ddab0700: prop repl 4, pRes=' //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:', len 43 4073.163614171:7f92ddab0700: end prop repl, pRes=' //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:', len 43 4073.163623787:7f92ddab0700: prop repl 4, pRes='10.0.250.4', len 10 4073.163628552:7f92ddab0700: end prop repl, pRes='10.0.250.4', len 10 4073.163633195:7f92ddab0700: prop repl 4, pRes=' Received: ', len 11 4073.163637734:7f92ddab0700: end prop repl, pRes=' Received: ', len 11 4073.163642553:7f92ddab0700: prop repl 4, pRes='10.0.250.4', len 10 4073.163647020:7f92ddab0700: end prop repl, pRes='10.0.250.4', len 10 4073.163651759:7f92ddab0700: prop repl 4, pRes=' ACK sip:[email protected]:5060 SIP/2.0#015', len 47 4073.163663774:7f92ddab0700: end prop repl, pRes=' ACK sip:[email protected]:5060 SIP/2.0#015', len 47 4073.163672584:7f92ddab0700: prop repl 4, pRes='10.0.250.4', len 10 4073.163677163:7f92ddab0700: end prop repl, pRes='10.0.250.4', len 10 4073.163681806:7f92ddab0700: prop repl 4, pRes=' Via: SIP/2.0/TCP 10.0.6.30:5060;branch=z9hG4bK372601ec29d47#015', len 64 4073.163686546:7f92ddab0700: end prop repl, pRes=' Via: SIP/2.0/TCP 10.0.6.30:5060;branch=z9hG4bK372601ec29d47#015', len 64 4073.163691408:7f92ddab0700: prop repl 4, pRes='10.0.250.4', len 10 4073.163695796:7f92ddab0700: end prop repl, pRes='10.0.250.4', len 10 4073.163700475:7f92ddab0700: prop repl 4, pRes=' From: "User Name" < sip:[email protected]>;tag=319430~d732e07f-799a-4d2b-9d6a-ae2aaf54507d-19889579#015', len 110 4073.163705413:7f92ddab0700: end prop repl, pRes=' From: "User Name" < sip:[email protected]>;tag=319430~d732e07f-799a-4d2b-9d6a-ae2aaf54507d-19889579#015', len 110 Needless to say, I'm not really sure what this is telling me. *Steve * On Fri, Apr 11, 2014 at 3:00 PM, David Lang <[email protected]> wrote:try starting rsyslog with -dn to see the startup debug messages. I'll bet that there's something that it's not happy with in the config syntax and that's casusing something to fail one note, you don't need the - everything in rsyslog is async unless you go to a lot of trouble to force it otherwise. David Lang On Fri, 11 Apr 2014, Steve Dainard wrote: Date: Fri, 11 Apr 2014 14:31:47 -0400From: Steve Dainard <[email protected]> Reply-To: rsyslog-users <[email protected]> To: [email protected] Subject: [rsyslog] Logging 'msg' only Hello list, I have a couple cisco routers sending sip message debug information to an rsyslog server running on Centos 6.5. I've setup the following template to separate out the logging files: $template DynaFile,"/var/log/%HOSTNAME%.log" *.* -?DynaFile $template MsgFormat,"%msg%\n" if $fromhost-ip == '10.0.250.4' then -?DynaFile;MsgFormat if $fromhost-ip == '10.1.1.6' then -?DynaFile;MsgFormat With these templates the output from the router is formatted as such (note date/timestamp/hostname): Apr 11 14:17:28 10.0.250.4 : //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Apr 11 14:17:28 10.0.250.4 : Received: Apr 11 14:17:28 10.0.250.4 : INVITE sip:[email protected]:5060 SIP/2.0#015 Apr 11 14:17:28 10.0.250.4 : Via: SIP/2.0/TCP 10.0.6.30:5060 ;branch=z9hG4bK371ba1ab73caa#015 Apr 11 14:17:28 10.0.250.4 : From: "User Name" <sip:[email protected];tag=319318~d732e07f-799a-4d2b-9d6a-ae2aaf54507d-19889474#015Apr 11 14:17:28 10.0.250.4 : To: <sip:[email protected]>#015 Apr 11 14:17:28 10.0.250.4 : Date: Fri, 11 Apr 2014 18:18:12 GMT#015 Apr 11 14:17:28 10.0.250.4 : Call-ID: [email protected]#015 Apr 11 14:17:28 10.0.250.4 : Supported: timer,resource-priority, replaces#015 Apr 11 14:17:28 10.0.250.4 : Min-SE: 1800#015 Apr 11 14:17:28 10.0.250.4 : User-Agent: Cisco-CUCM9.1#015 Apr 11 14:17:28 10.0.250.4 : Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY#015 Apr 11 14:17:28 10.0.250.4 : CSeq: 101 INVITE#015 Apr 11 14:17:28 10.0.250.4 : Expires: 180#015 Apr 11 14:17:28 10.0.250.4 : Allow-Events: presence#015 Apr 11 14:17:28 10.0.250.4 : Supported: X-cisco-srtp-fallback,X-cisco-original-called#015 Apr 11 14:17:28 10.0.250.4 : Cisco-Guid: 2734542720-0000065536-0000042552-0503709706#015 Apr 11 14:17:28 10.0.250.4 : Session-Expires: 1800#015 Apr 11 14:17:28 10.0.250.4 : P-Asserted-Identity: "User Name" < sip:[email protected]>#015 Apr 11 14:17:28 10.0.250.4 : Remote-Party-ID: "User Name" < sip:[email protected]>;party=calling;screen=yes;privacy=off#015 Received: INVITE sip:[email protected]:5060 SIP/2.0#015 Via: SIP/2.0/TCP 10.0.6.30:5060;branch=z9hG4bK371ba1ab73caa#015 From: "User Name" <sip:[email protected];tag=319318~d732e07f-799a-4d2b-9d6a-ae2aaf54507d-19889474#015To: <sip:[email protected]>#015 Date: Fri, 11 Apr 2014 18:18:12 GMT#015 Call-ID: [email protected]#015 Supported: timer,resource-priority,replaces#015 Min-SE: 1800#015 User-Agent: Cisco-CUCM9.1#015 Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY#015 CSeq: 101 INVITE#015 Expires: 180#015 Allow-Events: presence#015 Supported: X-cisco-srtp-fallback,X-cisco-original-called#015 Cisco-Guid: 2734542720-0000065536-0000042552-0503709706#015 Session-Expires: 1800#015 P-Asserted-Identity: "User Name" <sip:[email protected]>#015 Remote-Party-ID: "User Name" <sip:[email protected];party=calling;screen=yes;privacy=off#015Apr 11 14:17:28 10.0.250.4 : Contact: <sip:[email protected]:5060 ;transport=tcp>#015 Apr 11 14:17:28 10.0.250.4 : Max-Forwards: 70#015 Apr 11 14:17:28 10.0.250.4 : Content-Length: 0#015 Apr 11 14:17:28 10.0.250.4 : #015 Apr 11 14:17:28 10.0.250.4 : //6161/A2FDCF800000/SIP/Msg/ccsipDisplayMsg: And I want it to look like this (no date/timestamp/hostname): //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Received: INVITE sip:[email protected]:5060 SIP/2.0#015 Via: SIP/2.0/TCP 10.0.6.30:5060;branch=z9hG4bK371ba1ab73caa#015 From: "User Name" <sip:[email protected];tag=319318~d732e07f-799a-4d2b-9d6a-ae2aaf54507d-19889474#015To: <sip:[email protected]>#015 Date: Fri, 11 Apr 2014 18:18:12 GMT#015 Call-ID: [email protected]#015 Supported: timer,resource-priority,replaces#015 Min-SE: 1800#015 User-Agent: Cisco-CUCM9.1#015 Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY#015 CSeq: 101 INVITE#015 Expires: 180#015 Allow-Events: presence#015 Supported: X-cisco-srtp-fallback,X-cisco-original-called#015 Cisco-Guid: 2734542720-0000065536-0000042552-0503709706#015 Session-Expires: 1800#015 P-Asserted-Identity: "User Name" <sip:[email protected]>#015 Remote-Party-ID: "User Name" <sip:[email protected];party=calling;screen=yes;privacy=off#015Received: INVITE sip:[email protected]:5060 SIP/2.0#015 Via: SIP/2.0/TCP 10.0.6.30:5060;branch=z9hG4bK371ba1ab73caa#015 From: "User Name" <sip:[email protected];tag=319318~d732e07f-799a-4d2b-9d6a-ae2aaf54507d-19889474#015To: <sip:[email protected]>#015 Date: Fri, 11 Apr 2014 18:18:12 GMT#015 Call-ID: [email protected]#015 Supported: timer,resource-priority,replaces#015 Min-SE: 1800#015 User-Agent: Cisco-CUCM9.1#015 Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY#015 CSeq: 101 INVITE#015 Expires: 180#015 Allow-Events: presence#015 Supported: X-cisco-srtp-fallback,X-cisco-original-called#015 Cisco-Guid: 2734542720-0000065536-0000042552-0503709706#015 Session-Expires: 1800#015 P-Asserted-Identity: "User Name" <sip:[email protected]>#015 Remote-Party-ID: "User Name" <sip:[email protected];party=calling;screen=yes;privacy=off#015Contact: <sip:[email protected]:5060;transport=tcp>#015 Max-Forwards: 70#015 Content-Length: 0#015 #015 //6161/A2FDCF800000/SIP/Msg/ccsipDisplayMsg: From what I've read $template MsgFormat,"%msg%\n" should work, so I'm a bit confused. If I comment out #$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat the formatting is: 2014-04-11T14:25:20.296816-04:00 10.0.250.4 : a=rtpmap:0 PCMU/8000#015 2014-04-11T14:25:20.296816-04:00 10.0.250.4 : a=ptime:20#015 2014-04-11T14:25:20.296816-04:00 10.0.250.4 : a=rtpmap:101 telephone-event/8000#015 2014-04-11T14:25:20.296816-04:00 10.0.250.4 : a=fmtp:101 0-15#015 So its definitely rsyslog formatting, not the client side. Any help is appreciated, thanks. *Steve* _______________________________________________ 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._______________________________________________ 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.
