Long messages truncated in 1.5.x branch on Solaris 8
Hello, we are observing a wondrous behavior on our central logservers. We have an local application, that logs to the destinations above. And all messages greater that approx. 975 Bytes are truncated. But the enigma is: If using the local Solaris 'logger' application, all messages greater than 509 Bytes are truncated. But they are truncated on different positions depends on the message size! (Say, if you log 600 Bytes, you get the first 509 and if you try to log 761, you get the first 26.) Hmm ?! We tried out the log_msg_size() feature, available since 1.5.1?. With no luck. Both logservers using Solaris 8, one running syslog-ng 1.5.7, the other 1.5.18. We are using file() and pipe() destinations capable of queueing via log_fifo_size() and capable of formating output via template(..$MSG..\n). Before writing to the destinations, we do a lot of filtering, too. We are using the excellent syslog-ng a long time, but now we stuck inactive. Has anybody a hint for us? Is this a bug in syslog-ng, in Solaris, in our mind? Thanks a lot for any note. -- Best regards --Andreas Schulze [phone: +49.5246.80.1275, fax: +49.5246.80.2275] | I believe, it was Dennis Ritchie who said something like: | "C is rarely the best language for a given task, | but it's often the second-best". | The implication being that: "[...]" | | sh# cat>$$.c<<EOT | main(l,a,n,d)char**a;{for(d=atoi(a[1])/10*80-atoi(a[2])/5-596;n="@NK\ | ACLCCGZAAQBEAADAFaISADJABBA^SNLGAQABDAXIMBAACTBATAHDBANZcEMMCCCCAAhE\ | IJFAEAAABAfHJETBdFLDAANEfDNBPHdBcBBBEA_AL H E L L O, W O R L D! " | [l++-3];)for(;n-->64;)putchar(!d+++33^l&1);} | EOT | gcc -o$$ $$.c;clear;./$$ 52 8;rm -f $$*
On Fri, Jun 28, 2002 at 01:57:49PM +0200, Andreas Schulze wrote:
Hello,
we are observing a wondrous behavior on our central logservers.
We have an local application, that logs to the destinations above. And all messages greater that approx. 975 Bytes are truncated.
But the enigma is: If using the local Solaris 'logger' application, all messages greater than 509 Bytes are truncated. But they are truncated on different positions depends on the message size! (Say, if you log 600 Bytes, you get the first 509 and if you try to log 761, you get the first 26.) Hmm ?!
truss either syslog-ng or logger to see what it actually sends. log messages might be garbled if they are around 1024 in size, since syslog-ng might also modify it (with results in truncated messages again). Imagine the following scenario: - message to syslog-ng (with no host and date parts), 1024 bytes in size - syslog-ng rewrites the messages, inserts host and date (internally these are stored in different variables where the 1024 limit is not appliced) - syslog-ng formats the new message (according to the template given, or the usual syslog format) where the host and date parts of the message are inserted, the message now becomes more than 1024 bytes, thus the message is truncated If syslog-ng reads a message which exceeds 1024, the remaining is read as an independent message -- Bazsi PGP info: KeyID 9AF8D0A9 Fingerprint CD27 CFB0 802C 0944 9CFD 804E C82C 8EB1
Hello Balazs, thanks a lot for your fast response. We need a few days to consolidate our thoughts against syslog, syslog-ng and the whole stuff. We are hoping of your comments or suggestions. At the end there are some questions against syslog-ng. Maybe it's easy for you to answer.
we are observing a wondrous behavior on our central logservers.
We have an local application, that logs to the destinations above. And all messages greater that approx. 975 Bytes are truncated.
But the enigma is: If using the local Solaris 'logger' application, all messages greater than 509 Bytes are truncated. But they are truncated on different positions depends on the message size! (Say, if you log 600 Bytes, you get the first 509 and if you try to log 761, you get the first 26.) Hmm ?!
truss either syslog-ng or logger to see what it actually sends. log messages might be garbled if they are around 1024 in size, since syslog-ng might also modify it (with results in truncated messages again).
Trussing our syslog-ng isn't possible, because the daemons are heavy loaded. So we trussed the 'logger' app (using large messages) under SunOS/Linux. Under Solaris its difficult to see the msg_len sent at the first view, because Solaris uses the SVR4 log driver behavior via putmsg(2). But Linux, that uses the BSD style UNIX_DGRAM behavior, shows that the message is truncated at OS log driver layer. Solaris: open("/dev/conslog", O_WRONLY) = 1 putmsg(1, 0xFFBEE2E8, 0xFFBEE2DC, 0) = 0 Linux: socket(PF_UNIX, SOCK_DGRAM, 0) = 1 connect(1, {sin_family=AF_UNIX, path=" /dev/log"}, 16) = 0 send(1, "<11>Jul 2 16:47:57 DEBUG: 12345"..., 1016, 0) = 1016 Hmm. Locks not really good. A lock at "The Stevens (APUE)" validates, that SunOS implements a SVR4 log system with an additional BSD style syslog(3) interface to this. Anyone knows, how its possible to configure the log(7d) driver on Solaris to process large (>1024 Bytes) messages? Now, we remembered that there is a syslog 'standard' in RFC 3164. Ok, there is a message limit of 1024 over all, but its only referring to UDP. What's with the local log systems? System depended? Huargh.
Imagine the following scenario:
- message to syslog-ng (with no host and date parts), 1024 bytes in size - syslog-ng rewrites the messages, inserts host and date (internally these are stored in different variables where the 1024 limit is not appliced) - syslog-ng formats the new message (according to the template given, or the usual syslog format) where the host and date parts of the message are inserted, the message now becomes more than 1024 bytes, thus the message is truncated
We duplicated your problematic local log's´using 2 destinations. Dest_1 used template("..."), Dest_2 not. The messages are truncated for both destinations. Only for our interest: Is the string created by syslog-ng for holding the results of template(...) size limited?
If syslog-ng reads a message which exceeds 1024, the remaining is read as an independent message
It seems, that this doesn't work in our context. Seems that the syslog(3) interface or the log(7d) driver truncates the messages before they can arrive syslog-ng. We now try do write directly to /dev/*log*, to ensure that the problem is in log(7d). Is the syslog message format in RFC 3164 your reference, Balazs? Thanks for any hints. -- Best regards --Andreas Schulze [phone: +49.5246.80.1275, fax: +49.5246.80.2275] | I believe, it was Dennis Ritchie who said something like: | "C is rarely the best language for a given task, | but it's often the second-best". | The implication being that: "[...]" | | sh# cat>$$.c<<EOT | main(l,a,n,d)char**a;{for(d=atoi(a[1])/10*80-atoi(a[2])/5-596;n="@NK\ | ACLCCGZAAQBEAADAFaISADJABBA^SNLGAQABDAXIMBAACTBATAHDBANZcEMMCCCCAAhE\ | IJFAEAAABAfHJETBdFLDAANEfDNBPHdBcBBBEA_AL H E L L O, W O R L D! " | [l++-3];)for(;n-->64;)putchar(!d+++33^l&1);} | EOT | gcc -o$$ $$.c;clear;./$$ 52 8;rm -f $$*
On Tue, Jul 02, 2002 at 06:50:36PM +0200, Andreas Schulze wrote:
we are observing a wondrous behavior on our central logservers.
We have an local application, that logs to the destinations above. And all messages greater that approx. 975 Bytes are truncated.
But the enigma is: If using the local Solaris 'logger' application, all messages greater than 509 Bytes are truncated. But they are truncated on different positions depends on the message size! (Say, if you log 600 Bytes, you get the first 509 and if you try to log 761, you get the first 26.) Hmm ?!
truss either syslog-ng or logger to see what it actually sends. log messages might be garbled if they are around 1024 in size, since syslog-ng might also modify it (with results in truncated messages again).
Trussing our syslog-ng isn't possible, because the daemons are heavy loaded. So we trussed the 'logger' app (using large messages) under SunOS/Linux. Under Solaris its difficult to see the msg_len sent at the first view, because Solaris uses the SVR4 log driver behavior via putmsg(2). But Linux, that uses the BSD style UNIX_DGRAM behavior, shows that the message is truncated at OS log driver layer. Solaris: open("/dev/conslog", O_WRONLY) = 1 putmsg(1, 0xFFBEE2E8, 0xFFBEE2DC, 0) = 0 Linux: socket(PF_UNIX, SOCK_DGRAM, 0) = 1 connect(1, {sin_family=AF_UNIX, path=" /dev/log"}, 16) = 0 send(1, "<11>Jul 2 16:47:57 DEBUG: 12345"..., 1016, 0) = 1016 Hmm. Locks not really good.
A lock at "The Stevens (APUE)" validates, that SunOS implements a SVR4 log system with an additional BSD style syslog(3) interface to this.
Anyone knows, how its possible to configure the log(7d) driver on Solaris to process large (>1024 Bytes) messages?
Now, we remembered that there is a syslog 'standard' in RFC 3164. Ok, there is a message limit of 1024 over all, but its only referring to UDP. What's with the local log systems? System depended? Huargh.
The maximum message length is system dependent. syslog-ng itself has a configurable limit (above 1.5.17), with one exception, the result of templates might not exceed 2048 bytes in size. (I've found this limit right now) This 2048 limit doesn't affect destinations with no templates applied. This patch fixes this, and increases it to the limit given by log_msg_size(): diff -u -r1.50 affile.c --- affile.c 26 Apr 2002 09:43:53 -0000 1.50 +++ affile.c 3 Jul 2002 07:15:01 -0000 @@ -856,7 +856,7 @@ { "MESSAGE", M_MESSAGE }, { "SOURCEIP", M_SOURCE_IP } }; - char format[MAX_EXPANDED_MACRO], *format_ptr = format; + char format[cfg->log_msg_size + 1], *format_ptr = format; int left = sizeof(format); int i, j; ---- end of patch ---
Imagine the following scenario:
- message to syslog-ng (with no host and date parts), 1024 bytes in size - syslog-ng rewrites the messages, inserts host and date (internally these are stored in different variables where the 1024 limit is not appliced) - syslog-ng formats the new message (according to the template given, or the usual syslog format) where the host and date parts of the message are inserted, the message now becomes more than 1024 bytes, thus the message is truncated
We duplicated your problematic local log's´using 2 destinations. Dest_1 used template("..."), Dest_2 not. The messages are truncated for both destinations.
Is log_msg_size() set in your syslog-ng configuration?
Only for our interest: Is the string created by syslog-ng for holding the results of template(...) size limited?
see above, and the patch above.
If syslog-ng reads a message which exceeds 1024, the remaining is read as an independent message
It seems, that this doesn't work in our context. Seems that the syslog(3) interface or the log(7d) driver truncates the messages before they can arrive syslog-ng. We now try do write directly to /dev/*log*, to ensure that the problem is in log(7d).
Is the syslog message format in RFC 3164 your reference, Balazs?
syslog-ng had been released earlier than RFC3164, however I did contribute to rfc3164. -- Bazsi PGP info: KeyID 9AF8D0A9 Fingerprint CD27 CFB0 802C 0944 9CFD 804E C82C 8EB1
Balazs Scheidler wrote:
On Tue, Jul 02, 2002 at 06:50:36PM +0200, Andreas Schulze wrote:
truss either syslog-ng or logger to see what it actually sends. log messages might be garbled if they are around 1024 in size, since syslog-ng might also modify it (with results in truncated messages again).
Trussing our syslog-ng isn't possible, because the daemons are heavy loaded. So we trussed the 'logger' app (using large messages) under SunOS/Linux. Under Solaris its difficult to see the msg_len sent at the first view, because Solaris uses the SVR4 log driver behavior via putmsg(2). But Linux, that uses the BSD style UNIX_DGRAM behavior, shows that the message is truncated at OS log driver layer.
Now, we remembered that there is a syslog 'standard' in RFC 3164. Ok, there is a message limit of 1024 over all, but its only referring to UDP. What's with the local log systems? System depended? Huargh.
The maximum message length is system dependent. syslog-ng itself has a configurable limit (above 1.5.17), with one exception, the result of templates might not exceed 2048 bytes in size. (I've found this limit right now) This 2048 limit doesn't affect destinations with no templates applied.
Thanks for this patch. So we could fix an other potential problem.
We duplicated your problematic local log's´using 2 destinations. Dest_1 used template("..."), Dest_2 not. The messages are truncated for both destinations.
Is log_msg_size() set in your syslog-ng configuration?
Yes. Set to 4096 Bytes. But I'm afraid, that the messages are truncated before they reach syslog-ng at OS level by the log(7d) driver or the syslog(3) interface. Maybe you know, if its possible to work around this problem on Solaris? Thanks a lot. -- Best regards --Andreas Schulze [phone: +49.5246.80.1275, fax: +49.5246.80.2275] | I believe, it was Dennis Ritchie who said something like: | "C is rarely the best language for a given task, | but it's often the second-best". | The implication being that: "[...]" | | sh# cat>$$.c<<EOT | main(l,a,n,d)char**a;{for(d=atoi(a[1])/10*80-atoi(a[2])/5-596;n="@NK\ | ACLCCGZAAQBEAADAFaISADJABBA^SNLGAQABDAXIMBAACTBATAHDBANZcEMMCCCCAAhE\ | IJFAEAAABAfHJETBdFLDAANEfDNBPHdBcBBBEA_AL H E L L O, W O R L D! " | [l++-3];)for(;n-->64;)putchar(!d+++33^l&1);} | EOT | gcc -o$$ $$.c;clear;./$$ 52 8;rm -f $$*
On Wed, Jul 03, 2002 at 01:38:51PM +0200, Andreas Schulze wrote:
Balazs Scheidler wrote: But I'm afraid, that the messages are truncated before they reach syslog-ng at OS level by the log(7d) driver or the syslog(3) interface.
Maybe you know, if its possible to work around this problem on Solaris?
It should be doable using an LD_PRELOAD-able shared object, which would change the implementation of openlog(), closelog() and syslog() functions, so it either goes to syslog-ng directly (using a pipe or a unix_stream socket), or sends the message off immediately using udp or tcp. -- Bazsi PGP info: KeyID 9AF8D0A9 Fingerprint CD27 CFB0 802C 0944 9CFD 804E C82C 8EB1
participants (2)
-
Andreas Schulze
-
Balazs Scheidler