Netgate Discussion Forum
    • Categories
    • Recent
    • Tags
    • Popular
    • Users
    • Search
    • Register
    • Login

    IPsec Point-to-Point Fails Hard

    Scheduled Pinned Locked Moved IPsec
    5 Posts 3 Posters 1.6k Views
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • B
      Bjørkum
      last edited by

      My organization has been running an IPsec tunnel for about a year with both ends running the latest version of pfSense (2.1.4 as of this writing, previously 2.1.3).

      We've had problems on and off, but about 99% of the time its been stable (not good enough for our standards, mind you.)

      in the past six months, we've ironed out almost all of our major bugs, but it's still faulted out a couple of times, and I haven't been able to find anything to help me understand what's being logged when the failure happens.

      This is a sanitized copy of the logs covering our most recent outage:

      Aug 19 19:54:10	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=228093799(0xd986f67)
      Aug 19 19:54:10	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=159771144(0x985ea08)
      Aug 19 19:54:10	racoon: [VPN->RemoteSite]: INFO: respond new phase 2 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 19:50:43	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=121898106(0x744047a)
      Aug 19 19:50:43	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=119648669(0x721b19d)
      Aug 19 19:50:43	racoon: [VPN->RemoteSite]: INFO: initiate new phase 2 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 19:50:30	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=235549440(0xe0a3300)
      Aug 19 19:50:30	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=267095629(0xfeb8e4d)
      Aug 19 19:50:30	racoon: [VPN->RemoteSite]: INFO: initiate new phase 2 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 19:50:26	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=29527171(0x1c28c83)
      Aug 19 19:50:26	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=15104821(0xe67b35)
      Aug 19 19:50:25	racoon: [VPN->RemoteSite]: INFO: initiate new phase 2 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 19:50:25	racoon: [VPN->RemoteSite]: INFO: ISAKMP-SA established {ISP 1 Public IP 1}[500]-{RemoteIP}[500] spi:dad589bca3717502:5a5f569abd313e55
      Aug 19 19:50:25	racoon: INFO: received Vendor ID: DPD
      Aug 19 19:50:25	racoon: INFO: received broken Microsoft ID: FRAGMENTATION
      Aug 19 19:50:25	racoon: INFO: begin Identity Protection mode.
      Aug 19 19:50:25	racoon: [VPN->RemoteSite]: INFO: respond new phase 1 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 19:50:25	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=178848155(0xaa9019b)
      Aug 19 19:50:25	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=27143013(0x19e2b65)
      Aug 19 19:50:24	racoon: [VPN->RemoteSite]: INFO: initiate new phase 2 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 19:50:22	racoon: INFO: purged IPsec-SA proto_id=ESP spi=263322175.
      Aug 19 19:50:22	racoon: ERROR: pfkey DELETE received: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=106480519(0x658c387)
      Aug 19 19:50:22	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=263322175(0xfb1fa3f)
      Aug 19 19:50:22	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=180607411(0xac3d9b3)
      Aug 19 19:50:22	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=202609879(0xc1394d7)
      Aug 19 19:50:22	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=49876078(0x2f90c6e)
      Aug 19 19:50:21	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=106480519(0x658c387)
      Aug 19 19:50:21	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=174603812(0xa683e24)
      Aug 19 19:50:21	racoon: [VPN->RemoteSite]: INFO: respond new phase 2 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 19:50:21	racoon: [VPN->RemoteSite]: INFO: respond new phase 2 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 19:50:21	racoon: [VPN->RemoteSite]: INFO: initiate new phase 2 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 19:50:20	racoon: [VPN->RemoteSite]: INFO: ISAKMP-SA established {ISP 1 Public IP 1}[500]-{RemoteIP}[500] spi:b939b05f89ee26a8:e254e4374b0959f7
      Aug 19 19:50:20	racoon: INFO: received broken Microsoft ID: FRAGMENTATION
      Aug 19 19:50:20	racoon: INFO: received Vendor ID: DPD
      Aug 19 19:50:20	racoon: INFO: begin Identity Protection mode.
      Aug 19 19:50:20	racoon: [VPN->RemoteSite]: INFO: initiate new phase 1 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 19:50:20	racoon: [VPN->RemoteSite]: INFO: IPsec-SA request for {RemoteIP} queued due to no phase1 found.
      Aug 19 19:50:19	racoon: INFO: unsupported PF_KEY message REGISTER
      Aug 19 19:50:19	racoon: INFO: unsupported PF_KEY message REGISTER
      Aug 19 19:50:19	racoon: INFO: unsupported PF_KEY message REGISTER
      Aug 19 19:50:19	racoon: INFO: unsupported PF_KEY message REGISTER
      Aug 19 19:50:19	racoon: INFO: unsupported PF_KEY message REGISTER
      Aug 19 19:50:19	racoon: INFO: unsupported PF_KEY message REGISTER
      Aug 19 19:50:19	racoon: INFO: unsupported PF_KEY message REGISTER
      Aug 19 19:50:15	racoon: [VPN->RemoteSite]: [{RemoteIP}] ERROR: exchange Identity Protection not allowed in any applicable rmconf.
      Aug 19 19:50:11	racoon: INFO: unsupported PF_KEY message REGISTER
      Aug 19 19:50:11	racoon: [VPN->RemoteSite]: INFO: ISAKMP-SA deleted {ISP 1 Public IP 1}[500]-{RemoteIP}[500] spi:2ececdaa4598b6a2:5c6e69759bcc753a
      Aug 19 19:50:11	racoon: [Self]: INFO: 192.168.99.1[4500] used as isakmp port (fd=43)
      Aug 19 19:50:11	racoon: [Self]: INFO: 192.168.99.1[4500] used for NAT-T
      Aug 19 19:50:11	racoon: [Self]: INFO: 192.168.99.1[500] used as isakmp port (fd=42)
      Aug 19 19:50:11	racoon: [Self]: INFO: 192.168.99.1[500] used for NAT-T
      Aug 19 19:50:11	racoon: INFO: fe80:9::4e02:89ff:fe09:4ae[4500] used as isakmp port (fd=41)
      Aug 19 19:50:11	racoon: INFO: fe80:9::4e02:89ff:fe09:4ae[500] used as isakmp port (fd=40)
      Aug 19 19:50:11	racoon: [Self]: INFO: fe80:5::1[4500] used as isakmp port (fd=39)
      Aug 19 19:50:11	racoon: [Self]: INFO: fe80:5::1[500] used as isakmp port (fd=38)
      Aug 19 19:50:11	racoon: [Self]: INFO: ::1[4500] used as isakmp port (fd=37)
      Aug 19 19:50:11	racoon: [Self]: INFO: ::1[500] used as isakmp port (fd=36)
      Aug 19 19:50:11	racoon: [Self]: INFO: 127.0.0.1[4500] used as isakmp port (fd=35)
      Aug 19 19:50:11	racoon: [Self]: INFO: 127.0.0.1[4500] used for NAT-T
      Aug 19 19:50:11	racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=34)
      Aug 19 19:50:11	racoon: [Self]: INFO: 127.0.0.1[500] used for NAT-T
      Aug 19 19:50:11	racoon: INFO: fe80:4::4e02:89ff:fe09:4b1[4500] used as isakmp port (fd=33)
      Aug 19 19:50:11	racoon: INFO: fe80:4::4e02:89ff:fe09:4b1[500] used as isakmp port (fd=32)
      Aug 19 19:50:11	racoon: [Self]: INFO: 10.1.20.1[4500] used as isakmp port (fd=31)
      Aug 19 19:50:11	racoon: [Self]: INFO: 10.1.20.1[4500] used for NAT-T
      Aug 19 19:50:11	racoon: [Self]: INFO: 10.1.20.1[500] used as isakmp port (fd=30)
      Aug 19 19:50:11	racoon: [Self]: INFO: 10.1.20.1[500] used for NAT-T
      Aug 19 19:50:11	racoon: INFO: fe80:3::4e02:89ff:fe09:4b0[4500] used as isakmp port (fd=29)
      Aug 19 19:50:11	racoon: INFO: fe80:3::4e02:89ff:fe09:4b0[500] used as isakmp port (fd=28)
      Aug 19 19:50:11	racoon: [Self]: INFO: {ISP 2 Public IP 1}[4500] used as isakmp port (fd=27)
      Aug 19 19:50:11	racoon: [Self]: INFO: {ISP 2 Public IP 1}[4500] used for NAT-T
      Aug 19 19:50:11	racoon: [Self]: INFO: {ISP 2 Public IP 1}[500] used as isakmp port (fd=26)
      Aug 19 19:50:11	racoon: [Self]: INFO: {ISP 2 Public IP 1}[500] used for NAT-T
      Aug 19 19:50:11	racoon: [Self]: INFO: {ISP 1 Public IP 2}[4500] used as isakmp port (fd=25)
      Aug 19 19:50:11	racoon: [Self]: INFO: {ISP 1 Public IP 2}[4500] used for NAT-T
      Aug 19 19:50:11	racoon: [Self]: INFO: {ISP 1 Public IP 2}[500] used as isakmp port (fd=24)
      Aug 19 19:50:11	racoon: [Self]: INFO: {ISP 1 Public IP 2}[500] used for NAT-T
      Aug 19 19:50:11	racoon: INFO: fe80:2::4e02:89ff:fe09:4af[4500] used as isakmp port (fd=23)
      Aug 19 19:50:11	racoon: INFO: fe80:2::4e02:89ff:fe09:4af[500] used as isakmp port (fd=22)
      Aug 19 19:50:11	racoon: INFO: fe80:1::4e02:89ff:fe09:4ae[4500] used as isakmp port (fd=19)
      Aug 19 19:50:11	racoon: INFO: fe80:1::4e02:89ff:fe09:4ae[500] used as isakmp port (fd=18)
      Aug 19 19:50:11	racoon: [Self]: INFO: 192.168.1.1[4500] used as isakmp port (fd=17)
      Aug 19 19:50:11	racoon: [Self]: INFO: 192.168.1.1[4500] used for NAT-T
      Aug 19 19:50:11	racoon: [Self]: INFO: 192.168.1.1[500] used as isakmp port (fd=16)
      Aug 19 19:50:11	racoon: [Self]: INFO: 192.168.1.1[500] used for NAT-T
      Aug 19 19:50:11	racoon: INFO: unsupported PF_KEY message REGISTER
      Aug 19 19:50:11	racoon: INFO: unsupported PF_KEY message REGISTER
      Aug 19 19:50:11	racoon: INFO: unsupported PF_KEY message REGISTER
      Aug 19 19:50:11	racoon: INFO: unsupported PF_KEY message REGISTER
      Aug 19 19:50:11	racoon: INFO: unsupported PF_KEY message REGISTER
      Aug 19 19:50:11	racoon: ERROR: no iph2 found: ESP {RemoteIP}[500]->{ISP 1 Public IP 1}[500] spi=152426221(0x915d6ed)
      Aug 19 19:50:11	racoon: ERROR: pfkey DELETE received: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=62483466(0x3b96c0a)
      Aug 19 19:50:11	racoon: ERROR: no iph2 found: ESP {RemoteIP}[500]->{ISP 1 Public IP 1}[500] spi=8617416(0x837dc8)
      Aug 19 19:50:11	racoon: ERROR: pfkey DELETE received: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=130219438(0x7c2fdae)
      Aug 19 19:50:11	racoon: ERROR: no iph2 found: ESP {RemoteIP}[500]->{ISP 1 Public IP 1}[500] spi=216079264(0xce11ba0)
      Aug 19 19:50:11	racoon: ERROR: pfkey DELETE received: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=230695843(0xdc023a3)
      Aug 19 19:50:11	racoon: ERROR: no iph2 found: ESP {RemoteIP}[500]->{ISP 1 Public IP 1}[500] spi=20938334(0x13f7e5e)
      Aug 19 19:50:11	racoon: ERROR: no iph2 found: ESP {RemoteIP}[500]->{ISP 1 Public IP 1}[500] spi=102825367(0x620fd97)
      Aug 19 19:50:11	racoon: ERROR: pfkey DELETE received: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=144683486(0x89fb1de)
      Aug 19 19:50:11	racoon: ERROR: no iph2 found: ESP {RemoteIP}[500]->{ISP 1 Public IP 1}[500] spi=119558535(0x7205187)
      Aug 19 19:50:11	racoon: ERROR: no iph2 found: ESP {RemoteIP}[500]->{ISP 1 Public IP 1}[500] spi=156127355(0x94e507b)
      Aug 19 19:50:11	racoon: ERROR: pfkey DELETE received: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=36462564(0x22c5fe4)
      Aug 19 19:50:11	racoon: ERROR: no iph2 found: ESP {RemoteIP}[500]->{ISP 1 Public IP 1}[500] spi=185997930(0xb161a6a)
      Aug 19 19:50:11	racoon: ERROR: no iph2 found: ESP {RemoteIP}[500]->{ISP 1 Public IP 1}[500] spi=192406940(0xb77e59c)
      Aug 19 19:50:11	racoon: ERROR: pfkey DELETE received: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=80335979(0x4c9d46b)
      Aug 19 19:50:11	racoon: ERROR: pfkey DELETE received: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=32256311(0x1ec3137)
      Aug 19 19:50:11	racoon: INFO: unsupported PF_KEY message REGISTER
      Aug 19 19:20:04	racoon: ERROR: pfkey DELETE received: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=96848159(0x5c5c91f)
      Aug 19 19:20:03	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=36462564(0x22c5fe4)
      Aug 19 19:20:03	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=156127355(0x94e507b)
      Aug 19 19:20:03	racoon: [VPN->RemoteSite]: INFO: respond new phase 2 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 19:18:06	racoon: ERROR: pfkey DELETE received: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=27231381(0x19f8495)
      Aug 19 19:14:33	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=144683486(0x89fb1de)
      Aug 19 19:14:33	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=102825367(0x620fd97)
      Aug 19 19:14:33	racoon: [VPN->RemoteSite]: INFO: respond new phase 2 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 19:13:12	racoon: ERROR: {RemoteIP} give up to get IPsec-SA due to time up to wait.
      Aug 19 19:13:08	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=32256311(0x1ec3137)
      Aug 19 19:13:08	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=192406940(0xb77e59c)
      Aug 19 19:13:07	racoon: [VPN->RemoteSite]: INFO: respond new phase 2 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 19:12:42	racoon: [VPN->RemoteSite]: INFO: respond new phase 2 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 19:10:55	racoon: ERROR: {RemoteIP} give up to get IPsec-SA due to time up to wait.
      Aug 19 19:10:55	racoon: ERROR: {RemoteIP} give up to get IPsec-SA due to time up to wait.
      Aug 19 19:10:49	racoon: [VPN->RemoteSite]: INFO: ISAKMP-SA deleted {ISP 1 Public IP 1}[500]-{RemoteIP}[500] spi:608011b495ce8d0b:e32c2fafe8d1e90d
      Aug 19 19:10:49	racoon: INFO: purged ISAKMP-SA spi=608011b495ce8d0b:e32c2fafe8d1e90d.
      Aug 19 19:10:49	racoon: INFO: keeping IPsec-SA spi=152426221 - found valid ISAKMP-SA spi=2ececdaa4598b6a2:5c6e69759bcc753a.
      Aug 19 19:10:49	racoon: INFO: keeping IPsec-SA spi=62483466 - found valid ISAKMP-SA spi=2ececdaa4598b6a2:5c6e69759bcc753a.
      Aug 19 19:10:49	racoon: INFO: keeping IPsec-SA spi=8617416 - found valid ISAKMP-SA spi=2ececdaa4598b6a2:5c6e69759bcc753a.
      Aug 19 19:10:49	racoon: INFO: keeping IPsec-SA spi=130219438 - found valid ISAKMP-SA spi=2ececdaa4598b6a2:5c6e69759bcc753a.
      Aug 19 19:10:49	racoon: INFO: keeping IPsec-SA spi=216079264 - found valid ISAKMP-SA spi=2ececdaa4598b6a2:5c6e69759bcc753a.
      Aug 19 19:10:49	racoon: INFO: keeping IPsec-SA spi=230695843 - found valid ISAKMP-SA spi=2ececdaa4598b6a2:5c6e69759bcc753a.
      Aug 19 19:10:49	racoon: INFO: keeping IPsec-SA spi=20938334 - found valid ISAKMP-SA spi=2ececdaa4598b6a2:5c6e69759bcc753a.
      Aug 19 19:10:49	racoon: INFO: keeping IPsec-SA spi=27231381 - found valid ISAKMP-SA spi=2ececdaa4598b6a2:5c6e69759bcc753a.
      Aug 19 19:10:49	racoon: INFO: keeping IPsec-SA spi=119558535 - found valid ISAKMP-SA spi=2ececdaa4598b6a2:5c6e69759bcc753a.
      Aug 19 19:10:49	racoon: INFO: keeping IPsec-SA spi=96848159 - found valid ISAKMP-SA spi=2ececdaa4598b6a2:5c6e69759bcc753a.
      Aug 19 19:10:49	racoon: INFO: keeping IPsec-SA spi=185997930 - found valid ISAKMP-SA spi=2ececdaa4598b6a2:5c6e69759bcc753a.
      Aug 19 19:10:49	racoon: INFO: keeping IPsec-SA spi=80335979 - found valid ISAKMP-SA spi=2ececdaa4598b6a2:5c6e69759bcc753a.
      Aug 19 19:10:49	racoon: INFO: purging ISAKMP-SA spi=608011b495ce8d0b:e32c2fafe8d1e90d.
      Aug 19 19:10:49	racoon: [VPN->RemoteSite]: [{RemoteIP}] INFO: DPD: remote (ISAKMP-SA spi=608011b495ce8d0b:e32c2fafe8d1e90d) seems to be dead.
      Aug 19 19:10:25	racoon: [VPN->RemoteSite]: INFO: respond new phase 2 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 19:10:25	racoon: [VPN->RemoteSite]: INFO: respond new phase 2 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 19:10:24	racoon: NOTIFY: the packet is retransmitted by {RemoteIP}[500] (1).
      Aug 19 19:10:24	racoon: WARNING: the packet retransmitted in a short time from {RemoteIP}[500]
      Aug 19 19:10:24	racoon: [VPN->RemoteSite]: INFO: ISAKMP-SA established {ISP 1 Public IP 1}[500]-{RemoteIP}[500] spi:2ececdaa4598b6a2:5c6e69759bcc753a
      Aug 19 19:10:24	racoon: NOTIFY: the packet is retransmitted by {RemoteIP}[500] (1).
      Aug 19 19:10:24	racoon: WARNING: the packet retransmitted in a short time from {RemoteIP}[500]
      Aug 19 19:10:14	racoon: INFO: received Vendor ID: DPD
      Aug 19 19:10:14	racoon: INFO: received broken Microsoft ID: FRAGMENTATION
      Aug 19 19:10:14	racoon: INFO: begin Identity Protection mode.
      Aug 19 19:10:14	racoon: [VPN->RemoteSite]: INFO: respond new phase 1 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 17:04:00	racoon: [VPN->RemoteSite]: INFO: ISAKMP-SA deleted {ISP 1 Public IP 1}[500]-{RemoteIP}[500] spi:3ec2fb2ec559eba7:e92a52e05e6bd965
      Aug 19 17:04:00	racoon: [VPN->RemoteSite]: INFO: ISAKMP-SA expired {ISP 1 Public IP 1}[500]-{RemoteIP}[500] spi:3ec2fb2ec559eba7:e92a52e05e6bd965
      Aug 19 14:42:39	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=96848159(0x5c5c91f)
      Aug 19 14:42:39	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=119558535(0x7205187)
      Aug 19 14:42:39	racoon: [VPN->RemoteSite]: INFO: respond new phase 2 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 14:42:39	racoon: [VPN->RemoteSite]: INFO: IPsec-SA expired: ESP/Tunnel {RemoteIP}[500]->{ISP 1 Public IP 1}[500] spi=75900866(0x48627c2)
      Aug 19 14:42:39	racoon: [VPN->RemoteSite]: INFO: IPsec-SA expired: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=6229344(0x5f0d60)
      Aug 19 14:42:10	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=130219438(0x7c2fdae)
      Aug 19 14:42:10	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=8617416(0x837dc8)
      Aug 19 14:42:10	racoon: [VPN->RemoteSite]: INFO: IPsec-SA expired: ESP/Tunnel {RemoteIP}[500]->{ISP 1 Public IP 1}[500] spi=33217454(0x1fadbae)
      Aug 19 14:42:10	racoon: [VPN->RemoteSite]: INFO: IPsec-SA expired: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=200043994(0xbec6dda)
      Aug 19 14:42:10	racoon: [VPN->RemoteSite]: INFO: respond new phase 2 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 14:40:57	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=27231381(0x19f8495)
      Aug 19 14:40:57	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=20938334(0x13f7e5e)
      Aug 19 14:40:57	racoon: [VPN->RemoteSite]: INFO: IPsec-SA expired: ESP/Tunnel {RemoteIP}[500]->{ISP 1 Public IP 1}[500] spi=48479228(0x2e3bbfc)
      Aug 19 14:40:57	racoon: [VPN->RemoteSite]: INFO: initiate new phase 2 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 14:40:57	racoon: [VPN->RemoteSite]: INFO: IPsec-SA expired: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=188290008(0xb3913d8)
      Aug 19 14:40:54	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=80335979(0x4c9d46b)
      Aug 19 14:40:54	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=185997930(0xb161a6a)
      Aug 19 14:40:54	racoon: [VPN->RemoteSite]: INFO: IPsec-SA expired: ESP/Tunnel {RemoteIP}[500]->{ISP 1 Public IP 1}[500] spi=72744627(0x455feb3)
      Aug 19 14:40:54	racoon: [VPN->RemoteSite]: INFO: initiate new phase 2 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 14:40:54	racoon: [VPN->RemoteSite]: INFO: IPsec-SA expired: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=89756263(0x5599267)
      Aug 19 14:40:40	racoon: INFO: purged IPsec-SA proto_id=ESP spi=9235643.
      Aug 19 14:40:40	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=62483466(0x3b96c0a)
      Aug 19 14:40:40	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=152426221(0x915d6ed)
      Aug 19 14:40:40	racoon: [VPN->RemoteSite]: INFO: IPsec-SA expired: ESP/Tunnel {RemoteIP}[500]->{ISP 1 Public IP 1}[500] spi=58916423(0x382fe47)
      Aug 19 14:40:40	racoon: [VPN->RemoteSite]: INFO: initiate new phase 2 negotiation: {ISP 1 Public IP 1}[500]<=>{RemoteIP}[500]
      Aug 19 14:40:40	racoon: [VPN->RemoteSite]: INFO: IPsec-SA expired: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=9235643(0x8cecbb)
      Aug 19 14:40:39	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=230695843(0xdc023a3)
      Aug 19 14:40:39	racoon: [VPN->RemoteSite]: INFO: IPsec-SA established: ESP {ISP 1 Public IP 1}[500]->{RemoteIP}[500] spi=216079264(0xce11ba0)
      

      The entries around 19:10 reflect activity during the period of trouble.

      Entries starting at 19:50:11 and running to the top show re-establishment after manual intervention.

      My best guess is that DPD is responsible for the failure to re-establish, but racoon's logging is so cryptic and documentation thereof is so sparse that I don't feel like I can confidently say anything about this.

      If anyone can point me to some quality reference for racoon's error messages (I couldn't find anything here, on the main page, on KAME's site, or on IPsecTools's site,) I would be immensely appreciative.

      Likewise, if anyone can point out exactly why this isn't reconnecting from the logs, it'd be a big help.

      Thanks!

      1 Reply Last reply Reply Quote 0
      • ?
        Guest
        last edited by

        ..some of the stories you tell made me switch to openVPN tunnels with good results. Maybe you should give it a try, with a pre-shared secret a site-to-site tunnel is not that a big issue with 2.1.4…

        1 Reply Last reply Reply Quote 0
        • B
          Bjørkum
          last edited by

          I saw others suggest the same in other threads.  It's certainly worth consideration, I just have to do some research to make sure it'd do what we need it to without compromising security  :)

          1 Reply Last reply Reply Quote 0
          • T
            thorolason
            last edited by

            Have you tried disabling DPD ?
            i have had some problems on a long latancy ipsec tunnel where DPD was taking the tunnel down and not re-establishing it. Disabling it resolved the issue for me.

            Cheers - Thor

            1 Reply Last reply Reply Quote 0
            • B
              Bjørkum
              last edited by

              Thanks, Thor!

              The tunnels have remained pretty stable for the past few days since I relaxed DPD's tolerances, so I'm keeping my fingers crossed.  However, if they start to flake out on me again, that is my next step  :)

              1 Reply Last reply Reply Quote 0
              • First post
                Last post
              Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.