Snort 2.9.6.2 pkg v3.1.2 not logging Alerts

bmeeks

I just came in a few minutes ago and one of the three interfaces was stopped. Not sure when that happened.

The system has 8 G of ram, AMD64, relatively low traffic and Snort runs with the default AC-BNFA on each of the three interfaces. I will try the -NQ option and see if that makes a difference. Do you know if anyone has put together a chart showing the pattern options vs system requirements with actual numbers?

How do I increase the logging level so I can get a better idea what is actually going on with snort itself?

I just looked at the system.log and it is flooded with this:
barnyard2[68596]: ERROR: Unable to open directory '/var/log/snort/snort_em145093' (No such file or directory)

I checked and indeed it doesn't exist.

I shut down snort and the messages continued to flood syslog. Ran top and found a barnyard2 process running even after shutting down snort. Killed that process and the log entries stopped. WTF?

BAM

On occasion, there can exist a sort of zombie Barnyard2 or Snort process. One way I've seen this happen is if the processes are in the midst of auto-starting following a reboot or package re-install, and the user manually clicks restart in the GUI as well. This can result in multiple processes with the same sub-directory arguments. That will lead to crashes and other issues if the two processes were to collide say trying to write to the same files. I'm not saying you manually clicked start, but I know it has happened to others. Be patient when waiting for a restart. You can navigate away from the tab and come back to refresh the screen. With large rule sets, Snort can take up to 60 seconds or so to load on even an i5-equivalent box. On something like an Atom or less that process could be longer.

There were also some problems long ago with the pfSense packages restart logic that fires on a reboot causing a "double-start" of Barnyard and sometimes Snort. I am reasonably sure those problems have all been fixed by some protections coded into the Snort scripts.

There is no way to increase the logging verbosity of Snort. Due to user demand from the past, the logging was trimmed down to just obvious fatal errors.

Bill

highlandpeak

Are Atom processors AMD64 based?

From phpsysinfo:
Processors 4
Model AMD Phenom II X4 965 Processor
CPU Speed 3.42 GHz
Memory Usage 27% of 7.98 GB

Not mega as some would say but it s/b sufficient for the purpose.

No user error as to rushing to click on interface start button. I recognize that Sort takes quite a while to fully start.

I would propose that a bug has been introduced on update of patterns. I have switched off auto updates so I can monitor the process and indeed the update script tries to do a SOFT RESTART which fails silently on the second interface irrespective of whether 2 or 3 interfaces are used. The first and third interfaces do a START and succeed.

Relevant log excerpt:
Sep 1 10:35:02 SnortStartup[51964]: Barnyard2 START for WAN(52403_em1)…
Sep 1 10:34:40 SnortStartup[27511]: Snort START for WAN(52403_em1)…
Sep 1 10:34:40 SnortStartup[26824]: Barnyard2 SOFT RESTART for OPT1(53598_re0)…
Sep 1 10:34:38 SnortStartup[26014]: Snort SOFT RESTART for OPT1(53598_re0)…
Sep 1 10:34:32 SnortStartup[22871]: Barnyard2 START for LAN(53598_em0)…
Sep 1 10:34:10 SnortStartup[15603]: Snort START for LAN(53598_em0)…

BAM

bmeeks

@highlandpeak:

Are Atom processors AMD64 based?

From phpsysinfo:
Processors 4
Model AMD Phenom II X4 965 Processor
CPU Speed 3.42 GHz
Memory Usage 27% of 7.98 GB

Not mega as some would say but it s/b sufficient for the purpose.

No user error as to rushing to click on interface start button. I recognize that Sort takes quite a while to fully start.

I would propose that a bug has been introduced on update of patterns. I have switched off auto updates so I can monitor the process and indeed the update script tries to do a SOFT RESTART which fails silently on the second interface irrespective of whether 2 or 3 interfaces are used. The first and third interfaces do a START and succeed.

