Random connection drops on RED since core 178

Since core update 178 I recognize several “drops” of the RED connection.
The Internet connection does not drop, only the red network connection reconnects.
It looks like if you would unplug / replug the network cable and I realized this as the status indicates the connection time. It lasts 1-2 minutes until internet is back again available.

This issue never happened before since years running IPfire and it just happens since core 178.

Has there been any change or anybody has a clue what the reason could be?

What kind of internet connection do you use?
Is it configured as static IP or DHCP?

Can you see any messages in the logs, especially /var/log/messages or the system log section of the WUI?

Hi,
Network is static and RED is connected to a DSL Modem (fritzbox).

I checked the /var/log/messages now at the time of the last drop from this morning.
I assume this is where the connection dropped or restarted:

...
Sep 19 07:37:12 ipfireN5105 dhcpd: DHCPREQUEST for 192.168.0.57 from 02:a0:8c:cb:8b:38 via green0
Sep 19 07:37:12 ipfireN5105 dhcpd: DHCPACK on 192.168.0.57 to 02:a0:8c:cb:8b:38 via green0
Sep 19 07:37:56 ipfireN5105 syslogd 1.5.1: restart (remote reception).
Sep 19 07:37:56 ipfireN5105 unbound: [2686:0] notice: init module 0: validator
Sep 19 07:37:56 ipfireN5105 unbound: [2686:0] notice: init module 1: iterator
Sep 19 07:37:56 ipfireN5105 acpid: starting up with netlink and the input layer
Sep 19 07:37:56 ipfireN5105 acpid: 1 rule loaded
Sep 19 07:37:56 ipfireN5105 acpid: waiting for events: event logging is off
Sep 19 07:37:56 ipfireN5105 unbound: [2686:0] info: start of service (unbound 1.17.1).
...

If it makes sense, I could share more log content or tell me where to look for.
Thanks!

Either search in the WUI menu Logs - System Logs - Section: RED

or grep in the /var/log/messages for dhcpcd

I grepped /var/log/messages without any hit for dhcpcd

But I recognized that there has been a suricata update near the time of the drop. Indicating some errors:
Could there be any connection?

