Date: Tue, 13 Jan 2004 14:28:48 -0800 From: George Hartzell <hartzell@kestrel.alerce.com> To: freebsd-security@freebsd.org Subject: IPSEC btwn stable and Linksys BEFVP41 stopped working. Message-ID: <16388.28960.595527.20394@rosebud.alerce.com>
next in thread | raw e-mail | index | archive | help
Hi, I have been using IPsec to communicate between a laptop that tracks -stable and a Linksys BEFVP41 router. I only use it infrequently, but it's been working great. My setup is as described in http://grapeape.alerce.com/linksys-ipsec/article.html (which I am planning to submit to the handbook when it's done). I'm no longer able to make an ipsec connection, and I can't put my finger on anything that's changed. The most obvious candidate is the move from 4.8 to 4.9. It could also be that something involving the racoon port needs to move forward to match 4.9? I have recompiled the version of the port that I'm using, distinfo says: MD5 (racoon-20030711a.tar.gz) = 0546688efd5bb3725c8243045500a48a I'm loath to start blindly updating everything in sight, and since none of the comments in the racoon CVS directory talk about "fixing it for 4.9" or anything, I've been sticking with what I have for now. I have two hopefully useful pieces of information. Here's a trace from "racoon -F -d -f racoon.conf" 2004-01-13 13:36:39: INFO: main.c:172:main(): @(#)package version freebsd-20030711a 2004-01-13 13:36:39: INFO: main.c:174:main(): @(#)internal version 20001216 sakane@kame.net 2004-01-13 13:36:39: INFO: main.c:175:main(): @(#)This product linked OpenSSL 0.9.7c 30 Sep 2003 (http://www.openssl.org/) 2004-01-13 13:36:39: DEBUG: pfkey.c:371:pfkey_init(): call pfkey_send_register for AH 2004-01-13 13:36:39: DEBUG: pfkey.c:371:pfkey_init(): call pfkey_send_register for ESP 2004-01-13 13:36:39: DEBUG: pfkey.c:371:pfkey_init(): call pfkey_send_register for IPCOMP 2004-01-13 13:36:39: DEBUG: cftoken.l:549:yycf_set_buffer(): reading config file /usr/local/etc/racoon/racoon.conf 2004-01-13 13:36:39: DEBUG: algorithm.c:614:alg_oakley_dhdef(): hmac(modp1024) 2004-01-13 13:36:39: DEBUG: pfkey.c:2310:pk_checkalg(): compression algorithm can not be checked because sadb message doesn't support it. 2004-01-13 13:36:39: DEBUG: grabmyaddr.c:204:grab_myaddrs(): my interface: 64.1.164.95 (fxp0) 2004-01-13 13:36:39: DEBUG: grabmyaddr.c:204:grab_myaddrs(): my interface: fe80::a00:46ff:fe07:71d5%fxp0 (fxp0) 2004-01-13 13:36:39: DEBUG: grabmyaddr.c:204:grab_myaddrs(): my interface: ::1 (lo0) 2004-01-13 13:36:39: DEBUG: grabmyaddr.c:204:grab_myaddrs(): my interface: fe80::1%lo0 (lo0) 2004-01-13 13:36:39: DEBUG: grabmyaddr.c:204:grab_myaddrs(): my interface: 127.0.0.1 (lo0) 2004-01-13 13:36:39: DEBUG: grabmyaddr.c:471:autoconf_myaddrsport(): configuring default isakmp port. 2004-01-13 13:36:39: DEBUG: grabmyaddr.c:493:autoconf_myaddrsport(): 5 addrs are configured successfully 2004-01-13 13:36:39: INFO: isakmp.c:1358:isakmp_open(): 127.0.0.1[500] used as isakmp port (fd=5) 2004-01-13 13:36:39: INFO: isakmp.c:1358:isakmp_open(): fe80::1%lo0[500] used as isakmp port (fd=6) 2004-01-13 13:36:39: INFO: isakmp.c:1358:isakmp_open(): ::1[500] used as isakmp port (fd=7) 2004-01-13 13:36:39: INFO: isakmp.c:1358:isakmp_open(): fe80::a00:46ff:fe07:71d5%fxp0[500] used as isakmp port (fd=8) 2004-01-13 13:36:39: INFO: isakmp.c:1358:isakmp_open(): 64.1.164.95[500] used as isakmp port (fd=9) 2004-01-13 13:36:39: DEBUG: pfkey.c:195:pfkey_handler(): get pfkey X_SPDDUMP message 2004-01-13 13:36:39: DEBUG: pfkey.c:195:pfkey_handler(): get pfkey X_SPDDUMP message 2004-01-13 13:36:39: DEBUG: policy.c:184:cmpspidxstrict(): sub:0xbfbff828: 64.1.164.95/32[0] 192.168.1.0/24[0] proto=any dir=out 2004-01-13 13:36:39: DEBUG: policy.c:185:cmpspidxstrict(): db :0x80a1c08: 192.168.1.0/24[0] 64.1.164.95/32[0] proto=any dir=in 2004-01-13 13:36:41: DEBUG: pfkey.c:195:pfkey_handler(): get pfkey ACQUIRE message 2004-01-13 13:36:41: DEBUG: pfkey.c:1557:pk_recvacquire(): suitable outbound SP found: 64.1.164.95/32[0] 192.168.1.0/24[0] proto=any dir=out. 2004-01-13 13:36:41: DEBUG: policy.c:184:cmpspidxstrict(): sub:0xbfbff814: 192.168.1.0/24[0] 64.1.164.95/32[0] proto=any dir=in 2004-01-13 13:36:41: DEBUG: policy.c:185:cmpspidxstrict(): db :0x80a1c08: 192.168.1.0/24[0] 64.1.164.95/32[0] proto=any dir=in 2004-01-13 13:36:41: DEBUG: pfkey.c:1573:pk_recvacquire(): suitable inbound SP found: 192.168.1.0/24[0] 64.1.164.95/32[0] proto=any dir=in. 2004-01-13 13:36:41: DEBUG: pfkey.c:1612:pk_recvacquire(): new acquire 64.1.164.95/32[0] 192.168.1.0/24[0] proto=any dir=out 2004-01-13 13:36:41: DEBUG: sainfo.c:112:getsainfo(): anonymous sainfo selected. 2004-01-13 13:36:41: DEBUG: proposal.c:825:printsaproto(): (proto_id=ESP spisize=4 spi=00000000 spi_p=00000000 encmode=Tunnel reqid=0:0) 2004-01-13 13:36:41: DEBUG: proposal.c:859:printsatrns(): (trns_id=3DES encklen=0 authtype=2) 2004-01-13 13:36:41: DEBUG: remoteconf.c:129:getrmconf(): anonymous configuration selected for 64.1.164.92. 2004-01-13 13:36:41: INFO: isakmp.c:1684:isakmp_post_acquire(): IPsec-SA request for 64.1.164.92 queued due to no phase1 found. 2004-01-13 13:36:41: DEBUG: isakmp.c:793:isakmp_ph1begin_i(): === 2004-01-13 13:36:41: INFO: isakmp.c:798:isakmp_ph1begin_i(): initiate new phase 1 negotiation: 64.1.164.95[500]<=>64.1.164.92[500] 2004-01-13 13:36:41: INFO: isakmp.c:803:isakmp_ph1begin_i(): begin Identity Protection mode. 2004-01-13 13:36:41: DEBUG: isakmp.c:1996:isakmp_newcookie(): new cookie: 3a7de03600b9ca1e 2004-01-13 13:36:41: DEBUG: isakmp.c:2113:set_isakmp_payload(): add payload of len 52, next type 0 2004-01-13 13:36:41: DEBUG: isakmp.c:2248:isakmp_printpacket(): begin. 36:41.616852 64.1.164.95:500 -> 64.1.164.92:500: isakmp 1.0 msgid 00000000: phase 1 I ident: (sa: doi=ipsec situation=identity (p: #1 protoid=isakmp transform=1 (t: #1 id=ike (type=lifetype value=sec)(type=lifeduration len=4 value=00015180)(type=enc value=3des)(type=auth value=preshared)(type=hash value=sha1)(type=group desc value=modp1024)))) 2004-01-13 13:36:41: DEBUG: sockmisc.c:421:sendfromto(): sockname 64.1.164.95[500] 2004-01-13 13:36:41: DEBUG: sockmisc.c:423:sendfromto(): send packet from 64.1.164.95[500] 2004-01-13 13:36:41: DEBUG: sockmisc.c:425:sendfromto(): send packet to 64.1.164.92[500] 2004-01-13 13:36:41: DEBUG: sockmisc.c:570:sendfromto(): 1 times of 84 bytes message will be sent to 64.1.164.92[500] 2004-01-13 13:36:41: DEBUG: plog.c:193:plogdump(): 3a7de036 00b9ca1e 00000000 00000000 01100200 00000000 00000054 00000038 00000001 00000001 0000002c 01010001 00000024 01010000 800b0001 000c0004 00015180 80010005 80030001 80020002 80040002 2004-01-13 13:36:41: DEBUG: isakmp.c:1449:isakmp_ph1resend(): resend phase1 packet 3a7de03600b9ca1e:0000000000000000 2004-01-13 13:36:50: DEBUG: pfkey.c:195:pfkey_handler(): get pfkey ACQUIRE message 2004-01-13 13:36:50: DEBUG: pfkey.c:1541:pk_recvacquire(): ignore the acquire becuase ph2 found 2004-01-13 13:36:51: DEBUG: sockmisc.c:421:sendfromto(): sockname 64.1.164.95[500] 2004-01-13 13:36:51: DEBUG: sockmisc.c:423:sendfromto(): send packet from 64.1.164.95[500] 2004-01-13 13:36:51: DEBUG: sockmisc.c:425:sendfromto(): send packet to 64.1.164.92[500] 2004-01-13 13:36:51: DEBUG: sockmisc.c:570:sendfromto(): 1 times of 84 bytes message will be sent to 64.1.164.92[500] 2004-01-13 13:36:51: DEBUG: plog.c:193:plogdump(): 3a7de036 00b9ca1e 00000000 00000000 01100200 00000000 00000054 00000038 00000001 00000001 0000002c 01010001 00000024 01010000 800b0001 000c0004 00015180 80010005 80030001 80020002 80040002 2004-01-13 13:36:51: DEBUG: isakmp.c:1449:isakmp_ph1resend(): resend phase1 packet 3a7de03600b9ca1e:0000000000000000 ^C2004-01-13 13:36:53: INFO: session.c:299:check_sigreq(): caught signal 2 2004-01-13 13:36:53: DEBUG: pfkey.c:195:pfkey_handler(): get pfkey FLUSH message 2004-01-13 13:36:53: DEBUG: schedule.c:210:sched_scrub_param(): an undead schedule has been deleted. 2004-01-13 13:36:54: DEBUG: pfkey.c:271:pfkey_dump_sadb(): call pfkey_send_dump 2004-01-13 13:36:54: DEBUG: schedule.c:210:sched_scrub_param(): an undead schedule has been deleted. 2004-01-13 13:36:54: INFO: session.c:180:close_session(): racoon shutdown And when I have a ping running that should be going over the tunnel, the Linksys logs this: 2004-01-13 13:36:51 **IKE incoming packet dropped : unknown peer ! 2004-01-13 13:36:51 Received: IP=64.1.164.95 I_Cookie=[3a 7d e0 36 00 b9 ca 1e ] R_Cookie=[00 00 00 00 00 00 00 00 ] All of the examples of packets w/ I_cookies I could find by googling also had values for the R_cookie field..... Does this ring any bells for anyone. Can someone point me in a useful direction? g.
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?16388.28960.595527.20394>