[logback-user] syslogappender stacktraces get cut
Ingebrigt Berg
ingebrigt at jpro.no
Fri Apr 13 12:17:10 CEST 2012
I've committed some further changes as per your comment, was able to figure
it out.
Den 15:22 12. april 2012 skrev ceki <ceki at qos.ch> følgende:
>
> FYI, I just commented on https://github.com/ceki/**logback/pull/42<https://github.com/ceki/logback/pull/42>
>
>
>
> On 12.04.2012 15:20, Ingebrigt Berg wrote:
>
>> Done.
>>
>> Credit where credit is due, it was actually my coworker Marius Eikenes
>> that proposed this way of fixing the problem.
>> Thanx for looking into this, it's much appreciated.
>>
>> cheers,
>> Ingebrigt
>>
>> Den 09:08 12. april 2012 skrev ceki <ceki at qos.ch <mailto:ceki at qos.ch>>
>>
>> følgende:
>>
>> Hi Ingebrigt,
>>
>> Are you familiar with git/github? In short, you would fork logback
>> on github, make your changes and then send me a pull request.
>> Posting a diff file with your changes would be OK as well.
>>
>> BTW, I quite like your idea of a separate pattern for the stack trace.
>>
>> Best regards,
>> --
>> Ceki
>> http://twitter.com/#!/ceki <http://twitter.com/#%21/ceki>
>>
>>
>>
>>
>> On 11.04.2012 16:57, Ingebrigt Berg wrote:
>>
>> Hi again.
>>
>> As suggested I've implemented a POC on how SyslogAppender could be
>> fixed, and have got it working. It resolves our issue. With the
>> changes
>> I made, the stacktrace lines can be prefixed as required, and
>> with the
>> proper configuration they now end up in the correct file on our
>> logserver.
>>
>> My configuration now looks like this:
>>
>> <contextName>xxx-${CONTEXT___**PATH}-${environment}</__**
>> contextName>
>> <appender name="LOGSERVER_FILE"
>> class="no.xxx.logback.__**SyslogAppender">
>> <contextName>xxx-${CONTEXT___**PATH}-${environment}</__**
>> contextName>
>> <syslogHost>localhost</__**syslogHost>
>>
>> <facility>local3</facility>
>> <SuffixPattern>%contextName %d{dd.MM.yyyy HH:mm:ss.SSS} [%p]
>> [%c{1}]
>> [%X{ThreadId}]: %m%n</SuffixPattern>
>> <StackTraceSuffixPattern>xxx-$**__{CONTEXT_PATH}-${**environment}
>> -
>>
>> </StackTraceSuffixPattern>
>> </appender>
>>
>> ( Notice the new property <StackTraceSuffixPattern> )
>>
>> All I had to change in the code (in SyslogAppender.java) was to
>> implement a new member variable stackTraceSuffixPattern (plus
>> getter/setter) and to append it in line 89 (after the prefix and
>> before
>> the tab).
>>
>> In actual code I imagine you'd also want to add:
>> -a null test, to make the new parameter optional
>> -the new property should be subjected to pattern convertion
>> (this was
>> not required for my POC to work, but would be nice/expected)
>>
>> If someone would work with me and get this fix into logback
>> proper it
>> would be much appreciated. I can send/post working code. For how
>> to best
>> activate pattern conversion for the new property I would hope to
>> get
>> some help/guidance.
>>
>> cheers,
>> Ingebrigt Berg
>>
>>
>> Den 14:48 30. mars 2012 skrev Ingebrigt Berg <ingebrigt at jpro.no
>> <mailto:ingebrigt at jpro.no>
>> <mailto:ingebrigt at jpro.no <mailto:ingebrigt at jpro.no>>> følgende:
>>
>>
>>
>> Hi !
>>
>> We have looked more into this issue.
>>
>> From a TCPdump for the traffic between the app (using
>> logback) and
>> the syslog-server we learn that each line in the stacktrace is
>> actually sent as a separate message to syslog (sensitive info
>> replaced with xx/yy/zz):
>>
>> 11:28:37.911604 IP xx
>> localhost.localdomain.55934 >
>> localhost.localdomain.syslog:
>> [bad udp cksum af4f!] SYSLOG, length: 101
>> Facility local3 (19), Severity error (3)
>> Msg: Mar 30 11:28:37 yy2-31 zz-mce-test 30.03.2012
>> 11:28:37.910 [ERROR] [LogbackTester] []: Fjas\0x0a
>> 11:28:37.912028 IP xx
>> localhost.localdomain.55934 >
>> localhost.localdomain.syslog:
>> [bad udp cksum 6076!] SYSLOG, length: 104
>> Facility local3 (19), Severity error (3)
>> Msg: Mar 30 11:28:37 yy2-31 \0x09at
>>
>> sun.reflect.__**NativeConstructorAccessorImpl.**__newInstance0(Native
>> Method)
>>
>>
>> The first packet is a regular log statement, the second one is
>> a
>> line in a stack trace.
>>
>> Notice how
>> 'zz-mce-test 30.03.2012 11:28:37.910 [ERROR] [LogbackTester] []:'
>> is replaced with:
>> '\0x09at'
>>
>> If we interpret this correctly, SyslogAppender will log the
>> error
>> message and each StackTraceElement separately. But for the
>> StackTraceElements it will ignore what we configure in the
>> <SuffixPattern> property:
>> ( <SuffixPattern>%contextName %d{dd.MM.yyyy HH:mm:ss.SSS} [%p]
>> [%c{1}] [%X{ThreadId}]: %m%n</SuffixPattern> )
>> Instead the stackline messages simply get a '\0x09at' (a TAB)
>> appended in place of the SuffixPattern.
>>
>> This happens in line 89 in ch.qos.logback.classic.net
>> <http://ch.qos.logback.**classic.net<http://ch.qos.logback.classic.net>
>> >.__SyslogAppender:
>> sb.append(prefix).append(__**CoreConstants.TAB).append(__**
>> step);
>>
>>
>> Contrast that to line 59 in
>> ch.qos.logback.classic.net
>> <http://ch.qos.logback.**classic.net<http://ch.qos.logback.classic.net>>.__SyslogAppender
>> (normal
>>
>> messages), where
>> the SuffixPattern gets added:
>> fullLayout.setPattern(__**prefixPattern + suffixPattern);
>>
>>
>> We see two viable solutions:
>>
>> EITHER:
>> when a message is split into a main message and
>> StackTraceElements,
>> the StackTraceElement messages must also get the content of the
>> <SuffixPattern> appended
>>
>> OR:
>> an optional property <StackTraceSuffixPattern> could be added
>> to
>> SyslogAppender, allowing control of what goes into
>> StackTraceElement
>> messages.
>>
>> cheers,
>> Ingebrigt Berg + Marius Eikenes
>>
>>
>> Den 11:40 20. mars 2012 skrev Ingebrigt Berg
>> <ingebrigt at jpro.no <mailto:ingebrigt at jpro.no>
>> <mailto:ingebrigt at jpro.no <mailto:ingebrigt at jpro.no>>> følgende:
>>
>>
>>
>> Hi !
>>
>> We've recently made the switch from Log4j to Logback. We
>> use
>> Syslog to send logfiles to our logserver, and things
>> generally work.
>>
>> But when there are stacktraces in the logs we get in
>> trouble.
>> SyslogAppender will replace lineshifts with '#011' to
>> make the
>> logentry a single line. Then it will cut each line that
>> is to
>> long according to the syslog limit of 2K/line. Only the
>> fist
>> segment will arrive in the correct log. The remaining
>> segments
>> are not prefixed with everything in the suffixPattern,
>> and our
>> regexp will not have anything to match. The segment will
>> end up
>> in a 'trash' log for unmatchable loglines.
>>
>> My config for the SyslogAppender looks like this:
>>
>> <contextName>company-${__**CONTEXT_PATH}-${environment}</**
>> __contextName>
>> <appender name="LOGSERVER_FILE"
>> class="ch.qos.logback.classic.**__net.SyslogAppender">
>> <syslogHost>localhost</__**syslogHost>
>>
>> <facility>local3</facility>
>> <SuffixPattern>%contextName %d{dd.MM.yyyy HH:mm:ss.SSS} [%p]
>> [%c{1}] [%X{ThreadId}]: %m%n</SuffixPattern>
>> </appender>
>>
>> We use the contextName property to control the
>> logfilename. On
>> the receiving end we read the contextName parameter (using
>> a
>> regexp) for each log line, and write the line to a file
>> with a
>> corresponding name.
>>
>> We had a similar problem when we used Log4J (Where the Tag
>> element was used in the same manner), and fixed it back
>> then by
>> writing a custom log4j SyslogAppender. But the main
>> purpose of
>> moving to Logback is to loose all our home brew logging
>> stuff,
>> we don't want to go down that path again. If we can't make
>> Logback work out of the box with Syslog we'll probably
>> end up
>> going back to Log4J. (Another alternative is to replace
>> Syslog
>> with Gelf, but that's further down the road).
>>
>> However, I imagine Logback and Syslog being a common
>> combination, and surely someone must have this working
>> out of
>> the box. Any advice will be appreciated. My requirements
>> are simple:
>> -must work with no custom logging code, only config
>> (preferably xml)
>> -stacktraces in logs must work
>> -must be able to fully control the filename on the
>> recieving end.
>>
>> cheers,
>> Ingebrigt Berg
>>
>>
>
>
> --
> Ceki
> http://twitter.com/#!/ceki
>
> ______________________________**_________________
> Logback-user mailing list
> Logback-user at qos.ch
> http://mailman.qos.ch/mailman/**listinfo/logback-user<http://mailman.qos.ch/mailman/listinfo/logback-user>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.qos.ch/pipermail/logback-user/attachments/20120413/770b300f/attachment.html>
More information about the Logback-user
mailing list