Logs after "\n" are getting truncated
Hi All, When logging multiline messages (simple strings with in-line newlines "\n") our logs only show the first line (ie) before "\n" is encountered and rest of the line after the first newline character("\n") is truncated. Example: Code Snippet: HS_MAP_INFO_LOG("[ %s ] Resource [ %d ] Sensor Number: %2d, Sensor Type: %d, Event Category: %d, Assertion: %d, \n" "Event State: %d, Previous State: %d, OEM Code: %d, Sensor Specific: %d\n", eidStr, pEvt->Source, thisSensorEvent->SensorNum, thisSensorEvent->SensorType, thisSensorEvent->EventCategory, thisSensorEvent->Assertion, thisSensorEvent->EventState, thisSensorEvent->PreviousState, thisSensorEvent->Oem, thisSensorEvent->SensorSpecific); Expected Output on Log: May 4 11:32:34 base0-0-0-1-0-11-1 shelfHs[5255]: 5257: sHs[Info]: 1304523154.708143: hsMapLog.cpp(47): hsMapHpiShelfHsBUtils.cpp(240): [ 0:0:9:0:11:1 ] Resource [ 68 ] Sensor Number: 9, Sensor Type: 2, Event Category: 1, Assertion: 1, Event State: 16, PreviousState: 0, OEM Code: 0, Sensor Specific: 0 Actual Output populated on Log: May 4 10:18:37 base0-0-0-1-0-11-1 shelfHs[4539]: 4542: sHs[Info]: 1304518717.501982: hsMapLog.cpp(47): hsMapHpiShelfHsBUtils.cpp(240): [ 0:0:9:0:11:1 ] Resource [ 98 ] Sensor Number: 9, Sensor Type: 2, Event Category: 1, Assertion: 1, So,if anyone know some kind of fix/patch for resolving this issue, please let me know. Your help would be highly appreciated. Thanks & regards Swati. =====-----=====-----===== Notice: The information contained in this e-mail message and/or attachments to it may contain confidential or privileged information. If you are not the intended recipient, any dissemination, use, review, distribution, printing or copying of the information contained in this e-mail message and/or attachments to it are strictly prohibited. If you have received this communication in error, please notify us by reply e-mail or telephone and immediately and permanently delete the message and any attachments. Thank you
Swati4 M/TVM/TCS <swati4.m@tcs.com> writes:
Hi All,
When logging multiline messages (simple strings with in-line newlines "\n") our logs only show the first line (ie) before "\n" is encountered and rest of the line after the first newline character("\n") is truncated.
The main issue is that the syslog protocol is line-oriented: each line should be prefixed with a syslog-style header. Your logging function doesn't do that, I believe. This results in syslog-ng not being able to parse the second line. There are a few options I can think of: one is to modify your application to send each line as a separate log message (but then they'll appear as separate logs on the output aswell, so this might not be a desirable option). Another option would be to modify your application to NOT send a syslog message header at all, and use flags(no-parse) on the syslog-ng source side, and a custom parser, if you want to turn the message into something syslog-like. A third option would be to use an intermediate relay (a script, perhaps) that does some heuristics to discover where a message starts, and strips newlines until it finds another message, then sends the previous over to syslog-ng. The third would be the easiest, but probably the least performant too. It's the only one that doesn't need changes on the application side, though. There might be other options aswell, but these are the ones I could think of quickly. -- |8]
On Tue, 2011-11-08 at 15:02 +0100, Gergely Nagy wrote:
Swati4 M/TVM/TCS <swati4.m@tcs.com> writes:
Hi All,
When logging multiline messages (simple strings with in-line newlines "\n") our logs only show the first line (ie) before "\n" is encountered and rest of the line after the first newline character("\n") is truncated.
The main issue is that the syslog protocol is line-oriented: each line should be prefixed with a syslog-style header. Your logging function doesn't do that, I believe.
This results in syslog-ng not being able to parse the second line.
There are a few options I can think of: one is to modify your application to send each line as a separate log message (but then they'll appear as separate logs on the output aswell, so this might not be a desirable option).
Another option would be to modify your application to NOT send a syslog message header at all, and use flags(no-parse) on the syslog-ng source side, and a custom parser, if you want to turn the message into something syslog-like.
A third option would be to use an intermediate relay (a script, perhaps) that does some heuristics to discover where a message starts, and strips newlines until it finds another message, then sends the previous over to syslog-ng.
The third would be the easiest, but probably the least performant too. It's the only one that doesn't need changes on the application side, though.
There might be other options aswell, but these are the ones I could think of quickly.
Are you using the syslog() API to fire off this event with an embedded NL in it? Or HS_MAP_INFO_LOG() writes messages to a logfile and then you are tailing that with syslog-ng? If the first, then using unix-dgram() as the local log transport may help you get the NLs inside syslog-ng. In that case each and every datagram sent to /dev/log will be logged as a separate message, even if it contains NLs. unix-stream() doesn't work as in unix-stream NL is used as the record terminator. -- Bazsi
Hi , Thanks for your response. Modifying the transport unix-dgram fixes my issue.The logs are no longer getting truncated after \n.However,just wanted to clarify would changing the unix logging facility affect the remote logging or traffic in any way.I am using UDP ports for logging into remote. Thanks & Regards Swati ----- Original Message ----- From: "Balazs Scheidler" <bazsi@balabit.hu> To: "Syslog-ng users' and developers' mailing list" <syslog-ng@lists.balabit.hu> Sent: Thursday, November 10, 2011 1:59:51 AM Subject: Re: [syslog-ng] Logs after "\n" are getting truncated On Tue, 2011-11-08 at 15:02 +0100, Gergely Nagy wrote:
Swati4 M/TVM/TCS <swati4.m@tcs.com> writes:
Hi All,
When logging multiline messages (simple strings with in-line newlines "\n") our logs only show the first line (ie) before "\n" is encountered and rest of the line after the first newline character("\n") is truncated.
The main issue is that the syslog protocol is line-oriented: each line should be prefixed with a syslog-style header. Your logging function doesn't do that, I believe.
This results in syslog-ng not being able to parse the second line.
There are a few options I can think of: one is to modify your application to send each line as a separate log message (but then they'll appear as separate logs on the output aswell, so this might not be a desirable option).
Another option would be to modify your application to NOT send a syslog message header at all, and use flags(no-parse) on the syslog-ng source side, and a custom parser, if you want to turn the message into something syslog-like.
A third option would be to use an intermediate relay (a script, perhaps) that does some heuristics to discover where a message starts, and strips newlines until it finds another message, then sends the previous over to syslog-ng.
The third would be the easiest, but probably the least performant too. It's the only one that doesn't need changes on the application side, though.
There might be other options aswell, but these are the ones I could think of quickly.
Are you using the syslog() API to fire off this event with an embedded NL in it? Or HS_MAP_INFO_LOG() writes messages to a logfile and then you are tailing that with syslog-ng? If the first, then using unix-dgram() as the local log transport may help you get the NLs inside syslog-ng. In that case each and every datagram sent to /dev/log will be logged as a separate message, even if it contains NLs. unix-stream() doesn't work as in unix-stream NL is used as the record terminator. -- Bazsi ______________________________________________________________________________ Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng FAQ: http://www.balabit.com/wiki/syslog-ng-faq =====-----=====-----===== Notice: The information contained in this e-mail message and/or attachments to it may contain confidential or privileged information. If you are not the intended recipient, any dissemination, use, review, distribution, printing or copying of the information contained in this e-mail message and/or attachments to it are strictly prohibited. If you have received this communication in error, please notify us by reply e-mail or telephone and immediately and permanently delete the message and any attachments. Thank you
On Thu, 2011-11-10 at 15:48 +0530, Swati4 M/TVM/TCS wrote:
Hi ,
Thanks for your response. Modifying the transport unix-dgram fixes my issue.The logs are no longer getting truncated after \n.However,just wanted to clarify would changing the unix logging facility affect the remote logging or traffic in any way.I am using UDP ports for logging into remote.
No it doesn't. However you shouldn't use UDP for log transport. You can lose as much as 95% percent of it in peaks. -- Bazsi
No it doesn't. However you shouldn't use UDP for log transport. You can lose as much as 95% percent of it in peaks.
Certainly UDP is not as reliable as TCP, but canonically saying you shouldn't use UDP seems a bit of an overstatement. We use UDP to collect > 15k logs per second and do not experience drops. Can you describe the 95% drop rates you have experienced?
On Thu, 2011-11-10 at 13:40 -0600, Martin Holste wrote:
No it doesn't. However you shouldn't use UDP for log transport. You can lose as much as 95% percent of it in peaks.
Certainly UDP is not as reliable as TCP, but canonically saying you shouldn't use UDP seems a bit of an overstatement. We use UDP to collect > 15k logs per second and do not experience drops. Can you describe the 95% drop rates you have experienced?
Well, you need to generate a peak certainly, and once your IP receive buffer fills up, a lot of messages can be lost. Here's a tutorial by Marcus J. Ranum, who explains his findings (it's an interesting read anyway, but UDP packet loss is described in slide 33). http://www.ranum.com/security/computer_security/archives/logging-notes.pdf So definitely _you can_ tune udp receive parameters to make it fine, but once there's a runaway host generating lots of logs at wire speed, message loss will always be triggered. And not to mention that people usually run it with default parameters... -- Bazsi
Here's a tutorial by Marcus J. Ranum, who explains his findings (it's an interesting read anyway, but UDP packet loss is described in slide 33).
http://www.ranum.com/security/computer_security/archives/logging-notes.pdf
So definitely _you can_ tune udp receive parameters to make it fine, but once there's a runaway host generating lots of logs at wire speed, message loss will always be triggered.
What a great paper! Hilarious and insightful, though it's a bit dated now. Still, lots of great pull quotes like "One thing we have learned over time is that some log messages which nobody would consider security event messages may actually be the precursor-indicators of an attack." Great stuff. However, slide 33 is way off with regard to numbers. I don't know if it's a problem with the old hardware, OpenBSD, or some other parameter, but modern Linux kernels at least will definitely not see that kind of loss. I have yet to see Syslog-NG drop a UDP message because of a networking stack load problem. We verify this by looking at the sequence numbers from some of our most voluminous routers. What I have seen is Syslog-NG drop when the log destination gets backed up, like if writing directly to SQL. I've never seen a file destination drop a message due to overload.
participants (4)
-
Balazs Scheidler
-
Gergely Nagy
-
Martin Holste
-
Swati4 M/TVM/TCS