Relevant log excerpt:
Sep 1 10:35:02 SnortStartup[51964]: Barnyard2 START for WAN(52403_em1)…
Sep 1 10:34:40 SnortStartup[27511]: Snort START for WAN(52403_em1)…
Sep 1 10:34:40 SnortStartup[26824]: Barnyard2 SOFT RESTART for OPT1(53598_re0)…
Sep 1 10:34:38 SnortStartup[26014]: Snort SOFT RESTART for OPT1(53598_re0)…
Sep 1 10:34:32 SnortStartup[22871]: Barnyard2 START for LAN(53598_em0)…
Sep 1 10:34:10 SnortStartup[15603]: Snort START for LAN(53598_em0)…

BAM

Thank you for the extra troubleshooting information, but some of what you said confuses me – specifically this statement:

I have switched off auto updates so I can monitor the process and indeed the update script tries to do a SOFT RESTART which fails silently on the second interface irrespective of whether 2 or 3 interfaces are used.

If you disable auto-updates in the GUI by setting the drop-down to "NEVER", then the cron job should be killed that performs the auto update for ALL interfaces. The auto-update is an all-or-none proposition. So if you are confident the process is actually still auto-updating, then you have a sort of zombie cron task out there; or possibly you are a victim of an older bug where two cron tasks got created for doing the rule updates. If this bug affected you, then one of the processes would not get killed by disabling from within the GUI. But I was pretty sure that bug was fixed. It was like two or maybe three versions back.

Can you use Diagnostics…Edit File and load and capture the contents of this file, then post them here?

/etc/crontab

Bill

highlandpeak

The word manual was implied but not stated. By turning off the auto update I can monitor the process when I choose to run an update. This can be accomplished by clicking on check for update or force.

BAM

bmeeks

@highlandpeak:

The word manual was implied but not stated. By turning off the auto update I can monitor the process when I choose to run an update. This can be accomplished by clicking on check for update or force.

BAM

Ah…OK. The end of the update process will, if Snort is running, restart all the configured interfaces via the shell script at /usr/local/etc/rc.d/snort.sh. The fact you are getting a SOFT RESTART on one interface versus a COLD RESTART on the others makes me think you may have a zombie process out there with a matching PID file.

From the SERVICES menu, click the icon to stop Snort. Once it indicates stopped, go to the console command line (or via SSH) and execute this command–

ps -ax |grep snort

It should not show any active snort or barnyard2 processes. If you see any, kill them. Restart Snort and let me know if you see the behavior repeat.

Bill

highlandpeak

This is the result from the initial run of ps:

$ ps -ax |grep snort
22306 ?? Ss 1:26.71 /usr/pbi/snort-amd64/bin/snort -R 53598 -D -q -l /var
25712 ?? Ss 0:03.21 /usr/local/bin/barnyard2 -r 53598 -f snort_53598_em0.
49145 ?? Ss 1:31.61 /usr/pbi/snort-amd64/bin/snort -R 52403 -D -q -l /var
58545 ?? Ss 0:03.39 /usr/local/bin/barnyard2 -r 52403 -f snort_52403_em1.
76438 ?? S 0:00.00 sh -c ps -ax |grep snort 2>&1
76848 ?? Ss 0:02.88 /usr/pbi/snort-amd64/bin/snort -R 53598 -D -q -l /var
76881 ?? S 0:00.00 grep snort
78607 ?? Ss 0:03.18 /usr/local/bin/barnyard2 -r 53598 -f snort_53598_re0.

And, after killall barnyard2:

$ ps -ax |grep snort
22306 ?? Ss 1:26.73 /usr/pbi/snort-amd64/bin/snort -R 53598 -D -q -l /var
49145 ?? Ss 1:31.63 /usr/pbi/snort-amd64/bin/snort -R 52403 -D -q -l /var
76848 ?? Ss 0:02.88 /usr/pbi/snort-amd64/bin/snort -R 53598 -D -q -l /var
93536 ?? S 0:00.00 sh -c ps -ax |grep snort 2>&1
93846 ?? S 0:00.00 grep snort

See attached log file for this time frame.

