I got a problem with our Sophos UTM.
summarize:
Valid "ACK" pakets of a valid connection are dropped in the Sophos UTM at Sunday Morning, 2:58 a.m.
setup:
We are using two Sophos SG330 as an active-active HA-Cluster.
Firmware version: 9.210-20
system configuration:
Firewall with 19 rules
Intrusion Prevention on "alert"
Advanced Threat Protection
details:
We got a job which starts every sunday morning at 02:01 a.m.
This job builds up connections from four different servers to an internal server via tcp port 9494.
network1 -> allow port -> network2
192.168.0.0/24 -> tcp 9494 -> 192.168.1.0/24
At around 02:58 a.m. our job seems to be stopping and I'll see a few dropped "ACK" pakets in the firewall logs.
01:11-02:58:44 Sophos-1 ulogd[32471]: id="2001" action="drop" fwrule="19" srcip="192.168.1.11" dstip="192.168.0.31" proto="6" srcport="9494" dstport="55349" tcpflags="ACK"
(thats a trimmed log-entry. for the full log entry look at the logs.)
The server and the client still think that they are connected and keep sending new pakets. I saw dropped "ACK" pakets for the next 15 minutes.
These pakets are hitting my default drop-rule nr. 19. That said... the packetfilter seems to have forgotten their corresponding connection.
This keeps happening every week at almost the same time (plus, minus a few seconds).
But only this connections seems to be influenced. Other DB or SSH connections are ok.
When I run our job manually at the afternoon it finishes successfully after 2 hours with none dropped pakets.
Any idea why this is happening?
Is there some kind of config-reload with has problems with an active-active-cluster setup?
Here are all log-entries starting 4 secs before the first drop:
(names, ips, macs sanitized.)
Jan 11 02:58:40 Sophos1 2015: 01:11-02:58:40 Sophos -- MARK --
Jan 11 02:58:42 Sophos1 2015: 01:11-02:58:42 Sophos-1 confd[20299]: I main::cleanup_changelog:972() => id="3100" severity="info" sys="System" sub="confd" name="trimmed version 147 from changelog"
Jan 11 02:58:42 Sophos1 2015: 01:11-02:58:42 Sophos-1 syslog-ng[5178]: Configuration reload request received, reloading configuration;
Jan 11 02:58:42 Sophos1 2015: 01:11-02:58:42 Sophos-1 ulogd[30049]: SIGTERM received
Jan 11 02:58:42 Sophos1 2015: 01:11-02:58:42 Sophos-1 confd[20299]: I main::top-level:757() => id="310n" severity="info" sys="System" sub="confd" name="applied changes" user="system" srcip="127.0.0.1" sid="dgZgwnqwyPLlWapTCZWk" facility="system" client="c
onfd-client.pl" pid="32418" version="149" storage="/cfg"
Jan 11 02:58:42 Sophos1 2015: 01:11-02:58:42 Sophos-1 notifier[3871]: loading config version 0
Jan 11 02:58:42 Sophos1 2015: 01:11-02:58:42 Sophos-1 middleware[4321]: T main::top-level:213() => starting cycle 857, caught 1 signals
Jan 11 02:58:42 Sophos1 2015: 01:11-02:58:42 Sophos-1 middleware[4321]: T core::Config::Changed:134() => configversion=149
Jan 11 02:58:42 Sophos1 2015: 01:11-02:58:42 Sophos-1 middleware[4321]: T core::Config::Changed:144() => nodes=0 objects=0 triggers=1
Jan 11 02:58:42 Sophos1 2015: 01:11-02:58:42 Sophos-1 middleware[4321]: T core::Config::load:269() => modules=1,8
Jan 11 02:58:42 Sophos1 2015: 01:11-02:58:42 Sophos-2 confd[5920]: I Role::authenticate:146() => id="3106" severity="info" sys="System" sub="confd" name="authentication successful" user="ha_sync" srcip="198.19.250.1" sid="EinvyMSoTDwtTHvuAmKQ" facility="s
ystem" client="vpnreporter" call="new"
Jan 11 02:58:42 Sophos1 2015: 01:11-02:58:42 Sophos-1 confd-sync[2302]: id="3850" severity="info" sys="System" sub="ha" name="Version changed: 149"
Jan 11 02:58:42 Sophos1 2015: 01:11-02:58:42 Sophos-1 confd-sync[2302]: id="3850" severity="info" sys="System" sub="ha" name="Nothing todo"
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 afcd[30141]: vy_plugin: N: finalizing vineyard thread
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 afcd[30141]: vy_plugin: N: finalizing vineyard thread
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 afcd[30141]: vy_plugin: N: finalizing vineyard thread
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 afcd[30141]: STATUS: alert_lvl="GREEN" run_time=3601 num_cts=0 pktps_avg=247.02 pktps_avg_max=478.19 skipped_pktps_avg=1.99 skipped_pktps_avg_max=7.97 connps_avg=21.10 connps_avg_max=38.63 rusage_sys=42.448 rusage_usr=29.324
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 afcd[30141]: CIFS (nfmark 00000048): 41 packets, 41 connections
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 afcd[30141]: DNS (nfmark 0000007c): 2702 packets, 1319 connections
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 afcd[30141]: HTTP (nfmark 000000d3): 305832 packets, 58910 connections
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 afcd[30141]: NETBIOS (nfmark 00000146): 48 packets, 48 connections
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 afcd[30141]: NTP (nfmark 0000015d): 54 packets, 54 connections
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 afcd[30141]: POSTGRES (nfmark 0000017b): 115 packets, 115 connections
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 afcd[30141]: SFTP (nfmark 000001b5): 538 packets, 538 connections
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 afcd[30141]: SSH (nfmark 000001d8): 14397 packets, 74 connections
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 afcd[30141]: SYSLOG (nfmark 000001e8): 484 packets, 484 connections
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 afcd[30141]: packets: 699609 (537346 inspected, 9633 skipped)
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 afcd[30141]: connections: 63500 (61583 classified)
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 middleware[4321]: T modules::ipset:[:D]eleteUnused:320() => auto#=11/682 confd#=1/341
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 middleware[4321]: T main::top-level:271() => cycle 857 waiting for 1 children
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 afcd[32560]: _afc_cfg_file_plugin_parse: 1226 protocols registered
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 afcd[32560]: vy_plugin: N: aptp: threaddata loaded from /var/chroot-afc/etc/aptpdata
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 afcd[32560]: loaded plugin '/var/sec/chroot-afc/lib/afc/vineyard.so'
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 afcd[32560]: _afc_cfg_file_plugin_parse: 1226 protocols registered
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 afcd[32563]: AFC ready.
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 middleware[4321]: T main::top-level:260() => ending cycle 857, caught 0 signals, 0 children still running
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 ulogd[32471]: id="2001" severity="info" sys="SecureNet" sub="packetfilter" name="Packet dropped" action="drop" fwrule="19" initf="eth2.124" outitf="eth1.102" srcmac="xx:xx:xx:e4:63:fc" dstmac="xx:xx:xx:f0:b0:02" srcip="192.168.1.11" dstip="192.168.0.31" proto="6" length="1500" tos="0x00" prec="0x00" ttl="63" srcport="9494" dstport="55349" tcpflags="ACK"
Jan 11 02:58:44 Sophos1 2015: 01:11-02:58:44 Sophos-1 ulogd[32471]: id="2001" severity="info" sys="SecureNet" sub="packetfilter" name="Packet dropped" action="drop" fwrule="19" initf="eth2.124" outitf="eth1.102" srcmac="xx:xx:xx:e4:63:fc" dstmac="xx:xx:xx:f0:b0:02" srcip="192.168.1.11" dstip="192.168.0.31" proto="6" length="1201" tos="0x00" prec="0x00" ttl="63" srcport="9494" dstport="55349" tcpflags="ACK PSH"
Jan 11 02:58:45 Sophos1 2015: 01:11-02:58:45 Sophos-1 ulogd[32471]: id="2001" severity="info" sys="SecureNet" sub="packetfilter" name="Packet dropped" action="drop" fwrule="19" initf="eth2.124" outitf="eth1.102" srcmac="xx:xx:xx:e4:63:fc" dstmac="xx:xx:xx:f0:b0:02" srcip="192.168.1.11" dstip="192.168.0.31" proto="6" length="1500" tos="0x00" prec="0x00" ttl="63" srcport="9494" dstport="55349" tcpflags="ACK"
Jan 11 02:58:45 Sophos1 2015: 01:11-02:58:45 Sophos-1 ulogd[32471]: id="2001" severity="info" sys="SecureNet" sub="packetfilter" name="Packet dropped" action="drop" fwrule="19" initf="eth2.124" outitf="eth1.102" srcmac="xx:xx:xx:e4:63:fc" dstmac="xx:xx:xx:f0:b0:02" srcip="192.168.1.11" dstip="192.168.0.31" proto="6" length="64" tos="0x00" prec="0x00" ttl="63" srcport="9494" dstport="55349" tcpflags="ACK"
Jan 11 02:58:45 Sophos1 2015: 01:11-02:58:45 Sophos-1 ulogd[32471]: id="2001" severity="info" sys="SecureNet" sub="packetfilter" name="Packet dropped" action="drop" fwrule="19" initf="eth2.124" outitf="eth1.102" srcmac="xx:xx:xx:e4:63:fc" dstmac="xx:xx:xx:f0:b0:02" srcip="192.168.1.11" dstip="192.168.0.31" proto="6" length="1500" tos="0x00" prec="0x00" ttl="63" srcport="9494" dstport="55349" tcpflags="ACK"
Jan 11 02:58:45 Sophos1 2015: 01:11-02:58:45 Sophos-1 ulogd[32471]: id="2001" severity="info" sys="SecureNet" sub="packetfilter" name="Packet dropped" action="drop" fwrule="19" initf="eth2.124" outitf="eth1.102" srcmac="xx:xx:xx:e4:63:fc" dstmac="xx:xx:xx:f0:b0:02" srcip="192.168.1.11" dstip="192.168.0.31" proto="6" length="64" tos="0x00" prec="0x00" ttl="63" srcport="9494" dstport="55349" tcpflags="ACK"
Jan 11 02:58:45 Sophos1 2015: 01:11-02:58:45 Sophos-1 ulogd[32471]: id="2001" severity="info" sys="SecureNet" sub="packetfilter" name="Packet dropped" action="drop" fwrule="19" initf="eth2.124" outitf="eth1.102" srcmac="xx:xx:xx:e4:63:fc" dstmac="xx:xx:xx:f0:b0:02" srcip="192.168.1.11" dstip="192.168.0.32" proto="6" length="1500" tos="0x00" prec="0x00" ttl="63" srcport="9494" dstport="47510" tcpflags="ACK"
Thank you for your support,
Nik
This thread was automatically locked due to age.