Sep 19 07:38:01 ipfireN5105 suricata: This is Suricata version 6.0.13 RELEASE running in SYSTEM mode
Sep 19 07:38:01 ipfireN5105 suricata: CPUs/cores online: 4
Sep 19 07:38:01 ipfireN5105 suricata: SSSE3 support not detected, disabling Hyperscan for MPM
Sep 19 07:38:01 ipfireN5105 suricata: SSSE3 support not detected, disabling Hyperscan for SPM
Sep 19 07:38:01 ipfireN5105 suricata: HTTP memcap: 268435456
Sep 19 07:38:01 ipfireN5105 suricata: Enabling fail-open on queue
Sep 19 07:38:01 ipfireN5105 suricata: NFQ running in REPEAT mode with mark 2147483648/2147483648
Sep 19 07:38:01 ipfireN5105 suricata: dropped the caps for main thread
Sep 19 07:38:01 ipfireN5105 suricata: fast output device (regular) initialized: fast.log
Sep 19 07:38:01 ipfireN5105 suricata: Packets will start being processed before signatures are active.
Sep 19 07:38:01 ipfireN5105 suricata: binding this thread 0 to queue '0'
Sep 19 07:38:01 ipfireN5105 suricata: setting queue length to 4096
Sep 19 07:38:01 ipfireN5105 suricata: setting nfnl bufsize to 6144000
Sep 19 07:38:01 ipfireN5105 suricata: fail-open mode should be set on queue
Sep 19 07:38:01 ipfireN5105 suricata: binding this thread 1 to queue '1'
Sep 19 07:38:01 ipfireN5105 suricata: setting queue length to 4096
Sep 19 07:38:01 ipfireN5105 suricata: setting nfnl bufsize to 6144000
Sep 19 07:38:01 ipfireN5105 suricata: fail-open mode should be set on queue
Sep 19 07:38:01 ipfireN5105 suricata: binding this thread 2 to queue '2'
Sep 19 07:38:01 ipfireN5105 suricata: setting queue length to 4096
Sep 19 07:38:01 ipfireN5105 suricata: setting nfnl bufsize to 6144000
Sep 19 07:38:01 ipfireN5105 suricata: fail-open mode should be set on queue
Sep 19 07:38:01 ipfireN5105 suricata: binding this thread 3 to queue '3'
Sep 19 07:38:01 ipfireN5105 suricata: setting queue length to 4096
Sep 19 07:38:01 ipfireN5105 suricata: setting nfnl bufsize to 6144000
Sep 19 07:38:01 ipfireN5105 suricata: fail-open mode should be set on queue
Sep 19 07:38:01 ipfireN5105 suricata: all 4 packet processing threads, 2 management threads initialized, engine started.
Sep 19 07:38:01 ipfireN5105 suricata: rule reload starting
Sep 19 07:38:01 ipfireN5105 suricata: Including configuration file /var/ipfire/suricata/suricata-homenet.yaml.
Sep 19 07:38:01 ipfireN5105 suricata: Including configuration file /var/ipfire/suricata/suricata-dns-servers.yaml.
Sep 19 07:38:01 ipfireN5105 suricata: Including configuration file /var/ipfire/suricata/suricata-http-ports.yaml.
Sep 19 07:38:01 ipfireN5105 suricata: Including configuration file /var/ipfire/suricata/suricata-used-rulesfiles.yaml.
Sep 19 07:38:01 ipfireN5105 suricata: SSSE3 support not detected, disabling Hyperscan for SPM
Sep 19 07:38:01 ipfireN5105 unbound: [2686:0] info: service stopped (unbound 1.17.1).
Sep 19 07:38:01 ipfireN5105 unbound: [2686:0] info: server stats for thread 0: 2 queries, 0 answers from cache, 2 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Sep 19 07:38:01 ipfireN5105 unbound: [2686:0] info: server stats for thread 0: requestlist max 2 avg 1 exceeded 0 jostled 0
Sep 19 07:38:01 ipfireN5105 unbound: [2686:0] info: average recursion processing time 0.224513 sec
Sep 19 07:38:01 ipfireN5105 unbound: [2686:0] info: histogram of recursion processing times
Sep 19 07:38:01 ipfireN5105 unbound: [2686:0] info: [25%]=0 median[50%]=0 [75%]=0
Sep 19 07:38:01 ipfireN5105 unbound: [2686:0] info: lower(secs) upper(secs) recursions
Sep 19 07:38:01 ipfireN5105 unbound: [2686:0] info:    0.131072    0.262144 1
Sep 19 07:38:01 ipfireN5105 unbound: [2686:0] info:    0.262144    0.524288 1
Sep 19 07:38:01 ipfireN5105 unbound: [2686:0] notice: Restart of unbound 1.17.1.
Sep 19 07:38:01 ipfireN5105 unbound: [2686:0] notice: init module 0: validator
Sep 19 07:38:01 ipfireN5105 unbound: [2686:0] notice: init module 1: iterator
Sep 19 07:38:01 ipfireN5105 unbound: [2686:0] info: start of service (unbound 1.17.1).
Sep 19 07:38:01 ipfireN5105 unbound: [2686:0] info: generate keytag query _ta-4a5c-4f66. NULL IN
Sep 19 07:38:01 ipfireN5105 suricata: [ERRCODE: SC_ERR_INVALID_SIGNATURE(39)] - Complete IP space negated. Rule address range is NIL. Probably have a !any or an address range that supplies a NULL address range
Sep 19 07:38:01 ipfireN5105 suricata: [ERRCODE: SC_ERR_INVALID_SIGNATURE(39)] - error parsing signature "drop udp ![$SMTP_SERVERS,$DNS_SERVERS] any -> $DNS_SERVERS 53 (msg:"ET DNS DNS Lookup for localhost.DOMAIN.TLD"; content:"|01|"; offset:2; depth:1; content:"|00 01 00 00 00 00 00|"; distance:1; within:7; content:"|09|localhost"; fast_pattern; nocase; classtype:bad-unknown; sid:2011802; rev:6; metadata:created_at 2010_10_13, updated_at 2019_09_03;)" from file /var/lib/suricata/emerging-dns.rules at line 91
Sep 19 07:38:02 ipfireN5105 kernel: DROP_INPUT IN=red0 OUT= MAC=de:ab:3c:53:58:c5:c0:25:06:f0:9a:b1:08:00 SRC=163.116.179.35 DST=192.168.1.250 LEN=113 TOS=0x00 PREC=0x00 TTL=59 ID=9876 DF PROTO=UDP SPT=443 DPT=52514 LEN=93 MARK=0x80000000 
Sep 19 07:38:02 ipfireN5105 kernel: DROP_INPUT IN=red0 OUT= MAC=de:ab:3c:53:58:c5:c0:25:06:f0:9a:b1:08:00 SRC=163.116.179.35 DST=192.168.1.250 LEN=113 TOS=0x00 PREC=0x00 TTL=59 ID=9877 DF PROTO=UDP SPT=443 DPT=52514 LEN=93 MARK=0x80000000 
Sep 19 07:38:02 ipfireN5105 suricata: [ERRCODE: SC_ERR_INVALID_SIGNATURE(39)] - previous keyword has a fast_pattern:only; set. Can't have relative keywords around a fast_pattern only content
Sep 19 07:38:02 ipfireN5105 suricata: [ERRCODE: SC_ERR_INVALID_SIGNATURE(39)] - error parsing signature "drop tcp $EXTERNAL_NET $HTTP_PORTS -> $HOME_NET any (msg:"MALWARE-OTHER Win.Trojan.Zeus Spam 2013 dated zip/exe HTTP Response - potential malware download"; flow:to_client,established; content:"-2013.zip|0D 0A|"; fast_pattern:only; content:"-2013.zip|0D 0A|"; http_header; content:"-"; within:1; distance:-14; http_header; file_data; content:"-2013.exe"; content:"-"; within:1; distance:-14; metadata:impact_flag red, policy balanced-ips drop, policy max-detect-ips drop, policy security-ips drop, ruleset community, service http; reference:url,www.virustotal.com/en/file/2eff3ee6ac7f5bf85e4ebcbe51974d0708cef666581ef1385c628233614b22c0/analysis/; classtype:trojan-activity; sid:26470; rev:2;)" from file /var/lib/suricata/community-community.rules at line 2584
Sep 19 07:38:02 ipfireN5105 suricata: 60 rule files processed. 33616 rules successfully loaded, 2 rules failed
Sep 19 07:38:02 ipfireN5105 suricata: Threshold config parsed: 0 rule(s) found
Sep 19 07:38:03 ipfireN5105 suricata: 33619 signatures processed. 1406 are IP-only rules, 4349 are inspecting packet payload, 27556 inspect application layer, 108 are decoder event only
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'ET.http.binary' is checked but not set. Checked in 2019421 and 5 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'ET.http.javaclient' is checked but not set. Checked in 2017181 and 5 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'et.IE7.NoRef.NoCookie' is checked but not set. Checked in 2023671 and 9 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'ET.gocd.auth' is checked but not set. Checked in 2034333 and 0 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'dcerpc.rpcnetlogon' is checked but not set. Checked in 2030870 and 6 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'ET.JS.Obfus.Func' is checked but not set. Checked in 2017247 and 0 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'ET.pdf.in.http' is checked but not set. Checked in 2017150 and 3 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'ET.telnet.busybox' is checked but not set. Checked in 2023019 and 2 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'ET.http.javaclient.vulnerable' is checked but not set. Checked in 2013036 and 0 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'ET.ELFDownload' is checked but not set. Checked in 2019896 and 0 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'et.DocVBAProject' is checked but not set. Checked in 2020170 and 0 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'ET.MSSQL' is checked but not set. Checked in 2020569 and 0 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'ET.wininet.UA' is checked but not set. Checked in 2021312 and 0 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'et.MS.XMLHTTP.ip.request' is checked but not set. Checked in 2022050 and 1 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'et.MS.XMLHTTP.no.exe.request' is checked but not set. Checked in 2022053 and 0 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'et.MCOFF' is checked but not set. Checked in 2022303 and 0 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'et.MS.WinHttpRequest.no.exe.request' is checked but not set. Checked in 2022653 and 0 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'ET.armwget' is checked but not set. Checked in 2024242 and 0 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'ET.smb.binary' is checked but not set. Checked in 2027402 and 4 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'ET.Socks5.OnionReq' is checked but not set. Checked in 2027704 and 0 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'ET.autoit.ua' is checked but not set. Checked in 2019165 and 0 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'min.gethttp' is checked but not set. Checked in 2023711 and 0 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'ET.tcpraw.png' is checked but not set. Checked in 2035477 and 0 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'ET.generictelegram' is checked but not set. Checked in 2045614 and 0 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'et.WinHttpRequest' is checked but not set. Checked in 2019823 and 0 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'HTTP.UncompressedFlash' is checked but not set. Checked in 2023313 and 0 other sigs
Sep 19 07:38:03 ipfireN5105 suricata: [ERRCODE: SC_WARN_FLOWBIT(306)] - flowbit 'exe.no.referer' is checked but not set. Checked in 2020500 and 0 other sigs