After restarting Snort using the restart button on Status|Services, OPT1 does not start.

(Ignore the PIDs in this next ps -ax, because I ran it after I ran everything else in this post and they are as a result somewhat misleading)

$ ps -ax |grep snort
17420 ?? Ss 0:00.01 /usr/pbi/snort-amd64/bin/snort -R 53598 -D -q -l /var
21480 ?? Ss 0:00.00 /usr/local/bin/barnyard2 -r 53598 -f snort_53598_em0.
30028 ?? Ss 0:00.02 /usr/pbi/snort-amd64/bin/snort -R 52403 -D -q -l /var
34942 ?? Ss 0:00.00 /usr/local/bin/barnyard2 -r 52403 -f snort_52403_em1.
71585 ?? S 0:00.00 sh -c ps -ax |grep snort 2>&1
72041 ?? S 0:00.00 grep snort

Manually starting the OPT1 interface yields this:

$ ps -ax |grep snort
25928 ?? Ss 0:00.03 /usr/pbi/snort-amd64/bin/snort -R 53598 -D -q -l /var
43395 ?? Ss 0:00.04 /usr/local/bin/barnyard2 -r 53598 -f snort_53598_re0.
53381 ?? Ss 0:00.11 /usr/pbi/snort-amd64/bin/snort -R 53598 -D -q -l /var
57386 ?? Ss 0:00.05 /usr/local/bin/barnyard2 -r 53598 -f snort_53598_em0.
70663 ?? S 0:00.00 sh -c ps -ax |grep snort 2>&1
71022 ?? S 0:00.00 grep snort
80683 ?? Ss 0:00.14 /usr/pbi/snort-amd64/bin/snort -R 52403 -D -q -l /var
84848 ?? Ss 0:00.06 /usr/local/bin/barnyard2 -r 52403 -f snort_52403_em1.

After killall barnyard2 again:

$ ps -ax |grep snort
25928 ?? Ss 0:00.04 /usr/pbi/snort-amd64/bin/snort -R 53598 -D -q -l /var
38938 ?? S 0:00.00 sh -c ps -ax |grep snort 2>&1
39161 ?? S 0:00.00 grep snort
53381 ?? Ss 0:00.12 /usr/pbi/snort-amd64/bin/snort -R 53598 -D -q -l /var
80683 ?? Ss 0:00.17 /usr/pbi/snort-amd64/bin/snort -R 52403 -D -q -l /var

After stopping snort:

$ ps -ax |grep snort
7621 ?? S 0:00.00 sh -c ps -ax |grep snort 2>&1
7977 ?? S 0:00.00 grep snort

Starting Snort through the services menu fails to start OPT1 and logs a SOFT RESTART for OPT1:

Sep 2 16:20:39 SnortStartup[66406]: Barnyard2 START for WAN(52403_em1)…
Sep 2 16:20:17 SnortStartup[55725]: Snort START for WAN(52403_em1)…
Sep 2 16:20:17 SnortStartup[55099]: Barnyard2 SOFT RESTART for OPT1(53598_re0)…
Sep 2 16:20:15 SnortStartup[53888]: Snort SOFT RESTART for OPT1(53598_re0)…

And also:

$ ps -ax |grep snort
50023 ?? Ss 0:00.02 /usr/pbi/snort-amd64/bin/snort -R 53598 -D -q -l /var
53410 ?? Ss 0:00.01 /usr/local/bin/barnyard2 -r 53598 -f snort_53598_em0.
63578 ?? S 0:00.00 sh -c ps -ax |grep snort 2>&1
63891 ?? S 0:00.00 grep snort
64664 ?? Ss 0:00.03 /usr/pbi/snort-amd64/bin/snort -R 52403 -D -q -l /var
70107 ?? Ss 0:00.01 /usr/local/bin/barnyard2 -r 52403 -f snort_52403_em1.

This is a clean install and I have made no modifications to the system other than through the GUI. I did partially restore from backup some of the settings - things like nat and aliases, fwiw.

BAM

system.log.txt

