Does anyone have any clues as to what might be going on here? Any pointers are appreciated.
Thanks, Bharath Kumar On Wed, Dec 26, 2012 at 11:21 PM, Bharath Kumar <[email protected]> wrote: > Hi, > > First up, apologies if my previous messages did reach the group - there > was no way for me to check and they didn't appear in the archive yet. I > have done further debugging and wanted to ask a follow up question. > > I am facing a strange problem when trying to get Adtran Netvanta 5430 work > with Strongswan 5.0.1. Here's what's happening - I've debugged quite a bit, > added more debug statements in the code to find out what's going on, etc. > Any help is greatly appreciated. > > Using RSA authentication > > 1. IKE SA gets established OK. > 2. IKE Phase 2 starts and the initiator (Adtran) sends the first message > 3. Responder is ok with that and sends the quick mode 2nd message > 4. Initiator (Adtran) is happy and dandy but before sending the quick mode > 3rd message (Hash), it sends an INFORMATIONAL_V1 message 24577 > (replay-status) > 5. Initiator (Adtran) immediately sends QUICK MODE 3rd message (Hash) > > Now, per the logs on Strongswan side, everything is great until step 3 > above. When the INFORMATIONAL_V1 message comes in at step 4, it is > processed by process_r method in libcharon/sa/ikev1/tasks/quick_mode.c and > returns SUCCESS at line 1021 - this much I verified adding additional > debugging code. > > But before the QUICK MODE 3rd message comes in (step 5), Strongswan is > deleting the SAD entry and going back to QM_INIT. I verified it is in > QM_INIT by adding additional debugging. > > Any help is greatly appreciated. > > > Here is the ipsec.conf > ================ > # ipsec.conf - strongSwan IPsec configuration file > > # basic configuration > > config setup > # charondebug = "dmn 2, mgr 2, ike 2, chd 2, job 2, cfg 2, knl 2, > net 2, lib 2" > charondebug = "dmn 3, mgr 3, ike 4, chd 3, job 3, cfg 3, knl 3, > net 2, lib 3" > # nat_traversal="yes" > # strictcrlpolicy=yes > # uniqueids = no > > # Add connections here. > > conn %default > ikelifetime=480m > keylife=480m > rekeymargin=3m > keyingtries=1 > keyexchange=ikev1 > > conn adtran-cert > auto=route > authby=pubkey > left=%defaultroute > leftcert=vpngwCert.pem > leftsubnet=0.0.0.0/0 > #leftprotoport=tcp/http > right=107.0.5.22 > rightcert=Adtran-VPN.pem > rightsubnet=172.17.0.0/16 > #rightprotoport=tcp > #esp=aes128-sha1-modp1536 > > > > Here is the relevant log. > ========================= > > Dec 27 01:49:45 ip-10-0-0-139 charon: 07[NET] received packet: from > 107.0.5.22[500] to 10.0.0.139[500] > Dec 27 01:49:45 ip-10-0-0-139 charon: 07[NET] waiting for data on sockets > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[MGR] checkout IKE_SA by message > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[MGR] IKE_SA adtran-cert[2] > successfully checked out > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[NET] received packet: from > 107.0.5.22[500] to 10.0.0.139[500] > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[IKE] next IV for MID 3414728253 > => 8 bytes @ 0x7fdf8c000c60 > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[IKE] 0: A4 CF 08 28 94 0F EE > 0F ...(.... > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[ENC] parsed QUICK_MODE request > 3414728253 [ HASH SA No ID ID ] > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[IKE] Hash(1) => 20 bytes @ > 0x7fdf8c0018d0 > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[IKE] 0: C8 93 6D 4E 4E B2 98 > 9F 69 7D 31 16 02 A4 A5 4D ..mNN...i}1....M > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[IKE] 16: 99 26 74 FF > .&t. > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[IKE] next IV for MID 3414728253 > => 8 bytes @ 0x7fdf8c0018b0 > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[IKE] 0: 25 69 01 A7 BD 75 5F > 77 %i...u_w > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[IKE] BK - In QM_INIT > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[CFG] looking for a child config > for 0.0.0.0/0[tcp/http] <http://0.0.0.0/0%5Btcp/http%5D> === > 172.17.0.0/16[tcp] <http://172.17.0.0/16%5Btcp%5D> > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[CFG] proposing traffic selectors > for us: > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[CFG] 0.0.0.0/0 > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[CFG] proposing traffic selectors > for other: > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[CFG] 172.17.0.0/16 > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[CFG] candidate "adtran-cert" > with prio 1+1 > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[CFG] found matching child config > "adtran-cert" with prio 2 > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[CFG] selecting traffic selectors > for other: > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[CFG] config: 172.17.0.0/16, > received: 172.17.0.0/16[tcp] <http://172.17.0.0/16%5Btcp%5D> => match: > 172.17.0.0/16[tcp] <http://172.17.0.0/16%5Btcp%5D> > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[CFG] selecting traffic selectors > for us: > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[CFG] config: 0.0.0.0/0, > received: 0.0.0.0/0[tcp/http] <http://0.0.0.0/0%5Btcp/http%5D> => match: > 0.0.0.0/0[tcp/http] <http://0.0.0.0/0%5Btcp/http%5D> > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[CFG] selecting proposal: > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[CFG] no acceptable > ENCRYPTION_ALGORITHM found > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[CFG] selecting proposal: > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[CFG] no acceptable > DIFFIE_HELLMAN_GROUP found > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[CFG] selecting proposal: > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[CFG] proposal matches > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[CFG] received proposals: > ESP:3DES_CBC/HMAC_SHA1_96/NO_EXT_SEQ > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[CFG] configured proposals: > ESP:AES_CBC_128/HMAC_SHA1_96/MODP_2048/NO_EXT_SEQ, > ESP:3DES_CBC/HMAC_SHA1_96/MODP_1536/NO_EXT_SEQ, > ESP:AES_CBC_128/AES_CBC_192/AES_CBC_256/3DES_CBC/BLOWFISH_CBC_256/HMAC_SHA1_96/AES_XCBC_96/HMAC_MD5_96/NO_EXT_SEQ > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[CFG] selected proposal: > ESP:3DES_CBC/HMAC_SHA1_96/NO_EXT_SEQ > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[IKE] BK - In QM_INIT - calling > child_sa_create > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[KNL] getting SPI for reqid {2} > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[KNL] sending XFRM_MSG_ALLOCSPI: > => 248 bytes @ 0x7fdfab44c730 > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[KNL] 0: F8 00 00 00 16 00 01 > 00 CC 00 00 00 89 60 00 00 .............`.. > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[KNL] 16: 00 00 00 00 00 00 00 > 00 00 00 00 00 00 00 00 00 ................ > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[KNL] 32: 00 00 00 00 00 00 00 > 00 00 00 00 00 00 00 00 00 ................ > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[KNL] 48: 00 00 00 00 00 00 00 > 00 00 00 00 00 00 00 00 00 ................ > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[KNL] 64: 00 00 00 00 00 00 00 > 00 0A 00 00 8B 00 00 00 00 ................ > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[KNL] 80: 00 00 00 00 00 00 00 > 00 00 00 00 00 32 00 00 00 ............2... > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[KNL] 96: 6B 00 05 16 00 00 00 > 00 00 00 00 00 00 00 00 00 k............... > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[KNL] 112: 00 00 00 00 00 00 00 > 00 00 00 00 00 00 00 00 00 ................ > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[KNL] 128: 00 00 00 00 00 00 00 > 00 00 00 00 00 00 00 00 00 ................ > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[KNL] 144: 00 00 00 00 00 00 00 > 00 00 00 00 00 00 00 00 00 ................ > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[KNL] 160: 00 00 00 00 00 00 00 > 00 00 00 00 00 00 00 00 00 ................ > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[KNL] 176: 00 00 00 00 00 00 00 > 00 00 00 00 00 00 00 00 00 ................ > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[KNL] 192: 00 00 00 00 00 00 00 > 00 00 00 00 00 00 00 00 00 ................ > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[KNL] 208: 00 00 00 00 00 00 00 > 00 00 00 00 00 00 00 00 00 ................ > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[KNL] 224: 02 00 00 00 02 00 01 > 00 00 00 00 00 00 00 00 00 ................ > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[KNL] 240: 00 00 00 C0 FF FF FF > CF ....... > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[KNL] got SPI c959f83c for reqid > {2} > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[IKE] BK - Entering QM_NEGOTIATED > - in build_r > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[IKE] Hash(2) => 20 bytes @ > 0x7fdf8c004690 > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[IKE] 0: 25 C2 A9 3A 3E 2E C5 > DE 91 FE C7 CA 09 28 44 9C %..:>........(D. > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[IKE] 16: 14 18 D6 07 > .... > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[ENC] generating QUICK_MODE > response 3414728253 [ HASH SA No ID ID ] > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[IKE] next IV for MID 3414728253 > => 8 bytes @ 0x7fdf8c004b70 > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[IKE] 0: 75 BF 60 BC 36 B9 AA > F7 u.`.6... > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[NET] sending packet: from > 10.0.0.139[500] to 107.0.5.22[500] > Dec 27 01:49:45 ip-10-0-0-139 charon: 08[NET] sending packet: from > 10.0.0.139[500] to 107.0.5.22[500] > Dec 27 01:49:45 ip-10-0-0-139 charon: 04[JOB] next event in 3s 999ms, > waiting > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[MGR] checkin IKE_SA adtran-cert[2] > Dec 27 01:49:45 ip-10-0-0-139 charon: 14[MGR] check-in of IKE_SA > successful. > Dec 27 01:49:45 ip-10-0-0-139 charon: 07[NET] received packet: from > 107.0.5.22[500] to 10.0.0.139[500] > Dec 27 01:49:45 ip-10-0-0-139 charon: 07[NET] waiting for data on sockets > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[MGR] checkout IKE_SA by message > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[MGR] IKE_SA adtran-cert[2] > successfully checked out > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[NET] received packet: from > 107.0.5.22[500] to 10.0.0.139[500] > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[IKE] next IV for MID 2299459328=> 8 > bytes @ 0x7fdf98000e00 > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[IKE] 0: D1 2E 0B 3D 7A BB 2E > 55 ...=z..U > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[ENC] parsed INFORMATIONAL_V1 > request 2299459328 [ HASH N((24577)) ] > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[IKE] Hash => 20 bytes @ > 0x7fdf98001780 > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[IKE] 0: B5 91 96 6C B8 57 EA > CE FD CB 8B 6A E3 53 04 10 ...l.W.....j.S.. > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[IKE] 16: 09 4B CC 33 > .K.3 > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[IKE] next IV for MID 2299459328=> 8 > bytes @ 0x7fdf98000a70 > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[IKE] 0: C0 3A 7A F3 D2 19 58 > 45 .:z...XE > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[IKE] received (24577) notify > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[IKE] BK - In QM_NEGOTIATED > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[IKE] BK - In QM_NEGOTIATED - > returning without installing the SA > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[KNL] deleting SAD entry with SPI > c959f83c (mark 0/0x00000000) > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[KNL] sending XFRM_MSG_DELSA: => > 40 bytes @ 0x7fdfaaa4b770 > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[KNL] 0: 28 00 00 00 11 00 05 > 00 CD 00 00 00 89 60 00 00 (............`.. > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[KNL] 16: 0A 00 00 8B 00 00 00 > 00 00 00 00 00 00 00 00 00 ................ > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[KNL] 32: C9 59 F8 3C 02 00 32 > 00 .Y.<..2. > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[KNL] deleted SAD entry with SPI > c959f83c (mark 0/0x00000000) > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[MGR] checkin IKE_SA adtran-cert[2] > Dec 27 01:49:45 ip-10-0-0-139 charon: 15[MGR] check-in of IKE_SA > successful. > Dec 27 01:49:45 ip-10-0-0-139 charon: 07[NET] received packet: from > 107.0.5.22[500] to 10.0.0.139[500] > Dec 27 01:49:45 ip-10-0-0-139 charon: 07[NET] waiting for data on sockets > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[MGR] checkout IKE_SA by message > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[MGR] IKE_SA adtran-cert[2] > successfully checked out > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[NET] received packet: from > 107.0.5.22[500] to 10.0.0.139[500] > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[ENC] parsed QUICK_MODE request > 3414728253 [ HASH ] > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[IKE] Hash(3) => 20 bytes @ > 0x7fdf940012d0 > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[IKE] 0: 7C 2E 99 6E 60 E9 17 > 46 B1 35 F1 C0 99 EF FD 61 |..n`..F.5.....a > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[IKE] 16: BF E0 58 74 > ..Xt > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[IKE] next IV for MID 3414728253 > => 8 bytes @ 0x7fdf94001280 > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[IKE] 0: 01 E8 C5 A6 E3 66 2C > 9C .....f,. > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[IKE] BK - In QM_INIT > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[IKE] sa payload missing > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[IKE] queueing INFORMATIONAL task > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[IKE] activating new tasks > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[IKE] activating INFORMATIONAL > task > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[IKE] Hash => 20 bytes @ > 0x7fdf94000f00 > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[IKE] 0: 33 6C 5C 31 CF C1 75 > 47 36 CA 23 92 8A 02 E3 33 3l\1..uG6.#....3 > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[IKE] 16: 07 98 B9 59 > ...Y > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[ENC] generating INFORMATIONAL_V1 > request 613066051 [ HASH N(CRIT) ] > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[IKE] next IV for MID 613066051 => > 8 bytes @ 0x7fdf94001d20 > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[IKE] 0: DC B3 F3 3D 08 37 F2 > E3 ...=.7.. > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[IKE] next IV for MID 613066051 => > 8 bytes @ 0x7fdf94001940 > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[IKE] 0: C9 7B 6C F6 3C 6A 95 > D5 .{l.<j.. > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[NET] sending packet: from > 10.0.0.139[500] to 107.0.5.22[500] > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[IKE] activating new tasks > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[IKE] nothing to initiate > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[MGR] checkin IKE_SA adtran-cert[2] > Dec 27 01:49:45 ip-10-0-0-139 charon: 16[MGR] check-in of IKE_SA > successful. > Dec 27 01:49:45 ip-10-0-0-139 charon: 08[NET] sending packet: from > 10.0.0.139[500] to 107.0.5.22[500] > > ========================= > > > > > > >
_______________________________________________ Users mailing list [email protected] https://lists.strongswan.org/mailman/listinfo/users
