(SOLVED) Suricata Interfaces have to be manually Restarted

Raffi_

Hi @bmeeks,
I recently noticed a new problem in suricata 4.1.4_3. This may have been occuring before the update as well, I can't be sure. I'm able to start Suricata on both my LAN and OPT1 interfaces, both are /24 interfaces. After some time, it seems to stop on both interfaces and I have to manually restart it. When this happens, Suricata is still running according to the Status => Services page.

I have a bunch of errors in my suricata.log as seen below and it keeps going on with similar patterns. I'm not sure if these specific errors are the cause or not. The interface which is referred to below as em1 is my 4G LTE failover WAN which is never really used. That interface has an IP which changes frequently.

12/6/2019 -- 23:42:42 - <Info> -- alert-pf -> Received notification of IP address change on interface em1.
12/6/2019 -- 23:42:42 - <Info> -- alert-pf -> Received notification of IP address change on interface em1.
12/6/2019 -- 23:42:42 - <Info> -- alert-pf -> Received notification of IP address change on interface em1.
12/6/2019 -- 23:42:42 - <Info> -- alert-pf -> Received notification of IP address change on interface em1.
12/6/2019 -- 23:42:42 - <Info> -- alert-pf -> Received notification of IP address change on interface em1.
12/6/2019 -- 23:42:42 - <Info> -- alert-pf -> Received notification of IP address change on interface em1.
12/6/2019 -- 23:43:05 - <Warning> -- [ERRCODE: SC_WARN_UNCOMMON(230)] - alert-pf -> Firewall interface IP change notification thread received an invalid IP address via kernel routing message socket.
12/6/2019 -- 23:43:05 - <Warning> -- [ERRCODE: SC_WARN_UNCOMMON(230)] - alert-pf -> Firewall interface IP change notification thread received an invalid IP address via kernel routing message socket.
12/6/2019 -- 23:43:05 - <Warning> -- [ERRCODE: SC_WARN_UNCOMMON(230)] - alert-pf -> Firewall interface IP change notification thread received an invalid IP address via kernel routing message socket.
12/6/2019 -- 23:43:05 - <Warning> -- [ERRCODE: SC_WARN_UNCOMMON(230)] - alert-pf -> Firewall interface IP change notification thread received an invalid IP address via kernel routing message socket.
12/6/2019 -- 23:43:05 - <Warning> -- [ERRCODE: SC_WARN_UNCOMMON(230)] - alert-pf -> Firewall interface IP change notification thread received an invalid IP address via kernel routing message socket.
12/6/2019 -- 23:43:05 - <Warning> -- [ERRCODE: SC_WARN_UNCOMMON(230)] - alert-pf -> Firewall interface IP change notification thread received an invalid IP address via kernel routing message socket.
12/6/2019 -- 23:43:10 - <Warning> -- [ERRCODE: SC_WARN_UNCOMMON(230)] - alert-pf -> Firewall interface IP change notification thread received an invalid IP address via kernel routing message socket.
12/6/2019 -- 23:43:10 - <Warning> -- [ERRCODE: SC_WARN_UNCOMMON(230)] - alert-pf -> Firewall interface IP change notification thread received an invalid IP address via kernel routing message socket.
12/6/2019 -- 23:43:10 - <Warning> -- [ERRCODE: SC_WARN_UNCOMMON(230)] - alert-pf -> Firewall interface IP change notification thread received an invalid IP address via kernel routing message socket.
12/6/2019 -- 23:43:10 - <Warning> -- [ERRCODE: SC_WARN_UNCOMMON(230)] - alert-pf -> Firewall interface IP change notification thread received an invalid IP address via kernel routing message socket.
12/6/2019 -- 23:43:10 - <Warning> -- [ERRCODE: SC_WARN_UNCOMMON(230)] - alert-pf -> Firewall interface IP change notification thread received an invalid IP address via kernel routing message socket.
12/6/2019 -- 23:43:10 - <Warning> -- [ERRCODE: SC_WARN_UNCOMMON(230)] - alert-pf -> Firewall interface IP change notification thread received an invalid IP address via kernel routing message socket.
12/6/2019 -- 23:43:10 - <Info> -- alert-pf -> Received notification of IP address change on interface em1.
12/6/2019 -- 23:43:10 - <Error> -- [ERRCODE: SC_ERR_INVALID_ARGUMENT(13)] - Argument "tree" NULL
12/6/2019 -- 23:43:10 - <Info> -- alert-pf -> added address blank to automatic firewall interface IP Pass List.
12/6/2019 -- 23:43:10 - <Info> -- alert-pf -> Received notification of IP address change on interface em1.
12/6/2019 -- 23:43:10 - <Error> -- [ERRCODE: SC_ERR_INVALID_ARGUMENT(13)] - Argument "tree" NULL
12/6/2019 -- 23:43:10 - <Info> -- alert-pf -> added address blank to automatic firewall interface IP Pass List.
12/6/2019 -- 23:43:10 - <Info> -- alert-pf -> Received notification of IP address change on interface em1.
12/6/2019 -- 23:43:10 - <Error> -- [ERRCODE: SC_ERR_INVALID_ARGUMENT(13)] - Argument "tree" NULL
12/6/2019 -- 23:43:10 - <Info> -- alert-pf -> added address blank to automatic firewall interface IP Pass List.
12/6/2019 -- 23:43:10 - <Info> -- alert-pf -> Received notification of IP address change on interface em1.
12/6/2019 -- 23:43:10 - <Error> -- [ERRCODE: SC_ERR_INVALID_ARGUMENT(13)] - Argument "tree" NULL
12/6/2019 -- 23:43:10 - <Info> -- alert-pf -> added address blank to automatic firewall interface IP Pass List.
12/6/2019 -- 23:43:10 - <Info> -- alert-pf -> Received notification of IP address change on interface em1.
12/6/2019 -- 23:43:10 - <Error> -- [ERRCODE: SC_ERR_INVALID_ARGUMENT(13)] - Argument "tree" NULL
12/6/2019 -- 23:43:10 - <Info> -- alert-pf -> added address blank to automatic firewall interface IP Pass List.
12/6/2019 -- 23:43:10 - <Info> -- alert-pf -> Received notification of IP address change on interface em1.
12/6/2019 -- 23:43:10 - <Error> -- [ERRCODE: SC_ERR_INVALID_ARGUMENT(13)] - Argument "tree" NULL
12/6/2019 -- 23:43:10 - <Info> -- alert-pf -> added address blank to automatic firewall interface IP Pass List.
13/6/2019 -- 00:30:53 - <Notice> -- Signal Received.  Stopping engine.
13/6/2019 -- 00:30:53 - <Error> -- [ERRCODE: SC_ERR_PCAP_DISPATCH(20)] - error code -2 
13/6/2019 -- 00:30:53 - <Info> -- time elapsed 37603.703s
13/6/2019 -- 00:30:53 - <Info> -- (RX#01-igb1) Packets 3195608, bytes 1697670558
13/6/2019 -- 00:30:53 - <Info> -- (RX#01-igb1) Pcap Total:3195598 Recv:3195598 Drop:0 (0.0%).
13/6/2019 -- 00:30:53 - <Info> -- alert-pf output inserted 0 IP address blocks
13/6/2019 -- 00:30:53 - <Info> -- alert-pf output processed 3 alerts
13/6/2019 -- 00:30:53 - <Info> -- alert-pf output inserted 0 IP address blocks
13/6/2019 -- 00:30:53 - <Info> -- alert-pf output processed 3 alerts
13/6/2019 -- 00:30:53 - <Info> -- alert-pf output inserted 0 IP address blocks
13/6/2019 -- 00:30:53 - <Info> -- alert-pf output processed 3 alerts
13/6/2019 -- 00:30:53 - <Info> -- alert-pf output inserted 0 IP address blocks
13/6/2019 -- 00:30:53 - <Info> -- alert-pf output processed 3 alerts
13/6/2019 -- 00:30:53 - <Info> -- Alerts: 0

One thing I notice is that the one line below seems to be occurring during some kind of update routine. At least the time stamp would lead me to believe that.
13/6/2019 -- 00:30:53 - <Error> -- [ERRCODE: SC_ERR_PCAP_DISPATCH(20)] - error code -2

Currently, I haven't manually restarted the interfaces because I read in one of your other posts that the logs will be overwritten. So let me know if there is anything else you need.

Thanks,
Raffi

bmeeks

I feel certain this is related to a bug I accidentally introduced when I fixed Redmine Issue #9031. I found the bug this morning and am finishing testing of the fix, then I will post for the pfSense team to review and merge.

The bug will let Suricata delete an active memory pointer under certain conditions. Once that happens, weird stuff will occur up to and including a Suricata process crash when that deleted pointer is referenced elsewhere in the code. This bug only impacts Legacy Mode blocking operation.

Raffi_

Thanks for the quick response Bill! No problem, hope that update does the trick. I read in other threads about issues with blocks not working and wasn't sure if it was related so I figured I would start a new thread. Thanks for being on top of it, great work.

Raffi

bmeeks

I feel bad because this bug is all on me. I did not completely read and understand all of the features of a built-in Suricata binary function I am using to store Pass List and firewall interface IP addresses. The feature is a Radix Tree that is used to store IP addresses for high speed lookups. A parameter I thought was optional is not always optional. That was the cause of the Redmine Issue #9031 bug. I fixed that one by passing in a pointer value instead of NULL for that parameter. I overlooked the little fact that the Radix Tree code would, when removing an IP from the tree, automatically free the memory pointed to by the parameter. The proper way to make the API call is to provide your own deletion function that the Radix Tree can call. Fixed that mistake.

Look for a new package hopefully a little later today.

Raffi_

Thanks for the explanation. A little over my head, but I understand it for the most part :)
It would be nice if there was a way to roll back a package in cases like this I guess. Don't beat yourself up over it. You're doing your best and being responsive to the issues. We all make mistakes, at least you're owning up to it and making it right very quickly.

bmeeks

The fix for this bug is posted for the pfSense team to review and merge. I've asked them to expedite this one, so keep checking for a new Suricata package to show up in PACKAGE MANAGER either later today or early tomorrow.

The pull request for the fix is here: https://github.com/pfsense/FreeBSD-ports/pull/652.

Raffi_

Awesome. You're the man Bill! Thanks again :)

Raffi_

Hi Bill, thanks for the quick update.
I uninstalled 4.1.4_3 and installed 4.1.4_4. It seemed ok for a while. After some time I saw the same tree null errors and I also noticed one of the alerts that came up did not get blocked. The alert prior to it did come up in the block log however so I wonder if these tree null errors have something to do with alerts not being blocked.

I also ran a force update to see if my theory on the update was right. As soon as I did that, Suricata stopped running on both interfaces and that [ERRCODE: SC_ERR_PCAP_DISPATCH(20)] - error code -2, line came up again.

Let me know if you need any more info.

bmeeks

@Raffi_ said in Suricata Interfaces have to be manually Restarted:

Hi Bill, thanks for the quick update.
I uninstalled 4.1.4_3 and installed 4.1.4_4. It seemed ok for a while. After some time I saw the same tree null errors and I also noticed one of the alerts that came up did not get blocked. The alert prior to it did come up in the block log however so I wonder if these tree null errors have something to do with alerts not being blocked.

I also ran a force update to see if my theory on the update was right. As soon as I did that, Suricata stopped running on both interfaces and that [ERRCODE: SC_ERR_PCAP_DISPATCH(20)] - error code -2, line came up again.

Let me know if you need any more info.

This is really puzzling. The "tree is null" error should be impossible in the new binary. I'm wondering if you actually received the newest binary. It really sounds like you are still running the "unfixed" binary. Look at the file date and time for this file for me:

/usr/local/bin/suricata

It should yesterday's date. The values on my test machine are June 13, 2019 and the file size is 4340864 bytes.

kiokoman

sorry for the intrusion, but , this only apply to pfsense 2.4 ? because i don't see a 4.1.4_4 on my pfsense 2.5, the last available version is still 4.1.4_3

bmeeks

@kiokoman said in Suricata Interfaces have to be manually Restarted:

sorry for the intrusion, but , this only apply to pfsense 2.4 ? because i don't see a 4.1.4_4 on my pfsense 2.5, the last available version is still 4.1.4_3

The new version is supposed to be in both places. I'm wondering if something went weird with the package building and distribution in the 2.5-DEVEL tree. I have a 2.5-DEVEL virtual machine that is current and it also can't see the newest posted version of the Suricata package. However, if you browse the actual repository of posted packages the lastest version shows up there.

Raffi_

@bmeeks said in Suricata Interfaces have to be manually Restarted:

@Raffi_ said in Suricata Interfaces have to be manually Restarted:

Hi Bill, thanks for the quick update.
I uninstalled 4.1.4_3 and installed 4.1.4_4. It seemed ok for a while. After some time I saw the same tree null errors and I also noticed one of the alerts that came up did not get blocked. The alert prior to it did come up in the block log however so I wonder if these tree null errors have something to do with alerts not being blocked.

I also ran a force update to see if my theory on the update was right. As soon as I did that, Suricata stopped running on both interfaces and that [ERRCODE: SC_ERR_PCAP_DISPATCH(20)] - error code -2, line came up again.

Let me know if you need any more info.

This is really puzzling. The "tree is null" error should be impossible in the new binary. I'm wondering if you actually received the newest binary. It really sounds like you are still running the "unfixed" binary. Look at the file date and time for this file for me:
/usr/local/bin/suricata
It should yesterday's date. The values on my test machine are June 13, 2019 and the file size is 4340864 bytes.

Sorry for the trouble. Here is what mine looks like. It has the same date as yours but the size is a bit bigger.

bmeeks

@Raffi_ said in Suricata Interfaces have to be manually Restarted:

@bmeeks said in Suricata Interfaces have to be manually Restarted:
@Raffi_ said in Suricata Interfaces have to be manually Restarted:

Hi Bill, thanks for the quick update.
I uninstalled 4.1.4_3 and installed 4.1.4_4. It seemed ok for a while. After some time I saw the same tree null errors and I also noticed one of the alerts that came up did not get blocked. The alert prior to it did come up in the block log however so I wonder if these tree null errors have something to do with alerts not being blocked.

I also ran a force update to see if my theory on the update was right. As soon as I did that, Suricata stopped running on both interfaces and that [ERRCODE: SC_ERR_PCAP_DISPATCH(20)] - error code -2, line came up again.

Let me know if you need any more info.

This is really puzzling. The "tree is null" error should be impossible in the new binary. I'm wondering if you actually received the newest binary. It really sounds like you are still running the "unfixed" binary. Look at the file date and time for this file for me:
/usr/local/bin/suricata
It should yesterday's date. The values on my test machine are June 13, 2019 and the file size is 4340864 bytes.
Sorry for the trouble. Here is what mine looks like. It has the same date as yours but the size is a bit bigger.

The larger size is puzzling. Is your hardware a Netgate appliance or do you run on a generic Intel AMD64 type machine?

Raffi_

@bmeeks said in Suricata Interfaces have to be manually Restarted:

@Raffi_ said in Suricata Interfaces have to be manually Restarted:
@bmeeks said in Suricata Interfaces have to be manually Restarted:
@Raffi_ said in Suricata Interfaces have to be manually Restarted:

Hi Bill, thanks for the quick update.
I uninstalled 4.1.4_3 and installed 4.1.4_4. It seemed ok for a while. After some time I saw the same tree null errors and I also noticed one of the alerts that came up did not get blocked. The alert prior to it did come up in the block log however so I wonder if these tree null errors have something to do with alerts not being blocked.

I also ran a force update to see if my theory on the update was right. As soon as I did that, Suricata stopped running on both interfaces and that [ERRCODE: SC_ERR_PCAP_DISPATCH(20)] - error code -2, line came up again.

Let me know if you need any more info.

This is really puzzling. The "tree is null" error should be impossible in the new binary. I'm wondering if you actually received the newest binary. It really sounds like you are still running the "unfixed" binary. Look at the file date and time for this file for me:
/usr/local/bin/suricata
It should yesterday's date. The values on my test machine are June 13, 2019 and the file size is 4340864 bytes.
Sorry for the trouble. Here is what mine looks like. It has the same date as yours but the size is a bit bigger.
The larger size is puzzling. Is your hardware a Netgate appliance or do you run on a generic Intel AMD64 type machine?

I forgot to include the system info. It's not a netgate appliance, it's a custom build.
system specs.JPG

bmeeks

Let's compare MD5 hashes to see if your binary is the same as mine. Run this command from a shell prompt on the firewall:

md5 -q /usr/local/bin/suricata

The output should be:

cc5200e8369def9268b9e30c0c3f41c6

Let me know what you get.

Raffi_

@bmeeks said in Suricata Interfaces have to be manually Restarted:

Let's compare MD5 hashes to see if your binary is the same as mine. Run this command from a shell prompt on the firewall:
md5 -q /usr/local/bin/suricata
The output should be:
cc5200e8369def9268b9e30c0c3f41c6
Let me know what you get.

Here is what I got.

c962d5d995867c5baf3136035a34fac7

bmeeks

Okay. Thanks for the information. I've sent an email to my pfSense developer contact who works with me on the Suricata and Snort packages asking him to investigate. It's obvious the binary files are different. I would expect them to be the same.

I will wait to hear from him before taking any further action. The bug is fixed on my end so far as I can tell. I definitely saw the problem in the source code and fixed it there. So I'm wondering why the fix seems to be missing for users.

Raffi_

Thanks for the help Bill. I'll keep any eye out for an update on this. In the meantime, I'll try uninstalling and installing again just for the sake of being persistent. If anything changes on my end I'll let you know.

bmeeks

@Raffi_ said in Suricata Interfaces have to be manually Restarted:

Thanks for the help Bill. I'll keep any eye out for an update on this. In the meantime, I'll try uninstalling and installing again just for the sake of being persistent. If anything changes on my end I'll let you know.

I doubt that will make any difference so long as it still downloads and installs the same binary. It really looks like to me that the binary built as suricata-4.1.4_2 is not "really" my new 4.1.4_2. It appears to still have the old version of my custom blocking plugin patch. That's the only way I can explain the "tree is null" error. I very explicitly fixed that error ... .

Raffi_

@bmeeks said in Suricata Interfaces have to be manually Restarted:

@Raffi_ said in Suricata Interfaces have to be manually Restarted:

Thanks for the help Bill. I'll keep any eye out for an update on this. In the meantime, I'll try uninstalling and installing again just for the sake of being persistent. If anything changes on my end I'll let you know.

I doubt that will make any difference so long as it still downloads and installs the same binary. It really looks like to me that the binary built as suricata-4.1.4_2 is not "really" my new 4.1.4_2. It appears to still have the old version of my custom blocking plugin patch. That's the only way I can explain the "tree is null" error. I very explicitly fixed that error ... .

Yup, uninstall and install of 4.1.4_4 gave me the same md5 results as before.