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


Log in to reply