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

    Response Packet Ignored

    IPsec
    1
    1
    2.0k
    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.
    • C
      clarkdej
      last edited by

      Reviewed all settings for IPSEC VPN setup.  Phase1 ISAKMP Packet is being sent, but the return packet, though it appears valid looking at it with wireshark, seems to be ignored by pfSense.

      A packet capture doesn't show ESP packets at egress or ingress, so I assume packet capture ignores IPSEC stuff.

      The racoon debug mode makes no mention of a problem with the received response packet, it looks like it never sees it.

      Wireshark is connected to hub, connected to firewall WAN NIC.  I know the packet is being sent and response sent by remote box.

      How can I troubleshoot this further?

      ====== Logs

      Apr 10 08:45:43 racoon: 2009-04-10 08:45:43: DEBUG: msg 1 not interesting
      Apr 10 08:45:43 racoon: 2009-04-10 08:45:43: DEBUG: resend phase1 packet 2bfca020805582a7:0000000000000000
      Apr 10 08:45:43 racoon: 2009-04-10 08:45:43: DEBUG: 2bfca020 805582a7 00000000 00000000 01100400 00000000 00000124 04000038 00000001 00000001 0000002c 01010001 00000024 01010000 800b0001 800c7080 80010003 800e0080 80030001 80020002 80040002 0a000084 9a214db3 3856347c 2218c21d 4d668751 40c20cc1 a893e288 9e3b7931 dd94aec9 bebfe57b 8aeb81d5 ca1ebb96 6e0b22bb 9f626971 d42a423b 5423adfd a58da6e0 50b9aadb 692a3cec c67c36ec 018a810b 42dffc3f 09f1152d e1c89347 cd4a8b13 9530ffca 2cd407f6 28fc315b 595fe897 34e55295 9789df54 3cb0f089 f21bed8c 05000014 cecee9a3 e1970079 f66fccd2 70b3398a 0d00000c 011101f4 46ed9fbd 0d000018 4048b7d5 6ebce885 25e7de7f 00d6c2d3 80000000 00000014 afcad713 68a1f1c9 6b8696fc 77570100
      Apr 10 08:45:43 racoon: 2009-04-10 08:45:43: DEBUG: 1 times of 292 bytes message will be sent to 68.153.xx.xx[500]
      Apr 10 08:45:43 racoon: 2009-04-10 08:45:43: DEBUG: send packet to 68.153.xx.xx[500]
      Apr 10 08:45:43 racoon: 2009-04-10 08:45:43: DEBUG: send packet from 70.237.xx.xx[500]
      Apr 10 08:45:43 racoon: 2009-04-10 08:45:43: DEBUG: sockname 70.237.xx.xx[500]
      Apr 10 08:45:43 racoon: 2009-04-10 08:45:43: DEBUG: 292 bytes from 70.237.xx.xx[500] to 68.153.xx.xx[500]
      Apr 10 08:45:34 racoon: 2009-04-10 08:45:34: INFO: delete phase 2 handler.
      Apr 10 08:45:34 racoon: 2009-04-10 08:45:34: ERROR: phase2 negotiation failed due to time up waiting for phase1. ESP 68.153.xx.xx[0]->70.237.xx.xx[0]
      Apr 10 08:45:33 racoon: 2009-04-10 08:45:33: DEBUG: msg 1 not interesting
      Apr 10 08:45:33 racoon: 2009-04-10 08:45:33: DEBUG: resend phase1 packet 2bfca020805582a7:0000000000000000
      Apr 10 08:45:33 racoon: 2009-04-10 08:45:33: DEBUG: 2bfca020 805582a7 00000000 00000000 01100400 00000000 00000124 04000038 00000001 00000001 0000002c 01010001 00000024 01010000 800b0001 800c7080 80010003 800e0080 80030001 80020002 80040002 0a000084 9a214db3 3856347c 2218c21d 4d668751 40c20cc1 a893e288 9e3b7931 dd94aec9 bebfe57b 8aeb81d5 ca1ebb96 6e0b22bb 9f626971 d42a423b 5423adfd a58da6e0 50b9aadb 692a3cec c67c36ec 018a810b 42dffc3f 09f1152d e1c89347 cd4a8b13 9530ffca 2cd407f6 28fc315b 595fe897 34e55295 9789df54 3cb0f089 f21bed8c 05000014 cecee9a3 e1970079 f66fccd2 70b3398a 0d00000c 011101f4 46ed9fbd 0d000018 4048b7d5 6ebce885 25e7de7f 00d6c2d3 80000000 00000014 afcad713 68a1f1c9 6b8696fc 77570100
      Apr 10 08:45:33 racoon: 2009-04-10 08:45:33: DEBUG: 1 times of 292 bytes message will be sent to 68.153.xx.xx[500]
      Apr 10 08:45:33 racoon: 2009-04-10 08:45:33: DEBUG: send packet to 68.153.xx.xx[500]
      Apr 10 08:45:33 racoon: 2009-04-10 08:45:33: DEBUG: send packet from 70.237.xx.xx[500]
      Apr 10 08:45:33 racoon: 2009-04-10 08:45:33: DEBUG: sockname 70.237.xx.xx[500]
      Apr 10 08:45:33 racoon: 2009-04-10 08:45:33: DEBUG: 292 bytes from 70.237.xx.xx[500] to 68.153.xx.xx[500]
      Apr 10 08:45:23 racoon: 2009-04-10 08:45:23: DEBUG: msg 1 not interesting
      Apr 10 08:45:23 racoon: 2009-04-10 08:45:23: DEBUG: resend phase1 packet 2bfca020805582a7:0000000000000000
      Apr 10 08:45:23 racoon: 2009-04-10 08:45:23: DEBUG: 2bfca020 805582a7 00000000 00000000 01100400 00000000 00000124 04000038 00000001 00000001 0000002c 01010001 00000024 01010000 800b0001 800c7080 80010003 800e0080 80030001 80020002 80040002 0a000084 9a214db3 3856347c 2218c21d 4d668751 40c20cc1 a893e288 9e3b7931 dd94aec9 bebfe57b 8aeb81d5 ca1ebb96 6e0b22bb 9f626971 d42a423b 5423adfd a58da6e0 50b9aadb 692a3cec c67c36ec 018a810b 42dffc3f 09f1152d e1c89347 cd4a8b13 9530ffca 2cd407f6 28fc315b 595fe897 34e55295 9789df54 3cb0f089 f21bed8c 05000014 cecee9a3 e1970079 f66fccd2 70b3398a 0d00000c 011101f4 46ed9fbd 0d000018 4048b7d5 6ebce885 25e7de7f 00d6c2d3 80000000 00000014 afcad713 68a1f1c9 6b8696fc 77570100
      Apr 10 08:45:23 racoon: 2009-04-10 08:45:23: DEBUG: 1 times of 292 bytes message will be sent to 68.153.xx.xx[500]
      Apr 10 08:45:23 racoon: 2009-04-10 08:45:23: DEBUG: send packet to 68.153.xx.xx[500]
      Apr 10 08:45:23 racoon: 2009-04-10 08:45:23: DEBUG: send packet from 70.237.xx.xx[500]
      Apr 10 08:45:23 racoon: 2009-04-10 08:45:23: DEBUG: sockname 70.237.xx.xx[500]
      Apr 10 08:45:23 racoon: 2009-04-10 08:45:23: DEBUG: 292 bytes from 70.237.xx.xx[500] to 68.153.xx.xx[500]
      Apr 10 08:45:15 racoon: 2009-04-10 08:45:15: DEBUG: msg 1 not interesting
      Apr 10 08:45:14 racoon: 2009-04-10 08:45:14: DEBUG: msg 1 not interesting
      Apr 10 08:45:13 racoon: 2009-04-10 08:45:13: DEBUG: msg 1 not interesting
      Apr 10 08:45:13 racoon: 2009-04-10 08:45:13: DEBUG: resend phase1 packet 2bfca020805582a7:0000000000000000
      Apr 10 08:45:13 racoon: 2009-04-10 08:45:13: DEBUG: 2bfca020 805582a7 00000000 00000000 01100400 00000000 00000124 04000038 00000001 00000001 0000002c 01010001 00000024 01010000 800b0001 800c7080 80010003 800e0080 80030001 80020002 80040002 0a000084 9a214db3 3856347c 2218c21d 4d668751 40c20cc1 a893e288 9e3b7931 dd94aec9 bebfe57b 8aeb81d5 ca1ebb96 6e0b22bb 9f626971 d42a423b 5423adfd a58da6e0 50b9aadb 692a3cec c67c36ec 018a810b 42dffc3f 09f1152d e1c89347 cd4a8b13 9530ffca 2cd407f6 28fc315b 595fe897 34e55295 9789df54 3cb0f089 f21bed8c 05000014 cecee9a3 e1970079 f66fccd2 70b3398a 0d00000c 011101f4 46ed9fbd 0d000018 4048b7d5 6ebce885 25e7de7f 00d6c2d3 80000000 00000014 afcad713 68a1f1c9 6b8696fc 77570100
      Apr 10 08:45:13 racoon: 2009-04-10 08:45:13: DEBUG: 1 times of 292 bytes message will be sent to 68.153.xx.xx[500]
      Apr 10 08:45:13 racoon: 2009-04-10 08:45:13: DEBUG: send packet to 68.153.xx.xx[500]
      Apr 10 08:45:13 racoon: 2009-04-10 08:45:13: DEBUG: send packet from 70.237.xx.xx[500]
      Apr 10 08:45:13 racoon: 2009-04-10 08:45:13: DEBUG: sockname 70.237.xx.xx[500]
      Apr 10 08:45:13 racoon: 2009-04-10 08:45:13: DEBUG: 292 bytes from 70.237.xx.xx[500] to 68.153.xx.xx[500]
      Apr 10 08:45:12 racoon: 2009-04-10 08:45:12: DEBUG: msg 1 not interesting
      Apr 10 08:45:12 last message repeated 3 times
      Apr 10 08:45:12 racoon: 2009-04-10 08:45:12: DEBUG: msg 4 not interesting
      Apr 10 08:45:11 racoon: 2009-04-10 08:45:11: DEBUG: msg 4 not interesting
      Apr 10 08:45:11 racoon: 2009-04-10 08:45:11: DEBUG: msg 4 not interesting
      Apr 10 08:45:11 racoon: 2009-04-10 08:45:11: DEBUG: msg 1 not interesting
      Apr 10 08:45:11 racoon: 2009-04-10 08:45:11: DEBUG: msg 4 not interesting
      Apr 10 08:45:11 racoon: 2009-04-10 08:45:11: DEBUG: msg 4 not interesting
      Apr 10 08:45:10 last message repeated 5 times
      Apr 10 08:45:10 racoon: 2009-04-10 08:45:10: DEBUG: msg 4 not interesting
      Apr 10 08:45:09 last message repeated 7 times
      Apr 10 08:45:09 racoon: 2009-04-10 08:45:09: DEBUG: msg 4 not interesting
      Apr 10 08:45:08 last message repeated 7 times
      Apr 10 08:45:08 racoon: 2009-04-10 08:45:08: DEBUG: msg 4 not interesting
      Apr 10 08:45:07 last message repeated 5 times
      Apr 10 08:45:07 racoon: 2009-04-10 08:45:07: DEBUG: msg 4 not interesting
      Apr 10 08:45:06 last message repeated 7 times
      Apr 10 08:45:06 racoon: 2009-04-10 08:45:06: DEBUG: msg 4 not interesting
      Apr 10 08:45:05 last message repeated 5 times
      Apr 10 08:45:05 racoon: 2009-04-10 08:45:05: DEBUG: msg 4 not interesting
      Apr 10 08:45:04 last message repeated 3 times
      Apr 10 08:45:04 racoon: 2009-04-10 08:45:04: DEBUG: msg 4 not interesting
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: msg 1 not interesting
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: resend phase1 packet 2bfca020805582a7:0000000000000000
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: 2bfca020 805582a7 00000000 00000000 01100400 00000000 00000124 04000038 00000001 00000001 0000002c 01010001 00000024 01010000 800b0001 800c7080 80010003 800e0080 80030001 80020002 80040002 0a000084 9a214db3 3856347c 2218c21d 4d668751 40c20cc1 a893e288 9e3b7931 dd94aec9 bebfe57b 8aeb81d5 ca1ebb96 6e0b22bb 9f626971 d42a423b 5423adfd a58da6e0 50b9aadb 692a3cec c67c36ec 018a810b 42dffc3f 09f1152d e1c89347 cd4a8b13 9530ffca 2cd407f6 28fc315b 595fe897 34e55295 9789df54 3cb0f089 f21bed8c 05000014 cecee9a3 e1970079 f66fccd2 70b3398a 0d00000c 011101f4 46ed9fbd 0d000018 4048b7d5 6ebce885 25e7de7f 00d6c2d3 80000000 00000014 afcad713 68a1f1c9 6b8696fc 77570100
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: 1 times of 292 bytes message will be sent to 68.153.xx.xx[500]
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: send packet to 68.153.xx.xx[500]
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: send packet from 70.237.xx.xx[500]
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: sockname 70.237.xx.xx[500]
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: 292 bytes from 70.237.xx.xx[500] to 68.153.xx.xx[500]
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: add payload of len 16, next type 0
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: add payload of len 20, next type 13
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: add payload of len 8, next type 13
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: add payload of len 16, next type 5
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: add payload of len 128, next type 10
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: add payload of len 52, next type 4
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: authmethod is pre-shared key
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: 9a214db3 3856347c 2218c21d 4d668751 40c20cc1 a893e288 9e3b7931 dd94aec9 bebfe57b 8aeb81d5 ca1ebb96 6e0b22bb 9f626971 d42a423b 5423adfd a58da6e0 50b9aadb 692a3cec c67c36ec 018a810b 42dffc3f 09f1152d e1c89347 cd4a8b13 9530ffca 2cd407f6 28fc315b 595fe897 34e55295 9789df54 3cb0f089 f21bed8c
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: compute DH's public.
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: 41b3e9f6 18d7a699 0cf6fe1e f2c3bfce 31f75314 74c4dc56 6a6edf55 51bfa0a6 bea2c025 3d2992b8 f54dd163 4f0b1815 da0cf16b b58d1ad0 f9dfc99a c64a2fe0 f4f97e72 9d7c4ef3 31d03cd7 bd58c971 5e5da1b7 5ac2cf5a bd6dba58 1627b567 b243303c c55152fb f0d174da 6b162362 5c9c5a5c 6e942265 123be9d2 6601ebd3
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: compute DH's private.
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: use ID type of IPv4_address
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: new cookie: 2bfca020805582a7
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: INFO: begin Aggressive mode.
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: INFO: initiate new phase 1 negotiation: 70.237.xx.xx[500]<=>68.153.xx.xx[500]
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: ===
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: INFO: IPsec-SA request for 68.153.xx.xx queued due to no phase1 found.
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: configuration found for 68.153.xx.xx.
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: in post_acquire
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: (trns_id=BLOWFISH encklen=128 authtype=hmac-sha)
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: (proto_id=ESP spisize=4 spi=00000000 spi_p=00000000 encmode=Tunnel reqid=16404:16403)
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: selected sainfo: loc='192.168.1.0/24', rmt='10.1.0.0/16', peer='ANY', id=0
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: cmpid source: '10.1.0.0/16'
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: cmpid target: '10.1.0.0/16'
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: check and compare ids : values matched (IPv4_subnet)
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: cmpid source: '192.168.1.0/24'
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: cmpid target: '192.168.1.0/24'
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: check and compare ids : values matched (IPv4_subnet)
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: evaluating sainfo: loc='192.168.1.0/24', rmt='10.1.0.0/16', peer='ANY', id=0
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: getsainfo pass #2
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: getsainfo params: loc='192.168.1.0/24', rmt='10.1.0.0/16', peer='NULL', id=0
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: configuration found for 68.153.xx.xx.
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: new acquire 192.168.1.0/24[0] 10.1.0.0/16[0] proto=any dir=out
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: suitable inbound SP found: 10.1.0.0/16[0] 192.168.1.0/24[0] proto=any dir=in.
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: db :0x2853d408: 10.1.0.0/16[0] 192.168.1.0/24[0] proto=any dir=in
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: sub:0xbfbfe674: 10.1.0.0/16[0] 192.168.1.0/24[0] proto=any dir=in
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: db :0x2853d2d8: 192.168.1.0/24[0] 10.1.0.0/16[0] proto=any dir=out
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: sub:0xbfbfe674: 10.1.0.0/16[0] 192.168.1.0/24[0] proto=any dir=in
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: db :0x2853d1a8: 192.168.1.91/32[0] 192.168.1.0/24[0] proto=any dir=out
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: sub:0xbfbfe674: 10.1.0.0/16[0] 192.168.1.0/24[0] proto=any dir=in
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: db :0x2853d078: 192.168.1.0/24[0] 192.168.1.91/32[0] proto=any dir=in
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: sub:0xbfbfe674: 10.1.0.0/16[0] 192.168.1.0/24[0] proto=any dir=in
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: suitable outbound SP found: 192.168.1.0/24[0] 10.1.0.0/16[0] proto=any dir=out.
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: get pfkey ACQUIRE message
      Apr 10 08:45:03 racoon: 2009-04-10 08:45:03: DEBUG: pk_recv: retry[0] recv()
      Apr 10 08:44:59 racoon: 2009-04-10 08:44:59: DEBUG: msg 1 not interesting
      Apr 10 08:44:20 racoon: 2009-04-10 08:44:20: DEBUG: msg 1 not interesting
      Apr 10 08:44:13 racoon: 2009-04-10 08:44:13: DEBUG: msg 1 not interesting
      Apr 10 08:44:12 racoon: 2009-04-10 08:44:12: DEBUG: msg 1 not interesting
      Apr 10 08:44:11 racoon: 2009-04-10 08:44:11: DEBUG: msg 1 not interesting
      Apr 10 08:44:10 racoon: 2009-04-10 08:44:10: DEBUG: msg 1 not interesting
      Apr 10 08:44:09 racoon: 2009-04-10 08:44:09: DEBUG: msg 1 not interesting
      Apr 10 08:43:47 racoon: 2009-04-10 08:43:47: DEBUG: msg 1 not interesting
      Apr 10 08:43:40 racoon: 2009-04-10 08:43:40: DEBUG: msg 1 not interesting
      Apr 10 08:43:33 racoon: 2009-04-10 08:43:33: DEBUG: msg 1 not interesting
      Apr 10 08:43:25 racoon: 2009-04-10 08:43:25: DEBUG: msg 1 not interesting
      Apr 10 08:43:22 racoon: 2009-04-10 08:43:22: DEBUG: msg 1 not interesting
      Apr 10 08:43:20 racoon: 2009-04-10 08:43:20: DEBUG: msg 1 not interesting
      Apr 10 08:43:18 racoon: 2009-04-10 08:43:18: DEBUG: msg 1 not interesting
      Apr 10 08:43:16 racoon: 2009-04-10 08:43:16: DEBUG: msg 1 not interesting
      Apr 10 08:43:14 racoon: 2009-04-10 08:43:14: DEBUG: msg 1 not interesting
      Apr 10 08:43:13 racoon: 2009-04-10 08:43:13: DEBUG: msg 1 not interesting
      Apr 10 08:43:11 racoon: 2009-04-10 08:43:11: DEBUG: msg 1 not interesting
      Apr 10 08:43:10 racoon: 2009-04-10 08:43:10: DEBUG: msg 1 not interesting
      Apr 10 08:43:09 racoon: 2009-04-10 08:43:09: DEBUG: msg 1 not interesting
      Apr 10 08:43:08 racoon: 2009-04-10 08:43:08: DEBUG: msg 1 not interesting
      Apr 10 08:43:07 racoon: 2009-04-10 08:43:07: DEBUG: msg 1 not interesting
      Apr 10 08:43:00 racoon: 2009-04-10 08:43:00: ERROR: phase1 negotiation failed due to time up. 9f5de51f8f05a6a8:0000000000000000

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