IPSEC site-to-site doesn't work after phase2 sa expired



  • Hi everybody,

    i don't understand why my ipsec vpn tunnel goes down after first "phase2 sa expired" and there's no way to restart again my tunnel.

    My scenario.

    Site A (peer 1.1.1.1)

    Mode Tunnel
    Interface WAN
    DPD interval 60 seconds
    Local subnet 192.168.100.0/24
    Remote subnet 192.168.1.0/24
    Remote gateway 2.2.2.2

    Phase 1 proposal (Authentication)
    Negotiation mode Aggressive
    My identifier MyIPAddress
    Encryption algorithm 3DES
    Hash algorithm SHA1
    DH key group 2
    Lifetime 28800 seconds
    Authentication method Pre-Shared Key
    Pre-Shared Key mysecret

    Phase 2 proposal (SA/Key Exchange)
    Protocol ESP
    Encryption algorithms 3DES
    Hash algorithms MD5
    PFS key group 2
    Lifetime 3600 seconds

    Site B (peer 2.2.2.2, *there is a 1-to-1 nat to 192.168.150.10 <- WAN Address in pfsense)
    Mode Tunnel
    Interface WAN
    DPD interval 60 seconds
    Local subnet 192.168.1.0/24
    Remote subnet 192.168.100.0/24
    Remote gateway 1.1.1.1

    Phase 1 proposal (Authentication)
    Negotiation mode Aggressive
    My identifier MyIPAddress
    Encryption algorithm 3DES
    Hash algorithm SHA1
    DH key group 2
    Lifetime 28800 seconds
    Authentication method Pre-Shared Key
    Pre-Shared Key mysecret

    Phase 2 proposal (SA/Key Exchange)
    Protocol ESP
    Encryption algorithms 3DES
    Hash algorithms MD5
    PFS key group 2
    Lifetime 3600 seconds

    These are ACTUAL /var/etc/racoon.conf files of

    Site A

    listen {
            adminsock "/var/db/racoon/racoon.sock" "root" "wheel" 0660;
    }
    path pre_shared_key "/var/etc/psk.txt";

    path certificate  "/var/etc";

    remote 2.2.2.2 {
            exchange_mode aggressive;
            my_identifier address "1.1.1.1";

    peers_identifier address 2.2.2.2;
            initial_contact on;
            dpd_delay 60;
            ike_frag on;
            support_proxy on;
            proposal_check obey;

    proposal {
                    encryption_algorithm 3des;
                    hash_algorithm sha1;
                    authentication_method pre_shared_key;
                    dh_group 2;
                    lifetime time 28800 secs;
            }
            lifetime time 28800 secs;
    }

    sainfo address 192.168.100.0/24 any address 10.192.1.0/24 any {
            encryption_algorithm 3des;
            authentication_algorithm hmac_md5;
            compression_algorithm deflate;
            pfs_group 2;
            lifetime time 3600 secs;
    }

    Site B

    listen {
            adminsock "/var/db/racoon/racoon.sock" "root" "wheel" 0660;
    }
    path pre_shared_key "/var/etc/psk.txt";

    path certificate  "/var/etc";

    remote 1.1.1.1 {
            exchange_mode aggressive;
            my_identifier address "192.168.150.10";

    peers_identifier address 1.1.1.1;
            initial_contact on;
            dpd_delay 60;
            ike_frag on;
            support_proxy on;
            proposal_check obey;

    proposal {
                    encryption_algorithm 3des;
                    hash_algorithm sha1;
                    authentication_method pre_shared_key;
                    dh_group 2;
                    lifetime time 28800 secs;
            }
            lifetime time 28800 secs;
    }

    sainfo address 192.168.1.0/24 any address 192.168.100.0/24 any {
            encryption_algorithm 3des;
            authentication_algorithm hmac_md5;
            compression_algorithm deflate;
            pfs_group 2;
            lifetime time 3600 secs;
    }

    In my first setup, no lifetime were setup for both sites.
    Everything works until today… this is last working log of site A

    Mar 1 14:48:56 racoon: [Self]: INFO: 1.1.1.1[500] used as isakmp port (fd=15)
    Mar 1 14:48:56 racoon: [Self]: INFO: 192.168.100.1[500] used as isakmp port (fd=16)
    Mar 1 14:48:56 racoon: INFO: unsupported PF_KEY message REGISTER
    Mar 1 14:48:56 racoon: ERROR: such policy already exists. anyway replace it: 192.168.100.0/24[0] 192.168.1.0/24[0] proto=any dir=out
    Mar 1 14:48:56 racoon: ERROR: such policy already exists. anyway replace it: 192.168.1.0/24[0] 192.168.100.0/24[0] proto=any dir=in
    Mar 1 14:48:56 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
    Mar 1 14:48:56 racoon: [Self]: INFO: 1.1.1.1[500] used as isakmp port (fd=15)
    Mar 1 14:48:56 racoon: [Self]: INFO: 192.168.100.1[500] used as isakmp port (fd=16)
    Mar 1 14:49:56 racoon: [VPN Tunnel to Site B]: INFO: respond new phase 1 negotiation: 1.1.1.1[500]<=>2.2.2.2[500]
    Mar 1 14:49:56 racoon: INFO: begin Aggressive mode.
    Mar 1 14:49:56 racoon: INFO: received broken Microsoft ID: FRAGMENTATION
    Mar 1 14:49:56 racoon: INFO: received Vendor ID: DPD
    Mar 1 14:49:56 racoon: WARNING: No ID match.
    Mar 1 14:49:56 racoon: NOTIFY: couldn't find the proper pskey, try to get one by the peer's address.
    Mar 1 14:49:56 racoon: [VPN Tunnel to Site B]: INFO: ISAKMP-SA established 1.1.1.1[500]-2.2.2.2[500] spi:e81e2895e3a3c672:cee809c23053a564
    Mar 1 14:49:57 racoon: [VPN Tunnel to Site B]: INFO: respond new phase 2 negotiation: 1.1.1.1[0]<=>2.2.2.2[0]
    Mar 1 14:49:57 racoon: [VPN Tunnel to Site B]: INFO: IPsec-SA established: ESP 2.2.2.2[0]->1.1.1.1[0] spi=156106193(0x94dfdd1)
    Mar 1 14:49:57 racoon: [VPN Tunnel to Site B]: INFO: IPsec-SA established: ESP 1.1.1.1[0]->2.2.2.2[0] spi=128354211(0x7a687a3)
    Mar 1 21:13:58 racoon: [VPN Tunnel to Site B]: INFO: IPsec-SA expired: ESP 1.1.1.1[0]->2.2.2.2[0] spi=128354211(0x7a687a3)
    Mar 1 21:13:58 racoon: [VPN Tunnel to Site B]: INFO: IPsec-SA expired: ESP/Tunnel 2.2.2.2[0]->1.1.1.1[0] spi=156106193(0x94dfdd1)
    Mar 1 21:13:58 racoon: [VPN Tunnel to Site B]: INFO: respond new phase 2 negotiation: 1.1.1.1[0]<=>2.2.2.2[0]
    Mar 1 21:13:59 racoon: [VPN Tunnel to Site B]: INFO: IPsec-SA established: ESP 2.2.2.2[0]->1.1.1.1[0] spi=138429856(0x84045a0)
    Mar 1 21:13:59 racoon: [VPN Tunnel to Site B]: INFO: IPsec-SA established: ESP 1.1.1.1[0]->2.2.2.2[0] spi=186944455(0xb248bc7)
    Mar 1 22:49:56 racoon: [VPN Tunnel to Site B]: INFO: ISAKMP-SA expired 1.1.1.1[500]-2.2.2.2[500] spi:e81e2895e3a3c672:cee809c23053a564
    Mar 1 22:49:57 racoon: [VPN Tunnel to Site B]: INFO: ISAKMP-SA deleted 1.1.1.1[500]-2.2.2.2[500] spi:e81e2895e3a3c672:cee809c23053a564
    Mar 2 05:14:00 racoon: [VPN Tunnel to Site B]: INFO: phase2 sa expired 1.1.1.1-2.2.2.2
    Mar 2 05:14:01 racoon: [VPN Tunnel to Site B]: INFO: phase2 sa deleted 1.1.1.1-2.2.2.2
    Mar 2 11:45:01 racoon: INFO: unsupported PF_KEY message REGISTER
    Mar 2 11:45:01 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
    Mar 2 11:45:01 racoon: [Self]: INFO: 1.1.1.1[500] used as isakmp port (fd=15)
    Mar 2 11:45:01 racoon: [Self]: INFO: 192.168.100.1[500] used as isakmp port (fd=16)
    Mar 2 11:47:19 racoon: INFO: unsupported PF_KEY message REGISTER
    Mar 2 11:47:20 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
    Mar 2 11:47:20 racoon: [Self]: INFO: 1.1.1.1[500] used as isakmp port (fd=15)
    Mar 2 11:47:20 racoon: [Self]: INFO: 192.168.100.1[500] used as isakmp port (fd=16)
    Mar 2 11:48:53 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
    Mar 2 11:48:53 racoon: [Self]: INFO: 1.1.1.1[500] used as isakmp port (fd=15)
    Mar 2 11:48:53 racoon: [Self]: INFO: 192.168.100.1[500] used as isakmp port (fd=16)
    Mar 2 11:48:53 racoon: INFO: caught signal 15
    Mar 2 11:48:54 racoon: INFO: racoon shutdown
    Mar 2 11:48:59 racoon: INFO: @(#)ipsec-tools 0.7.2 (http://ipsec-tools.sourceforge.net)
    Mar 2 11:48:59 racoon: INFO: @(#)This product linked OpenSSL 0.9.8e 23 Feb 2007 (http://www.openssl.org/)
    Mar 2 11:48:59 racoon: INFO: Reading configuration from "/var/etc/racoon.conf"
    Mar 2 11:48:59 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
    Mar 2 11:48:59 racoon: [Self]: INFO: 1.1.1.1[500] used as isakmp port (fd=15)
    Mar 2 11:48:59 racoon: [Self]: INFO: 192.168.100.1[500] used as isakmp port (fd=16)
    Mar 2 11:48:59 racoon: INFO: unsupported PF_KEY message REGISTER
    Mar 2 11:48:59 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
    Mar 2 11:48:59 racoon: [Self]: INFO: 1.1.1.1[500] used as isakmp port (fd=15)
    Mar 2 11:48:59 racoon: [Self]: INFO: 192.168.100.1[500] used as isakmp port (fd=16)

    and this is last working log of site B

    Mar 1 14:49:18 racoon: [Self]: INFO: 192.168.150.10[500] used as isakmp port (fd=15)
    Mar 1 14:49:18 racoon: [Self]: INFO: 192.168.1.50[500] used as isakmp port (fd=16)
    Mar 1 14:49:18 racoon: INFO: unsupported PF_KEY message REGISTER
    Mar 1 14:49:18 racoon: ERROR: such policy already exists. anyway replace it: 192.168.1.0/24[0] 192.168.100.0/24[0] proto=any dir=out
    Mar 1 14:49:18 racoon: ERROR: such policy already exists. anyway replace it: 192.168.100.0/24[0] 192.168.1.0/24[0] proto=any dir=in
    Mar 1 14:49:18 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
    Mar 1 14:49:18 racoon: [Self]: INFO: 192.168.150.10[500] used as isakmp port (fd=15)
    Mar 1 14:49:18 racoon: [Self]: INFO: 192.168.1.50[500] used as isakmp port (fd=16)
    Mar 1 14:49:56 racoon: [VPN Tunnel to Site A]: INFO: IPsec-SA request for 1.1.1.1 queued due to no phase1 found.
    Mar 1 14:49:56 racoon: [VPN Tunnel to Site A]: INFO: initiate new phase 1 negotiation: 192.168.150.10[500]<=>1.1.1.1[500]
    Mar 1 14:49:56 racoon: INFO: begin Aggressive mode.
    Mar 1 14:49:56 racoon: INFO: received broken Microsoft ID: FRAGMENTATION
    Mar 1 14:49:56 racoon: INFO: received Vendor ID: DPD
    Mar 1 14:49:56 racoon: NOTIFY: couldn't find the proper pskey, try to get one by the peer's address.
    Mar 1 14:49:56 racoon: [VPN Tunnel to Site A]: INFO: ISAKMP-SA established 192.168.150.10[500]-1.1.1.1[500] spi:e81e2895e3a3c672:cee809c23053a564
    Mar 1 14:49:57 racoon: [VPN Tunnel to Site A]: INFO: initiate new phase 2 negotiation: 192.168.150.10[500]<=>1.1.1.1[500]
    Mar 1 14:49:57 racoon: [VPN Tunnel to Site A]: INFO: IPsec-SA established: ESP 1.1.1.1[0]->192.168.150.10[0] spi=128354211(0x7a687a3)
    Mar 1 14:49:57 racoon: [VPN Tunnel to Site A]: INFO: IPsec-SA established: ESP 192.168.150.10[0]->1.1.1.1[0] spi=156106193(0x94dfdd1)
    Mar 1 21:13:58 racoon: [VPN Tunnel to Site A]: INFO: IPsec-SA expired: ESP 192.168.150.10[0]->1.1.1.1[0] spi=156106193(0x94dfdd1)
    Mar 1 21:13:58 racoon: [VPN Tunnel to Site A]: INFO: initiate new phase 2 negotiation: 192.168.150.10[0]<=>1.1.1.1[0]
    Mar 1 21:13:58 racoon: [VPN Tunnel to Site A]: INFO: IPsec-SA expired: ESP/Tunnel 1.1.1.1[0]->192.168.150.10[0] spi=128354211(0x7a687a3)
    Mar 1 21:13:58 racoon: [VPN Tunnel to Site A]: INFO: IPsec-SA established: ESP 1.1.1.1[0]->192.168.150.10[0] spi=186944455(0xb248bc7)
    Mar 1 21:13:58 racoon: [VPN Tunnel to Site A]: INFO: IPsec-SA established: ESP 192.168.150.10[0]->1.1.1.1[0] spi=138429856(0x84045a0)
    Mar 1 22:49:56 racoon: [VPN Tunnel to Site A]: INFO: ISAKMP-SA expired 192.168.150.10[500]-1.1.1.1[500] spi:e81e2895e3a3c672:cee809c23053a564
    Mar 1 22:49:57 racoon: [VPN Tunnel to Site A]: INFO: ISAKMP-SA deleted 192.168.150.10[500]-1.1.1.1[500] spi:e81e2895e3a3c672:cee809c23053a564
    Mar 2 05:13:58 racoon: [VPN Tunnel to Site A]: INFO: phase2 sa expired 192.168.150.10-1.1.1.1
    Mar 2 05:13:59 racoon: [VPN Tunnel to Site A]: INFO: phase2 sa deleted 192.168.150.10-1.1.1.1
    Mar 2 11:45:19 racoon: INFO: unsupported PF_KEY message REGISTER
    Mar 2 11:45:19 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
    Mar 2 11:45:19 racoon: [Self]: INFO: 192.168.150.10[500] used as isakmp port (fd=15)
    Mar 2 11:45:19 racoon: [Self]: INFO: 192.168.1.50[500] used as isakmp port (fd=16)
    Mar 2 11:47:32 racoon: INFO: unsupported PF_KEY message REGISTER
    Mar 2 11:47:32 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
    Mar 2 11:47:32 racoon: [Self]: INFO: 192.168.150.10[500] used as isakmp port (fd=15)
    Mar 2 11:47:32 racoon: [Self]: INFO: 192.168.1.50[500] used as isakmp port (fd=16)
    Mar 2 11:48:43 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
    Mar 2 11:48:43 racoon: [Self]: INFO: 192.168.150.10[500] used as isakmp port (fd=15)
    Mar 2 11:48:43 racoon: [Self]: INFO: 192.168.1.50[500] used as isakmp port (fd=16)
    Mar 2 11:48:43 racoon: INFO: caught signal 15
    Mar 2 11:48:44 racoon: INFO: racoon shutdown
    Mar 2 11:48:57 racoon: INFO: @(#)ipsec-tools 0.7.2 (http://ipsec-tools.sourceforge.net)
    Mar 2 11:48:57 racoon: INFO: @(#)This product linked OpenSSL 0.9.8e 23 Feb 2007 (http://www.openssl.org/)
    Mar 2 11:48:57 racoon: INFO: Reading configuration from "/var/etc/racoon.conf"
    Mar 2 11:48:57 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
    Mar 2 11:48:57 racoon: [Self]: INFO: 192.168.150.10[500] used as isakmp port (fd=15)
    Mar 2 11:48:57 racoon: [Self]: INFO: 192.168.1.50[500] used as isakmp port (fd=16)
    Mar 2 11:48:57 racoon: INFO: unsupported PF_KEY message REGISTER
    Mar 2 11:48:57 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
    Mar 2 11:48:57 racoon: [Self]: INFO: 192.168.150.10[500] used as isakmp port (fd=15)
    Mar 2 11:48:57 racoon: [Self]: INFO: 192.168.1.50[500] used as isakmp port (fd=16)

    After ISAKMP-SA expired messages, i've added lifetime for phase 1 and phase 2, but no luck :(

    This is racoon in debug mode on site A:

    2011-03-02 17:44:09: INFO: @(#)ipsec-tools 0.7.2 (http://ipsec-tools.sourceforge.net)
    2011-03-02 17:44:09: INFO: @(#)This product linked OpenSSL 0.9.8e 23 Feb 2007 (http://www.openssl.org/)
    2011-03-02 17:44:09: INFO: Reading configuration from "/var/etc/racoon.conf"
    2011-03-02 17:44:09: DEBUG: call pfkey_send_register for AH
    2011-03-02 17:44:09: DEBUG: call pfkey_send_register for ESP
    2011-03-02 17:44:09: DEBUG: call pfkey_send_register for IPCOMP
    2011-03-02 17:44:09: DEBUG: reading config file /var/etc/racoon.conf
    2011-03-02 17:44:09: DEBUG: hmac(modp1024)
    2011-03-02 17:44:09: DEBUG: compression algorithm can not be checked because sadb message doesn't support it.
    2011-03-02 17:44:09: DEBUG: getsainfo params: loc='192.168.100.0/24', rmt='10.192.1.0/24', peer='NULL', id=0
    2011-03-02 17:44:09: DEBUG: getsainfo pass #2
    2011-03-02 17:44:09: DEBUG: open /var/db/racoon/racoon.sock as racoon management.
    2011-03-02 17:44:09: DEBUG: my interface: 192.168.100.1 (vge0)
    2011-03-02 17:44:09: DEBUG: my interface: 1.1.1.1 (re0)
    2011-03-02 17:44:09: DEBUG: my interface: 127.0.0.1 (lo0)
    2011-03-02 17:44:09: DEBUG: configuring default isakmp port.
    2011-03-02 17:44:09: DEBUG: 3 addrs are configured successfully
    2011-03-02 17:44:09: INFO: 127.0.0.1[500] used as isakmp port (fd=7)
    2011-03-02 17:44:09: INFO: 1.1.1.1[500] used as isakmp port (fd=8)
    2011-03-02 17:44:09: INFO: 192.168.100.1[500] used as isakmp port (fd=9)
    2011-03-02 17:44:09: DEBUG: pk_recv: retry[0] recv()
    2011-03-02 17:44:09: DEBUG: get pfkey X_SPDDUMP message
    2011-03-02 17:44:09: DEBUG: pk_recv: retry[0] recv()
    2011-03-02 17:44:09: DEBUG: get pfkey X_SPDDUMP message
    2011-03-02 17:44:09: DEBUG: sub:0xbfbfe5b4: 192.168.100.1/32[0] 192.168.100.0/24[0] proto=any dir=out
    2011-03-02 17:44:09: DEBUG: db :0x2853c118: 192.168.100.0/24[0] 192.168.100.1/32[0] proto=any dir=in

    on site B:

    2011-03-02 17:44:21: INFO: @(#)ipsec-tools 0.7.2 (http://ipsec-tools.sourceforge.net)
    2011-03-02 17:44:21: INFO: @(#)This product linked OpenSSL 0.9.8e 23 Feb 2007 (http://www.openssl.org/)
    2011-03-02 17:44:21: INFO: Reading configuration from "/var/etc/racoon.conf"
    2011-03-02 17:44:21: DEBUG: call pfkey_send_register for AH
    2011-03-02 17:44:21: DEBUG: call pfkey_send_register for ESP
    2011-03-02 17:44:21: DEBUG: call pfkey_send_register for IPCOMP
    2011-03-02 17:44:21: DEBUG: reading config file /var/etc/racoon.conf
    2011-03-02 17:44:21: DEBUG: hmac(modp1024)
    2011-03-02 17:44:21: DEBUG: compression algorithm can not be checked because sadb message doesn't support it.
    2011-03-02 17:44:21: DEBUG: getsainfo params: loc='192.168.1.0/24', rmt='192.168.100.0/24', peer='NULL', id=0
    2011-03-02 17:44:21: DEBUG: getsainfo pass #2
    2011-03-02 17:44:21: DEBUG: open /var/db/racoon/racoon.sock as racoon management.
    2011-03-02 17:44:21: DEBUG: my interface: 192.168.1.50 (vge0)
    2011-03-02 17:44:21: DEBUG: my interface: 192.168.150.10 (re0)
    2011-03-02 17:44:21: DEBUG: my interface: 127.0.0.1 (lo0)
    2011-03-02 17:44:21: DEBUG: configuring default isakmp port.
    2011-03-02 17:44:21: DEBUG: 3 addrs are configured successfully
    2011-03-02 17:44:21: INFO: 127.0.0.1[500] used as isakmp port (fd=7)
    2011-03-02 17:44:21: INFO: 192.168.150.10[500] used as isakmp port (fd=8)
    2011-03-02 17:44:21: INFO: 192.168.1.50[500] used as isakmp port (fd=9)
    2011-03-02 17:44:21: DEBUG: pk_recv: retry[0] recv()
    2011-03-02 17:44:21: DEBUG: get pfkey X_SPDDUMP message
    2011-03-02 17:44:21: DEBUG: pk_recv: retry[0] recv()
    2011-03-02 17:44:21: DEBUG: get pfkey X_SPDDUMP message
    2011-03-02 17:44:21: DEBUG: sub:0xbfbfe5b4: 192.168.1.50/32[0] 192.168.1.0/24[0] proto=any dir=out
    2011-03-02 17:44:21: DEBUG: db :0x2853c118: 192.168.1.0/24[0] 192.168.1.50/32[0] proto=any dir=in

    No other messages are available.

    Can anyone tell me where i'm wrong??

    Sierra


Log in to reply