Has anyone else experienced syslog-ng occasionally pausing for a few minutes, immediately after logging one or more truncated entries? It usually pauses for anywhere from 1-10 minutes or so, and the process seems to be fine during this time (still bound to the port, doesn't appear to be zombied or using up all the CPU or memory, etc), then it continues after the pause as if nothing happened. The entry immediately after the pause is sometimes truncated also. The lines that are getting truncated appear to always be kernel log entries, more specifically from iptables, so I tried both using klogd as well as a file() source using /proc/kmsg, both with the same results. I saw a thread a few days ago about garbled/truncated entries, and what I got from that thread was to set the log_msg_size() option to something larger than the largest line your expecting. I set mine to 2048, and that still has not solved the problem, so I'm not sure if it's the same issue that has been discussed in the previous thread or something different. Below I've listed a few log entries (gathered from tail -f logfile), and my syslog-ng.conf file is appended below my sig. ---8<-----(snip)-----8<--- Aug 12 08:10:01 172.30.10.3 arpwatch: eth7 bogon 192.168.168.14 0:4:c0:3:a8:0 Aug 12 08:10:01 172.30.10.60 traqer: doing 10 minute stuff Aug 12 08:10:01 172.30.10.60 kernel: fwlog output accept db IN= OUT=ipsec0 SRC=172.30.10.60 DST=172.30.10.61 LEN=60 TOS=0x00 PREC=0x00 TTL=232 ID=1196 PROTO=TCP SPT=51118 DPT=5432 WINDOW=32440 RES=0x00 CWR ECE SYN URGP=0 Aug 12 08:10:01 loghost01 fwlog input drop cleanup IN=ipsec0 OUT= MAC=00:06:5b:84:60:7e:00:08:02:10: (pause) Aug 12 08:20:01 loghost01 fwlog input drop cleanup IN=ipsec0 OUT= MAC=00:06: Aug 12 08:11:05 loghost01 stunnel[23914]: httpd connected from 172.30.8.40:47705 Aug 12 08:11:05 loghost01 stunnel[23914]: SSL_accept: Peer suddenly disconnected ---8<-----(snip)-----8<--- Aug 12 11:01:29 172.30.10.60 pluto[3590]: "itdb" #814: ignoring Delete SA payload Aug 12 11:01:29 172.30.10.60 pluto[3590]: "itdb" #814: received and ignored informational message Aug 12 11:01:29 loghost01 fwlog input drop cleanup IN=ipsec0 OUT= MAC=00:06:5b:84:60:7e:00:08: Aug 12 11:01:29 loghost01 fwlog input drop cleanup IN=ipsec0 OUT= MAC= Aug 12 11:01:29 loghost01 fwlog input drop cleanup IN=ipsec0 OUT= MAC= (pause) Aug 12 11:06:49 loghost01 fwlog input drop cleanup IN=ipsec0 OUT= MAC=00:06: Aug 12 11:02:07 loghost01 snmptrapd[31633]: 209.48.214.5: Enterprise Specific Trap (500) Uptime: 6 days, 16:43:47.00, SNMPv2-SMI::enterprises.3224.2.1 = 40, SNMPv2-SMI::enterprises.3224.2.3 = "ALARM: vpn \"LC*Lon-VPN\" is up. (08/12/2002 11:01:27)" Aug 12 11:02:06 loghost01 stunnel[11455]: httpd connected from 172.30.8.40:40969 Aug 12 11:02:06 loghost01 stunnel[11455]: SSL_accept: Peer suddenly disconnected ---8<-----(snip)-----8<--- Aug 12 11:06:49 10.10.2.200 kernel: fwlog inet accept ssl IN=eth0 OUT=eth3 SRC=195.126.219.35 DST=192.168.200.20 LEN=60 TOS=0x00 PREC=0x00 TTL=50 ID=59691 DF PROTO=TCP SPT=19846 DPT=443 WINDOW=32120 RES=0x00 SYN URGP=0 Aug 12 11:06:49 172.31.1.5 LasColinas-NS10: ALARM: vpn "LC*Lon-VPN" is up. (08/12/2002 11:01:27) Aug 12 11:06:49 172.30.10.3 arpwatch: eth1 bogon 172.19.1.6 0:3:fe:60:8:40 Aug 12 11:06:49 172.31.1.5 LasColinas-NS10: Can't connect to E-mail server 172.30.2.51 (08/12/2002 11:01:49) Aug 12 11:06:49 loghost01 fwlog input drop cleanup IN=ipsec0 OUT= MAC=00:06:5b:84:60:7e:00:08:02:10: (pause) Aug 12 11:08:36 loghost01 fwlog input drop cleanup IN=ipsec0 OUT= MAC=00:06: Aug 12 11:08:07 loghost01 stunnel[24185]: httpd connected from 172.30.8.40:60549 Aug 12 11:08:07 loghost01 stunnel[24185]: SSL_accept: Peer suddenly disconnected ---8<-----(snip)-----8<--- Aug 12 11:16:13 172.31.1.5 LasColinas-NS10: NetScreen Traffic Log: device_id=LasColinas-NS10 start_time="08/12/2002 11:09:21" src=172.30.8.76 dst=172.31.1.5 service=icmp proto=1 policy_id=18 direction=incoming duration=1 sent=96 rcvd=96 action=Tunnel (LC*Dal-VPN) icmp type=8 Aug 12 11:20:01 loghost01 fwlog input drop cleanup IN=ipsec0 OUT= Aug 12 11:11:04 loghost01 tac_plus[9564]: Read -1 bytes from 172.30.8.40 , expecting 12 (pause) Aug 12 11:20:01 loghost01 MAC=00:06:5b:84:60:7e:00:08:02:10:cb:a4:08:00 SRC=172.30.10.61 DST=172.30.8.40 LEN=275 TOS=0x00 PREC=0x00 TTL=134 ID=4745 DF PROTO=UDP SPT=514 DPT=514 LEN=255 Aug 12 11:20:01 172.31.1.5 LasColinas-NS10: NetScreen Traffic Log: device_id=LasColinas-NS10 start_time="08/12/2002 11:09:20" src=172.30.8.5 dst=172.31.1.5 service=icmp proto=1 policy_id=18 direction=incoming duration=1 sent=112 rcvd=112 action=Tunnel (LC*Dal-VPN) icmp type=8 ---8<-----(snip)-----8<--- If anyone has experienced this or has any other ideas that I may not have tried yet, any info you can provide would be most appreciated. Thanks, --- Dustin D. Trammell Information Security Specialist Penson Financial Services, Inc. ### Syslog-NG Config File # Global Options options { chain_hostnames(no); use_dns(no); log_fifo_size(2000); log_msg_size(2048); sync(0); }; # Source Objects source s_local { internal(); }; source s_kmsg { file("/proc/kmsg"); }; source s_devlog { unix-stream("/dev/log" max-connections(150)); }; source s_udp514 { udp(); }; source s_tcp514 { tcp(ip("127.0.0.1") max-connections(150) keep-alive(yes)); }; source s_kernel { file("/proc/kmsg"); }; # Destination Objects destination d_varlog { file("/var/log/log"); }; destination d_tty8 { pipe("/dev/tty8"); }; destination d_logresp { pipe("/usr/local/logrespond/fifo/log" owner(logrespond) group(root) perm(0600) ); }; destination d_logtraq { pipe("/usr/local/logtraq/logpipe" owner(root) group(logtraq) perm(0640) ); }; # Log Paths log { source(s_local); source(s_kmsg); source(s_devlog); source(s_udp514); source(s_tcp514); source(s_kernel); destination(d_varlog); destination(d_tty8); destination(d_logresp); destination(d_logtraq); };
I am having very similar truncating going on. Bazsi is working on a fix. However, my logs never paused, maybe for a little bit (5-10seconds) but that is prolly just net traffic jumps. Good luck to Bazsi!!! Caylan Van Larson Unix Administrator - Systems Team Member University of North Dakota (Aerospace College) caylan@cs.und.edu 701-777-6151 (work) On Mon, 12 Aug 2002, Dustin Trammell wrote:
Has anyone else experienced syslog-ng occasionally pausing for a few minutes, immediately after logging one or more truncated entries? It usually pauses for anywhere from 1-10 minutes or so, and the process seems to be fine during this time (still bound to the port, doesn't appear to be zombied or using up all the CPU or memory, etc), then it continues after the pause as if nothing happened. The entry immediately after the pause is sometimes truncated also. The lines that are getting truncated appear to always be kernel log entries, more specifically from iptables, so I tried both using klogd as well as a file() source using /proc/kmsg, both with the same results. I saw a thread a few days ago about garbled/truncated entries, and what I got from that thread was to set the log_msg_size() option to something larger than the largest line your expecting. I set mine to 2048, and that still has not solved the problem, so I'm not sure if it's the same issue that has been discussed in the previous thread or something different. Below I've listed a few log entries (gathered from tail -f logfile), and my syslog-ng.conf file is appended below my sig.
---8<-----(snip)-----8<--- Aug 12 08:10:01 172.30.10.3 arpwatch: eth7 bogon 192.168.168.14 0:4:c0:3:a8:0 Aug 12 08:10:01 172.30.10.60 traqer: doing 10 minute stuff Aug 12 08:10:01 172.30.10.60 kernel: fwlog output accept db IN= OUT=ipsec0 SRC=172.30.10.60 DST=172.30.10.61 LEN=60 TOS=0x00 PREC=0x00 TTL=232 ID=1196 PROTO=TCP SPT=51118 DPT=5432 WINDOW=32440 RES=0x00 CWR ECE SYN URGP=0 Aug 12 08:10:01 loghost01 fwlog input drop cleanup IN=ipsec0 OUT= MAC=00:06:5b:84:60:7e:00:08:02:10: (pause) Aug 12 08:20:01 loghost01 fwlog input drop cleanup IN=ipsec0 OUT= MAC=00:06: Aug 12 08:11:05 loghost01 stunnel[23914]: httpd connected from 172.30.8.40:47705 Aug 12 08:11:05 loghost01 stunnel[23914]: SSL_accept: Peer suddenly disconnected ---8<-----(snip)-----8<--- Aug 12 11:01:29 172.30.10.60 pluto[3590]: "itdb" #814: ignoring Delete SA payload Aug 12 11:01:29 172.30.10.60 pluto[3590]: "itdb" #814: received and ignored informational message Aug 12 11:01:29 loghost01 fwlog input drop cleanup IN=ipsec0 OUT= MAC=00:06:5b:84:60:7e:00:08: Aug 12 11:01:29 loghost01 fwlog input drop cleanup IN=ipsec0 OUT= MAC= Aug 12 11:01:29 loghost01 fwlog input drop cleanup IN=ipsec0 OUT= MAC= (pause) Aug 12 11:06:49 loghost01 fwlog input drop cleanup IN=ipsec0 OUT= MAC=00:06: Aug 12 11:02:07 loghost01 snmptrapd[31633]: 209.48.214.5: Enterprise Specific Trap (500) Uptime: 6 days, 16:43:47.00, SNMPv2-SMI::enterprises.3224.2.1 = 40, SNMPv2-SMI::enterprises.3224.2.3 = "ALARM: vpn \"LC*Lon-VPN\" is up. (08/12/2002 11:01:27)" Aug 12 11:02:06 loghost01 stunnel[11455]: httpd connected from 172.30.8.40:40969 Aug 12 11:02:06 loghost01 stunnel[11455]: SSL_accept: Peer suddenly disconnected ---8<-----(snip)-----8<--- Aug 12 11:06:49 10.10.2.200 kernel: fwlog inet accept ssl IN=eth0 OUT=eth3 SRC=195.126.219.35 DST=192.168.200.20 LEN=60 TOS=0x00 PREC=0x00 TTL=50 ID=59691 DF PROTO=TCP SPT=19846 DPT=443 WINDOW=32120 RES=0x00 SYN URGP=0 Aug 12 11:06:49 172.31.1.5 LasColinas-NS10: ALARM: vpn "LC*Lon-VPN" is up. (08/12/2002 11:01:27) Aug 12 11:06:49 172.30.10.3 arpwatch: eth1 bogon 172.19.1.6 0:3:fe:60:8:40 Aug 12 11:06:49 172.31.1.5 LasColinas-NS10: Can't connect to E-mail server 172.30.2.51 (08/12/2002 11:01:49) Aug 12 11:06:49 loghost01 fwlog input drop cleanup IN=ipsec0 OUT= MAC=00:06:5b:84:60:7e:00:08:02:10: (pause) Aug 12 11:08:36 loghost01 fwlog input drop cleanup IN=ipsec0 OUT= MAC=00:06: Aug 12 11:08:07 loghost01 stunnel[24185]: httpd connected from 172.30.8.40:60549 Aug 12 11:08:07 loghost01 stunnel[24185]: SSL_accept: Peer suddenly disconnected ---8<-----(snip)-----8<--- Aug 12 11:16:13 172.31.1.5 LasColinas-NS10: NetScreen Traffic Log: device_id=LasColinas-NS10 start_time="08/12/2002 11:09:21" src=172.30.8.76 dst=172.31.1.5 service=icmp proto=1 policy_id=18 direction=incoming duration=1 sent=96 rcvd=96 action=Tunnel (LC*Dal-VPN) icmp type=8 Aug 12 11:20:01 loghost01 fwlog input drop cleanup IN=ipsec0 OUT= Aug 12 11:11:04 loghost01 tac_plus[9564]: Read -1 bytes from 172.30.8.40 , expecting 12 (pause) Aug 12 11:20:01 loghost01 MAC=00:06:5b:84:60:7e:00:08:02:10:cb:a4:08:00 SRC=172.30.10.61 DST=172.30.8.40 LEN=275 TOS=0x00 PREC=0x00 TTL=134 ID=4745 DF PROTO=UDP SPT=514 DPT=514 LEN=255 Aug 12 11:20:01 172.31.1.5 LasColinas-NS10: NetScreen Traffic Log: device_id=LasColinas-NS10 start_time="08/12/2002 11:09:20" src=172.30.8.5 dst=172.31.1.5 service=icmp proto=1 policy_id=18 direction=incoming duration=1 sent=112 rcvd=112 action=Tunnel (LC*Dal-VPN) icmp type=8 ---8<-----(snip)-----8<---
If anyone has experienced this or has any other ideas that I may not have tried yet, any info you can provide would be most appreciated.
Thanks,
--- Dustin D. Trammell Information Security Specialist Penson Financial Services, Inc.
### Syslog-NG Config File
# Global Options options { chain_hostnames(no); use_dns(no); log_fifo_size(2000); log_msg_size(2048); sync(0); };
# Source Objects source s_local { internal(); }; source s_kmsg { file("/proc/kmsg"); }; source s_devlog { unix-stream("/dev/log" max-connections(150)); }; source s_udp514 { udp(); }; source s_tcp514 { tcp(ip("127.0.0.1") max-connections(150) keep-alive(yes)); }; source s_kernel { file("/proc/kmsg"); };
# Destination Objects destination d_varlog { file("/var/log/log"); }; destination d_tty8 { pipe("/dev/tty8"); }; destination d_logresp { pipe("/usr/local/logrespond/fifo/log" owner(logrespond) group(root) perm(0600) ); }; destination d_logtraq { pipe("/usr/local/logtraq/logpipe" owner(root) group(logtraq) perm(0640) ); };
# Log Paths log { source(s_local); source(s_kmsg); source(s_devlog); source(s_udp514); source(s_tcp514); source(s_kernel); destination(d_varlog); destination(d_tty8); destination(d_logresp); destination(d_logtraq); };
_______________________________________________ syslog-ng maillist - syslog-ng@lists.balabit.hu https://lists.balabit.hu/mailman/listinfo/syslog-ng Frequently asked questions at http://www.campin.net/syslog-ng/faq.html
On Mon, Aug 12, 2002 at 01:33:35PM -0500, Dustin Trammell wrote:
Has anyone else experienced syslog-ng occasionally pausing for a few minutes, immediately after logging one or more truncated entries? It usually pauses for anywhere from 1-10 minutes or so, and the process seems to be fine during this time (still bound to the port, doesn't appear to be zombied or using up all the CPU or memory, etc), then it continues after the pause as if nothing happened. The entry immediately after the pause is sometimes truncated also. The lines that are getting truncated appear to always be kernel log entries, more specifically from iptables, so I tried both using klogd as well as a file() source using /proc/kmsg, both with the same results. I saw a thread a few days ago about garbled/truncated entries, and what I got from that thread was to set the log_msg_size() option to something larger than the largest line your expecting. I set mine to 2048, and that still has not solved the problem, so I'm not sure if it's the same issue that has been discussed in the previous thread or something different. Below I've listed a few log entries (gathered from tail -f logfile), and my syslog-ng.conf file is appended below my sig.
You should not use klogd a file("/proc/kmsg") source at the same time. This might block syslog-ng _and_ clobber messages. (klogd and syslog-ng is racing for messages) Run one, or the other, but not both. -- Bazsi PGP info: KeyID 9AF8D0A9 Fingerprint CD27 CFB0 802C 0944 9CFD 804E C82C 8EB1
participants (3)
-
Balazs Scheidler
-
Caylan Van Larson
-
Dustin Trammell