[syslog-ng]Urgent: Mangled messages in pipe() destinations in versions >1.5.8

[Andreas Schulze]

Hello Balazs,

>>Balazs Scheidler wrote:
>>
>>I think, you changed the internal buffering from a line based buffer
>>to byte based buffer between 1.5.8 and 1.5.9.
>>In 1.5.7 there isn't that problem.
>>Maybe, line based buffering seems a better idea in this context.
> 
> Thanks for the detailed report. I think I have found the problem this time.
> Can you check this patch?

I checked the patch. Using patched libol-0.3.6 and syslog-ng-1.5.24.
It solves the message drops in pipes(). Thanks a lot for this.
But it seems, it doesn't solve the mangled messages problem. :(

I try to explain it. Look at the following truss output.
(Remember, that we use several log path's pointing to the same pipe(),
so all fd's (13,18,24,41,54) points to /tmp/pipe e.g.
fd 41 is the heavy loaded path and caused the EAGAIN's.)

[...]
write(41, " < @ - - I L M - - @ >  ".., 4096)	= 4096
write(41, " r c v / % l o s s   =  ".., 3562)	Err#11 EAGAIN
   (Can't write to /tmp/pipe. Ok. We are buffered now.
    Thanks for your patch :)
[...]
write(41, " r c v / % l o s s   =  ".., 4096)	= 4096
   (Here we see, that we are buffered.)
write(41, " :   |   i c m p . b o t".., 4096)	= 4096
write(41, " a v g / m a x   =   9 .".., 4096)	= 4096
   (Successfull. But we really NEED a trailing newline.
    Why? See below.)
write(41, " 0 2 / 0 1 / 2 0 0 3   1".., 2923)	Err#11 EAGAIN
   (/tmp/pipe isn't available. Ok. We are buffered. No problem?)
write(13, " < @ - - C L M - - @ >  ".., 490)	Err#11 EAGAIN
[...]
write(54, " < @ - - T L M - - @ >  ".., 721)	= 721
   (Shit. Here is the problem. We produced a mangled message.
    Because the last successfull write(2) (to fd 41) used
    a byte buffer.)
write(41, " 0 2 / 0 1 / 2 0 0 3   1".., 4096)	= 4096
write(41, " 4 . 7 0 / 5 . 0 3 / 5 .".., 4096)	Err#11 EAGAIN
write(18, " < @ - - S L M - - @ >  ".., 315)	Err#11 EAGAIN
write(13, " < @ - - C L M - - @ >  ".., 490)	Err#11 EAGAIN
[...]
write(41, " 4 . 7 0 / 5 . 0 3 / 5 .".., 4096)	= 4096
write(41, " < @ - - I L M - - @ >  ".., 4096)	= 4096
write(41, " l o s s   =   5 / 5 / 0".., 4096)	Err#11 EAGAIN
write(18, " < @ - - S L M - - @ >  ".., 630)	Err#11 EAGAIN
write(13, " < @ - - C L M - - @ >  ".., 490)	Err#11 EAGAIN
[...]
write(54, " < @ - - T L M - - @ >  ".., 436)	= 436
write(41, " l o s s   =   5 / 5 / 0".., 4096)	= 4096
   (And here is the other problem. We produce a mangled message.
    Because the write to fd 41 doesn't start at the message boundary.)
write(41, " < @ - - I L M - - @ >  ".., 4096)	Err#11 EAGAIN
write(18, " < @ - - S L M - - @ >  ".., 630)	Err#11 EAGAIN
write(13, " < @ - - C L M - - @ >  ".., 490)	Err#11 EAGAIN
[...]

----------
I think its important, that the final chunk to write(2),
is oriented on the message boundaries.
Means, that the buffer should start with the beginning of a logline
and ends with the terminating newline of the same/other/next logline.
----------

I hope, I made the problem more transparent
and will be happy, if a patch is easily possible.

Maybe there is a better solution.
Thanks a lot for your feedback.
-- 
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 $$*