highlandpeak

Ok, now after actually killing barnyard, stopping snort and then starting snort like you said (/usr/local/etc/rc.d/snort.sh), I do get this:

$ ps -ax |grep snort
17420 ?? Ss 0:00.08 /usr/pbi/snort-amd64/bin/snort -R 53598 -D -q -l /var
30028 ?? Ss 0:00.10 /usr/pbi/snort-amd64/bin/snort -R 52403 -D -q -l /var
45098 ?? S 0:00.00 sh -c ps -ax |grep snort 2>&1
45574 ?? S 0:00.00 grep snort

But on the status page OPT1 is not running, nor is barnyard on any of the interfaces.

Clicking on the OPT1 Snort icon to start the interface results in a correct start and also for the previously stopped barnyard2 service for OPT1 only.

After manually starting barnyard on the other twoi interfaces:
$ ps -ax |grep snort
17420 ?? Ss 0:00.12 /usr/pbi/snort-amd64/bin/snort -R 53598 -D -q -l /var
30028 ?? Ss 0:00.18 /usr/pbi/snort-amd64/bin/snort -R 52403 -D -q -l /var
44352 ?? Ss 0:00.00 /usr/local/bin/barnyard2 -r 52403 -f snort_52403_em1.
66818 ?? S 0:00.00 sh -c ps -ax |grep snort 2>&1
67147 ?? S 0:00.00 grep snort
92410 ?? Ss 0:00.00 /usr/local/bin/barnyard2 -r 53598 -f snort_53598_em0.
95130 ?? Ss 0:00.01 /usr/pbi/snort-amd64/bin/snort -R 53598 -D -q -l /var
98270 ?? Ss 0:00.01 /usr/local/bin/barnyard2 -r 53598 -f snort_53598_re0.

BAM

bmeeks

This is puzzling. I'm trying to think of possible causes. Here is what you should generally see, a pair of matching Snort and Barnyard2 processes for each enabled interface:

 9811  ??  Ss     4:27.56 /usr/local/bin/barnyard2 -r 59991 -f snort_59991_em0.
15888  ??  SNs    2:19.38 /usr/pbi/snort-amd64/bin/snort -R 59991 -D -q -l /var
20434  ??  SNs    0:05.51 /usr/pbi/snort-amd64/bin/snort -R 5104 -D -q -l /var/
23865  ??  SNs    5:57.22 /usr/local/bin/barnyard2 -r 5104 -f snort_5104_em2.u2
29040  ??  SNs    6:41.15 /usr/local/bin/barnyard2 -r 61640 -f snort_61640_em1.
29640  ??  SNs    6:23.39 /usr/pbi/snort-amd64/bin/snort -R 61640 -D -q -l /var

Notice above the following number pairs: 59991, 5104 and 61640. Those are the UUIDs that Snort generates to uniquely identify each interface. So in the example above from my firewall, you see three pairs of identical UUIDs showing I have Snort and Barnyard2 running on three interfaces. So something like the above is what you expect to see (although obviously your UUID numbers may differ).

Go into the GUI for Snort and click the "e" edit icon beside any interface. On the page that opens, just scroll to the bottom and click SAVE. That will generate a new snort.sh script for all interfaces. This will make sure that file is good.

One other thing just popped in my mind – is this a NanoBSD install or a full install? Also, did you by chance alter the NIC cards in the box or otherwise edit the interfaces? Just wondering because your first messages about a missing directory indicate a fundamental configuration change somewhere. Remember what I said the UUIDs were for: uniquely identifying Snort interfaces. What happened to the interface with UUID 45093? When you did the "partial restore" you mentioned, it's possible that brought in some old interface data such that now the Snort configuration is inconsistent with reality on your box.

I know you might now want to hear this, but your best chance for a fix is to remove Snort and its current configuration completely. You do this by going to GLOBAL SETTINGS and unchecking the box to "save settings when removing Snort". This will wipe the current Snort config when you delete the package on the System…Packages...Installed Packages menu. You could run through the screens and jot down any particular settings you want back in the event you deviated from the defaults. If you do indeed have a muddled config for Snort, then each time you remove and reinstall the package it will be picking up that same muddled config unless you uncheck that box and start from scratch.

