Thread Info
  • State Not Answered
  • Locked Locked
  • Replies 8 replies
  • Subscribers 2 subscribers
  • Views 3342 views
  • Users 0 members are here
Options
Suggested
This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

Dropped "ACK" pakets every sunday morning

NikFehl
Hello UserBB,

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.
Parents
  • 0
    My rule #19 is just for logging.
    It says drop anything and log.

    The only reason to have such an explicit rule with the UTM is to NOT have the drop appear in the log.

    If you already know the answer, then I guess you don't need our help. ;-)

    Cheers - Bob
    PS OK, I appreciate your frustration since you're obviously not a neophyte in TCP/IP - do you have any more success after the following?

    cc set packetfilter timeouts ip_conntrack_tcp_timeout_last_ack 60

  • 0 in reply to BAlfson
    Just a short summary:

    I was in contact with the Sophos Support.
    They also saw the failure.  And couldn't explain it.
    Rule matches... but sometimes connections get dropped (only the mentioned job).

    We saw in TCPdumps that the stateful connection backwards was dropped.
    So the rule matched for incoming connections... but lost the state for the answer "ack" paket after about one hour.

    Solution (or workaround) was interesting... and frustrating.
    We just reloaded the rule. (Just added logging)
    Nothing else changed... but now its working all the time.

    I'm not happy withit... but its working now.. so I just wanted to inform you.

    thank you for your support.

    br
    Nik.
Reply
  • 0 in reply to BAlfson
    Just a short summary:

    I was in contact with the Sophos Support.
    They also saw the failure.  And couldn't explain it.
    Rule matches... but sometimes connections get dropped (only the mentioned job).

    We saw in TCPdumps that the stateful connection backwards was dropped.
    So the rule matched for incoming connections... but lost the state for the answer "ack" paket after about one hour.

    Solution (or workaround) was interesting... and frustrating.
    We just reloaded the rule. (Just added logging)
    Nothing else changed... but now its working all the time.

    I'm not happy withit... but its working now.. so I just wanted to inform you.

    thank you for your support.

    br
    Nik.
Children
No Data