Bug #409
Incompatibility with AVM IKE / Problem with Reauthentication
Start date:
11.09.2013
Due date:
Estimated time:
Affected version:
5.1.0
Resolution:
Fixed
Description
Hi,
it looks there is a problem with DPD or interoperability. Always after an IKE and SA is established, I got an error on the AVM IKE Server.
fehlerhafte Paketlaenge: Hdr-length > read-Data
-> meaning wrong packet length
So I started debugging on this. As you can see in the tcpdump, the packet sent at 16:39:14.929827 has 16 bytes less than the other packets.
I do not have an explanation for this, that is why I added a debug log of strongswan.
Perhaps it has to do with the new SA created in that moment and the dpd job does not already know it and sends "empty" instead.
Consequences:
This results in an unstable VPN connection if I do not add a rightip to this conn (which may result in strongswan setting up the connection). But the strongswan gateway should only act as an responder, not as an initiator.
Please help,
André
If more details are needed, I will provide any information.
Log of Fritzbox
2013-09-09 16:34:03 avmike:marcant: Phase 2 ready 2013-09-09 16:34:03 avmike:< cb_sa_created(name=marcant,id=160,...,flags=0x00002001) 2013-09-09 16:34:03 avmike:marcant: start waiting connections 2013-09-09 16:34:03 avmike:marcant: NO waiting connections 2013-09-09 16:39:14 avmike:FreeIPsecSA: spi=3386db66 protocol=3 iotype=1 2013-09-09 16:39:14 avmike:FreeIPsecSA: spi=c779dcad protocol=3 iotype=2 2013-09-09 16:39:14 avmike:marcant fehlerhafte Paketlaenge: Hdr-length > read-Data
tcpdump on charon side
16:37:35.421216 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 120)
strongswan-server.net.isakmp > avmclient.net.isakmp: [bad udp cksum 788a!] isakmp 1.0 msgid e976c4c5 cookie 4dad7d9ab6375f48->12a805313f7b7287: phase 2/others I inf[E]: [encrypted hash]
16:39:14.929827 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 104)
strongswan-server.net.isakmp > avmclient.net.isakmp: [bad udp cksum 15c3!] isakmp 1.0 msgid 8440d00c cookie 4dad7d9ab6375f48->12a805313f7b7287: phase 2/others I inf[E]: [encrypted hash]
16:39:35.485101 IP (tos 0x0, ttl 53, id 29272, offset 0, flags [none], proto UDP (17), length 120)
avmclient.net.isakmp > strongswan-server.net.isakmp: [udp sum ok] isakmp 1.0 msgid 69079b39 cookie 4dad7d9ab6375f48->12a805313f7b7287: phase 2/others R inf[E]: [encrypted hash]
16:39:35.490312 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 120)
strongswan-server.net.isakmp > avmclient.net.isakmp: [bad udp cksum 9fa!] isakmp 1.0 msgid f2bd8630 cookie 4dad7d9ab6375f48->12a805313f7b7287: phase 2/others I inf[E]: [encrypted hash]
16:41:35.554890 IP (tos 0x0, ttl 53, id 29273, offset 0, flags [none], proto UDP (17), length 120)
avmclient.net.isakmp > strongswan-server.net.isakmp: [udp sum ok] isakmp 1.0 msgid d70910fb cookie 4dad7d9ab6375f48->12a805313f7b7287: phase 2/others R inf[E]: [encrypted hash]
Strongswan 4.1.0 Log
Sep 9 16:39:06 rossini charon: 12[MGR] checkout IKE_SA
Sep 9 16:39:06 rossini charon: 12[MGR] IKE_SA rw-test1[487] successfully checked out
Sep 9 16:39:06 rossini charon: 12[KNL] querying policy 192.168.200.0/24 === 0.0.0.0/0 in (mark 0/0x00000000)
Sep 9 16:39:06 rossini charon: 12[KNL] sending XFRM_MSG_GETPOLICY: => 80 bytes @ 0x7f700e812890
Sep 9 16:39:06 rossini charon: 12[KNL] 0: 50 00 00 00 15 00 01 00 90 9C 01 00 E6 1C 00 00 P...............
Sep 9 16:39:06 rossini charon: 12[KNL] 16: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:06 rossini charon: 12[KNL] 32: C0 A8 C8 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:06 rossini charon: 12[KNL] 48: 00 00 00 00 00 00 00 00 02 00 00 18 00 00 00 00 ................
Sep 9 16:39:06 rossini charon: 12[KNL] 64: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:06 rossini charon: 12[KNL] querying policy 192.168.200.0/24 === 0.0.0.0/0 fwd (mark 0/0x00000000)
Sep 9 16:39:06 rossini charon: 12[KNL] sending XFRM_MSG_GETPOLICY: => 80 bytes @ 0x7f700e812890
Sep 9 16:39:06 rossini charon: 12[KNL] 0: 50 00 00 00 15 00 01 00 91 9C 01 00 E6 1C 00 00 P...............
Sep 9 16:39:06 rossini charon: 12[KNL] 16: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:06 rossini charon: 12[KNL] 32: C0 A8 C8 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:06 rossini charon: 12[KNL] 48: 00 00 00 00 00 00 00 00 02 00 00 18 00 00 00 00 ................
Sep 9 16:39:06 rossini charon: 12[KNL] 64: 00 00 00 00 00 00 00 00 00 00 00 00 02 00 00 00 ................
Sep 9 16:39:06 rossini charon: 12[KNL] querying policy 192.168.200.0/24 === 0.0.0.0/0 in (mark 0/0x00000000)
Sep 9 16:39:06 rossini charon: 12[KNL] sending XFRM_MSG_GETPOLICY: => 80 bytes @ 0x7f700e812890
Sep 9 16:39:06 rossini charon: 12[KNL] 0: 50 00 00 00 15 00 01 00 92 9C 01 00 E6 1C 00 00 P...............
Sep 9 16:39:06 rossini charon: 12[KNL] 16: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:06 rossini charon: 12[KNL] 32: C0 A8 C8 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:06 rossini charon: 12[KNL] 48: 00 00 00 00 00 00 00 00 02 00 00 18 00 00 00 00 ................
Sep 9 16:39:06 rossini charon: 12[KNL] 64: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:06 rossini charon: 12[KNL] querying policy 192.168.200.0/24 === 0.0.0.0/0 fwd (mark 0/0x00000000)
Sep 9 16:39:06 rossini charon: 12[KNL] sending XFRM_MSG_GETPOLICY: => 80 bytes @ 0x7f700e812890
Sep 9 16:39:06 rossini charon: 12[KNL] 0: 50 00 00 00 15 00 01 00 93 9C 01 00 E6 1C 00 00 P...............
Sep 9 16:39:06 rossini charon: 12[KNL] 16: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:06 rossini charon: 12[KNL] 32: C0 A8 C8 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:06 rossini charon: 12[KNL] 48: 00 00 00 00 00 00 00 00 02 00 00 18 00 00 00 00 ................
Sep 9 16:39:06 rossini charon: 12[KNL] 64: 00 00 00 00 00 00 00 00 00 00 00 00 02 00 00 00 ................
Sep 9 16:39:06 rossini charon: 12[MGR] checkin IKE_SA rw-test1[487]
Sep 9 16:39:06 rossini charon: 12[MGR] check-in of IKE_SA successful.
Sep 9 16:39:14 rossini charon: 08[KNL] received a XFRM_MSG_EXPIRE
Sep 9 16:39:14 rossini charon: 08[KNL] creating delete job for ESP CHILD_SA with SPI 3386db66 and reqid {1}
Sep 9 16:39:14 rossini charon: 09[MGR] checkout IKE_SA by ID
Sep 9 16:39:14 rossini charon: 14[KNL] received a XFRM_MSG_EXPIRE
Sep 9 16:39:14 rossini charon: 09[MGR] IKE_SA rw-test1[487] successfully checked out
Sep 9 16:39:14 rossini charon: 14[KNL] creating delete job for ESP CHILD_SA with SPI c779dcad and reqid {1}
Sep 9 16:39:14 rossini charon: 09[IKE] queueing QUICK_DELETE task
Sep 9 16:39:14 rossini charon: 09[IKE] activating new tasks
Sep 9 16:39:14 rossini charon: 14[MGR] checkout IKE_SA by ID
Sep 9 16:39:14 rossini charon: 09[IKE] activating QUICK_DELETE task
Sep 9 16:39:14 rossini charon: 09[IKE] closing expired CHILD_SA rw-test1{1} with SPIs c779dcad_i 3386db66_o and TS 0.0.0.0/0 === 192.168.200.0/24
Sep 9 16:39:14 rossini charon: 09[KNL] deleting SAD entry with SPI c779dcad (mark 0/0x00000000)
Sep 9 16:39:14 rossini charon: 09[KNL] sending XFRM_MSG_DELSA: => 40 bytes @ 0x7f70106157a0
Sep 9 16:39:14 rossini charon: 09[KNL] 0: 28 00 00 00 11 00 05 00 94 9C 01 00 E6 1C 00 00 (...............
Sep 9 16:39:14 rossini charon: 09[KNL] 16: D9 0E A0 45 00 00 00 00 00 00 00 00 00 00 00 00 ...E............
Sep 9 16:39:14 rossini charon: 09[KNL] 32: C7 79 DC AD 02 00 32 00 .y....2.
Sep 9 16:39:14 rossini charon: 09[KNL] deleting SAD entry with SPI 3386db66 (mark 0/0x00000000)
Sep 9 16:39:14 rossini charon: 09[KNL] sending XFRM_MSG_DELSA: => 40 bytes @ 0x7f70106157a0
Sep 9 16:39:14 rossini charon: 09[KNL] 0: 28 00 00 00 11 00 05 00 95 9C 01 00 E6 1C 00 00 (...............
Sep 9 16:39:14 rossini charon: 09[KNL] 16: 4E 31 E1 28 00 00 00 00 00 00 00 00 00 00 00 00 N1.(............
Sep 9 16:39:14 rossini charon: 09[KNL] 32: 33 86 DB 66 02 00 32 00 3..f..2.
Sep 9 16:39:14 rossini charon: 09[KNL] deleting policy 0.0.0.0/0 === 192.168.200.0/24 out (mark 0/0x00000000)
Sep 9 16:39:14 rossini charon: 09[KNL] policy still used by another CHILD_SA, not removed
Sep 9 16:39:14 rossini charon: 09[KNL] updating policy 0.0.0.0/0 === 192.168.200.0/24 out (mark 0/0x00000000)
Sep 9 16:39:14 rossini charon: 09[KNL] sending XFRM_MSG_UPDPOLICY: => 252 bytes @ 0x7f7010615210
Sep 9 16:39:14 rossini charon: 09[KNL] 0: FC 00 00 00 19 00 05 00 96 9C 01 00 E6 1C 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 16: C0 A8 C8 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 32: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 48: 00 00 00 00 00 00 00 00 02 00 18 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 64: 00 00 00 00 00 00 00 00 FF FF FF FF FF FF FF FF ................
Sep 9 16:39:14 rossini charon: 09[KNL] 80: FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
Sep 9 16:39:14 rossini charon: 09[KNL] 96: FF FF FF FF FF FF FF FF 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 112: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 128: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 144: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 160: 00 00 00 00 00 00 00 00 A3 07 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 176: 01 00 00 00 00 00 00 00 44 00 05 00 4E 31 E1 28 ........D...N1.(
Sep 9 16:39:14 rossini charon: 09[KNL] 192: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 208: 32 00 00 00 02 00 00 00 D9 0E A0 45 00 00 00 00 2..........E....
Sep 9 16:39:14 rossini charon: 09[KNL] 224: 00 00 00 00 00 00 00 00 01 00 00 00 01 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 240: FF FF FF FF FF FF FF FF FF FF FF FF ............
Sep 9 16:39:14 rossini charon: 09[KNL] deleting policy 192.168.200.0/24 === 0.0.0.0/0 in (mark 0/0x00000000)
Sep 9 16:39:14 rossini charon: 09[KNL] policy still used by another CHILD_SA, not removed
Sep 9 16:39:14 rossini charon: 09[KNL] updating policy 192.168.200.0/24 === 0.0.0.0/0 in (mark 0/0x00000000)
Sep 9 16:39:14 rossini charon: 09[KNL] sending XFRM_MSG_UPDPOLICY: => 252 bytes @ 0x7f7010615210
Sep 9 16:39:14 rossini charon: 09[KNL] 0: FC 00 00 00 19 00 05 00 97 9C 01 00 E6 1C 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 16: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 32: C0 A8 C8 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 48: 00 00 00 00 00 00 00 00 02 00 00 18 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 64: 00 00 00 00 00 00 00 00 FF FF FF FF FF FF FF FF ................
Sep 9 16:39:14 rossini charon: 09[KNL] 80: FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
Sep 9 16:39:14 rossini charon: 09[KNL] 96: FF FF FF FF FF FF FF FF 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 112: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 128: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 144: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 160: 00 00 00 00 00 00 00 00 A3 07 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 176: 00 00 00 00 00 00 00 00 44 00 05 00 D9 0E A0 45 ........D......E
Sep 9 16:39:14 rossini charon: 09[KNL] 192: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 208: 32 00 00 00 02 00 00 00 4E 31 E1 28 00 00 00 00 2.......N1.(....
Sep 9 16:39:14 rossini charon: 09[KNL] 224: 00 00 00 00 00 00 00 00 01 00 00 00 01 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 240: FF FF FF FF FF FF FF FF FF FF FF FF ............
Sep 9 16:39:14 rossini charon: 09[KNL] deleting policy 192.168.200.0/24 === 0.0.0.0/0 fwd (mark 0/0x00000000)
Sep 9 16:39:14 rossini charon: 09[KNL] policy still used by another CHILD_SA, not removed
Sep 9 16:39:14 rossini charon: 09[KNL] updating policy 192.168.200.0/24 === 0.0.0.0/0 fwd (mark 0/0x00000000)
Sep 9 16:39:14 rossini charon: 09[KNL] sending XFRM_MSG_UPDPOLICY: => 252 bytes @ 0x7f7010615210
Sep 9 16:39:14 rossini charon: 09[KNL] 0: FC 00 00 00 19 00 05 00 98 9C 01 00 E6 1C 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 16: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 32: C0 A8 C8 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 48: 00 00 00 00 00 00 00 00 02 00 00 18 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 64: 00 00 00 00 00 00 00 00 FF FF FF FF FF FF FF FF ................
Sep 9 16:39:14 rossini charon: 09[KNL] 80: FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
Sep 9 16:39:14 rossini charon: 09[KNL] 96: FF FF FF FF FF FF FF FF 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 112: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 128: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 144: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 160: 00 00 00 00 00 00 00 00 A3 07 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 176: 02 00 00 00 00 00 00 00 44 00 05 00 D9 0E A0 45 ........D......E
Sep 9 16:39:14 rossini charon: 09[KNL] 192: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 208: 32 00 00 00 02 00 00 00 4E 31 E1 28 00 00 00 00 2.......N1.(....
Sep 9 16:39:14 rossini charon: 09[KNL] 224: 00 00 00 00 00 00 00 00 01 00 00 00 01 00 00 00 ................
Sep 9 16:39:14 rossini charon: 09[KNL] 240: FF FF FF FF FF FF FF FF FF FF FF FF ............
Sep 9 16:39:14 rossini charon: 09[KNL] getting a local address in traffic selector 0.0.0.0/0
Sep 9 16:39:14 rossini charon: 09[KNL] using host %any
Sep 9 16:39:14 rossini charon: 09[KNL] using 217.14.X.X as nexthop to reach 78.49.225.40
Sep 9 16:39:14 rossini charon: 09[KNL] 217.14.X.Y is on interface bond0.11
Sep 9 16:39:14 rossini charon: 09[KNL] deleting policy 0.0.0.0/0 === 192.168.200.0/24 out (mark 0/0x00000000)
Sep 9 16:39:14 rossini charon: 09[KNL] policy still used by another CHILD_SA, not removed
Sep 9 16:39:14 rossini charon: 09[KNL] deleting policy 192.168.200.0/24 === 0.0.0.0/0 in (mark 0/0x00000000)
Sep 9 16:39:14 rossini charon: 09[KNL] policy still used by another CHILD_SA, not removed
Sep 9 16:39:14 rossini charon: 09[KNL] deleting policy 192.168.200.0/24 === 0.0.0.0/0 fwd (mark 0/0x00000000)
Sep 9 16:39:14 rossini charon: 09[KNL] policy still used by another CHILD_SA, not removed
Sep 9 16:39:14 rossini charon: 09[IKE] sending DELETE for ESP CHILD_SA with SPI c779dcad
Sep 9 16:39:14 rossini charon: 09[ENC] added payload of type DELETE_V1 to message
Sep 9 16:39:14 rossini charon: 09[ENC] added payload of type DELETE_V1 to message
Sep 9 16:39:14 rossini charon: 09[IKE] Hash => 20 bytes @ 0x7f6fcc001460
Sep 9 16:39:14 rossini charon: 09[IKE] 0: 1D A3 BA 82 A5 32 BA 17 6C 14 32 B1 72 60 02 D2 .....2..l.2.r`..
Sep 9 16:39:14 rossini charon: 09[IKE] 16: D7 7F CC A0 ....
Sep 9 16:39:14 rossini charon: 09[ENC] generating INFORMATIONAL_V1 request 2218840076 [ HASH D ]
Sep 9 16:39:14 rossini charon: 09[ENC] insert payload HASH_V1 into encrypted payload
Sep 9 16:39:14 rossini charon: 09[ENC] insert payload DELETE_V1 into encrypted payload
Sep 9 16:39:28 rossini charon: 05[MGR] checkout IKE_SA by ID
Sep 9 16:39:28 rossini charon: 05[MGR] IKE_SA rw-test1[487] successfully checked out
Sep 9 16:39:28 rossini charon: 05[KNL] querying policy 192.168.200.0/24 === 0.0.0.0/0 in (mark 0/0x00000000)
Sep 9 16:39:28 rossini charon: 05[KNL] sending XFRM_MSG_GETPOLICY: => 80 bytes @ 0x7f7012e198a0
Sep 9 16:39:28 rossini charon: 05[KNL] 0: 50 00 00 00 15 00 01 00 99 9C 01 00 E6 1C 00 00 P...............
Sep 9 16:39:28 rossini charon: 05[KNL] 16: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:28 rossini charon: 05[KNL] 32: C0 A8 C8 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:28 rossini charon: 05[KNL] 48: 00 00 00 00 00 00 00 00 02 00 00 18 00 00 00 00 ................
Sep 9 16:39:28 rossini charon: 05[KNL] 64: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:28 rossini charon: 05[KNL] querying policy 192.168.200.0/24 === 0.0.0.0/0 fwd (mark 0/0x00000000)
Sep 9 16:39:28 rossini charon: 05[KNL] sending XFRM_MSG_GETPOLICY: => 80 bytes @ 0x7f7012e198a0
Sep 9 16:39:28 rossini charon: 05[KNL] 0: 50 00 00 00 15 00 01 00 9A 9C 01 00 E6 1C 00 00 P...............
Sep 9 16:39:28 rossini charon: 05[KNL] 16: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:28 rossini charon: 05[KNL] 32: C0 A8 C8 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:28 rossini charon: 05[KNL] 48: 00 00 00 00 00 00 00 00 02 00 00 18 00 00 00 00 ................
Sep 9 16:39:28 rossini charon: 05[KNL] 64: 00 00 00 00 00 00 00 00 00 00 00 00 02 00 00 00 ................
Sep 9 16:39:28 rossini charon: 05[KNL] querying policy 0.0.0.0/0 === 192.168.200.0/24 out (mark 0/0x00000000)
Sep 9 16:39:28 rossini charon: 05[KNL] sending XFRM_MSG_GETPOLICY: => 80 bytes @ 0x7f7012e198a0
Sep 9 16:39:28 rossini charon: 05[KNL] 0: 50 00 00 00 15 00 01 00 9B 9C 01 00 E6 1C 00 00 P...............
Sep 9 16:39:28 rossini charon: 05[KNL] 16: C0 A8 C8 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:28 rossini charon: 05[KNL] 32: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:28 rossini charon: 05[KNL] 48: 00 00 00 00 00 00 00 00 02 00 18 00 00 00 00 00 ................
Sep 9 16:39:28 rossini charon: 05[KNL] 64: 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 ................
Sep 9 16:39:28 rossini charon: 05[MGR] checkin IKE_SA rw-test1[487]
Sep 9 16:39:28 rossini charon: 05[MGR] check-in of IKE_SA successful.
Sep 9 16:39:29 rossini charon: 04[MGR] checkout IKE_SA by ID
Sep 9 16:39:29 rossini charon: 04[MGR] IKE_SA rw-test1[487] successfully checked out
Sep 9 16:39:29 rossini charon: 04[KNL] querying policy 192.168.200.0/24 === 0.0.0.0/0 in (mark 0/0x00000000)
Sep 9 16:39:29 rossini charon: 04[KNL] sending XFRM_MSG_GETPOLICY: => 80 bytes @ 0x7f701381a8a0
Sep 9 16:39:29 rossini charon: 04[KNL] 0: 50 00 00 00 15 00 01 00 9C 9C 01 00 E6 1C 00 00 P...............
Sep 9 16:39:29 rossini charon: 04[KNL] 16: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:29 rossini charon: 04[KNL] 32: C0 A8 C8 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:29 rossini charon: 04[KNL] 48: 00 00 00 00 00 00 00 00 02 00 00 18 00 00 00 00 ................
Sep 9 16:39:29 rossini charon: 04[KNL] 64: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:29 rossini charon: 04[KNL] querying policy 192.168.200.0/24 === 0.0.0.0/0 fwd (mark 0/0x00000000)
Sep 9 16:39:29 rossini charon: 04[KNL] sending XFRM_MSG_GETPOLICY: => 80 bytes @ 0x7f701381a8a0
Sep 9 16:39:29 rossini charon: 04[KNL] 0: 50 00 00 00 15 00 01 00 9D 9C 01 00 E6 1C 00 00 P...............
Sep 9 16:39:29 rossini charon: 04[KNL] 16: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:29 rossini charon: 04[KNL] 32: C0 A8 C8 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:29 rossini charon: 04[KNL] 48: 00 00 00 00 00 00 00 00 02 00 00 18 00 00 00 00 ................
Sep 9 16:39:29 rossini charon: 04[KNL] 64: 00 00 00 00 00 00 00 00 00 00 00 00 02 00 00 00 ................
Sep 9 16:39:29 rossini charon: 04[KNL] querying policy 0.0.0.0/0 === 192.168.200.0/24 out (mark 0/0x00000000)
Sep 9 16:39:29 rossini charon: 04[KNL] sending XFRM_MSG_GETPOLICY: => 80 bytes @ 0x7f701381a8a0
Sep 9 16:39:29 rossini charon: 04[KNL] 0: 50 00 00 00 15 00 01 00 9E 9C 01 00 E6 1C 00 00 P...............
Sep 9 16:39:29 rossini charon: 04[KNL] 16: C0 A8 C8 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:29 rossini charon: 04[KNL] 32: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:29 rossini charon: 04[KNL] 48: 00 00 00 00 00 00 00 00 02 00 18 00 00 00 00 00 ................
Sep 9 16:39:29 rossini charon: 04[KNL] 64: 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 ................
Sep 9 16:39:29 rossini charon: 04[MGR] checkin IKE_SA rw-test1[487]
Sep 9 16:39:29 rossini charon: 04[MGR] check-in of IKE_SA successful.
Sep 9 16:39:29 rossini charon: 11[MGR] checkout IKE_SA by ID
Sep 9 16:39:29 rossini charon: 11[MGR] IKE_SA rw-test1[487] successfully checked out
Sep 9 16:39:29 rossini charon: 11[KNL] querying policy 192.168.200.0/24 === 0.0.0.0/0 in (mark 0/0x00000000)
Sep 9 16:39:29 rossini charon: 11[KNL] sending XFRM_MSG_GETPOLICY: => 80 bytes @ 0x7f700f2138a0
Sep 9 16:39:29 rossini charon: 11[KNL] 0: 50 00 00 00 15 00 01 00 9F 9C 01 00 E6 1C 00 00 P...............
Sep 9 16:39:29 rossini charon: 11[KNL] 16: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:29 rossini charon: 11[KNL] 32: C0 A8 C8 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:29 rossini charon: 11[KNL] 48: 00 00 00 00 00 00 00 00 02 00 00 18 00 00 00 00 ................
Sep 9 16:39:29 rossini charon: 11[KNL] 64: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:29 rossini charon: 11[KNL] querying policy 192.168.200.0/24 === 0.0.0.0/0 fwd (mark 0/0x00000000)
Sep 9 16:39:29 rossini charon: 11[KNL] sending XFRM_MSG_GETPOLICY: => 80 bytes @ 0x7f700f2138a0
Sep 9 16:39:29 rossini charon: 11[KNL] 0: 50 00 00 00 15 00 01 00 A0 9C 01 00 E6 1C 00 00 P...............
Sep 9 16:39:29 rossini charon: 11[KNL] 16: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:29 rossini charon: 11[KNL] 32: C0 A8 C8 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:29 rossini charon: 11[KNL] 48: 00 00 00 00 00 00 00 00 02 00 00 18 00 00 00 00 ................
Sep 9 16:39:29 rossini charon: 11[KNL] 64: 00 00 00 00 00 00 00 00 00 00 00 00 02 00 00 00 ................
Sep 9 16:39:29 rossini charon: 11[KNL] querying policy 0.0.0.0/0 === 192.168.200.0/24 out (mark 0/0x00000000)
Sep 9 16:39:29 rossini charon: 11[KNL] sending XFRM_MSG_GETPOLICY: => 80 bytes @ 0x7f700f2138a0
Sep 9 16:39:29 rossini charon: 11[KNL] 0: 50 00 00 00 15 00 01 00 A1 9C 01 00 E6 1C 00 00 P...............
Sep 9 16:39:29 rossini charon: 11[KNL] 16: C0 A8 C8 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:29 rossini charon: 11[KNL] 32: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Sep 9 16:39:29 rossini charon: 11[KNL] 48: 00 00 00 00 00 00 00 00 02 00 18 00 00 00 00 00 ................
Sep 9 16:39:29 rossini charon: 11[KNL] 64: 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 ................
Sep 9 16:39:29 rossini charon: 11[MGR] checkin IKE_SA rw-test1[487]
Sep 9 16:39:29 rossini charon: 11[MGR] check-in of IKE_SA successful.
Sep 9 16:39:35 rossini charon: 02[NET] received packet => 92 bytes @ 0x7f7014c1a3e0
Sep 9 16:39:35 rossini charon: 02[NET] 0: 4D AD 7D 9A B6 37 5F 48 12 A8 05 31 3F 7B 72 87 M.}..7_H...1?{r.
Sep 9 16:39:35 rossini charon: 02[NET] 16: 08 10 05 01 69 07 9B 39 00 00 00 5C B0 03 67 F2 ....i..9...\..g.
Sep 9 16:39:35 rossini charon: 02[NET] 32: E0 5C 04 65 75 EB 69 93 A3 79 9C 58 47 A8 81 7E .\.eu.i..y.XG..~
Sep 9 16:39:35 rossini charon: 02[NET] 48: F1 B5 76 D1 7B 49 8B 5F 3B 4C BE 33 C8 17 0C 21 ..v.{I._;L.3...!
Sep 9 16:39:35 rossini charon: 02[NET] 64: 85 5F 10 4C 8F EF F1 97 E4 F2 50 13 77 CA 48 FB ._.L......P.w.H.
Sep 9 16:39:35 rossini charon: 02[NET] 80: 55 84 93 8F BD AA 50 7D 36 99 FB 1D U.....P}6...
Sep 9 16:39:35 rossini charon: 02[NET] received packet: from 78.49.225.40[500] to 217.14.160.69[500]
Sep 9 16:39:35 rossini charon: 02[ENC] parsing header of message
Sep 9 16:39:35 rossini charon: 02[ENC] parsing HEADER payload, 92 bytes left
Sep 9 16:39:35 rossini charon: 02[ENC] parsing payload from => 92 bytes @ 0x7f6ff4000f20
Sep 9 16:39:35 rossini charon: 02[ENC] 0: 4D AD 7D 9A B6 37 5F 48 12 A8 05 31 3F 7B 72 87 M.}..7_H...1?{r.
Sep 9 16:39:35 rossini charon: 02[ENC] 16: 08 10 05 01 69 07 9B 39 00 00 00 5C B0 03 67 F2 ....i..9...\..g.
Sep 9 16:39:35 rossini charon: 02[ENC] 32: E0 5C 04 65 75 EB 69 93 A3 79 9C 58 47 A8 81 7E .\.eu.i..y.XG..~
Sep 9 16:39:35 rossini charon: 02[ENC] 48: F1 B5 76 D1 7B 49 8B 5F 3B 4C BE 33 C8 17 0C 21 ..v.{I._;L.3...!
Sep 9 16:39:35 rossini charon: 02[ENC] 64: 85 5F 10 4C 8F EF F1 97 E4 F2 50 13 77 CA 48 FB ._.L......P.w.H.
Sep 9 16:39:35 rossini charon: 02[ENC] 80: 55 84 93 8F BD AA 50 7D 36 99 FB 1D U.....P}6...
Sep 9 16:39:35 rossini charon: 02[ENC] parsing rule 0 IKE_SPI
Sep 9 16:39:35 rossini charon: 02[ENC] => 8 bytes @ 0x7f6ff4001098
Sep 9 16:39:35 rossini charon: 02[ENC] 0: 4D AD 7D 9A B6 37 5F 48 M.}..7_H
Sep 9 16:39:35 rossini charon: 02[ENC] parsing rule 1 IKE_SPI
Sep 9 16:39:35 rossini charon: 02[ENC] => 8 bytes @ 0x7f6ff40010a0
Sep 9 16:39:35 rossini charon: 02[ENC] 0: 12 A8 05 31 3F 7B 72 87 ...1?{r.
Sep 9 16:39:35 rossini charon: 02[ENC] parsing rule 2 U_INT_8
Sep 9 16:39:35 rossini charon: 02[ENC] => 8
Sep 9 16:39:35 rossini charon: 02[ENC] parsing rule 3 U_INT_4
Sep 9 16:39:35 rossini charon: 02[ENC] => 1
Sep 9 16:39:35 rossini charon: 02[ENC] parsing rule 4 U_INT_4
Sep 9 16:39:35 rossini charon: 02[ENC] => 0
Sep 9 16:39:35 rossini charon: 02[ENC] parsing rule 5 U_INT_8
Sep 9 16:39:35 rossini charon: 02[ENC] => 5
Sep 9 16:39:35 rossini charon: 02[ENC] parsing rule 6 RESERVED_BIT
Sep 9 16:39:35 rossini charon: 02[ENC] => 0
Sep 9 16:39:35 rossini charon: 02[ENC] parsing rule 7 RESERVED_BIT
Sep 9 16:39:35 rossini charon: 02[ENC] => 0
Sep 9 16:39:35 rossini charon: 02[ENC] parsing rule 8 FLAG
Sep 9 16:39:35 rossini charon: 02[ENC] => 0
Sep 9 16:39:35 rossini charon: 02[ENC] parsing rule 9 FLAG
Sep 9 16:39:35 rossini charon: 02[ENC] => 0
Sep 9 16:39:35 rossini charon: 02[ENC] parsing rule 10 FLAG
Sep 9 16:39:35 rossini charon: 02[ENC] => 0
Sep 9 16:39:35 rossini charon: 02[ENC] parsing rule 11 FLAG
Sep 9 16:39:35 rossini charon: 02[ENC] => 0
Sep 9 16:39:35 rossini charon: 02[ENC] parsing rule 12 FLAG
Sep 9 16:39:35 rossini charon: 02[ENC] => 0
Sep 9 16:39:35 rossini charon: 02[ENC] parsing rule 13 FLAG
Sep 9 16:39:35 rossini charon: 02[ENC] => 1
Sep 9 16:39:35 rossini charon: 02[ENC] parsing rule 14 U_INT_32
Sep 9 16:39:35 rossini charon: 02[ENC] => 1762106169
Sep 9 16:39:35 rossini charon: 02[ENC] parsing rule 15 HEADER_LENGTH
Sep 9 16:39:35 rossini charon: 02[ENC] => 92
Sep 9 16:39:35 rossini charon: 02[ENC] parsing HEADER payload finished
Sep 9 16:39:35 rossini charon: 02[ENC] parsed a INFORMATIONAL_V1 message header
Sep 9 16:39:35 rossini charon: 02[NET] waiting for data on sockets
Sep 9 16:39:35 rossini charon: 14[MGR] checkout IKE_SA by message
Sep 9 16:39:35 rossini charon: 14[MGR] IKE_SA rw-test1[487] successfully checked out
Sep 9 16:39:35 rossini charon: 14[NET] received packet: from 78.49.X.Y[500] to 217.14.X.Y[500] (92 bytes)
Sep 9 16:39:35 rossini charon: 14[ENC] parsing body of message, first payload is HASH_V1
Sep 9 16:39:35 rossini charon: 14[ENC] parsing ENCRYPTED_V1 payload, 64 bytes left
Sep 9 16:39:35 rossini charon: 14[ENC] parsing payload from => 64 bytes @ 0x7f6ff4000f3c
Sep 9 16:39:35 rossini charon: 14[ENC] 0: B0 03 67 F2 E0 5C 04 65 75 EB 69 93 A3 79 9C 58 ..g..\.eu.i..y.X
Sep 9 16:39:35 rossini charon: 14[ENC] 16: 47 A8 81 7E F1 B5 76 D1 7B 49 8B 5F 3B 4C BE 33 G..~..v.{I._;L.3
Sep 9 16:39:35 rossini charon: 14[ENC] 32: C8 17 0C 21 85 5F 10 4C 8F EF F1 97 E4 F2 50 13 ...!._.L......P.
Sep 9 16:39:35 rossini charon: 14[ENC] 48: 77 CA 48 FB 55 84 93 8F BD AA 50 7D 36 99 FB 1D w.H.U.....P}6...
Sep 9 16:39:35 rossini charon: 14[ENC] parsing rule 0 ENCRYPTED_DATA
Sep 9 16:39:35 rossini charon: 14[ENC] => 64 bytes @ 0x7f6fc0004170
Sep 9 16:39:35 rossini charon: 14[ENC] 0: B0 03 67 F2 E0 5C 04 65 75 EB 69 93 A3 79 9C 58 ..g..\.eu.i..y.X
Sep 9 16:39:35 rossini charon: 14[ENC] 16: 47 A8 81 7E F1 B5 76 D1 7B 49 8B 5F 3B 4C BE 33 G..~..v.{I._;L.3
Sep 9 16:39:35 rossini charon: 14[ENC] 32: C8 17 0C 21 85 5F 10 4C 8F EF F1 97 E4 F2 50 13 ...!._.L......P.
Sep 9 16:39:35 rossini charon: 14[ENC] 48: 77 CA 48 FB 55 84 93 8F BD AA 50 7D 36 99 FB 1D w.H.U.....P}6...
Sep 9 16:39:35 rossini charon: 14[ENC] parsing ENCRYPTED_V1 payload finished
Sep 9 16:39:35 rossini charon: 14[ENC] process payload of type ENCRYPTED_V1
Sep 9 16:39:35 rossini charon: 14[ENC] found an encrypted payload
Sep 9 16:39:35 rossini charon: 14[IKE] next IV for MID 1762106169 => 16 bytes @ 0x7f6fc0001190
Sep 9 16:39:35 rossini charon: 14[IKE] 0: 03 1F 8D EF 57 73 7C CC 23 D5 C1 D1 DF F8 30 A6 ....Ws|.#.....0.
Sep 9 16:39:35 rossini charon: 14[ENC] decrypting payloads:
Sep 9 16:39:35 rossini charon: 14[ENC] encrypted => 64 bytes @ 0x7f6fc0004170
Sep 9 16:39:35 rossini charon: 14[ENC] 0: B0 03 67 F2 E0 5C 04 65 75 EB 69 93 A3 79 9C 58 ..g..\.eu.i..y.X
Sep 9 16:39:35 rossini charon: 14[ENC] 16: 47 A8 81 7E F1 B5 76 D1 7B 49 8B 5F 3B 4C BE 33 G..~..v.{I._;L.3
Sep 9 16:39:35 rossini charon: 14[ENC] 32: C8 17 0C 21 85 5F 10 4C 8F EF F1 97 E4 F2 50 13 ...!._.L......P.
Sep 9 16:39:35 rossini charon: 14[ENC] 48: 77 CA 48 FB 55 84 93 8F BD AA 50 7D 36 99 FB 1D w.H.U.....P}6...
Sep 9 16:39:35 rossini charon: 14[ENC] plain => 64 bytes @ 0x7f6fc0004170
Sep 9 16:39:35 rossini charon: 14[ENC] 0: 0B 00 00 18 85 EC 3F F4 4B FD ED 76 88 A2 75 1F ......?.K..v..u.
Sep 9 16:39:35 rossini charon: 14[ENC] 16: DF 75 8C 54 AB FC 6D 85 00 00 00 20 00 00 00 01 .u.T..m.... ....
Sep 9 16:39:35 rossini charon: 14[ENC] 32: 01 10 8D 28 4D AD 7D 9A B6 37 5F 48 12 A8 05 31 ...(M.}..7_H...1
Sep 9 16:39:35 rossini charon: 14[ENC] 48: 3F 7B 72 87 15 17 CD 30 00 00 00 00 00 00 00 00 ?{r....0........
Sep 9 16:39:35 rossini charon: 14[ENC] parsing HASH_V1 payload, 64 bytes left
Sep 9 16:39:35 rossini charon: 14[ENC] parsing payload from => 64 bytes @ 0x7f6fc0004170
Sep 9 16:39:35 rossini charon: 14[ENC] 0: 0B 00 00 18 85 EC 3F F4 4B FD ED 76 88 A2 75 1F ......?.K..v..u.
Sep 9 16:39:35 rossini charon: 14[ENC] 16: DF 75 8C 54 AB FC 6D 85 00 00 00 20 00 00 00 01 .u.T..m.... ....
Sep 9 16:39:35 rossini charon: 14[ENC] 32: 01 10 8D 28 4D AD 7D 9A B6 37 5F 48 12 A8 05 31 ...(M.}..7_H...1
Sep 9 16:39:35 rossini charon: 14[ENC] 48: 3F 7B 72 87 15 17 CD 30 00 00 00 00 00 00 00 00 ?{r....0........
Sep 9 16:39:35 rossini charon: 14[ENC] parsing rule 0 U_INT_8
Sep 9 16:39:35 rossini charon: 14[ENC] => 11
Sep 9 16:39:35 rossini charon: 14[ENC] parsing rule 1 RESERVED_BYTE
Sep 9 16:39:35 rossini charon: 14[ENC] => 0
Sep 9 16:39:35 rossini charon: 14[ENC] parsing rule 2 PAYLOAD_LENGTH
Sep 9 16:39:35 rossini charon: 14[ENC] => 24
Sep 9 16:39:35 rossini charon: 14[ENC] parsing rule 3 CHUNK_DATA
History
#1 Updated by Tobias Brunner over 8 years ago
- Description updated (diff)
- Status changed from New to Feedback
- Assignee set to Tobias Brunner
This results in an unstable VPN connection if I do not add a rightip to this conn (which may result in strongswan setting up the connection).
Hm, I'm not sure I understand your reasoning here. Why should strongSwan initiate the connection if the only thing you change is right=<ip>? Unless you use ipsec up <name>, auto=start or auto=route strongSwan has no reason to initiate the connection.
And how exactly does setting an IP fix this issue? How are the log or the dumped packets different?
The log you posted shows a DELETE request from strongSwan because the IPsec SA expired:
Sep 9 16:39:14 rossini charon: 09[IKE] closing expired CHILD_SA rw-test1{1} with SPIs c779dcad_i 3386db66_o and TS 0.0.0.0/0 === 192.168.200.0/24
This is the shorter message you see in the tcpdump output. The FRITZ!Box seems to delete those SAs too:
2013-09-09 16:39:14 avmike:FreeIPsecSA: spi=3386db66 protocol=3 iotype=1 2013-09-09 16:39:14 avmike:FreeIPsecSA: spi=c779dcad protocol=3 iotype=2
It's unclear, though, whether it does so because of the received DELETE payload or because the SA expired locally too. Maybe the box expected a DPD packet and has a problem that it received a DELETE request instead. But from the timings of the captured packets that seems unlikely:
16:37:35 strongswan-server.net.isakmp > avmclient.net.isakmp DPD response 16:39:14 strongswan-server.net.isakmp > avmclient.net.isakmp DELETE request (there maybe be no response as DELETES are unconfirmed, with informational character only) 16:39:35 avmclient.net.isakmp > strongswan-server.net.isakmp DPD request 16:39:35 strongswan-server.net.isakmp > avmclient.net.isakmp DPD response
So perhaps the error is because it, in fact, deleted the SAs locally and now can't find any SAs with the SPIs referenced in the DELETE payload (some forum messages regarding that error indicated as much). But since we can't be sure, you perhaps should ask AVM what the message means exactly.
Anyway, since there seems to be another successful DPD exchange later the question is, what exactly is the problem? Does rekeying not work? That is, is there no IPsec SA after this?
Perhaps you should have a look at your lifetime configuration.
#2 Updated by Andre Valentin over 8 years ago
Hi!
Tobias Brunner wrote:
Hm, I'm not sure I understand your reasoning here. Why should strongSwan initiate the connection if the only thing you change is right=<ip>? Unless you use
ipsec up <name>, auto=start or auto=route strongSwan has no reason to initiate the connection.
Okay, I migrated these VPN's from racoon to strongswan. If I use racoon as a responder, I get no errors in the log. Also rekeying always works fine. With strongswan, I get those errors and sometimes rekeying breaks in a way, that there is an SA but no communication is possible, or there is no SA on the strongswan side.
That's why I opened that ticket.
If I use
right=%xyz.dyndns
everyhing works because strongswan will setup the tunnel. I took all lifetimes from the working racoon config.
Perhaps you should have a look at your lifetime configuration.
I tried every combination, but after some days there is always a problem.
If it helps, I could recreate the whole setup that worked in racoon as a strongswan config and sniff and log everything.
Here is my current config:
config setup
uniqueids=no
conn %default
ikelifetime=1h
lifetime=1h
rekeymargin=3m
keyingtries=1
authby=secret
conn fritz-base
left=217.14.X.Y
leftsubnet=0.0.0.0/0
leftid=@xxxx.yyyy.ff
rightallowany=yes
# Phase 1 and 2
ikelifetime=1h
lifetime=20m
ike=aes256-sha1-modp1024
esp=aes256-sha1-modp1024
# Does not work
compress=no
aggressive=no
authby=secret
keyingtries=%forever
keyexchange=ikev1
fragmentation=no
dpdaction=restart
rekey=yes
conn rw-test
also=fritz-base
right=test.dyn.org
rightid=@test.dyn.org
rightsubnet=192.168.200.0/24
auto=route
Thanks for your answer,
André
#3 Updated by Tobias Brunner over 8 years ago
Hm, I'm not sure I understand your reasoning here. Why should strongSwan initiate the connection if the only thing you change is right=<ip>? Unless you use
ipsec up <name>, auto=start or auto=route strongSwan has no reason to initiate the connection.Okay, I migrated these VPN's from racoon to strongswan. If I use racoon as a responder, I get no errors in the log. Also rekeying always works fine. With strongswan, I get those errors and sometimes rekeying breaks in a way, that there is an SA but no communication is possible, or there is no SA on the strongswan side.
There are definitely some interoperability issues with IKEv1 rekeying, for instance #317. Perhaps this is the same issue. Martin just pushed some changes to the ikev1-reauth branch you could try.
Since we rarely have access to the actual devices to do interoperability tests, we mostly fly blindly and do the best we can to follow the RFCs (which of course is an issue with IKEv1 as many details are either not described in RFCs, or implemented differently by different vendors).
If it helps, I could recreate the whole setup that worked in racoon as a strongswan config and sniff and log everything.
More data could definitely help. Especially to see in what state the daemon is when this issue seems to hit. But you don't have to change your config for that. Also, the logs don't have to be as detailed as the excerpt you posted above (level 2 or even level 1 should suffice - particularly on low-level groups like enc or asn1).
#4 Updated by Andre Valentin over 8 years ago
Tobias Brunner wrote:
More data could definitely help. Especially to see in what state the daemon is when this issue seems to hit. But you don't have to change your config for that. Also, the logs don't have to be as detailed as the excerpt you posted above (level 2 or even level 1 should suffice - particularly on low-level groups like enc or asn1).
I will provide the logs, but it will take some days.
Thanks for your support!
André
#5 Updated by Andre Valentin over 8 years ago
Andre Valentin wrote:
I will provide the logs, but it will take some days.
I just noticed this change:
]http://git.strongswan.org/?p=strongswan.git;a=shortlog;h=refs/heads/ikev1-reauth
Perhaps that helps. I will try it before I publish more logs.
Thanks,
André
#6 Updated by Andre Valentin over 8 years ago
Andre Valentin wrote:
http://git.strongswan.org/?p=strongswan.git;a=shortlog;h=refs/heads/ikev1-reauth
This patch fixed my problems when only acting as a responder! Please close this ticket.
Thank you very much for your help,
André
#7 Updated by Tobias Brunner over 8 years ago
- Status changed from Feedback to Closed
- Resolution set to Fixed
That's good to hear, thanks.
#8 Updated by Tobias Brunner over 8 years ago
- Tracker changed from Issue to Bug
- Subject changed from Incompatibility with AVM IKE / Problem with DPD to Incompatibility with AVM IKE / Problem with Reauthentication
- Category set to charon
- Target version set to 5.1.1