The logs you posted first show a restart of syslogd at 07:37:56.
This can be initiated by system restart between 07:37:12 ( the last dhcpd log ) and 07:37:56.
Your second post shows the restart of suricata and unbound as part of the boot process.

Therefore, I do not think you loose internet connection only. The whole system restarts. The state of the logs seem to show a short power loss. A normal reboot would log its events to syslog.

Another idea. Do you have some kind of watchdog activated?

2 Likes

Hi, after 4 days running, similar behaviour now.
The system does not reboot. No watchdog activated here.
I will further observe, but it is strange as the system was running long time fine, just after 178 update this behaviour occurs.

[quote=“Adolf Belka, post:4, topic:10358, username:bonnietwin”]
or grep in the /var/log/messages for dhcpcd
[/quote]

I think the grep should be:

grep dhcpd /var/log/messages

And you are looking for issues at the time of a drop.

You need dhcpcd if it is red you are looking for.

dhcpd is the program that gives out ip’s to the clients on the lan.

3 Likes

:face_with_open_eyes_and_hand_over_mouth:

I learned something new today!

So does that mean RED is not dropping? Or that he is not using RED dhcp?

Back in post 3 it is said that the connection is a Static IP connection. My understanding is that would still be via dhcpcd but I don’t know what would be in the logs for the RED connection. I have only ever used a dhcp connection.

