I have an RV180 and am using the logging feature to log outgoing (LAN_WAN) packets which occur once a minute using an access rule. I'm emailing the logs once an hour. I've turned off all logging but debugging in the default logging policy. I've selected only "LAN (Local Network) to WAN (Internet)" "Accepted Packets" in the Routing Logs config page. The logging seems to work fine up until I get a WAN_PING event, even though I'm not logging any incoming packets. The WAN_PING log entry overwrites the current outgoing packet log, and then somehow corrupts the log buffer because the next hour's logging is disrupted and the next hour's emailed log is truncated. The RV180 isn't dropping packets that I can tell, but the log getting corrupted like this can't be a good thing.
When I view the logs in the web interface in real time, I never see the WAN_PING event. It does get injected into the emailed log on top of an expected log entry, however. That hour's log will be complete, with the inclusion of the WAN_PING event. But the next hour's logs are afected by the WAN_PING event. The system will log all outgoing packets until it gets to the time when the WAN_PING was recieved the previous hour, and then each subsequent log entry overwrites the next until the log is emailed at the end of the hour. The last outgoing packet log entry of the hour is included in the email log.
This is an example of the logging error. The first and last log entries shown are normal, as is the rest of that hour's log. The middle log entry is corrupted with the WAN_PING entry.
...
[fw]Sun Jun 23 21:25:55 2013(UTC) [fw][Kernel][KERNEL] [2965739.600000] LAN_WAN[ACCEPT]IN=bdg1 OUT=eth1 SRC=xxx.xxx.xxx.xxx DST=xxx.xxx.xxx.xxx LEN=44 TOS=0x00 PREC=0x00 TTL=253 ID=51743 DF PROTO=TCP SPT=xxxx DPT=xxxx WINDOW=2816 RES=0x00 SYN URGP=0 MAR=0x1
[fw]Sun Jun 23 21:26:45 2013(UTC) [fw][Kernel][KERNEL] [2965789.900000] WAN_PING[DROP]IN=eth1 OUT= DST MAC=xx:xx:xx:xx:xx:xx SRC MAC=xx:xx:xx:xx:xx:xx PAYLOAD TYPE=08:00 SRC=xxx.xxx.xxx.xxx DST=xxx.xxx.xxx.xxx LEN=61 TOS=0x00 PREC=0x00 TTL=112 ID=33016 PROTO=ICMP TYPE=8 CODE=0 ID=512 SEQ=46834 [fw]Sun Jun 23 21:26:45 2013(UTC) [fw][Kernel][KERNEL] [2965792.280000] WAN_PING[DROP]IN=eth1 OUT= DST MAC=xx:xx:xx:xx:xx:xx SRC MAC=xx:xx:xx:xx:xx:xx PAYLOAD TYPE=08:00 SRC=xxx.xxx.xxx.xxx DST=xxx.xxx.xxx.xxx LEN=61 TOS=0x00 PREC=0x00 TTL=112 ID=33236 PROTO=ICMP TYPE=8 CODE=0 ID=512 SEQ=36851 [fw]Sun Jun 23 21:26:55 2013(UTC) [fw][Kernel][KERNEL] [2965800.260000] LAN_WAN[ACCEPT]IN=bdg1 OUT=eth1 SRC=xxx.xxx.xxx.xxx DST=xxx.xxx.xxx.xxx LEN=44 TOS=0x00 PREC=0x00 TTL=253 ID=51748 DF PROTO=TCP SPT=xxxx DPT=xxxx WINDOW=2816 RES=0x00 SYN URGP=0 MAR=0x1
[fw]Sun Jun 23 21:27:55 2013(UTC) [fw][Kernel][KERNEL] [2965861.650000] LAN_WAN[ACCEPT]IN=bdg1 OUT=eth1 SRC=xxx.xxx.xxx.xxx DST=xxx.xxx.xxx.xxx LEN=44 TOS=0x00 PREC=0x00 TTL=253 ID=51752 DF PROTO=TCP SPT=xxxx DPT=xxxx WINDOW=2816 RES=0x00 SYN URGP=0 MAR=0x1
...
Once a WAN_PING event occurs, the next hour's log is truncated, starting at the time when the WAN_PING drop was logged during the previous hour. The normal log entries will be skipped in the emailed log, with only the last entry of the hour included. The WAN_PING event will be the last entry of the emailed log. If more than one WAN_PING is received as in this case, the second and following WAN_PING eventes are added to the end of the following hour's truncated log. While not shown here, those WAN_PING event log entries are not on their own line, but jumbled together on a single line as the original WAN_PING event shown above. Subsequent logs are OK until the next WAN_PING dropped packet is logged, and the pattern is repeated.
...
[fw]Sun Jun 23 22:23:53 2013(UTC) [fw][Kernel][KERNEL] [2969216.120000] LAN_WAN[ACCEPT]IN=bdg1 OUT=eth1 SRC=xxx.xxx.xxx.xxx DST=xxx.xxx.xxx.xxx LEN=44 TOS=0x00 PREC=0x00 TTL=253 ID=51995 DF PROTO=TCP SPT=xxxx DPT=xxxx WINDOW=2816 RES=0x00 SYN URGP=0 MAR=0x1
[fw]Sun Jun 23 23:01:27 2013(UTC) [fw][Kernel][KERNEL] [2971473.230000] LAN_WAN[ACCEPT]IN=bdg1 OUT=eth1 SRC=xxx.xxx.xxx.xxx DST=xxx.xxx.xxx.xxx LEN=44 TOS=0x00 PREC=0x00 TTL=253 ID=52157 DF PROTO=TCP SPT=xxxx DPT=xxxx WINDOW=2816 RES=0x00 SYN URGP=0 MAR=0x1
[fw]Sun Jun 23 21:26:45 2013(UTC) [fw][Kernel][KERNEL] [2965792.280000] WAN_PING[DROP]IN=eth1 OUT= DST MAC=xx:xx:xx:xx:xx:xx SRC MAC=xx:xx:xx:xx:xx:xx PAYLOAD TYPE=08:00 SRC=xxx.xxx.xxx.xxx DST=xxx.xxx.xxx.xxx LEN=61 TOS=0x00 PREC=0x00 TTL=112 ID=33236 PROTO=ICMP TYPE=8 CODE=0 ID=512 SEQ=36851
Is there a way to make this behavior stop?
--Mark
