[strongSwan] afetr router restart CHILD_SA is established and deleted after a while

Emil Płoski emil.ploski at pks-ostroleka.pl
Mon Oct 1 12:46:44 CEST 2012


Hi

I've got VPN (for testing purposes) between router and PC. After router restart (button; power loss simulation) CHILD_SA is reestablished, but after a while it's deleted. IKE_SA stays established, but CHILD_SA is dead.
'ipsec restart' on both or 'ipsec down/up conn-name' fixes connection.

My ipsec.conf:

config setup
        charondebug="ike 4"

conn %default
        ikelifetime=86400s
        keylife=28800s
        rekeymargin=3m
        keyingtries=%forever
        keyexchange=ikev1
        authby=secret
        esp=aes128-sha1-modp1536
        ike=aes128-sha1-modp1536
        dpdaction=restart
        dpddelay=30s
        dpdtimeout=60s

conn test
        left=195.100.10.197
        leftsubnet=195.100.16.0/24
        right=195.100.10.198
        rightsubnet=10.0.0.0/24
        auto=start
        reauth=no


Log:

2012-10-01 11:45:57 Daemon.Info 195.100.10.197 Jan  1 00:00:33 syslog: 12[IKE] CHILD_SA test{1} established with SPIs c6ddaaae_i c047ff9a_o and TS 195.100.16.0/24 === 10.0.0.0/24
2012-10-01 11:45:57 System0.Info 195.100.10.197 Jan  1 00:00:33 syslog: 12[IKE] CHILD_SA test{1} established with SPIs c6ddaaae_i c047ff9a_o and TS 195.100.16.0/24 === 10.0.0.0/24
2012-10-01 11:45:57 Daemon.Info 195.100.10.197 Jan  1 00:00:33 syslog: 12[IKE] reinitiating already active tasks
2012-10-01 11:45:57 Daemon.Info 195.100.10.197 Jan  1 00:00:33 syslog: 12[IKE]   QUICK_MODE task
2012-10-01 11:45:57 Daemon.Info 195.100.10.197 Jan  1 00:00:33 syslog: 12[IKE] Hash(3) => 20 bytes @ 0x7898a8
2012-10-01 11:45:57 Daemon.Info 195.100.10.197 Jan  1 00:00:33 syslog: 12[IKE]    0: 98 F6 F7 CA 0A 5F 60 31 1D 87 47 93 0F 92 EA E2  ....._`1..G.....
2012-10-01 11:45:57 Daemon.Info 195.100.10.197 Jan  1 00:00:33 syslog: 12[IKE]   16: 93 D1 38 0E                                      ..8.
2012-10-01 11:45:57 Daemon.Info 195.100.10.197 Jan  1 00:00:33 syslog: 12[ENC] generating QUICK_MODE request 3577244664 [ HASH ]
2012-10-01 11:45:57 Daemon.Info 195.100.10.197 Jan  1 00:00:33 syslog: 12[IKE] next IV for MID 3577244664 => 16 bytes @ 0x7898a8
2012-10-01 11:45:57 Daemon.Info 195.100.10.197 Jan  1 00:00:33 syslog: 12[IKE]    0: 16 34 F9 83 30 D6 0E 3B 88 E4 7E 38 E9 37 0D E5  .4..0..;..~8.7..
2012-10-01 11:45:57 Daemon.Info 195.100.10.197 Jan  1 00:00:33 syslog: 12[NET] sending packet: from 195.100.10.197[500] to 195.100.10.198[500]
2012-10-01 11:45:57 Daemon.Info 195.100.10.197 Jan  1 00:00:33 syslog: 12[IKE] activating new tasks
2012-10-01 11:45:57 Daemon.Info 195.100.10.197 Jan  1 00:00:33 syslog: 12[IKE] nothing to initiate
2012-10-01 11:46:00 Daemon.Info 195.100.10.197 Jan  1 00:00:36 dnsmasq[1384]: started, version 2.62 cachesize 150
2012-10-01 11:46:00 Daemon.Info 195.100.10.197 Jan  1 00:00:36 dnsmasq[1384]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP no-DHCPv6 no-Lua TFTP no-conntrack
2012-10-01 11:46:00 Daemon.Info 195.100.10.197 Jan  1 00:00:36 dnsmasq-dhcp[1384]: DHCP, IP range 195.100.16.100 -- 195.100.16.249, lease time 12h
2012-10-01 11:46:00 Daemon.Info 195.100.10.197 Jan  1 00:00:36 dnsmasq[1384]: using local addresses only for domain lan
2012-10-01 11:46:00 Daemon.Info 195.100.10.197 Jan  1 00:00:36 dnsmasq[1384]: reading /tmp/resolv.conf.auto
2012-10-01 11:46:00 Daemon.Info 195.100.10.197 Jan  1 00:00:36 dnsmasq[1384]: using nameserver 194.204.159.1#53
2012-10-01 11:46:00 Daemon.Info 195.100.10.197 Jan  1 00:00:36 dnsmasq[1384]: using nameserver 194.204.152.34#53
2012-10-01 11:46:00 Daemon.Info 195.100.10.197 Jan  1 00:00:36 dnsmasq[1384]: using local addresses only for domain lan
2012-10-01 11:46:00 Daemon.Info 195.100.10.197 Jan  1 00:00:36 dnsmasq[1384]: read /etc/hosts - 1 addresses
2012-10-01 11:46:00 Daemon.Info 195.100.10.197 Jan  1 00:00:36 dnsmasq-dhcp[1384]: read /etc/ethers - 0 addresses
2012-10-01 11:46:00 User.Info 195.100.10.197 Jan  1 00:00:36 sysinit: setting up led WAN
2012-10-01 11:46:00 User.Info 195.100.10.197 Jan  1 00:00:36 sysinit: setting up led LAN1
2012-10-01 11:46:00 User.Info 195.100.10.197 Jan  1 00:00:36 sysinit: setting up led LAN2
2012-10-01 11:46:00 User.Info 195.100.10.197 Jan  1 00:00:36 sysinit: setting up led LAN3
2012-10-01 11:46:00 User.Info 195.100.10.197 Jan  1 00:00:36 sysinit: setting up led LAN4
2012-10-01 11:46:00 User.Info 195.100.10.197 Jan  1 00:00:36 sysinit: setting up led WLAN
2012-10-01 11:46:02 Daemon.Info 195.100.10.197 Jan  1 00:00:39 dnsmasq-dhcp[1384]: DHCPREQUEST(br-lan) 195.100.16.173 00:1d:60:41:b4:7d
2012-10-01 11:46:02 Daemon.Info 195.100.10.197 Jan  1 00:00:39 dnsmasq-dhcp[1384]: DHCPACK(br-lan) 195.100.16.173 00:1d:60:41:b4:7d OST082-lapep
2012-10-01 11:46:08 Daemon.Info 195.100.10.197 Oct  1 09:46:20 syslog: 09[KNL] creating delete job for ESP CHILD_SA with SPI c047ff9a and reqid {1}
2012-10-01 11:46:08 Daemon.Info 195.100.10.197 Oct  1 09:46:20 syslog: 09[KNL] creating delete job for ESP CHILD_SA with SPI c6ddaaae and reqid {1}
2012-10-01 11:46:08 Daemon.Info 195.100.10.197 Oct  1 09:46:20 syslog: 03[IKE] queueing QUICK_DELETE task
2012-10-01 11:46:08 Daemon.Info 195.100.10.197 Oct  1 09:46:20 syslog: 03[IKE] activating new tasks
2012-10-01 11:46:08 Daemon.Info 195.100.10.197 Oct  1 09:46:20 syslog: 03[IKE]   activating QUICK_DELETE task
2012-10-01 11:46:08 Daemon.Info 195.100.10.197 Oct  1 09:46:20 syslog: 03[IKE] closing expired CHILD_SA test{1} with SPIs c6ddaaae_i c047ff9a_o and TS 195.100.16.0/24 === 10.0.0.0/24
2012-10-01 11:46:08 System0.Info 195.100.10.197 Oct  1 09:46:20 syslog: 03[IKE] closing expired CHILD_SA test{1} with SPIs c6ddaaae_i c047ff9a_o and TS 195.100.16.0/24 === 10.0.0.0/24
2012-10-01 11:46:08 Daemon.Info 195.100.10.197 Oct  1 09:46:20 syslog: 03[IKE] sending DELETE for ESP CHILD_SA with SPI c6ddaaae
2012-10-01 11:46:08 Daemon.Info 195.100.10.197 Oct  1 09:46:20 syslog: 03[IKE] Hash => 20 bytes @ 0x78aae8
2012-10-01 11:46:08 Daemon.Info 195.100.10.197 Oct  1 09:46:20 syslog: 03[IKE]    0: 9B 1B 9D F8 1E 10 E3 A2 49 A7 DA 3E 19 04 A9 E6  ........I..>....
2012-10-01 11:46:08 Daemon.Info 195.100.10.197 Oct  1 09:46:20 syslog: 03[IKE]   16: 40 79 1D 6B                                      @y.k
2012-10-01 11:46:08 Daemon.Info 195.100.10.197 Oct  1 09:46:20 syslog: 03[ENC] generating INFORMATIONAL_V1 request 4257814719 [ HASH D ]
2012-10-01 11:46:08 Daemon.Info 195.100.10.197 Oct  1 09:46:20 syslog: 03[IKE] next IV for MID 4257814719 => 16 bytes @ 0x78aae8
2012-10-01 11:46:08 Daemon.Info 195.100.10.197 Oct  1 09:46:20 syslog: 03[IKE]    0: 80 5E 69 62 44 0C FB F8 B1 B6 3A 8B 08 83 79 49  .^ibD.....:...yI
2012-10-01 11:46:08 Daemon.Info 195.100.10.197 Oct  1 09:46:20 syslog: 03[IKE] next IV for MID 4257814719 => 16 bytes @ 0x789b18
2012-10-01 11:46:08 Daemon.Info 195.100.10.197 Oct  1 09:46:20 syslog: 03[IKE]    0: 49 8B 81 38 DF 16 85 38 CE BB 89 12 FA 69 AD FD  I..8...8.....i..
2012-10-01 11:46:08 Daemon.Info 195.100.10.197 Oct  1 09:46:20 syslog: 03[NET] sending packet: from 195.100.10.197[500] to 195.100.10.198[500]
2012-10-01 11:46:08 Daemon.Info 195.100.10.197 Oct  1 09:46:20 syslog: 03[IKE] activating new tasks
2012-10-01 11:46:08 Daemon.Info 195.100.10.197 Oct  1 09:46:20 syslog: 03[IKE] nothing to initiate
2012-10-01 11:46:08 Daemon.Info 195.100.10.197 Oct  1 09:46:20 syslog: 02[JOB] CHILD_SA with reqid 1 not found for delete
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 16[IKE] sending DPD request
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 16[IKE] queueing ISAKMP_DPD task
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 16[IKE] activating new tasks
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 16[IKE]   activating ISAKMP_DPD task
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 16[IKE] Hash => 20 bytes @ 0x78a5b0
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 16[IKE]    0: BB 82 BF 90 CB C8 47 84 40 89 6F 0C F1 BF 1A A3  ......G. at .o.....
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 16[IKE]   16: 4D AE 18 D7                                      M...
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 16[ENC] generating INFORMATIONAL_V1 request 2774761878 [ HASH N(DPD) ]
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 16[IKE] next IV for MID 2774761878 => 16 bytes @ 0x78a5b0
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 16[IKE]    0: 21 C0 AC 4B 85 3A D0 0C AB E8 A4 47 F2 54 8B B0  !..K.:.....G.T..
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 16[IKE] next IV for MID 2774761878 => 16 bytes @ 0x789228
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 07[NET] received packet: from 195.100.10.198[500] to 195.100.10.197[500]
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 07[IKE] next IV for MID 1220768690 => 16 bytes @ 0x78a5b0
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 07[IKE]    0: B2 5B FC 02 5B 40 92 15 DC 1B 9B 42 03 98 22 18  .[..[@.....B..".
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 07[ENC] parsed INFORMATIONAL_V1 request 1220768690 [ HASH N(DPD_ACK) ]
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 07[IKE] Hash => 20 bytes @ 0x78aa68
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 07[IKE]    0: CB CB 90 57 4F E5 48 9F B3 3D 22 F6 19 82 CC BB  ...WO.H..=".....
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 07[IKE]   16: 4E D3 17 26                                      N..&
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 07[IKE] next IV for MID 1220768690 => 16 bytes @ 0x7898a8
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 07[IKE]    0: 57 16 96 72 75 06 CA 13 54 EB B1 D4 80 DA 05 4D  W..ru...T......M
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 07[IKE] activating new tasks
2012-10-01 11:46:26 Daemon.Info 195.100.10.197 Oct  1 09:46:38 syslog: 07[IKE] nothing to initiate
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.strongswan.org/pipermail/users/attachments/20121001/81eef9fe/attachment.html>


More information about the Users mailing list