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

Help with "Invalid Traffic" in logs

Hi,

We have an XG 135 running SFOS 18.5.3 MR-3-Build408. There are two gateways, a primary and backup.

One of our users is encountering an intermittent timeout on a specific website when performing a specific action. I have been checking our firewall logs as well as our internal DNS logs but have yet to track it down.

However, there is one thing that caught my eye. Around the time of the failures I'm seeing 5 or 6 sequential entries in the log titled "Invalid Traffic" with the message being "Invalid Packet". These seem to be going to Google or Microsoft servers. This is likely coincidental as it occurs on other PCs too but I would like to rule it out if possible.

In general I'm seeing a mixture of "Invalid Packet" and "Could not associate packet to any connection." when I filter all traffic by "Log comp is Invalid traffic".

I would appreciate any comments.

Thanks,

Alan



This thread was automatically locked due to age.
  • Hello ,

    Thank you for reaching out to the community, 
    The following article and the solution to mitigate  the situation is provided here: https://docs.sophos.com/nsg/sophos-firewall/18.5/Help/en-us/webhelp/onlinehelp/AdministratorHelp/Logs/LogViewer/InvalidTrafficEvents/index.html


    Thanks & Regards,
    _______________________________________________________________

    Vivek Jagad | Team Lead, Global Support & Services 

    Log a Support Case | Sophos Service Guide
    Best Practices – Support Case


    Sophos Community | Product Documentation | Sophos Techvids | SMS
    If a post solves your question please use the 'Verify Answer' button.

  • actually this article will not help. you need to conntrack the connections and that is a difficult task.

    I've seen this yesterday at one of my XGS136 with 18.5 MR3 and I have not seen that with MR2.

    Here it is traffic beeing generated by the XGS itself to WAN or devices connecting to the XG, even my webadmin session.

    The firewall log contains almost 99% Invalid Traffic and Invalid TCP state logs only.

    I have only one WAN gateway.

     do you have a lag / LACP configured on your XG and is this a HA A/P cluster?

    I wonder if it has to do with a LAG bug that came with MR3.

  • Thanks for your comments.

    Alan Spark do you have a lag / LACP configured on your XG?

    No, we don't have a LAG interface configured. We have a LAN bridge and our primary and secondary WAN connections.

  • I had a look at some fresh logs today and they don't seem to have a firewall rule associated and are NAT rule 0, at least the ones that I'm linking with the timeout behaviour that is being reported. They also appear to be from cloud services such as Amazon or Microsoft which we believe are used by the website that we're having these issues with.

    I'm not seeing anything in the other log categories (e.g. web filter). Anything else worth checking?

  • sounds like system (XG) generated traffic.

    can you dump the traffic on CLI tcpdump -i any host 123.123.123.123 -nve

    what is the source interface?

    what's the source IP generating the traffic? To which device does it belong?

  • The source IP that I was initially investigating was that of the user encountering the timeout. However, I have since learned that it is happening more generally. For example, an internal web server is showing up regularly as the source IP with my local IP being the destination.

    The source interface is usually port 1 which is our LAN connection. This is with the N/A firewall rule and 0 NAT rule that I described earlier. Sometimes I see entries that have no source interface but still the N/A firewall rule and 0 NAT rule, these have an external source IP and a destination of our WAN IP. These have the “Could not associate packet to any connection.” message rather than “Invalid packet.”,

    I can run tcpdump but it is very difficult to correlate with the firewall logs, as I don’t have a definite way of reproducing it. It happens regularly because we have a client running that is constantly communicating with the server but this means that the tcpdump output is constant. Here is a small sample where a.a.a.a is my local IP and b.b.b.b is the remote server:

    0x0, ttl 127, id 63328, offset 0, flags [DF], proto TCP (6), length 52)

        a.a.a.a.8498 > b.b.b.b.443: Flags [.], cksum 0xcaa4 (correct), ack 6538, win 511, options [nop,nop,sack 1 {1457:1731}], length 0

    07:45:25.344224 ipsec0, IN:  In 00:00:00:00:00:00 ethertype IPv4 (0x0800), length 68: (tos 0x0, ttl 128, id 63329, offset 0, flags [DF], proto TCP (6), length 52)

        a.a.a.a.8498 > b.b.b.b.443: Flags [.], cksum 0xcaa4 (correct), ack 6538, win 511, options [nop,nop,sack 1 {1457:1731}], length 0

    07:45:25.344277 br0, OUT: Out 11:11:11:11:11:11 ethertype IPv4 (0x0800), length 68: (tos 0x0, ttl 127, id 63329, offset 0, flags [DF], proto TCP (6), length 52)

        a.a.a.a.8498 > b.b.b.b.443: Flags [.], cksum 0xcaa4 (correct), ack 6538, win 511, options [nop,nop,sack 1 {1457:1731}], length 0

    07:45:25.344284 Port1, OUT: Out 11:11:11:11:11:11 ethertype IPv4 (0x0800), length 68: (tos 0x0, ttl 127, id 63329, offset 0, flags [DF], proto TCP (6), length 52)

        a.a.a.a.8498 > b.b.b.b.443: Flags [.], cksum 0xcaa4 (correct), ack 6538, win 511, options [nop,nop,sack 1 {1457:1731}], length 0

  • For example, an internal web server is showing up regularly as the source IP with my local IP being the destination.

    We can see that when the session has ended or stopped and the server send's some kind of keep alive. For the XG the session has ended so it drops the packets from the webserver tcp 443 to random high port like 51234 to the client from which the connection has been started before.

    An other thing that might happen, is that sessions are dropped caused by IPS updates on XG. Check for IPS updates in the logs and if you see those "Could not associate packet to any connection." messages appear shortly after.

  • Check for IPS updates in the logs and if you see those "Could not associate packet to any connection." messages appear shortly after.

    The last IPS update was "09:16:00, May 31 2022". There were several of these "could not associate" messages a couple of minutes later but they are extremely frequent - there seems to be a block of them every minute or two. I also note that some of them have an "In Interface" associated with them, but most do not.

  • Do a conntrack -E |grep IP 

    Then reproduce the issue or wait for this issue to occur. You should see the connection maybe closed. 

    __________________________________________________________________________________________________________________

  • I have followed your advice and pasted outputs below. However, see also the end of my message for some new information about the main problem that I'm trying to solve.

    I have reproduced the "Invalid packet" behaviour here where a.a.a.a is one of our servers that I first identified in the GUI log and b.b.b.b is our WAN IP. The original destination (52.97.179.226) appears to be a Microsoft IP.

    GUI Firewall Output

    2022-06-01 06:46:04Firewall
    messageid="01001"
    log_type="Firewall"
    log_component="Invalid Traffic"
    log_subtype="Denied"
    status="Deny"
    con_duration="0"
    fw_rule_id="N/A"
    nat_rule_id="0"
    policy_type="0"
    user=""
    user_group=""
    web_policy_id="0"
    ips_policy_id="0"
    appfilter_policy_id="0"
    app_name=""
    app_risk="0"
    app_technology=""
    app_category=""
    vlan_id=""
    ether_type="IPv4 (0x0800)"
    bridge_name=""
    bridge_display_name=""
    in_interface="Port1"
    in_display_interface="Port1"
    out_interface=""
    out_display_interface=""
    src_mac="00:00:00:00:00:00"
    dst_mac=""
    src_ip="a.a.a.a"
    src_country="R1"
    dst_ip="52.97.219.226"
    dst_country="GBR"
    protocol="TCP"
    src_port="41402"
    dst_port="993"
    packets_sent="0"
    packets_received="0"
    bytes_sent="0"
    bytes_received="0"
    src_trans_ip=""
    src_trans_port="0"
    dst_trans_ip=""
    dst_trans_port="0"
    src_zone_type=""
    src_zone=""
    dst_zone_type=""
    dst_zone=""
    con_direction=""
    con_id=""
    virt_con_id=""
    hb_status="No Heartbeat"
    message="Invalid packet."
    appresolvedby="Signature"
    app_is_cloud="0"

    Conntrack Output

    [NEW] proto=tcp proto-no=6 timeout=120 state=SYN_SENT orig-src=a.a.a.a orig-dst=52.97.179.226 orig-sport=37190 orig-dport=993 [UNREPLIED] reply-src=52.97.179.226 reply-dst=b.b.b.b reply-sport=993 reply-dport=37190 mark=0x8001 id=1941491456 masterid=0 devin=Port1 devout=Port2 nseid=16784884 ips=3 sslvpnid=0 webfltid=4 appfltid=0 icapid=0 policytype=1 fwid=5 natid=3 fw_action=1 bwid=0 appid=0 appcatid=0 hbappid=0 hbappcatid=0 dpioffload=0 sigoffload=0 inzone=1 outzone=2 devinindex=5 devoutindex=6 hb_src=0 hb_dst=0 flags0=0x10800a080020000a flags1=0xd0020a00010 flagvalues=1,3,21,35,41,43,55,60,68,85,87,93,104,106,107 catid=0 user=0 luserid=0 usergp=0 hotspotuserid=0 hotspotid=0 dst_mac=11:11:11:11:11:11 src_mac=00:00:00:00:00:00 startstamp=1654062421 microflow[0]=INVALID microflow[1]=INVALID hostrev[0]=0 hostrev[1]=0 ipspid=0 diffserv=0 loindex=6 tlsruleid=0 ips_nfqueue=1 sess_verdict=0 gwoff=0 cluster_node=0 current_state[0]=11038 current_state[1]=0 vlan_id=0 inmark=0x0 brinindex=21 sessionid=1430 sessionidrev=7201 session_update_rev=1 dnat_done=0 upclass=0:0 dnclass=0:0 pbrid_dir0=0 pbrid_dir1=0 nhop_id[0]=65535 nhop_id[1]=65535 nhop_rev[0]=0 nhop_rev[1]=0 conn_fp_id=NOT_OFFLOADED
    [UPDATE] proto=tcp proto-no=6 timeout=60 state=SYN_RECV orig-src=a.a.a.a orig-dst=52.97.179.226 orig-sport=37190 orig-dport=993 reply-src=52.97.179.226 reply-dst=b.b.b.b reply-sport=993 reply-dport=37190 mark=0x8001 id=1941491456 masterid=0 devin=Port1 devout=Port2 nseid=16784884 ips=3 sslvpnid=0 webfltid=4 appfltid=0 icapid=0 policytype=1 fwid=5 natid=3 fw_action=1 bwid=0 appid=0 appcatid=0 hbappid=0 hbappcatid=0 dpioffload=0 sigoffload=0 inzone=1 outzone=2 devinindex=5 devoutindex=6 hb_src=0 hb_dst=0 flags0=0x10800a080020000a flags1=0xd0020a00010 flagvalues=1,3,21,35,41,43,55,60,68,85,87,93,104,106,107 catid=0 user=0 luserid=0 usergp=0 hotspotuserid=0 hotspotid=0 dst_mac=11:11:11:11:11:11 src_mac=00:00:00:00:00:00 startstamp=1654062421 microflow[0]=INVALID microflow[1]=INVALID hostrev[0]=0 hostrev[1]=0 ipspid=0 diffserv=0 loindex=6 tlsruleid=0 ips_nfqueue=1 sess_verdict=0 gwoff=0 cluster_node=0 current_state[0]=11038 current_state[1]=11038 vlan_id=0 inmark=0x0 brinindex=21 sessionid=1430 sessionidrev=7201 session_update_rev=1 dnat_done=0 upclass=0:0 dnclass=0:0 pbrid_dir0=0 pbrid_dir1=0 nhop_id[0]=65535 nhop_id[1]=65535 nhop_rev[0]=0 nhop_rev[1]=0 conn_fp_id=NOT_OFFLOADED
    [UPDATE] proto=tcp proto-no=6 timeout=10800 state=ESTABLISHED orig-src=a.a.a.a orig-dst=52.97.179.226 orig-sport=37190 orig-dport=993 reply-src=52.97.179.226 reply-dst=b.b.b.b reply-sport=993 reply-dport=37190 [ASSURED] mark=0x8001 id=1941491456 masterid=0 devin=Port1 devout=Port2 nseid=16784884 ips=3 sslvpnid=0 webfltid=4 appfltid=0 icapid=0 policytype=1 fwid=5 natid=3 fw_action=1 bwid=0 appid=0 appcatid=0 hbappid=0 hbappcatid=0 dpioffload=0 sigoffload=0 inzone=1 outzone=2 devinindex=5 devoutindex=6 hb_src=0 hb_dst=0 flags0=0x10800a080020000a flags1=0xd0020a00010 flagvalues=1,3,21,35,41,43,55,60,68,85,87,93,104,106,107 catid=0 user=0 luserid=0 usergp=0 hotspotuserid=0 hotspotid=0 dst_mac=11:11:11:11:11:11 src_mac=00:00:00:00:00:00 startstamp=1654062421 microflow[0]=INVALID microflow[1]=INVALID hostrev[0]=0 hostrev[1]=0 ipspid=0 diffserv=0 loindex=6 tlsruleid=0 ips_nfqueue=1 sess_verdict=0 gwoff=0 cluster_node=0 current_state[0]=11038 current_state[1]=11038 vlan_id=0 inmark=0x0 brinindex=21 sessionid=1430 sessionidrev=7201 session_update_rev=1 dnat_done=0 upclass=0:0 dnclass=0:0 pbrid_dir0=0 pbrid_dir1=0 nhop_id[0]=65535 nhop_id[1]=65535 nhop_rev[0]=0 nhop_rev[1]=0 conn_fp_id=NOT_OFFLOADED
    [UPDATE] proto=tcp proto-no=6 timeout=120 state=FIN_WAIT orig-src=a.a.a.a orig-dst=52.97.179.226 orig-sport=37190 orig-dport=993 reply-src=52.97.179.226 reply-dst=b.b.b.b reply-sport=993 reply-dport=37190 [ASSURED] mark=0x8001 id=1941491456 masterid=0 devin=Port1 devout=Port2 nseid=16784884 ips=3 sslvpnid=0 webfltid=4 appfltid=0 icapid=0 policytype=1 fwid=5 natid=3 fw_action=1 bwid=0 appid=0 appcatid=0 hbappid=0 hbappcatid=0 dpioffload=0x3e sigoffload=0 inzone=1 outzone=2 devinindex=5 devoutindex=6 hb_src=0 hb_dst=0 flags0=0x10800a080020000a flags1=0x1d0120a10010 flagvalues=1,3,21,35,41,43,55,60,68,80,85,87,93,96,104,106,107,108 catid=83 user=0 luserid=0 usergp=0 hotspotuserid=0 hotspotid=0 dst_mac=11:11:11:11:11:11 src_mac=00:00:00:00:00:00 startstamp=1654062421 microflow[0]=INVALID microflow[1]=INVALID hostrev[0]=0 hostrev[1]=0 ipspid=0 diffserv=0 loindex=6 tlsruleid=0 ips_nfqueue=1 sess_verdict=0 gwoff=0 cluster_node=0 current_state[0]=11038 current_state[1]=11038 vlan_id=0 inmark=0x0 brinindex=21 sessionid=1430 sessionidrev=7201 session_update_rev=7 dnat_done=0 upclass=0:0 dnclass=0:0 pbrid_dir0=0 pbrid_dir1=0 nhop_id[0]=65535 nhop_id[1]=65535 nhop_rev[0]=0 nhop_rev[1]=0 conn_fp_id=NOT_OFFLOADED
    [UPDATE] proto=tcp proto-no=6 timeout=10 state=CLOSE_WAIT orig-src=a.a.a.a orig-dst=52.97.179.226 orig-sport=37190 orig-dport=993 reply-src=52.97.179.226 reply-dst=b.b.b.b reply-sport=993 reply-dport=37190 [ASSURED] mark=0x8001 id=1941491456 masterid=0 devin=Port1 devout=Port2 nseid=16784884 ips=3 sslvpnid=0 webfltid=4 appfltid=0 icapid=0 policytype=1 fwid=5 natid=3 fw_action=1 bwid=0 appid=0 appcatid=0 hbappid=0 hbappcatid=0 dpioffload=0x3e sigoffload=0 inzone=1 outzone=2 devinindex=5 devoutindex=6 hb_src=0 hb_dst=0 flags0=0x10800a080020000a flags1=0x1d0120a10010 flagvalues=1,3,21,35,41,43,55,60,68,80,85,87,93,96,104,106,107,108 catid=83 user=0 luserid=0 usergp=0 hotspotuserid=0 hotspotid=0 dst_mac=11:11:11:11:11:11 src_mac=00:00:00:00:00:00 startstamp=1654062421 microflow[0]=INVALID microflow[1]=INVALID hostrev[0]=0 hostrev[1]=0 ipspid=0 diffserv=0 loindex=6 tlsruleid=0 ips_nfqueue=1 sess_verdict=0 gwoff=0 cluster_node=0 current_state[0]=11038 current_state[1]=11038 vlan_id=0 inmark=0x0 brinindex=21 sessionid=1430 sessionidrev=7201 session_update_rev=7 dnat_done=0 upclass=0:0 dnclass=0:0 pbrid_dir0=0 pbrid_dir1=0 nhop_id[0]=65535 nhop_id[1]=65535 nhop_rev[0]=0 nhop_rev[1]=0 conn_fp_id=NOT_OFFLOADED
    [UPDATE] proto=tcp proto-no=6 timeout=120 state=LAST_ACK orig-src=a.a.a.a orig-dst=52.97.179.226 orig-sport=37190 orig-dport=993 reply-src=52.97.179.226 reply-dst=b.b.b.b reply-sport=993 reply-dport=37190 [ASSURED] mark=0x8001 id=1941491456 masterid=0 devin=Port1 devout=Port2 nseid=16784884 ips=3 sslvpnid=0 webfltid=4 appfltid=0 icapid=0 policytype=1 fwid=5 natid=3 fw_action=1 bwid=0 appid=0 appcatid=0 hbappid=0 hbappcatid=0 dpioffload=0x3e sigoffload=0 inzone=1 outzone=2 devinindex=5 devoutindex=6 hb_src=0 hb_dst=0 flags0=0x10800a080020000a flags1=0x1d0120a10010 flagvalues=1,3,21,35,41,43,55,60,68,80,85,87,93,96,104,106,107,108 catid=83 user=0 luserid=0 usergp=0 hotspotuserid=0 hotspotid=0 dst_mac=11:11:11:11:11:11 src_mac=00:00:00:00:00:00 startstamp=1654062421 microflow[0]=INVALID microflow[1]=INVALID hostrev[0]=0 hostrev[1]=0 ipspid=0 diffserv=0 loindex=6 tlsruleid=0 ips_nfqueue=1 sess_verdict=0 gwoff=0 cluster_node=0 current_state[0]=11038 current_state[1]=11038 vlan_id=0 inmark=0x0 brinindex=21 sessionid=1430 sessionidrev=7201 session_update_rev=7 dnat_done=0 upclass=0:0 dnclass=0:0 pbrid_dir0=0 pbrid_dir1=0 nhop_id[0]=65535 nhop_id[1]=65535 nhop_rev[0]=0 nhop_rev[1]=0 conn_fp_id=NOT_OFFLOADED

    I also reproduced the scenario where there is no "In Interface" or "Out Interface" listed in the GUI firewall log with the "Could not associate packet to any connection" message, again where a.a.a.a is the internal server and b.b.b.b is the WAN IP. This time it is a Google server (35.207.140.42).

    GUI Firewall Log

    2022-06-01 06:54:56Firewall
    messageid="01001"
    log_type="Firewall"
    log_component="Invalid Traffic"
    log_subtype="Denied"
    status="Deny"
    con_duration="0"
    fw_rule_id="N/A"
    nat_rule_id="0"
    policy_type="0"
    user=""
    user_group=""
    web_policy_id="0"
    ips_policy_id="0"
    appfilter_policy_id="0"
    app_name=""
    app_risk="0"
    app_technology=""
    app_category=""
    vlan_id=""
    ether_type="IPv4 (0x0800)"
    bridge_name=""
    bridge_display_name=""
    in_interface=""
    in_display_interface=""
    out_interface=""
    out_display_interface=""
    src_mac=""
    dst_mac=""
    src_ip="35.207.140.42"
    src_country="DEU"
    dst_ip="b.b.b.b"
    dst_country="GBR"
    protocol="TCP"
    src_port="443"
    dst_port="64681"
    packets_sent="0"
    packets_received="0"
    bytes_sent="0"
    bytes_received="0"
    src_trans_ip=""
    src_trans_port="0"
    dst_trans_ip=""
    dst_trans_port="0"
    src_zone_type=""
    src_zone=""
    dst_zone_type=""
    dst_zone=""
    con_direction=""
    con_id=""
    virt_con_id=""
    hb_status="No Heartbeat"
    message="Could not associate packet to any connection."
    appresolvedby="Signature"
    app_is_cloud="0"

    Conntrack Output

    [DESTROY] proto=tcp      proto-no=6 orig-src=a.a.a.a orig-dst=35.207.140.42 orig-sport=58604 orig-dport=443 packets=15 bytes=1698 reply-src=35.207.140.42 reply-dst=b.b.b.b reply-sport=443 reply-dport=58604 packets=22 bytes=18137 [ASSURED] mark=0x8001 id=2886620800 masterid=0 devin=Port1 devout=Port2 nseid=16784937 ips=3 sslvpnid=0 webfltid=4 appfltid=0 icapid=0 policytype=1 fwid=5 natid=3 fw_action=1 bwid=0 appid=100 appcatid=5 hbappid=0 hbappcatid=0 dpioffload=0x3e sigoffload=0 inzone=1 outzone=2 devinindex=5 devoutindex=6 hb_src=0 hb_dst=0 flags0=0x10800a080020000a flags1=0x1d0124a00010 flagvalues=1,3,21,35,41,43,55,60,68,85,87,90,93,96,104,106,107,108 catid=29 user=0 luserid=0 usergp=0 hotspotuserid=0 hotspotid=0 dst_mac=00:00:00:00:00:00 src_mac=11:11:11:11:11:11 startstamp=1654062543 microflow[0]=INVALID microflow[1]=INVALID hostrev[0]=0 hostrev[1]=0 ipspid=0 diffserv=0 loindex=6 tlsruleid=1 ips_nfqueue=2 sess_verdict=0 gwoff=0 cluster_node=0 current_state[0]=11039 current_state[1]=11039 vlan_id=0 inmark=0x0 brinindex=21 sessionid=156 sessionidrev=12819 session_update_rev=10 dnat_done=0 upclass=0:0 dnclass=0:0 pbrid_dir0=0 pbrid_dir1=0 nhop_id[0]=65535 nhop_id[1]=65535 nhop_rev[0]=0 nhop_rev[1]=0 conn_fp_id=NOT_OFFLOADED

    Finally, I received another report of further timeouts from one of our users and can again correlate it to similar log messages from cloud services. However, I did notice a difference. This one doesn't have a message value but it has a web_policy_id and ips_policy_id value. I can see the corresponding Default Workplace Policy but I don't know how to identify ips_policy_id or the underlying reason but I see many blockages following this pattern around the time of the reported user issues.

    2022-05-31 16:59:44Firewall
    messageid="00002"
    log_type="Firewall"
    log_component="Firewall Rule"
    log_subtype="Denied"
    status="Deny"
    con_duration="0"
    fw_rule_id="5"
    nat_rule_id="0"
    policy_type="1"
    user=""
    user_group=""
    web_policy_id="4"
    ips_policy_id="3"
    appfilter_policy_id="0"
    app_name=""
    app_risk="0"
    app_technology=""
    app_category=""
    vlan_id=""
    ether_type="IPv4 (0x0800)"
    bridge_name=""
    bridge_display_name=""
    in_interface="Port1"
    in_display_interface="Port1"
    out_interface=""
    out_display_interface=""
    src_mac="00:00:00:00:00:00"
    dst_mac=""
    src_ip="a.a.a.a"
    src_country="R1"
    dst_ip="142.250.200.40"
    dst_country="USA"
    protocol="UDP"
    src_port="63158"
    dst_port="443"
    packets_sent="0"
    packets_received="0"
    bytes_sent="0"
    bytes_received="0"
    src_trans_ip=""
    src_trans_port="0"
    dst_trans_ip=""
    dst_trans_port="0"
    src_zone_type=""
    src_zone=""
    dst_zone_type=""
    dst_zone=""
    con_direction=""
    con_id=""
    virt_con_id=""
    hb_status="No Heartbeat"
    message=""
    appresolvedby="Signature"
    app_is_cloud="0"
    web_policy="Default Workplace Policy"