* Re: Fw: [Bugme-new] [Bug 4138] New: ipsec with racoon in transport mode with esp and ah hangs (problem is in xfrm_state_add)
2005-01-31 10:54 ` Herbert Xu
@ 2005-01-31 15:19 ` Andreas Unterluggauer
2005-01-31 15:40 ` Andreas Unterluggauer
2005-01-31 19:40 ` David S. Miller
2 siblings, 0 replies; 11+ messages in thread
From: Andreas Unterluggauer @ 2005-01-31 15:19 UTC (permalink / raw)
To: Herbert Xu; +Cc: netdev
[-- Attachment #1: Type: text/plain, Size: 650 bytes --]
Hi Herbert,
>
> Could you get a dump of the messages that racoon has received
> and sent? That should tell us exactly what's happening.
here is the output from racoon in debug-mode and with some additional
messages (search for andi in the racoon.log file). I hope I put the messages
in the right functions, so that you can see what is happening.
for me it looks like racoon doesn't get the SADB_ACQUIRE message.
if you could tell me where to put log-messages, it would be easier for me.
because I am now a bit confused, who is sending and who is receving messages
(from the kernel or from the remote computer or from ?).
cheers
andi
[-- Attachment #2: racoon.log --]
[-- Type: text/x-log, Size: 55814 bytes --]
racoon -d -F -f racoon.conf
Foreground mode.
2005-01-31 15:56:46: INFO: @(#)ipsec-tools 0.5rc2 (http://ipsec-tools.sourceforge.net)
2005-01-31 15:56:46: INFO: @(#)This product linked OpenSSL 0.9.7a Feb 19 2003 (http://www.openssl.org/)
2005-01-31 15:56:46: DEBUG: call pfkey_send_register for AH
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 7, p->sadb_msg_satype: 2, seq: 0)
2005-01-31 15:56:46: DEBUG: call pfkey_send_register for ESP
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 7, p->sadb_msg_satype: 3, seq: 0)
2005-01-31 15:56:46: DEBUG: call pfkey_send_register for IPCOMP
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 7, p->sadb_msg_satype: 9, seq: 0)
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 18, p->sadb_msg_satype: 0, seq: 0)
2005-01-31 15:56:46: DEBUG: reading config file racoon.conf
2005-01-31 15:56:46: DEBUG: hmac(modp1024)
2005-01-31 15:56:46: DEBUG: compression algorithm can not be checked because sadb message doesn't support it.
2005-01-31 15:56:46: DEBUG: my interface: 127.0.0.1 (lo)
2005-01-31 15:56:46: DEBUG: my interface: 192.168.2.5 (eth0)
2005-01-31 15:56:46: DEBUG: configuring default isakmp port.
2005-01-31 15:56:46: DEBUG: 2 addrs are configured successfully
2005-01-31 15:56:46: INFO: 192.168.2.5[500] used as isakmp port (fd=6)
2005-01-31 15:56:46: INFO: 127.0.0.1[500] used as isakmp port (fd=7)
2005-01-31 15:56:46: DEBUG: get pfkey X_SPDDUMP message
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 18)
2005-01-31 15:56:46: DEBUG: get pfkey X_SPDDUMP message
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 18)
2005-01-31 15:56:46: DEBUG: sub:0xbfe8b150: 192.168.2.5/32[0] 192.168.2.3/32[0] proto=any dir=out
2005-01-31 15:56:46: DEBUG: db :0x9192650: 192.168.2.3/32[0] 192.168.2.5/32[0] proto=any dir=in
2005-01-31 15:56:46: DEBUG: get pfkey X_SPDDUMP message
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 18)
2005-01-31 15:56:46: DEBUG: sub:0xbfe8b150: 192.168.2.3/32[0] 192.168.2.5/32[0] proto=any dir=fwd
2005-01-31 15:56:46: DEBUG: db :0x9192650: 192.168.2.3/32[0] 192.168.2.5/32[0] proto=any dir=in
2005-01-31 15:56:46: DEBUG: sub:0xbfe8b150: 192.168.2.3/32[0] 192.168.2.5/32[0] proto=any dir=fwd
2005-01-31 15:56:46: DEBUG: db :0x91929a8: 192.168.2.5/32[0] 192.168.2.3/32[0] proto=any dir=out
2005-01-31 15:56:52: DEBUG: ===
2005-01-31 15:56:52: DEBUG: 80 bytes message received from 192.168.2.3[500] to 192.168.2.5[500]
2005-01-31 15:56:52: DEBUG:
1b3a78e3 adfafb1d 00000000 00000000 01100200 00000000 00000050 00000034
00000001 00000001 00000028 01010001 00000020 01010000 800b0001 800c1c20
80010005 80030001 80020002 80040002
2005-01-31 15:56:52: DEBUG: anonymous configuration selected for 192.168.2.3[500].
2005-01-31 15:56:52: DEBUG: ===
2005-01-31 15:56:52: INFO: respond new phase 1 negotiation: 192.168.2.5[500]<=>192.168.2.3[500]
2005-01-31 15:56:52: INFO: begin Identity Protection mode.
2005-01-31 15:56:52: DEBUG: begin.
2005-01-31 15:56:52: DEBUG: seen nptype=1(sa)
2005-01-31 15:56:52: DEBUG: succeed.
2005-01-31 15:56:52: DEBUG: total SA len=48
2005-01-31 15:56:52: DEBUG:
00000001 00000001 00000028 01010001 00000020 01010000 800b0001 800c1c20
80010005 80030001 80020002 80040002
2005-01-31 15:56:52: DEBUG: begin.
2005-01-31 15:56:52: DEBUG: seen nptype=2(prop)
2005-01-31 15:56:52: DEBUG: succeed.
2005-01-31 15:56:52: DEBUG: proposal #1 len=40
2005-01-31 15:56:52: DEBUG: begin.
2005-01-31 15:56:52: DEBUG: seen nptype=3(trns)
2005-01-31 15:56:52: DEBUG: succeed.
2005-01-31 15:56:52: DEBUG: transform #1 len=32
2005-01-31 15:56:52: DEBUG: type=Life Type, flag=0x8000, lorv=seconds
2005-01-31 15:56:52: DEBUG: type=Life Duration, flag=0x8000, lorv=7200
2005-01-31 15:56:52: DEBUG: type=Encryption Algorithm, flag=0x8000, lorv=3DES-CBC
2005-01-31 15:56:52: DEBUG: encryption(3des)
2005-01-31 15:56:52: DEBUG: type=Authentication Method, flag=0x8000, lorv=pre-shared key
2005-01-31 15:56:52: DEBUG: type=Hash Algorithm, flag=0x8000, lorv=SHA
2005-01-31 15:56:52: DEBUG: hash(sha1)
2005-01-31 15:56:52: DEBUG: type=Group Description, flag=0x8000, lorv=1024-bit MODP group
2005-01-31 15:56:52: DEBUG: hmac(modp1024)
2005-01-31 15:56:52: DEBUG: pair 1:
2005-01-31 15:56:52: DEBUG: 0x9193600: next=(nil) tnext=(nil)
2005-01-31 15:56:52: DEBUG: proposal #1: 1 transform
2005-01-31 15:56:52: DEBUG: prop#=1, prot-id=ISAKMP, spi-size=0, #trns=1
2005-01-31 15:56:52: DEBUG: trns#=1, trns-id=IKE
2005-01-31 15:56:52: DEBUG: type=Life Type, flag=0x8000, lorv=seconds
2005-01-31 15:56:52: DEBUG: type=Life Duration, flag=0x8000, lorv=7200
2005-01-31 15:56:52: DEBUG: type=Encryption Algorithm, flag=0x8000, lorv=3DES-CBC
2005-01-31 15:56:52: DEBUG: type=Authentication Method, flag=0x8000, lorv=pre-shared key
2005-01-31 15:56:52: DEBUG: type=Hash Algorithm, flag=0x8000, lorv=SHA
2005-01-31 15:56:52: DEBUG: type=Group Description, flag=0x8000, lorv=1024-bit MODP group
2005-01-31 15:56:52: DEBUG: Compared: DB:Peer
2005-01-31 15:56:52: DEBUG: (lifetime = 7200:7200)
2005-01-31 15:56:52: DEBUG: (lifebyte = 0:0)
2005-01-31 15:56:52: DEBUG: enctype = 3DES-CBC:3DES-CBC
2005-01-31 15:56:52: DEBUG: (encklen = 0:0)
2005-01-31 15:56:52: DEBUG: hashtype = SHA:SHA
2005-01-31 15:56:52: DEBUG: authmethod = pre-shared key:pre-shared key
2005-01-31 15:56:52: DEBUG: dh_group = 1024-bit MODP group:1024-bit MODP group
2005-01-31 15:56:52: DEBUG: an acceptable proposal found.
2005-01-31 15:56:52: DEBUG: hmac(modp1024)
2005-01-31 15:56:52: DEBUG: new cookie:
c0e4d647591c43f6
2005-01-31 15:56:52: DEBUG: add payload of len 48, next type 0
2005-01-31 15:56:52: DEBUG: 80 bytes from 192.168.2.5[500] to 192.168.2.3[500]
2005-01-31 15:56:52: DEBUG: sockname 192.168.2.5[500]
2005-01-31 15:56:52: DEBUG: send packet from 192.168.2.5[500]
2005-01-31 15:56:52: DEBUG: send packet to 192.168.2.3[500]
2005-01-31 15:56:52: DEBUG: src4 192.168.2.5[500]
2005-01-31 15:56:52: DEBUG: dst4 192.168.2.3[500]
2005-01-31 15:56:52: DEBUG: 1 times of 80 bytes message will be sent to 192.168.2.5[500]
2005-01-31 15:56:52: DEBUG:
1b3a78e3 adfafb1d c0e4d647 591c43f6 01100200 00000000 00000050 00000034
00000001 00000001 00000028 01010001 00000020 01010000 800b0001 800c1c20
80010005 80030001 80020002 80040002
2005-01-31 15:56:52: DEBUG: resend phase1 packet 1b3a78e3adfafb1d:c0e4d647591c43f6
2005-01-31 15:56:52: DEBUG: ===
2005-01-31 15:56:52: DEBUG: 180 bytes message received from 192.168.2.3[500] to 192.168.2.5[500]
2005-01-31 15:56:52: DEBUG:
1b3a78e3 adfafb1d c0e4d647 591c43f6 04100200 00000000 000000b4 0a000084
7e6539fc f1e5d843 e5e77841 a3e8562d 8d49a26c 7279e895 af794c1d e8eb0bd0
073acf4d 520f6e56 70a123e5 789ac09d 1bdde2a9 a2ca6814 75be799b fc60dace
7dd2b091 7d486705 ddc2ae18 f87797e2 495fa031 2e9d2e1d df8c2eb2 11fe091f
f3794ef4 f4fa6e19 1715f997 15b7d613 e0d4c777 425f26c5 b77a420c 8906b0a2
00000014 c2e23705 244b2fb6 8fa0c213 df495ed8
2005-01-31 15:56:52: DEBUG: begin.
2005-01-31 15:56:52: DEBUG: seen nptype=4(ke)
2005-01-31 15:56:52: DEBUG: seen nptype=10(nonce)
2005-01-31 15:56:52: DEBUG: succeed.
2005-01-31 15:56:52: DEBUG: ===
2005-01-31 15:56:52: DEBUG: compute DH's private.
2005-01-31 15:56:52: DEBUG:
48c34747 1757c555 37772022 1b14a024 5358d9c0 ff09aed6 250d7525 4d45a4c1
a59bcd10 01bcbca0 57f10f3a a14a50a8 fb1758e7 3453370c 46f12224 0c48206c
06c00254 45fe7405 dfdd58d4 002d8e3d fc731391 cab96722 13787a33 48e2d95b
92439d45 48220000 e7b628ad 00c7c014 e41f310e 1ecc829d 9a9fee67 6ca8833c
2005-01-31 15:56:52: DEBUG: compute DH's public.
2005-01-31 15:56:52: DEBUG:
000000e4 d2ceeb13 d25e222f 5fc19a6f c0527b9a 9372e63b a3409c24 de2330dc
27e26b95 fe8fbfc3 c7f7e82a c41060b0 0fa76fc6 851a8add e98ec402 c0a50f61
c293aaac 74966752 63e7b471 873705a3 08cb9231 a8b2bd40 dbb78a98 2a57d60f
52c9b8f2 3c431703 257466a7 5fb7e8a6 cec76b84 8b12b933 4e33146d 17668783
2005-01-31 15:56:52: DEBUG: add payload of len 128, next type 10
2005-01-31 15:56:52: DEBUG: add payload of len 16, next type 0
2005-01-31 15:56:52: DEBUG: 180 bytes from 192.168.2.5[500] to 192.168.2.3[500]
2005-01-31 15:56:52: DEBUG: sockname 192.168.2.5[500]
2005-01-31 15:56:52: DEBUG: send packet from 192.168.2.5[500]
2005-01-31 15:56:52: DEBUG: send packet to 192.168.2.3[500]
2005-01-31 15:56:52: DEBUG: src4 192.168.2.5[500]
2005-01-31 15:56:52: DEBUG: dst4 192.168.2.3[500]
2005-01-31 15:56:52: DEBUG: 1 times of 180 bytes message will be sent to 192.168.2.5[500]
2005-01-31 15:56:52: DEBUG:
1b3a78e3 adfafb1d c0e4d647 591c43f6 04100200 00000000 000000b4 0a000084
000000e4 d2ceeb13 d25e222f 5fc19a6f c0527b9a 9372e63b a3409c24 de2330dc
27e26b95 fe8fbfc3 c7f7e82a c41060b0 0fa76fc6 851a8add e98ec402 c0a50f61
c293aaac 74966752 63e7b471 873705a3 08cb9231 a8b2bd40 dbb78a98 2a57d60f
52c9b8f2 3c431703 257466a7 5fb7e8a6 cec76b84 8b12b933 4e33146d 17668783
00000014 babea1e6 12f9e644 1aaae71b 39a25d9e
2005-01-31 15:56:52: DEBUG: resend phase1 packet 1b3a78e3adfafb1d:c0e4d647591c43f6
2005-01-31 15:56:52: DEBUG: compute DH's shared.
2005-01-31 15:56:52: DEBUG:
a28217a0 366249d5 6f519ac5 24f256d1 0964e10e caf3f872 cf14981d 4b5037b0
493e1826 8a9773ee 693bacf8 9619b9cf f36ed130 a4b8f482 b67dbfd9 4f10ad5e
de69a7c6 9ddaee2e 6d15c84d e4cc9d77 8c823392 ce82a7e5 f1ef12c7 bd82a50d
c4a42b6f ae58044e 1b836bd3 27fdfaec 26396c66 748411c6 1e896955 7827f2f3
2005-01-31 15:56:52: DEBUG: the psk found.
2005-01-31 15:56:52: DEBUG: nonce 1: 2005-01-31 15:56:52: DEBUG:
c2e23705 244b2fb6 8fa0c213 df495ed8
2005-01-31 15:56:52: DEBUG: nonce 2: 2005-01-31 15:56:52: DEBUG:
babea1e6 12f9e644 1aaae71b 39a25d9e
2005-01-31 15:56:52: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:52: DEBUG: SKEYID computed:
2005-01-31 15:56:52: DEBUG:
52e7e3bd 23f090dc 437806d9 f2d066e7 712fa970
2005-01-31 15:56:52: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:52: DEBUG: SKEYID_d computed:
2005-01-31 15:56:52: DEBUG:
7b9f85ad 24187eb8 4f9a2d0c fa112b7d be1e8bb8
2005-01-31 15:56:52: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:52: DEBUG: SKEYID_a computed:
2005-01-31 15:56:52: DEBUG:
c404a559 37883e79 71bd9bfd e1102feb d590079f
2005-01-31 15:56:52: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:52: DEBUG: SKEYID_e computed:
2005-01-31 15:56:52: DEBUG:
9d97fadd a756e74f 7ae20cc2 abcf8c69 995d10ac
2005-01-31 15:56:52: DEBUG: encryption(3des)
2005-01-31 15:56:52: DEBUG: hash(sha1)
2005-01-31 15:56:52: DEBUG: len(SKEYID_e) < len(Ka) (20 < 24), generating long key (Ka = K1 | K2 | ...)
2005-01-31 15:56:52: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:52: DEBUG: compute intermediate encryption key K1
2005-01-31 15:56:52: DEBUG:
00
2005-01-31 15:56:52: DEBUG:
5a7c9253 3da7ec0c a029a28f 5d4bfbbb d0730ef7
2005-01-31 15:56:52: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:52: DEBUG: compute intermediate encryption key K2
2005-01-31 15:56:52: DEBUG:
5a7c9253 3da7ec0c a029a28f 5d4bfbbb d0730ef7
2005-01-31 15:56:52: DEBUG:
5b24dc57 d13355e0 05619375 4ca1867a 78e577a6
2005-01-31 15:56:52: DEBUG: final encryption key computed:
2005-01-31 15:56:52: DEBUG:
5a7c9253 3da7ec0c a029a28f 5d4bfbbb d0730ef7 5b24dc57
2005-01-31 15:56:52: DEBUG: hash(sha1)
2005-01-31 15:56:52: DEBUG: encryption(3des)
2005-01-31 15:56:52: DEBUG: IV computed:
2005-01-31 15:56:52: DEBUG:
dfabb8a1 669e3464
2005-01-31 15:56:52: DEBUG: ===
2005-01-31 15:56:52: DEBUG: 68 bytes message received from 192.168.2.3[500] to 192.168.2.5[500]
2005-01-31 15:56:52: DEBUG:
1b3a78e3 adfafb1d c0e4d647 591c43f6 05100201 00000000 00000044 ad20bf06
c242b46e 96fb63cd c87a73c5 dd82fb4a f0dc20b7 0123e607 8071e97e 3930d6b6
7cfb6911
2005-01-31 15:56:52: DEBUG: begin decryption.
2005-01-31 15:56:52: DEBUG: encryption(3des)
2005-01-31 15:56:52: DEBUG: IV was saved for next processing:
2005-01-31 15:56:52: DEBUG:
3930d6b6 7cfb6911
2005-01-31 15:56:52: DEBUG: encryption(3des)
2005-01-31 15:56:52: DEBUG: with key:
2005-01-31 15:56:52: DEBUG:
5a7c9253 3da7ec0c a029a28f 5d4bfbbb d0730ef7 5b24dc57
2005-01-31 15:56:52: DEBUG: decrypted payload by IV:
2005-01-31 15:56:52: DEBUG:
dfabb8a1 669e3464
2005-01-31 15:56:52: DEBUG: decrypted payload, but not trimed.
2005-01-31 15:56:52: DEBUG:
0800000c 011101f4 c0a80203 00000018 4ba6bc99 869b2231 74dc9ed4 26982126
c9666eaf 8591e803
2005-01-31 15:56:52: DEBUG: padding len=4
2005-01-31 15:56:52: DEBUG: skip to trim padding.
2005-01-31 15:56:52: DEBUG: decrypted.
2005-01-31 15:56:52: DEBUG:
1b3a78e3 adfafb1d c0e4d647 591c43f6 05100201 00000000 00000044 0800000c
011101f4 c0a80203 00000018 4ba6bc99 869b2231 74dc9ed4 26982126 c9666eaf
8591e803
2005-01-31 15:56:52: DEBUG: begin.
2005-01-31 15:56:52: DEBUG: seen nptype=5(id)
2005-01-31 15:56:52: DEBUG: seen nptype=8(hash)
2005-01-31 15:56:52: DEBUG: succeed.
2005-01-31 15:56:52: DEBUG: HASH received:2005-01-31 15:56:52: DEBUG:
4ba6bc99 869b2231 74dc9ed4 26982126 c9666eaf
2005-01-31 15:56:52: DEBUG: HASH with:
2005-01-31 15:56:52: DEBUG:
7e6539fc f1e5d843 e5e77841 a3e8562d 8d49a26c 7279e895 af794c1d e8eb0bd0
073acf4d 520f6e56 70a123e5 789ac09d 1bdde2a9 a2ca6814 75be799b fc60dace
7dd2b091 7d486705 ddc2ae18 f87797e2 495fa031 2e9d2e1d df8c2eb2 11fe091f
f3794ef4 f4fa6e19 1715f997 15b7d613 e0d4c777 425f26c5 b77a420c 8906b0a2
000000e4 d2ceeb13 d25e222f 5fc19a6f c0527b9a 9372e63b a3409c24 de2330dc
27e26b95 fe8fbfc3 c7f7e82a c41060b0 0fa76fc6 851a8add e98ec402 c0a50f61
c293aaac 74966752 63e7b471 873705a3 08cb9231 a8b2bd40 dbb78a98 2a57d60f
52c9b8f2 3c431703 257466a7 5fb7e8a6 cec76b84 8b12b933 4e33146d 17668783
1b3a78e3 adfafb1d c0e4d647 591c43f6 00000001 00000001 00000028 01010001
00000020 01010000 800b0001 800c1c20 80010005 80030001 80020002 80040002
011101f4 c0a80203
2005-01-31 15:56:52: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:52: DEBUG: HASH computed:
2005-01-31 15:56:52: DEBUG:
4ba6bc99 869b2231 74dc9ed4 26982126 c9666eaf
2005-01-31 15:56:52: DEBUG: HASH for PSK validated.
2005-01-31 15:56:52: DEBUG: peer's ID
2005-01-31 15:56:52: DEBUG:
011101f4 c0a80203
2005-01-31 15:56:52: DEBUG: ===
2005-01-31 15:56:52: DEBUG: use ID type of IPv4_address
2005-01-31 15:56:52: DEBUG: generate HASH_R
2005-01-31 15:56:52: DEBUG: HASH with:
2005-01-31 15:56:52: DEBUG:
000000e4 d2ceeb13 d25e222f 5fc19a6f c0527b9a 9372e63b a3409c24 de2330dc
27e26b95 fe8fbfc3 c7f7e82a c41060b0 0fa76fc6 851a8add e98ec402 c0a50f61
c293aaac 74966752 63e7b471 873705a3 08cb9231 a8b2bd40 dbb78a98 2a57d60f
52c9b8f2 3c431703 257466a7 5fb7e8a6 cec76b84 8b12b933 4e33146d 17668783
7e6539fc f1e5d843 e5e77841 a3e8562d 8d49a26c 7279e895 af794c1d e8eb0bd0
073acf4d 520f6e56 70a123e5 789ac09d 1bdde2a9 a2ca6814 75be799b fc60dace
7dd2b091 7d486705 ddc2ae18 f87797e2 495fa031 2e9d2e1d df8c2eb2 11fe091f
f3794ef4 f4fa6e19 1715f997 15b7d613 e0d4c777 425f26c5 b77a420c 8906b0a2
c0e4d647 591c43f6 1b3a78e3 adfafb1d 00000001 00000001 00000028 01010001
00000020 01010000 800b0001 800c1c20 80010005 80030001 80020002 80040002
011101f4 c0a80205
2005-01-31 15:56:52: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:52: DEBUG: HASH computed:
2005-01-31 15:56:52: DEBUG:
c14bac70 06f1d8de 4972451b e297ec65 e65b784c
2005-01-31 15:56:52: DEBUG: add payload of len 8, next type 8
2005-01-31 15:56:52: DEBUG: add payload of len 20, next type 0
2005-01-31 15:56:52: DEBUG: begin encryption.
2005-01-31 15:56:52: DEBUG: encryption(3des)
2005-01-31 15:56:52: DEBUG: pad length = 4
2005-01-31 15:56:52: DEBUG:
0800000c 011101f4 c0a80205 00000018 c14bac70 06f1d8de 4972451b e297ec65
e65b784c a4cc8c03
2005-01-31 15:56:52: DEBUG: encryption(3des)
2005-01-31 15:56:52: DEBUG: with key:
2005-01-31 15:56:52: DEBUG:
5a7c9253 3da7ec0c a029a28f 5d4bfbbb d0730ef7 5b24dc57
2005-01-31 15:56:52: DEBUG: encrypted payload by IV:
2005-01-31 15:56:52: DEBUG:
3930d6b6 7cfb6911
2005-01-31 15:56:52: DEBUG: save IV for next:
2005-01-31 15:56:52: DEBUG:
d0b3dc22 1d31f2d0
2005-01-31 15:56:52: DEBUG: encrypted.
2005-01-31 15:56:52: DEBUG: 68 bytes from 192.168.2.5[500] to 192.168.2.3[500]
2005-01-31 15:56:52: DEBUG: sockname 192.168.2.5[500]
2005-01-31 15:56:52: DEBUG: send packet from 192.168.2.5[500]
2005-01-31 15:56:52: DEBUG: send packet to 192.168.2.3[500]
2005-01-31 15:56:52: DEBUG: src4 192.168.2.5[500]
2005-01-31 15:56:52: DEBUG: dst4 192.168.2.3[500]
2005-01-31 15:56:52: DEBUG: 1 times of 68 bytes message will be sent to 192.168.2.5[500]
2005-01-31 15:56:52: DEBUG:
1b3a78e3 adfafb1d c0e4d647 591c43f6 05100201 00000000 00000044 f654f8e5
82c1a183 3e0724b9 4a5c7c9a 2dd8d5ed 0a442025 b256eb40 26eb90d1 d0b3dc22
1d31f2d0
2005-01-31 15:56:52: DEBUG: compute IV for phase2
2005-01-31 15:56:52: DEBUG: phase1 last IV:
2005-01-31 15:56:52: DEBUG:
d0b3dc22 1d31f2d0 c526736e
2005-01-31 15:56:52: DEBUG: hash(sha1)
2005-01-31 15:56:52: DEBUG: encryption(3des)
2005-01-31 15:56:52: DEBUG: phase2 IV computed:
2005-01-31 15:56:52: DEBUG:
ecb15503 ffc9819e
2005-01-31 15:56:52: DEBUG: HASH with:
2005-01-31 15:56:52: DEBUG:
c526736e 0000001c 00000001 01106002 1b3a78e3 adfafb1d c0e4d647 591c43f6
2005-01-31 15:56:52: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:52: DEBUG: HASH computed:
2005-01-31 15:56:52: DEBUG:
7eae471b 9a17c55c 1010011f 5f59721a 681f2928
2005-01-31 15:56:52: DEBUG: begin encryption.
2005-01-31 15:56:52: DEBUG: encryption(3des)
2005-01-31 15:56:52: DEBUG: pad length = 4
2005-01-31 15:56:52: DEBUG:
0b000018 7eae471b 9a17c55c 1010011f 5f59721a 681f2928 0000001c 00000001
01106002 1b3a78e3 adfafb1d c0e4d647 591c43f6 94e0db03
2005-01-31 15:56:52: DEBUG: encryption(3des)
2005-01-31 15:56:52: DEBUG: with key:
2005-01-31 15:56:52: DEBUG:
5a7c9253 3da7ec0c a029a28f 5d4bfbbb d0730ef7 5b24dc57
2005-01-31 15:56:52: DEBUG: encrypted payload by IV:
2005-01-31 15:56:52: DEBUG:
ecb15503 ffc9819e
2005-01-31 15:56:52: DEBUG: save IV for next:
2005-01-31 15:56:52: DEBUG:
9f28ddb4 d437e77a
2005-01-31 15:56:52: DEBUG: encrypted.
2005-01-31 15:56:52: DEBUG: 84 bytes from 192.168.2.5[500] to 192.168.2.3[500]
2005-01-31 15:56:52: DEBUG: sockname 192.168.2.5[500]
2005-01-31 15:56:52: DEBUG: send packet from 192.168.2.5[500]
2005-01-31 15:56:52: DEBUG: send packet to 192.168.2.3[500]
2005-01-31 15:56:52: DEBUG: src4 192.168.2.5[500]
2005-01-31 15:56:52: DEBUG: dst4 192.168.2.3[500]
2005-01-31 15:56:52: DEBUG: 1 times of 84 bytes message will be sent to 192.168.2.5[500]
2005-01-31 15:56:52: DEBUG:
1b3a78e3 adfafb1d c0e4d647 591c43f6 08100501 c526736e 00000054 acc30f7e
33aa64d5 60b46418 f70cc8f7 18e13f5f 2f992c8e 98fb1326 a9944a07 92f6e1af
e61015e8 3a323d1d caab1e48 9f28ddb4 d437e77a
2005-01-31 15:56:52: DEBUG: sendto Information notify.
2005-01-31 15:56:52: INFO: ISAKMP-SA established 192.168.2.5[500]-192.168.2.3[500] spi:1b3a78e3adfafb1d:c0e4d647591c43f6
2005-01-31 15:56:52: DEBUG: ===
2005-01-31 15:56:52: DEBUG: ===
2005-01-31 15:56:52: DEBUG: 84 bytes message received from 192.168.2.3[500] to 192.168.2.5[500]
2005-01-31 15:56:52: DEBUG:
1b3a78e3 adfafb1d c0e4d647 591c43f6 08100501 d9b420b1 00000054 0b062d5f
65c48bb1 f1f97d55 7a63f3d2 b1f3ce52 08e18c9d 046a9522 f17660de 412b67f8
6fb2edca 729bc018 c252ecb1 c5f19ec7 155d9b78
2005-01-31 15:56:52: DEBUG: receive Information.
2005-01-31 15:56:52: DEBUG: compute IV for phase2
2005-01-31 15:56:52: DEBUG: phase1 last IV:
2005-01-31 15:56:52: DEBUG:
d0b3dc22 1d31f2d0 d9b420b1
2005-01-31 15:56:52: DEBUG: hash(sha1)
2005-01-31 15:56:52: DEBUG: encryption(3des)
2005-01-31 15:56:52: DEBUG: phase2 IV computed:
2005-01-31 15:56:52: DEBUG:
0a67a66c d95a02d0
2005-01-31 15:56:52: DEBUG: begin decryption.
2005-01-31 15:56:52: DEBUG: encryption(3des)
2005-01-31 15:56:52: DEBUG: IV was saved for next processing:
2005-01-31 15:56:52: DEBUG:
c5f19ec7 155d9b78
2005-01-31 15:56:52: DEBUG: encryption(3des)
2005-01-31 15:56:52: DEBUG: with key:
2005-01-31 15:56:52: DEBUG:
5a7c9253 3da7ec0c a029a28f 5d4bfbbb d0730ef7 5b24dc57
2005-01-31 15:56:52: DEBUG: decrypted payload by IV:
2005-01-31 15:56:52: DEBUG:
0a67a66c d95a02d0
2005-01-31 15:56:52: DEBUG: decrypted payload, but not trimed.
2005-01-31 15:56:52: DEBUG:
0b000018 94d84a48 99b0dc57 96900dd9 cf0da364 ef1fada0 0000001c 00000001
01106002 1b3a78e3 adfafb1d c0e4d647 591c43f6 d8c0e303
2005-01-31 15:56:52: DEBUG: padding len=4
2005-01-31 15:56:52: DEBUG: skip to trim padding.
2005-01-31 15:56:52: DEBUG: decrypted.
2005-01-31 15:56:52: DEBUG:
1b3a78e3 adfafb1d c0e4d647 591c43f6 08100501 d9b420b1 00000054 0b000018
94d84a48 99b0dc57 96900dd9 cf0da364 ef1fada0 0000001c 00000001 01106002
1b3a78e3 adfafb1d c0e4d647 591c43f6 d8c0e303
2005-01-31 15:56:52: DEBUG: HASH with:
2005-01-31 15:56:52: DEBUG:
d9b420b1 0000001c 00000001 01106002 1b3a78e3 adfafb1d c0e4d647 591c43f6
2005-01-31 15:56:52: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:52: DEBUG: HASH computed:
2005-01-31 15:56:52: DEBUG:
94d84a48 99b0dc57 96900dd9 cf0da364 ef1fada0
2005-01-31 15:56:52: DEBUG: hash validated.
2005-01-31 15:56:52: DEBUG: begin.
2005-01-31 15:56:52: DEBUG: seen nptype=8(hash)
2005-01-31 15:56:52: DEBUG: seen nptype=11(notify)
2005-01-31 15:56:52: DEBUG: succeed.
2005-01-31 15:56:52: DEBUG: call pfkey_send_dump
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 10, p->sadb_msg_satype: 0, seq: 0)
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 10)
2005-01-31 15:56:52: DEBUG: notification message 24578:INITIAL-CONTACT, doi=1 proto_id=1 spi=1b3a78e3adfafb1d c0e4d647591c43f6 (size=16).
2005-01-31 15:56:53: DEBUG: ===
2005-01-31 15:56:53: DEBUG: 300 bytes message received from 192.168.2.3[500] to 192.168.2.5[500]
2005-01-31 15:56:53: DEBUG:
1b3a78e3 adfafb1d c0e4d647 591c43f6 08102001 f165fca7 0000012c dcfeb0b2
e0b2eccd ea3f08ad 69fe90b4 8bd46e67 9879b11f e767fd68 635c7608 b0479c72
e61639f9 1dbdeb22 38e0764e f781131b 7cf18203 24888306 9bb1ed29 16a9d44f
573124d8 f45ab587 982f0184 89d26499 8312d6cf 7383357e a592a161 f53c9ec6
6befbcf8 a7ea3cc2 79b54188 c013c058 56064703 ab6bf3b3 d88dcf8d 585acba2
999b4d38 cf28dc13 001eee0d 87ef22e4 2af56a81 be66df06 da579520 a1438911
a484cf3c 84f08206 76b16b3e ef272d4a 356ee6c1 57eab6a7 bb50bde2 ee149222
75219866 0beca2c9 42be153c 7e45ed2f 8a722ab5 6d43377f 08520ace 3a87a070
40920c00 a6578bf9 a6ba7809 6334d3fa 20666cc6 5f6d88b1 424cec6d f2559408
f176b3b7 f0e213b8 d6423ed8
2005-01-31 15:56:53: INFO: andi: in isakmp.c, isakmp_ph2begin_r: iph2->seq 369749501
2005-01-31 15:56:53: DEBUG: compute IV for phase2
2005-01-31 15:56:53: DEBUG: phase1 last IV:
2005-01-31 15:56:53: DEBUG:
d0b3dc22 1d31f2d0 f165fca7
2005-01-31 15:56:53: DEBUG: hash(sha1)
2005-01-31 15:56:53: DEBUG: encryption(3des)
2005-01-31 15:56:53: DEBUG: phase2 IV computed:
2005-01-31 15:56:53: DEBUG:
85f7a521 c958f031
2005-01-31 15:56:53: DEBUG: ===
2005-01-31 15:56:53: INFO: respond new phase 2 negotiation: 192.168.2.5[0]<=>192.168.2.3[0]
2005-01-31 15:56:53: DEBUG: begin decryption.
2005-01-31 15:56:53: DEBUG: encryption(3des)
2005-01-31 15:56:53: DEBUG: IV was saved for next processing:
2005-01-31 15:56:53: DEBUG:
f0e213b8 d6423ed8
2005-01-31 15:56:53: DEBUG: encryption(3des)
2005-01-31 15:56:53: DEBUG: with key:
2005-01-31 15:56:53: DEBUG:
5a7c9253 3da7ec0c a029a28f 5d4bfbbb d0730ef7 5b24dc57
2005-01-31 15:56:53: DEBUG: decrypted payload by IV:
2005-01-31 15:56:53: DEBUG:
85f7a521 c958f031
2005-01-31 15:56:53: DEBUG: decrypted payload, but not trimed.
2005-01-31 15:56:53: DEBUG:
01000018 17618673 472d64d3 bfc732ce 2b439a02 edfda95d 0a00005c 00000001
00000001 02000028 01020401 00fea865 0000001c 01030000 80010001 80020e10
80040002 80050002 80030002 00000028 01030401 06aff78a 0000001c 01030000
80010001 80020e10 80040002 80050002 80030002 04000014 c7d64915 bdd7f74e
89c2ca14 e9b1ddb5 00000084 416fb889 f849ba95 60f85d54 7ac2cee5 d84b7c30
0e318740 b0ae8f43 e64168ae 82498bb9 1e87fb24 cce327a2 8932a0a4 60fae7cd
fff242cb 115df7f2 4ff5e26a 2eddd093 089d2f4a a0664b60 c81b0dfe adf8934b
bad975a1 39801e4f 19dd64a6 e5cf684f 4fab2a8e fcb359e2 14c9ba33 6b547e53
b202a193 0c045aed 00557972 809ddf03
2005-01-31 15:56:53: DEBUG: padding len=4
2005-01-31 15:56:53: DEBUG: skip to trim padding.
2005-01-31 15:56:53: DEBUG: decrypted.
2005-01-31 15:56:53: DEBUG:
1b3a78e3 adfafb1d c0e4d647 591c43f6 08102001 f165fca7 0000012c 01000018
17618673 472d64d3 bfc732ce 2b439a02 edfda95d 0a00005c 00000001 00000001
02000028 01020401 00fea865 0000001c 01030000 80010001 80020e10 80040002
80050002 80030002 00000028 01030401 06aff78a 0000001c 01030000 80010001
80020e10 80040002 80050002 80030002 04000014 c7d64915 bdd7f74e 89c2ca14
e9b1ddb5 00000084 416fb889 f849ba95 60f85d54 7ac2cee5 d84b7c30 0e318740
b0ae8f43 e64168ae 82498bb9 1e87fb24 cce327a2 8932a0a4 60fae7cd fff242cb
115df7f2 4ff5e26a 2eddd093 089d2f4a a0664b60 c81b0dfe adf8934b bad975a1
39801e4f 19dd64a6 e5cf684f 4fab2a8e fcb359e2 14c9ba33 6b547e53 b202a193
0c045aed 00557972 809ddf03
2005-01-31 15:56:53: DEBUG: begin.
2005-01-31 15:56:53: DEBUG: seen nptype=8(hash)
2005-01-31 15:56:53: DEBUG: seen nptype=1(sa)
2005-01-31 15:56:53: DEBUG: seen nptype=10(nonce)
2005-01-31 15:56:53: DEBUG: seen nptype=4(ke)
2005-01-31 15:56:53: DEBUG: succeed.
2005-01-31 15:56:53: DEBUG: HASH(1) validate:2005-01-31 15:56:53: DEBUG:
17618673 472d64d3 bfc732ce 2b439a02 edfda95d
2005-01-31 15:56:53: DEBUG: HASH with:
2005-01-31 15:56:53: DEBUG:
f165fca7 0a00005c 00000001 00000001 02000028 01020401 00fea865 0000001c
01030000 80010001 80020e10 80040002 80050002 80030002 00000028 01030401
06aff78a 0000001c 01030000 80010001 80020e10 80040002 80050002 80030002
04000014 c7d64915 bdd7f74e 89c2ca14 e9b1ddb5 00000084 416fb889 f849ba95
60f85d54 7ac2cee5 d84b7c30 0e318740 b0ae8f43 e64168ae 82498bb9 1e87fb24
cce327a2 8932a0a4 60fae7cd fff242cb 115df7f2 4ff5e26a 2eddd093 089d2f4a
a0664b60 c81b0dfe adf8934b bad975a1 39801e4f 19dd64a6 e5cf684f 4fab2a8e
fcb359e2 14c9ba33 6b547e53 b202a193 0c045aed 00557972
2005-01-31 15:56:53: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:53: DEBUG: HASH computed:
2005-01-31 15:56:53: DEBUG:
17618673 472d64d3 bfc732ce 2b439a02 edfda95d
2005-01-31 15:56:53: DEBUG: anonymous sainfo selected.
2005-01-31 15:56:53: DEBUG: get sa info: anonymous
2005-01-31 15:56:53: DEBUG: get a destination address of SP index from phase1 address due to no ID payloads found OR because ID type is not address.
2005-01-31 15:56:53: DEBUG: get a source address of SP index from phase1 address due to no ID payloads found OR because ID type is not address.
2005-01-31 15:56:53: DEBUG: get a src address from ID payload 192.168.2.3[0] prefixlen=32 ul_proto=0
2005-01-31 15:56:53: DEBUG: get dst address from ID payload 192.168.2.5[0] prefixlen=32 ul_proto=0
2005-01-31 15:56:53: DEBUG: sub:0xbfe8afc0: 192.168.2.3/32[0] 192.168.2.5/32[0] proto=any dir=in
2005-01-31 15:56:53: DEBUG: db: 0x9192650: 192.168.2.3/32[0] 192.168.2.5/32[0] proto=any dir=in
2005-01-31 15:56:53: DEBUG: 0xbfe8afc0 masked with /32: 192.168.2.3[0]
2005-01-31 15:56:53: DEBUG: 0x9192650 masked with /32: 192.168.2.3[0]
2005-01-31 15:56:53: DEBUG: 0xbfe8afc0 masked with /32: 192.168.2.5[0]
2005-01-31 15:56:53: DEBUG: 0x9192650 masked with /32: 192.168.2.5[0]
2005-01-31 15:56:53: DEBUG: sub:0xbfe8afc0: 192.168.2.5/32[0] 192.168.2.3/32[0] proto=any dir=out
2005-01-31 15:56:53: DEBUG: db: 0x9192650: 192.168.2.3/32[0] 192.168.2.5/32[0] proto=any dir=in
2005-01-31 15:56:53: DEBUG: sub:0xbfe8afc0: 192.168.2.5/32[0] 192.168.2.3/32[0] proto=any dir=out
2005-01-31 15:56:53: DEBUG: db: 0x91929a8: 192.168.2.5/32[0] 192.168.2.3/32[0] proto=any dir=out
2005-01-31 15:56:53: DEBUG: 0xbfe8afc0 masked with /32: 192.168.2.5[0]
2005-01-31 15:56:53: DEBUG: 0x91929a8 masked with /32: 192.168.2.5[0]
2005-01-31 15:56:53: DEBUG: 0xbfe8afc0 masked with /32: 192.168.2.3[0]
2005-01-31 15:56:53: DEBUG: 0x91929a8 masked with /32: 192.168.2.3[0]
2005-01-31 15:56:53: DEBUG: suitable SP found:192.168.2.5/32[0] 192.168.2.3/32[0] proto=any dir=out
2005-01-31 15:56:53: DEBUG: (proto_id=AH spisize=4 spi=00000000 spi_p=00000000 encmode=Transport reqid=0:0)
2005-01-31 15:56:53: DEBUG: (trns_id=SHA authtype=hmac-sha)
2005-01-31 15:56:53: DEBUG: (proto_id=ESP spisize=4 spi=00000000 spi_p=00000000 encmode=Transport reqid=0:0)
2005-01-31 15:56:53: DEBUG: (trns_id=3DES encklen=0 authtype=hmac-sha)
2005-01-31 15:56:53: DEBUG: total SA len=88
2005-01-31 15:56:53: DEBUG:
00000001 00000001 02000028 01020401 00fea865 0000001c 01030000 80010001
80020e10 80040002 80050002 80030002 00000028 01030401 06aff78a 0000001c
01030000 80010001 80020e10 80040002 80050002 80030002
2005-01-31 15:56:53: DEBUG: begin.
2005-01-31 15:56:53: DEBUG: seen nptype=2(prop)
2005-01-31 15:56:53: DEBUG: seen nptype=2(prop)
2005-01-31 15:56:53: DEBUG: succeed.
2005-01-31 15:56:53: DEBUG: proposal #1 len=40
2005-01-31 15:56:53: DEBUG: begin.
2005-01-31 15:56:53: DEBUG: seen nptype=3(trns)
2005-01-31 15:56:53: DEBUG: succeed.
2005-01-31 15:56:53: DEBUG: transform #1 len=28
2005-01-31 15:56:53: DEBUG: type=SA Life Type, flag=0x8000, lorv=seconds
2005-01-31 15:56:53: DEBUG: type=SA Life Duration, flag=0x8000, lorv=3600
2005-01-31 15:56:53: DEBUG: life duration was in TLV.
2005-01-31 15:56:53: DEBUG: type=Encryption Mode, flag=0x8000, lorv=Transport
2005-01-31 15:56:53: DEBUG: type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha
2005-01-31 15:56:53: DEBUG: type=Group Description, flag=0x8000, lorv=2
2005-01-31 15:56:53: DEBUG: hmac(modp1024)
2005-01-31 15:56:53: DEBUG: proposal #1 len=40
2005-01-31 15:56:53: DEBUG: begin.
2005-01-31 15:56:53: DEBUG: seen nptype=3(trns)
2005-01-31 15:56:53: DEBUG: succeed.
2005-01-31 15:56:53: DEBUG: transform #1 len=28
2005-01-31 15:56:53: DEBUG: type=SA Life Type, flag=0x8000, lorv=seconds
2005-01-31 15:56:53: DEBUG: type=SA Life Duration, flag=0x8000, lorv=3600
2005-01-31 15:56:53: DEBUG: life duration was in TLV.
2005-01-31 15:56:53: DEBUG: type=Encryption Mode, flag=0x8000, lorv=Transport
2005-01-31 15:56:53: DEBUG: type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha
2005-01-31 15:56:53: DEBUG: type=Group Description, flag=0x8000, lorv=2
2005-01-31 15:56:53: DEBUG: hmac(modp1024)
2005-01-31 15:56:53: DEBUG: pair 1:
2005-01-31 15:56:53: DEBUG: 0x91946a0: next=0x91946b8 tnext=(nil)
2005-01-31 15:56:53: DEBUG: 0x91946b8: next=(nil) tnext=(nil)
2005-01-31 15:56:53: DEBUG: proposal #1: 2 transform
2005-01-31 15:56:53: DEBUG: begin compare proposals.
2005-01-31 15:56:53: DEBUG: pair[1]: 0x91946a0
2005-01-31 15:56:53: DEBUG: 0x91946a0: next=0x91946b8 tnext=(nil)
2005-01-31 15:56:53: DEBUG: 0x91946b8: next=(nil) tnext=(nil)
2005-01-31 15:56:53: DEBUG: prop#=1 prot-id=AH spi-size=4 #trns=1 trns#=1 trns-id=SHA
2005-01-31 15:56:53: DEBUG: type=SA Life Type, flag=0x8000, lorv=seconds
2005-01-31 15:56:53: DEBUG: type=SA Life Duration, flag=0x8000, lorv=3600
2005-01-31 15:56:53: DEBUG: type=Encryption Mode, flag=0x8000, lorv=Transport
2005-01-31 15:56:53: DEBUG: type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha
2005-01-31 15:56:53: DEBUG: type=Group Description, flag=0x8000, lorv=2
2005-01-31 15:56:53: DEBUG: prop#=1 prot-id=ESP spi-size=4 #trns=1 trns#=1 trns-id=3DES
2005-01-31 15:56:53: DEBUG: type=SA Life Type, flag=0x8000, lorv=seconds
2005-01-31 15:56:53: DEBUG: type=SA Life Duration, flag=0x8000, lorv=3600
2005-01-31 15:56:53: DEBUG: type=Encryption Mode, flag=0x8000, lorv=Transport
2005-01-31 15:56:53: DEBUG: type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha
2005-01-31 15:56:53: DEBUG: type=Group Description, flag=0x8000, lorv=2
2005-01-31 15:56:53: DEBUG: peer's single bundle:
2005-01-31 15:56:53: DEBUG: (proto_id=AH spisize=4 spi=00fea865 spi_p=00000000 encmode=Transport reqid=0:0)
2005-01-31 15:56:53: DEBUG: (trns_id=SHA authtype=hmac-sha)
2005-01-31 15:56:53: DEBUG: (proto_id=ESP spisize=4 spi=06aff78a spi_p=00000000 encmode=Transport reqid=0:0)
2005-01-31 15:56:53: DEBUG: (trns_id=3DES encklen=0 authtype=hmac-sha)
2005-01-31 15:56:53: DEBUG: my single bundle:
2005-01-31 15:56:53: DEBUG: (proto_id=AH spisize=4 spi=00000000 spi_p=00000000 encmode=Transport reqid=0:0)
2005-01-31 15:56:53: DEBUG: (trns_id=SHA authtype=hmac-sha)
2005-01-31 15:56:53: DEBUG: (proto_id=ESP spisize=4 spi=00000000 spi_p=00000000 encmode=Transport reqid=0:0)
2005-01-31 15:56:53: DEBUG: (trns_id=3DES encklen=0 authtype=hmac-sha)
2005-01-31 15:56:53: DEBUG: matched
2005-01-31 15:56:53: DEBUG: ===
2005-01-31 15:56:53: DEBUG: andi: pfkey.c, pfkey_send_getspi (pr->proto_id: 2,iph2->seq: 369749501)
andi: libipsec/pfkey.c, pfkey_send_getspi: (satype: 2, seq: 369749501)
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 1, p->sadb_msg_satype: 2, seq: 369749501)
2005-01-31 15:56:53: DEBUG: pfkey GETSPI sent: AH/Transport 192.168.2.3->192.168.2.5
2005-01-31 15:56:53: DEBUG: andi: pfkey.c, pfkey_send_getspi (pr->proto_id: 3,iph2->seq: 369749501)
andi: libipsec/pfkey.c, pfkey_send_getspi: (satype: 3, seq: 369749501)
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 1, p->sadb_msg_satype: 3, seq: 369749501)
2005-01-31 15:56:53: DEBUG: pfkey GETSPI sent: ESP/Transport 192.168.2.3->192.168.2.5
2005-01-31 15:56:53: DEBUG: pfkey getspi sent.
2005-01-31 15:56:53: DEBUG: get pfkey GETSPI message
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 1)
2005-01-31 15:56:53: DEBUG: andi: pfkey.c, pk_recvgetspi: msg->sadb_msg_seq 369749501, msg->sadb_msg_type: GETSPI .
2005-01-31 15:56:53: DEBUG: pfkey GETSPI succeeded: AH/Transport 192.168.2.3->192.168.2.5 spi=129077146(0x7b18f9a)
2005-01-31 15:56:53: DEBUG: get pfkey GETSPI message
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 1)
2005-01-31 15:56:53: DEBUG: andi: pfkey.c, pk_recvgetspi: msg->sadb_msg_seq 369749501, msg->sadb_msg_type: GETSPI .
2005-01-31 15:56:53: DEBUG: pfkey GETSPI succeeded: ESP/Transport 192.168.2.3->192.168.2.5 spi=219187533(0xd10894d)
2005-01-31 15:56:53: DEBUG: total SA len=88
2005-01-31 15:56:53: DEBUG:
00000001 00000001 02000028 01020401 00000000 0000001c 01030000 80010001
80020e10 80040002 80050002 80030002 00000028 01030401 00000000 0000001c
01030000 80010001 80020e10 80040002 80050002 80030002
2005-01-31 15:56:53: DEBUG: begin.
2005-01-31 15:56:53: DEBUG: seen nptype=2(prop)
2005-01-31 15:56:53: DEBUG: seen nptype=2(prop)
2005-01-31 15:56:53: DEBUG: succeed.
2005-01-31 15:56:53: DEBUG: proposal #1 len=40
2005-01-31 15:56:53: DEBUG: begin.
2005-01-31 15:56:53: DEBUG: seen nptype=3(trns)
2005-01-31 15:56:53: DEBUG: succeed.
2005-01-31 15:56:53: DEBUG: transform #1 len=28
2005-01-31 15:56:53: DEBUG: type=SA Life Type, flag=0x8000, lorv=seconds
2005-01-31 15:56:53: DEBUG: type=SA Life Duration, flag=0x8000, lorv=3600
2005-01-31 15:56:53: DEBUG: life duration was in TLV.
2005-01-31 15:56:53: DEBUG: type=Encryption Mode, flag=0x8000, lorv=Transport
2005-01-31 15:56:53: DEBUG: type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha
2005-01-31 15:56:53: DEBUG: type=Group Description, flag=0x8000, lorv=2
2005-01-31 15:56:53: DEBUG: hmac(modp1024)
2005-01-31 15:56:53: DEBUG: proposal #1 len=40
2005-01-31 15:56:53: DEBUG: begin.
2005-01-31 15:56:53: DEBUG: seen nptype=3(trns)
2005-01-31 15:56:53: DEBUG: succeed.
2005-01-31 15:56:53: DEBUG: transform #1 len=28
2005-01-31 15:56:53: DEBUG: type=SA Life Type, flag=0x8000, lorv=seconds
2005-01-31 15:56:53: DEBUG: type=SA Life Duration, flag=0x8000, lorv=3600
2005-01-31 15:56:53: DEBUG: life duration was in TLV.
2005-01-31 15:56:53: DEBUG: type=Encryption Mode, flag=0x8000, lorv=Transport
2005-01-31 15:56:53: DEBUG: type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha
2005-01-31 15:56:53: DEBUG: type=Group Description, flag=0x8000, lorv=2
2005-01-31 15:56:53: DEBUG: hmac(modp1024)
2005-01-31 15:56:53: DEBUG: pair 1:
2005-01-31 15:56:53: DEBUG: 0x9193f68: next=0x9193c38 tnext=(nil)
2005-01-31 15:56:53: DEBUG: 0x9193c38: next=(nil) tnext=(nil)
2005-01-31 15:56:53: DEBUG: proposal #1: 2 transform
2005-01-31 15:56:53: DEBUG: hmac(modp1024)
2005-01-31 15:56:54: DEBUG: compute DH's private.
2005-01-31 15:56:54: DEBUG:
61ad1a7c 415cc7ca c6b10f8f a509fd30 fc25d6de e2dc3228 3f49513d 213e6d1d
6974d149 87d7ec4a 5d94e7ae c3222132 f9ec891e e48e8e69 9ba1a68d 7cb89355
57942666 093c2d08 1fe48b36 ca5fdb07 fa41c14d b3e1cca7 e59c9dd5 52d4300e
9929bf2d 5d0d8c06 90134e8b 3f8900dd 5c5bc152 aa165c2e d9386aec c274189e
2005-01-31 15:56:54: DEBUG: compute DH's public.
2005-01-31 15:56:54: DEBUG:
1a9a548f 5cb12fc5 349c1372 6d2cc511 51029530 0e739921 f0d6371c 97075f8f
04aa195c 446f788d 5856a2fb 85e21369 ea0bbf44 a2aeea15 f9138f7b ab9a303f
861da44f 6d8b3599 bacac90f ac7ae542 5c32765f fb8b26aa b0392050 7059cae9
d360eac8 4318e7d1 8beda674 a51bc003 559a4854 cdbdf9e7 66338448 1c01038f
2005-01-31 15:56:54: DEBUG: add payload of len 88, next type 10
2005-01-31 15:56:54: DEBUG: add payload of len 16, next type 4
2005-01-31 15:56:54: DEBUG: add payload of len 128, next type 0
2005-01-31 15:56:54: DEBUG: HASH with:
2005-01-31 15:56:54: DEBUG:
f165fca7 c7d64915 bdd7f74e 89c2ca14 e9b1ddb5 0a00005c 00000001 00000001
02000028 01020401 07b18f9a 0000001c 01030000 80010001 80020e10 80040002
80050002 80030002 00000028 01030401 0d10894d 0000001c 01030000 80010001
80020e10 80040002 80050002 80030002 04000014 d298eaa0 a8d2b56e 564d817d
816323c8 00000084 1a9a548f 5cb12fc5 349c1372 6d2cc511 51029530 0e739921
f0d6371c 97075f8f 04aa195c 446f788d 5856a2fb 85e21369 ea0bbf44 a2aeea15
f9138f7b ab9a303f 861da44f 6d8b3599 bacac90f ac7ae542 5c32765f fb8b26aa
b0392050 7059cae9 d360eac8 4318e7d1 8beda674 a51bc003 559a4854 cdbdf9e7
66338448 1c01038f
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG: HASH computed:
2005-01-31 15:56:54: DEBUG:
1c2c3697 3fb6aa73 f0587484 9093486c e94d5f1a
2005-01-31 15:56:54: DEBUG: add payload of len 20, next type 1
2005-01-31 15:56:54: DEBUG: begin encryption.
2005-01-31 15:56:54: DEBUG: encryption(3des)
2005-01-31 15:56:54: DEBUG: pad length = 4
2005-01-31 15:56:54: DEBUG:
01000018 1c2c3697 3fb6aa73 f0587484 9093486c e94d5f1a 0a00005c 00000001
00000001 02000028 01020401 07b18f9a 0000001c 01030000 80010001 80020e10
80040002 80050002 80030002 00000028 01030401 0d10894d 0000001c 01030000
80010001 80020e10 80040002 80050002 80030002 04000014 d298eaa0 a8d2b56e
564d817d 816323c8 00000084 1a9a548f 5cb12fc5 349c1372 6d2cc511 51029530
0e739921 f0d6371c 97075f8f 04aa195c 446f788d 5856a2fb 85e21369 ea0bbf44
a2aeea15 f9138f7b ab9a303f 861da44f 6d8b3599 bacac90f ac7ae542 5c32765f
fb8b26aa b0392050 7059cae9 d360eac8 4318e7d1 8beda674 a51bc003 559a4854
cdbdf9e7 66338448 1c01038f 80c29e03
2005-01-31 15:56:54: DEBUG: encryption(3des)
2005-01-31 15:56:54: DEBUG: with key:
2005-01-31 15:56:54: DEBUG:
5a7c9253 3da7ec0c a029a28f 5d4bfbbb d0730ef7 5b24dc57
2005-01-31 15:56:54: DEBUG: encrypted payload by IV:
2005-01-31 15:56:54: DEBUG:
f0e213b8 d6423ed8
2005-01-31 15:56:54: DEBUG: save IV for next:
2005-01-31 15:56:54: DEBUG:
8facb279 a73879cc
2005-01-31 15:56:54: DEBUG: encrypted.
2005-01-31 15:56:54: DEBUG: 300 bytes from 192.168.2.5[500] to 192.168.2.3[500]
2005-01-31 15:56:54: DEBUG: sockname 192.168.2.5[500]
2005-01-31 15:56:54: DEBUG: send packet from 192.168.2.5[500]
2005-01-31 15:56:54: DEBUG: send packet to 192.168.2.3[500]
2005-01-31 15:56:54: DEBUG: src4 192.168.2.5[500]
2005-01-31 15:56:54: DEBUG: dst4 192.168.2.3[500]
2005-01-31 15:56:54: DEBUG: 1 times of 300 bytes message will be sent to 192.168.2.5[500]
2005-01-31 15:56:54: DEBUG:
1b3a78e3 adfafb1d c0e4d647 591c43f6 08102001 f165fca7 0000012c c59be1a6
93abf8bf cde86a3a e5e428f7 a00db733 43b4dd3e e97adf5b fa4f2609 978df62c
683dbfd2 cdf45e68 0621eb57 193b98cc 392a1bdc bee50fb1 e7e62fa6 4dd38e2c
8810a16b 54e1fdbc 8a130800 8721f2aa 600b7947 b9533309 3ee0bb33 d06de978
c7c44108 5c06d7ae d88639e4 024eb8aa b9fbf222 2920d647 d7589737 7b8f7232
23a84acc f3a340b8 9536ed1a 7a86ac0b 9bf35505 f101cd99 741ac02d 0ff91283
377fea8f d0ac3ae8 fdef3258 d817c2d3 80e4254a 36f1bc93 a0b3857b aa9e1dc7
8b98d62d 0c208041 d3def06e 1a290fab 567deff4 11ae9f98 dbdb0ec2 e8b61cfe
75a991e9 5429bb2b a3a98e56 be822247 b7d4afac d845f41f 88899909 8131b83e
d9289dca 8facb279 a73879cc
2005-01-31 15:56:54: DEBUG: resend phase2 packet 1b3a78e3adfafb1d:c0e4d647591c43f6:0000f165
2005-01-31 15:56:54: DEBUG: ===
2005-01-31 15:56:54: DEBUG: 60 bytes message received from 192.168.2.3[500] to 192.168.2.5[500]
2005-01-31 15:56:54: DEBUG:
1b3a78e3 adfafb1d c0e4d647 591c43f6 08102001 f165fca7 0000003c 7bffc9a8
da9a42f6 a6188903 a72cd735 d5cc4492 002a4ba7 15839dc3 a87a8972
2005-01-31 15:56:54: DEBUG: begin decryption.
2005-01-31 15:56:54: DEBUG: encryption(3des)
2005-01-31 15:56:54: DEBUG: IV was saved for next processing:
2005-01-31 15:56:54: DEBUG:
15839dc3 a87a8972
2005-01-31 15:56:54: DEBUG: encryption(3des)
2005-01-31 15:56:54: DEBUG: with key:
2005-01-31 15:56:54: DEBUG:
5a7c9253 3da7ec0c a029a28f 5d4bfbbb d0730ef7 5b24dc57
2005-01-31 15:56:54: DEBUG: decrypted payload by IV:
2005-01-31 15:56:54: DEBUG:
8facb279 a73879cc
2005-01-31 15:56:54: DEBUG: decrypted payload, but not trimed.
2005-01-31 15:56:54: DEBUG:
00000018 d3b6e22d 0c973dec 931eeb37 d8ba14e3 4c7102df 95d3e7bd f6faf607
2005-01-31 15:56:54: DEBUG: padding len=8
2005-01-31 15:56:54: DEBUG: skip to trim padding.
2005-01-31 15:56:54: DEBUG: decrypted.
2005-01-31 15:56:54: DEBUG:
1b3a78e3 adfafb1d c0e4d647 591c43f6 08102001 f165fca7 0000003c 00000018
d3b6e22d 0c973dec 931eeb37 d8ba14e3 4c7102df 95d3e7bd f6faf607
2005-01-31 15:56:54: DEBUG: begin.
2005-01-31 15:56:54: DEBUG: seen nptype=8(hash)
2005-01-31 15:56:54: DEBUG: succeed.
2005-01-31 15:56:54: DEBUG: HASH(3) validate:2005-01-31 15:56:54: DEBUG:
d3b6e22d 0c973dec 931eeb37 d8ba14e3 4c7102df
2005-01-31 15:56:54: DEBUG: HASH with:
2005-01-31 15:56:54: DEBUG:
00f165fc a7c7d649 15bdd7f7 4e89c2ca 14e9b1dd b5d298ea a0a8d2b5 6e564d81
7d816323 c8
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG: HASH computed:
2005-01-31 15:56:54: DEBUG:
d3b6e22d 0c973dec 931eeb37 d8ba14e3 4c7102df
2005-01-31 15:56:54: DEBUG: ===
2005-01-31 15:56:54: DEBUG: compute DH's shared.
2005-01-31 15:56:54: DEBUG:
ab12d518 48c49b88 b8b41d82 809e78ce 5324cefe 9392b981 97c8c1dc 972c21f3
37b65750 5f6a4f13 6a042fc6 69024994 dbc37801 37902186 e324ae60 d6c396ac
ac9bbd16 38b30565 48aa3baa bfc3430b 4355151d ac8b5b46 e19264f2 01994fd1
f5e44159 1d9b471c b3764b05 95c28afd 94f29a19 974bf59f b3f8ce9a 3119326c
2005-01-31 15:56:54: DEBUG: KEYMAT compute with
2005-01-31 15:56:54: DEBUG:
ab12d518 48c49b88 b8b41d82 809e78ce 5324cefe 9392b981 97c8c1dc 972c21f3
37b65750 5f6a4f13 6a042fc6 69024994 dbc37801 37902186 e324ae60 d6c396ac
ac9bbd16 38b30565 48aa3baa bfc3430b 4355151d ac8b5b46 e19264f2 01994fd1
f5e44159 1d9b471c b3764b05 95c28afd 94f29a19 974bf59f b3f8ce9a 3119326c
0207b18f 9ac7d649 15bdd7f7 4e89c2ca 14e9b1dd b5d298ea a0a8d2b5 6e564d81
7d816323 c8
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG: encklen=0 authklen=0
2005-01-31 15:56:54: DEBUG: generating 480 bits of key (dupkeymat=3)
2005-01-31 15:56:54: DEBUG: generating K1...K3 for KEYMAT.
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG:
3af874ac 08fe556c fddec368 1fb82bf8 e907261e 8ead23f4 ffbcd976 526f0569
7ebaa182 8f5de2ab e9c2c443 444c2847 f44aeb9b d9a16c3c 9c2ae6b8
2005-01-31 15:56:54: DEBUG: KEYMAT compute with
2005-01-31 15:56:54: DEBUG:
ab12d518 48c49b88 b8b41d82 809e78ce 5324cefe 9392b981 97c8c1dc 972c21f3
37b65750 5f6a4f13 6a042fc6 69024994 dbc37801 37902186 e324ae60 d6c396ac
ac9bbd16 38b30565 48aa3baa bfc3430b 4355151d ac8b5b46 e19264f2 01994fd1
f5e44159 1d9b471c b3764b05 95c28afd 94f29a19 974bf59f b3f8ce9a 3119326c
030d1089 4dc7d649 15bdd7f7 4e89c2ca 14e9b1dd b5d298ea a0a8d2b5 6e564d81
7d816323 c8
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG: encryption(3des)
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG: encklen=192 authklen=160
2005-01-31 15:56:54: DEBUG: generating 640 bits of key (dupkeymat=4)
2005-01-31 15:56:54: DEBUG: generating K1...K4 for KEYMAT.
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG:
71029e05 9f9f7fa9 1dc99080 7cb4a9ee b9bf2792 32deacc8 80596d90 ba7c0543
c1b40d8a f790d58e ccf66f87 653494e8 cbb3f725 c0f119ee f2f1e4e6 83d9e937
0a1fbbfa 40590ee8 8479816c 1ab9321f
2005-01-31 15:56:54: DEBUG: KEYMAT compute with
2005-01-31 15:56:54: DEBUG:
ab12d518 48c49b88 b8b41d82 809e78ce 5324cefe 9392b981 97c8c1dc 972c21f3
37b65750 5f6a4f13 6a042fc6 69024994 dbc37801 37902186 e324ae60 d6c396ac
ac9bbd16 38b30565 48aa3baa bfc3430b 4355151d ac8b5b46 e19264f2 01994fd1
f5e44159 1d9b471c b3764b05 95c28afd 94f29a19 974bf59f b3f8ce9a 3119326c
0200fea8 65c7d649 15bdd7f7 4e89c2ca 14e9b1dd b5d298ea a0a8d2b5 6e564d81
7d816323 c8
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG: encklen=0 authklen=0
2005-01-31 15:56:54: DEBUG: generating 480 bits of key (dupkeymat=3)
2005-01-31 15:56:54: DEBUG: generating K1...K3 for KEYMAT.
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG:
d1bc914f 7e79fd37 a72b8c46 a4326199 5ef4009c 72540f34 fba939c2 79232d22
1dada88a edebf394 42a181f6 6929749b d5a02847 7035ef42 50b8f77b
2005-01-31 15:56:54: DEBUG: KEYMAT compute with
2005-01-31 15:56:54: DEBUG:
ab12d518 48c49b88 b8b41d82 809e78ce 5324cefe 9392b981 97c8c1dc 972c21f3
37b65750 5f6a4f13 6a042fc6 69024994 dbc37801 37902186 e324ae60 d6c396ac
ac9bbd16 38b30565 48aa3baa bfc3430b 4355151d ac8b5b46 e19264f2 01994fd1
f5e44159 1d9b471c b3764b05 95c28afd 94f29a19 974bf59f b3f8ce9a 3119326c
0306aff7 8ac7d649 15bdd7f7 4e89c2ca 14e9b1dd b5d298ea a0a8d2b5 6e564d81
7d816323 c8
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG: encryption(3des)
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG: encklen=192 authklen=160
2005-01-31 15:56:54: DEBUG: generating 640 bits of key (dupkeymat=4)
2005-01-31 15:56:54: DEBUG: generating K1...K4 for KEYMAT.
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG:
ff237a88 c0438bc9 3e19ff2c 4b0c9a2a 2e7797d4 50de0b4e 50f124ac 808c9ec5
cf098100 ff24656f 3faaf2e0 ccc6323a 346d426e 8fba2cc3 b6c4f2e2 24231bf2
c636d43a 689cf0a7 b2d89724 58f43176
2005-01-31 15:56:54: DEBUG: KEYMAT computed.
2005-01-31 15:56:54: DEBUG: call pk_sendupdate
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG: call pfkey_send_update_nat
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 2, p->sadb_msg_satype: 2, seq: 369749501)
andi: libipsec/pfkey.c, pfkey_send_x1: (satype: 2, spi 2593108231)
2005-01-31 15:56:54: DEBUG: encryption(3des)
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG: call pfkey_send_update_nat
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 2, p->sadb_msg_satype: 3, seq: 369749501)
andi: libipsec/pfkey.c, pfkey_send_x1: (satype: 3, spi 1300828173)
2005-01-31 15:56:54: DEBUG: pfkey update sent.
2005-01-31 15:56:54: DEBUG: andi: pfkey.c, pk_sendadd: start
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG: call pfkey_send_add_nat
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 3, p->sadb_msg_satype: 2, seq: 369749501)
andi: libipsec/pfkey.c, pfkey_send_x1: (satype: 2, spi 1705573888)
2005-01-31 15:56:54: DEBUG: encryption(3des)
2005-01-31 15:56:54: DEBUG: hmac(hmac_sha1)
2005-01-31 15:56:54: DEBUG: call pfkey_send_add_nat
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 3, p->sadb_msg_satype: 3, seq: 369749501)
andi: libipsec/pfkey.c, pfkey_send_x1: (satype: 3, spi 2331488006)
2005-01-31 15:56:54: DEBUG: andi: pfkey.c, pk_sendadd: ende
2005-01-31 15:56:54: DEBUG: pfkey add sent.
2005-01-31 15:56:54: DEBUG: get pfkey UPDATE message
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 2)
2005-01-31 15:56:54: DEBUG: andi: pfkey.c, pk_recvupdate: start
2005-01-31 15:56:54: DEBUG: andi: in pfkey.c, pk_recvupdate: msg->sadb_msg_seq 369749501, msg->sadb_msg_type: UPDATE
2005-01-31 15:56:54: DEBUG: pfkey UPDATE succeeded: AH/Transport 192.168.2.3->192.168.2.5 spi=129077146(0x7b18f9a)
2005-01-31 15:56:54: INFO: IPsec-SA established: AH/Transport 192.168.2.3->192.168.2.5 spi=129077146(0x7b18f9a)
2005-01-31 15:56:54: DEBUG: get pfkey UPDATE message
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 2)
2005-01-31 15:56:54: DEBUG: andi: pfkey.c, pk_recvupdate: start
2005-01-31 15:56:54: DEBUG: andi: in pfkey.c, pk_recvupdate: msg->sadb_msg_seq 369749501, msg->sadb_msg_type: UPDATE
2005-01-31 15:56:54: DEBUG: pfkey UPDATE succeeded: ESP/Transport 192.168.2.3->192.168.2.5 spi=219187533(0xd10894d)
2005-01-31 15:56:54: INFO: IPsec-SA established: ESP/Transport 192.168.2.3->192.168.2.5 spi=219187533(0xd10894d)
2005-01-31 15:56:54: DEBUG: andi: pfkey.c, pk_recvupdate: ende
2005-01-31 15:56:54: DEBUG: ===
2005-01-31 15:56:54: DEBUG: get pfkey ADD message
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 3)
2005-01-31 15:56:54: DEBUG: andi: in pfkey.c, pk_recvadd: msg->sadb_msg_seq 369749501, msg->sadb_msg_type: ADD
2005-01-31 15:56:54: INFO: IPsec-SA established: AH/Transport 192.168.2.5->192.168.2.3 spi=16689253(0xfea865)
2005-01-31 15:56:54: DEBUG: ===
2005-01-31 15:56:54: DEBUG: get pfkey ADD message
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 3)
2005-01-31 15:56:54: DEBUG: andi: in pfkey.c, pk_recvadd: msg->sadb_msg_seq 369749501, msg->sadb_msg_type: ADD
2005-01-31 15:56:54: INFO: IPsec-SA established: ESP/Transport 192.168.2.5->192.168.2.3 spi=112195466(0x6aff78a)
2005-01-31 15:56:54: DEBUG: ===
2005-01-31 15:57:02: INFO: caught signal 2
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 9, p->sadb_msg_satype: 0, seq: 0)
2005-01-31 15:57:02: DEBUG: get pfkey FLUSH message
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 9)
2005-01-31 15:57:02: DEBUG: compute IV for phase2
2005-01-31 15:57:02: DEBUG: phase1 last IV:
2005-01-31 15:57:02: DEBUG:
d0b3dc22 1d31f2d0 f6cf0393
2005-01-31 15:57:02: DEBUG: hash(sha1)
2005-01-31 15:57:02: DEBUG: encryption(3des)
2005-01-31 15:57:02: DEBUG: phase2 IV computed:
2005-01-31 15:57:02: DEBUG:
4c579727 173cfcdf
2005-01-31 15:57:02: DEBUG: HASH with:
2005-01-31 15:57:02: DEBUG:
f6cf0393 00000010 00000001 02040001 07b18f9a
2005-01-31 15:57:02: DEBUG: hmac(hmac_sha1)
2005-01-31 15:57:02: DEBUG: HASH computed:
2005-01-31 15:57:02: DEBUG:
0715e057 78eb3389 9e5ad122 a1437de0 d17af863
2005-01-31 15:57:02: DEBUG: begin encryption.
2005-01-31 15:57:02: DEBUG: encryption(3des)
2005-01-31 15:57:02: DEBUG: pad length = 8
2005-01-31 15:57:02: DEBUG:
0c000018 0715e057 78eb3389 9e5ad122 a1437de0 d17af863 00000010 00000001
02040001 07b18f9a b3e7baec f4a9ef07
2005-01-31 15:57:02: DEBUG: encryption(3des)
2005-01-31 15:57:02: DEBUG: with key:
2005-01-31 15:57:02: DEBUG:
5a7c9253 3da7ec0c a029a28f 5d4bfbbb d0730ef7 5b24dc57
2005-01-31 15:57:02: DEBUG: encrypted payload by IV:
2005-01-31 15:57:02: DEBUG:
4c579727 173cfcdf
2005-01-31 15:57:02: DEBUG: save IV for next:
2005-01-31 15:57:02: DEBUG:
0f1fe112 9212600e
2005-01-31 15:57:02: DEBUG: encrypted.
2005-01-31 15:57:02: DEBUG: 76 bytes from 192.168.2.5[500] to 192.168.2.3[500]
2005-01-31 15:57:02: DEBUG: sockname 192.168.2.5[500]
2005-01-31 15:57:02: DEBUG: send packet from 192.168.2.5[500]
2005-01-31 15:57:02: DEBUG: send packet to 192.168.2.3[500]
2005-01-31 15:57:02: DEBUG: src4 192.168.2.5[500]
2005-01-31 15:57:02: DEBUG: dst4 192.168.2.3[500]
2005-01-31 15:57:02: DEBUG: 1 times of 76 bytes message will be sent to 192.168.2.5[500]
2005-01-31 15:57:02: DEBUG:
1b3a78e3 adfafb1d c0e4d647 591c43f6 08100501 f6cf0393 0000004c bd4fcd13
d7973d7c a9370d65 ed55caef 745583b1 33c4c9ff 541ae249 a7641bde adb4c1bf
319b79f4 0f1fe112 9212600e
2005-01-31 15:57:02: DEBUG: sendto Information delete.
2005-01-31 15:57:02: DEBUG: compute IV for phase2
2005-01-31 15:57:02: DEBUG: phase1 last IV:
2005-01-31 15:57:02: DEBUG:
d0b3dc22 1d31f2d0 c9a50cea
2005-01-31 15:57:02: DEBUG: hash(sha1)
2005-01-31 15:57:02: DEBUG: encryption(3des)
2005-01-31 15:57:02: DEBUG: phase2 IV computed:
2005-01-31 15:57:02: DEBUG:
b55ad535 fe76042b
2005-01-31 15:57:02: DEBUG: HASH with:
2005-01-31 15:57:02: DEBUG:
c9a50cea 00000010 00000001 03040001 0d10894d
2005-01-31 15:57:02: DEBUG: hmac(hmac_sha1)
2005-01-31 15:57:02: DEBUG: HASH computed:
2005-01-31 15:57:02: DEBUG:
be21e06e 14682bdf 5d12beda b6f08dd6 9c5439c2
2005-01-31 15:57:02: DEBUG: begin encryption.
2005-01-31 15:57:02: DEBUG: encryption(3des)
2005-01-31 15:57:02: DEBUG: pad length = 8
2005-01-31 15:57:02: DEBUG:
0c000018 be21e06e 14682bdf 5d12beda b6f08dd6 9c5439c2 00000010 00000001
03040001 0d10894d bf9aa6cd d5a7ac07
2005-01-31 15:57:02: DEBUG: encryption(3des)
2005-01-31 15:57:02: DEBUG: with key:
2005-01-31 15:57:02: DEBUG:
5a7c9253 3da7ec0c a029a28f 5d4bfbbb d0730ef7 5b24dc57
2005-01-31 15:57:02: DEBUG: encrypted payload by IV:
2005-01-31 15:57:02: DEBUG:
b55ad535 fe76042b
2005-01-31 15:57:02: DEBUG: save IV for next:
2005-01-31 15:57:02: DEBUG:
10aedf12 50d5d196
2005-01-31 15:57:02: DEBUG: encrypted.
2005-01-31 15:57:02: DEBUG: 76 bytes from 192.168.2.5[500] to 192.168.2.3[500]
2005-01-31 15:57:02: DEBUG: sockname 192.168.2.5[500]
2005-01-31 15:57:02: DEBUG: send packet from 192.168.2.5[500]
2005-01-31 15:57:02: DEBUG: send packet to 192.168.2.3[500]
2005-01-31 15:57:02: DEBUG: src4 192.168.2.5[500]
2005-01-31 15:57:02: DEBUG: dst4 192.168.2.3[500]
2005-01-31 15:57:02: DEBUG: 1 times of 76 bytes message will be sent to 192.168.2.5[500]
2005-01-31 15:57:02: DEBUG:
1b3a78e3 adfafb1d c0e4d647 591c43f6 08100501 c9a50cea 0000004c 461c5c4d
f2ca3b90 c73807da d84f253e e3acaa86 ec8d0dc2 be1ed5ea 19cc1e63 16ad963f
a9a566e4 10aedf12 50d5d196
2005-01-31 15:57:02: DEBUG: sendto Information delete.
2005-01-31 15:57:02: DEBUG: an undead schedule has been deleted.
2005-01-31 15:57:03: DEBUG: call pfkey_send_dump
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 10, p->sadb_msg_satype: 0, seq: 0)
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 10)
2005-01-31 15:57:03: DEBUG: compute IV for phase2
2005-01-31 15:57:03: DEBUG: phase1 last IV:
2005-01-31 15:57:03: DEBUG:
d0b3dc22 1d31f2d0 8e1131ff
2005-01-31 15:57:03: DEBUG: hash(sha1)
2005-01-31 15:57:03: DEBUG: encryption(3des)
2005-01-31 15:57:03: DEBUG: phase2 IV computed:
2005-01-31 15:57:03: DEBUG:
a32d8d7b f61e2114
2005-01-31 15:57:03: DEBUG: HASH with:
2005-01-31 15:57:03: DEBUG:
8e1131ff 0000001c 00000001 01100001 1b3a78e3 adfafb1d c0e4d647 591c43f6
2005-01-31 15:57:03: DEBUG: hmac(hmac_sha1)
2005-01-31 15:57:03: DEBUG: HASH computed:
2005-01-31 15:57:03: DEBUG:
cc70fba0 88f669db 3aa73457 8721f054 42e69e3a
2005-01-31 15:57:03: DEBUG: begin encryption.
2005-01-31 15:57:03: DEBUG: encryption(3des)
2005-01-31 15:57:03: DEBUG: pad length = 4
2005-01-31 15:57:03: DEBUG:
0c000018 cc70fba0 88f669db 3aa73457 8721f054 42e69e3a 0000001c 00000001
01100001 1b3a78e3 adfafb1d c0e4d647 591c43f6 a7aff503
2005-01-31 15:57:03: DEBUG: encryption(3des)
2005-01-31 15:57:03: DEBUG: with key:
2005-01-31 15:57:03: DEBUG:
5a7c9253 3da7ec0c a029a28f 5d4bfbbb d0730ef7 5b24dc57
2005-01-31 15:57:03: DEBUG: encrypted payload by IV:
2005-01-31 15:57:03: DEBUG:
a32d8d7b f61e2114
2005-01-31 15:57:03: DEBUG: save IV for next:
2005-01-31 15:57:03: DEBUG:
0b8f99d8 d092b040
2005-01-31 15:57:03: DEBUG: encrypted.
2005-01-31 15:57:03: DEBUG: 84 bytes from 192.168.2.5[500] to 192.168.2.3[500]
2005-01-31 15:57:03: DEBUG: sockname 192.168.2.5[500]
2005-01-31 15:57:03: DEBUG: send packet from 192.168.2.5[500]
2005-01-31 15:57:03: DEBUG: send packet to 192.168.2.3[500]
2005-01-31 15:57:03: DEBUG: src4 192.168.2.5[500]
2005-01-31 15:57:03: DEBUG: dst4 192.168.2.3[500]
2005-01-31 15:57:03: DEBUG: 1 times of 84 bytes message will be sent to 192.168.2.5[500]
2005-01-31 15:57:03: DEBUG:
1b3a78e3 adfafb1d c0e4d647 591c43f6 08100501 8e1131ff 00000054 fb2707d6
5c326720 9677a767 e8b8e127 8ce26bc4 69ee5837 717bbbed 6d13934a beefc296
1a04179e a9302874 f547249b 0b8f99d8 d092b040
2005-01-31 15:57:03: DEBUG: sendto Information delete.
2005-01-31 15:57:03: DEBUG: an undead schedule has been deleted.
2005-01-31 15:57:03: INFO: racoon shutdown
[root@litiusoft racoon]#
^ permalink raw reply [flat|nested] 11+ messages in thread* Re: Fw: [Bugme-new] [Bug 4138] New: ipsec with racoon in transport mode with esp and ah hangs (problem is in xfrm_state_add)
2005-01-31 10:54 ` Herbert Xu
2005-01-31 15:19 ` Andreas Unterluggauer
@ 2005-01-31 15:40 ` Andreas Unterluggauer
2005-01-31 21:11 ` Herbert Xu
2005-01-31 19:40 ` David S. Miller
2 siblings, 1 reply; 11+ messages in thread
From: Andreas Unterluggauer @ 2005-01-31 15:40 UTC (permalink / raw)
To: Herbert Xu; +Cc: netdev
[-- Attachment #1: Type: text/plain, Size: 392 bytes --]
Hi Herbert,
> for me it looks like racoon doesn't get the SADB_ACQUIRE message.
for the log-file in the last message I made a ping from the remote computer,
that's the reason why there is no SADB_ACQUIRE message.
now I have attached a log-file from a ping to the remote computer. there you
can see that racoon is getting one ACQUIRE message (and then generating two
SA's?)
cheers
andi
[-- Attachment #2: racoon2.log --]
[-- Type: text/x-log, Size: 48540 bytes --]
2005-01-31 16:29:35: INFO: @(#)ipsec-tools 0.5rc2 (http://ipsec-tools.sourceforge.net)
2005-01-31 16:29:35: INFO: @(#)This product linked OpenSSL 0.9.7a Feb 19 2003 (http://www.openssl.org/)
2005-01-31 16:29:35: DEBUG: call pfkey_send_register for AH
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 7, p->sadb_msg_satype: 2, seq: 0)
2005-01-31 16:29:36: DEBUG: call pfkey_send_register for ESP
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 7, p->sadb_msg_satype: 3, seq: 0)
2005-01-31 16:29:36: DEBUG: call pfkey_send_register for IPCOMP
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 7, p->sadb_msg_satype: 9, seq: 0)
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 18, p->sadb_msg_satype: 0, seq: 0)
2005-01-31 16:29:36: DEBUG: reading config file racoon.conf
2005-01-31 16:29:36: DEBUG: hmac(modp1024)
2005-01-31 16:29:36: DEBUG: compression algorithm can not be checked because sadb message doesn't support it.
2005-01-31 16:29:36: DEBUG: my interface: 127.0.0.1 (lo)
2005-01-31 16:29:36: DEBUG: my interface: 192.168.2.5 (eth0)
2005-01-31 16:29:36: DEBUG: configuring default isakmp port.
2005-01-31 16:29:36: DEBUG: 2 addrs are configured successfully
2005-01-31 16:29:36: INFO: 192.168.2.5[500] used as isakmp port (fd=6)
2005-01-31 16:29:36: INFO: 127.0.0.1[500] used as isakmp port (fd=7)
2005-01-31 16:29:36: DEBUG: get pfkey X_SPDDUMP message
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 18)
2005-01-31 16:29:36: DEBUG: get pfkey X_SPDDUMP message
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 18)
2005-01-31 16:29:36: DEBUG: sub:0xbff871a0: 192.168.2.5/32[0] 192.168.2.3/32[0] proto=any dir=out
2005-01-31 16:29:36: DEBUG: db :0x862a650: 192.168.2.3/32[0] 192.168.2.5/32[0] proto=any dir=in
2005-01-31 16:29:36: DEBUG: get pfkey X_SPDDUMP message
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 18)
2005-01-31 16:29:36: DEBUG: sub:0xbff871a0: 192.168.2.3/32[0] 192.168.2.5/32[0] proto=any dir=fwd
2005-01-31 16:29:36: DEBUG: db :0x862a650: 192.168.2.3/32[0] 192.168.2.5/32[0] proto=any dir=in
2005-01-31 16:29:36: DEBUG: sub:0xbff871a0: 192.168.2.3/32[0] 192.168.2.5/32[0] proto=any dir=fwd
2005-01-31 16:29:36: DEBUG: db :0x862a9a8: 192.168.2.5/32[0] 192.168.2.3/32[0] proto=any dir=out
2005-01-31 16:29:56: DEBUG: get pfkey ACQUIRE message
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 6)
2005-01-31 16:29:56: DEBUG: andi: pfkey.c, pk_recvacquire: start.
2005-01-31 16:29:56: DEBUG: suitable outbound SP found: 192.168.2.5/32[0] 192.168.2.3/32[0] proto=any dir=out.
2005-01-31 16:29:56: DEBUG: sub:0xbff87180: 192.168.2.3/32[0] 192.168.2.5/32[0] proto=any dir=in
2005-01-31 16:29:56: DEBUG: db :0x862a650: 192.168.2.3/32[0] 192.168.2.5/32[0] proto=any dir=in
2005-01-31 16:29:56: DEBUG: suitable inbound SP found: 192.168.2.3/32[0] 192.168.2.5/32[0] proto=any dir=in.
2005-01-31 16:29:56: INFO: andi: in pfkey.c, pk_recvacquire: n=0, iph2[n]->seq=2
2005-01-31 16:29:56: INFO: andi: spid=761, satype=3
2005-01-31 16:29:56: DEBUG: new acquire 192.168.2.5/32[0] 192.168.2.3/32[0] proto=any dir=out
2005-01-31 16:29:56: DEBUG: anonymous sainfo selected.
2005-01-31 16:29:56: DEBUG: (proto_id=AH spisize=4 spi=00000000 spi_p=00000000 encmode=Transport reqid=0:0)
2005-01-31 16:29:56: DEBUG: (trns_id=SHA authtype=hmac-sha)
2005-01-31 16:29:56: DEBUG: (proto_id=ESP spisize=4 spi=00000000 spi_p=00000000 encmode=Transport reqid=0:0)
2005-01-31 16:29:56: DEBUG: (trns_id=3DES encklen=0 authtype=hmac-sha)
2005-01-31 16:29:56: DEBUG: anonymous configuration selected for 192.168.2.3.
2005-01-31 16:29:56: INFO: IPsec-SA request for 192.168.2.3 queued due to no phase1 found.
2005-01-31 16:29:56: DEBUG: ===
2005-01-31 16:29:56: INFO: initiate new phase 1 negotiation: 192.168.2.5[500]<=>192.168.2.3[500]
2005-01-31 16:29:56: INFO: begin Identity Protection mode.
2005-01-31 16:29:56: DEBUG: new cookie:
6c9b61569b3a8f1e
2005-01-31 16:29:56: DEBUG: add payload of len 48, next type 0
2005-01-31 16:29:56: DEBUG: 80 bytes from 192.168.2.5[500] to 192.168.2.3[500]
2005-01-31 16:29:56: DEBUG: sockname 192.168.2.5[500]
2005-01-31 16:29:56: DEBUG: send packet from 192.168.2.5[500]
2005-01-31 16:29:56: DEBUG: send packet to 192.168.2.3[500]
2005-01-31 16:29:56: DEBUG: src4 192.168.2.5[500]
2005-01-31 16:29:56: DEBUG: dst4 192.168.2.3[500]
2005-01-31 16:29:56: DEBUG: 1 times of 80 bytes message will be sent to 192.168.2.5[500]
2005-01-31 16:29:56: DEBUG:
6c9b6156 9b3a8f1e 00000000 00000000 01100200 00000000 00000050 00000034
00000001 00000001 00000028 01010001 00000020 01010000 800b0001 800c1c20
80010005 80030001 80020002 80040002
2005-01-31 16:29:56: DEBUG: resend phase1 packet 6c9b61569b3a8f1e:0000000000000000
2005-01-31 16:29:56: DEBUG: ===
2005-01-31 16:29:56: DEBUG: 80 bytes message received from 192.168.2.3[500] to 192.168.2.5[500]
2005-01-31 16:29:56: DEBUG:
6c9b6156 9b3a8f1e be23bf6c 739326c6 01100200 00000000 00000050 00000034
00000001 00000001 00000028 01010001 00000020 01010000 800b0001 800c1c20
80010005 80030001 80020002 80040002
2005-01-31 16:29:56: DEBUG: begin.
2005-01-31 16:29:56: DEBUG: seen nptype=1(sa)
2005-01-31 16:29:56: DEBUG: succeed.
2005-01-31 16:29:56: DEBUG: total SA len=48
2005-01-31 16:29:56: DEBUG:
00000001 00000001 00000028 01010001 00000020 01010000 800b0001 800c1c20
80010005 80030001 80020002 80040002
2005-01-31 16:29:56: DEBUG: begin.
2005-01-31 16:29:56: DEBUG: seen nptype=2(prop)
2005-01-31 16:29:56: DEBUG: succeed.
2005-01-31 16:29:56: DEBUG: proposal #1 len=40
2005-01-31 16:29:56: DEBUG: begin.
2005-01-31 16:29:56: DEBUG: seen nptype=3(trns)
2005-01-31 16:29:56: DEBUG: succeed.
2005-01-31 16:29:56: DEBUG: transform #1 len=32
2005-01-31 16:29:56: DEBUG: type=Life Type, flag=0x8000, lorv=seconds
2005-01-31 16:29:56: DEBUG: type=Life Duration, flag=0x8000, lorv=7200
2005-01-31 16:29:56: DEBUG: type=Encryption Algorithm, flag=0x8000, lorv=3DES-CBC
2005-01-31 16:29:56: DEBUG: encryption(3des)
2005-01-31 16:29:56: DEBUG: type=Authentication Method, flag=0x8000, lorv=pre-shared key
2005-01-31 16:29:56: DEBUG: type=Hash Algorithm, flag=0x8000, lorv=SHA
2005-01-31 16:29:56: DEBUG: hash(sha1)
2005-01-31 16:29:56: DEBUG: type=Group Description, flag=0x8000, lorv=1024-bit MODP group
2005-01-31 16:29:56: DEBUG: hmac(modp1024)
2005-01-31 16:29:56: DEBUG: pair 1:
2005-01-31 16:29:56: DEBUG: 0x862b898: next=(nil) tnext=(nil)
2005-01-31 16:29:56: DEBUG: proposal #1: 1 transform
2005-01-31 16:29:56: DEBUG: prop#=1, prot-id=ISAKMP, spi-size=0, #trns=1
2005-01-31 16:29:56: DEBUG: trns#=1, trns-id=IKE
2005-01-31 16:29:56: DEBUG: type=Life Type, flag=0x8000, lorv=seconds
2005-01-31 16:29:56: DEBUG: type=Life Duration, flag=0x8000, lorv=7200
2005-01-31 16:29:56: DEBUG: type=Encryption Algorithm, flag=0x8000, lorv=3DES-CBC
2005-01-31 16:29:56: DEBUG: type=Authentication Method, flag=0x8000, lorv=pre-shared key
2005-01-31 16:29:56: DEBUG: type=Hash Algorithm, flag=0x8000, lorv=SHA
2005-01-31 16:29:56: DEBUG: type=Group Description, flag=0x8000, lorv=1024-bit MODP group
2005-01-31 16:29:56: DEBUG: Compared: DB:Peer
2005-01-31 16:29:56: DEBUG: (lifetime = 7200:7200)
2005-01-31 16:29:56: DEBUG: (lifebyte = 0:0)
2005-01-31 16:29:56: DEBUG: enctype = 3DES-CBC:3DES-CBC
2005-01-31 16:29:56: DEBUG: (encklen = 0:0)
2005-01-31 16:29:56: DEBUG: hashtype = SHA:SHA
2005-01-31 16:29:56: DEBUG: authmethod = pre-shared key:pre-shared key
2005-01-31 16:29:56: DEBUG: dh_group = 1024-bit MODP group:1024-bit MODP group
2005-01-31 16:29:56: DEBUG: an acceptable proposal found.
2005-01-31 16:29:56: DEBUG: hmac(modp1024)
2005-01-31 16:29:56: DEBUG: ===
2005-01-31 16:29:56: DEBUG: compute DH's private.
2005-01-31 16:29:56: DEBUG:
60f7d969 73f80465 2ae88214 af0716e9 4f7f3925 aa2963a3 b982ad97 5870191f
f4688758 763997f2 3d138df7 dcf765de d83b2b05 ca463837 5feda28b 8b884432
8f4581f3 3357caca 868d1595 49f8b049 802fe55a d75f7f2d e93d43f6 5174eee1
4cd02e4d f4a05f79 0de5add8 a6521e22 3ee09e57 c362b866 fb491411 17694feb
2005-01-31 16:29:56: DEBUG: compute DH's public.
2005-01-31 16:29:56: DEBUG:
3ea0f424 d7a63ac8 1ddfd00f 568f5241 76b06d85 f61391fb f673af15 27dd28e5
78990eec afdfb902 a7be1c40 fb1b14d3 79ce8030 34d67426 3cbff91b 05d4ac3a
1a647370 3521737a fa87dcd4 2ab4351d 5e007a59 d3deee78 635b5aa3 53621cc5
b4cd76d9 50595c1f b955e1ac 100c2d28 fb9c9174 e919e18e f72d3f58 192bb64f
2005-01-31 16:29:56: DEBUG: add payload of len 128, next type 10
2005-01-31 16:29:56: DEBUG: add payload of len 16, next type 0
2005-01-31 16:29:56: DEBUG: 180 bytes from 192.168.2.5[500] to 192.168.2.3[500]
2005-01-31 16:29:56: DEBUG: sockname 192.168.2.5[500]
2005-01-31 16:29:56: DEBUG: send packet from 192.168.2.5[500]
2005-01-31 16:29:56: DEBUG: send packet to 192.168.2.3[500]
2005-01-31 16:29:56: DEBUG: src4 192.168.2.5[500]
2005-01-31 16:29:56: DEBUG: dst4 192.168.2.3[500]
2005-01-31 16:29:56: DEBUG: 1 times of 180 bytes message will be sent to 192.168.2.5[500]
2005-01-31 16:29:56: DEBUG:
6c9b6156 9b3a8f1e be23bf6c 739326c6 04100200 00000000 000000b4 0a000084
3ea0f424 d7a63ac8 1ddfd00f 568f5241 76b06d85 f61391fb f673af15 27dd28e5
78990eec afdfb902 a7be1c40 fb1b14d3 79ce8030 34d67426 3cbff91b 05d4ac3a
1a647370 3521737a fa87dcd4 2ab4351d 5e007a59 d3deee78 635b5aa3 53621cc5
b4cd76d9 50595c1f b955e1ac 100c2d28 fb9c9174 e919e18e f72d3f58 192bb64f
00000014 ac4bbee1 f7b8f75e e83611f6 3644828e
2005-01-31 16:29:56: DEBUG: resend phase1 packet 6c9b61569b3a8f1e:be23bf6c739326c6
2005-01-31 16:29:56: DEBUG: ===
2005-01-31 16:29:56: DEBUG: 180 bytes message received from 192.168.2.3[500] to 192.168.2.5[500]
2005-01-31 16:29:56: DEBUG:
6c9b6156 9b3a8f1e be23bf6c 739326c6 04100200 00000000 000000b4 0a000084
1f3e1c57 1edef355 839a4bd6 b99446ea 4dc4ad07 c2d67d0d ccdf3d12 b0a76896
2f5e9e44 a1043eed e14a8030 79a5aa71 bef01b18 8278f9c4 66bc49b9 8fece4b3
7729072e 2e5ec10e 42bf9a80 e6e1ad9d 1fb6e238 7af196f8 98ea5e8d 148071e1
e3e6967f 20510103 a517d98d 9e13ba6d abc970f9 52b58329 32228ceb fff14a13
00000014 ece04032 83a5d64c e3443a73 c64531ad
2005-01-31 16:29:56: DEBUG: begin.
2005-01-31 16:29:56: DEBUG: seen nptype=4(ke)
2005-01-31 16:29:56: DEBUG: seen nptype=10(nonce)
2005-01-31 16:29:56: DEBUG: succeed.
2005-01-31 16:29:56: DEBUG: ===
2005-01-31 16:29:56: DEBUG: compute DH's shared.
2005-01-31 16:29:56: DEBUG:
c6e02605 557a12bd 6f587688 3f8e2625 0353d200 9399d55d ffa60a72 9dd42a0a
3b041f36 555e03aa ef68b6dc e1d443cc 5561e805 58ea2fe0 57f9a996 73dc50f8
59d5c0b6 6106e7c9 468984b1 379bd2f5 9373fbb0 62982f27 931ddabf ca385290
e007dcac 7f558199 afd055e5 fa41c33a 016ec19a fc00b62e dd039f20 c7e708e8
2005-01-31 16:29:56: DEBUG: the psk found.
2005-01-31 16:29:56: DEBUG: nonce 1: 2005-01-31 16:29:56: DEBUG:
ac4bbee1 f7b8f75e e83611f6 3644828e
2005-01-31 16:29:56: DEBUG: nonce 2: 2005-01-31 16:29:56: DEBUG:
ece04032 83a5d64c e3443a73 c64531ad
2005-01-31 16:29:56: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:56: DEBUG: SKEYID computed:
2005-01-31 16:29:56: DEBUG:
003bb469 b8f3a172 7b6f780c 5d393a0b 9329baeb
2005-01-31 16:29:56: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:56: DEBUG: SKEYID_d computed:
2005-01-31 16:29:56: DEBUG:
2a712766 e9180f0c 7cc89731 da3c10ad 7569efbc
2005-01-31 16:29:56: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:56: DEBUG: SKEYID_a computed:
2005-01-31 16:29:56: DEBUG:
bc9a9f36 417e3df8 394f1b76 75df267b 6d46a745
2005-01-31 16:29:56: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:56: DEBUG: SKEYID_e computed:
2005-01-31 16:29:56: DEBUG:
570541d4 6a6ad98d 26642038 da9bf06b d12e42c2
2005-01-31 16:29:56: DEBUG: encryption(3des)
2005-01-31 16:29:56: DEBUG: hash(sha1)
2005-01-31 16:29:56: DEBUG: len(SKEYID_e) < len(Ka) (20 < 24), generating long key (Ka = K1 | K2 | ...)
2005-01-31 16:29:56: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:56: DEBUG: compute intermediate encryption key K1
2005-01-31 16:29:56: DEBUG:
00
2005-01-31 16:29:56: DEBUG:
87950d10 c43b3cc4 5f8c71c1 0abde5ae 611d58e8
2005-01-31 16:29:56: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:56: DEBUG: compute intermediate encryption key K2
2005-01-31 16:29:56: DEBUG:
87950d10 c43b3cc4 5f8c71c1 0abde5ae 611d58e8
2005-01-31 16:29:56: DEBUG:
f3ac42fa 685f0c8d 18924d32 b7f52bb5 5326d31a
2005-01-31 16:29:56: DEBUG: final encryption key computed:
2005-01-31 16:29:56: DEBUG:
87950d10 c43b3cc4 5f8c71c1 0abde5ae 611d58e8 f3ac42fa
2005-01-31 16:29:56: DEBUG: hash(sha1)
2005-01-31 16:29:56: DEBUG: encryption(3des)
2005-01-31 16:29:56: DEBUG: IV computed:
2005-01-31 16:29:56: DEBUG:
29a8fe0b 68b537b7
2005-01-31 16:29:56: DEBUG: use ID type of IPv4_address
2005-01-31 16:29:56: DEBUG: HASH with:
2005-01-31 16:29:56: DEBUG:
3ea0f424 d7a63ac8 1ddfd00f 568f5241 76b06d85 f61391fb f673af15 27dd28e5
78990eec afdfb902 a7be1c40 fb1b14d3 79ce8030 34d67426 3cbff91b 05d4ac3a
1a647370 3521737a fa87dcd4 2ab4351d 5e007a59 d3deee78 635b5aa3 53621cc5
b4cd76d9 50595c1f b955e1ac 100c2d28 fb9c9174 e919e18e f72d3f58 192bb64f
1f3e1c57 1edef355 839a4bd6 b99446ea 4dc4ad07 c2d67d0d ccdf3d12 b0a76896
2f5e9e44 a1043eed e14a8030 79a5aa71 bef01b18 8278f9c4 66bc49b9 8fece4b3
7729072e 2e5ec10e 42bf9a80 e6e1ad9d 1fb6e238 7af196f8 98ea5e8d 148071e1
e3e6967f 20510103 a517d98d 9e13ba6d abc970f9 52b58329 32228ceb fff14a13
6c9b6156 9b3a8f1e be23bf6c 739326c6 00000001 00000001 00000028 01010001
00000020 01010000 800b0001 800c1c20 80010005 80030001 80020002 80040002
011101f4 c0a80205
2005-01-31 16:29:56: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:56: DEBUG: HASH computed:
2005-01-31 16:29:56: DEBUG:
39be6a33 3e209d6a 5ccd53f4 1b08ec90 36e5da92
2005-01-31 16:29:56: DEBUG: add payload of len 8, next type 8
2005-01-31 16:29:56: DEBUG: add payload of len 20, next type 0
2005-01-31 16:29:56: DEBUG: begin encryption.
2005-01-31 16:29:56: DEBUG: encryption(3des)
2005-01-31 16:29:56: DEBUG: pad length = 4
2005-01-31 16:29:56: DEBUG:
0800000c 011101f4 c0a80205 00000018 39be6a33 3e209d6a 5ccd53f4 1b08ec90
36e5da92 b9a68703
2005-01-31 16:29:56: DEBUG: encryption(3des)
2005-01-31 16:29:56: DEBUG: with key:
2005-01-31 16:29:56: DEBUG:
87950d10 c43b3cc4 5f8c71c1 0abde5ae 611d58e8 f3ac42fa
2005-01-31 16:29:56: DEBUG: encrypted payload by IV:
2005-01-31 16:29:56: DEBUG:
29a8fe0b 68b537b7
2005-01-31 16:29:56: DEBUG: save IV for next:
2005-01-31 16:29:56: DEBUG:
2b125b91 7a8b9ebd
2005-01-31 16:29:56: DEBUG: encrypted.
2005-01-31 16:29:56: DEBUG: 68 bytes from 192.168.2.5[500] to 192.168.2.3[500]
2005-01-31 16:29:56: DEBUG: sockname 192.168.2.5[500]
2005-01-31 16:29:56: DEBUG: send packet from 192.168.2.5[500]
2005-01-31 16:29:56: DEBUG: send packet to 192.168.2.3[500]
2005-01-31 16:29:56: DEBUG: src4 192.168.2.5[500]
2005-01-31 16:29:56: DEBUG: dst4 192.168.2.3[500]
2005-01-31 16:29:56: DEBUG: 1 times of 68 bytes message will be sent to 192.168.2.5[500]
2005-01-31 16:29:56: DEBUG:
6c9b6156 9b3a8f1e be23bf6c 739326c6 05100201 00000000 00000044 5ec981b2
fdd33b68 1544c131 964fe8e2 64df498c 597b4959 4d8972b0 7bfe3c9d 2b125b91
7a8b9ebd
2005-01-31 16:29:56: DEBUG: resend phase1 packet 6c9b61569b3a8f1e:be23bf6c739326c6
2005-01-31 16:29:56: DEBUG: ===
2005-01-31 16:29:56: DEBUG: 68 bytes message received from 192.168.2.3[500] to 192.168.2.5[500]
2005-01-31 16:29:56: DEBUG:
6c9b6156 9b3a8f1e be23bf6c 739326c6 05100201 00000000 00000044 65138087
62f9b823 ad529137 0ead6d2a b9159dc1 c1485032 89d39648 aba88945 ec7dbbee
437705e2
2005-01-31 16:29:56: DEBUG: begin decryption.
2005-01-31 16:29:56: DEBUG: encryption(3des)
2005-01-31 16:29:56: DEBUG: IV was saved for next processing:
2005-01-31 16:29:56: DEBUG:
ec7dbbee 437705e2
2005-01-31 16:29:56: DEBUG: encryption(3des)
2005-01-31 16:29:56: DEBUG: with key:
2005-01-31 16:29:56: DEBUG:
87950d10 c43b3cc4 5f8c71c1 0abde5ae 611d58e8 f3ac42fa
2005-01-31 16:29:56: DEBUG: decrypted payload by IV:
2005-01-31 16:29:56: DEBUG:
2b125b91 7a8b9ebd
2005-01-31 16:29:56: DEBUG: decrypted payload, but not trimed.
2005-01-31 16:29:56: DEBUG:
0800000c 011101f4 c0a80203 00000018 66059430 a61e698c 6a09b8c8 9c40bc2e
fd51bfb2 ebf9a403
2005-01-31 16:29:56: DEBUG: padding len=4
2005-01-31 16:29:56: DEBUG: skip to trim padding.
2005-01-31 16:29:56: DEBUG: decrypted.
2005-01-31 16:29:56: DEBUG:
6c9b6156 9b3a8f1e be23bf6c 739326c6 05100201 00000000 00000044 0800000c
011101f4 c0a80203 00000018 66059430 a61e698c 6a09b8c8 9c40bc2e fd51bfb2
ebf9a403
2005-01-31 16:29:56: DEBUG: begin.
2005-01-31 16:29:56: DEBUG: seen nptype=5(id)
2005-01-31 16:29:56: DEBUG: seen nptype=8(hash)
2005-01-31 16:29:56: DEBUG: succeed.
2005-01-31 16:29:56: DEBUG: HASH received:2005-01-31 16:29:56: DEBUG:
66059430 a61e698c 6a09b8c8 9c40bc2e fd51bfb2
2005-01-31 16:29:56: DEBUG: HASH with:
2005-01-31 16:29:56: DEBUG:
1f3e1c57 1edef355 839a4bd6 b99446ea 4dc4ad07 c2d67d0d ccdf3d12 b0a76896
2f5e9e44 a1043eed e14a8030 79a5aa71 bef01b18 8278f9c4 66bc49b9 8fece4b3
7729072e 2e5ec10e 42bf9a80 e6e1ad9d 1fb6e238 7af196f8 98ea5e8d 148071e1
e3e6967f 20510103 a517d98d 9e13ba6d abc970f9 52b58329 32228ceb fff14a13
3ea0f424 d7a63ac8 1ddfd00f 568f5241 76b06d85 f61391fb f673af15 27dd28e5
78990eec afdfb902 a7be1c40 fb1b14d3 79ce8030 34d67426 3cbff91b 05d4ac3a
1a647370 3521737a fa87dcd4 2ab4351d 5e007a59 d3deee78 635b5aa3 53621cc5
b4cd76d9 50595c1f b955e1ac 100c2d28 fb9c9174 e919e18e f72d3f58 192bb64f
be23bf6c 739326c6 6c9b6156 9b3a8f1e 00000001 00000001 00000028 01010001
00000020 01010000 800b0001 800c1c20 80010005 80030001 80020002 80040002
011101f4 c0a80203
2005-01-31 16:29:56: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:56: DEBUG: HASH computed:
2005-01-31 16:29:56: DEBUG:
66059430 a61e698c 6a09b8c8 9c40bc2e fd51bfb2
2005-01-31 16:29:56: DEBUG: HASH for PSK validated.
2005-01-31 16:29:56: DEBUG: peer's ID:2005-01-31 16:29:56: DEBUG:
011101f4 c0a80203
2005-01-31 16:29:56: DEBUG: ===
2005-01-31 16:29:56: DEBUG: compute IV for phase2
2005-01-31 16:29:56: DEBUG: phase1 last IV:
2005-01-31 16:29:56: DEBUG:
ec7dbbee 437705e2 89f3c58d
2005-01-31 16:29:56: DEBUG: hash(sha1)
2005-01-31 16:29:56: DEBUG: encryption(3des)
2005-01-31 16:29:56: DEBUG: phase2 IV computed:
2005-01-31 16:29:56: DEBUG:
3fa6b89d 32e87d86
2005-01-31 16:29:56: DEBUG: HASH with:
2005-01-31 16:29:56: DEBUG:
89f3c58d 0000001c 00000001 01106002 6c9b6156 9b3a8f1e be23bf6c 739326c6
2005-01-31 16:29:56: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:56: DEBUG: HASH computed:
2005-01-31 16:29:56: DEBUG:
7ed2c692 3fe16dd2 e46593a9 573d6a88 a510128d
2005-01-31 16:29:56: DEBUG: begin encryption.
2005-01-31 16:29:56: DEBUG: encryption(3des)
2005-01-31 16:29:56: DEBUG: pad length = 4
2005-01-31 16:29:56: DEBUG:
0b000018 7ed2c692 3fe16dd2 e46593a9 573d6a88 a510128d 0000001c 00000001
01106002 6c9b6156 9b3a8f1e be23bf6c 739326c6 d6ca9b03
2005-01-31 16:29:56: DEBUG: encryption(3des)
2005-01-31 16:29:56: DEBUG: with key:
2005-01-31 16:29:56: DEBUG:
87950d10 c43b3cc4 5f8c71c1 0abde5ae 611d58e8 f3ac42fa
2005-01-31 16:29:56: DEBUG: encrypted payload by IV:
2005-01-31 16:29:56: DEBUG:
3fa6b89d 32e87d86
2005-01-31 16:29:56: DEBUG: save IV for next:
2005-01-31 16:29:56: DEBUG:
e2bed52a dea2cc72
2005-01-31 16:29:56: DEBUG: encrypted.
2005-01-31 16:29:56: DEBUG: 84 bytes from 192.168.2.5[500] to 192.168.2.3[500]
2005-01-31 16:29:56: DEBUG: sockname 192.168.2.5[500]
2005-01-31 16:29:56: DEBUG: send packet from 192.168.2.5[500]
2005-01-31 16:29:56: DEBUG: send packet to 192.168.2.3[500]
2005-01-31 16:29:56: DEBUG: src4 192.168.2.5[500]
2005-01-31 16:29:56: DEBUG: dst4 192.168.2.3[500]
2005-01-31 16:29:56: DEBUG: 1 times of 84 bytes message will be sent to 192.168.2.5[500]
2005-01-31 16:29:56: DEBUG:
6c9b6156 9b3a8f1e be23bf6c 739326c6 08100501 89f3c58d 00000054 fbdc170e
36e67786 e622c244 8a878f1f b7fbbef4 4642efc4 9cf67fa5 da0495b1 3620a46d
52dea759 6d57815f 0ca417f8 e2bed52a dea2cc72
2005-01-31 16:29:56: DEBUG: sendto Information notify.
2005-01-31 16:29:56: INFO: ISAKMP-SA established 192.168.2.5[500]-192.168.2.3[500] spi:6c9b61569b3a8f1e:be23bf6c739326c6
2005-01-31 16:29:56: DEBUG: ===
2005-01-31 16:29:56: DEBUG: ===
2005-01-31 16:29:56: DEBUG: 84 bytes message received from 192.168.2.3[500] to 192.168.2.5[500]
2005-01-31 16:29:56: DEBUG:
6c9b6156 9b3a8f1e be23bf6c 739326c6 08100501 91e46358 00000054 40d05ae5
185847e2 164bcd53 5b6939e4 9a4acda0 dd2dd242 2e8d4672 a4ae182c bf25a4f2
10297d6b fb884828 0386e672 a66fc0a6 98ff04f7
2005-01-31 16:29:56: DEBUG: receive Information.
2005-01-31 16:29:56: DEBUG: compute IV for phase2
2005-01-31 16:29:56: DEBUG: phase1 last IV:
2005-01-31 16:29:56: DEBUG:
ec7dbbee 437705e2 91e46358
2005-01-31 16:29:56: DEBUG: hash(sha1)
2005-01-31 16:29:56: DEBUG: encryption(3des)
2005-01-31 16:29:56: DEBUG: phase2 IV computed:
2005-01-31 16:29:56: DEBUG:
f017f542 91fd6b14
2005-01-31 16:29:56: DEBUG: begin decryption.
2005-01-31 16:29:56: DEBUG: encryption(3des)
2005-01-31 16:29:56: DEBUG: IV was saved for next processing:
2005-01-31 16:29:56: DEBUG:
a66fc0a6 98ff04f7
2005-01-31 16:29:56: DEBUG: encryption(3des)
2005-01-31 16:29:56: DEBUG: with key:
2005-01-31 16:29:56: DEBUG:
87950d10 c43b3cc4 5f8c71c1 0abde5ae 611d58e8 f3ac42fa
2005-01-31 16:29:56: DEBUG: decrypted payload by IV:
2005-01-31 16:29:56: DEBUG:
f017f542 91fd6b14
2005-01-31 16:29:56: DEBUG: decrypted payload, but not trimed.
2005-01-31 16:29:56: DEBUG:
0b000018 94d8c097 8b1c2814 0426019c 931a39c2 c60f66cf 0000001c 00000001
01106002 6c9b6156 9b3a8f1e be23bf6c 739326c6 c6ebef03
2005-01-31 16:29:56: DEBUG: padding len=4
2005-01-31 16:29:56: DEBUG: skip to trim padding.
2005-01-31 16:29:56: DEBUG: decrypted.
2005-01-31 16:29:56: DEBUG:
6c9b6156 9b3a8f1e be23bf6c 739326c6 08100501 91e46358 00000054 0b000018
94d8c097 8b1c2814 0426019c 931a39c2 c60f66cf 0000001c 00000001 01106002
6c9b6156 9b3a8f1e be23bf6c 739326c6 c6ebef03
2005-01-31 16:29:56: DEBUG: HASH with:
2005-01-31 16:29:56: DEBUG:
91e46358 0000001c 00000001 01106002 6c9b6156 9b3a8f1e be23bf6c 739326c6
2005-01-31 16:29:56: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:56: DEBUG: HASH computed:
2005-01-31 16:29:56: DEBUG:
94d8c097 8b1c2814 0426019c 931a39c2 c60f66cf
2005-01-31 16:29:56: DEBUG: hash validated.
2005-01-31 16:29:56: DEBUG: begin.
2005-01-31 16:29:56: DEBUG: seen nptype=8(hash)
2005-01-31 16:29:56: DEBUG: seen nptype=11(notify)
2005-01-31 16:29:56: DEBUG: succeed.
2005-01-31 16:29:56: DEBUG: call pfkey_send_dump
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 10, p->sadb_msg_satype: 0, seq: 0)
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 10)
2005-01-31 16:29:56: DEBUG: notification message 24578:INITIAL-CONTACT, doi=1 proto_id=1 spi=6c9b61569b3a8f1e be23bf6c739326c6 (size=16).
2005-01-31 16:29:57: DEBUG: ===
2005-01-31 16:29:57: DEBUG: begin QUICK mode.
2005-01-31 16:29:57: INFO: initiate new phase 2 negotiation: 192.168.2.5[0]<=>192.168.2.3[0]
2005-01-31 16:29:57: DEBUG: compute IV for phase2
2005-01-31 16:29:57: DEBUG: phase1 last IV:
2005-01-31 16:29:57: DEBUG:
ec7dbbee 437705e2 c4e55a01
2005-01-31 16:29:57: DEBUG: hash(sha1)
2005-01-31 16:29:57: DEBUG: encryption(3des)
2005-01-31 16:29:57: DEBUG: phase2 IV computed:
2005-01-31 16:29:57: DEBUG:
73c9a87b d8ffd124
2005-01-31 16:29:57: DEBUG: andi: pfkey.c, pfkey_send_getspi (pr->proto_id: 2,iph2->seq: 2)
andi: libipsec/pfkey.c, pfkey_send_getspi: (satype: 2, seq: 2)
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 1, p->sadb_msg_satype: 2, seq: 2)
2005-01-31 16:29:57: DEBUG: pfkey GETSPI sent: AH/Transport 192.168.2.3->192.168.2.5
2005-01-31 16:29:57: DEBUG: andi: pfkey.c, pfkey_send_getspi (pr->proto_id: 3,iph2->seq: 2)
andi: libipsec/pfkey.c, pfkey_send_getspi: (satype: 3, seq: 2)
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 1, p->sadb_msg_satype: 3, seq: 2)
2005-01-31 16:29:57: DEBUG: pfkey GETSPI sent: ESP/Transport 192.168.2.3->192.168.2.5
2005-01-31 16:29:57: DEBUG: pfkey getspi sent.
2005-01-31 16:29:57: DEBUG: get pfkey GETSPI message
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 1)
2005-01-31 16:29:57: DEBUG: andi: pfkey.c, pk_recvgetspi: msg->sadb_msg_seq 2, msg->sadb_msg_type: GETSPI .
2005-01-31 16:29:57: DEBUG: pfkey GETSPI succeeded: AH/Transport 192.168.2.3->192.168.2.5 spi=123055453(0x755ad5d)
2005-01-31 16:29:57: DEBUG: get pfkey GETSPI message
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 1)
2005-01-31 16:29:57: DEBUG: andi: pfkey.c, pk_recvgetspi: msg->sadb_msg_seq 2, msg->sadb_msg_type: GETSPI .
2005-01-31 16:29:57: DEBUG: pfkey GETSPI succeeded: ESP/Transport 192.168.2.3->192.168.2.5 spi=145448323(0x8ab5d83)
2005-01-31 16:29:57: DEBUG: hmac(modp1024)
2005-01-31 16:29:57: DEBUG: hmac(modp1024)
2005-01-31 16:29:57: DEBUG: hmac(modp1024)
2005-01-31 16:29:57: DEBUG: hmac(modp1024)
2005-01-31 16:29:57: DEBUG: hmac(modp1024)
2005-01-31 16:29:57: DEBUG: compute DH's private.
2005-01-31 16:29:57: DEBUG:
60e938bd 0b04792b aa801034 9ada06ff 6717a03b 678f58e8 19435bfc 64545c75
dd0c94ee 53f94709 ef7d052b 2bfc4be4 8a6ad828 9f5a067b 6d03b2a3 0e158e1a
d9bb66d3 506d56d0 a8693f1d 1f77d9a0 ad3cd620 8a7b324d 4e88d63a 61fbd904
ff23138b defbb198 abc5addd 7d878ed3 c05ef310 8be0c616 b958d33f af9f90d1
2005-01-31 16:29:57: DEBUG: compute DH's public.
2005-01-31 16:29:57: DEBUG:
8c92aea1 d09291fd 7563aa3a 5ae7d084 647e501d c8076dd7 b1090266 e3597ca4
5c637f44 6cfa73d5 feb5e271 e0a9db3e 44194000 1eee073e c9eeae5d 028820c5
b8271142 d78a2532 fb2d89f5 eeece32a 46c53178 22c6b0ce 710169ef b64aa667
f94dbfa1 c750c75b 0b7c39f7 8c6d2f3a 067d7b3a d5297cef afc98c46 5fa8362e
2005-01-31 16:29:57: DEBUG: use local ID type IPv4_address
2005-01-31 16:29:57: DEBUG: use remote ID type IPv4_address
2005-01-31 16:29:57: DEBUG: IDci:2005-01-31 16:29:57: DEBUG:
01000000 c0a80205
2005-01-31 16:29:57: DEBUG: IDcr:2005-01-31 16:29:57: DEBUG:
01000000 c0a80203
2005-01-31 16:29:57: DEBUG: add payload of len 88, next type 10
2005-01-31 16:29:57: DEBUG: add payload of len 16, next type 4
2005-01-31 16:29:57: DEBUG: add payload of len 128, next type 0
2005-01-31 16:29:57: DEBUG: HASH with:
2005-01-31 16:29:57: DEBUG:
c4e55a01 0a00005c 00000001 00000001 02000028 01020401 0755ad5d 0000001c
01030000 80010001 80020e10 80040002 80050002 80030002 00000028 01030401
08ab5d83 0000001c 01030000 80010001 80020e10 80040002 80050002 80030002
04000014 e8df8a9c e76da0a2 8c0e0a3a 917629d1 00000084 8c92aea1 d09291fd
7563aa3a 5ae7d084 647e501d c8076dd7 b1090266 e3597ca4 5c637f44 6cfa73d5
feb5e271 e0a9db3e 44194000 1eee073e c9eeae5d 028820c5 b8271142 d78a2532
fb2d89f5 eeece32a 46c53178 22c6b0ce 710169ef b64aa667 f94dbfa1 c750c75b
0b7c39f7 8c6d2f3a 067d7b3a d5297cef afc98c46 5fa8362e
2005-01-31 16:29:57: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:57: DEBUG: HASH computed:
2005-01-31 16:29:57: DEBUG:
6d65b5de 76e1803e f81592ab caf886b4 be40871b
2005-01-31 16:29:57: DEBUG: add payload of len 20, next type 1
2005-01-31 16:29:57: DEBUG: begin encryption.
2005-01-31 16:29:57: DEBUG: encryption(3des)
2005-01-31 16:29:57: DEBUG: pad length = 4
2005-01-31 16:29:57: DEBUG:
01000018 6d65b5de 76e1803e f81592ab caf886b4 be40871b 0a00005c 00000001
00000001 02000028 01020401 0755ad5d 0000001c 01030000 80010001 80020e10
80040002 80050002 80030002 00000028 01030401 08ab5d83 0000001c 01030000
80010001 80020e10 80040002 80050002 80030002 04000014 e8df8a9c e76da0a2
8c0e0a3a 917629d1 00000084 8c92aea1 d09291fd 7563aa3a 5ae7d084 647e501d
c8076dd7 b1090266 e3597ca4 5c637f44 6cfa73d5 feb5e271 e0a9db3e 44194000
1eee073e c9eeae5d 028820c5 b8271142 d78a2532 fb2d89f5 eeece32a 46c53178
22c6b0ce 710169ef b64aa667 f94dbfa1 c750c75b 0b7c39f7 8c6d2f3a 067d7b3a
d5297cef afc98c46 5fa8362e b6f9b003
2005-01-31 16:29:57: DEBUG: encryption(3des)
2005-01-31 16:29:57: DEBUG: with key:
2005-01-31 16:29:57: DEBUG:
87950d10 c43b3cc4 5f8c71c1 0abde5ae 611d58e8 f3ac42fa
2005-01-31 16:29:57: DEBUG: encrypted payload by IV:
2005-01-31 16:29:57: DEBUG:
73c9a87b d8ffd124
2005-01-31 16:29:57: DEBUG: save IV for next:
2005-01-31 16:29:57: DEBUG:
a9c4ad5d d5b949ec
2005-01-31 16:29:57: DEBUG: encrypted.
2005-01-31 16:29:57: DEBUG: 300 bytes from 192.168.2.5[500] to 192.168.2.3[500]
2005-01-31 16:29:57: DEBUG: sockname 192.168.2.5[500]
2005-01-31 16:29:57: DEBUG: send packet from 192.168.2.5[500]
2005-01-31 16:29:57: DEBUG: send packet to 192.168.2.3[500]
2005-01-31 16:29:57: DEBUG: src4 192.168.2.5[500]
2005-01-31 16:29:57: DEBUG: dst4 192.168.2.3[500]
2005-01-31 16:29:57: DEBUG: 1 times of 300 bytes message will be sent to 192.168.2.5[500]
2005-01-31 16:29:57: DEBUG:
6c9b6156 9b3a8f1e be23bf6c 739326c6 08102001 c4e55a01 0000012c 41df7dab
e4a5ba24 4c1bd87f cafa84c1 09eef1b9 7915f73f dac141df bad2f8f1 2e7c7ce0
a4a64cb1 53d483cd b0d107d1 7f422ce6 6ba67296 75377a3d 508bf8fc fedfa848
9ad5aecd 33c07338 90b15431 2a840698 2009a171 bee12883 08ef50e8 11ae3b11
a9bc6e20 650eeb27 8d28fa6f 1b7f2fcb ef20ad59 f5db4d80 95a8f171 dbe1ac88
d83cfe31 8f36a813 98d11b5b ae1906d6 d1d67e15 4ebd391d 5d905ed0 0ae0f9b0
b937b75c 1d090898 2aa8ff25 1d88ab7d 9381a64d 7d75c60b 3b50af96 e0d0f6e2
3b1587bc 5d1015c0 192be00d 54e9b176 84433135 cf864421 d4b28693 725b7b04
83b3228a 9372e46b 6a217c5b 073041e2 3e3f08d3 694eecf8 f6164fc4 3422e096
a0e3b7c0 a9c4ad5d d5b949ec
2005-01-31 16:29:57: DEBUG: resend phase2 packet 6c9b61569b3a8f1e:be23bf6c739326c6:0000c4e5
2005-01-31 16:29:57: DEBUG: ===
2005-01-31 16:29:57: DEBUG: 300 bytes message received from 192.168.2.3[500] to 192.168.2.5[500]
2005-01-31 16:29:57: DEBUG:
6c9b6156 9b3a8f1e be23bf6c 739326c6 08102001 c4e55a01 0000012c ce32691f
8cf44de0 889917dc 08aa06c2 271d8aaf e7d246bc 3fa85a25 1151258e c6e81816
eb2246c9 29497519 aba00c21 17bedc93 b49612d4 39add46c 9d98d032 7f39c23c
3634f729 1dc8521b b92c01d0 51d10b64 8e30b188 b2972363 50d1df7d f5e64f08
68ae0a7e 0fc3ecd4 4cb39f26 8f2b72ba 4c81ee16 2981af19 6cb3f957 fd089b5e
532b2703 045b3f36 937c75eb 9c62b38c 20f4124a 06c0d87e ed1b603a a9f02576
fd006c7e cc6d1d84 65e9a178 becff6d3 14ba368b 804c993a b3433a63 a7f5aad7
578c915b 9c477a1c e2792319 ca6717ca 99fc475b 30bcce57 344cafa7 633ffb26
87637a41 348a4b52 9743f8f4 b7282b7f f573c1e8 acfce30e 5889a3da 820295cd
d212267c 4fa7b500 01a65080
2005-01-31 16:29:57: DEBUG: begin decryption.
2005-01-31 16:29:57: DEBUG: encryption(3des)
2005-01-31 16:29:57: DEBUG: IV was saved for next processing:
2005-01-31 16:29:57: DEBUG:
4fa7b500 01a65080
2005-01-31 16:29:57: DEBUG: encryption(3des)
2005-01-31 16:29:57: DEBUG: with key:
2005-01-31 16:29:57: DEBUG:
87950d10 c43b3cc4 5f8c71c1 0abde5ae 611d58e8 f3ac42fa
2005-01-31 16:29:57: DEBUG: decrypted payload by IV:
2005-01-31 16:29:57: DEBUG:
a9c4ad5d d5b949ec
2005-01-31 16:29:57: DEBUG: decrypted payload, but not trimed.
2005-01-31 16:29:57: DEBUG:
01000018 380ea746 6ae0ae2c 85ae1028 0de177dd 0d1641e4 0a00005c 00000001
00000001 02000028 01020401 0b02099a 0000001c 01030000 80010001 80020e10
80040002 80050002 80030002 00000028 01030401 0630e761 0000001c 01030000
80010001 80020e10 80040002 80050002 80030002 04000014 e96f29c8 6a300328
08b33126 f4cb4093 00000084 817cb76e 24ad3957 420f2480 3896017c 763c6b92
f22b6370 99afb7b9 00f322a8 d226f566 2eed3952 505c8c09 e6268dbe c6f2289a
eef9b5d1 cdd5fe02 edaeb785 9debe28e 7e18da13 9d8362f3 f0d1a6b0 3e8c2db8
75cf093a abd2aad9 0983bed7 8409dd12 e37dd22d 69589355 17e83f06 b7bd4e86
74130982 4515324b 7dfcd2d4 f0a28e03
2005-01-31 16:29:57: DEBUG: padding len=4
2005-01-31 16:29:57: DEBUG: skip to trim padding.
2005-01-31 16:29:57: DEBUG: decrypted.
2005-01-31 16:29:57: DEBUG:
6c9b6156 9b3a8f1e be23bf6c 739326c6 08102001 c4e55a01 0000012c 01000018
380ea746 6ae0ae2c 85ae1028 0de177dd 0d1641e4 0a00005c 00000001 00000001
02000028 01020401 0b02099a 0000001c 01030000 80010001 80020e10 80040002
80050002 80030002 00000028 01030401 0630e761 0000001c 01030000 80010001
80020e10 80040002 80050002 80030002 04000014 e96f29c8 6a300328 08b33126
f4cb4093 00000084 817cb76e 24ad3957 420f2480 3896017c 763c6b92 f22b6370
99afb7b9 00f322a8 d226f566 2eed3952 505c8c09 e6268dbe c6f2289a eef9b5d1
cdd5fe02 edaeb785 9debe28e 7e18da13 9d8362f3 f0d1a6b0 3e8c2db8 75cf093a
abd2aad9 0983bed7 8409dd12 e37dd22d 69589355 17e83f06 b7bd4e86 74130982
4515324b 7dfcd2d4 f0a28e03
2005-01-31 16:29:57: DEBUG: begin.
2005-01-31 16:29:57: DEBUG: seen nptype=8(hash)
2005-01-31 16:29:57: DEBUG: seen nptype=1(sa)
2005-01-31 16:29:57: DEBUG: seen nptype=10(nonce)
2005-01-31 16:29:57: DEBUG: seen nptype=4(ke)
2005-01-31 16:29:57: DEBUG: succeed.
2005-01-31 16:29:57: DEBUG: HASH allocated:hbuf->l=288 actual:tlen=260
2005-01-31 16:29:57: DEBUG: HASH(2) received:2005-01-31 16:29:57: DEBUG:
380ea746 6ae0ae2c 85ae1028 0de177dd 0d1641e4
2005-01-31 16:29:57: DEBUG: HASH with:
2005-01-31 16:29:57: DEBUG:
c4e55a01 e8df8a9c e76da0a2 8c0e0a3a 917629d1 0a00005c 00000001 00000001
02000028 01020401 0b02099a 0000001c 01030000 80010001 80020e10 80040002
80050002 80030002 00000028 01030401 0630e761 0000001c 01030000 80010001
80020e10 80040002 80050002 80030002 04000014 e96f29c8 6a300328 08b33126
f4cb4093 00000084 817cb76e 24ad3957 420f2480 3896017c 763c6b92 f22b6370
99afb7b9 00f322a8 d226f566 2eed3952 505c8c09 e6268dbe c6f2289a eef9b5d1
cdd5fe02 edaeb785 9debe28e 7e18da13 9d8362f3 f0d1a6b0 3e8c2db8 75cf093a
abd2aad9 0983bed7 8409dd12 e37dd22d 69589355 17e83f06 b7bd4e86 74130982
4515324b 7dfcd2d4
2005-01-31 16:29:57: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:57: DEBUG: HASH computed:
2005-01-31 16:29:57: DEBUG:
380ea746 6ae0ae2c 85ae1028 0de177dd 0d1641e4
2005-01-31 16:29:57: DEBUG: total SA len=88
2005-01-31 16:29:57: DEBUG:
00000001 00000001 02000028 01020401 0755ad5d 0000001c 01030000 80010001
80020e10 80040002 80050002 80030002 00000028 01030401 08ab5d83 0000001c
01030000 80010001 80020e10 80040002 80050002 80030002
2005-01-31 16:29:57: DEBUG: begin.
2005-01-31 16:29:57: DEBUG: seen nptype=2(prop)
2005-01-31 16:29:57: DEBUG: seen nptype=2(prop)
2005-01-31 16:29:57: DEBUG: succeed.
2005-01-31 16:29:57: DEBUG: proposal #1 len=40
2005-01-31 16:29:57: DEBUG: begin.
2005-01-31 16:29:57: DEBUG: seen nptype=3(trns)
2005-01-31 16:29:57: DEBUG: succeed.
2005-01-31 16:29:57: DEBUG: transform #1 len=28
2005-01-31 16:29:57: DEBUG: type=SA Life Type, flag=0x8000, lorv=seconds
2005-01-31 16:29:57: DEBUG: type=SA Life Duration, flag=0x8000, lorv=3600
2005-01-31 16:29:57: DEBUG: life duration was in TLV.
2005-01-31 16:29:57: DEBUG: type=Encryption Mode, flag=0x8000, lorv=Transport
2005-01-31 16:29:57: DEBUG: type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha
2005-01-31 16:29:57: DEBUG: type=Group Description, flag=0x8000, lorv=2
2005-01-31 16:29:57: DEBUG: hmac(modp1024)
2005-01-31 16:29:57: DEBUG: proposal #1 len=40
2005-01-31 16:29:57: DEBUG: begin.
2005-01-31 16:29:57: DEBUG: seen nptype=3(trns)
2005-01-31 16:29:57: DEBUG: succeed.
2005-01-31 16:29:57: DEBUG: transform #1 len=28
2005-01-31 16:29:57: DEBUG: type=SA Life Type, flag=0x8000, lorv=seconds
2005-01-31 16:29:57: DEBUG: type=SA Life Duration, flag=0x8000, lorv=3600
2005-01-31 16:29:57: DEBUG: life duration was in TLV.
2005-01-31 16:29:57: DEBUG: type=Encryption Mode, flag=0x8000, lorv=Transport
2005-01-31 16:29:57: DEBUG: type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha
2005-01-31 16:29:57: DEBUG: type=Group Description, flag=0x8000, lorv=2
2005-01-31 16:29:57: DEBUG: hmac(modp1024)
2005-01-31 16:29:57: DEBUG: pair 1:
2005-01-31 16:29:57: DEBUG: 0x862c218: next=0x862b3e0 tnext=(nil)
2005-01-31 16:29:57: DEBUG: 0x862b3e0: next=(nil) tnext=(nil)
2005-01-31 16:29:57: DEBUG: proposal #1: 2 transform
2005-01-31 16:29:57: DEBUG: total SA len=88
2005-01-31 16:29:57: DEBUG:
00000001 00000001 02000028 01020401 0b02099a 0000001c 01030000 80010001
80020e10 80040002 80050002 80030002 00000028 01030401 0630e761 0000001c
01030000 80010001 80020e10 80040002 80050002 80030002
2005-01-31 16:29:57: DEBUG: begin.
2005-01-31 16:29:57: DEBUG: seen nptype=2(prop)
2005-01-31 16:29:57: DEBUG: seen nptype=2(prop)
2005-01-31 16:29:57: DEBUG: succeed.
2005-01-31 16:29:57: DEBUG: proposal #1 len=40
2005-01-31 16:29:57: DEBUG: begin.
2005-01-31 16:29:57: DEBUG: seen nptype=3(trns)
2005-01-31 16:29:57: DEBUG: succeed.
2005-01-31 16:29:57: DEBUG: transform #1 len=28
2005-01-31 16:29:57: DEBUG: type=SA Life Type, flag=0x8000, lorv=seconds
2005-01-31 16:29:57: DEBUG: type=SA Life Duration, flag=0x8000, lorv=3600
2005-01-31 16:29:57: DEBUG: life duration was in TLV.
2005-01-31 16:29:57: DEBUG: type=Encryption Mode, flag=0x8000, lorv=Transport
2005-01-31 16:29:57: DEBUG: type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha
2005-01-31 16:29:57: DEBUG: type=Group Description, flag=0x8000, lorv=2
2005-01-31 16:29:57: DEBUG: hmac(modp1024)
2005-01-31 16:29:57: DEBUG: proposal #1 len=40
2005-01-31 16:29:57: DEBUG: begin.
2005-01-31 16:29:57: DEBUG: seen nptype=3(trns)
2005-01-31 16:29:57: DEBUG: succeed.
2005-01-31 16:29:57: DEBUG: transform #1 len=28
2005-01-31 16:29:57: DEBUG: type=SA Life Type, flag=0x8000, lorv=seconds
2005-01-31 16:29:57: DEBUG: type=SA Life Duration, flag=0x8000, lorv=3600
2005-01-31 16:29:57: DEBUG: life duration was in TLV.
2005-01-31 16:29:57: DEBUG: type=Encryption Mode, flag=0x8000, lorv=Transport
2005-01-31 16:29:57: DEBUG: type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha
2005-01-31 16:29:57: DEBUG: type=Group Description, flag=0x8000, lorv=2
2005-01-31 16:29:57: DEBUG: hmac(modp1024)
2005-01-31 16:29:57: DEBUG: pair 1:
2005-01-31 16:29:57: DEBUG: 0x862b450: next=0x862b5a0 tnext=(nil)
2005-01-31 16:29:57: DEBUG: 0x862b5a0: next=(nil) tnext=(nil)
2005-01-31 16:29:57: DEBUG: proposal #1: 2 transform
2005-01-31 16:29:57: DEBUG: begin compare proposals.
2005-01-31 16:29:57: DEBUG: pair[1]: 0x862b450
2005-01-31 16:29:57: DEBUG: 0x862b450: next=0x862b5a0 tnext=(nil)
2005-01-31 16:29:57: DEBUG: 0x862b5a0: next=(nil) tnext=(nil)
2005-01-31 16:29:57: DEBUG: prop#=1 prot-id=AH spi-size=4 #trns=1 trns#=1 trns-id=SHA
2005-01-31 16:29:57: DEBUG: type=SA Life Type, flag=0x8000, lorv=seconds
2005-01-31 16:29:57: DEBUG: type=SA Life Duration, flag=0x8000, lorv=3600
2005-01-31 16:29:57: DEBUG: type=Encryption Mode, flag=0x8000, lorv=Transport
2005-01-31 16:29:57: DEBUG: type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha
2005-01-31 16:29:57: DEBUG: type=Group Description, flag=0x8000, lorv=2
2005-01-31 16:29:57: DEBUG: prop#=1 prot-id=ESP spi-size=4 #trns=1 trns#=1 trns-id=3DES
2005-01-31 16:29:57: DEBUG: type=SA Life Type, flag=0x8000, lorv=seconds
2005-01-31 16:29:57: DEBUG: type=SA Life Duration, flag=0x8000, lorv=3600
2005-01-31 16:29:57: DEBUG: type=Encryption Mode, flag=0x8000, lorv=Transport
2005-01-31 16:29:57: DEBUG: type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha
2005-01-31 16:29:57: DEBUG: type=Group Description, flag=0x8000, lorv=2
2005-01-31 16:29:57: DEBUG: peer's single bundle:
2005-01-31 16:29:57: DEBUG: (proto_id=AH spisize=4 spi=0b02099a spi_p=00000000 encmode=Transport reqid=0:0)
2005-01-31 16:29:57: DEBUG: (trns_id=SHA authtype=hmac-sha)
2005-01-31 16:29:57: DEBUG: (proto_id=ESP spisize=4 spi=0630e761 spi_p=00000000 encmode=Transport reqid=0:0)
2005-01-31 16:29:57: DEBUG: (trns_id=3DES encklen=0 authtype=hmac-sha)
2005-01-31 16:29:57: DEBUG: my single bundle:
2005-01-31 16:29:57: DEBUG: (proto_id=AH spisize=4 spi=0755ad5d spi_p=00000000 encmode=Transport reqid=0:0)
2005-01-31 16:29:57: DEBUG: (trns_id=SHA authtype=hmac-sha)
2005-01-31 16:29:57: DEBUG: (proto_id=ESP spisize=4 spi=08ab5d83 spi_p=00000000 encmode=Transport reqid=0:0)
2005-01-31 16:29:57: DEBUG: (trns_id=3DES encklen=0 authtype=hmac-sha)
2005-01-31 16:29:57: DEBUG: matched
2005-01-31 16:29:57: DEBUG: ===
2005-01-31 16:29:57: DEBUG: HASH(3) generate
2005-01-31 16:29:57: DEBUG: HASH with:
2005-01-31 16:29:57: DEBUG:
00c4e55a 01e8df8a 9ce76da0 a28c0e0a 3a917629 d1e96f29 c86a3003 2808b331
26f4cb40 93
2005-01-31 16:29:57: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:57: DEBUG: HASH computed:
2005-01-31 16:29:57: DEBUG:
8e1078c6 e27f5b7c 417232af 17ea670a 6209476f
2005-01-31 16:29:57: DEBUG: add payload of len 20, next type 0
2005-01-31 16:29:57: DEBUG: begin encryption.
2005-01-31 16:29:57: DEBUG: encryption(3des)
2005-01-31 16:29:57: DEBUG: pad length = 8
2005-01-31 16:29:57: DEBUG:
00000018 8e1078c6 e27f5b7c 417232af 17ea670a 6209476f e9e0ac88 a1fc8407
2005-01-31 16:29:57: DEBUG: encryption(3des)
2005-01-31 16:29:57: DEBUG: with key:
2005-01-31 16:29:57: DEBUG:
87950d10 c43b3cc4 5f8c71c1 0abde5ae 611d58e8 f3ac42fa
2005-01-31 16:29:57: DEBUG: encrypted payload by IV:
2005-01-31 16:29:57: DEBUG:
4fa7b500 01a65080
2005-01-31 16:29:57: DEBUG: save IV for next:
2005-01-31 16:29:57: DEBUG:
55362eb5 6175fc2f
2005-01-31 16:29:57: DEBUG: encrypted.
2005-01-31 16:29:57: DEBUG: 60 bytes from 192.168.2.5[500] to 192.168.2.3[500]
2005-01-31 16:29:57: DEBUG: sockname 192.168.2.5[500]
2005-01-31 16:29:57: DEBUG: send packet from 192.168.2.5[500]
2005-01-31 16:29:57: DEBUG: send packet to 192.168.2.3[500]
2005-01-31 16:29:57: DEBUG: src4 192.168.2.5[500]
2005-01-31 16:29:57: DEBUG: dst4 192.168.2.3[500]
2005-01-31 16:29:57: DEBUG: 1 times of 60 bytes message will be sent to 192.168.2.5[500]
2005-01-31 16:29:57: DEBUG:
6c9b6156 9b3a8f1e be23bf6c 739326c6 08102001 c4e55a01 0000003c de07f7dc
b98f7a0d a5dca431 f62059eb d2cf9943 2093a977 55362eb5 6175fc2f
2005-01-31 16:29:57: DEBUG: compute DH's shared.
2005-01-31 16:29:57: DEBUG:
9772727f d7c3077d cbc3a754 c01a6739 742445a1 ee69dd0e 401fcdca 387680c8
20d00459 1707ff44 f12623ad 01a23d78 eda3f7c2 c4194025 51dd8e3d 2c6dc226
d1e301b8 f646791e eceb475c 8bef4fa9 abb1fa9e 51240206 3a215462 6e8ccc48
5bedbcef 21a78faa d9619891 101d7132 ec61dac8 8ccd5ce4 093fbefa 04eb288c
2005-01-31 16:29:57: DEBUG: KEYMAT compute with
2005-01-31 16:29:57: DEBUG:
9772727f d7c3077d cbc3a754 c01a6739 742445a1 ee69dd0e 401fcdca 387680c8
20d00459 1707ff44 f12623ad 01a23d78 eda3f7c2 c4194025 51dd8e3d 2c6dc226
d1e301b8 f646791e eceb475c 8bef4fa9 abb1fa9e 51240206 3a215462 6e8ccc48
5bedbcef 21a78faa d9619891 101d7132 ec61dac8 8ccd5ce4 093fbefa 04eb288c
020755ad 5de8df8a 9ce76da0 a28c0e0a 3a917629 d1e96f29 c86a3003 2808b331
26f4cb40 93
2005-01-31 16:29:57: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:57: DEBUG: encklen=0 authklen=0
2005-01-31 16:29:57: DEBUG: generating 480 bits of key (dupkeymat=3)
2005-01-31 16:29:57: DEBUG: generating K1...K3 for KEYMAT.
2005-01-31 16:29:57: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:57: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:57: DEBUG:
77ea373c ab2de6a9 e6579312 cf676dbf 21c8bb96 ebace6a6 b1166bf6 54e1cf78
1d21fda6 0ddc751d f03bdb9a 291fe5e4 ca2b43f3 4f325344 184a9142
2005-01-31 16:29:57: DEBUG: KEYMAT compute with
2005-01-31 16:29:57: DEBUG:
9772727f d7c3077d cbc3a754 c01a6739 742445a1 ee69dd0e 401fcdca 387680c8
20d00459 1707ff44 f12623ad 01a23d78 eda3f7c2 c4194025 51dd8e3d 2c6dc226
d1e301b8 f646791e eceb475c 8bef4fa9 abb1fa9e 51240206 3a215462 6e8ccc48
5bedbcef 21a78faa d9619891 101d7132 ec61dac8 8ccd5ce4 093fbefa 04eb288c
0308ab5d 83e8df8a 9ce76da0 a28c0e0a 3a917629 d1e96f29 c86a3003 2808b331
26f4cb40 93
2005-01-31 16:29:57: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:57: DEBUG: encryption(3des)
2005-01-31 16:29:57: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:57: DEBUG: encklen=192 authklen=160
2005-01-31 16:29:57: DEBUG: generating 640 bits of key (dupkeymat=4)
2005-01-31 16:29:57: DEBUG: generating K1...K4 for KEYMAT.
2005-01-31 16:29:57: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:57: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:57: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:57: DEBUG:
e0192628 3eaf975f b16ae699 19fe9e6c dccbf969 08579f54 4405a8f2 89edc409
67d3dd51 982e56c9 193ea791 d4f8ac73 ea9839b3 07999674 361ac816 a212efae
4cabfcb3 ee977bc6 dba0fc02 6b6e4448
2005-01-31 16:29:57: DEBUG: KEYMAT compute with
2005-01-31 16:29:57: DEBUG:
9772727f d7c3077d cbc3a754 c01a6739 742445a1 ee69dd0e 401fcdca 387680c8
20d00459 1707ff44 f12623ad 01a23d78 eda3f7c2 c4194025 51dd8e3d 2c6dc226
d1e301b8 f646791e eceb475c 8bef4fa9 abb1fa9e 51240206 3a215462 6e8ccc48
5bedbcef 21a78faa d9619891 101d7132 ec61dac8 8ccd5ce4 093fbefa 04eb288c
020b0209 9ae8df8a 9ce76da0 a28c0e0a 3a917629 d1e96f29 c86a3003 2808b331
26f4cb40 93
2005-01-31 16:29:57: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:57: DEBUG: encklen=0 authklen=0
2005-01-31 16:29:57: DEBUG: generating 480 bits of key (dupkeymat=3)
2005-01-31 16:29:57: DEBUG: generating K1...K3 for KEYMAT.
2005-01-31 16:29:57: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:57: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:57: DEBUG:
cb630d9b 01c67612 34237d02 1b0282ce 678cb71e 6bf59eeb d6346e54 433db1cf
342b19a1 106ce650 80e76fb1 b717c3b2 fbde4a06 17dc6cb4 7e1bf87a
2005-01-31 16:29:57: DEBUG: KEYMAT compute with
2005-01-31 16:29:57: DEBUG:
9772727f d7c3077d cbc3a754 c01a6739 742445a1 ee69dd0e 401fcdca 387680c8
20d00459 1707ff44 f12623ad 01a23d78 eda3f7c2 c4194025 51dd8e3d 2c6dc226
d1e301b8 f646791e eceb475c 8bef4fa9 abb1fa9e 51240206 3a215462 6e8ccc48
5bedbcef 21a78faa d9619891 101d7132 ec61dac8 8ccd5ce4 093fbefa 04eb288c
030630e7 61e8df8a 9ce76da0 a28c0e0a 3a917629 d1e96f29 c86a3003 2808b331
26f4cb40 93
2005-01-31 16:29:57: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:57: DEBUG: encryption(3des)
2005-01-31 16:29:57: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:57: DEBUG: encklen=192 authklen=160
2005-01-31 16:29:57: DEBUG: generating 640 bits of key (dupkeymat=4)
2005-01-31 16:29:57: DEBUG: generating K1...K4 for KEYMAT.
2005-01-31 16:29:57: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:57: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:57: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:57: DEBUG:
bba49802 a5c4b1f9 ea8acbca 89e71d58 0ccc98de 3c058484 72d3f62e 4610ea03
7c3b16b8 55510b1b 0ca537df e0628f09 deb7f29e 25c72ca6 47c2ec40 abe1120e
6757f6ba 8142b446 9ac07c04 138221c0
2005-01-31 16:29:57: DEBUG: KEYMAT computed.
2005-01-31 16:29:57: DEBUG: call pk_sendupdate
2005-01-31 16:29:57: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:57: DEBUG: call pfkey_send_update_nat
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 2, p->sadb_msg_satype: 2, seq: 2)
andi: libipsec/pfkey.c, pfkey_send_x1: (satype: 2, spi 1571640583)
2005-01-31 16:29:58: DEBUG: encryption(3des)
2005-01-31 16:29:58: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:58: DEBUG: call pfkey_send_update_nat
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 2, p->sadb_msg_satype: 3, seq: 2)
andi: libipsec/pfkey.c, pfkey_send_x1: (satype: 3, spi 2203953928)
2005-01-31 16:29:58: DEBUG: pfkey update sent.
2005-01-31 16:29:58: DEBUG: andi: pfkey.c, pk_sendadd: start
2005-01-31 16:29:58: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:58: DEBUG: call pfkey_send_add_nat
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 3, p->sadb_msg_satype: 2, seq: 2)
andi: libipsec/pfkey.c, pfkey_send_x1: (satype: 2, spi 2584281611)
2005-01-31 16:29:58: DEBUG: encryption(3des)
2005-01-31 16:29:58: DEBUG: hmac(hmac_sha1)
2005-01-31 16:29:58: DEBUG: call pfkey_send_add_nat
andi: libipsec/pfkey.c, pfkey_setsadbmsg: (p->type: 3, p->sadb_msg_satype: 3, seq: 2)
andi: libipsec/pfkey.c, pfkey_send_x1: (satype: 3, spi 1642541062)
2005-01-31 16:29:58: DEBUG: andi: pfkey.c, pk_sendadd: ende
2005-01-31 16:29:58: DEBUG: pfkey add sent.
2005-01-31 16:29:58: DEBUG: get pfkey UPDATE message
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 2)
2005-01-31 16:29:58: DEBUG: andi: pfkey.c, pk_recvupdate: start
2005-01-31 16:29:58: DEBUG: andi: in pfkey.c, pk_recvupdate: msg->sadb_msg_seq 2, msg->sadb_msg_type: UPDATE
2005-01-31 16:29:58: DEBUG: pfkey UPDATE succeeded: AH/Transport 192.168.2.3->192.168.2.5 spi=123055453(0x755ad5d)
2005-01-31 16:29:58: INFO: IPsec-SA established: AH/Transport 192.168.2.3->192.168.2.5 spi=123055453(0x755ad5d)
2005-01-31 16:29:58: DEBUG: get pfkey UPDATE message
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 2)
2005-01-31 16:29:58: DEBUG: andi: pfkey.c, pk_recvupdate: start
2005-01-31 16:29:58: DEBUG: andi: in pfkey.c, pk_recvupdate: msg->sadb_msg_seq 2, msg->sadb_msg_type: UPDATE
2005-01-31 16:29:58: DEBUG: pfkey UPDATE succeeded: ESP/Transport 192.168.2.3->192.168.2.5 spi=145448323(0x8ab5d83)
2005-01-31 16:29:58: INFO: IPsec-SA established: ESP/Transport 192.168.2.3->192.168.2.5 spi=145448323(0x8ab5d83)
2005-01-31 16:29:58: DEBUG: andi: pfkey.c, pk_recvupdate: ende
2005-01-31 16:29:58: DEBUG: ===
2005-01-31 16:29:58: DEBUG: get pfkey ADD message
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 3)
2005-01-31 16:29:58: DEBUG: andi: in pfkey.c, pk_recvadd: msg->sadb_msg_seq 2, msg->sadb_msg_type: ADD
2005-01-31 16:29:58: INFO: IPsec-SA established: AH/Transport 192.168.2.5->192.168.2.3 spi=184682906(0xb02099a)
2005-01-31 16:29:58: DEBUG: ===
2005-01-31 16:29:58: DEBUG: get pfkey ADD message
andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 3)
2005-01-31 16:29:58: DEBUG: andi: in pfkey.c, pk_recvadd: msg->sadb_msg_seq 2, msg->sadb_msg_type: ADD
2005-01-31 16:29:58: INFO: IPsec-SA established: ESP/Transport 192.168.2.5->192.168.2.3 spi=103868257(0x630e761)
2005-01-31 16:29:58: DEBUG: ===
^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: Fw: [Bugme-new] [Bug 4138] New: ipsec with racoon in transport mode with esp and ah hangs (problem is in xfrm_state_add)
2005-01-31 15:40 ` Andreas Unterluggauer
@ 2005-01-31 21:11 ` Herbert Xu
2005-02-01 10:53 ` Andreas Unterluggauer
2005-03-08 22:36 ` Patrick McHardy
0 siblings, 2 replies; 11+ messages in thread
From: Herbert Xu @ 2005-01-31 21:11 UTC (permalink / raw)
To: Andreas Unterluggauer; +Cc: netdev
Hi Andreas:
On Mon, Jan 31, 2005 at 03:40:16PM +0000, Andreas Unterluggauer wrote:
>
> 2005-01-31 16:29:58: DEBUG: ===
> 2005-01-31 16:29:58: DEBUG: get pfkey ADD message
> andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 3)
> 2005-01-31 16:29:58: DEBUG: andi: in pfkey.c, pk_recvadd: msg->sadb_msg_seq 2, msg->sadb_msg_type: ADD
> 2005-01-31 16:29:58: INFO: IPsec-SA established: ESP/Transport 192.168.2.5->192.168.2.3 spi=103868257(0x630e761)
> 2005-01-31 16:29:58: DEBUG: ===
Does the machine hang at this point in time? If not, then this is
simply a racoon bug. Although the acquire message carries a policy
with it, it's really only acquiring a single SA. Therefore, only
the SA being acquired should be added with that sequence number.
Cheers,
--
Visit Openswan at http://www.openswan.org/
Email: Herbert Xu ~{PmV>HI~} <herbert@gondor.apana.org.au>
Home Page: http://gondor.apana.org.au/~herbert/
PGP Key: http://gondor.apana.org.au/~herbert/pubkey.txt
^ permalink raw reply [flat|nested] 11+ messages in thread* Re: Fw: [Bugme-new] [Bug 4138] New: ipsec with racoon in transport mode with esp and ah hangs (problem is in xfrm_state_add)
2005-01-31 21:11 ` Herbert Xu
@ 2005-02-01 10:53 ` Andreas Unterluggauer
2005-03-08 22:36 ` Patrick McHardy
1 sibling, 0 replies; 11+ messages in thread
From: Andreas Unterluggauer @ 2005-02-01 10:53 UTC (permalink / raw)
To: Herbert Xu; +Cc: netdev, David S. Miller
Hallo Herbert,
> On Mon, Jan 31, 2005 at 03:40:16PM +0000, Andreas Unterluggauer wrote:
> > 2005-01-31 16:29:58: DEBUG: ===
> > 2005-01-31 16:29:58: DEBUG: get pfkey ADD message
> > andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 3)
> > 2005-01-31 16:29:58: DEBUG: andi: in pfkey.c, pk_recvadd:
> > msg->sadb_msg_seq 2, msg->sadb_msg_type: ADD 2005-01-31 16:29:58: INFO:
> > IPsec-SA established: ESP/Transport 192.168.2.5->192.168.2.3
> > spi=103868257(0x630e761) 2005-01-31 16:29:58: DEBUG: ===
>
> Does the machine hang at this point in time? If not, then this is
> simply a racoon bug. Although the acquire message carries a policy
> with it, it's really only acquiring a single SA. Therefore, only
> the SA being acquired should be added with that sequence number.
the machine (kernel) is not hanging!
only the programm (e.g. ping ) is hanging until it gets a timeout. the kernel
is acquiring a SA and racoon answers, and the kernel is acquiring and racoon
answers ... until the user-programm stops.
thanks for the information, that its a racoon (ipsec-tools) problem. I will
contact the ipsec-tools developers.
ciao
andi
^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: Fw: [Bugme-new] [Bug 4138] New: ipsec with racoon in transport mode with esp and ah hangs (problem is in xfrm_state_add)
2005-01-31 21:11 ` Herbert Xu
2005-02-01 10:53 ` Andreas Unterluggauer
@ 2005-03-08 22:36 ` Patrick McHardy
2005-03-08 23:00 ` Herbert Xu
1 sibling, 1 reply; 11+ messages in thread
From: Patrick McHardy @ 2005-03-08 22:36 UTC (permalink / raw)
To: Herbert Xu; +Cc: Andreas Unterluggauer, netdev
[-- Attachment #1: Type: text/plain, Size: 1010 bytes --]
Herbert Xu wrote:
> Hi Andreas:
>
> On Mon, Jan 31, 2005 at 03:40:16PM +0000, Andreas Unterluggauer wrote:
>
>>2005-01-31 16:29:58: DEBUG: ===
>>2005-01-31 16:29:58: DEBUG: get pfkey ADD message
>>andi: libipsec/pfkey.c, pfkey_check: start (msg->sadb_msg_satype: 3)
>>2005-01-31 16:29:58: DEBUG: andi: in pfkey.c, pk_recvadd: msg->sadb_msg_seq 2, msg->sadb_msg_type: ADD
>>2005-01-31 16:29:58: INFO: IPsec-SA established: ESP/Transport 192.168.2.5->192.168.2.3 spi=103868257(0x630e761)
>>2005-01-31 16:29:58: DEBUG: ===
>
>
> Does the machine hang at this point in time? If not, then this is
> simply a racoon bug. Although the acquire message carries a policy
> with it, it's really only acquiring a single SA. Therefore, only
> the SA being acquired should be added with that sequence number.
You're right, but I think there is also kernel misbehaviour here that
is fixed by the patch for __xfrm_state_find_acq_byseq() I sent to Dave
earlier. Andreas, can you try this patch please ?
Regards
Patrick
[-- Attachment #2: x --]
[-- Type: text/plain, Size: 420 bytes --]
===== net/xfrm/xfrm_state.c 1.55 vs edited =====
--- 1.55/net/xfrm/xfrm_state.c 2005-03-07 06:23:53 +01:00
+++ edited/net/xfrm/xfrm_state.c 2005-03-08 18:42:13 +01:00
@@ -609,7 +609,7 @@
for (i = 0; i < XFRM_DST_HSIZE; i++) {
list_for_each_entry(x, xfrm_state_bydst+i, bydst) {
- if (x->km.seq == seq) {
+ if (x->km.seq == seq && x->km.state == XFRM_STATE_ACQ) {
xfrm_state_hold(x);
return x;
}
^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: Fw: [Bugme-new] [Bug 4138] New: ipsec with racoon in transport mode with esp and ah hangs (problem is in xfrm_state_add)
2005-01-31 10:54 ` Herbert Xu
2005-01-31 15:19 ` Andreas Unterluggauer
2005-01-31 15:40 ` Andreas Unterluggauer
@ 2005-01-31 19:40 ` David S. Miller
2005-01-31 20:26 ` Herbert Xu
2 siblings, 1 reply; 11+ messages in thread
From: David S. Miller @ 2005-01-31 19:40 UTC (permalink / raw)
To: Herbert Xu; +Cc: akpm, au, netdev
On Mon, 31 Jan 2005 21:54:33 +1100
Herbert Xu <herbert@gondor.apana.org.au> wrote:
> Well without the check we would have silently ignored the sequence
> number which is why you wouldn't have noticed the problem with racoon
> before.
>
> However, for those who need to use the sequence number this check is
> necessary.
Yes, but the loop in the kernel must be prevented nevertheless,
buggy userland or not.
^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: Fw: [Bugme-new] [Bug 4138] New: ipsec with racoon in transport mode with esp and ah hangs (problem is in xfrm_state_add)
2005-01-31 19:40 ` David S. Miller
@ 2005-01-31 20:26 ` Herbert Xu
2005-01-31 20:36 ` David S. Miller
0 siblings, 1 reply; 11+ messages in thread
From: Herbert Xu @ 2005-01-31 20:26 UTC (permalink / raw)
To: David S. Miller; +Cc: akpm, au, netdev
On Mon, Jan 31, 2005 at 11:40:04AM -0800, David S. Miller wrote:
>
> Yes, but the loop in the kernel must be prevented nevertheless,
> buggy userland or not.
I'm not sure that there is a loop. Apart from the word hang in the
subject line, the submitter didn't talk about a loop at all.
Perhaps he's referring to the loop where the kernel continuously
sends acquire messages to racoon but racoon responds by doing
duplicate adds thus deleting the larval SAs?
--
Visit Openswan at http://www.openswan.org/
Email: Herbert Xu ~{PmV>HI~} <herbert@gondor.apana.org.au>
Home Page: http://gondor.apana.org.au/~herbert/
PGP Key: http://gondor.apana.org.au/~herbert/pubkey.txt
^ permalink raw reply [flat|nested] 11+ messages in thread* Re: Fw: [Bugme-new] [Bug 4138] New: ipsec with racoon in transport mode with esp and ah hangs (problem is in xfrm_state_add)
2005-01-31 20:26 ` Herbert Xu
@ 2005-01-31 20:36 ` David S. Miller
0 siblings, 0 replies; 11+ messages in thread
From: David S. Miller @ 2005-01-31 20:36 UTC (permalink / raw)
To: Herbert Xu; +Cc: akpm, au, netdev
On Tue, 1 Feb 2005 07:26:08 +1100
Herbert Xu <herbert@gondor.apana.org.au> wrote:
> I'm not sure that there is a loop. Apart from the word hang in the
> subject line, the submitter didn't talk about a loop at all.
>
> Perhaps he's referring to the loop where the kernel continuously
> sends acquire messages to racoon but racoon responds by doing
> duplicate adds thus deleting the larval SAs?
Ok, that's a different case, the loop is in userspace there.
^ permalink raw reply [flat|nested] 11+ messages in thread