I will try and find some time to set a vm IPFire up with a static address and see what is put in the logs when IPFire starts and makes a connection unless someone else knows what occurs from their own experience.

In post 6 Bernhard has identified that syslog is restarting and that would not occur as part of just dropping a RED connection. syslog is restarted as part of a reboot. Maybe looking in the /var/log/bootlog for any messages leading up to around and just after Sep 19th, 07:37:12 to 07:37:56 would help see what is happening.

2 Likes

Suricata looks to have been restarted. Unless you disabled the IPS on the WUI and then enabled it again then those messages, I believe are only seen when a reboot occurs.

The ERRCODE messages are just warnings saying that some of the signatures that have been provided are checking the flowbit but the flowbit has not been set so it is a pointless check. The signatures don’t need to check for the flowbit or they should ensure that the flowbit is set. This has been seen is various signatures for a long time but the signature providers have not corrected the involved signatures but it doesn’t stop the signatures fulfilling their main purpose.

I can’t easily see how Core Update 178 would trigger dropping a RED connection.
Core Update 178 was a security release with very limited changes - only some kernel fixes for the latest AMD and Intel cpu hardware vulnerabilities and a fix for a bug in Hyper-V virtual system that prevented those users booting at all with Core Update 177.
https://blog.ipfire.org/post/ipfire-2-27-core-update-178-released

The file /var/ipfire/dhcpc/dhcpcd-red0.info would give details of the IP’s etc that were received from your Fritzbox modem but I would suspect that for a static connection that file would just contain the IP’s, gateway,dns etc that you provided when you did your setup of IPFire.
I am going to try and get some time to set up a static connection vm and see what is in that file and what shows up in the logs.

1 Like

Thanks for taking this topic into account.

In fact there is no file /var/ipfire/dhcpc/dhcpcd-red0.info
All files in /var/ipfire/dhcpc/ seem to have the timestamp of the initial installation.

I also checked the /var/log/bootlog.x files:
Beside the manual reboots triggered by me yesterday and this morning, I can see the last bootlog file is 10 days old. So this would not be in line with the previous “drop” 4 days ago.

I scheduled now a daily reboot in the morning. Maybe this will help to be stable during the day.
Will keep you posted.

I have managed to set up a static address vm system.

That is what I have also found.

Having thought about it for a while, I think that with a static address specified then nothing needs to be provided from external because everything is defined within IPFire and stored in /var/ipfire/ethernet/settings

This stores the red IP Address, the red gateway IP address and the red subnet address.

When IPFire is rebooted then the red nic has the appropriate IP address assigned to it.

With a dhcp connection the ISP server is asked fort an IP address which is then assigned to the red nic. With a static connection IPFire just assigns the defined IP address to the nic in the same way that it assigns the IP addresses to the green, blue and orange nics.

When the problem happens again, run ip address show which will show if your red nic is UP and what IP address is assigned to it.
If the nic is UP and your static IP address is assigned to it then I think the connection problem is unlikely to be with the red interface in IPFire but more likely some problem in your fritzbox modem that is dropping the connection.

2 Likes

Ok, I will try. But as said, the issue lasts only for 1-2min and then its up again.
Sometimes not even directly recognized, but during web conferences the drop is clearly recognized … :unamused:
Btw, Fritzbox shows also nothing unusual. However, as there was also a firmware update lately, it could also have some relation to that. Will observe and post update.
Thanks!

1 Like

FYI - if I physically unplug the ethernet cable I see this in the message log:

Sep 24 10:39:15 ipfireAPU kernel: igb 0000:04:00.0 red0: igb: red0 NIC Link is Down
. . .
Sep 24 10:44:29 ipfireAPU kernel: igb 0000:04:00.0 red0: igb: red0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX/TX

I do not know if your issue will error in a similar way.

1 Like

After many tests I identified that the root cause of this issue seems to be within the IPS.
Despite the first assumption that RED drops, I admit it looks like the system really rebooted in these cases. System had been updated to core 180, with no change in behaviour.
However, I still I don’t know exactly why, but disabling the IPS seems to prevent disconnections / reboots.
I was so far not able to get more information out of the log files.
I had following three Rulesets enabled:
Snort/VRT GPLv2 Community Rules
Abuse.ch SSLBL Blacklist Rules
Emergingthreats.net Community Rules

Next step might be to enable one after each other if the cause is linked to a specific ruleset or a generic IPS issue.

If the issue is related to switching IPS on/off, it may be related to the memory usage. Are there OOM messages near the reboots?

1 Like