KeyID tag issue since 2.4.5



  • Hi all,

    We use PFSense in alot of sort of situations.
    It looks like since the update to firmware 2.4.5 of PFSense the IPSec tunnels are not working anymore when using Peer Identifier: KeyID Tag.
    For now, I had this in 3 complete different situations/networks, when all using KeyID Tag.

    They all 3 had this issue, for now I changed the Peer Identifier to IP Address, but that's not what we like.

    The thing in common is, they all connect to Draytek routers. All worked atleast for more than 1 year. And the Draytek side havent changed/updated.

    Are there more issues known?

    Regards, Marco


  • Rebel Alliance Developer Netgate

    Before 2.4.5, when you chose Key ID tag it wasn't actually configured as Key ID but the type was omitted which made strongSwan guess at what it was. If it looked like something else, say, an IP address, then it was sent using IP address as the type. Not Key ID.

    Now on 2.4.5 it's properly marked as Key ID. If the remote end wasn't actually using Key ID, or it was broken in a similar way, then your previously misconfigured VPN is now not working.

    https://redmine.pfsense.org/issues/9243



  • Hi Jimp,

    I am trying to understand, does this mean, before this PFSense accepted all KeyID tags, no matter what is entered on the other side? That's why it worked.

    I have had contact with Draytek, they call it Local ID and at PFSense side it's called Key ID Tag.

    On both sites I enter the same but no connection.

    Draytek support took a look at it with Syslog and they cannot find cause why it's not accepting.

    1. Do you have any advice?
    2. Is there an alternative?

  • Rebel Alliance Developer Netgate

    @hdservices said in KeyID tag issue since 2.4.5:

    I am trying to understand, does this mean, before this PFSense accepted all KeyID tags, no matter what is entered on the other side? That's why it worked.

    No, it checked the value but it guessed at the type.

    I have had contact with Draytek, they call it Local ID and at PFSense side it's called Key ID Tag.

    That doesn't seem like the same thing. That sounds like it's just a local identifier and not a type of identifier. "Key ID" is a specific type of identifier

    On both sites I enter the same but no connection.

    If what you are entering looks like an IP address, then on pfSense pick one of the IP address options (Peer IP address to use the remote gateway address, or IP address with a specific value)



  • @jimp So if I understand correctly, we should be able to get it working again, but just need to know which type it guessed before.

    It wasn't looking like an IP adress. I just entered a word with only letters.
    That's what I entered at Draytek side at Local ID and at PFSense KeyID Tag.

    Do you have more suggestions of what pfsense would think it was?


  • Rebel Alliance Developer Netgate

    Probably "User Distinguished Name"



  • No luck, yet..

    I tried :

    Any (Couldnt enter anything but worth the try..)
    Disting. Name > No luck
    User distinguashed named > It forced me to change the ID with FQDN, I did on both sides, no luck
    ASN.1.disting. > No luck

    As known KeyID tag > No luck :(

    Any more idea's?

    I do have a test environment setup, so we can test anything we want. I can even give access to it. Draytek & PFsense.

    Thanks for help so far, Regards, Marco


  • Rebel Alliance Developer Netgate

    You have no similar option on the other side to control the format?

    One of the DN/UDN options would normally have worked...

    If you initiate from the Draytek side, what shows up in your logs?



  • @jimp Hi Jimp,

    I do not see any other option on the other side, Draytek says this should be the format (Local ID on their site, Key ID Tag on PFSense side)
    Not getting much of a support there, since the PFsense updates 'breaks' the working VPN.

    Would it help I can give login info to both sides where you can test and check out? If nessecary I can even set up a PFSense 2.4.4 where it works properly.

    Regards Marco


  • Rebel Alliance Developer Netgate

    There may be something else unrelated happening. If you really did try "ASN.1 Distinguished Name" and it didn't work, then the old format wouldn't help you. I looked in the code and in the config and when you choose that, it puts the value in as-is (provided it doesn't start with a #), which is what the old Key ID behavior was.

    I was going to put in an "Auto" mode to let it guess like it did before, but ASN.1 DN already does that.



  • I was not using # - It was really a simple word.
    You can get me a beta version with auto mode option? To see if that works again?


  • Rebel Alliance Developer Netgate

    I'm telling you that choosing ASN.1 Distinguished Name would be functionally identical to "Auto" -- neither one would add a type prefix.

    Check your /var/etc/ipsec/ipsec.conf for the identifier to see how it shows up each time.



  • 9b365d86-0884-4c32-8731-2eb733bdff4c-image.png
    This is the info in the file when I set it to ASN.1 DN and type in a keyword.

    Tunnel does not come online with this setting.


  • Rebel Alliance Developer Netgate

    So rightid doesn't have any kind of type prefix. That's exactly what would have been in the config on 2.4.4-p3 when set to Key ID.



  • WIll it help if I send you log info from PFsense IPsec logging?
    Can I send it to an e-mail address or PM?

    It should see with what Draytek is trying to connect (Draytek is dialling out)


  • Rebel Alliance Developer Netgate

    Sorry, I can't commit to helping with this kind of issue privately. If you can anonymize the logs a bit and post them here, myself or others may be able to assist.



  • Ok did so. Here the working log based on Peer IP address (WAN address)

    Working:
    May 6 07:56:15 charon 10[CFG] vici client 14149 disconnected
    May 6 07:56:15 charon 11[CFG] vici client 14149 requests: list-sas
    May 6 07:56:15 charon 10[CFG] vici client 14149 registered for: list-sa
    May 6 07:56:15 charon 11[CFG] vici client 14149 connected
    May 6 07:56:12 charon 05[CHD] <con1000|289> CHILD_SA con1000{395} state change: INSTALLING => INSTALLED
    May 6 07:56:12 charon 05[IKE] <con1000|289> CHILD_SA con1000{395} established with SPIs c8c66c98_i d000df9e_o and TS 192.168.31.0/24|/0 === 10.0.4.0/24|/0
    May 6 07:56:12 charon 05[CHD] <con1000|289> SPI 0xd000df9e, src x.x.x.x dst x.x.x.x
    May 6 07:56:12 charon 05[CHD] <con1000|289> adding outbound ESP SA
    May 6 07:56:12 charon 05[CHD] <con1000|289> SPI 0xc8c66c98, src x.x.x.x dst x.x.x.x
    May 6 07:56:12 charon 05[CHD] <con1000|289> adding inbound ESP SA
    May 6 07:56:12 charon 05[CHD] <con1000|289> using HMAC_SHA2_256_128 for integrity
    May 6 07:56:12 charon 05[CHD] <con1000|289> using AES_CBC for encryption
    May 6 07:56:12 charon 05[CHD] <con1000|289> CHILD_SA con1000{395} state change: CREATED => INSTALLING
    May 6 07:56:12 charon 05[ENC] parsed QUICK_MODE request 109397397 [ HASH ]
    May 6 07:56:12 charon 05[NET] <con1000|289> received packet: from x.x.x.x[4500] to x.x.x.x[4500] (76 bytes)
    May 6 07:56:12 charon 05[NET] <con1000|289> sending packet: from x.x.x.x[4500] to x.x.x.x[4500] (460 bytes)
    May 6 07:56:12 charon 05[ENC] generating QUICK_MODE response 109397397 [ HASH SA No KE ID ID ]
    May 6 07:56:12 charon 05[IKE] <con1000|289> received 3600s lifetime, configured 0s
    May 6 07:56:12 charon 05[CFG] <con1000|289> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
    May 6 07:56:12 charon 05[CFG] <con1000|289> configured proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
    May 6 07:56:12 charon 05[CFG] <con1000|289> received proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/MODP_2048/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_MD5_96/MODP_2048/NO_EXT_SEQ
    May 6 07:56:12 charon 05[CFG] <con1000|289> proposal matches
    May 6 07:56:12 charon 05[CFG] <con1000|289> selecting proposal:
    May 6 07:56:12 charon 05[CFG] <con1000|289> config: 192.168.31.0/24|/0, received: 192.168.31.0/24|/0 => match: 192.168.31.0/24|/0
    May 6 07:56:12 charon 05[CFG] <con1000|289> selecting traffic selectors for us:
    May 6 07:56:12 charon 05[CFG] <con1000|289> config: 10.0.4.0/24|/0, received: 10.0.4.0/24|/0 => match: 10.0.4.0/24|/0
    May 6 07:56:12 charon 05[CFG] <con1000|289> selecting traffic selectors for other:
    May 6 07:56:12 charon 05[CFG] <con1000|289> found matching child config "con1000" with prio 10
    May 6 07:56:12 charon 05[CFG] <con1000|289> candidate "con1000" with prio 5+5
    May 6 07:56:12 charon 05[CFG] <con1000|289> 10.0.4.0/24|/0
    May 6 07:56:12 charon 05[CFG] <con1000|289> proposing traffic selectors for other:
    May 6 07:56:12 charon 05[CFG] <con1000|289> 192.168.31.0/24|/0
    May 6 07:56:12 charon 05[CFG] <con1000|289> proposing traffic selectors for us:
    May 6 07:56:12 charon 05[CFG] <con1000|289> looking for a child config for 192.168.31.0/24|/0 === 10.0.4.0/24|/0
    May 6 07:56:12 charon 05[ENC] parsed QUICK_MODE request 109397397 [ HASH SA No KE ID ID ]
    May 6 07:56:12 charon 05[NET] <con1000|289> received packet: from x.x.x.x[4500] to x.x.x.x[4500] (508 bytes)
    May 6 07:56:12 charon 11[NET] <con1000|289> sending packet: from x.x.x.x[4500] to x.x.x.x[4500] (92 bytes)
    May 6 07:56:12 charon 11[ENC] <con1000|289> generating ID_PROT response 0 [ ID HASH ]
    May 6 07:56:12 charon 11[IKE] <con1000|289> IKE_SA con1000[289] state change: CONNECTING => ESTABLISHED
    May 6 07:56:12 charon 11[IKE] <con1000|289> IKE_SA con1000[289] established between x.x.x.x[x.x.x.x]...x.x.x.x[192.168.1.60]
    May 6 07:56:12 charon 11[CFG] <289> selected peer config "con1000"
    May 6 07:56:12 charon 11[CFG] <289> candidate "con1000", match: 1/20/3100 (me/other/ike)
    May 6 07:56:12 charon 11[CFG] <289> candidate "bypasslan", match: 1/1/24 (me/other/ike)
    May 6 07:56:12 charon 11[CFG] <289> looking for pre-shared key peer configs matching x.x.x.x...x.x.x.x[192.168.1.60]
    May 6 07:56:12 charon 11[ENC] <289> parsed ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
    May 6 07:56:12 charon 11[NET] <289> received packet: from x.x.x.x[4500] to x.x.x.x[4500] (108 bytes)
    May 6 07:56:11 charon 11[NET] <289> sending packet: from x.x.x.x[500] to x.x.x.x[500] (396 bytes)
    May 6 07:56:11 charon 11[ENC] <289> generating ID_PROT response 0 [ KE No NAT-D NAT-D ]
    May 6 07:56:11 charon 11[CFG] <289> candidate "con1000", match: 1/1/3100 (me/other/ike)
    May 6 07:56:11 charon 11[CFG] <289> candidate "bypasslan", match: 1/1/24 (me/other/ike)
    May 6 07:56:11 charon 11[IKE] <289> remote host is behind NAT
    May 6 07:56:11 charon 11[ENC] <289> parsed ID_PROT request 0 [ KE No NAT-D NAT-D ]
    May 6 07:56:11 charon 11[NET] <289> received packet: from x.x.x.x[500] to x.x.x.x[500] (380 bytes)
    May 6 07:56:11 charon 11[NET] <289> sending packet: from x.x.x.x[500] to x.x.x.x[500] (136 bytes)
    May 6 07:56:11 charon 11[ENC] <289> generating ID_PROT response 0 [ SA V V V ]
    May 6 07:56:11 charon 11[IKE] <289> sending NAT-T (RFC 3947) vendor ID
    May 6 07:56:11 charon 11[IKE] <289> sending DPD vendor ID
    May 6 07:56:11 charon 11[IKE] <289> sending XAuth vendor ID
    May 6 07:56:11 charon 11[CFG] <289> selected proposal: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048
    May 6 07:56:11 charon 11[CFG] <289> configured proposals: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048
    May 6 07:56:11 charon 11[CFG] <289> received proposals: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048, IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_2048, IKE:AES_CBC_256/HMAC_MD5_96/PRF_HMAC_MD5/MODP_2048, IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1536, IKE:AES_CBC_256/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1536, IKE:AES_CBC_192/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_2048, IKE:AES_CBC_192/HMAC_MD5_96/PRF_HMAC_MD5/MODP_2048, IKE:AES_CBC_128/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1536, IKE:AES_CBC_128/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1536, IKE:3DES_CBC/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1536, IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1536
    May 6 07:56:11 charon 11[CFG] <289> proposal matches
    May 6 07:56:11 charon 11[CFG] <289> selecting proposal:
    May 6 07:56:11 charon 11[IKE] <289> IKE_SA (unnamed)[289] state change: CREATED => CONNECTING
    May 6 07:56:11 charon 11[IKE] <289> x.x.x.x is initiating a Main Mode IKE_SA
    May 6 07:56:11 charon 11[IKE] <289> received draft-ietf-ipsec-nat-t-ike-00 vendor ID
    May 6 07:56:11 charon 11[IKE] <289> received draft-ietf-ipsec-nat-t-ike-02 vendor ID
    May 6 07:56:11 charon 11[IKE] <289> received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
    May 6 07:56:11 charon 11[IKE] <289> received draft-ietf-ipsec-nat-t-ike-03 vendor ID
    May 6 07:56:11 charon 11[IKE] <289> received NAT-T (RFC 3947) vendor ID
    May 6 07:56:11 charon 11[IKE] <289> received DPD vendor ID
    May 6 07:56:11 charon 11[CFG] <289> found matching ike config: x.x.x.x...x.x.x.x with prio 3100
    May 6 07:56:11 charon 11[CFG] <289> candidate: x.x.x.x...x.x.x.x, prio 3100
    May 6 07:56:11 charon 11[CFG] <289> candidate: %any...%any, prio 24
    May 6 07:56:11 charon 11[CFG] <289> looking for an IKEv1 config for x.x.x.x...x.x.x.x
    May 6 07:56:11 charon 11[ENC] <289> parsed ID_PROT request 0 [ SA V V V V V V ]
    May 6 07:56:11 charon 11[NET] <289> received packet: from x.x.x.x[500] to x.x.x.x[500] (556 bytes)
    May 6 07:56:10 charon 05[CFG] vici client 14148 disconnected
    May 6 07:56:10 charon 13[CFG] vici client 14148 requests: list-sas
    May 6 07:56:10 charon 05[CFG] vici client 14148 registered for: list-sa
    May 6 07:56:10 charon 13[CFG] vici client 14148 connected
    May 6 07:56:10 charon 13[IKE] <con1000|288> IKE_SA con1000[288] state change: DELETING => DESTROYING
    May 6 07:56:10 charon 13[NET] <con1000|288> sending packet: from x.x.x.x[4500] to x.x.x.x[4500] (108 bytes)
    May 6 07:56:10 charon 13[ENC] generating INFORMATIONAL_V1 request 2804867589 [ HASH D ]
    May 6 07:56:10 charon 13[IKE] <con1000|288> IKE_SA con1000[288] state change: ESTABLISHED => DELETING
    May 6 07:56:10 charon 13[IKE] <con1000|288> sending DELETE for IKE_SA con1000[288]
    May 6 07:56:10 charon 13[IKE] <con1000|288> deleting IKE_SA con1000[288] between x.x.x.x[x.x.x.x]...x.x.x.x[192.168.1.60]
    May 6 07:56:10 charon 13[IKE] <con1000|288> activating ISAKMP_DELETE task
    May 6 07:56:10 charon 13[IKE] <con1000|288> activating new tasks
    May 6 07:56:10 charon 13[NET] <con1000|288> sending packet: from x.x.x.x[4500] to x.x.x.x[4500] (92 bytes)
    May 6 07:56:10 charon 13[ENC] generating INFORMATIONAL_V1 request 738891620 [ HASH D ]
    May 6 07:56:10 charon 13[IKE] <con1000|288> sending DELETE for ESP CHILD_SA with SPI c8de6673
    May 6 07:56:10 charon 13[CHD] <con1000|288> CHILD_SA con1000{394} state change: DELETED => DESTROYING
    May 6 07:56:10 charon 13[CHD] <con1000|288> CHILD_SA con1000{394} state change: DELETING => DELETED
    May 6 07:56:10 charon 13[IKE] <con1000|288> closing CHILD_SA con1000{394} with SPIs c8de6673_i (3992 bytes) d000df9d_o (8432 bytes) and TS 192.168.31.0/24|/0 === 10.0.4.0/24|/0
    May 6 07:56:10 charon 13[CHD] <con1000|288> CHILD_SA con1000{394} state change: INSTALLED => DELETING
    May 6 07:56:10 charon 13[IKE] <con1000|288> activating QUICK_DELETE task
    May 6 07:56:10 charon 13[IKE] <con1000|288> activating new tasks
    May 6 07:56:10 charon 13[IKE] <con1000|288> queueing ISAKMP_DELETE task
    May 6 07:56:10 charon 13[IKE] <con1000|288> queueing QUICK_DELETE task
    May 6 07:56:10 charon 11[CFG] received stroke: terminate 'con1000[288]'
    May 6 07:56:06 charon 11[CFG] vici client 14147 disconnected
    May 6 07:56:06 charon 16[CFG] vici client 14147 requests: list-sas
    May 6 07:56:06 charon 11[CFG] vici client 14147 registered for: list-sa
    May 6 07:56:06 charon 11[CFG] vici client 14147 connected

    And here the log not working with ASN.1 defined now (So in previous version I used KeyIDTag)
    Here you see the VPN fail

    May 6 07:58:52 charon 10[CFG] vici client 14177 disconnected
    May 6 07:58:52 charon 10[CFG] vici client 14177 requests: list-sas
    May 6 07:58:52 charon 10[CFG] vici client 14177 registered for: list-sa
    May 6 07:58:52 charon 06[CFG] vici client 14177 connected
    May 6 07:58:47 charon 08[CFG] vici client 14176 disconnected
    May 6 07:58:47 charon 08[CFG] vici client 14176 requests: list-sas
    May 6 07:58:47 charon 06[CFG] vici client 14176 registered for: list-sa
    May 6 07:58:47 charon 08[CFG] vici client 14176 connected
    May 6 07:58:47 charon 08[IKE] <290> IKE_SA (unnamed)[290] state change: CONNECTING => DESTROYING
    May 6 07:58:47 charon 08[NET] <290> sending packet: from x.x.x.x[4500] to x.x.x.x[4500] (108 bytes)
    May 6 07:58:47 charon 08[ENC] <290> generating INFORMATIONAL_V1 request 626828801 [ HASH N(AUTH_FAILED) ]
    May 6 07:58:47 charon 08[IKE] <290> activating INFORMATIONAL task
    May 6 07:58:47 charon 08[IKE] <290> activating new tasks
    May 6 07:58:47 charon 08[IKE] <290> queueing INFORMATIONAL task
    May 6 07:58:47 charon 08[IKE] <290> found 1 matching config, but none allows pre-shared key authentication using Main Mode
    May 6 07:58:47 charon 08[CFG] <290> candidate "bypasslan", match: 1/1/24 (me/other/ike)
    May 6 07:58:47 charon 08[CFG] <290> looking for pre-shared key peer configs matching x.x.x.x...x.x.x.x[192.168.1.60]
    May 6 07:58:47 charon 08[ENC] <290> parsed ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
    May 6 07:58:47 charon 08[NET] <290> received packet: from x.x.x.x[4500] to x.x.x.x[4500] (108 bytes)
    May 6 07:58:47 charon 08[NET] <290> sending packet: from x.x.x.x[500] to x.x.x.x[500] (396 bytes)
    May 6 07:58:47 charon 08[ENC] <290> generating ID_PROT response 0 [ KE No NAT-D NAT-D ]
    May 6 07:58:47 charon 08[CFG] <290> candidate "con1000", match: 1/1/3100 (me/other/ike)
    May 6 07:58:47 charon 08[CFG] <290> candidate "bypasslan", match: 1/1/24 (me/other/ike)
    May 6 07:58:47 charon 08[IKE] <290> remote host is behind NAT
    May 6 07:58:47 charon 08[ENC] <290> parsed ID_PROT request 0 [ KE No NAT-D NAT-D ]
    May 6 07:58:47 charon 08[NET] <290> received packet: from x.x.x.x[500] to x.x.x.x[500] (380 bytes)
    May 6 07:58:47 charon 08[NET] <290> sending packet: from x.x.x.x[500] to x.x.x.x[500] (136 bytes)
    May 6 07:58:47 charon 08[IKE] <290> received retransmit of request with ID 0, retransmitting response
    May 6 07:58:47 charon 08[NET] <290> received packet: from x.x.x.x[500] to x.x.x.x[500] (556 bytes)
    May 6 07:58:44 charon 16[NET] <290> sending packet: from x.x.x.x[500] to x.x.x.x[500] (136 bytes)
    May 6 07:58:44 charon 16[ENC] <290> generating ID_PROT response 0 [ SA V V V ]
    May 6 07:58:44 charon 16[IKE] <290> sending NAT-T (RFC 3947) vendor ID
    May 6 07:58:44 charon 16[IKE] <290> sending DPD vendor ID
    May 6 07:58:44 charon 16[IKE] <290> sending XAuth vendor ID
    May 6 07:58:44 charon 16[CFG] <290> selected proposal: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048
    May 6 07:58:44 charon 16[CFG] <290> configured proposals: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048
    May 6 07:58:44 charon 16[CFG] <290> received proposals: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048, IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_2048, IKE:AES_CBC_256/HMAC_MD5_96/PRF_HMAC_MD5/MODP_2048, IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1536, IKE:AES_CBC_256/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1536, IKE:AES_CBC_192/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_2048, IKE:AES_CBC_192/HMAC_MD5_96/PRF_HMAC_MD5/MODP_2048, IKE:AES_CBC_128/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1536, IKE:AES_CBC_128/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1536, IKE:3DES_CBC/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1536, IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1536
    May 6 07:58:44 charon 16[CFG] <290> proposal matches
    May 6 07:58:44 charon 16[CFG] <290> selecting proposal:
    May 6 07:58:44 charon 16[IKE] <290> IKE_SA (unnamed)[290] state change: CREATED => CONNECTING
    May 6 07:58:44 charon 16[IKE] <290> x.x.x.x is initiating a Main Mode IKE_SA
    May 6 07:58:44 charon 16[IKE] <290> received draft-ietf-ipsec-nat-t-ike-00 vendor ID
    May 6 07:58:44 charon 16[IKE] <290> received draft-ietf-ipsec-nat-t-ike-02 vendor ID
    May 6 07:58:44 charon 16[IKE] <290> received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
    May 6 07:58:44 charon 16[IKE] <290> received draft-ietf-ipsec-nat-t-ike-03 vendor ID
    May 6 07:58:44 charon 16[IKE] <290> received NAT-T (RFC 3947) vendor ID
    May 6 07:58:44 charon 16[IKE] <290> received DPD vendor ID
    May 6 07:58:44 charon 16[CFG] <290> found matching ike config: x.x.x.x...x.x.x.x with prio 3100
    May 6 07:58:44 charon 16[CFG] <290> candidate: x.x.x.x...x.x.x.x, prio 3100
    May 6 07:58:44 charon 16[CFG] <290> candidate: %any...%any, prio 24
    May 6 07:58:44 charon 16[CFG] <290> looking for an IKEv1 config for x.x.x.x...x.x.x.x
    May 6 07:58:44 charon 16[ENC] <290> parsed ID_PROT request 0 [ SA V V V V V V ]
    May 6 07:58:44 charon 16[NET] <290> received packet: from x.x.x.x[500] to x.x.x.x[500] (556 bytes)
    May 6 07:58:42 charon 16[CFG] ignoring acquire, connection attempt pending
    May 6 07:58:42 charon 08[KNL] creating acquire job for policy x.x.x.x/32|/0 === x.x.x.x/32|/0 with reqid {17}
    May 6 07:58:42 charon 08[CFG] vici client 14175 disconnected
    May 6 07:58:42 charon 16[CFG] vici client 14175 requests: list-sas
    May 6 07:58:42 charon 08[CFG] vici client 14175 registered for: list-sa
    May 6 07:58:42 charon 12[CFG] vici client 14175 connected
    May 6 07:58:42 charon 12[IKE] <con1000|289> IKE_SA con1000[289] state change: DELETING => DESTROYING
    May 6 07:58:42 charon 12[NET] <con1000|289> sending packet: from x.x.x.x[4500] to x.x.x.x[4500] (108 bytes)
    May 6 07:58:42 charon 12[ENC] generating INFORMATIONAL_V1 request 1940305061 [ HASH D ]
    May 6 07:58:42 charon 12[IKE] <con1000|289> IKE_SA con1000[289] state change: ESTABLISHED => DELETING
    May 6 07:58:42 charon 12[IKE] <con1000|289> sending DELETE for IKE_SA con1000[289]
    May 6 07:58:42 charon 12[IKE] <con1000|289> deleting IKE_SA con1000[289] between x.x.x.x[x.x.x.x]...x.x.x.x[192.168.1.60]
    May 6 07:58:42 charon 12[IKE] <con1000|289> activating ISAKMP_DELETE task
    May 6 07:58:42 charon 12[IKE] <con1000|289> activating new tasks
    May 6 07:58:42 charon 12[NET] <con1000|289> sending packet: from x.x.x.x[4500] to x.x.x.x[4500] (92 bytes)
    May 6 07:58:42 charon 12[ENC] generating INFORMATIONAL_V1 request 3096891326 [ HASH D ]
    May 6 07:58:42 charon 12[IKE] <con1000|289> sending DELETE for ESP CHILD_SA with SPI c8c66c98
    May 6 07:58:42 charon 12[CHD] <con1000|289> CHILD_SA con1000{395} state change: DELETED => DESTROYING
    May 6 07:58:42 charon 12[CHD] <con1000|289> CHILD_SA con1000{395} state change: DELETING => DELETED
    May 6 07:58:42 charon 12[IKE] <con1000|289> closing CHILD_SA con1000{395} with SPIs c8c66c98_i (14792 bytes) d000df9e_o (31252 bytes) and TS 192.168.31.0/24|/0 === 10.0.4.0/24|/0
    May 6 07:58:42 charon 12[CHD] <con1000|289> CHILD_SA con1000{395} state change: INSTALLED => DELETING
    May 6 07:58:42 charon 12[IKE] <con1000|289> activating QUICK_DELETE task
    May 6 07:58:42 charon 12[IKE] <con1000|289> activating new tasks
    May 6 07:58:42 charon 12[IKE] <con1000|289> queueing ISAKMP_DELETE task
    May 6 07:58:42 charon 12[IKE] <con1000|289> queueing QUICK_DELETE task
    May 6 07:58:42 charon 16[CFG] received stroke: terminate 'con1000[289]'



  • Do you have time to look at my logs ;-)?



  • Anytime already ? Regards Marco


  • Rebel Alliance Developer Netgate

    @hdservices said in KeyID tag issue since 2.4.5:

    May 6 07:58:47	charon		08[CFG] <290> candidate "bypasslan", match: 1/1/24 (me/other/ike)
    May 6 07:58:47	charon		08[CFG] <290> looking for pre-shared key peer configs matching x.x.x.x...x.x.x.x[192.168.1.60]
    May 6 07:58:47	charon		08[ENC] <290> parsed ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
    May 6 07:58:47	charon		08[NET] <290> received packet: from x.x.x.x[4500] to x.x.x.x[4500] (108 bytes)
    May 6 07:58:47	charon		08[NET] <290> sending packet: from x.x.x.x[500] to x.x.x.x[500] (396 bytes)
    May 6 07:58:47	charon		08[ENC] <290> generating ID_PROT response 0 [ KE No NAT-D NAT-D ]
    May 6 07:58:47	charon		08[CFG] <290> candidate "con1000", match: 1/1/3100 (me/other/ike)
    May 6 07:58:47	charon		08[CFG] <290> candidate "bypasslan", match: 1/1/24 (me/other/ike)
    

    It's selecting bypasslan which means the P1 info didn't match. Either you didn't match up the ID (Looks like the remote is sending 192.168.1.60 as its ID) or the Pre-Shared key for 192.168.1.60 could not be found.


Log in to reply