Hello misc,
My openBSD Gateway seems to have a problem with ISAKMP Nat Traversal to a
remote Sonicwall. The ISAKMP Exchange fails in pase 2.
The remote Sonicwall is behind a NAT device.
Before I blame one side or the other for misbehavior, I would like you to take
a look at the traces I will provide here and help me with the proper
interpretation.
The setup is simple:
openBSD has direct access to the internet with IP address 217.110.66.79
SonicWall is behind IP address 217.86.184.8
My /etc/ipsec.conf is
ike active esp tunnel from 129.143.250.128/25 to 192.168.199.0/24 peer
217.86.184.8 main auth hmac-md5 enc aes-128 group modp1024 quick auth
hmac-md5 enc aes-128 group modp1024 psk 'xyz'
What I think happens here is that openBSD recognizes that a NAT device is
between Sonicwall and itself. And switches to NAT encapsulation. And Sonciwall
only proposes NAT-T with RFC3947. ( Also see the NAT related messages in the
debug output below )
But in the phase 2 transform proposal openBSD requests 'TUNNEL' encapsulation
mode instead of 'UDP-encapsulated-TUNNEL' as required by RFC-3947. ( See bytes
78-7b in the hexdump of the first quick mode packet, it reads 80040001 instead
of 80040003 ).
Here is tcpdump output from /var/run/isakmpd.pcap ( I have removed the hexdump
part from all but the last packet for brevity )
10:36:51.578451 0.0.0.0.500 > 217.86.184.8.500: [udp sum ok] isakmp v1.0
exchange ID_PROT
cookie: daf885a1cd119c2d->0000000000000000 msgid: 00000000 len: 184
payload: SA len: 56 DOI: 1(IPSEC) situation: IDENTITY_ONLY
payload: PROPOSAL len: 44 proposal: 1 proto: ISAKMP spisz: 0
xforms: 1
payload: TRANSFORM len: 36
transform: 0 ID: ISAKMP
attribute ENCRYPTION_ALGORITHM = AES_CBC
attribute HASH_ALGORITHM = MD5
attribute AUTHENTICATION_METHOD = PRE_SHARED
attribute GROUP_DESCRIPTION = MODP_1024
attribute LIFE_TYPE = SECONDS
attribute LIFE_DURATION = 3600
attribute KEY_LENGTH = 128
payload: VENDOR len: 20
payload: VENDOR len: 20 (supports v2 NAT-T,
draft-ietf-ipsec-nat-t-ike-02)
payload: VENDOR len: 20 (supports v3 NAT-T,
draft-ietf-ipsec-nat-t-ike-03)
payload: VENDOR len: 20 (supports NAT-T, RFC 3947)
payload: VENDOR len: 20 (supports DPD v1.0) [ttl 0] (id 1, len 212)
10:36:51.651586 217.86.184.8.500 > 217.110.66.79.500: [udp sum ok] isakmp v1.0
exchange ID_PROT
cookie: daf885a1cd119c2d->3264ac29e5082e4c msgid: 00000000 len: 116
payload: SA len: 56 DOI: 1(IPSEC) situation: IDENTITY_ONLY
payload: PROPOSAL len: 44 proposal: 1 proto: ISAKMP spisz: 0
xforms: 1
payload: TRANSFORM len: 36
transform: 1 ID: ISAKMP
attribute ENCRYPTION_ALGORITHM = AES_CBC
attribute KEY_LENGTH = 128
attribute HASH_ALGORITHM = MD5
attribute GROUP_DESCRIPTION = MODP_1024
attribute AUTHENTICATION_METHOD = PRE_SHARED
attribute LIFE_TYPE = SECONDS
attribute LIFE_DURATION = 3600
payload: VENDOR len: 12
payload: VENDOR len: 20 (supports NAT-T, RFC 3947) [ttl 0] (id 1, len
144)
10:36:51.745502 217.110.66.79.500 > 217.86.184.8.500: [udp sum ok] isakmp v1.0
exchange ID_PROT
cookie: daf885a1cd119c2d->3264ac29e5082e4c msgid: 00000000 len: 220
payload: KEY_EXCH len: 132
payload: NONCE len: 20
payload: NAT-D len: 20
payload: NAT-D len: 20 [ttl 0] (id 1, len 248)
10:36:51.833947 217.86.184.8.500 > 217.110.66.79.500: [udp sum ok] isakmp v1.0
exchange ID_PROT
cookie: daf885a1cd119c2d->3264ac29e5082e4c msgid: 00000000 len: 268
payload: KEY_EXCH len: 132
payload: NAT-D len: 20
payload: NAT-D len: 20
payload: NONCE len: 24
payload: VENDOR len: 12
payload: VENDOR len: 12 (supports draft-ietf-ipsra-isakmp-xauth-06.txt)
payload: VENDOR len: 20 (supports DPD v1.0) [ttl 0] (id 1, len 296)
10:36:51.927437 217.110.66.79.4500 > 217.86.184.8.4500: [bad udp cksum aaf3!]
udpencap: isakmp v1.0 exchange ID_PROT
cookie: daf885a1cd119c2d->3264ac29e5082e4c msgid: 00000000 len: 88
payload: ID len: 12 type: IPV4_ADDR = 217.110.66.79
payload: HASH len: 20
payload: NOTIFICATION len: 28
notification: INITIAL CONTACT (daf885a1cd119c2d->3264ac29e5082e4c)
[ttl 0] (id 1, len 120)
10:36:51.998066 217.86.184.8.4500 > 217.110.66.79.4500: [bad udp cksum 1c00!]
udpencap: isakmp v1.0 exchange ID_PROT
cookie: daf885a1cd119c2d->3264ac29e5082e4c msgid: 00000000 len: 60
payload: ID len: 12 type: IPV4_ADDR = 192.168.50.253
payload: HASH len: 20 [ttl 0] (id 1, len 92)
10:36:52.092038 217.110.66.79.4500 > 217.86.184.8.4500: [udp sum ok] udpencap:
isakmp v1.0 exchange QUICK_MODE
cookie: daf885a1cd119c2d->3264ac29e5082e4c msgid: 15222280 len: 288
payload: HASH len: 20
payload: SA len: 56 DOI: 1(IPSEC) situation: IDENTITY_ONLY
payload: PROPOSAL len: 44 proposal: 1 proto: IPSEC_ESP spisz: 4
xforms: 1 SPI: 0x95d528a5
payload: TRANSFORM len: 32
transform: 1 ID: AES
attribute LIFE_TYPE = SECONDS
attribute LIFE_DURATION = 1200
attribute ENCAPSULATION_MODE = TUNNEL
attribute AUTHENTICATION_ALGORITHM = HMAC_MD5
attribute GROUP_DESCRIPTION = 2
attribute KEY_LENGTH = 128
payload: NONCE len: 20
payload: KEY_EXCH len: 132
payload: ID len: 16 type: IPV4_ADDR_SUBNET =
129.143.250.128/255.255.255.128
payload: ID len: 16 type: IPV4_ADDR_SUBNET =
192.168.199.0/255.255.255.0 [ttl 0] (id 1, len 320)
0000: 4500 0140 0001 0000 0011 0c90 d96e 424f [email protected]
0010: d956 b808 1194 1194 012c 285b 0000 0000 .V.......,([....
0020: daf8 85a1 cd11 9c2d 3264 ac29 e508 2e4c .......-2d.)...L
0030: 0810 2000 1522 2280 0000 0120 0100 0014 .. .."".... ....
0040: 1db1 7091 0a7b b345 84d2 11a9 1e43 b16f ..p..{.E.....C.o
0050: 0a00 0038 0000 0001 0000 0001 0000 002c ...8...........,
0060: 0103 0401 95d5 28a5 0000 0020 010c 0000 ......(.... ....
0070: 8001 0001 8002 04b0 8004 0001 8005 0001 ................
0080: 8003 0002 8006 0080 0400 0014 168c 87e4 ................
0090: d36c 1705 2104 c48d 9afb 55a6 0500 0084 .l..!.....U.....
00a0: 077a f2a2 1433 6161 54cd 51e4 7702 a0bd .z...3aaT.Q.w...
00b0: f392 1d96 d7fe 4183 5caf 53ac c8d5 e6c7 ......A.\.S.....
00c0: 92c7 9af0 697d fbd0 c0da 14e0 11fc c7a9 ....i}..........
00d0: 4578 37f8 f25e 8b24 f869 f24d bea9 5daa Ex7..^.$.i.M..].
00e0: 5417 4604 377a 8a42 18ab d528 238e 3115 T.F.7z.B...(#.1.
00f0: 0120 f7b1 ca65 7260 d108 28da d4af 69ed . ...er`..(...i.
0100: cc46 8258 fcf5 22ee e517 8a47 9851 eb49 .F.X.."....G.Q.I
0110: 26b7 20bd 4657 2838 ad01 9a13 a5d1 dab8 &. .FW(8........
0120: 0500 0010 0400 0000 818f fa80 ffff ff80 ................
0130: 0000 0010 0400 0000 c0a8 c700 ffff ff00 ................
And here is the debug output from isakmpd -D 6=99 -D7=99 -D8=99 -D2=50 -K -L
Sep 9 10:36:35 q-dsl isakmpd[9931]: isakmpd: starting
Sep 9 10:36:36 q-dsl isakmpd[8122]: nat_t_setup_hashes:
MD5("draft-ietf-ipsec-nat-t-ike-02 ") (16 bytes)
Sep 9 10:36:36 q-dsl isakmpd[8122]: nat_t_setup_hashes:
Sep 9 10:36:36 q-dsl isakmpd[8122]: 90cb8091 3ebb696e 086381b5 ec427b1f
Sep 9 10:36:36 q-dsl isakmpd[8122]: nat_t_setup_hashes:
MD5("draft-ietf-ipsec-nat-t-ike-03") (16 bytes)
Sep 9 10:36:36 q-dsl isakmpd[8122]: nat_t_setup_hashes:
Sep 9 10:36:36 q-dsl isakmpd[8122]: 7d9419a6 5310ca6f 2c179d92 15529d56
Sep 9 10:36:36 q-dsl isakmpd[8122]: nat_t_setup_hashes: MD5("RFC 3947") (16
bytes)
Sep 9 10:36:36 q-dsl isakmpd[8122]: nat_t_setup_hashes:
Sep 9 10:36:36 q-dsl isakmpd[8122]: 4a131c81 07035845 5c5728f2 0e95452f
Sep 9 10:36:36 q-dsl isakmpd[8122]: setup_vendor_hashes: MD5("OpenBSD-5.2")
(16 bytes)
Sep 9 10:36:36 q-dsl isakmpd[8122]: setup_vendor_hashes:
Sep 9 10:36:36 q-dsl isakmpd[8122]: b8f26eaa 4cbf1b9a 150a3f12 dd64d183
Sep 9 10:36:36 q-dsl isakmpd[8122]: log_packet_init: starting IKE packet
capture to file "/var/run/isakmpd.pcap"
Sep 9 10:36:41 q-dsl isakmpd[8122]: sa_find: no SA matched query
Sep 9 10:36:51 q-dsl last message repeated 2 times
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_establish_p1: 0x7e39c700
peer-217.86.184.8 phase1-peer-217.86.184.8 policy initiator phase 1 doi 1
exchange 2 step 0
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_establish_p1: icookie
daf885a1cd119c2d rcookie 0000000000000000
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_establish_p1: msgid 00000000
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_reference: SA 0x7e39ca00 now has 1
references
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_enter: SA 0x7e39ca00 added to SA list
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_reference: SA 0x7e39ca00 now has 2
references
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_create: sa 0x7e39ca00 phase 1 added to
exchange 0x7e39c700 (peer-217.86.184.8)
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_reference: SA 0x7e39ca00 now has 3
references
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_validate: checking for required SA
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_run: exchange 0x7e39c700 finished
step 0, advancing...
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_lookup_by_name: peer-217.86.184.8
== peer-217.86.184.8 && 1 == 1?
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_remove: SA 0x7e39ca00 removed from SA
list
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_release: SA 0x7e39ca00 had 3 references
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_reference: SA 0x7e39ca00 now has 3
references
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_enter: SA 0x7e39ca00 added to SA list
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_free: freeing 0x7e39f000
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_release: SA 0x7e39ca00 had 3 references
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_parse_payloads: offset 28 payload
SA
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_parse_payloads: offset 84 payload
VENDOR
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_parse_payloads: offset 96 payload
VENDOR
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_reference: SA 0x7e39ca00 now has 3
references
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_parse_payloads: offset 40 payload
PROPOSAL
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_parse_payloads: offset 48 payload
TRANSFORM
Sep 9 10:36:51 q-dsl isakmpd[8122]: Transform 1's attributes
Sep 9 10:36:51 q-dsl isakmpd[8122]: Attribute ENCRYPTION_ALGORITHM value 7
Sep 9 10:36:51 q-dsl isakmpd[8122]: Attribute KEY_LENGTH value 128
Sep 9 10:36:51 q-dsl isakmpd[8122]: Attribute HASH_ALGORITHM value 1
Sep 9 10:36:51 q-dsl isakmpd[8122]: Attribute GROUP_DESCRIPTION value 2
Sep 9 10:36:51 q-dsl isakmpd[8122]: Attribute AUTHENTICATION_METHOD value 1
Sep 9 10:36:51 q-dsl isakmpd[8122]: Attribute LIFE_TYPE value 1
Sep 9 10:36:51 q-dsl isakmpd[8122]: Attribute LIFE_DURATION value 3600
Sep 9 10:36:51 q-dsl isakmpd[8122]: check_vendor_openbsd: bad size 8 != 16
Sep 9 10:36:51 q-dsl isakmpd[8122]: dpd_check_vendor_payload: bad size 8 != 16
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_validate_vendor: vendor ID seen
Sep 9 10:36:51 q-dsl isakmpd[8122]: nat_t_check_vendor_payload: NAT-T capable
peer detected
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_validate: checking for required SA
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_negotiate_sa: transform 1 proto 1
proposal 1 ok
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_validate_xf_attrs: phase 1 mode 0 type
1 len 2
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_validate_xf_attrs: phase 1 mode 0 type
14 len 2
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_validate_xf_attrs: phase 1 mode 0 type
2 len 2
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_validate_xf_attrs: phase 1 mode 0 type
4 len 2
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_validate_xf_attrs: phase 1 mode 0 type
3 len 2
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_validate_xf_attrs: phase 1 mode 0 type
11 len 2
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_validate_xf_attrs: phase 1 mode 0 type
12 len 2
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_validate_xf_attrs: phase 1 mode 1 type
1 len 2
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_validate_xf_attrs: phase 1 mode 1 type
2 len 2
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_validate_xf_attrs: phase 1 mode 1 type
3 len 2
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_validate_xf_attrs: phase 1 mode 1 type
4 len 2
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_validate_xf_attrs: phase 1 mode 1 type
11 len 2
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_validate_xf_attrs: phase 1 mode 1 type
12 len 2
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_validate_xf_attrs: phase 1 mode 1 type
14 len 2
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_validate_proto_xf: attr_map xf
0x869c5800 proto 0x85f087c0 pa 0x82e2bb30 found 1
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_validate_proto_xf: req_attr xf
0x869c5800 proto 0x85f087c0 pa 0x82e2bb30 found 1
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_add_transform: proto 0x85f087c0 no 1
proto 1 chosen 0x869c5800 sa 0x7e39ca00 id 1
Sep 9 10:36:51 q-dsl isakmpd[8122]: ike_phase_1_validate_prop: success
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_negotiate_sa: proposal 1 succeeded
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_handle_leftover_payloads:
unexpected payload VENDOR
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_run: exchange 0x7e39c700 finished
step 1, advancing...
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_reference: SA 0x7e39ca00 now has 4
references
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_nonce: NONCE_i:
Sep 9 10:36:51 q-dsl isakmpd[8122]: 860ed9d8 039cf270 c5dc0ff1 26d1086d
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_validate: checking for required
KEY_EXCH
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_validate: checking for required
NONCE
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_run: exchange 0x7e39c700 finished
step 2, advancing...
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_reference: SA 0x7e39ca00 now has 5
references
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_free: freeing 0x7e39f700
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_release: SA 0x7e39ca00 had 5 references
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_parse_payloads: offset 28 payload
KEY_EXCH
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_parse_payloads: offset 160 payload
NAT_D
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_parse_payloads: offset 180 payload
NAT_D
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_parse_payloads: offset 200 payload
NONCE
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_parse_payloads: offset 224 payload
VENDOR
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_parse_payloads: offset 236 payload
VENDOR
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_parse_payloads: offset 248 payload
VENDOR
Sep 9 10:36:51 q-dsl isakmpd[8122]: check_vendor_openbsd: bad size 8 != 16
Sep 9 10:36:51 q-dsl isakmpd[8122]: dpd_check_vendor_payload: bad size 8 != 16
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_validate_vendor: vendor ID seen
Sep 9 10:36:51 q-dsl isakmpd[8122]: check_vendor_openbsd: bad size 8 != 16
Sep 9 10:36:51 q-dsl isakmpd[8122]: dpd_check_vendor_payload: bad size 8 != 16
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_validate_vendor: vendor ID seen
Sep 9 10:36:51 q-dsl isakmpd[8122]: dpd_check_vendor_payload: DPD capable peer
detected
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_validate: checking for required
KEY_EXCH
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_validate: checking for required
NONCE
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_nonce: NONCE_r:
Sep 9 10:36:51 q-dsl isakmpd[8122]: 88ee8a64 40c442d3 fc9ca727 99c569df
522786a6
Sep 9 10:36:51 q-dsl isakmpd[8122]: nat_t_exchange_check_nat_d: NAT detected,
we're behind it
Sep 9 10:36:51 q-dsl isakmpd[8122]: ike_phase_1_post_exchange_KE_NONCE: g^xy:
Sep 9 10:36:51 q-dsl isakmpd[8122]: 136de78f b8acda57 853e5fdd 59429df4
168791f7 aba30f64 fc9ba6a9 14f3a9dc
Sep 9 10:36:51 q-dsl isakmpd[8122]: cf1c899e fce4fca5 101ddc0b 32500505
de025e3f 6c9af45d 199c7a28 cbaeb116
Sep 9 10:36:51 q-dsl isakmpd[8122]: d0ba0a99 5374372c 8974a4d2 5be7c2be
d2a64c4c 9bf8a765 40196f4a 902629e3
Sep 9 10:36:51 q-dsl isakmpd[8122]: 947e4b7f f25ce3c7 8c0c7512 a92bdb0a
07bf32cd 8ef1a56c 87ae6226 917f4f0d
Sep 9 10:36:51 q-dsl isakmpd[8122]: ike_phase_1_post_exchange_KE_NONCE: SKEYID:
Sep 9 10:36:51 q-dsl isakmpd[8122]: c5053a12 4f706994 49673142 0d71cd17
Sep 9 10:36:51 q-dsl isakmpd[8122]: ike_phase_1_post_exchange_KE_NONCE:
SKEYID_d:
Sep 9 10:36:51 q-dsl isakmpd[8122]: 8300ac8c 34c3e8e2 c78dbb8e a5539481
Sep 9 10:36:51 q-dsl isakmpd[8122]: ike_phase_1_post_exchange_KE_NONCE:
SKEYID_a:
Sep 9 10:36:51 q-dsl isakmpd[8122]: 4b9395f3 1719c087 4812fb3d 585ade9c
Sep 9 10:36:51 q-dsl isakmpd[8122]: ike_phase_1_post_exchange_KE_NONCE:
SKEYID_e:
Sep 9 10:36:51 q-dsl isakmpd[8122]: fd20805e 7dad1fa6 b158a3cf 75d14bc5
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_handle_leftover_payloads:
unexpected payload VENDOR
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_handle_leftover_payloads:
unexpected payload VENDOR
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_free: freeing 0x7e39f580
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_release: SA 0x7e39ca00 had 4 references
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_run: exchange 0x7e39c700 finished
step 3, advancing...
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_reference: SA 0x7e39ca00 now has 4
references
Sep 9 10:36:51 q-dsl isakmpd[8122]: ike_phase_1_send_ID: IPV4_ADDR:
Sep 9 10:36:51 q-dsl isakmpd[8122]: d96e424f
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_validate: checking for required ID
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_validate: checking for required
AUTH
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_run: exchange 0x7e39c700 finished
step 4, advancing...
Sep 9 10:36:51 q-dsl isakmpd[8122]: virtual_send_message: enabling NAT-T
encapsulation for this exchange
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_reference: SA 0x7e39ca00 now has 5
references
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_free: freeing 0x7e39f680
Sep 9 10:36:51 q-dsl isakmpd[8122]: sa_release: SA 0x7e39ca00 had 5 references
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_parse_payloads: offset 28 payload
ID
Sep 9 10:36:51 q-dsl isakmpd[8122]: message_parse_payloads: offset 40 payload
HASH
Sep 9 10:36:51 q-dsl isakmpd[8122]: ipsec_validate_id_information: proto 0
port 0 type 1
Sep 9 10:36:51 q-dsl isakmpd[8122]: ipsec_validate_id_information: IPv4:
Sep 9 10:36:51 q-dsl isakmpd[8122]: c0a832fd
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_validate: checking for required ID
Sep 9 10:36:51 q-dsl isakmpd[8122]: exchange_validate: checking for required
AUTH
Sep 9 10:36:51 q-dsl isakmpd[8122]: ike_phase_1_recv_ID: IPV4_ADDR:
Sep 9 10:36:51 q-dsl isakmpd[8122]: c0a832fd
Sep 9 10:36:51 q-dsl isakmpd[8122]: ike_phase_1_recv_AUTH: computed HASH_R:
Sep 9 10:36:52 q-dsl isakmpd[8122]: 3deb0d42 7f807f4e 538e1cfd 96e78cce
Sep 9 10:36:52 q-dsl isakmpd[8122]: message_free: freeing 0x7e39f400
Sep 9 10:36:52 q-dsl isakmpd[8122]: sa_release: SA 0x7e39ca00 had 4 references
Sep 9 10:36:52 q-dsl isakmpd[8122]: exchange_finalize: 0x7e39c700
peer-217.86.184.8 phase1-peer-217.86.184.8 policy initiator phase 1 doi 1
exchange 2 step 5
Sep 9 10:36:52 q-dsl isakmpd[8122]: exchange_finalize: icookie
daf885a1cd119c2d rcookie 3264ac29e5082e4c
Sep 9 10:36:52 q-dsl isakmpd[8122]: exchange_finalize: msgid 00000000
Sep 9 10:36:52 q-dsl isakmpd[8122]: sa_find: no SA matched query
Sep 9 10:36:52 q-dsl isakmpd[8122]: exchange_finalize: phase 1 done: initiator
id 217.110.66.79, responder id 192.168.50.253, src: 217.110.66.79 dst:
217.86.184.8
Sep 9 10:36:52 q-dsl isakmpd[8122]: sa_reference: SA 0x7e39ca00 now has 4
references
Sep 9 10:36:52 q-dsl isakmpd[8122]: sa_reference: SA 0x7e39ca00 now has 5
references
Sep 9 10:36:52 q-dsl isakmpd[8122]: exchange_establish_finalize: finalizing
exchange 0x7e39c700 with arg 0x85f08f00
(from-129.143.250.128/25-to-192.168.199.0/24) & fail = 0
Sep 9 10:36:52 q-dsl isakmpd[8122]: exchange_lookup_by_name:
from-129.143.250.128/25-to-192.168.199.0/24 == peer-217.86.184.8 && 2 == 1?
Sep 9 10:36:52 q-dsl isakmpd[8122]: sa_find: return SA 0x7e39ca00
Sep 9 10:36:52 q-dsl isakmpd[8122]: exchange_establish_p2: 0x7e39c600
from-129.143.250.128/25-to-192.168.199.0/24
phase2-from-129.143.250.128/25-to-192.168.199.0/24 policy initiator phase 2 doi
1 exchange 32 step 0
Sep 9 10:36:52 q-dsl isakmpd[8122]: exchange_establish_p2: icookie
daf885a1cd119c2d rcookie 3264ac29e5082e4c
Sep 9 10:36:52 q-dsl isakmpd[8122]: exchange_establish_p2: msgid 15222280
sa_list
Sep 9 10:36:52 q-dsl isakmpd[8122]: sa_reference: SA 0x7e39c800 now has 1
references
Sep 9 10:36:52 q-dsl isakmpd[8122]: sa_enter: SA 0x7e39c800 added to SA list
Sep 9 10:36:52 q-dsl isakmpd[8122]: sa_reference: SA 0x7e39c800 now has 2
references
Sep 9 10:36:52 q-dsl isakmpd[8122]: sa_create: sa 0x7e39c800 phase 2 added to
exchange 0x7e39c600 (from-129.143.250.128/25-to-192.168.199.0/24)
Sep 9 10:36:52 q-dsl isakmpd[8122]: sa_reference: SA 0x7e39ca00 now has 6
references
Sep 9 10:36:52 q-dsl isakmpd[8122]: exchange_nonce: NONCE_i:
Sep 9 10:36:52 q-dsl isakmpd[8122]: 168c87e4 d36c1705 2104c48d 9afb55a6
Sep 9 10:36:52 q-dsl isakmpd[8122]: initiator_send_HASH_SA_NONCE: IDic:
Sep 9 10:36:52 q-dsl isakmpd[8122]: 00000000 04000000 818ffa80 ffffff80
Sep 9 10:36:52 q-dsl isakmpd[8122]: initiator_send_HASH_SA_NONCE: IDrc:
Sep 9 10:36:52 q-dsl isakmpd[8122]: 01000000 04000000 c0a8c700 ffffff00
Sep 9 10:36:52 q-dsl isakmpd[8122]: exchange_validate: checking for required
HASH
Sep 9 10:36:52 q-dsl isakmpd[8122]: exchange_validate: checking for required SA
Sep 9 10:36:52 q-dsl isakmpd[8122]: exchange_validate: checking for required
NONCE
Sep 9 10:36:52 q-dsl isakmpd[8122]: exchange_run: exchange 0x7e39c600 finished
step 0, advancing...
Sep 9 10:36:52 q-dsl isakmpd[8122]: sa_find: no SA matched query
Sep 9 10:36:52 q-dsl isakmpd[8122]: sa_release: SA 0x7e39ca00 had 6 references
Sep 9 10:36:52 q-dsl isakmpd[8122]: exchange_free_aux: freeing exchange
0x7e39c700
Sep 9 10:36:52 q-dsl isakmpd[8122]: message_free: freeing 0x83340b80
Sep 9 10:36:52 q-dsl isakmpd[8122]: sa_release: SA 0x7e39ca00 had 5 references
Sep 9 10:36:52 q-dsl isakmpd[8122]: virtual_send_message: enabling NAT-T
encapsulation for this exchange
Sep 9 10:36:59 q-dsl isakmpd[8122]: sa_reference: SA 0x7e39ca00 now has 5
references
Sep 9 10:36:59 q-dsl isakmpd[8122]: message_recv: phase 1 message after ISAKMP
SA is ready
Sep 9 10:36:59 q-dsl isakmpd[8122]: message_free: freeing 0x7e39fb00
Sep 9 10:36:59 q-dsl isakmpd[8122]: sa_release: SA 0x7e39ca00 had 5 references
Sep 9 10:37:08 q-dsl isakmpd[8122]: sa_reference: SA 0x7e39ca00 now has 5
references
Sep 9 10:37:08 q-dsl isakmpd[8122]: message_recv: phase 1 message after ISAKMP
SA is ready
Sep 9 10:37:08 q-dsl isakmpd[8122]: message_free: freeing 0x7e39f100
Sep 9 10:37:08 q-dsl isakmpd[8122]: sa_release: SA 0x7e39ca00 had 5 references
Sep 9 10:37:19 q-dsl isakmpd[8122]: transport_send_messages: giving up on
exchange from-129.143.250.128/25-to-192.168.199.0/24, no response from peer
217.86.184.8:4500
Sep 9 10:37:19 q-dsl isakmpd[8122]: message_free: freeing 0x7e39f680
Sep 9 10:37:19 q-dsl isakmpd[8122]: sa_release: SA 0x7e39ca00 had 4 references
Sep 9 10:37:19 q-dsl isakmpd[8122]: sa_reference: SA 0x7e39ca00 now has 4
references
Sep 9 10:37:19 q-dsl isakmpd[8122]: message_recv: phase 1 message after ISAKMP
SA is ready
Sep 9 10:37:19 q-dsl isakmpd[8122]: message_free: freeing 0x7e39f900
Sep 9 10:37:19 q-dsl isakmpd[8122]: sa_release: SA 0x7e39ca00 had 4 references
Sep 9 10:37:51 q-dsl isakmpd[8122]: sa_find: no SA matched query
Sep 9 10:37:51 q-dsl isakmpd[8122]: exchange_lookup_by_name:
from-129.143.250.128/25-to-192.168.199.0/24 ==
from-129.143.250.128/25-to-192.168.199.0/24 && 2 == 2?
Sep 9 10:37:51 q-dsl isakmpd[8122]: exchange_establish:
from-129.143.250.128/25-to-192.168.199.0/24 exchange already exists as
0x7e39c600
And here is dmesg.boot:
OpenBSD 5.4 (GENERIC) #30: Sat Jul 20 22:58:41 MDT 2013
[email protected]:/usr/src/sys/arch/i386/compile/GENERIC
cpu0: Geode(TM) Integrated Processor by AMD PCS ("AuthenticAMD" 586-class) 500
MHz
cpu0: FPU,DE,PSE,TSC,MSR,CX8,SEP,PGE,CMOV,CFLUSH,MMX,MMXX,3DNOW2,3DNOW
real mem = 536408064 (511MB)
avail mem = 516194304 (492MB)
mainbus0 at root
bios0 at mainbus0: AT/286+ BIOS, date 20/71/05, BIOS32 rev. 0 @ 0xfac40
pcibios0 at bios0: rev 2.0 @ 0xf0000/0x10000
pcibios0: pcibios_get_intr_routing - function not supported
pcibios0: PCI IRQ Routing information unavailable.
pcibios0: PCI bus #0 is the last bus
bios0: ROM list: 0xc8000/0xa800
cpu0 at mainbus0: (uniprocessor)
amdmsr0 at mainbus0
pci0 at mainbus0 bus 0: configuration mode 1 (bios)
0:20:0: io address conflict 0x6100/0x100
0:20:0: io address conflict 0x6200/0x200
pchb0 at pci0 dev 1 function 0 "AMD Geode LX" rev 0x31
glxsb0 at pci0 dev 1 function 2 "AMD Geode LX Crypto" rev 0x00: RNG AES
vr0 at pci0 dev 6 function 0 "VIA VT6105M RhineIII" rev 0x96: irq 11, address
00:00:24:c9:59:24
ukphy0 at vr0 phy 1: Generic IEEE 802.3u media interface, rev. 3: OUI 0x004063,
model 0x0034
vr1 at pci0 dev 7 function 0 "VIA VT6105M RhineIII" rev 0x96: irq 5, address
00:00:24:c9:59:25
ukphy1 at vr1 phy 1: Generic IEEE 802.3u media interface, rev. 3: OUI 0x004063,
model 0x0034
vr2 at pci0 dev 8 function 0 "VIA VT6105M RhineIII" rev 0x96: irq 9, address
00:00:24:c9:59:26
ukphy2 at vr2 phy 1: Generic IEEE 802.3u media interface, rev. 3: OUI 0x004063,
model 0x0034
vr3 at pci0 dev 9 function 0 "VIA VT6105M RhineIII" rev 0x96: irq 12, address
00:00:24:c9:59:27
ukphy3 at vr3 phy 1: Generic IEEE 802.3u media interface, rev. 3: OUI 0x004063,
model 0x0034
glxpcib0 at pci0 dev 20 function 0 "AMD CS5536 ISA" rev 0x03: rev 3, 32-bit
3579545Hz timer, watchdog, gpio, i2c
gpio0 at glxpcib0: 32 pins
iic0 at glxpcib0
pciide0 at pci0 dev 20 function 2 "AMD CS5536 IDE" rev 0x01: DMA, channel 0
wired to compatibility, channel 1 wired to compatibility
wd0 at pciide0 channel 0 drive 0: <SanDisk SDCFH2-004G>
wd0: 4-sector PIO, LBA, 3919MB, 8027712 sectors
wd0(pciide0:0:0): using PIO mode 4, DMA mode 2
pciide0: channel 1 ignored (disabled)
ohci0 at pci0 dev 21 function 0 "AMD CS5536 USB" rev 0x02: irq 15, version 1.0,
legacy support
ehci0 at pci0 dev 21 function 1 "AMD CS5536 USB" rev 0x02: irq 15
usb0 at ehci0: USB revision 2.0
uhub0 at usb0 "AMD EHCI root hub" rev 2.00/1.00 addr 1
isa0 at glxpcib0
isadma0 at isa0
com0 at isa0 port 0x3f8/8 irq 4: ns16550a, 16 byte fifo
com0: console
com1 at isa0 port 0x2f8/8 irq 3: ns16550a, 16 byte fifo
pckbc0 at isa0 port 0x60/5
pckbd0 at pckbc0 (kbd slot)
pckbc0: using irq 1 for kbd slot
wskbd0 at pckbd0: console keyboard
pcppi0 at isa0 port 0x61
spkr0 at pcppi0
nsclpcsio0 at isa0 port 0x2e/2: NSC PC87366 rev 10: GPIO VLM TMS
gpio1 at nsclpcsio0: 29 pins
npx0 at isa0 port 0xf0/16: reported by CPUID; using exception 16
usb1 at ohci0: USB revision 1.0
uhub1 at usb1 "AMD OHCI root hub" rev 1.00/1.00 addr 1
mtrr: K6-family MTRR support (2 registers)
vscsi0 at root
scsibus0 at vscsi0: 256 targets
softraid0 at root
scsibus1 at softraid0: 256 targets
root on wd0a (5acd6c91162ffb03.a) swap on wd0b dump on wd0b
Please also note the message in the debug output:
Sep 9 10:36:51 q-dsl isakmpd[8122]: nat_t_exchange_check_nat_d: NAT detected,
we're behind it
Which seems either wrong or at least misleading: we are directly connect to the
internet, it is the other side that is behind a NAT.
What also strikes me is that the 'Next Proposal' fields at byte offset 005c
and 0068 are zero instead of 02 (PROPOSAL) and 03 (TRANSFORM) as the figure
ant page of rfc 2408 suggests.
Please let me know how you read this matter.
Thanks
Christoph Leser
