[strongSwan] Help with StrongSwan 4.3.2 freeze up (again)

Andreas Steffen andreas.steffen at strongswan.org
Tue Nov 29 06:12:08 CET 2011


Hello Simon,

there is not much sense in tracking down a problem in strongSwan 4.3.2
which was released in June 2009, i.e. more than two years ago. In the
meantime many improvements to the longtime stability of the charon
daemon were made. Please update to strongSwan 4.6.1 and check if the
freeze still occurs.

Best regards

Andreas

On 11/29/2011 02:44 AM, Simon Chan wrote:
> 
> Greetings,
> 
> Appreciate if someone can give me a hand to track down a hard to
> reproduce freeze up problem.
> 
> When the problem occurs, support staffs can remote login and the system
> appears normal in cpu load, disk usage and memory usage. Only charon
> appears dead. ps aux shows charon is in 'S' mode. ipsec statusall just
> hangs. ipsec stop leave mess behind (because stroke can't talk to
> charon?) so support just reboot the PC to recover.
> 
> StrongSwan version: 4.3.2
> Linux version: Debian 5.0.4
> Kernel: 2.6.32
> 
> It just happened again at one site. The last log entries before charon
> stopped working look like this:
> 
> Nov 28 11:18:06 moon charon: 15[KNL] adding policy 0.0.0.0/0 ===
> 10.2.19.0/24 out
> Nov 28 11:18:06 moon charon: 17[IKE] CHILD_SA SN00000A2446-1{10046}
> established with SPIs c0a4afb0_i c7e5a8d0_o and TS 0.0.0.0/0 ===
> 10.1.46.0/24 10.2.46.0/24 10.3.46.0/24 
> Nov 28 11:18:06 moon charon: 17[IKE] CHILD_SA SN00000A2446-1{10046}
> established with SPIs c0a4afb0_i c7e5a8d0_o and TS 0.0.0.0/0 ===
> 10.1.46.0/24 10.2.46.0/24 10.3.46.0/24 
> Nov 28 11:18:06 moon charon: 15[KNL] policy 10.2.19.0/24 === 0.0.0.0/0
> in already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 15[KNL] adding policy 10.2.19.0/24 ===
> 0.0.0.0/0 in
> Nov 28 11:18:06 moon charon: 15[KNL] policy 10.2.19.0/24 === 0.0.0.0/0
> fwd already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 15[KNL] adding policy 10.2.19.0/24 ===
> 0.0.0.0/0 fwd
> Nov 28 11:18:06 moon charon: 15[KNL] policy 0.0.0.0/0 === 10.3.19.0/24
> out already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 15[KNL] adding policy 0.0.0.0/0 ===
> 10.3.19.0/24 out
> Nov 28 11:18:06 moon charon: 15[KNL] policy 10.3.19.0/24 === 0.0.0.0/0
> in already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 15[KNL] adding policy 10.3.19.0/24 ===
> 0.0.0.0/0 in
> Nov 28 11:18:06 moon charon: 15[KNL] policy 10.3.19.0/24 === 0.0.0.0/0
> fwd already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 15[KNL] adding policy 10.3.19.0/24 ===
> 0.0.0.0/0 fwd
> Nov 28 11:18:06 moon charon: 15[KNL] getting interface name for a.b.c.d
> Nov 28 12:06:02 moon ntpd[8484]: kernel time sync status change 0001
> Nov 28 12:17:01 moon CRON[13865]: pam_unix(cron:session): session opened
> for user root by (uid=0)
> Nov 28 12:17:01 moon CRON[13865]: pam_unix(cron:session): session closed
> for user root
> 
> ------------------------------------------------------------------------
> **
> Did a grep in the source code and noticed that kernel_netlink_net.c
> calls mutex->lock after the "getting interface name" debug print.
> 
> Q1. Does it mean that there is a mismatch in the thread calling
> mutex->lock/mutex->unlock? What else can cause mutex->lock wait forever?
> 
> However in /var/log/messages the "getting interface name" log always
> appear in triplicate and right next to each other. That may be because
> all the tunnels have 3 subnets (10.1.x.0, 10.2.x.0, 10.3.x.0) so there
> are 3 fwd policies. Just before freeze up, the 3 fwd policies were logged:
> 
> Nov 28 11:18:06 moon charon: 15[KNL] adding policy 10.1.19.0/24 ===
> 0.0.0.0/0 fwd
> Nov 28 11:18:06 moon charon: 15[KNL] adding policy 10.2.19.0/24 ===
> 0.0.0.0/0 fwd
> Nov 28 11:18:06 moon charon: 15[KNL] adding policy 10.3.19.0/24 ===
> 0.0.0.0/0 fwd
> 
> Q2. Does these 3 log entries exonerate "mutex->lock" in
> get_interface_name? Cause if mutex->lock cannot return, then I should
> have only 1 "adding policy ... fwd" in the log, not three. May be there
> were 2 more "getting interface name" log entries got buffered up?
> 
>  Q3. Probably I fail to understand the code. I think add_policy in
> kernel_netlink_ipsec.c prints the "adding policy..." log and then if the
> policy is fwd, add a route thus triggering the "getting interface name"
> log. In that case "getting interface name" log should interleave with
> "adding policy ... fwd" logs. Where else can get_interface_name be
> called during add policies?
> 
> Q4. One thing I noticed from the full log was that just before frozen,
> charon had 2 threads doing REKEY_SA simultaneously. (See the
> interleaving thread 15 and 17 below.) Could threads running concurrently
> increase chance of lockup? The PC has 2 cores. Is there a setup
> parameter to disable multi-threading?
> 
> Really appreciate any help anyone can provide. Thanks.
> Simon
> 
> ===========================================================
> 
> Here goes the full log:
> 
> Nov 28 11:18:06 moon charon: 07[NET] received packet: from
> 46.46.46.46[4500] to a.b.c.d[4500]
> Nov 28 11:18:06 moon charon: 07[NET] waiting for data on raw sockets
> Nov 28 11:18:06 moon charon: 17[MGR] checkout IKE_SA by message
> Nov 28 11:18:06 moon charon: 17[MGR] IKE_SA successfully checked out
> Nov 28 11:18:06 moon charon: 17[NET] received packet: from
> 46.46.46.46[4500] to a.b.c.d[4500]
> Nov 28 11:18:06 moon charon: 17[ENC] parsed IKE_AUTH request 1 [ IDi IDr
> AUTH SA TSi TSr N(MOBIKE_SUP) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR)
> N(ADD_4_ADDR) N(ADD_4_ADDR) N(MULT_AUTH) ]
> Nov 28 11:18:06 moon charon: 17[CFG] looking for peer configs matching
> a.b.c.d[a.b.c.d]...46.46.46.46[SN00000A2446]
> Nov 28 11:18:06 moon charon: 07[NET] received packet: from
> 19.19.19.19[4500] to a.b.c.d[4500]
> Nov 28 11:18:06 moon charon: 07[NET] waiting for data on raw sockets
> Nov 28 11:18:06 moon charon: 17[CFG]   candidate "SN00000A2446-1",
> match: 20/20/5 (me/other/ike)
> Nov 28 11:18:06 moon charon: 17[CFG] selected peer config 'SN00000A2446-1'
> Nov 28 11:18:06 moon charon: 17[IKE] authentication of 'SN00000A2446'
> with pre-shared key successful
> Nov 28 11:18:06 moon charon: 17[IKE] peer supports MOBIKE
> Nov 28 11:18:06 moon charon: 17[IKE] got additional MOBIKE peer address:
> 10.2.46.1
> Nov 28 11:18:06 moon charon: 17[IKE] got additional MOBIKE peer address:
> 10.3.46.1
> Nov 28 11:18:06 moon charon: 17[IKE] got additional MOBIKE peer address:
> 10.1.46.1
> Nov 28 11:18:06 moon charon: 17[IKE] got additional MOBIKE peer address:
> 10.100.2.7
> Nov 28 11:18:06 moon charon: 17[IKE] got additional MOBIKE peer address:
> 10.99.0.99
> Nov 28 11:18:06 moon charon: 17[IKE] authentication of 'a.b.c.d'
> (myself) with pre-shared key
> Nov 28 11:18:06 moon charon: 17[IKE] successfully created shared key MAC
> Nov 28 11:18:06 moon charon: 17[MGR] checkout IKE_SA
> Nov 28 11:18:06 moon charon: 17[MGR] IKE_SA successfully checked out
> Nov 28 11:18:06 moon charon: 17[IKE] deleting duplicate IKE_SA for peer
> 'SN00000A2446' due to uniqueness policy
> Nov 28 11:18:06 moon charon: 17[IKE] queueing IKE_DELETE task
> Nov 28 11:18:06 moon charon: 02[JOB] got event, queuing job for execution
> Nov 28 11:18:06 moon charon: 02[JOB] next event in 530ms, waiting
> Nov 28 11:18:06 moon charon: 17[IKE] delaying task initiation, exchange
> in progress
> Nov 28 11:18:06 moon charon: 17[MGR] checkin IKE_SA
> Nov 28 11:18:06 moon charon: 17[MGR] check-in of IKE_SA successful.
> Nov 28 11:18:06 moon charon: 17[IKE] IKE_SA SN00000A2446-1[41959] state
> change: CONNECTING => ESTABLISHED
> Nov 28 11:18:06 moon charon: 17[IKE] IKE_SA SN00000A2446-1[41959]
> established between a.b.c.d[a.b.c.d]...46.46.46.46[SN00000A2446]
> Nov 28 11:18:06 moon charon: 17[IKE] IKE_SA SN00000A2446-1[41959]
> established between a.b.c.d[a.b.c.d]...46.46.46.46[SN00000A2446]
> Nov 28 11:18:06 moon charon: 17[CFG] looking for a child config for
> 0.0.0.0/0 === 10.1.46.0/24 10.2.46.0/24 10.3.46.0/24 
> Nov 28 11:18:06 moon charon: 17[CFG] selecting traffic selectors for other:
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.1.46.0/24, received:
> 10.1.46.0/24 => match: 10.1.46.0/24
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.1.46.0/24, received:
> 10.2.46.0/24 => no match
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.1.46.0/24, received:
> 10.3.46.0/24 => no match
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.2.46.0/24, received:
> 10.1.46.0/24 => no match
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.2.46.0/24, received:
> 10.2.46.0/24 => match: 10.2.46.0/24
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.2.46.0/24, received:
> 10.3.46.0/24 => no match
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.3.46.0/24, received:
> 10.1.46.0/24 => no match
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.3.46.0/24, received:
> 10.2.46.0/24 => no match
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.3.46.0/24, received:
> 10.3.46.0/24 => match: 10.3.46.0/24
> Nov 28 11:18:06 moon charon: 17[CFG]   candidate "SN00000A2446-1" with
> prio 3
> Nov 28 11:18:06 moon charon: 17[CFG] selecting traffic selectors for other:
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.1.46.0/24, received:
> 10.1.46.0/24 => match: 10.1.46.0/24
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.1.46.0/24, received:
> 10.2.46.0/24 => no match
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.1.46.0/24, received:
> 10.3.46.0/24 => no match
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.2.46.0/24, received:
> 10.1.46.0/24 => no match
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.2.46.0/24, received:
> 10.2.46.0/24 => match: 10.2.46.0/24
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.2.46.0/24, received:
> 10.3.46.0/24 => no match
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.3.46.0/24, received:
> 10.1.46.0/24 => no match
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.3.46.0/24, received:
> 10.2.46.0/24 => no match
> - - - another thread started to run (I think) - - -
> Nov 28 11:18:06 moon charon: 02[JOB] next event in 530ms, waiting
> Nov 28 11:18:06 oCM3 charon: 12[MGR] checkout IKE_SA
> Nov 28 11:18:06 oCM3 charon: 12[MGR] IKE_SA successfully checked out
> Nov 28 11:18:06 oCM3 charon: 12[IKE] giving up after 5 retransmits
> Nov 28 11:18:06 oCM3 charon: 12[MGR] checkin and destroy IKE_SA
> Nov 28 11:18:06 oCM3 charon: 12[IKE] IKE_SA SN00000A2407-1[41832] state
> change: ESTABLISHED => DESTROYING
> . . .
> deleting policies and SAD entries
> . . .
> Nov 28 11:18:06 oCM3 charon: 12[MGR] check-in and destroy of IKE_SA
> successful
> Nov 28 11:18:06 moon charon: 15[MGR] checkout IKE_SA by message
> Nov 28 11:18:06 moon charon: 15[MGR] IKE_SA successfully checked out
> Nov 28 11:18:06 moon charon: 15[NET] received packet: from
> 19.19.19.19[4500] to a.b.c.d[4500]
> Nov 28 11:18:06 moon charon: 15[ENC] parsed CREATE_CHILD_SA request 8 [
> N(REKEY_SA) SA No TSi TSr ]
> Nov 28 11:18:06 moon charon: 15[CFG] looking for a child config for
> 0.0.0.0/0 === 10.1.19.0/24 10.2.19.0/24 10.3.19.0/24 
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.3.46.0/24, received:
> 10.3.46.0/24 => match: 10.3.46.0/24
> Nov 28 11:18:06 moon charon: 17[CFG]   candidate "SN00000A2446-1" with
> prio 3
> Nov 28 11:18:06 moon charon: 15[CFG] selecting traffic selectors for other:
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.1.19.0/24, received:
> 10.1.19.0/24 => match: 10.1.19.0/24
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.1.19.0/24, received:
> 10.2.19.0/24 => no match
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.1.19.0/24, received:
> 10.3.19.0/24 => no match
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.2.19.0/24, received:
> 10.1.19.0/24 => no match
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.2.19.0/24, received:
> 10.2.19.0/24 => match: 10.2.19.0/24
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.2.19.0/24, received:
> 10.3.19.0/24 => no match
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.3.19.0/24, received:
> 10.1.19.0/24 => no match
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.3.19.0/24, received:
> 10.2.19.0/24 => no match
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.3.19.0/24, received:
> 10.3.19.0/24 => match: 10.3.19.0/24
> Nov 28 11:18:06 moon charon: 15[CFG]   candidate "SN00000A2419-1" with
> prio 3
> Nov 28 11:18:06 moon charon: 15[CFG] selecting traffic selectors for other:
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.1.19.0/24, received:
> 10.1.19.0/24 => match: 10.1.19.0/24
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.1.19.0/24, received:
> 10.2.19.0/24 => no match
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.1.19.0/24, received:
> 10.3.19.0/24 => no match
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.2.19.0/24, received:
> 10.1.19.0/24 => no match
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.2.19.0/24, received:
> 10.2.19.0/24 => match: 10.2.19.0/24
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.2.19.0/24, received:
> 10.3.19.0/24 => no match
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.3.19.0/24, received:
> 10.1.19.0/24 => no match
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.3.19.0/24, received:
> 10.2.19.0/24 => no match
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.3.19.0/24, received:
> 10.3.19.0/24 => match: 10.3.19.0/24
> Nov 28 11:18:06 moon charon: 15[CFG]   candidate "SN00000A2419-1" with
> prio 3
> Nov 28 11:18:06 moon charon: 15[CFG] found matching child config
> "SN00000A2419-1" with prio 3
> Nov 28 11:18:06 moon charon: 15[CFG] selecting proposal:
> Nov 28 11:18:06 moon charon: 17[CFG] found matching child config
> "SN00000A2446-1" with prio 3
> Nov 28 11:18:06 moon charon: 15[CFG]   proposal matches
> Nov 28 11:18:06 moon charon: 15[CFG] received proposals:
> ESP:AES_CBC_128/HMAC_MD5_96/NO_EXT_SEQ
> Nov 28 11:18:06 moon charon: 15[CFG] configured proposals:
> ESP:AES_CBC_128/HMAC_MD5_96/NO_EXT_SEQ
> Nov 28 11:18:06 moon charon: 15[CFG] selected proposal:
> ESP:AES_CBC_128/HMAC_MD5_96/NO_EXT_SEQ
> Nov 28 11:18:06 moon charon: 15[KNL] getting SPI for reqid {26161}
> Nov 28 11:18:06 moon charon: 17[CFG] selecting proposal:
> Nov 28 11:18:06 moon charon: 17[CFG]   proposal matches
> Nov 28 11:18:06 moon charon: 17[CFG] received proposals:
> ESP:AES_CBC_128/HMAC_MD5_96/NO_EXT_SEQ
> Nov 28 11:18:06 moon charon: 17[CFG] configured proposals:
> ESP:AES_CBC_128/HMAC_MD5_96/NO_EXT_SEQ
> Nov 28 11:18:06 moon charon: 17[CFG] selected proposal:
> ESP:AES_CBC_128/HMAC_MD5_96/NO_EXT_SEQ
> Nov 28 11:18:06 moon charon: 17[KNL] getting SPI for reqid {10046}
> Nov 28 11:18:06 moon charon: 17[KNL] got SPI c0a4afb0 for reqid {10046}
> Nov 28 11:18:06 moon charon: 17[CFG] selecting traffic selectors for us:
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 0.0.0.0/0, received:
> 0.0.0.0/0 => match: 0.0.0.0/0
> Nov 28 11:18:06 moon charon: 17[CFG] selecting traffic selectors for other:
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.1.46.0/24, received:
> 10.1.46.0/24 => match: 10.1.46.0/24
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.1.46.0/24, received:
> 10.2.46.0/24 => no match
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.1.46.0/24, received:
> 10.3.46.0/24 => no match
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.2.46.0/24, received:
> 10.1.46.0/24 => no match
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.2.46.0/24, received:
> 10.2.46.0/24 => match: 10.2.46.0/24
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.2.46.0/24, received:
> 10.3.46.0/24 => no match
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.3.46.0/24, received:
> 10.1.46.0/24 => no match
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.3.46.0/24, received:
> 10.2.46.0/24 => no match
> Nov 28 11:18:06 moon charon: 17[CFG]  config: 10.3.46.0/24, received:
> 10.3.46.0/24 => match: 10.3.46.0/24
> Nov 28 11:18:06 moon charon: 17[CHD]   using AES_CBC for encryption
> Nov 28 11:18:06 moon charon: 17[CHD]   using HMAC_MD5_96 for integrity
> Nov 28 11:18:06 moon charon: 17[CHD] adding inbound ESP SA
> Nov 28 11:18:06 moon charon: 17[CHD]   SPI 0xc0a4afb0, src 46.46.46.46
> dst a.b.c.d
> Nov 28 11:18:06 moon charon: 17[KNL] adding SAD entry with SPI c0a4afb0
> and reqid {10046}
> Nov 28 11:18:06 moon charon: 17[KNL]   using encryption algorithm
> AES_CBC with key size 128
> Nov 28 11:18:06 moon charon: 17[KNL]   using integrity algorithm
> HMAC_MD5_96 with key size 128
> Nov 28 11:18:06 moon charon: 17[CHD] adding outbound ESP SA
> Nov 28 11:18:06 moon charon: 17[CHD]   SPI 0xc7e5a8d0, src a.b.c.d dst
> 46.46.46.46
> Nov 28 11:18:06 moon charon: 17[KNL] adding SAD entry with SPI c7e5a8d0
> and reqid {10046}
> Nov 28 11:18:06 moon charon: 17[KNL]   using encryption algorithm
> AES_CBC with key size 128
> Nov 28 11:18:06 moon charon: 17[KNL]   using integrity algorithm
> HMAC_MD5_96 with key size 128
> Nov 28 11:18:06 moon charon: 17[KNL] policy 0.0.0.0/0 === 10.1.46.0/24
> out already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 17[KNL] adding policy 0.0.0.0/0 ===
> 10.1.46.0/24 out
> Nov 28 11:18:06 moon charon: 17[KNL] policy 10.1.46.0/24 === 0.0.0.0/0
> in already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 17[KNL] adding policy 10.1.46.0/24 ===
> 0.0.0.0/0 in
> Nov 28 11:18:06 moon charon: 17[KNL] policy 10.1.46.0/24 === 0.0.0.0/0
> fwd already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 17[KNL] adding policy 10.1.46.0/24 ===
> 0.0.0.0/0 fwd
> Nov 28 11:18:06 moon charon: 17[KNL] policy 0.0.0.0/0 === 10.2.46.0/24
> out already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 17[KNL] adding policy 0.0.0.0/0 ===
> 10.2.46.0/24 out
> Nov 28 11:18:06 moon charon: 17[KNL] policy 10.2.46.0/24 === 0.0.0.0/0
> in already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 17[KNL] adding policy 10.2.46.0/24 ===
> 0.0.0.0/0 in
> Nov 28 11:18:06 moon charon: 17[KNL] policy 10.2.46.0/24 === 0.0.0.0/0
> fwd already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 17[KNL] adding policy 10.2.46.0/24 ===
> 0.0.0.0/0 fwd
> Nov 28 11:18:06 moon charon: 17[KNL] policy 0.0.0.0/0 === 10.3.46.0/24
> out already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 17[KNL] adding policy 0.0.0.0/0 ===
> 10.3.46.0/24 out
> Nov 28 11:18:06 moon charon: 17[KNL] policy 10.3.46.0/24 === 0.0.0.0/0
> in already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 17[KNL] adding policy 10.3.46.0/24 ===
> 0.0.0.0/0 in
> Nov 28 11:18:06 moon charon: 17[KNL] policy 10.3.46.0/24 === 0.0.0.0/0
> fwd already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 17[KNL] adding policy 10.3.46.0/24 ===
> 0.0.0.0/0 fwd
> Nov 28 11:18:06 moon charon: 17[KNL] getting interface name for a.b.c.d
> Nov 28 11:18:06 moon charon: 17[KNL] a.b.c.d is on interface eth0
> Nov 28 11:18:06 moon charon: 17[KNL] getting interface name for a.b.c.d
> Nov 28 11:18:06 moon charon: 17[KNL] a.b.c.d is on interface eth0
> Nov 28 11:18:06 moon charon: 17[KNL] getting interface name for a.b.c.d
> Nov 28 11:18:06 moon charon: 17[KNL] a.b.c.d is on interface eth0
> Nov 28 11:18:06 moon charon: 15[KNL] got SPI cdd777e4 for reqid {26161}
> Nov 28 11:18:06 moon charon: 15[CFG] selecting traffic selectors for us:
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 0.0.0.0/0, received:
> 0.0.0.0/0 => match: 0.0.0.0/0
> Nov 28 11:18:06 moon charon: 15[CFG] selecting traffic selectors for other:
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.1.19.0/24, received:
> 10.1.19.0/24 => match: 10.1.19.0/24
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.1.19.0/24, received:
> 10.2.19.0/24 => no match
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.1.19.0/24, received:
> 10.3.19.0/24 => no match
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.2.19.0/24, received:
> 10.1.19.0/24 => no match
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.2.19.0/24, received:
> 10.2.19.0/24 => match: 10.2.19.0/24
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.2.19.0/24, received:
> 10.3.19.0/24 => no match
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.3.19.0/24, received:
> 10.1.19.0/24 => no match
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.3.19.0/24, received:
> 10.2.19.0/24 => no match
> Nov 28 11:18:06 moon charon: 15[CFG]  config: 10.3.19.0/24, received:
> 10.3.19.0/24 => match: 10.3.19.0/24
> Nov 28 11:18:06 moon charon: 15[CHD]   using AES_CBC for encryption
> Nov 28 11:18:06 moon charon: 15[CHD]   using HMAC_MD5_96 for integrity
> Nov 28 11:18:06 moon charon: 15[CHD] adding inbound ESP SA
> Nov 28 11:18:06 moon charon: 15[CHD]   SPI 0xcdd777e4, src 19.19.19.19
> dst a.b.c.d
> Nov 28 11:18:06 moon charon: 15[KNL] adding SAD entry with SPI cdd777e4
> and reqid {26161}
> Nov 28 11:18:06 moon charon: 15[KNL]   using encryption algorithm
> AES_CBC with key size 128
> Nov 28 11:18:06 moon charon: 15[KNL]   using integrity algorithm
> HMAC_MD5_96 with key size 128
> Nov 28 11:18:06 moon charon: 15[CHD] adding outbound ESP SA
> Nov 28 11:18:06 moon charon: 15[CHD]   SPI 0xc27035ad, src a.b.c.d dst
> 19.19.19.19
> Nov 28 11:18:06 moon charon: 15[KNL] adding SAD entry with SPI c27035ad
> and reqid {26161}
> Nov 28 11:18:06 moon charon: 15[KNL]   using encryption algorithm
> AES_CBC with key size 128
> Nov 28 11:18:06 moon charon: 15[KNL]   using integrity algorithm
> HMAC_MD5_96 with key size 128
> Nov 28 11:18:06 moon charon: 15[KNL] policy 0.0.0.0/0 === 10.1.19.0/24
> out already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 15[KNL] adding policy 0.0.0.0/0 ===
> 10.1.19.0/24 out
> Nov 28 11:18:06 moon charon: 15[KNL] policy 10.1.19.0/24 === 0.0.0.0/0
> in already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 15[KNL] adding policy 10.1.19.0/24 ===
> 0.0.0.0/0 in
> Nov 28 11:18:06 moon charon: 15[KNL] policy 10.1.19.0/24 === 0.0.0.0/0
> fwd already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 15[KNL] adding policy 10.1.19.0/24 ===
> 0.0.0.0/0 fwd
> Nov 28 11:18:06 moon charon: 15[KNL] policy 0.0.0.0/0 === 10.2.19.0/24
> out already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 15[KNL] adding policy 0.0.0.0/0 ===
> 10.2.19.0/24 out
> Nov 28 11:18:06 moon charon: 17[IKE] CHILD_SA SN00000A2446-1{10046}
> established with SPIs c0a4afb0_i c7e5a8d0_o and TS 0.0.0.0/0 ===
> 10.1.46.0/24 10.2.46.0/24 10.3.46.0/24 
> Nov 28 11:18:06 moon charon: 17[IKE] CHILD_SA SN00000A2446-1{10046}
> established with SPIs c0a4afb0_i c7e5a8d0_o and TS 0.0.0.0/0 ===
> 10.1.46.0/24 10.2.46.0/24 10.3.46.0/24 
> Nov 28 11:18:06 moon charon: 15[KNL] policy 10.2.19.0/24 === 0.0.0.0/0
> in already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 15[KNL] adding policy 10.2.19.0/24 ===
> 0.0.0.0/0 in
> Nov 28 11:18:06 moon charon: 15[KNL] policy 10.2.19.0/24 === 0.0.0.0/0
> fwd already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 15[KNL] adding policy 10.2.19.0/24 ===
> 0.0.0.0/0 fwd
> Nov 28 11:18:06 moon charon: 15[KNL] policy 0.0.0.0/0 === 10.3.19.0/24
> out already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 15[KNL] adding policy 0.0.0.0/0 ===
> 10.3.19.0/24 out
> Nov 28 11:18:06 moon charon: 15[KNL] policy 10.3.19.0/24 === 0.0.0.0/0
> in already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 15[KNL] adding policy 10.3.19.0/24 ===
> 0.0.0.0/0 in
> Nov 28 11:18:06 moon charon: 15[KNL] policy 10.3.19.0/24 === 0.0.0.0/0
> fwd already exists, increasing refcount
> Nov 28 11:18:06 moon charon: 15[KNL] adding policy 10.3.19.0/24 ===
> 0.0.0.0/0 fwd
> Nov 28 11:18:06 moon charon: 15[KNL] getting interface name for a.b.c.d
> Nov 28 12:06:02 moon ntpd[8484]: kernel time sync status change 0001
> Nov 28 12:17:01 moon CRON[13865]: pam_unix(cron:session): session opened
> for user root by (uid=0)
> Nov 28 12:17:01 moon CRON[13865]: pam_unix(cron:session): session closed
> for user root
> 
> -----------------------------------------------------
> ipsec.conf for the two tunnels shown:
> 
> conn SN00000A2446-1
>     left=a.b.c.d
>     right=%any
>     rightid=@SN00000A2446
>     rekey=no
>     leftsubnet=0.0.0.0/0
>     leftsourceip=a.b.c.d
>     rightsubnet=10.1.46.0/24,10.2.46.0/24,10.3.46.0/24
>     leftfirewall=yes
>     ike=aes128-md5-modp1536!
>     ikelifetime=28800s
>     keyexchange=ikev2
>     mobike=yes
>     dpddelay=30s
>     dpdtimeout=120s
>     dpdaction=clear
>     keyingtries=%forever
>     esp=aes128-md5!
>     keylife=3600s
>     rekeymargin=540s
>     type=tunnel
>     pfs=yes
>     compress=no
>     authby=secret
>     auto=add
> 
> conn SN00000A2419-1
>     left=a.b.c.d
>     right=%any
>     rightid=@SN00000A2419
>     rekey=no
>     leftsubnet=0.0.0.0/0
>     leftsourceip=a.b.c.d
>     rightsubnet=10.1.19.0/24,10.2.19.0/24,10.3.19.0/24
>     leftfirewall=yes
>     ike=aes128-md5-modp1536!
>     ikelifetime=28800s
>     keyexchange=ikev2
>     mobike=yes
>     dpddelay=30s
>     dpdtimeout=120s
>     dpdaction=clear
>     keyingtries=%forever
>     esp=aes128-md5!
>     keylife=3600s
>     rekeymargin=540s
>     type=tunnel
>     pfs=yes
>     compress=no
>     authby=secret
>     auto=add

======================================================================
Andreas Steffen                         andreas.steffen at strongswan.org
strongSwan - the Linux VPN Solution!                www.strongswan.org
Institute for Internet Technologies and Applications
University of Applied Sciences Rapperswil
CH-8640 Rapperswil (Switzerland)
===========================================================[ITA-HSR]==




More information about the Users mailing list