Re: [logback-user] syslogappender stacktraces get cut
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.SyslogAppender: sb.append(prefix).append(CoreConstants.TAB).append(step); Contrast that to line 59 in 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> 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
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> 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.SyslogAppender: sb.append(prefix).append(CoreConstants.TAB).append(step);
Contrast that to line 59 in 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> 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
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 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>> 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.SyslogAppender: sb.append(prefix).append(CoreConstants.TAB).append(step);
Contrast that to line 59 in 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>> 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
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> 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
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>> 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.** SyslogAppender: sb.append(prefix).append(**CoreConstants.TAB).append(**step);
Contrast that to line 59 in 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>> 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
______________________________**_________________ Logback-user mailing list Logback-user@qos.ch http://mailman.qos.ch/mailman/**listinfo/logback-user<http://mailman.qos.ch/mailman/listinfo/logback-user>
FYI, I just commented on 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@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> <mailto:ingebrigt@jpro.no <mailto:ingebrigt@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>.__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>.__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
-- Ceki http://twitter.com/#!/ceki
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@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@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> <mailto:ingebrigt@jpro.no <mailto:ingebrigt@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@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
-- Ceki http://twitter.com/#!/ceki
______________________________**_________________ Logback-user mailing list Logback-user@qos.ch http://mailman.qos.ch/mailman/**listinfo/logback-user<http://mailman.qos.ch/mailman/listinfo/logback-user>
Hi Ceki! Just checking up on this, if it's likely to go into Logback, and if you think there are any further changes required on my part. I've been using a local copy of the changes in SyslogAppender in 2 applications. They have been tested all week (the newest version including a stacktraceLayout), so far they're doing fine and our problems with Syslog logging are gone. Production on april 25 (I don't expect this to be in logback by then). No hurry in getting the fix in, but it's important to know soon if Logback will eventually include this (or a functionally similar) fix. I have another 20-30 applications I'll be doing similar maintenance work on over the next few months, and until I know where this is heading it's a bit difficult to get a go ahead on moving them all from Log4j to Logback (We don't really want to maintain inhouse modifications to Logback permanently). cheers, Ingebrigt Den 15:22 12. april 2012 skrev ceki <ceki@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@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> <mailto:ingebrigt@jpro.no <mailto:ingebrigt@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@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
-- Ceki http://twitter.com/#!/ceki
______________________________**_________________ Logback-user mailing list Logback-user@qos.ch http://mailman.qos.ch/mailman/**listinfo/logback-user<http://mailman.qos.ch/mailman/listinfo/logback-user>
Hi ! I completed some changes in SyslogAppender a month ago, but no response so far, and my pull request has expired. Sending a last reminder, in case it has simply been forgotten (let me know if you want me to issue another pull request). cheers, Ingebrigt 2012/4/19 Ingebrigt Berg <ingebrigt@jpro.no>
Hi Ceki!
Just checking up on this, if it's likely to go into Logback, and if you think there are any further changes required on my part.
I've been using a local copy of the changes in SyslogAppender in 2 applications. They have been tested all week (the newest version including a stacktraceLayout), so far they're doing fine and our problems with Syslog logging are gone. Production on april 25 (I don't expect this to be in logback by then).
No hurry in getting the fix in, but it's important to know soon if Logback will eventually include this (or a functionally similar) fix. I have another 20-30 applications I'll be doing similar maintenance work on over the next few months, and until I know where this is heading it's a bit difficult to get a go ahead on moving them all from Log4j to Logback (We don't really want to maintain inhouse modifications to Logback permanently).
cheers, Ingebrigt
Den 15:22 12. april 2012 skrev ceki <ceki@qos.ch> følgende:
FYI, I just commented on 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@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> <mailto:ingebrigt@jpro.no <mailto:ingebrigt@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>.__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>.__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
-- Ceki http://twitter.com/#!/ceki
_______________________________________________ Logback-user mailing list Logback-user@qos.ch http://mailman.qos.ch/mailman/listinfo/logback-user
participants (2)
-
ceki -
Ingebrigt Berg