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.
Parents Reply Children
  • 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"

  • I am quite sure this is not an issue what so ever. It is simply a closing connection. So those packets are duplicated send and being logged as closing packets. 

    __________________________________________________________________________________________________________________

  • Ok, but I'm not so sure about the last scenario that I described as it definitely coincides with the errors that are being reported. Why are they being denied against "Default Workplace Policy"? Can we identify IPS policy 3?

  • It is a destroyed connection. So the connection is getting closed and deleted. 

    fwid=5 Show us a screenshot of this FW Rule. But likely you are chasing something, which is not important. 

    When conntrack is closing/Destroying the connection, it is because somebody (Client or Server) is sending a RST packet. This means, the client or the server (likely the client in this scenario) is closing the connection. 

    Those packets are often times send multiple times. Therefore logged as invalid traffic. There is no issue in this process what so ever. Your issue is a application issue. Something the app is causing and is closing the connection. 

    There is a TCP Handshake. Which means the connection on a TCP Level is there. But the other levels (TLS for example) is closing the connection.

    You see this in this: packets=15 bytes=1698 

    15 Packets are send between those clients. The firewall is not simply closing the connection at this point. Instead the client or server is closing the connection for whatever reason after the talked to each other (in fact 15 packets, which could be TLS handshake or something in the application). 

    __________________________________________________________________________________________________________________