IPSEC Phase 2 issue on 2.2 beta



  • I upgraded from 2.15 to 2.2 beta and it seems like only my first phase 2 entry in a site-to-site VPN is working.  All the other entries afterwards are not even though they are green and show working in the gui status.  This is a pretty glaring problem, so I assume somebody knows about it?



  • I'm not aware of any issues related to that. There aren't any open bugs along those lines, but might be some edge case we haven't seen yet. What's in your IPsec logs?



  • Under Overview in the IPSEC status, it only lists my first phase 2 entry, even though I've tried to give interesting traffic on all subnets.  SPD shows them all though.

    Here are the logs.  Only 172.16.0.0/12 is working.  My 192.168.0.0/16 is not coming up, nor some 10.x.x.x networks I defined as phase 2.  All worked under 2.1x.

    Oct 24 06:21:55 	charon: 06[ENC] parsed INFORMATIONAL_V1 request 1160328775 [ HASH N(DPD_ACK) ]
    Oct 24 06:21:55 	charon: 06[NET] received packet: from 12.31.45.2[500] to 174.69.73.119[500] (92 bytes)
    Oct 24 06:21:55 	charon: 15[NET] sending packet: from 174.69.73.119[500] to 12.31.45.2[500] (92 bytes)
    Oct 24 06:21:55 	charon: 15[ENC] generating INFORMATIONAL_V1 request 3806859028 [ HASH N(DPD) ]
    Oct 24 06:21:55 	charon: 15[IKE] sending DPD request
    Oct 24 06:21:55 	charon: 15[IKE] <con1|1> sending DPD request
    Oct 24 06:21:45 	charon: 15[ENC] parsed INFORMATIONAL_V1 request 2864146621 [ HASH N(DPD_ACK) ]
    Oct 24 06:21:45 	charon: 15[NET] received packet: from 12.31.45.2[500] to 174.69.73.119[500] (92 bytes)
    Oct 24 06:21:45 	charon: 13[NET] sending packet: from 174.69.73.119[500] to 12.31.45.2[500] (92 bytes)
    Oct 24 06:21:45 	charon: 13[ENC] generating INFORMATIONAL_V1 request 527709969 [ HASH N(DPD) ]
    Oct 24 06:21:45 	charon: 13[IKE] sending DPD request
    Oct 24 06:21:45 	charon: 13[IKE] <con1|1> sending DPD request
    Oct 24 06:21:27 	charon: 13[ENC] parsed INFORMATIONAL_V1 request 2103794363 [ HASH N(DPD_ACK) ]
    Oct 24 06:21:27 	charon: 13[NET] received packet: from 12.31.45.2[500] to 174.69.73.119[500] (92 bytes)
    Oct 24 06:21:27 	charon: 13[NET] sending packet: from 174.69.73.119[500] to 12.31.45.2[500] (92 bytes)
    Oct 24 06:21:27 	charon: 13[ENC] generating INFORMATIONAL_V1 request 3610101397 [ HASH N(DPD) ]
    Oct 24 06:21:27 	charon: 13[IKE] sending DPD request
    Oct 24 06:21:27 	charon: 13[IKE] <con1|1> sending DPD request
    Oct 24 06:21:15 	charon: 13[ENC] parsed INFORMATIONAL_V1 request 1904149608 [ HASH N(DPD_ACK) ]
    Oct 24 06:21:15 	charon: 13[NET] received packet: from 12.31.45.2[500] to 174.69.73.119[500] (92 bytes)
    Oct 24 06:21:15 	charon: 13[NET] sending packet: from 174.69.73.119[500] to 12.31.45.2[500] (92 bytes)
    Oct 24 06:21:15 	charon: 13[ENC] generating INFORMATIONAL_V1 request 745622136 [ HASH N(DPD) ]
    Oct 24 06:21:15 	charon: 13[IKE] sending DPD request
    Oct 24 06:21:15 	charon: 13[IKE] <con1|1> sending DPD request
    Oct 24 06:21:05 	charon: 12[CFG] received stroke: route 'con1'
    Oct 24 06:21:05 	charon: 14[CFG] added configuration 'con1'
    Oct 24 06:21:05 	charon: 14[CFG] received stroke: add connection 'con1'
    Oct 24 06:21:05 	charon: 14[CFG] deleted connection 'con1'
    Oct 24 06:21:05 	charon: 14[CFG] received stroke: delete connection 'con1'
    Oct 24 06:21:05 	charon: 12[CFG] received stroke: unroute 'con1'
    Oct 24 06:21:05 	charon: 14[CFG] rereading crls from '/var/etc/ipsec/ipsec.d/crls'
    Oct 24 06:21:05 	charon: 14[CFG] rereading attribute certificates from '/var/etc/ipsec/ipsec.d/acerts'
    Oct 24 06:21:05 	charon: 14[CFG] rereading aa certificates from '/var/etc/ipsec/ipsec.d/aacerts'
    Oct 24 06:21:05 	charon: 14[CFG] rereading ocsp signer certificates from '/var/etc/ipsec/ipsec.d/ocspcerts'
    Oct 24 06:21:05 	charon: 14[CFG] loaded ca certificate "C=US, ST=Ohio, L=Toledo, O=Home, E=noone@nowhere.com, CN=home-ca" from '/var/etc/ipsec/ipsec.d/cacerts/1d563641.0.crt'
    Oct 24 06:21:05 	charon: 14[CFG] rereading ca certificates from '/var/etc/ipsec/ipsec.d/cacerts'
    Oct 24 06:21:05 	charon: 14[CFG] loaded IKE secret for 12.31.45.2
    Oct 24 06:21:05 	charon: 14[CFG] loading secrets from '/var/etc/ipsec/ipsec.secrets'
    Oct 24 06:21:05 	charon: 14[CFG] rereading secrets
    Oct 24 06:21:01 	charon: 16[NET] sending packet: from 174.69.73.119[500] to 12.31.45.2[500] (60 bytes)
    Oct 24 06:21:01 	charon: 16[ENC] generating QUICK_MODE request 4035439451 [ HASH ]
    Oct 24 06:21:01 	charon: 16[IKE] CHILD_SA con1{1} established with SPIs cceacaa2_i 5c16dbcc_o and TS 10.240.12.0/24|/0 === 172.16.0.0/12|/0
    Oct 24 06:21:01 	charon: 16[IKE] <con1|1> CHILD_SA con1{1} established with SPIs cceacaa2_i 5c16dbcc_o and TS 10.240.12.0/24|/0 === 172.16.0.0/12|/0
    Oct 24 06:21:01 	charon: 16[IKE] received 28800s lifetime, configured 0s
    Oct 24 06:21:01 	charon: 16[IKE] <con1|1> received 28800s lifetime, configured 0s
    Oct 24 06:21:01 	charon: 16[ENC] parsed QUICK_MODE response 4035439451 [ HASH SA No ID ID N((24576)) ]
    Oct 24 06:21:01 	charon: 16[NET] received packet: from 12.31.45.2[500] to 174.69.73.119[500] (204 bytes)
    Oct 24 06:21:01 	charon: 16[NET] sending packet: from 174.69.73.119[500] to 12.31.45.2[500] (252 bytes)
    Oct 24 06:21:01 	charon: 16[ENC] generating QUICK_MODE request 4035439451 [ HASH SA No ID ID ]
    Oct 24 06:21:01 	charon: 16[IKE] IKE_SA con1[1] established between 174.69.73.119[174.69.73.119]...12.31.45.2[12.31.45.2]</con1|1></con1|1></con1|1></con1|1></con1|1></con1|1>
    


  • @cmb:

    I'm not aware of any issues related to that. There aren't any open bugs along those lines,

    Isn't this what Karl has been reporting for some time, asking for the cisco unity plugin?
    https://forum.pfsense.org/index.php?topic=79737.msg452796#msg452796



  • Well, in light of that, I'm moving back to 2.15.  It's just a home firewall, but I do like my VPN to work.  :)



  • there is something going on there.
    https://redmine.pfsense.org/issues/3961



  • Looks like there are a number of useful fixes in strongswan 5.2.1 (https://wiki.strongswan.org/versions/53):

    • kernel-pfroute fixes

    • kernel-pfkey fixes

    • cisco unity fixes

    • IKEv1 re-keying fixes



  • Looking forward to any updates on this - basically it's a problem interoperating with an IPSec tunnel with multiple subnets against a Sonicwall NSA 3600.



  • @karl23:

    Looking forward to any updates on this - basically it's a problem interoperating with an IPSec tunnel with multiple subnets against a Sonicwall NSA 3600.

    It's against any device as far as I can tell.



  • I'm seeing issues similar to those described in this thread–and possibly some differences.  I thought I'd share what I'm seeing.

    Running the snapshot from OCT 27.

    IPSec tunnel between PFSense and Cisco ASA 9.1.5.

    Two phase 2 networks configured.

    If I initiate traffic from behind the PFSense system, I get an Phase 1 SA, and no phase 2-regardless of which network I'm trying to hit in the P2.

    If I initiate traffic from the behind the ASA, it builds the Phase 1 and the Phase 2 for any network in the Phase 2.

    If that network is the first network in the Phase 2 list--I can pass traffic without issue.  If that network is not first, I can't pass any traffic regardless.

    If I switch the order of the Phase 2 and restart the tunnel from the ASA side, I can now pass traffic on the new 1st entry.

    Here is the log data for initiating traffic from behind PFSense and only getting a P1 SA:

    Oct 27 21:22:26	charon: 16[MGR] check-in of IKE_SA successful.
    Oct 27 21:22:26	charon: 16[MGR] <con1|9> check-in of IKE_SA successful.
    Oct 27 21:22:26	charon: 16[MGR] checkin IKE_SA con1[9]
    Oct 27 21:22:26	charon: 16[MGR] <con1|9> checkin IKE_SA con1[9]
    Oct 27 21:22:26	charon: 05[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500]
    Oct 27 21:22:26	charon: 05[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500]
    Oct 27 21:22:26	charon: 16[IKE] nothing to initiate
    Oct 27 21:22:26	charon: 16[IKE] <con1|9> nothing to initiate
    Oct 27 21:22:26	charon: 16[IKE] activating new tasks
    Oct 27 21:22:26	charon: 16[IKE] <con1|9> activating new tasks
    Oct 27 21:22:26	charon: 16[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (92 bytes)
    Oct 27 21:22:26	charon: 16[NET] <con1|9> sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (92 bytes)
    Oct 27 21:22:26	charon: 16[IKE] activating ISAKMP_DPD task
    Oct 27 21:22:26	charon: 16[IKE] <con1|9> activating ISAKMP_DPD task
    Oct 27 21:22:26	charon: 16[IKE] activating new tasks
    Oct 27 21:22:26	charon: 16[IKE] <con1|9> activating new tasks
    Oct 27 21:22:26	charon: 16[IKE] queueing ISAKMP_DPD task
    Oct 27 21:22:26	charon: 16[IKE] <con1|9> queueing ISAKMP_DPD task
    Oct 27 21:22:26	charon: 16[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500] (92 bytes)
    Oct 27 21:22:26	charon: 16[NET] <con1|9> received packet: from 2.2.2.2[500] to 1.1.1.1[500] (92 bytes)
    Oct 27 21:22:26	charon: 16[MGR] IKE_SA con1[9] successfully checked out
    Oct 27 21:22:26	charon: 16[MGR] IKE_SA con1[9] successfully checked out
    Oct 27 21:22:26	charon: 16[MGR] checkout IKE_SA by message
    Oct 27 21:22:26	charon: 16[MGR] checkout IKE_SA by message
    Oct 27 21:22:26	charon: 04[NET] waiting for data on sockets
    Oct 27 21:22:26	charon: 04[NET] waiting for data on sockets
    Oct 27 21:22:26	charon: 04[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500]
    Oct 27 21:22:26	charon: 04[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500]
    Oct 27 21:22:13	charon: 16[MGR] check-in of IKE_SA successful.
    Oct 27 21:22:13	charon: 16[MGR] <con1|9> check-in of IKE_SA successful.
    Oct 27 21:22:13	charon: 16[MGR] checkin IKE_SA con1[9]
    Oct 27 21:22:13	charon: 16[MGR] <con1|9> checkin IKE_SA con1[9]
    Oct 27 21:22:13	charon: 16[MGR] IKE_SA con1[9] successfully checked out
    Oct 27 21:22:13	charon: 16[MGR] IKE_SA con1[9] successfully checked out
    Oct 27 21:22:13	charon: 16[MGR] checkout IKE_SA
    Oct 27 21:22:13	charon: 16[MGR] checkout IKE_SA
    Oct 27 21:22:13	charon: 16[MGR] check-in of IKE_SA successful.
    Oct 27 21:22:13	charon: 16[MGR] <con1|9> check-in of IKE_SA successful.
    Oct 27 21:22:13	charon: 16[MGR] checkin IKE_SA con1[9]
    Oct 27 21:22:13	charon: 16[MGR] <con1|9> checkin IKE_SA con1[9]
    Oct 27 21:22:13	charon: 16[MGR] IKE_SA con1[9] successfully checked out
    Oct 27 21:22:13	charon: 16[MGR] IKE_SA con1[9] successfully checked out
    Oct 27 21:22:13	charon: 16[MGR] checkout IKE_SA
    Oct 27 21:22:13	charon: 16[MGR] checkout IKE_SA
    Oct 27 21:22:13	charon: 03[MGR] check-in of IKE_SA successful.
    Oct 27 21:22:13	charon: 03[MGR] <con1|9> check-in of IKE_SA successful.
    Oct 27 21:22:13	charon: 03[MGR] checkin IKE_SA con1[9]
    Oct 27 21:22:13	charon: 03[MGR] <con1|9> checkin IKE_SA con1[9]
    Oct 27 21:22:13	charon: 03[MGR] IKE_SA con1[9] successfully checked out
    Oct 27 21:22:13	charon: 03[MGR] IKE_SA con1[9] successfully checked out
    Oct 27 21:22:13	charon: 03[MGR] checkout IKE_SA
    Oct 27 21:22:13	charon: 03[MGR] checkout IKE_SA
    Oct 27 21:22:09	charon: 03[MGR] check-in of IKE_SA successful.
    Oct 27 21:22:09	charon: 03[MGR] <con1|9> check-in of IKE_SA successful.
    Oct 27 21:22:09	charon: 03[MGR] checkin IKE_SA con1[9]
    Oct 27 21:22:09	charon: 03[MGR] <con1|9> checkin IKE_SA con1[9]
    Oct 27 21:22:09	charon: 03[IKE] nothing to initiate
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> nothing to initiate
    Oct 27 21:22:09	charon: 03[IKE] activating new tasks
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> activating new tasks
    Oct 27 21:22:09	charon: 03[IKE] maximum IKE_SA lifetime 28622s
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> maximum IKE_SA lifetime 28622s
    Oct 27 21:22:09	charon: 03[IKE] scheduling reauthentication in 28082s
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> scheduling reauthentication in 28082s
    Oct 27 21:22:09	charon: 03[IKE] IKE_SA con1[9] state change: CONNECTING => ESTABLISHED
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> IKE_SA con1[9] state change: CONNECTING => ESTABLISHED
    Oct 27 21:22:09	charon: 03[IKE] IKE_SA con1[9] established between 1.1.1.1[1.1.1.1]...2.2.2.2[2.2.2.2]
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> IKE_SA con1[9] established between 1.1.1.1[1.1.1.1]...2.2.2.2[2.2.2.2]
    Oct 27 21:22:09	charon: 03[IKE] received DPD vendor ID
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> received DPD vendor ID
    Oct 27 21:22:09	charon: 03[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500] (92 bytes)
    Oct 27 21:22:09	charon: 03[NET] <con1|9> received packet: from 2.2.2.2[500] to 1.1.1.1[500] (92 bytes)
    Oct 27 21:22:09	charon: 03[MGR] IKE_SA con1[9] successfully checked out
    Oct 27 21:22:09	charon: 03[MGR] IKE_SA con1[9] successfully checked out
    Oct 27 21:22:09	charon: 03[MGR] checkout IKE_SA by message
    Oct 27 21:22:09	charon: 03[MGR] checkout IKE_SA by message
    Oct 27 21:22:09	charon: 04[NET] waiting for data on sockets
    Oct 27 21:22:09	charon: 04[NET] waiting for data on sockets
    Oct 27 21:22:09	charon: 04[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500]
    Oct 27 21:22:09	charon: 04[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500]
    Oct 27 21:22:09	charon: 03[MGR] check-in of IKE_SA successful.
    Oct 27 21:22:09	charon: 05[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500]
    Oct 27 21:22:09	charon: 03[MGR] <con1|9> check-in of IKE_SA successful.
    Oct 27 21:22:09	charon: 05[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500]
    Oct 27 21:22:09	charon: 03[MGR] checkin IKE_SA con1[9]
    Oct 27 21:22:09	charon: 03[MGR] <con1|9> checkin IKE_SA con1[9]
    Oct 27 21:22:09	charon: 03[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (76 bytes)
    Oct 27 21:22:09	charon: 03[NET] <con1|9> sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (76 bytes)
    Oct 27 21:22:09	charon: 03[IKE] MAIN_MODE task
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> MAIN_MODE task
    Oct 27 21:22:09	charon: 03[IKE] ISAKMP_VENDOR task
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> ISAKMP_VENDOR task
    Oct 27 21:22:09	charon: 03[IKE] reinitiating already active tasks
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> reinitiating already active tasks
    Oct 27 21:22:09	charon: 03[IKE] received XAuth vendor ID
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> received XAuth vendor ID
    Oct 27 21:22:09	charon: 03[IKE] received Cisco Unity vendor ID
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> received Cisco Unity vendor ID
    Oct 27 21:22:09	charon: 03[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500] (304 bytes)
    Oct 27 21:22:09	charon: 03[NET] <con1|9> received packet: from 2.2.2.2[500] to 1.1.1.1[500] (304 bytes)
    Oct 27 21:22:09	charon: 03[MGR] IKE_SA con1[9] successfully checked out
    Oct 27 21:22:09	charon: 03[MGR] IKE_SA con1[9] successfully checked out
    Oct 27 21:22:09	charon: 03[MGR] checkout IKE_SA by message
    Oct 27 21:22:09	charon: 03[MGR] checkout IKE_SA by message
    Oct 27 21:22:09	charon: 04[NET] waiting for data on sockets
    Oct 27 21:22:09	charon: 04[NET] waiting for data on sockets
    Oct 27 21:22:09	charon: 04[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500]
    Oct 27 21:22:09	charon: 04[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500]
    Oct 27 21:22:09	charon: 05[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500]
    Oct 27 21:22:09	charon: 05[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500]
    Oct 27 21:22:09	charon: 03[MGR] check-in of IKE_SA successful.
    Oct 27 21:22:09	charon: 03[MGR] <con1|9> check-in of IKE_SA successful.
    Oct 27 21:22:09	charon: 03[MGR] checkin IKE_SA con1[9]
    Oct 27 21:22:09	charon: 03[MGR] <con1|9> checkin IKE_SA con1[9]
    Oct 27 21:22:09	charon: 03[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (244 bytes)
    Oct 27 21:22:09	charon: 03[NET] <con1|9> sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (244 bytes)
    Oct 27 21:22:09	charon: 03[LIB] size of DH secret exponent: 1023 bits
    Oct 27 21:22:09	charon: 03[LIB] <con1|9> size of DH secret exponent: 1023 bits
    Oct 27 21:22:09	charon: 03[IKE] MAIN_MODE task
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> MAIN_MODE task
    Oct 27 21:22:09	charon: 03[IKE] ISAKMP_VENDOR task
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> ISAKMP_VENDOR task
    Oct 27 21:22:09	charon: 03[IKE] reinitiating already active tasks
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> reinitiating already active tasks
    Oct 27 21:22:09	charon: 03[IKE] received FRAGMENTATION vendor ID
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> received FRAGMENTATION vendor ID
    Oct 27 21:22:09	charon: 03[IKE] received NAT-T (RFC 3947) vendor ID
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> received NAT-T (RFC 3947) vendor ID
    Oct 27 21:22:09	charon: 03[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500] (128 bytes)
    Oct 27 21:22:09	charon: 03[NET] <con1|9> received packet: from 2.2.2.2[500] to 1.1.1.1[500] (128 bytes)
    Oct 27 21:22:09	charon: 03[MGR] IKE_SA con1[9] successfully checked out
    Oct 27 21:22:09	charon: 03[MGR] IKE_SA con1[9] successfully checked out
    Oct 27 21:22:09	charon: 03[MGR] checkout IKE_SA by message
    Oct 27 21:22:09	charon: 03[MGR] checkout IKE_SA by message
    Oct 27 21:22:09	charon: 04[NET] waiting for data on sockets
    Oct 27 21:22:09	charon: 04[NET] waiting for data on sockets
    Oct 27 21:22:09	charon: 04[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500]
    Oct 27 21:22:09	charon: 04[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500]
    Oct 27 21:22:09	charon: 05[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500]
    Oct 27 21:22:09	charon: 05[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500]
    Oct 27 21:22:09	charon: 03[MGR] checkin IKE_SA con1[9]
    Oct 27 21:22:09	charon: 03[MGR] <con1|9> checkin IKE_SA con1[9]
    Oct 27 21:22:09	charon: 03[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (200 bytes)
    Oct 27 21:22:09	charon: 03[NET] <con1|9> sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (200 bytes)
    Oct 27 21:22:09	charon: 03[IKE] IKE_SA con1[9] state change: CREATED => CONNECTING
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> IKE_SA con1[9] state change: CREATED => CONNECTING
    Oct 27 21:22:09	charon: 03[IKE] initiating Main Mode IKE_SA con1[9] to 2.2.2.2
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> initiating Main Mode IKE_SA con1[9] to 2.2.2.2
    Oct 27 21:22:09	charon: 03[IKE] sending draft-ietf-ipsec-nat-t-ike-02\n vendor ID
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> sending draft-ietf-ipsec-nat-t-ike-02\n vendor ID
    Oct 27 21:22:09	charon: 03[IKE] sending NAT-T (RFC 3947) vendor ID
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> sending NAT-T (RFC 3947) vendor ID
    Oct 27 21:22:09	charon: 03[IKE] sending FRAGMENTATION vendor ID
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> sending FRAGMENTATION vendor ID
    Oct 27 21:22:09	charon: 03[IKE] sending Cisco Unity vendor ID
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> sending Cisco Unity vendor ID
    Oct 27 21:22:09	charon: 03[IKE] sending DPD vendor ID
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> sending DPD vendor ID
    Oct 27 21:22:09	charon: 03[IKE] sending XAuth vendor ID
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> sending XAuth vendor ID
    Oct 27 21:22:09	charon: 03[IKE] activating ISAKMP_NATD task
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> activating ISAKMP_NATD task
    Oct 27 21:22:09	charon: 03[IKE] activating ISAKMP_CERT_POST task
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> activating ISAKMP_CERT_POST task
    Oct 27 21:22:09	charon: 03[IKE] activating MAIN_MODE task
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> activating MAIN_MODE task
    Oct 27 21:22:09	charon: 03[IKE] activating ISAKMP_CERT_PRE task
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> activating ISAKMP_CERT_PRE task
    Oct 27 21:22:09	charon: 03[IKE] activating ISAKMP_VENDOR task
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> activating ISAKMP_VENDOR task
    Oct 27 21:22:09	charon: 03[IKE] activating new tasks
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> activating new tasks
    Oct 27 21:22:09	charon: 03[IKE] queueing QUICK_MODE task
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> queueing QUICK_MODE task
    Oct 27 21:22:09	charon: 03[IKE] queueing ISAKMP_NATD task
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> queueing ISAKMP_NATD task
    Oct 27 21:22:09	charon: 03[IKE] queueing ISAKMP_CERT_POST task
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> queueing ISAKMP_CERT_POST task
    Oct 27 21:22:09	charon: 03[IKE] queueing MAIN_MODE task
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> queueing MAIN_MODE task
    Oct 27 21:22:09	charon: 03[IKE] queueing ISAKMP_CERT_PRE task
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> queueing ISAKMP_CERT_PRE task
    Oct 27 21:22:09	charon: 03[IKE] queueing ISAKMP_VENDOR task
    Oct 27 21:22:09	charon: 03[IKE] <con1|9> queueing ISAKMP_VENDOR task
    Oct 27 21:22:09	charon: 03[MGR] created IKE_SA (unnamed)[9]
    Oct 27 21:22:09	charon: 03[MGR] created IKE_SA (unnamed)[9]
    Oct 27 21:22:09	charon: 03[MGR] checkout IKE_SA by config</con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9>
    

    Here is the log if I initiate traffic from behind ASA:

    Oct 27 21:24:24	charon: 11[MGR] check-in of IKE_SA successful.
    Oct 27 21:24:24	charon: 11[MGR] <con1|10> check-in of IKE_SA successful.
    Oct 27 21:24:24	charon: 11[MGR] checkin IKE_SA con1[10]
    Oct 27 21:24:24	charon: 11[MGR] <con1|10> checkin IKE_SA con1[10]
    Oct 27 21:24:24	charon: 11[MGR] IKE_SA con1[10] successfully checked out
    Oct 27 21:24:24	charon: 11[MGR] IKE_SA con1[10] successfully checked out
    Oct 27 21:24:24	charon: 11[MGR] checkout IKE_SA
    Oct 27 21:24:24	charon: 11[MGR] checkout IKE_SA
    Oct 27 21:24:20	charon: 11[MGR] check-in of IKE_SA successful.
    Oct 27 21:24:20	charon: 11[MGR] <con1|10> check-in of IKE_SA successful.
    Oct 27 21:24:20	charon: 11[MGR] checkin IKE_SA con1[10]
    Oct 27 21:24:20	charon: 11[MGR] <con1|10> checkin IKE_SA con1[10]
    Oct 27 21:24:20	charon: 11[IKE] CHILD_SA con1{1} established with SPIs c50da63c_i 1496d46b_o and TS 172.22.22.0/24|/0 === 10.100.20.0/24|/0
    Oct 27 21:24:20	charon: 11[IKE] <con1|10> CHILD_SA con1{1} established with SPIs c50da63c_i 1496d46b_o and TS 172.22.22.0/24|/0 === 10.100.20.0/24|/0
    Oct 27 21:24:20	charon: 11[CHD] SPI 0x1496d46b, src 1.1.1.1 dst 2.2.2.2
    Oct 27 21:24:20	charon: 11[CHD] <con1|10> SPI 0x1496d46b, src 1.1.1.1 dst 2.2.2.2
    Oct 27 21:24:20	charon: 11[CHD] adding outbound ESP SA
    Oct 27 21:24:20	charon: 11[CHD] <con1|10> adding outbound ESP SA
    Oct 27 21:24:20	charon: 11[CHD] SPI 0xc50da63c, src 2.2.2.2 dst 1.1.1.1
    Oct 27 21:24:20	charon: 11[CHD] <con1|10> SPI 0xc50da63c, src 2.2.2.2 dst 1.1.1.1
    Oct 27 21:24:20	charon: 11[CHD] adding inbound ESP SA
    Oct 27 21:24:20	charon: 11[CHD] <con1|10> adding inbound ESP SA
    Oct 27 21:24:20	charon: 11[CHD] using HMAC_SHA1_96 for integrity
    Oct 27 21:24:20	charon: 11[CHD] <con1|10> using HMAC_SHA1_96 for integrity
    Oct 27 21:24:20	charon: 11[CHD] using AES_CBC for encryption
    Oct 27 21:24:20	charon: 11[CHD] <con1|10> using AES_CBC for encryption
    Oct 27 21:24:20	charon: 11[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500] (76 bytes)
    Oct 27 21:24:20	charon: 11[NET] <con1|10> received packet: from 2.2.2.2[500] to 1.1.1.1[500] (76 bytes)
    Oct 27 21:24:20	charon: 11[MGR] IKE_SA con1[10] successfully checked out
    Oct 27 21:24:20	charon: 11[MGR] IKE_SA con1[10] successfully checked out
    Oct 27 21:24:20	charon: 11[MGR] checkout IKE_SA by message
    Oct 27 21:24:20	charon: 11[MGR] checkout IKE_SA by message
    Oct 27 21:24:20	charon: 04[NET] waiting for data on sockets
    Oct 27 21:24:20	charon: 04[NET] waiting for data on sockets
    Oct 27 21:24:20	charon: 04[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500]
    Oct 27 21:24:20	charon: 04[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500]
    Oct 27 21:24:20	charon: 05[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500]
    Oct 27 21:24:20	charon: 05[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500]
    Oct 27 21:24:20	charon: 11[MGR] check-in of IKE_SA successful.
    Oct 27 21:24:20	charon: 11[MGR] <con1|10> check-in of IKE_SA successful.
    Oct 27 21:24:20	charon: 11[MGR] checkin IKE_SA con1[10]
    Oct 27 21:24:20	charon: 11[MGR] <con1|10> checkin IKE_SA con1[10]
    Oct 27 21:24:20	charon: 11[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (332 bytes)
    Oct 27 21:24:20	charon: 11[NET] <con1|10> sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (332 bytes)
    Oct 27 21:24:19	charon: 11[LIB] size of DH secret exponent: 1023 bits
    Oct 27 21:24:19	charon: 11[LIB] <con1|10> size of DH secret exponent: 1023 bits
    Oct 27 21:24:19	charon: 11[IKE] received 4608000000 lifebytes, configured 0
    Oct 27 21:24:19	charon: 11[IKE] <con1|10> received 4608000000 lifebytes, configured 0
    Oct 27 21:24:19	charon: 11[IKE] received 28800s lifetime, configured 3600s
    Oct 27 21:24:19	charon: 11[IKE] <con1|10> received 28800s lifetime, configured 3600s
    Oct 27 21:24:19	charon: 11[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500] (348 bytes)
    Oct 27 21:24:19	charon: 11[NET] <con1|10> received packet: from 2.2.2.2[500] to 1.1.1.1[500] (348 bytes)
    Oct 27 21:24:19	charon: 11[MGR] IKE_SA con1[10] successfully checked out
    Oct 27 21:24:19	charon: 11[MGR] IKE_SA con1[10] successfully checked out
    Oct 27 21:24:19	charon: 11[MGR] checkout IKE_SA by message
    Oct 27 21:24:19	charon: 11[MGR] checkout IKE_SA by message
    Oct 27 21:24:19	charon: 04[NET] waiting for data on sockets
    Oct 27 21:24:19	charon: 04[NET] waiting for data on sockets
    Oct 27 21:24:19	charon: 04[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500]
    Oct 27 21:24:19	charon: 04[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500]
    Oct 27 21:24:19	charon: 11[MGR] check-in of IKE_SA successful.
    Oct 27 21:24:19	charon: 11[MGR] <con1|10> check-in of IKE_SA successful.
    Oct 27 21:24:19	charon: 11[MGR] checkin IKE_SA con1[10]
    Oct 27 21:24:19	charon: 11[MGR] <con1|10> checkin IKE_SA con1[10]
    Oct 27 21:24:19	charon: 11[MGR] IKE_SA con1[10] successfully checked out
    Oct 27 21:24:19	charon: 11[MGR] IKE_SA con1[10] successfully checked out
    Oct 27 21:24:19	charon: 15[MGR] check-in of IKE_SA successful.
    Oct 27 21:24:19	charon: 15[MGR] <con1|10> check-in of IKE_SA successful.
    Oct 27 21:24:19	charon: 05[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500]
    Oct 27 21:24:19	charon: 15[MGR] checkin IKE_SA con1[10]
    Oct 27 21:24:19	charon: 05[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500]
    Oct 27 21:24:19	charon: 15[MGR] <con1|10> checkin IKE_SA con1[10]
    Oct 27 21:24:19	charon: 15[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (76 bytes)
    Oct 27 21:24:19	charon: 15[NET] <con1|10> sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (76 bytes)
    Oct 27 21:24:19	charon: 11[MGR] checkout IKE_SA
    Oct 27 21:24:19	charon: 11[MGR] checkout IKE_SA
    Oct 27 21:24:19	charon: 15[IKE] maximum IKE_SA lifetime 28798s
    Oct 27 21:24:19	charon: 15[IKE] <con1|10> maximum IKE_SA lifetime 28798s
    Oct 27 21:24:19	charon: 15[IKE] scheduling reauthentication in 28258s
    Oct 27 21:24:19	charon: 15[IKE] <con1|10> scheduling reauthentication in 28258s
    Oct 27 21:24:19	charon: 15[IKE] IKE_SA con1[10] state change: CONNECTING => ESTABLISHED
    Oct 27 21:24:19	charon: 15[IKE] <con1|10> IKE_SA con1[10] state change: CONNECTING => ESTABLISHED
    Oct 27 21:24:19	charon: 15[IKE] IKE_SA con1[10] established between 1.1.1.1[1.1.1.1]...2.2.2.2[2.2.2.2]
    Oct 27 21:24:19	charon: 15[IKE] <con1|10> IKE_SA con1[10] established between 1.1.1.1[1.1.1.1]...2.2.2.2[2.2.2.2]
    Oct 27 21:24:19	charon: 15[IKE] received DPD vendor ID
    Oct 27 21:24:19	charon: 15[IKE] <10> received DPD vendor ID
    Oct 27 21:24:19	charon: 15[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500] (92 bytes)
    Oct 27 21:24:19	charon: 15[NET] <10> received packet: from 2.2.2.2[500] to 1.1.1.1[500] (92 bytes)
    Oct 27 21:24:19	charon: 15[MGR] IKE_SA (unnamed)[10] successfully checked out
    Oct 27 21:24:19	charon: 15[MGR] IKE_SA (unnamed)[10] successfully checked out
    Oct 27 21:24:19	charon: 15[MGR] checkout IKE_SA by message
    Oct 27 21:24:19	charon: 04[NET] waiting for data on sockets
    Oct 27 21:24:19	charon: 15[MGR] checkout IKE_SA by message
    Oct 27 21:24:19	charon: 04[NET] waiting for data on sockets
    Oct 27 21:24:19	charon: 04[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500]
    Oct 27 21:24:19	charon: 04[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500]
    Oct 27 21:24:19	charon: 15[MGR] check-in of IKE_SA successful.
    Oct 27 21:24:19	charon: 15[MGR] <10> check-in of IKE_SA successful.
    Oct 27 21:24:19	charon: 05[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500]
    Oct 27 21:24:19	charon: 15[MGR] checkin IKE_SA (unnamed)[10]
    Oct 27 21:24:19	charon: 05[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500]
    Oct 27 21:24:19	charon: 15[MGR] <10> checkin IKE_SA (unnamed)[10]
    Oct 27 21:24:19	charon: 15[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (244 bytes)
    Oct 27 21:24:19	charon: 15[NET] <10> sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (244 bytes)
    Oct 27 21:24:19	charon: 15[LIB] size of DH secret exponent: 1023 bits
    Oct 27 21:24:19	charon: 15[LIB] <10> size of DH secret exponent: 1023 bits
    Oct 27 21:24:19	charon: 15[IKE] received XAuth vendor ID
    Oct 27 21:24:19	charon: 15[IKE] <10> received XAuth vendor ID
    Oct 27 21:24:19	charon: 15[IKE] received Cisco Unity vendor ID
    Oct 27 21:24:19	charon: 15[IKE] <10> received Cisco Unity vendor ID
    Oct 27 21:24:19	charon: 15[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500] (304 bytes)
    Oct 27 21:24:19	charon: 15[NET] <10> received packet: from 2.2.2.2[500] to 1.1.1.1[500] (304 bytes)
    Oct 27 21:24:19	charon: 15[MGR] IKE_SA (unnamed)[10] successfully checked out
    Oct 27 21:24:19	charon: 15[MGR] IKE_SA (unnamed)[10] successfully checked out
    Oct 27 21:24:19	charon: 15[MGR] checkout IKE_SA by message
    Oct 27 21:24:19	charon: 15[MGR] checkout IKE_SA by message
    Oct 27 21:24:19	charon: 04[NET] waiting for data on sockets
    Oct 27 21:24:19	charon: 04[NET] waiting for data on sockets
    Oct 27 21:24:19	charon: 04[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500]
    Oct 27 21:24:19	charon: 04[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500]
    Oct 27 21:24:19	charon: 15[MGR] check-in of IKE_SA successful.
    Oct 27 21:24:19	charon: 15[MGR] <10> check-in of IKE_SA successful.
    Oct 27 21:24:19	charon: 05[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500]
    Oct 27 21:24:19	charon: 15[MGR] checkin IKE_SA (unnamed)[10]
    Oct 27 21:24:19	charon: 05[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500]
    Oct 27 21:24:19	charon: 15[MGR] <10> checkin IKE_SA (unnamed)[10]
    Oct 27 21:24:19	charon: 15[NET] sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (184 bytes)
    Oct 27 21:24:19	charon: 15[NET] <10> sending packet: from 1.1.1.1[500] to 2.2.2.2[500] (184 bytes)
    Oct 27 21:24:19	charon: 15[IKE] sending NAT-T (RFC 3947) vendor ID
    Oct 27 21:24:19	charon: 15[IKE] <10> sending NAT-T (RFC 3947) vendor ID
    Oct 27 21:24:19	charon: 15[IKE] sending FRAGMENTATION vendor ID
    Oct 27 21:24:19	charon: 15[IKE] <10> sending FRAGMENTATION vendor ID
    Oct 27 21:24:19	charon: 15[IKE] sending Cisco Unity vendor ID
    Oct 27 21:24:19	charon: 15[IKE] <10> sending Cisco Unity vendor ID
    Oct 27 21:24:19	charon: 15[IKE] sending DPD vendor ID
    Oct 27 21:24:19	charon: 15[IKE] <10> sending DPD vendor ID
    Oct 27 21:24:19	charon: 15[IKE] sending XAuth vendor ID
    Oct 27 21:24:19	charon: 15[IKE] <10> sending XAuth vendor ID
    Oct 27 21:24:19	charon: 15[IKE] IKE_SA (unnamed)[10] state change: CREATED => CONNECTING
    Oct 27 21:24:19	charon: 15[IKE] <10> IKE_SA (unnamed)[10] state change: CREATED => CONNECTING
    Oct 27 21:24:19	charon: 15[IKE] 2.2.2.2 is initiating a Main Mode IKE_SA
    Oct 27 21:24:19	charon: 15[IKE] <10> 2.2.2.2 is initiating a Main Mode IKE_SA
    Oct 27 21:24:19	charon: 15[IKE] received FRAGMENTATION vendor ID
    Oct 27 21:24:19	charon: 15[IKE] <10> received FRAGMENTATION vendor ID
    Oct 27 21:24:19	charon: 15[IKE] received NAT-T (RFC 3947) vendor ID
    Oct 27 21:24:19	charon: 15[IKE] <10> received NAT-T (RFC 3947) vendor ID
    Oct 27 21:24:19	charon: 15[IKE] received draft-ietf-ipsec-nat-t-ike-03 vendor ID
    Oct 27 21:24:19	charon: 15[IKE] <10> received draft-ietf-ipsec-nat-t-ike-03 vendor ID
    Oct 27 21:24:19	charon: 15[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
    Oct 27 21:24:19	charon: 15[IKE] <10> received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
    Oct 27 21:24:19	charon: 15[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500] (460 bytes)
    Oct 27 21:24:19	charon: 15[NET] <10> received packet: from 2.2.2.2[500] to 1.1.1.1[500] (460 bytes)
    Oct 27 21:24:19	charon: 15[MGR] created IKE_SA (unnamed)[10]
    Oct 27 21:24:19	charon: 15[MGR] created IKE_SA (unnamed)[10]
    Oct 27 21:24:19	charon: 15[MGR] checkout IKE_SA by message
    Oct 27 21:24:19	charon: 15[MGR] checkout IKE_SA by message
    Oct 27 21:24:19	charon: 04[NET] waiting for data on sockets
    Oct 27 21:24:19	charon: 04[NET] waiting for data on sockets
    Oct 27 21:24:19	charon: 04[NET] received packet: from 2.2.2.2[500] to 1.1.1.1[500]</con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10></con1|10>
    


  • Can you try with tomorrow snapshots?



  • I don't have the time to take down my FW at the moment, but if ankaerith can confirm it works, I'll upgrade to 2.2beta to test.



  • I'll try to give it a shot in the next day or two.



  • Has anyone confirmed this has been fixed?


Log in to reply