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@qos.ch <mailto:ceki@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@jpro.no
<mailto:
ingebrigt@jpro.no>
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>.__SyslogAppender:
sb.append(prefix).append(__CoreConstants.TAB).append(__step);
<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@jpro.no <mailto:
ingebrigt@jpro.no>
<mailto:ingebrigt@jpro.no <mailto:ingebrigt@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