[syslog-ng] logging pauses and log entry truncation

[Dustin Trammell]

One difference I noticed between your log entries and mine is, yours appear
to either get mangled and/or truncated, and then that's it, it continues on
the next line with a new log entry.  I've seen a bit different behavior in
mine, where it will mangle and/or truncate a line, but then on the next
entry, it continues with the rest of the previous entry.  It's like when
reading from /proc/kmsg it's erroneously detecting an end of line, sending
that bit of data to the destinations, then continues reading from
/proc/kmsg, starting where it cut off.  For example:

Aug 14 10:17:46 loghost01 fwlog input drop cleanup IN=eth0 OUT= MAC=00:06:
Aug 14 10:17:46 loghost01 5b:84:60:7e:00:50:04:a5:11:1f:08:00
SRC=172.30.10.33 DST=172.30.8.40 LEN=60 TOS=0x00 PREC=0x00 TTL=219 ID=61008
DF PROTO=TCP SPT=54189 DPT=32601 WINDOW=5840 RES=0x00 SYN URGP=0

Aug 14 10:17:52 loghost01 <4>fwlog input drop cleanup IN=eth0 OUT= MAC=00:
Aug 14 10:17:52 loghost01 06:5b:84:60:7e:00:50:04:a5:11:1f:08:00
SRC=172.30.10.33 DST=172.30.8.40 LEN=60 TOS=0x00 PREC=0x00 TTL=219 ID=36311
DF PROTO=TCP SPT=54189 DPT=32601 WINDOW=5840 RES=0x00 SYN URGP=0

As you can see, the first line gets truncated, then on the next line, it
continues with the rest of the log entry starting where the previous one got
cut off.

While writing this, I just saw the most mangled entry I've seen yet:

Aug 14 10:16:15 loghost01 fwlog input drop clenup Ib:84:602. PREC=0x00
TTL=79 ID=T=TCP S SYN  TCP i OUT MAC=00:06:5b:84172.3072.=5840 RES=0x00 N=0

As opposed to what it /should/ look like:

Aug 14 10:17:46 loghost01 fwlog input drop cleanup IN=eth0 OUT=
MAC=00:06:5b:84:60:7e:00:50:04:a5:11:1f:08:00 SRC=172.30.10.33
DST=172.30.8.40 LEN=60 TOS=0x00 PREC=0x00 TTL=219 ID=45827 DF PROTO=TCP
SPT=38821 DPT=32606 WINDOW=5840 RES=0x00 SYN URGP=0

Weird weird stuff.  Hopefully some of this discussion and related log
snippets will help Balazs pinpoint the problem.

---
Dustin D. Trammell
Information Security Specialist
Penson Financial Services, Inc.



-----Original Message-----
From: Caylan Van Larson [mailto:caylan@cs.und.edu]
Sent: Wednesday, August 14, 2002 10:08
To: 'syslog-ng@lists.balabit.hu'
Subject: RE: [syslog-ng] logging pauses and log entry truncation


Yes, similar, but also erratic.  I have it happening in the MAC addy and 
toward the end.  Sometimes it seems as they are folded in on itself.

I have placed a sample on www.cs.und.edu/~caylan/kern for your viewing 
pleasure.  It is not my sytle to make things like this publicly accessible 
but I want to get this issue resolved.

In case you did not see the above URL or are too lazy :P

Aug 14 10:02:30 smack IPTABLES UDP-IN: IN=eth1 OUT=
MAC=00:03:47:4e:32:44:00:05:01:fb:e3:fc:08:
Aug 14 10:02:31 smack IPTABLES TCP-IN: IN=eth1 OUT=
MAC=00:03:47:4e:32:44:00:05:01:fb:e3:fc:08:00 SRC=63.151.197.164
DST=134.129.212.30 LEN=48 TOS=0x00 PREC=0x00TT14 2103DF PRTCP SW=163
Aug 14 10:02:32 smack IPTABLES UDP-IN: IN=eth1 OUT=
MAC=00:03:47:4e:32:44:00:05:01:fb:e3:fc:08:
Aug 14 10:02:32 smack IPTABLES UDP-IN: IN=eth1 OUT=
MAC=00:03:47:4e:32:44:00:05:01:fb:e3:fc:
Aug 14 10:02:32 smack IPTABLES UDP-IN: IN=eth1 OUT=
MAC=00:03:47:4e:32:44:00:05:01:fb:e3:fc:08:00 SRC=134.129.215.35 DST=1PSPT7
DPT=137 L
Aug 14 10:02:32 smack IPTABLES UDP-IN: IN=eth1 OUT=
MAC=00:03:47:4e:32:44:00:05:01:fb:e3:fc:08:
Aug 14 10:02:33 smack IPTABLES UDP-IN: IN=eth1 OUT=
MAC=00:03:47:4e:32:44:00:05:01:fb:e3:fc:08:00 SRC=134.129.215.35
DST=134.129.212.30 LEN=9 138 N=20
Aug 14 10:02:33 smack IPTABLES UDP-IN: IN=eth1 OUT=
MAC=00:03:47:4e:32:44:00:05:01:fb:e3:fc:08:

Thats a pretty damn good sample!

Good luck,


Caylan Van Larson
Unix Administrator - Systems Team Member
University of North Dakota (Aerospace College)
caylan@cs.und.edu
701-777-6151 (work)