Thread Info
  • State Verified Answer
  • +2 person also asked this people also asked this
  • Locked Locked
  • Replies 20 replies
  • Subscribers 7 subscribers
  • Views 39079 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

[solved] Log flooded with INVALID_MESSAGE_ID errors

RanX
Hi to all !
 
As I got no idea, why I see this error and how to resolve it, I hope somebody from the board can help me.
I've got several IPSec site-to-site Tunnels
One throws me the following errors every 2 seconds
 
2017:08:21-11:09:25 vpn pluto[23586]: "S_XXXXXX_VPN_IPsec" #53: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0x276091ae (perhaps this is a duplicated packet)
2017:08:21-11:09:25 vpn pluto[23586]: "S_XXXXXX_VPN_IPsec" #53: sending encrypted notification INVALID_MESSAGE_ID to EXTERNAL_IP_OF_REMOTEGW:500

I got two SAs over this tunnel, both work, so I wonder, what this error is about and how I could get rid of it.

Best Regards

Ranx



This thread was automatically locked due to age.
  • 0

    Hi and welcome to the UTM Community!

    Several questions:

    1. What is the device on the other end of the tunnel?
    2. Are the corresponding lifetimes the same in the IPsec Policies on both ends?
    3. Are the DPD settings identical?

    Cheers - Bob

     
    Sophos UTM Community Moderator
    Sophos Certified Architect - UTM
    Sophos Certified Engineer - XG
    Gold Solution Partner since 2005
    MediaSoft, Inc. USA
  • 0 in reply to BAlfson
    Hello Bob,
     
    excuse my late reply, but as you know, an admin's work is never done ... ;)
     
    I contacted our partner on the other side;
    this is the information I got:
     
    1. on the other side sits a Checkpoint firewall
    2. we compared lifetimes and they are equal
    3. my counterpart on the other side was not sure, whether possible and if, were to make DPD settings for the tunnel
     
    There are two SAs over this tunnel one looses connection after a while and can only be reactivated by restarting the connection.
     
    Hope this is sufficient information, to give me some hints, how to continue with this issue.
     
    Best Regards
     
    RanX
  • 0 in reply to RanX

    There's not enough information to make a guess.  Please show pictures of the Edits of the IPsec Connection, Remote  Gateway and Policy.  Also, corresponding information for the Checkpoint.  We also need to see ore of the log.  Disable the IPsec Connection and start the IPsec Live Log.  Once the log has shown a few lines, enable the IPsec Connection.  Show us the lines after you enabled up through the first line with the INVALID message - probably about 60 lines.

    Cheers - Bob

     
    Sophos UTM Community Moderator
    Sophos Certified Architect - UTM
    Sophos Certified Engineer - XG
    Gold Solution Partner since 2005
    MediaSoft, Inc. USA
  • 0 in reply to BAlfson
    Hi Bob,
     
    I do not have access to the Checkpoint side of the tunnel; thus I can only provide information from the UTM on our side.
    Hope this will shed some light on the issue anyway.
    Here it is:
     
     
    The excerpt from the log:

    2017:09:21-11:43:28 vpn pluto[6473]: loading secrets from "/etc/ipsec.secrets"
    2017:09:21-11:43:28 vpn pluto[6473]: loaded private key from 'Local X509 Cert.pem'
    2017:09:21-11:43:28 vpn pluto[6473]: loaded PSK secret for "IP_OF_OUR_UTM" "IP_OF_REMOTE_CHECKPOINT_FW"
    2017:09:21-11:43:28 vpn pluto[6473]: loading ca certificates from '/etc/ipsec.d/cacerts'
    2017:09:21-11:43:28 vpn pluto[6473]: loaded ca certificate from '/etc/ipsec.d/cacerts/VPN Signing CA.pem'
    2017:09:21-11:43:28 vpn pluto[6473]: loading aa certificates from '/etc/ipsec.d/aacerts'
    2017:09:21-11:43:28 vpn pluto[6473]: loading ocsp certificates from '/etc/ipsec.d/ocspcerts'
    2017:09:21-11:43:28 vpn pluto[6473]: loading attribute certificates from '/etc/ipsec.d/acerts'
    2017:09:21-11:43:28 vpn pluto[6473]: Changing to directory '/etc/ipsec.d/crls'
    2017:09:21-11:43:28 vpn pluto[6473]: added connection description "S_LOGFLOOD_VPN_IPsec"
    2017:09:21-11:43:28 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13815: initiating Main Mode
    2017:09:21-11:43:28 vpn pluto[6473]: added connection description "S_LOGFLOOD_VPN_IPsec"
    2017:09:21-11:43:28 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13815: ignoring Vendor ID payload [FRAGMENTATION]
    2017:09:21-11:43:28 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13815: Peer ID is ID_IPV4_ADDR: '"IP_OF_REMOTE_CHECKPOINT_FW"'
    2017:09:21-11:43:28 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13815: ISAKMP SA established
    2017:09:21-11:43:28 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13816: initiating Quick Mode PSK+ENCRYPT+TUNNEL+PFS+UP {using isakmp#13815}
    2017:09:21-11:43:28 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13817: initiating Quick Mode PSK+ENCRYPT+TUNNEL+PFS+UP {using isakmp#13815}
    2017:09:21-11:43:29 vpn pluto[6473]: id="2203" severity="info" sys="SecureNet" sub="vpn" event="Site-to-site VPN up" variant="ipsec" connection="LOGFLOOD_VPN_IPsec" address=""IP_OF_OUR_UTM"" local_net="192.168.111.0/24" remote_net="10.28.28.0/22"
    2017:09:21-11:43:29 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13816: sent QI2, IPsec SA established {ESP=>0x9cc10bcd <0x871cee7d}
    2017:09:21-11:43:29 vpn pluto[6473]: id="2203" severity="info" sys="SecureNet" sub="vpn" event="Site-to-site VPN up" variant="ipsec" connection="LOGFLOOD_VPN_IPsec" address=""IP_OF_OUR_UTM"" local_net="192.168.111.0/24" remote_net="172.21.0.0/16"
    2017:09:21-11:43:29 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13817: sent QI2, IPsec SA established {ESP=>0x693593fb <0x0206522d}
    2017:09:21-11:43:31 vpn pluto[6473]: packet from "IP_OF_REMOTE_CHECKPOINT_FW":500: ignoring Vendor ID payload [f4ed19e0c114eb516faaac0ee37daf2807b4381f000000010000138d59c389a3...]
    2017:09:21-11:43:31 vpn pluto[6473]: packet from "IP_OF_REMOTE_CHECKPOINT_FW":500: ignoring Vendor ID payload [FRAGMENTATION]
    2017:09:21-11:43:31 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13818: responding to Main Mode
    2017:09:21-11:43:31 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13818: Peer ID is ID_IPV4_ADDR: '"IP_OF_REMOTE_CHECKPOINT_FW"'
    2017:09:21-11:43:31 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13818: sent MR3, ISAKMP SA established
    2017:09:21-11:43:31 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13818: cannot respond to IPsec SA request because no connection is known for 0.0.0.0/0==="IP_OF_OUR_UTM"["IP_OF_OUR_UTM"]..."IP_OF_REMOTE_CHECKPOINT_FW"["IP_OF_REMOTE_CHECKPOINT_FW"]===10.28.28.0/22
    2017:09:21-11:43:31 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13818: sending encrypted notification INVALID_ID_INFORMATION to "IP_OF_REMOTE_CHECKPOINT_FW":500
    2017:09:21-11:43:33 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13818: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0x6516dd40 (perhaps this is a duplicated packet)
    2017:09:21-11:43:33 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13818: sending encrypted notification INVALID_MESSAGE_ID to "IP_OF_REMOTE_CHECKPOINT_FW":500
    2017:09:21-11:43:35 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13818: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0x6516dd40 (perhaps this is a duplicated packet)
    2017:09:21-11:43:35 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13818: sending encrypted notification INVALID_MESSAGE_ID to "IP_OF_REMOTE_CHECKPOINT_FW":500
    2017:09:21-11:43:37 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13818: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0x6516dd40 (perhaps this is a duplicated packet)
    2017:09:21-11:43:37 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13818: sending encrypted notification INVALID_MESSAGE_ID to "IP_OF_REMOTE_CHECKPOINT_FW":500
    2017:09:21-11:43:39 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13818: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0x6516dd40 (perhaps this is a duplicated packet)
    2017:09:21-11:47:59 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13815: cannot respond to IPsec SA request because no connection is known for 0.0.0.0/0==="IP_OF_OUR_UTM"["IP_OF_OUR_UTM"]..."IP_OF_REMOTE_CHECKPOINT_FW"["IP_OF_REMOTE_CHECKPOINT_FW"]===172.21.0.0/16
    2017:09:21-11:48:35 vpn pluto[6473]: packet from "IP_OF_REMOTE_CHECKPOINT_FW":500: ignoring Vendor ID payload [f4ed19e0c114eb516faaac0ee37daf2807b4381f000000010000138d59c38af3...]
    2017:09:21-11:48:35 vpn pluto[6473]: packet from "IP_OF_REMOTE_CHECKPOINT_FW":500: ignoring Vendor ID payload [FRAGMENTATION]
    2017:09:21-11:48:35 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13820: responding to Main Mode
    2017:09:21-11:48:35 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13820: Peer ID is ID_IPV4_ADDR: '"IP_OF_REMOTE_CHECKPOINT_FW"'
    2017:09:21-11:48:35 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13820: sent MR3, ISAKMP SA established
    2017:09:21-11:48:35 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13820: cannot respond to IPsec SA request because no connection is known for 0.0.0.0/0==="IP_OF_OUR_UTM"["IP_OF_OUR_UTM"]..."IP_OF_REMOTE_CHECKPOINT_FW"["IP_OF_REMOTE_CHECKPOINT_FW"]===10.28.28.0/22
    2017:09:21-11:48:35 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #13820: sending encrypted notification INVALID_ID_INFORMATION to "IP_OF_REMOTE_CHECKPOINT_FW":500
     
    I hope this will be enough, to get an idea about the issue.
     
    Best Regards
     
    RanX
  • 0 in reply to RanX

    [FRAGMENTATION] - what happens if you select 'Support path MTU discovery'?

    Although it's unrelated to this problem, I would recommend changing to a policy that doesn't use 3DES or SHA1 for the IPsec SAs.  3DES is an old, slow algorithm.  AES-128 is faster and more secure.  I would start with the "AES-128 PFS" Policy and change the 'IPsec authentication algorithm' to SHA2.

    Cheers - Bob

     
    Sophos UTM Community Moderator
    Sophos Certified Architect - UTM
    Sophos Certified Engineer - XG
    Gold Solution Partner since 2005
    MediaSoft, Inc. USA
  • 0 in reply to BAlfson
    Hello Bob,
     
    about the algorithms: yes I know ... ;)
    We got a whole bunch of VPNs to customer networks to support them on our software.
    Often the tunnel settings are given by the customer, so I have to take, what I get ...
     
    Setting 'Support path MTU discovery' active did not do me the favour to change anything.
    The INVALID_MESSAGE_ID errors persist.
     
    Another strange behaviour I noticed, when restartig the tunnel can be seen in the log excerpt below.
    When stopping the connection I see a whole lot of 'deleting state' messages for this single tunnel.
    Maybe this is of some help.
     
    Best Regards
     
    RanX
     
    Log:
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14934: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14872: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14894: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14915: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14859: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14909: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14908: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14870: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14875: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14948: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14900: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14881: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14939: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14873: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14857: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14925: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14866: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14943: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14879: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14945: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14923: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14896: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14868: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14916: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14891: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14907: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14884: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14937: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14910: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14902: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14921: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14946: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14930: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14878: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14927: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14920: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14918: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14887: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14882: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14862: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14901: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14898: deleting state (STATE_MAIN_R3)
    2017:09:22-13:04:54 vpn pluto[6473]: "S_LOGFLOOD_VPN_IPsec" #14863: deleting state (STATE_MAIN_R3)
     
     
  • 0 in reply to RanX

    This seems to be a misconfiguration in the Checkpoint as it's attempting to establish the tunnel anew after we believe that it's up.  MAYBE you can correct the situation by switching to an identical Remote Gateway in "Respond only" mode, but I bet you will need to show them your log above where the IPsec SAs are established and then the UTM finds itself "responding to Main Mode."

    Cheers - Bob

     
    Sophos UTM Community Moderator
    Sophos Certified Architect - UTM
    Sophos Certified Engineer - XG
    Gold Solution Partner since 2005
    MediaSoft, Inc. USA
  • 0 in reply to BAlfson
    Hi Bob,
     
    thank you for your proposals !
    I gave "respond only" a try but the VPN wouldn't connect then, so I had to switch it back.
    I was afraid it would turn out to this.
    The Checkpoint is as it is, thus I have to accept it "spamming" my logs, because nobody will touch this on the other side as long as the tunnel keeps working.
    Anyway - at least we tried.
     
    I appreciate your kind help !
     
    RanX
  • 0 in reply to RanX

    Hi RanX,

    I'm having exactly the same problem...did you find a solution?

    Many thanks.

    Kind regards.

    Max.

  • 0 in reply to RanX

    cannot respond to IPsec SA request because no connection is known for 0.0.0.0/0==="IP_OF_OUR_UTM"["IP_OF_OUR_UTM"]..."IP_OF_REMOTE_CHECKPOINT_FW"["IP_OF_REMOTE_CHECKPOINT_FW"]===10.28.28.0/22

     

    A typical checkpoint configuration error. There are often unwanted superneting SAs

     

Unfiltered HTML