[syslog-ng] TCP recv bug in syslog-ng v2.09?

Thu Aug 19 17:34:39 CEST 2010

bing! (light bulb just went off).
I wasn't thinking about the whole established vs. non established connection
thing.
I couldn't figure out why, if UDP wasn't sending a newline, it wasn't
causing the same problem. I wasn't thinking about the fact that the
connection was closing, thus ending the stream.

Thanks for the help!

______________________________________________________________

Clayton Dukes
______________________________________________________________

On Thu, Aug 19, 2010 at 11:29 AM, <syslogng at feystorm.net> wrote:

>  I explained it already :-)
> When the message comes in over TCP and doesnt end with a newline, syslog-ng
> assumes the message is going to be continued in another packet. When the
> cumulative total of all the messages exceeds the max message size it flushes
> the buffer out and you get all the messages mashed together at once.
> You can try filing a bug report on bugzilla.balabit.com and request a new
> flag or something that treats each packet on a tcp source as a separate
> message, but I'd say the problem is more cisco than syslog-ng since
> syslog-ng works fine with all other sources except cisco devices :-/
> Look at it this way, every thing that sends logs out to tcp expects the
> receiving syslog daemon to treat a packet without a newline as a message to
> be continued in a later packet. If syslog-ng changed that default behavior,
> all these other things that expect the behavior would break.
>
> -Patrick
>
>
> Sent: Thursday, August 19, 2010 9:12:36 AM
>
> From: Clayton Dukes <cdukes at gmail.com> <cdukes at gmail.com>
> To: Syslog-ng users' and developers' mailing list
> <syslog-ng at lists.balabit.hu> <syslog-ng at lists.balabit.hu>
> Subject: Re: [syslog-ng] TCP recv bug in syslog-ng v2.09?
>
> Following up on this:
>
>  Interestingly, however, is that when I use tcpdump, I DO see each message
> coming in via TCP...so now I'm leaning back towards syslog-ng being the
> problem.
>
>
>
> Here's what I can see:
>
>
>
> UDP:
>
> #tcpdump -vvv host 14.3.23.50 -i eth0
>
> tcpdump: listening on eth0, link-type EN10MB (Ethernet), capture size 96
> bytes
>
> 09:13:31.465239 IP (tos 0xb8, ttl 251, id 1323, offset 0, flags [none],
> proto UDP (17), length 134)
>
>     14.3.23.50.51526 > server.x.com.syslog: SYSLOG, length: 106
>
>         Facility local7 (23), Severity notice (5)
>
>         Msg: 2975: *Aug 19 12:34:19.465: %SYS-5-CONFIG_I[|syslog]
>
>
>
>
>
> TCP:
>
> #tcpdump -vvv host 14.3.23.50 -i eth0
>
> 09:46:29.902063 IP (tos 0x0, ttl 251, id 12253, offset 0, flags [none],
> proto TCP (6), length 146)
>
>     14.3.23.50.31746 > server.x.com.601: Flags [.], seq 233:339, ack 1, win
> 4128, length 106
>
> 09:46:29.902077 IP (tos 0x0, ttl 64, id 27779, offset 0, flags [DF], proto
> TCP (6), length 40)
>
>     server.x.com.601 > 14.3.23.50.31746: Flags [.], cksum 0xa3bb (correct),
> seq 1, ack 339, win 5840, length 0
>
>
>
>
>
> So, it looks like the syslog message does end, but why is syslog-ng
> buffering and showing multiple TCP-based messages as a single message?
>
> Do I have something misconfigured?
>
>
>
>
>  ______________________________________________________________
>
> Clayton Dukes
> ______________________________________________________________
>
>
> On Tue, Aug 17, 2010 at 3:14 PM, Clayton Dukes <cdukes at gmail.com> wrote:
>
>> yikes!
>> seriously?
>> Guess I'll have to file a bug internally :-)
>> Can someone else positively verify this?
>> Or any suggestions on how I can so that we can recreate it in a lab?
>>
>> ______________________________________________________________
>>
>> Clayton Dukes
>> ______________________________________________________________
>>
>>
>>
>> On Tue, Aug 17, 2010 at 2:52 PM, <syslogng at feystorm.net> wrote:
>>
>>> If I recall correctly its because cisco equipment doesnt terminate its
>>> log entries with newlines, so when sending via TCP, syslog-ng thinks the
>>> message is going to be continued in another packet (UDP is assumed to be 1
>>> packet per log entry).
>>> The only way to fix this is an ugly hack to set the timeout so that when
>>> it doesnt get a reply within a certain time, it assumes the log entry ended.
>>> but if several log entries are sent within the timeout, then they'll all be
>>> mashed together into 1 syslog-ng entry.
>>>
>>>
>>> Sent: Tuesday, August 17, 2010 12:28:28 PM
>>> From: Clayton Dukes <cdukes at gmail.com> <cdukes at gmail.com>
>>> To: Syslog-ng users' and developers' mailing list
>>> <syslog-ng at lists.balabit.hu> <syslog-ng at lists.balabit.hu>
>>> Subject: [syslog-ng] TCP recv bug in syslog-ng v2.09?
>>>
>>>  Hey guys,
>>> Are there any known bugs for syslog-ng v2.09  that won't allow a cisco
>>> router to send logs over tcp?
>>> I can see a connection established in syslog-ng.
>>> I also see the message come in via tcpdump, but nothing in syslog-ng's
>>> output.
>>> If I change the router from tcp to udp, messages come in as expected.
>>>
>>>  *Router config:*
>>>
>>>  logging source-interface Loopback0
>>> logging 172.18.224.150
>>> logging host 172.18.224.190 transport tcp
>>>
>>>
>>>  *syslog-ng config:*
>>>
>>>  source s_all {
>>>         udp();
>>>         tcp(ip(11.31.130.99) port(8002) max-connections(300));
>>>         tcp(ip(172.18.224.190) port(601) max-connections(300));
>>> };
>>>
>>>
>>>  *debug output:*
>>> I commented out the line above for the other interface (11.31.130.99),
>>> restarted and this is all I see:
>>> Syslog connection accepted; from='AF_INET(14.3.23.50:63845)',
>>> to='AF_INET(172.18.224.190:601)'
>>>
>>>
>>>  *tcpdump:*
>>>
>>>  14:13:46.914566 IP (tos 0x0, ttl 251, id 4303, offset 0, flags [none],
>>> proto TCP (6), length 134)
>>>     14.3.23.50.63845 > xxx.com.601: Flags [.], seq 230:324, ack 1, win
>>> 4128, length 94
>>>
>>>
>>>  *Router debug:*
>>>
>>>  *Aug 17 17:34:19.772: %SYS-5-CONFIG_I: Configured from console by pnoc
>>> on vty0 (172.18.224.151)
>>> *Aug 17 17:34:20.776: Released port 15205 in Transport Port Agent for
>>> TCP IP type 1 delay 240000
>>> *Aug 17 17:34:20.776: TCB 0x850F9754 destroyed
>>> *Aug 17 17:34:25.775: TCB83648E60 created
>>> *Aug 17 17:34:25.775: TCB83648E60 setting property TCP_PID (8) 845083E4
>>> *Aug 17 17:34:25.775: TCB83648E60 setting property TCP_NO_DELAY (1)
>>> 845083E8
>>> *Aug 17 17:34:25.775: TCB83648E60 setting property TCP keepalive timeout
>>> (17) 845084A0
>>> *Aug 17 17:34:25.775: TCP: Random local port generated 63845, network 1
>>> *Aug 17 17:34:25.775: TCB83648E60 bound to 14.3.23.50.63845
>>> *Aug 17 17:34:25.775: Reserved port 63845 in Transport Port Agent for
>>> TCP IP type 1
>>> *Aug 17 17:34:25.775: TCP: sending SYN, seq 3300233565, ack 0
>>> *Aug 17 17:34:25.775: TCP0: Connection to 172.18.224.190:601,
>>> advertising MSS 536
>>> *Aug 17 17:34:25.775: TCP0: state was CLOSED -> SYNSENT [63845 ->
>>> 172.18.224.190(601)]
>>> *Aug 17 17:34:25.779: TCP0: state was SYNSENT -> ESTAB [63845 ->
>>> 172.18.224.190(601)]
>>> *Aug 17 17:34:25.779: TCP: tcb 83648E60 connection to 172.18.224.190:601,
>>> peer MSS 1460, MSS is 536
>>> *Aug 17 17:34:25.779: TCB83648E60 connected to 172.18.224.190.601
>>> *Aug 17 17:34:25.779: %SYS-6-LOGGINGHOST_STARTSTOP: Logging to host
>>> 172.18.224.190 port 601 started - reconnection
>>>
>>>  ______________________________________________________________
>>>
>>> Clayton Dukes
>>> ______________________________________________________________
>>>
>>> ------------------------------
>>>
>>> ______________________________________________________________________________
>>> Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng
>>> Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng
>>> FAQ: http://www.campin.net/syslog-ng/faq.html
>>>
>>>
>>>
>>> ______________________________________________________________________________
>>> Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng
>>> Documentation:
>>> http://www.balabit.com/support/documentation/?product=syslog-ng
>>> FAQ: http://www.campin.net/syslog-ng/faq.html
>>>
>>>
>>>
>>
>  ------------------------------
>
> ______________________________________________________________________________
> Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng
> Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng
> FAQ: http://www.campin.net/syslog-ng/faq.html
>
>
>
> ______________________________________________________________________________
> Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng
> Documentation:
> http://www.balabit.com/support/documentation/?product=syslog-ng
> FAQ: http://www.campin.net/syslog-ng/faq.html
>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.balabit.hu/pipermail/syslog-ng/attachments/20100819/7047fac0/attachment-0001.htm 