On Tue, Mar 01, 2016 at 01:11:08PM +0100, Frank Wille wrote: > Brett Lymn wrote: > > > OK, does phase 2 actually complete? > > I doubt that. Currently I'm not even sure whether phase 1 completes, because > the phase1-up script is never called. On the other hand the phase1-down > script is called, as soon as the connection is terminated. >
Well, it does seem to get close.... see below. > > > What does a "setkey -aD" output? > > No SAD entries. And no SPD entries either. > I guess they would be added by the phase1-up script...? > In the logs you can see the SAD entries get created but they get removed when the connection gets torn down. > > > Have you tried a tcpdump to see what is going on at the network level? > > Yes, always. I have attached the tcpdump from my client and the vpn-status > log of the Lancom-router (the VPN "server"). > That's helpful. I normally use -s 0 -x with my tcpdump so I can see what is in the packets but it may not be very useful here. > > > You should expect encrypted packets, if you are seeing stuff in the > > clear then check your routing and ensure the packets are properly > > routed to the vpn tunnel end point. > > This is something to worry about as soon as both phases have been completed, > which definitely is not the case. ;) > Well, there is a chance that the negotiation was failing due to packets not going where you expect. That doesn't appear to be happening but checking the simple things can't hurt and can save a lot of grief :) > > > It has been a long while since I played with this but I seem to recall > > that you do get a log of what is being proposed by both sides. > > The proposal is accepted (refer to the Lancom VPN log). > Yes and by NetBSD too, you can actually see the phase 1 has completed in the racoon logs but then the SA gets removed. > Looking at the tcpdump I wonder why the NetBSD client says it is exchanging > "isakmp: phase 2" packets, while the Lancom still calls these isakmp > notifies "Phase-1 SA"? > As Greg said, this is probably just terminology, I wouldn't get hung up on that too much. OK, lets have a bit of a look at the logs and see what is going on... > Mar 1 11:52:07 powerbook racoon: [1.2.3.4] INFO: received INITIAL-CONTACT > Mar 1 11:52:07 powerbook racoon: INFO: ISAKMP-SA established > 192.168.1.5[4500]-1.2.3.4[4500] spi:4da2f5f910bbdf44:444ae08dd7de45a5 This is good - we have a security association here, note the SPI numbers here, they will be useful later. > Mar 1 11:53:12 powerbook racoon: [1.2.3.4] INFO: DPD: remote (ISAKMP-SA > spi=4da2f5f910bbdf44:444ae08dd7de45a5) seems to be dead. > Mar 1 11:53:12 powerbook racoon: INFO: purging ISAKMP-SA > spi=4da2f5f910bbdf44:444ae08dd7de45a5. > Mar 1 11:53:12 powerbook racoon: INFO: purged ISAKMP-SA > spi=4da2f5f910bbdf44:444ae08dd7de45a5. > Mar 1 11:53:12 powerbook racoon: INFO: ISAKMP-SA deleted > 192.168.1.5[4500]-1.2.3.4[4500] spi:4da2f5f910bbdf44:444ae08dd7de45a5 > Mar 1 11:53:12 powerbook racoon: INFO: KA remove: > 192.168.1.5[4500]->1.2.3.4[4500] Then the SA gets torn down. > 11:52:06.441891 IP 192.168.1.5.500 > 1.2.3.4.500: isakmp: phase 1 I ident Nothing really out of place in the tcpdump... the log from the other side is interesting: > > [VPN-Status] 2016/03/01 11:52:07,096 > IKE info: exchange_finalize: assuming identified for road-warrior with cert, > id=VPNCLIENT15EF90, RemoteGW=91.56.237.127 > > > [VPN-Status] 2016/03/01 11:52:07,121 > IKE info: Phase-1 [responder] for peer VPNCLIENT15EF90 initiator id > CN=VPNCLIENT15,O=WPS,C=DE,L=HERFORD,ST=NRW,OU=IT,postalCode=32052, responder > id CN=ZENTRALE,O=WPS,C=DE,L=HERFORD,ST=NRW,OU=IT,postalCode=32052 > IKE info: initiator cookie: 0x4da2f5f910bbdf44, responder cookie: > 0x444ae08dd7de45a5 > IKE info: NAT-T enabled in mode rfc, we are not behind a nat, the remote side > is behind a nat > IKE info: SA ISAKMP for peer VPNCLIENT15EF90 encryption aes-cbc > authentication MD5 > IKE info: life time ( 28800 sec/ 0 kb) DPD 0 sec > This is good - we have a phase 1 done here, note the initiator and responder cookies match the SPI numbers from the NetBSD side. Looking good at this point. > > [VPN-Status] 2016/03/01 11:52:23,541 > IKE info: ISAKMP_NOTIFY_DPD_R_U_THERE sent for Phase-1 SA to peer > VPNCLIENT15EF90, sequence nr 0x7a8b3f4b > > > [VPN-Status] 2016/03/01 11:52:23,614 > IKE info: NOTIFY received of type ISAKMP_NOTIFY_DPD_R_U_THERE_ACK for peer > VPNCLIENT15EF90 Seq-Nr 0x7a8b3f4b, expected 0x7a8b3f4b > This is good, we see a query and response > > [VPN-Status] 2016/03/01 11:52:27,223 > IKE info: NOTIFY received of type ISAKMP_NOTIFY_DPD_R_U_THERE for peer > VPNCLIENT15EF90 Seq-Nr 0xe8, expected 0xe8 > > > [VPN-Status] 2016/03/01 11:52:27,224 > IKE info: ISAKMP_NOTIFY_DPD_R_U_THERE_ACK sent for Phase-1 SA to peer > VPNCLIENT15EF90, sequence nr 0xe8 > OK and here is where things fall apart. The client sends an "are you there" request and vpn server sends a reply but it seems like the packet did not get through and then things go bad from there... > > [VPN-Status] 2016/03/01 11:52:37,096 > VPN: connection for VPNCLIENT15EF90 (91.56.237.127) timed out: no response > > [VPN-Status] 2016/03/01 11:52:37,096 > VPN: Error: IFC-R-Connection-timeout-dynamic (0x1205) for VPNCLIENT15EF90 > (91.56.237.127) > > [VPN-Status] 2016/03/01 11:52:37,096 > vpn-maps[38], remote: VPNCLIENT15EF90 > > [VPN-Status] 2016/03/01 11:52:37,096 > VPN: installing ruleset for VPNCLIENT15EF90 (91.56.237.127) > > [VPN-Status] 2016/03/01 11:52:37,096 > VPN: WAN state changed to WanDisconnect for VPNCLIENT15EF90 (91.56.237.127), > called by: 009c5cb8 > > [VPN-Status] 2016/03/01 11:52:37,097 > IKE info: Phase-1 SA removed: peer VPNCLIENT15EF90 rule VPNCLIENT15EF90 > removed > > > [VPN-Status] 2016/03/01 11:52:37,102 > VPN: WAN state changed to WanIdle for VPNCLIENT15EF90 (91.56.237.127), called > by: 009c5cb8 > > [VPN-Status] 2016/03/01 11:52:37,103 > removeAllDeletedRoutes, called by: 009bdd24 > > [VPN-Status] 2016/03/01 11:52:37,108 > VPN: VPNCLIENT15EF90 (91.56.237.127) disconnected > So the SA is torn down here on the vpn server side because there was no response, probably because the NetBSD client is still waiting for an ack to the are you there. > > [VPN-Status] 2016/03/01 11:52:47,318 > IKE log: 115247.318276 Default message_drop_invalid_cookies: invalid > cookie(s) 4da2f5f910bbdf44 444ae08dd7de45a5 > > > [VPN-Status] 2016/03/01 11:52:47,318 > IKE log: 115247.318468 Default dropped message from 91.56.237.127 port 2500 > due to notification type INVALID_COOKIE > > > [VPN-Status] 2016/03/01 11:52:47,318 > IKE info: Informational messages are unidirectional and therefore are not > answered! (cookies 4D A2 F5 F9 10 BB DF 44 44 4A E0 8D D7 DE 45 A5) > The rest of this is the NetBSD client still trying to talk at the vpn server after the SA has been torn down. Note the match of the cookie and the SPI, this is how we can tell what is happening. OK so what we can see here is that there seems to be some packet loss that is causing the NetBSD client to wait for an answer but during that time the vpn server decides nothing is happening and tears the connection down. So, some things to consider: 0) How reliable is the internet connection on the client side? It seems these days there is an assumption the connection is fast. I have had an instance where I tried to test a vpn connection using a dial up modem, it failed miserably, timing out - the very same configuration worked perfectly from a public wireless network. 1) Since one side is doing NAT-T, do you have port forwarding on the router so that the IKE packets (udp 500 and 4500) are forwarded back to the vpn client? Though it seems you must already have this right to get the phase 1 done... 2) any firewall rules blocking the incoming traffic? Again, just check though it doesn't make much sense give you have managed to get so far along. 3) some firewalls/routers don't like large udp packets, there are some racoon settings for fragmenting packets - perhaps you need those. Though my experience with this is that the tunnel comes up and a ping will work but trying something heavier like a remote display or login will mysteriously fail. -- Brett Lymn Let go, or be dragged - Zen proverb.