Bill

highlandpeak

OK, groundhog day. Been there done that, but I did it again because this is so fun.

I have now uninstalled Snort for the umpteenth time. This time verifying that it would delete settings on uninstall.

So, I uninstalled snort, checked for zombies, rebooted, checked for zombies, installed snort, checked for zombies, configured and started WAN, checked for processes and indeed the PIDs matched. Created LAN and OPT1 using same settings as WAN, then started each interface. PIDs were matching.

$ ps -ax |grep snort
62118 ?? S 0:00.00 sh -c ps -ax |grep snort 2>&1
62344 ?? S 0:00.00 grep snort
72185 ?? Ss 0:00.03 /usr/pbi/snort-amd64/bin/snort -R 42630 -D -q -l /var
75913 ?? Ss 0:00.01 /usr/local/bin/barnyard2 -r 42630 -f snort_42630_em1.

Log file complained of corrupted WALDO. See attached file.

Created LAN and OPT1 using same settings as WAN, then started each interface. PIDs were matching.

Checked for zombies - can't be too careful with all the zombies here in Atlanta.

Forced update for patterns, WAN started on its own, not so for both LAN & OPT1. Waited several minutes and in the mean time checked logs and found references to soft restart for LAN & OPT1.

Started LAN & OPT manually. And…

$ ps -ax |grep snort
43616 ?? Ss 0:00.03 /usr/pbi/snort-amd64/bin/snort -R 42630 -D -q -l /var
48172 ?? Ss 0:00.00 /usr/local/bin/barnyard2 -r 42630 -f snort_42630_em0.
72185 ?? Ss 0:00.16 /usr/pbi/snort-amd64/bin/snort -R 42630 -D -q -l /var
75913 ?? Ss 0:00.02 /usr/local/bin/barnyard2 -r 42630 -f snort_42630_em1.
93276 ?? Ss 0:00.00 /usr/pbi/snort-amd64/bin/snort -R 42630 -D -q -l /var
94472 ?? Ss 0:00.00 /usr/local/bin/barnyard2 -r 42630 -f snort_42630_re0.
98519 ?? S 0:00.00 sh -c ps -ax |grep snort 2>&1
98849 ?? S 0:00.00 grep snort

At this point it seems rather obvious that there is a bug(s). Restart does not seem to be the correct way of handling starting after update. Why use START on WAN and RESTART on LAN & WAN?

WAN works but LAN & OPT1 don't.

Oh, btw, as you might have noticed now both LAN & OPT1 won't start after updates instead of just the OPT1.

So, unless you have anything to offer to the contrary, I will write this off as a buggy implementation and move on.

Thanks for all your time.

BAM

