Snort restarting every 15 mins
-
Looking in the system logs snort seems to be restarting every 15 mins :-
Apr 23 23:30:02 gw php: : [TDR DEBUG] S: 1177308000 E: 1177315200 N: 1177367402
Apr 23 23:30:02 gw php: : [TDR DEBUG] tdr_position(1,2,3,4,5) 1
Apr 23 23:30:02 gw php: : [SNORT] Snort_dynamic_ip_reload.php is starting.
Apr 23 23:30:02 gw php: : Dynamic WAN interface present. Restarting snort due to filter changes.
Apr 23 23:30:21 gw SnortStartup[72616]: Ram free BEFORE starting Snort: 22M – Ram free AFTER starting Snort: 22M -- Mode lowmem -- Snort memory usage:It looks like its triggered by some check on the dynamic WAN address (which never actually changes for what its worth).
Is this normal?
Regards
Ben
-
Upgrade to a recent snapshot. This was fixed yesterday.
-
I just upgraded, but now I see snort taking about 80 - 90 % of the CPU. And then after a few mins it crashes out due to running out of swap space.
Apr 25 23:28:16 kernel: xl0: promiscuous mode disabled
Apr 25 23:28:16 kernel: pid 4456 (snort), uid 0, was killed: out of swap space
Apr 25 23:28:09 kernel: swap_pager_getswapspace(3): failed
Apr 25 23:28:09 kernel: swap_pager_getswapspace(15): failed[SNIP]
Apr 25 23:28:06 kernel: swap_pager_getswapspace(10): failed
Apr 25 23:28:06 kernel: swap_pager_getswapspace(16): failed
Apr 25 23:24:45 SnortStartup[4605]: Ram free BEFORE starting Snort: 22M – Ram free AFTER starting Snort: 22M -- Mode ac-sparsebands -- Snort memory usage:
Apr 25 23:24:28 snort[4456]: Daemon initialized, signaled parent pid: 4454
Apr 25 23:24:28 snort[4456]: Daemon initialized, signaled parent pid: 4454
Apr 25 23:24:28 snort[4454]: Daemon parent exiting
Apr 25 23:24:28 snort[4454]: Daemon parent exiting
Apr 25 23:24:28 snort[4456]: Writing PID "4456" to file "/var/run//snort_xl0.pid"
Apr 25 23:24:28 snort[4456]: Writing PID "4456" to file "/var/run//snort_xl0.pid"
Apr 25 23:24:28 snort[4456]: PID path stat checked out ok, PID path set to /var/run/
Apr 25 23:24:28 snort[4456]: PID path stat checked out ok, PID path set to /var/run/
Apr 25 23:24:28 kernel: xl0: promiscuous mode enabled
Apr 25 23:24:28 snort[4454]: Initializing daemon mode
Apr 25 23:24:28 snort[4454]: Initializing daemon mode
Apr 25 23:24:28 kernel: xl0: promiscuous mode disabled
Apr 25 23:24:28 kernel: xl0: promiscuous mode enabled
Apr 25 23:24:27 snort[4454]: 285 out of 512 flowbits in use.
Apr 25 23:24:27 snort[4454]: 285 out of 512 flowbits in use.Seems to be some double logging going on as well there during part of it.
BTW. How do I tail the system log. It seems to have a chunk of binary in it (CLOG followed by binary), and then it seems I can only view it via the web interface. ls -l suggests it not getting any bigger either.
[EDIT]: I just reverted back to 1.2-BETA-1-PRERELEASE-SNAPSHOT-04-21-07 which is what I was running when I made the first post. I just checked and actually it turns out that although snort shows as what looks like re-starting every 15 mins it must crash without leaving anything in the logs as its not actually running when I do a PS. It must just be pure luck then that it does capture some stuff during the small time its running, because the snort alerts view does have some entries in it.
[EDIT 2]: Actually I think this is a memory issue, I just reduced the number of rules and it seems to be running fine now under 1.2-BETA-1-PRERELEASE-SNAPSHOT-04-23-07 . I think maybe I got carried away with the rules somewhere along the lines, so the alerts I saw in the 04-21 release where before I enabled extra rules. I'm going to get some more memory for the machine and then I can confirm this.
Regards
Ben
-
Ok, one ebay purchase later, I have upgraded the memory to the max for this system. Its now at 512M. So I don't think its a memory issue anymore, oh and for this test I am only running one set of rules. web-attack.rules
I'm running 1.2-BETA-1-PRERELEASE-SNAPSHOT-04-23-07, I removed the snort package, and re-installed it.
It looks like its still restarting every 15 mins :-
Apr 30 18:30:03 gw php: : [SNORT] Snort_dynamic_ip_reload.php is starting.
Apr 30 18:30:03 gw php: : Dynamic WAN interface present. Restarting snort due to filter changes.
Apr 30 18:30:03 gw snort2c[4417]: SIGTERM received - exiting
Apr 30 18:30:03 gw snort2c[4417]: SIGTERM received - exiting
Apr 30 18:30:03 gw kernel: xl0: promiscuous mode disabled
Apr 30 18:30:03 gw snort[4236]: *** Caught Term-Signal
Apr 30 18:30:03 gw snort[4236]: *** Caught Term-Signal
Apr 30 18:30:03 gw snort[4236]: Final Flow Statistics
Apr 30 18:30:03 gw snort[4236]: Final Flow Statistics
Apr 30 18:30:03 gw snort[4236]: ,–--[ FLOWCACHE STATS ]–--------
Apr 30 18:30:03 gw snort[4236]: ,–--[ FLOWCACHE STATS ]–--------
Apr 30 18:30:03 gw snort[4236]: Memcap: 10485760 Overhead Bytes 16400 used(%0.359545)/blocks (37701/120) Overhead blocks: 1 Could Hold: (58579)
Apr 30 18:30:03 gw snort[4236]: Memcap: 10485760 Overhead Bytes 16400 used(%0.359545)/blocks (37701/120) Overhead blocks: 1 Could Hold: (58579)
Apr 30 18:30:03 gw snort[4236]: IPV4 count: 119 frees: 0 low_time: 1177953425, high_time: 1177954202, diff: 0h:12:57s
Apr 30 18:30:03 gw snort[4236]: IPV4 count: 119 frees: 0 low_time: 1177953425, high_time: 1177954202, diff: 0h:12:57s
Apr 30 18:30:03 gw snort[4236]: finds: 8523 reversed: 5393(%0.000000) find_success: 8404 find_fail: 119 percent_success: (%0.000000) new_flows: 119
Apr 30 18:30:03 gw snort[4236]: finds: 8523 reversed: 5393(%0.000000) find_success: 8404 find_fail: 119 percent_success: (%0.000000) new_flows: 119
Apr 30 18:30:03 gw snort[4236]: Protocol: 1 (%0.000000) finds: 130 reversed: 65(%0.000000) find_success: 129 find_fail: 1 percent_success: (%0.000000) new_flows: 1
Apr 30 18:30:03 gw snort[4236]: Protocol: 1 (%0.000000) finds: 130 reversed: 65(%0.000000) find_success: 129 find_fail: 1 percent_success: (%0.000000) new_flows: 1
Apr 30 18:30:03 gw snort[4236]: Protocol: 6 (%0.000000) finds: 7917 reversed: 5186(%0.000000) find_success: 7859 find_fail: 58 percent_success: (%0.000000) new_flows: 58
Apr 30 18:30:03 gw snort[4236]: Protocol: 6 (%0.000000) finds: 7917 reversed: 5186(%0.000000) find_success: 7859 find_fail: 58 percent_success: (%0.000000) new_flows: 58
Apr 30 18:30:03 gw snort[4236]: Protocol: 17 (%0.000000) finds: 452 reversed: 130(%0.000000) find_success: 393 find_fail: 59 percent_success: (%0.000000) new_flows: 59
Apr 30 18:30:03 gw snort[4236]: Protocol: 17 (%0.000000) finds: 452 reversed: 130(%0.000000) find_success: 393 find_fail: 59 percent_success: (%0.000000) new_flows: 59
Apr 30 18:30:03 gw snort[4236]: Protocol: 50 (%0.000000) finds: 24 reversed: 12(%0.000000) find_success: 23 find_fail: 1 percent_success: (%0.000000) new_flows: 1
Apr 30 18:30:03 gw snort[4236]: Protocol: 50 (%0.000000) finds: 24 reversed: 12(%0.000000) find_success: 23 find_fail: 1 percent_success: (%0.000000) new_flows: 1
Apr 30 18:30:03 gw snort[4236]: Snort received 21683 packets
Apr 30 18:30:03 gw snort[4236]: Snort received 21683 packets
Apr 30 18:30:03 gw snort[4236]: Analyzed: 21673(99.954%)
Apr 30 18:30:03 gw snort[4236]: Analyzed: 21673(99.954%)
Apr 30 18:30:03 gw snort[4236]: Dropped: 0(0.000%)
Apr 30 18:30:03 gw snort[4236]: Dropped: 0(0.000%)
Apr 30 18:30:03 gw snort[4236]: Outstanding: 10(0.046%)
Apr 30 18:30:03 gw snort[4236]: Outstanding: 10(0.046%)
Apr 30 18:30:03 gw snort[4236]: ===============================================================================
Apr 30 18:30:03 gw snort[4236]: ===============================================================================
Apr 30 18:30:03 gw snort[4236]: Breakdown by protocol:
Apr 30 18:30:03 gw snort[4236]: Breakdown by protocol:
Apr 30 18:30:03 gw snort[4236]: TCP: 6196 (28.589%)
Apr 30 18:30:03 gw snort[4236]: TCP: 6196 (28.589%)
Apr 30 18:30:03 gw snort[4236]: UDP: 452 (2.086%)
Apr 30 18:30:03 gw snort[4236]: UDP: 452 (2.086%)
Apr 30 18:30:03 gw snort[4236]: ICMP: 130 (0.600%)
Apr 30 18:30:03 gw snort[4236]: ICMP: 130 (0.600%)
Apr 30 18:30:03 gw snort[4236]: ARP: 14871 (68.615%)
Apr 30 18:30:03 gw snort[4236]: ARP: 14871 (68.615%)
Apr 30 18:30:03 gw snort[4236]: EAPOL: 0 (0.000%)
Apr 30 18:30:03 gw snort[4236]: EAPOL: 0 (0.000%)
Apr 30 18:30:03 gw snort[4236]: IPv6: 0 (0.000%)
Apr 30 18:30:03 gw snort[4236]: IPv6: 0 (0.000%)
Apr 30 18:30:03 gw snort[4236]: ETHLOOP: 0 (0.000%)
Apr 30 18:30:03 gw snort[4236]: ETHLOOP: 0 (0.000%)
Apr 30 18:30:03 gw snort[4236]: IPX: 0 (0.000%)
Apr 30 18:30:03 gw snort[4236]: IPX: 0 (0.000%)
Apr 30 18:30:03 gw snort[4236]: FRAG: 0 (0.000%)
Apr 30 18:30:03 gw snort[4236]: FRAG: 0 (0.000%)
Apr 30 18:30:03 gw snort[4236]: OTHER: 24 (0.111%)
Apr 30 18:30:03 gw snort[4236]: OTHER: 24 (0.111%)
Apr 30 18:30:03 gw snort[4236]: DISCARD: 0 (0.000%)
Apr 30 18:30:03 gw snort[4236]: DISCARD: 0 (0.000%)
Apr 30 18:30:03 gw snort[4236]: ===============================================================================
Apr 30 18:30:03 gw snort[4236]: ===============================================================================
Apr 30 18:30:03 gw snort[4236]: Action Stats:
Apr 30 18:30:03 gw snort[4236]: Action Stats:
Apr 30 18:30:03 gw snort[4236]: ALERTS: 1
Apr 30 18:30:03 gw snort[4236]: ALERTS: 1
Apr 30 18:30:03 gw snort[4236]: LOGGED: 1
Apr 30 18:30:03 gw snort[4236]: LOGGED: 1
Apr 30 18:30:03 gw snort[4236]: PASSED: 0
Apr 30 18:30:03 gw snort[4236]: PASSED: 0
Apr 30 18:30:03 gw snort[4236]: ===============================================================================
Apr 30 18:30:03 gw snort[4236]: ===============================================================================
Apr 30 18:30:03 gw snort[4236]: TCP Stream Reassembly Stats:
Apr 30 18:30:03 gw snort[4236]: TCP Stream Reassembly Stats:
Apr 30 18:30:03 gw snort[4236]: TCP Packets Used: 6196 (28.589%)
Apr 30 18:30:03 gw snort[4236]: TCP Packets Used: 6196 (28.589%)
Apr 30 18:30:03 gw snort[4236]: Stream Trackers: 107
Apr 30 18:30:03 gw snort[4236]: Stream Trackers: 107
Apr 30 18:30:03 gw snort[4236]: Stream flushes: 1721
Apr 30 18:30:03 gw snort[4236]: Stream flushes: 1721
Apr 30 18:30:03 gw snort[4236]: Segments used: 3762
Apr 30 18:30:03 gw snort[4236]: Segments used: 3762
Apr 30 18:30:03 gw snort[4236]: Segments Queued: 3829
Apr 30 18:30:03 gw snort[4236]: Segments Queued: 3829
Apr 30 18:30:03 gw snort[4236]: Stream4 Memory Faults: 0
Apr 30 18:30:03 gw snort[4236]: Stream4 Memory Faults: 0
Apr 30 18:30:03 gw snort[4236]: ===============================================================================
Apr 30 18:30:03 gw snort[4236]: ===============================================================================
Apr 30 18:30:03 gw snort[4236]: Snort exiting
Apr 30 18:30:03 gw snort[4236]: Snort exiting
Apr 30 18:30:22 gw SnortStartup[6597]: Ram free BEFORE starting Snort: 60M – Ram free AFTER starting Snort: 60M -- Mode ac-sparsebands -- Snort memory usage:
Apr 30 18:45:03 gw php: : [SNORT] Snort_dynamic_ip_reload.php is starting.
Apr 30 18:45:03 gw php: : Dynamic WAN interface present. Restarting snort due to filter changes.
Apr 30 18:45:22 gw SnortStartup[8764]: Ram free BEFORE starting Snort: 60M – Ram free AFTER starting Snort: 60M -- Mode ac-sparsebands -- Snort memory usage:
Apr 30 19:00:03 gw php: : [SNORT] Snort_dynamic_ip_reload.php is starting.
Apr 30 19:00:03 gw php: : Dynamic WAN interface present. Restarting snort due to filter changes.
Apr 30 19:00:22 gw SnortStartup[10878]: Ram free BEFORE starting Snort: 60M – Ram free AFTER starting Snort: 60M -- Mode ac-sparsebands -- Snort memory usage:I also notice that snort is not actually running when I check. It looks like the first restart does really kill it, and then all the other ones never get is going again.
Is there anything else I should try, or any other info I can provide to help track down the issue?
Regards
Ben
-
Upgrade to 1.2-BETA-1. This was fixed in the last few days.
-
Just after I posted I noticed 1.2-BETA-1 was out. So I upgraded, but need to wait an hour or so to check its working. I had planned to post back as soon as I had tested it.
Ben
-
Sadly it seems that its still doing it in 1.2-BETA-1 :-
Apr 30 20:45:03 gw php: : [SNORT] Snort_dynamic_ip_reload.php is starting.
Apr 30 20:45:03 gw php: : Dynamic WAN interface present. Restarting snort due to filter changes.
Apr 30 20:45:03 gw snort[4048]: *** Caught Term-Signal
Apr 30 20:45:03 gw snort[4048]: *** Caught Term-Signal
Apr 30 20:45:03 gw snort[4048]: Final Flow Statistics
Apr 30 20:45:03 gw snort[4048]: Final Flow Statistics
Apr 30 20:45:03 gw snort[4048]: ,–--[ FLOWCACHE STATS ]–--------
Apr 30 20:45:03 gw snort[4048]: ,–--[ FLOWCACHE STATS ]–--------
[SNIP]
Apr 30 20:45:03 gw snort[4048]: Stream Trackers: 12
Apr 30 20:45:03 gw snort[4048]: Stream flushes: 8
Apr 30 20:45:03 gw snort[4048]: Stream flushes: 8
Apr 30 20:45:03 gw snort[4048]: Segments used: 12
Apr 30 20:45:03 gw snort[4048]: Segments used: 12
Apr 30 20:45:03 gw snort[4048]: Segments Queued: 14
Apr 30 20:45:03 gw snort[4048]: Segments Queued: 14
Apr 30 20:45:03 gw snort[4048]: Stream4 Memory Faults: 0
Apr 30 20:45:03 gw snort[4048]: Stream4 Memory Faults: 0
Apr 30 20:45:03 gw snort[4048]: ===============================================================================
Apr 30 20:45:03 gw snort[4048]: ===============================================================================
Apr 30 20:45:03 gw kernel: xl0: promiscuous mode disabled
Apr 30 20:45:03 gw snort[4048]: Snort exiting
Apr 30 20:45:03 gw snort[4048]: Snort exiting
Apr 30 20:45:22 gw SnortStartup[4636]: Ram free BEFORE starting Snort: 318M – Ram free AFTER starting Snort: 317M -- Mode ac-sparsebands -- Snort memory usage:
Apr 30 21:00:03 gw php: : [SNORT] Snort_dynamic_ip_reload.php is starting.
Apr 30 21:00:03 gw php: : Dynamic WAN interface present. Restarting snort due to filter changes.
Apr 30 21:00:23 gw SnortStartup[6619]: Ram free BEFORE starting Snort: 317M – Ram free AFTER starting Snort: 316M -- Mode ac-sparsebands -- Snort memory usage:
Apr 30 21:15:03 gw php: : [SNORT] Snort_dynamic_ip_reload.php is starting.
Apr 30 21:15:03 gw php: : Dynamic WAN interface present. Restarting snort due to filter changes.
Apr 30 21:15:22 gw SnortStartup[8522]: Ram free BEFORE starting Snort: 316M – Ram free AFTER starting Snort: 316M -- Mode ac-sparsebands -- Snort memory usage:
Apr 30 21:30:03 gw php: : [SNORT] Snort_dynamic_ip_reload.php is starting.
Apr 30 21:30:03 gw php: : Dynamic WAN interface present. Restarting snort due to filter changes.
Apr 30 21:30:22 gw SnortStartup[10475]: Ram free BEFORE starting Snort: 316M – Ram free AFTER starting Snort: 316M -- Mode ac-sparsebands -- Snort memory usage:Regards
Ben
-
I need to see the log files prior where it says that the ip is different.
-
Now there is the interesting thing. The IP does not change, and there is nothing in the logs about it changing.
I have emailed you the entire log file.
Regards
Ben
-
Okay, I found the problem. Please uninstall and reinstall snort 10+ minutes from this post.
-
Well done, thats sorted it out :)
Thanks very much
Ben