PS: Oh, for the love of ((^$#! Now the friggin interface is not logging alerts!

system.log2.txt

BBcan177

What memory setting are you using? Use "AC-BNFA-NQ" as the pattern matcher. Maybe you are running out of memory and it's causing the other interfaces to crash?

highlandpeak

I had thought early on that it was memory problem and have been using AC-BNFA-NQ.

BAM

highlandpeak

Here are a couple of observations:

It appears that I have (possibly) solved the restart problem. It relates to how the 2nd & 3rd interfaces are added. If I click on the top most + button to create the interfaces instead of the one at the end of the WAN line - I see no SOFT RESTART on update but rather a START. More importantly the interfaces continue to run without intervention.

Logging fails if WAN IP rep is enabled. Resumes if it is disabled.

BAM

BBcan177

Did you enable IP rep on all interfaces? It should only be enabled on the WAN interface. Unless I am reading your last post incorrectly.

highlandpeak

Logging was a separate issue from the interfaces failing. But yes I had enabled it on all interfaces.

I have reenabled it on WAN only and for the moment it appears to be working.

Thanks for the tip!

Where did this info come from, experience or is there somewhere you could point to with useful tidbits like this? The help link on the config page comes up empty.

BAM

Guest

btw did you do a fresh install of your pfSense and restored your config? Might have saved you some time, if not…

highlandpeak

I did, but I had problems with the process. The MB had some quirks that made it difficult to get it to recognize the thumb drives for the install which took multiple tries before I had success.

Or… too much espresso.

I restored only some of the config and manually recreated the rest.

This was somewhat ok because I couldn't tell what the root problem was before embarking on the reinstall process and I couldn't be sure that it wouldn't preserve the garbage after restoration. So I took a conservative route and restored only the more PIA things.

BAM

bmeeks

@highlandpeak:

Here are a couple of observations:

It appears that I have (possibly) solved the restart problem. It relates to how the 2nd & 3rd interfaces are added. If I click on the top most + button to create the interfaces instead of the one at the end of the WAN line - I see no SOFT RESTART on update but rather a START. More importantly the interfaces continue to run without intervention.

Logging fails if WAN IP rep is enabled. Resumes if it is disabled.

BAM

Thanks! This may be the key observation. I need to look further into the new code added to support the + button at the right end of each interface line. That button is supposed to "clone" the interface onto a new available physical interface but then change the UUID and directory paths. Perhaps there is a subtle bug living in that code. It is new with either this 3.1.2 version or it came out with 3.1.1 (don't remember at the moment while I'm typing this).

The + button at the upper right top row creates a totally new interface from scratch (no clone basis). The new + button to the right of each configured interface line is meant to behave like the same buttons in the firewall rules GUI for "…create a new rule based on this one...", except in the case of Snort it creates a new interface based on the current one. Enabled rule categories, preprocessor settings and other stuff are supposed to all get copied over and just the UUID and interface name are changed (also resets HOME_NET, EXTERNAL_NET and PASS LISTS to "default" for the cloned interface).

I tested this before deployment, but may not have tested in enough. Give me a few more days to finish up some Suricata work, and then I will examine this code in detail.

Bill

bmeeks

@highlandpeak:

Here are a couple of observations:

It appears that I have (possibly) solved the restart problem. It relates to how the 2nd & 3rd interfaces are added. If I click on the top most + button to create the interfaces instead of the one at the end of the WAN line - I see no SOFT RESTART on update but rather a START. More importantly the interfaces continue to run without intervention.

Logging fails if WAN IP rep is enabled. Resumes if it is disabled.

BAM

UPDATE
Your observation above about the problem being related to exactly which icon on the INTERFACES tab was used to create new interfaces was on target. There is a bug in that code. It forgets to create a new UUID for the cloned interface when you use the + icons beside each interface line (the one whose tooltip will say something similar to "…create a new interface based on this one..."). The same bug exists in the Suricata package as well since those two share a lot of GUI code. I fixed it in Suricata and it will be included in the update currently under review.

For Snort, I want to take a week or so and port over some of the new Suricata GUI features, and during that time I will fix this bug as well.

In the meantime, as a workaround, do not use the + icons at the right of each interface line. This means "cloning" an interface should not be used until the next Snort update is released.

Sorry about the bug, but thank you for persisting and finding the key clue. It escaped my VM testing because in my VMs the interfaces (WAN vs. LAN) had different NIC types and thus even when they shared a UUID it still worked. That would not be true in machines with multiple NICs of the same type.

Bill

highlandpeak

Bill,

Thanks for the hard work.

BAM

bmeeks

@highlandpeak:

Bill,

Thanks for the hard work.

BAM

If your configuration is still muddled up and giving you problems, send me a PM and I will work with you offline to get it fixed. Essentially what was happening to you is the Snort PHP code was getting confused by the duplicate UUIDs for different interfaces and wound up trying to "start" the wrong one (one that is already started). That's why one of your interfaces was giving a SOFT RESTART notice. Its UUID matched one of your earlier configured interfaces (most likely the one it was cloned from). Snort uses that UUID to differentiate interface instances.

Bill