[Openswan Users] NAT-T debug session. Hope this helps
albert agusti
aagusti at serialnet.net
Wed Oct 27 14:01:02 CEST 2004
Skipped content of type multipart/alternative-------------- next part --------------
//CLEAN START AT BOTH ENDS
//SMAUG WILL ACT AS RESPONDER
//GLAURUNG WILL ACT AS INITIATOR
//THIS IS SMAUG SECURE LOG
Oct 27 12:20:41 smaug pluto[6181]: Starting Pluto (Openswan Version 2.2.0 X.509-1.5.4 PLUTO_USES_KEYRR)
Oct 27 12:20:41 smaug pluto[6181]: including NAT-Traversal patch (Version 0.6c)
Oct 27 12:20:41 smaug pluto[6181]: | inserting event EVENT_REINIT_SECRET, timeout in 3600 seconds
Oct 27 12:20:41 smaug pluto[6181]: ike_alg_register_enc(): Activating OAKLEY_AES_CBC: Ok (ret=0)
Oct 27 12:20:41 smaug pluto[6181]: Using Linux 2.6 IPsec interface code
Oct 27 12:20:41 smaug pluto[6181]: Changing to directory '/etc/ipsec.d/cacerts'
Oct 27 12:20:41 smaug pluto[6181]: Could not change to directory '/etc/ipsec.d/aacerts'
Oct 27 12:20:41 smaug pluto[6181]: Changing to directory '/etc/ipsec.d/ocspcerts'
Oct 27 12:20:41 smaug pluto[6181]: Changing to directory '/etc/ipsec.d/crls'
Oct 27 12:20:41 smaug pluto[6181]: Warning: empty directory
Oct 27 12:20:41 smaug pluto[6181]: | inserting event 11??, timeout in 41959 seconds
Oct 27 12:20:41 smaug pluto[6181]: | next event EVENT_REINIT_SECRET in 3600 seconds
Oct 27 12:20:41 smaug pluto[6181]: |
Oct 27 12:20:41 smaug pluto[6181]: | *received whack message
Oct 27 12:20:41 smaug pluto[6181]: | next event EVENT_REINIT_SECRET in 3600 seconds
Oct 27 12:20:41 smaug pluto[6181]: |
Oct 27 12:20:41 smaug pluto[6181]: | *received whack message
Oct 27 12:20:41 smaug pluto[6181]: | next event EVENT_REINIT_SECRET in 3600 seconds
Oct 27 12:20:41 smaug pluto[6181]: |
Oct 27 12:20:41 smaug pluto[6181]: | *received whack message
Oct 27 12:20:41 smaug pluto[6181]: | Added new connection albert with policy RSASIG+ENCRYPT+TUNNEL+PFS
Oct 27 12:20:41 smaug pluto[6181]: | from whack: got --esp=3des-md5,3des-sha1
Oct 27 12:20:41 smaug pluto[6181]: | esp string values: 3_000-1, 3_000-2, flags=-strict
Oct 27 12:20:41 smaug pluto[6181]: | from whack: got --ike=3des-md5,3des-sha
Oct 27 12:20:41 smaug pluto[6181]: | ike string values: 5_000-1-5, 5_000-1-2, 5_000-2-5, 5_000-2-2, flags=-strict
Oct 27 12:20:41 smaug pluto[6181]: | counting wild cards for @smaug.serialnet.net is 0
Oct 27 12:20:41 smaug pluto[6181]: | sendcert is 3
Oct 27 12:20:41 smaug pluto[6181]: | counting wild cards for @glaurung.serialnet.net is 0
Oct 27 12:20:41 smaug pluto[6181]: | sendcert is 3
Oct 27 12:20:41 smaug pluto[6181]: | alg_info_addref() alg_info->ref_cnt=1
Oct 27 12:20:41 smaug pluto[6181]: | alg_info_addref() alg_info->ref_cnt=1
Oct 27 12:20:41 smaug pluto[6181]: | alg_info_addref() alg_info->ref_cnt=2
Oct 27 12:20:41 smaug pluto[6181]: | alg_info_addref() alg_info->ref_cnt=2
Oct 27 12:20:41 smaug pluto[6181]: added connection description "albert"
Oct 27 12:20:41 smaug pluto[6181]: | 192.168.3.11/32===192.168.3.11[@smaug.serialnet.net]---192.168.3.1...I.I.I.I[@glaurung.serialnet.net]===192.168.1.10/32
Oct 27 12:20:41 smaug pluto[6181]: | ike_life: 3600s; ipsec_life: 28800s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0; policy: RSASIG+ENCRYPT+TUNNEL+PFS
Oct 27 12:20:41 smaug pluto[6181]: | next event EVENT_REINIT_SECRET in 3600 seconds
Oct 27 12:20:41 smaug pluto[6181]: |
Oct 27 12:20:41 smaug pluto[6181]: | *received whack message
Oct 27 12:20:41 smaug pluto[6181]: listening for IKE messages
Oct 27 12:20:41 smaug pluto[6181]: | found lo with address 127.0.0.1
Oct 27 12:20:41 smaug pluto[6181]: | found eth0 with address 192.168.3.11
Oct 27 12:20:41 smaug pluto[6181]: adding interface eth0/eth0 192.168.3.11
Oct 27 12:20:41 smaug pluto[6181]: adding interface eth0/eth0 192.168.3.11:4500
Oct 27 12:20:41 smaug pluto[6181]: adding interface lo/lo 127.0.0.1
Oct 27 12:20:41 smaug pluto[6181]: adding interface lo/lo 127.0.0.1:4500
Oct 27 12:20:41 smaug pluto[6181]: | found lo with address 0000:0000:0000:0000:0000:0000:0000:0001
Oct 27 12:20:41 smaug pluto[6181]: adding interface lo/lo ::1
Oct 27 12:20:41 smaug pluto[6181]: loading secrets from "/etc/ipsec.secrets"
Oct 27 12:20:41 smaug pluto[6181]: | loaded private key for keyid: PPK_RSA:AQNtzdaGd
Oct 27 12:20:41 smaug pluto[6181]: | next event EVENT_REINIT_SECRET in 3600 seconds
Oct 27 12:21:06 smaug pluto[6181]: |
Oct 27 12:21:06 smaug pluto[6181]: | *received 256 bytes from I.I.I.I:500 on eth0
Oct 27 12:21:06 smaug pluto[6181]: packet from I.I.I.I:500: received Vendor ID payload [Dead Peer Detection]
Oct 27 12:21:06 smaug pluto[6181]: packet from I.I.I.I:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-03]
Oct 27 12:21:06 smaug pluto[6181]: packet from I.I.I.I:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02] meth=107, but already using method 108
Oct 27 12:21:06 smaug pluto[6181]: packet from I.I.I.I:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-00]
Oct 27 12:21:06 smaug pluto[6181]: | creating state object #1 at 0x91e7340
Oct 27 12:21:06 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:21:06 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:21:06 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:21:06 smaug pluto[6181]: | state hash entry 20
Oct 27 12:21:06 smaug pluto[6181]: | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #1
Oct 27 12:21:06 smaug pluto[6181]: "albert" #1: responding to Main Mode
Oct 27 12:21:06 smaug pluto[6181]: "albert" #1: transition from state (null) to state STATE_MAIN_R1
Oct 27 12:21:06 smaug pluto[6181]: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
Oct 27 12:21:06 smaug pluto[6181]: | next event EVENT_RETRANSMIT in 10 seconds for #1
Oct 27 12:21:07 smaug pluto[6181]: |
Oct 27 12:21:07 smaug pluto[6181]: | *received 284 bytes from I.I.I.I:500 on eth0
Oct 27 12:21:07 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:21:07 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:21:07 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:21:07 smaug pluto[6181]: | state hash entry 20
Oct 27 12:21:07 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:21:07 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R1
Oct 27 12:21:07 smaug pluto[6181]: "albert" #1: NAT-Traversal: Result using draft-ietf-ipsec-nat-t-ike-02/03: both are NATed
Oct 27 12:21:07 smaug pluto[6181]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:21:07 smaug pluto[6181]: "albert" #1: transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
Oct 27 12:21:07 smaug pluto[6181]: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
Oct 27 12:21:07 smaug pluto[6181]: | next event EVENT_RETRANSMIT in 10 seconds for #1
Oct 27 12:21:07 smaug pluto[6181]: |
Oct 27 12:21:07 smaug pluto[6181]: | *received 340 bytes from I.I.I.I:4500 on eth0
Oct 27 12:21:07 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:21:07 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:21:07 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:21:07 smaug pluto[6181]: | state hash entry 20
Oct 27 12:21:07 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:21:07 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R2
Oct 27 12:21:07 smaug pluto[6181]: "albert" #1: Peer ID is ID_FQDN: '@glaurung.serialnet.net'
Oct 27 12:21:07 smaug pluto[6181]: | offered CA: '%none'
Oct 27 12:21:07 smaug pluto[6181]: | required CA is '%any'
Oct 27 12:21:07 smaug pluto[6181]: | key issuer CA is '%any'
Oct 27 12:21:07 smaug pluto[6181]: | an RSA Sig check passed with *AQOdUUfRj [preloaded key]
Oct 27 12:21:07 smaug pluto[6181]: | thinking about whether to send my certificate:
Oct 27 12:21:07 smaug pluto[6181]: | I have RSA key: OAKLEY_RSA_SIG cert.type: CERT_NONE
Oct 27 12:21:07 smaug pluto[6181]: | sendcert: CERT_ALWAYSSEND and I did not get a certificate request
Oct 27 12:21:07 smaug pluto[6181]: | so do not send cert.
Oct 27 12:21:07 smaug pluto[6181]: "albert" #1: I did not send a certificate because I do not have one.
Oct 27 12:21:07 smaug pluto[6181]: | looking for secret for @smaug.serialnet.net->@glaurung.serialnet.net of kind PPK_RSA
Oct 27 12:21:07 smaug pluto[6181]: | signing hash with RSA Key *AQNtzdaGd
Oct 27 12:21:07 smaug pluto[6181]: "albert" #1: transition from state STATE_MAIN_R2 to state STATE_MAIN_R3
Oct 27 12:21:07 smaug pluto[6181]: | NAT-T: new mapping I.I.I.I:500/4500)
Oct 27 12:21:07 smaug pluto[6181]: | inserting event EVENT_SA_REPLACE, timeout in 3330 seconds for #1
Oct 27 12:21:07 smaug pluto[6181]: "albert" #1: sent MR3, ISAKMP SA established
Oct 27 12:21:07 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 20 seconds
Oct 27 12:21:07 smaug pluto[6181]: |
Oct 27 12:21:07 smaug pluto[6181]: | *received 380 bytes from I.I.I.I:4500 on eth0
Oct 27 12:21:07 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:21:07 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:21:07 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:21:07 smaug pluto[6181]: | state hash entry 20
Oct 27 12:21:07 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 656b09e3 vs 00000000
Oct 27 12:21:07 smaug pluto[6181]: | state object not found
Oct 27 12:21:07 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:21:07 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:21:07 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:21:07 smaug pluto[6181]: | state hash entry 20
Oct 27 12:21:07 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:21:07 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:21:07 smaug pluto[6181]: | peer client is subnet 192.168.1.10/32
Oct 27 12:21:07 smaug pluto[6181]: | peer client protocol/port is 0/0
Oct 27 12:21:07 smaug pluto[6181]: | our client is subnet 192.168.3.11/32
Oct 27 12:21:07 smaug pluto[6181]: | our client protocol/port is 0/0
Oct 27 12:21:07 smaug pluto[6181]: | duplicating state object #1
Oct 27 12:21:07 smaug pluto[6181]: | creating state object #2 at 0x91e81a8
Oct 27 12:21:07 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:21:07 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:21:07 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:21:07 smaug pluto[6181]: | state hash entry 20
Oct 27 12:21:07 smaug pluto[6181]: | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #2
Oct 27 12:21:07 smaug pluto[6181]: "albert" #2: responding to Quick Mode
Oct 27 12:21:07 smaug pluto[6181]: | route owner of "albert" unrouted: NULL
Oct 27 12:21:07 smaug pluto[6181]: | install_inbound_ipsec_sa() checking if we can route
Oct 27 12:21:07 smaug pluto[6181]: | route owner of "albert" unrouted: NULL; eroute owner: NULL
Oct 27 12:21:07 smaug pluto[6181]: | could_route called for albert (kind=CK_PERMANENT)
Oct 27 12:21:07 smaug pluto[6181]: | add inbound eroute 192.168.1.10/32:0 --0-> 192.168.3.11/32:0 => tun.10000 at 192.168.3.11 (raw_eroute)
Oct 27 12:21:07 smaug pluto[6181]: "albert" #2: transition from state (null) to state STATE_QUICK_R1
Oct 27 12:21:07 smaug pluto[6181]: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #2
Oct 27 12:21:07 smaug pluto[6181]: | next event EVENT_RETRANSMIT in 10 seconds for #2
Oct 27 12:21:08 smaug pluto[6181]: |
Oct 27 12:21:08 smaug pluto[6181]: | *received 52 bytes from I.I.I.I:4500 on eth0
Oct 27 12:21:08 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:21:08 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:21:08 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:21:08 smaug pluto[6181]: | state hash entry 20
Oct 27 12:21:08 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 656b09e3 vs 656b09e3
Oct 27 12:21:08 smaug pluto[6181]: | state object #2 found, in STATE_QUICK_R1
Oct 27 12:21:08 smaug pluto[6181]: | install_ipsec_sa() for #2: outbound only
Oct 27 12:21:08 smaug pluto[6181]: | route owner of "albert" unrouted: NULL; eroute owner: NULL
Oct 27 12:21:08 smaug pluto[6181]: | could_route called for albert (kind=CK_PERMANENT)
Oct 27 12:21:08 smaug pluto[6181]: | sr for #2: unrouted
Oct 27 12:21:08 smaug pluto[6181]: | route owner of "albert" unrouted: NULL; eroute owner: NULL
Oct 27 12:21:08 smaug pluto[6181]: | eroute_connection add eroute 192.168.3.11/32:0 --0-> 192.168.1.10/32:0 => tun.0 at I.I.I.I (raw_eroute)
Oct 27 12:21:08 smaug pluto[6181]: | executing up-host: 2>&1 PLUTO_VERSION='1.1' PLUTO_VERB='up-host' PLUTO_CONNECTION='albert' PLUTO_NEXT_HOP='192.168.3.1' PLUTO_INTERFACE='eth0' PLUTO_ME='192.168.3.11' PLUTO_MY_ID='@smaug.serialnet.net' PLUTO_MY_CLIENT='192.168.3.11/32' PLUTO_MY_CLIENT_NET='192.168.3.11' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='I.I.I.I' PLUTO_PEER_ID='@glaurung.serialnet.net' PLUTO_PEER_CLIENT='192.168.1.10/32' PLUTO_PEER_CLIENT_NET='192.168.1.10' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_CONN_POLICY='RSASIG+ENCRYPT+TUNNEL+PFS' ipsec _updown
Oct 27 12:21:08 smaug pluto[6181]: | route_and_eroute: firewall_notified: true
Oct 27 12:21:08 smaug pluto[6181]: | executing prepare-host: 2>&1 PLUTO_VERSION='1.1' PLUTO_VERB='prepare-host' PLUTO_CONNECTION='albert' PLUTO_NEXT_HOP='192.168.3.1' PLUTO_INTERFACE='eth0' PLUTO_ME='192.168.3.11' PLUTO_MY_ID='@smaug.serialnet.net' PLUTO_MY_CLIENT='192.168.3.11/32' PLUTO_MY_CLIENT_NET='192.168.3.11' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='I.I.I.I' PLUTO_PEER_ID='@glaurung.serialnet.net' PLUTO_PEER_CLIENT='192.168.1.10/32' PLUTO_PEER_CLIENT_NET='192.168.1.10' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_CONN_POLICY='RSASIG+ENCRYPT+TUNNEL+PFS' ipsec _updown
Oct 27 12:21:08 smaug pluto[6181]: | executing route-host: 2>&1 PLUTO_VERSION='1.1' PLUTO_VERB='route-host' PLUTO_CONNECTION='albert' PLUTO_NEXT_HOP='192.168.3.1' PLUTO_INTERFACE='eth0' PLUTO_ME='192.168.3.11' PLUTO_MY_ID='@smaug.serialnet.net' PLUTO_MY_CLIENT='192.168.3.11/32' PLUTO_MY_CLIENT_NET='192.168.3.11' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='I.I.I.I' PLUTO_PEER_ID='@glaurung.serialnet.net' PLUTO_PEER_CLIENT='192.168.1.10/32' PLUTO_PEER_CLIENT_NET='192.168.1.10' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_CONN_POLICY='RSASIG+ENCRYPT+TUNNEL+PFS' ipsec _updown
Oct 27 12:21:08 smaug pluto[6181]: | route_and_eroute: instance "albert", setting eroute_owner {spd=0x91e51cc,sr=0x91e51cc} to #2 (was #0) (newest_ipsec_sa=#0)
Oct 27 12:21:08 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:21:08 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:21:08 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:21:08 smaug pluto[6181]: | state hash entry 20
Oct 27 12:21:08 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:21:08 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:21:08 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:21:08 smaug pluto[6181]: "albert" #2: Dead Peer Detection (RFC 3706) enabled
Oct 27 12:21:08 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:21:08 smaug pluto[6181]: "albert" #2: transition from state STATE_QUICK_R1 to state STATE_QUICK_R2
Oct 27 12:21:08 smaug pluto[6181]: | inserting event EVENT_SA_REPLACE, timeout in 28530 seconds for #2
Oct 27 12:21:08 smaug pluto[6181]: "albert" #2: IPsec SA established {ESP=>0x5a36b24a <0xfeefe4f0 NATOA=0.0.0.0}
// TUNNEL IS UP AND AFTER THAT DPD COOKIES AND NAT IS PROCESSED OK
// NEXT INTERESSTING POINT AT 12:27:07
Oct 27 12:21:08 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:21:18 smaug pluto[6181]: |
Oct 27 12:21:18 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:21:18 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:21:18 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:21:18 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:21:18 smaug pluto[6181]: | state hash entry 20
Oct 27 12:21:18 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:21:18 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:21:18 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:21:18 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19654 expected: 0
Oct 27 12:21:18 smaug pluto[6181]: | next event 9?? in 0 seconds for #2
Oct 27 12:21:18 smaug pluto[6181]: |
Oct 27 12:21:18 smaug pluto[6181]: | *time to handle event
Oct 27 12:21:18 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:21:18 smaug pluto[6181]: | not yet time for dpd event: 1098872478 < 1098872488
Oct 27 12:21:18 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:21:18 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:21:27 smaug pluto[6181]: |
Oct 27 12:21:27 smaug pluto[6181]: | *time to handle event
Oct 27 12:21:27 smaug pluto[6181]: | event after this is 9?? in 1 seconds
Oct 27 12:21:27 smaug pluto[6181]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:21:27 smaug pluto[6181]: | next event 9?? in 1 seconds for #2
Oct 27 12:21:28 smaug pluto[6181]: |
Oct 27 12:21:28 smaug pluto[6181]: | *time to handle event
Oct 27 12:21:28 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:21:28 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:21:28 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:21:28 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:21:28 smaug pluto[6181]: |
Oct 27 12:21:28 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:21:28 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:21:28 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:21:28 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:21:28 smaug pluto[6181]: | state hash entry 20
Oct 27 12:21:28 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:21:28 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:21:28 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:21:28 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19655 expected: 18496
Oct 27 12:21:28 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:21:28 smaug pluto[6181]: |
Oct 27 12:21:28 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:21:28 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:21:28 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:21:28 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:21:28 smaug pluto[6181]: | state hash entry 20
Oct 27 12:21:28 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:21:28 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:21:28 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:21:28 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:21:38 smaug pluto[6181]: |
Oct 27 12:21:38 smaug pluto[6181]: | *time to handle event
Oct 27 12:21:38 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:21:38 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:21:38 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:21:38 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:21:38 smaug pluto[6181]: |
Oct 27 12:21:38 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:21:38 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:21:38 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:21:38 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:21:38 smaug pluto[6181]: | state hash entry 20
Oct 27 12:21:38 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:21:38 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:21:38 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:21:38 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19656 expected: 18497
Oct 27 12:21:38 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:21:38 smaug pluto[6181]: |
Oct 27 12:21:38 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:21:38 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:21:38 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:21:38 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:21:38 smaug pluto[6181]: | state hash entry 20
Oct 27 12:21:38 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:21:38 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:21:38 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:21:38 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:21:47 smaug pluto[6181]: |
Oct 27 12:21:47 smaug pluto[6181]: | *time to handle event
Oct 27 12:21:47 smaug pluto[6181]: | event after this is 9?? in 1 seconds
Oct 27 12:21:47 smaug pluto[6181]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:21:47 smaug pluto[6181]: | next event 9?? in 1 seconds for #2
Oct 27 12:21:48 smaug pluto[6181]: |
Oct 27 12:21:48 smaug pluto[6181]: | *time to handle event
Oct 27 12:21:48 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:21:48 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:21:48 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:21:48 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:21:48 smaug pluto[6181]: |
Oct 27 12:21:48 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:21:48 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:21:48 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:21:48 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:21:48 smaug pluto[6181]: | state hash entry 20
Oct 27 12:21:48 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:21:48 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:21:48 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:21:48 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19657 expected: 18498
Oct 27 12:21:48 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:21:48 smaug pluto[6181]: |
Oct 27 12:21:48 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:21:48 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:21:48 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:21:48 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:21:48 smaug pluto[6181]: | state hash entry 20
Oct 27 12:21:48 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:21:48 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:21:48 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:21:48 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:21:58 smaug pluto[6181]: |
Oct 27 12:21:58 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:21:58 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:21:58 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:21:58 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:21:58 smaug pluto[6181]: | state hash entry 20
Oct 27 12:21:58 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:21:58 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:21:58 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:21:58 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19658 expected: 0
Oct 27 12:21:58 smaug pluto[6181]: | next event 9?? in 0 seconds for #2
Oct 27 12:21:58 smaug pluto[6181]: |
Oct 27 12:21:58 smaug pluto[6181]: | *time to handle event
Oct 27 12:21:58 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:21:58 smaug pluto[6181]: | not yet time for dpd event: 1098872518 < 1098872528
Oct 27 12:21:58 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:21:58 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:22:07 smaug pluto[6181]: |
Oct 27 12:22:07 smaug pluto[6181]: | *time to handle event
Oct 27 12:22:07 smaug pluto[6181]: | event after this is 9?? in 1 seconds
Oct 27 12:22:07 smaug pluto[6181]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:22:07 smaug pluto[6181]: | next event 9?? in 1 seconds for #2
Oct 27 12:22:08 smaug pluto[6181]: |
Oct 27 12:22:08 smaug pluto[6181]: | *time to handle event
Oct 27 12:22:08 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:22:08 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:22:08 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:22:08 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:22:08 smaug pluto[6181]: |
Oct 27 12:22:08 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:22:08 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:22:08 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:22:08 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:22:08 smaug pluto[6181]: | state hash entry 20
Oct 27 12:22:08 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:22:08 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:22:08 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:22:08 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19659 expected: 18499
Oct 27 12:22:08 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:22:08 smaug pluto[6181]: |
Oct 27 12:22:08 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:22:08 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:22:08 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:22:08 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:22:08 smaug pluto[6181]: | state hash entry 20
Oct 27 12:22:08 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:22:08 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:22:08 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:22:08 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:22:18 smaug pluto[6181]: |
Oct 27 12:22:18 smaug pluto[6181]: | *time to handle event
Oct 27 12:22:18 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:22:18 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:22:18 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:22:18 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:22:18 smaug pluto[6181]: |
Oct 27 12:22:18 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:22:18 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:22:18 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:22:18 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:22:18 smaug pluto[6181]: | state hash entry 20
Oct 27 12:22:18 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:22:18 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:22:18 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:22:18 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19660 expected: 18500
Oct 27 12:22:18 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:22:18 smaug pluto[6181]: |
Oct 27 12:22:18 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:22:18 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:22:18 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:22:18 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:22:18 smaug pluto[6181]: | state hash entry 20
Oct 27 12:22:18 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:22:18 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:22:18 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:22:18 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:22:27 smaug pluto[6181]: |
Oct 27 12:22:27 smaug pluto[6181]: | *time to handle event
Oct 27 12:22:27 smaug pluto[6181]: | event after this is 9?? in 1 seconds
Oct 27 12:22:27 smaug pluto[6181]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:22:27 smaug pluto[6181]: | next event 9?? in 1 seconds for #2
Oct 27 12:22:28 smaug pluto[6181]: |
Oct 27 12:22:28 smaug pluto[6181]: | *time to handle event
Oct 27 12:22:28 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:22:28 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:22:28 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:22:28 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:22:28 smaug pluto[6181]: |
Oct 27 12:22:28 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:22:28 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:22:28 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:22:28 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:22:28 smaug pluto[6181]: | state hash entry 20
Oct 27 12:22:28 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:22:28 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:22:28 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:22:28 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19661 expected: 18501
Oct 27 12:22:28 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:22:28 smaug pluto[6181]: |
Oct 27 12:22:28 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:22:28 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:22:28 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:22:28 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:22:28 smaug pluto[6181]: | state hash entry 20
Oct 27 12:22:28 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:22:28 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:22:28 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:22:28 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:22:38 smaug pluto[6181]: |
Oct 27 12:22:38 smaug pluto[6181]: | *time to handle event
Oct 27 12:22:38 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:22:38 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:22:38 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:22:38 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:22:38 smaug pluto[6181]: |
Oct 27 12:22:38 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:22:38 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:22:38 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:22:38 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:22:38 smaug pluto[6181]: | state hash entry 20
Oct 27 12:22:38 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:22:38 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:22:38 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:22:38 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19662 expected: 18502
Oct 27 12:22:38 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:22:38 smaug pluto[6181]: |
Oct 27 12:22:38 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:22:38 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:22:38 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:22:38 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:22:38 smaug pluto[6181]: | state hash entry 20
Oct 27 12:22:38 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:22:38 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:22:38 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:22:38 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:22:47 smaug pluto[6181]: |
Oct 27 12:22:47 smaug pluto[6181]: | *time to handle event
Oct 27 12:22:47 smaug pluto[6181]: | event after this is 9?? in 1 seconds
Oct 27 12:22:47 smaug pluto[6181]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:22:47 smaug pluto[6181]: | next event 9?? in 1 seconds for #2
Oct 27 12:22:48 smaug pluto[6181]: |
Oct 27 12:22:48 smaug pluto[6181]: | *time to handle event
Oct 27 12:22:48 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:22:48 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:22:48 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:22:48 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:22:48 smaug pluto[6181]: |
Oct 27 12:22:48 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:22:48 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:22:48 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:22:48 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:22:48 smaug pluto[6181]: | state hash entry 20
Oct 27 12:22:48 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:22:48 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:22:48 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:22:48 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19663 expected: 18503
Oct 27 12:22:48 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:22:48 smaug pluto[6181]: |
Oct 27 12:22:48 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:22:48 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:22:48 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:22:48 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:22:48 smaug pluto[6181]: | state hash entry 20
Oct 27 12:22:48 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:22:48 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:22:48 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:22:48 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:22:58 smaug pluto[6181]: |
Oct 27 12:22:58 smaug pluto[6181]: | *time to handle event
Oct 27 12:22:58 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:22:58 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:22:58 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:22:58 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:22:58 smaug pluto[6181]: |
Oct 27 12:22:58 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:22:58 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:22:58 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:22:58 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:22:58 smaug pluto[6181]: | state hash entry 20
Oct 27 12:22:58 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:22:58 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:22:58 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:22:58 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19664 expected: 18504
Oct 27 12:22:58 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:22:58 smaug pluto[6181]: |
Oct 27 12:22:58 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:22:58 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:22:58 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:22:58 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:22:58 smaug pluto[6181]: | state hash entry 20
Oct 27 12:22:58 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:22:58 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:22:58 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:22:58 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:23:07 smaug pluto[6181]: |
Oct 27 12:23:07 smaug pluto[6181]: | *time to handle event
Oct 27 12:23:07 smaug pluto[6181]: | event after this is 9?? in 1 seconds
Oct 27 12:23:07 smaug pluto[6181]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:23:07 smaug pluto[6181]: | next event 9?? in 1 seconds for #2
Oct 27 12:23:08 smaug pluto[6181]: |
Oct 27 12:23:08 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:23:08 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:23:08 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:23:08 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:23:08 smaug pluto[6181]: | state hash entry 20
Oct 27 12:23:08 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:23:08 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:23:08 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:23:08 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19665 expected: 0
Oct 27 12:23:08 smaug pluto[6181]: | next event 9?? in 0 seconds for #2
Oct 27 12:23:08 smaug pluto[6181]: |
Oct 27 12:23:08 smaug pluto[6181]: | *time to handle event
Oct 27 12:23:08 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:23:08 smaug pluto[6181]: | not yet time for dpd event: 1098872588 < 1098872598
Oct 27 12:23:08 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:23:08 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:23:18 smaug pluto[6181]: |
Oct 27 12:23:18 smaug pluto[6181]: | *time to handle event
Oct 27 12:23:18 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:23:18 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:23:18 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:23:18 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:23:18 smaug pluto[6181]: |
Oct 27 12:23:18 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:23:18 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:23:18 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:23:18 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:23:18 smaug pluto[6181]: | state hash entry 20
Oct 27 12:23:18 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:23:18 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:23:18 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:23:18 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19666 expected: 18505
Oct 27 12:23:18 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:23:18 smaug pluto[6181]: |
Oct 27 12:23:18 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:23:18 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:23:18 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:23:18 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:23:18 smaug pluto[6181]: | state hash entry 20
Oct 27 12:23:18 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:23:18 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:23:18 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:23:18 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:23:27 smaug pluto[6181]: |
Oct 27 12:23:27 smaug pluto[6181]: | *time to handle event
Oct 27 12:23:27 smaug pluto[6181]: | event after this is 9?? in 1 seconds
Oct 27 12:23:27 smaug pluto[6181]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:23:27 smaug pluto[6181]: | next event 9?? in 1 seconds for #2
Oct 27 12:23:28 smaug pluto[6181]: |
Oct 27 12:23:28 smaug pluto[6181]: | *time to handle event
Oct 27 12:23:28 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:23:28 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:23:28 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:23:28 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:23:28 smaug pluto[6181]: |
Oct 27 12:23:28 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:23:28 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:23:28 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:23:28 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:23:28 smaug pluto[6181]: | state hash entry 20
Oct 27 12:23:28 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:23:28 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:23:28 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:23:28 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19667 expected: 18506
Oct 27 12:23:28 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:23:28 smaug pluto[6181]: |
Oct 27 12:23:28 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:23:28 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:23:28 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:23:28 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:23:28 smaug pluto[6181]: | state hash entry 20
Oct 27 12:23:28 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:23:28 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:23:28 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:23:28 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:23:38 smaug pluto[6181]: |
Oct 27 12:23:38 smaug pluto[6181]: | *time to handle event
Oct 27 12:23:38 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:23:38 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:23:38 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:23:38 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:23:38 smaug pluto[6181]: |
Oct 27 12:23:38 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:23:38 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:23:38 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:23:38 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:23:38 smaug pluto[6181]: | state hash entry 20
Oct 27 12:23:38 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:23:38 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:23:38 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:23:38 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19668 expected: 18507
Oct 27 12:23:38 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:23:38 smaug pluto[6181]: |
Oct 27 12:23:38 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:23:38 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:23:38 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:23:38 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:23:38 smaug pluto[6181]: | state hash entry 20
Oct 27 12:23:38 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:23:38 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:23:38 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:23:38 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:23:47 smaug pluto[6181]: |
Oct 27 12:23:47 smaug pluto[6181]: | *time to handle event
Oct 27 12:23:47 smaug pluto[6181]: | event after this is 9?? in 1 seconds
Oct 27 12:23:47 smaug pluto[6181]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:23:47 smaug pluto[6181]: | next event 9?? in 1 seconds for #2
Oct 27 12:23:48 smaug pluto[6181]: |
Oct 27 12:23:48 smaug pluto[6181]: | *time to handle event
Oct 27 12:23:48 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:23:48 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:23:48 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:23:48 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:23:48 smaug pluto[6181]: |
Oct 27 12:23:48 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:23:48 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:23:48 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:23:48 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:23:48 smaug pluto[6181]: | state hash entry 20
Oct 27 12:23:48 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:23:48 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:23:48 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:23:48 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19669 expected: 18508
Oct 27 12:23:48 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:23:48 smaug pluto[6181]: |
Oct 27 12:23:48 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:23:48 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:23:48 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:23:48 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:23:48 smaug pluto[6181]: | state hash entry 20
Oct 27 12:23:48 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:23:48 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:23:48 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:23:48 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:23:58 smaug pluto[6181]: |
Oct 27 12:23:58 smaug pluto[6181]: | *time to handle event
Oct 27 12:23:58 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:23:58 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:23:58 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:23:58 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:23:58 smaug pluto[6181]: |
Oct 27 12:23:58 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:23:58 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:23:58 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:23:58 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:23:58 smaug pluto[6181]: | state hash entry 20
Oct 27 12:23:58 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:23:58 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:23:58 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:23:58 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19670 expected: 18509
Oct 27 12:23:58 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:23:58 smaug pluto[6181]: |
Oct 27 12:23:58 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:23:58 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:23:58 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:23:58 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:23:58 smaug pluto[6181]: | state hash entry 20
Oct 27 12:23:58 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:23:58 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:23:58 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:23:58 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:24:07 smaug pluto[6181]: |
Oct 27 12:24:07 smaug pluto[6181]: | *time to handle event
Oct 27 12:24:07 smaug pluto[6181]: | event after this is 9?? in 1 seconds
Oct 27 12:24:07 smaug pluto[6181]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:24:07 smaug pluto[6181]: | next event 9?? in 1 seconds for #2
Oct 27 12:24:08 smaug pluto[6181]: |
Oct 27 12:24:08 smaug pluto[6181]: | *time to handle event
Oct 27 12:24:08 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:24:08 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:24:08 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:24:08 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:24:08 smaug pluto[6181]: |
Oct 27 12:24:08 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:24:08 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:24:08 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:24:08 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:24:08 smaug pluto[6181]: | state hash entry 20
Oct 27 12:24:08 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:24:08 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:24:08 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:24:08 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19671 expected: 18510
Oct 27 12:24:08 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:24:08 smaug pluto[6181]: |
Oct 27 12:24:08 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:24:08 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:24:08 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:24:08 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:24:08 smaug pluto[6181]: | state hash entry 20
Oct 27 12:24:08 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:24:08 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:24:08 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:24:08 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:24:18 smaug pluto[6181]: |
Oct 27 12:24:18 smaug pluto[6181]: | *time to handle event
Oct 27 12:24:18 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:24:18 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:24:18 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:24:18 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:24:18 smaug pluto[6181]: |
Oct 27 12:24:18 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:24:18 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:24:18 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:24:18 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:24:18 smaug pluto[6181]: | state hash entry 20
Oct 27 12:24:18 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:24:18 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:24:18 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:24:18 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19672 expected: 18511
Oct 27 12:24:18 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:24:19 smaug pluto[6181]: |
Oct 27 12:24:19 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:24:19 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:24:19 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:24:19 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:24:19 smaug pluto[6181]: | state hash entry 20
Oct 27 12:24:19 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:24:19 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:24:19 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:24:19 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 8 seconds
Oct 27 12:24:27 smaug pluto[6181]: |
Oct 27 12:24:27 smaug pluto[6181]: | *time to handle event
Oct 27 12:24:27 smaug pluto[6181]: | event after this is 9?? in 1 seconds
Oct 27 12:24:27 smaug pluto[6181]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:24:27 smaug pluto[6181]: | next event 9?? in 1 seconds for #2
Oct 27 12:24:28 smaug pluto[6181]: |
Oct 27 12:24:28 smaug pluto[6181]: | *time to handle event
Oct 27 12:24:28 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:24:28 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:24:28 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:24:28 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:24:28 smaug pluto[6181]: |
Oct 27 12:24:28 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:24:28 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:24:28 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:24:28 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:24:28 smaug pluto[6181]: | state hash entry 20
Oct 27 12:24:28 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:24:28 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:24:28 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:24:28 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:24:38 smaug pluto[6181]: |
Oct 27 12:24:38 smaug pluto[6181]: | *time to handle event
Oct 27 12:24:38 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:24:38 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:24:38 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:24:38 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:24:38 smaug pluto[6181]: |
Oct 27 12:24:38 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:24:38 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:24:38 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:24:38 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:24:38 smaug pluto[6181]: | state hash entry 20
Oct 27 12:24:38 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:24:38 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:24:38 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:24:38 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19673 expected: 18513
Oct 27 12:24:38 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:24:38 smaug pluto[6181]: |
Oct 27 12:24:38 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:24:38 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:24:38 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:24:38 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:24:38 smaug pluto[6181]: | state hash entry 20
Oct 27 12:24:38 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:24:38 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:24:38 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:24:38 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:24:47 smaug pluto[6181]: |
Oct 27 12:24:47 smaug pluto[6181]: | *time to handle event
Oct 27 12:24:47 smaug pluto[6181]: | event after this is 9?? in 1 seconds
Oct 27 12:24:47 smaug pluto[6181]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:24:47 smaug pluto[6181]: | next event 9?? in 1 seconds for #2
Oct 27 12:24:48 smaug pluto[6181]: |
Oct 27 12:24:48 smaug pluto[6181]: | *time to handle event
Oct 27 12:24:48 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:24:48 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:24:48 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:24:48 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:24:48 smaug pluto[6181]: |
Oct 27 12:24:48 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:24:48 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:24:48 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:24:48 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:24:48 smaug pluto[6181]: | state hash entry 20
Oct 27 12:24:48 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:24:48 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:24:48 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:24:48 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19674 expected: 18514
Oct 27 12:24:48 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:24:48 smaug pluto[6181]: |
Oct 27 12:24:48 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:24:48 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:24:48 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:24:48 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:24:48 smaug pluto[6181]: | state hash entry 20
Oct 27 12:24:48 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:24:48 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:24:48 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:24:48 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:24:58 smaug pluto[6181]: |
Oct 27 12:24:58 smaug pluto[6181]: | *time to handle event
Oct 27 12:24:58 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:24:58 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:24:58 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:24:58 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:24:58 smaug pluto[6181]: |
Oct 27 12:24:58 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:24:58 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:24:58 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:24:58 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:24:58 smaug pluto[6181]: | state hash entry 20
Oct 27 12:24:58 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:24:58 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:24:58 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:24:58 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19675 expected: 18515
Oct 27 12:24:58 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:24:58 smaug pluto[6181]: |
Oct 27 12:24:58 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:24:58 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:24:58 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:24:58 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:24:58 smaug pluto[6181]: | state hash entry 20
Oct 27 12:24:58 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:24:58 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:24:58 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:24:58 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:25:07 smaug pluto[6181]: |
Oct 27 12:25:07 smaug pluto[6181]: | *time to handle event
Oct 27 12:25:07 smaug pluto[6181]: | event after this is 9?? in 1 seconds
Oct 27 12:25:07 smaug pluto[6181]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:25:07 smaug pluto[6181]: | next event 9?? in 1 seconds for #2
Oct 27 12:25:08 smaug pluto[6181]: |
Oct 27 12:25:08 smaug pluto[6181]: | *time to handle event
Oct 27 12:25:08 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:25:08 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:25:08 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:25:08 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:25:08 smaug pluto[6181]: |
Oct 27 12:25:08 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:25:08 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:25:08 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:25:08 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:25:08 smaug pluto[6181]: | state hash entry 20
Oct 27 12:25:08 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:25:08 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:25:08 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:25:08 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19676 expected: 18516
Oct 27 12:25:08 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:25:08 smaug pluto[6181]: |
Oct 27 12:25:08 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:25:08 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:25:08 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:25:08 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:25:08 smaug pluto[6181]: | state hash entry 20
Oct 27 12:25:08 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:25:08 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:25:08 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:25:08 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:25:18 smaug pluto[6181]: |
Oct 27 12:25:18 smaug pluto[6181]: | *time to handle event
Oct 27 12:25:18 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:25:18 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:25:18 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:25:18 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:25:18 smaug pluto[6181]: |
Oct 27 12:25:18 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:25:18 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:25:18 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:25:18 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:25:18 smaug pluto[6181]: | state hash entry 20
Oct 27 12:25:18 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:25:18 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:25:18 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:25:18 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19677 expected: 18517
Oct 27 12:25:18 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:25:18 smaug pluto[6181]: |
Oct 27 12:25:18 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:25:18 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:25:18 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:25:18 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:25:18 smaug pluto[6181]: | state hash entry 20
Oct 27 12:25:18 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:25:18 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:25:18 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:25:18 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:25:27 smaug pluto[6181]: |
Oct 27 12:25:27 smaug pluto[6181]: | *time to handle event
Oct 27 12:25:27 smaug pluto[6181]: | event after this is 9?? in 1 seconds
Oct 27 12:25:27 smaug pluto[6181]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:25:27 smaug pluto[6181]: | next event 9?? in 1 seconds for #2
Oct 27 12:25:28 smaug pluto[6181]: |
Oct 27 12:25:28 smaug pluto[6181]: | *time to handle event
Oct 27 12:25:28 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:25:28 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:25:28 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:25:28 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:25:28 smaug pluto[6181]: |
Oct 27 12:25:28 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:25:28 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:25:28 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:25:28 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:25:28 smaug pluto[6181]: | state hash entry 20
Oct 27 12:25:28 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:25:28 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:25:28 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:25:28 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19678 expected: 18518
Oct 27 12:25:28 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:25:29 smaug pluto[6181]: |
Oct 27 12:25:29 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:25:29 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:25:29 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:25:29 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:25:29 smaug pluto[6181]: | state hash entry 20
Oct 27 12:25:29 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:25:29 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:25:29 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:25:29 smaug pluto[6181]: | next event 9?? in 9 seconds for #2
Oct 27 12:25:38 smaug pluto[6181]: |
Oct 27 12:25:38 smaug pluto[6181]: | *time to handle event
Oct 27 12:25:38 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:25:38 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:25:38 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:25:38 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:25:38 smaug pluto[6181]: |
Oct 27 12:25:38 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:25:38 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:25:38 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:25:38 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:25:38 smaug pluto[6181]: | state hash entry 20
Oct 27 12:25:38 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:25:38 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:25:38 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:25:38 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:25:47 smaug pluto[6181]: |
Oct 27 12:25:47 smaug pluto[6181]: | *time to handle event
Oct 27 12:25:47 smaug pluto[6181]: | event after this is 9?? in 1 seconds
Oct 27 12:25:47 smaug pluto[6181]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:25:47 smaug pluto[6181]: | next event 9?? in 1 seconds for #2
Oct 27 12:25:48 smaug pluto[6181]: |
Oct 27 12:25:48 smaug pluto[6181]: | *time to handle event
Oct 27 12:25:48 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:25:48 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:25:48 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:25:48 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:25:48 smaug pluto[6181]: |
Oct 27 12:25:48 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:25:48 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:25:48 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:25:48 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:25:48 smaug pluto[6181]: | state hash entry 20
Oct 27 12:25:48 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:25:48 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:25:48 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:25:48 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19679 expected: 18520
Oct 27 12:25:48 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:25:48 smaug pluto[6181]: |
Oct 27 12:25:48 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:25:48 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:25:48 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:25:48 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:25:48 smaug pluto[6181]: | state hash entry 20
Oct 27 12:25:48 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:25:48 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:25:48 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:25:48 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:25:58 smaug pluto[6181]: |
Oct 27 12:25:58 smaug pluto[6181]: | *time to handle event
Oct 27 12:25:58 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:25:58 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:25:58 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:25:58 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:25:58 smaug pluto[6181]: |
Oct 27 12:25:58 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:25:58 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:25:58 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:25:58 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:25:58 smaug pluto[6181]: | state hash entry 20
Oct 27 12:25:58 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:25:58 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:25:58 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:25:58 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19680 expected: 18521
Oct 27 12:25:58 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:25:58 smaug pluto[6181]: |
Oct 27 12:25:58 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:25:58 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:25:58 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:25:58 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:25:58 smaug pluto[6181]: | state hash entry 20
Oct 27 12:25:58 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:25:58 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:25:58 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:25:58 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:26:07 smaug pluto[6181]: |
Oct 27 12:26:07 smaug pluto[6181]: | *time to handle event
Oct 27 12:26:07 smaug pluto[6181]: | event after this is 9?? in 1 seconds
Oct 27 12:26:07 smaug pluto[6181]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:26:07 smaug pluto[6181]: | next event 9?? in 1 seconds for #2
Oct 27 12:26:08 smaug pluto[6181]: |
Oct 27 12:26:08 smaug pluto[6181]: | *time to handle event
Oct 27 12:26:08 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:26:08 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:26:08 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:26:08 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:26:08 smaug pluto[6181]: |
Oct 27 12:26:08 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:26:08 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:26:08 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:26:08 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:26:08 smaug pluto[6181]: | state hash entry 20
Oct 27 12:26:08 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:26:08 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:26:08 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:26:08 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19681 expected: 18522
Oct 27 12:26:08 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:26:08 smaug pluto[6181]: |
Oct 27 12:26:08 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:26:08 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:26:08 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:26:08 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:26:08 smaug pluto[6181]: | state hash entry 20
Oct 27 12:26:08 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:26:08 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:26:08 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:26:08 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:26:18 smaug pluto[6181]: |
Oct 27 12:26:18 smaug pluto[6181]: | *time to handle event
Oct 27 12:26:18 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:26:18 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:26:18 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:26:18 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:26:18 smaug pluto[6181]: |
Oct 27 12:26:18 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:26:18 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:26:18 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:26:18 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:26:18 smaug pluto[6181]: | state hash entry 20
Oct 27 12:26:18 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:26:18 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:26:18 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:26:18 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19682 expected: 18523
Oct 27 12:26:18 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:26:18 smaug pluto[6181]: |
Oct 27 12:26:18 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:26:18 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:26:18 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:26:18 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:26:18 smaug pluto[6181]: | state hash entry 20
Oct 27 12:26:18 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:26:18 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:26:18 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:26:18 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:26:27 smaug pluto[6181]: |
Oct 27 12:26:27 smaug pluto[6181]: | *time to handle event
Oct 27 12:26:27 smaug pluto[6181]: | event after this is 9?? in 1 seconds
Oct 27 12:26:27 smaug pluto[6181]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:26:27 smaug pluto[6181]: | next event 9?? in 1 seconds for #2
Oct 27 12:26:28 smaug pluto[6181]: |
Oct 27 12:26:28 smaug pluto[6181]: | *time to handle event
Oct 27 12:26:28 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:26:28 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:26:28 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:26:28 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:26:28 smaug pluto[6181]: |
Oct 27 12:26:28 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:26:28 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:26:28 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:26:28 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:26:28 smaug pluto[6181]: | state hash entry 20
Oct 27 12:26:28 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:26:28 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:26:28 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:26:28 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19683 expected: 18524
Oct 27 12:26:28 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:26:28 smaug pluto[6181]: |
Oct 27 12:26:28 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:26:28 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:26:28 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:26:28 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:26:28 smaug pluto[6181]: | state hash entry 20
Oct 27 12:26:28 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:26:28 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:26:28 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:26:28 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:26:38 smaug pluto[6181]: |
Oct 27 12:26:38 smaug pluto[6181]: | *time to handle event
Oct 27 12:26:38 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:26:38 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:26:38 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:26:38 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:26:38 smaug pluto[6181]: |
Oct 27 12:26:38 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:26:38 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:26:38 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:26:38 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:26:38 smaug pluto[6181]: | state hash entry 20
Oct 27 12:26:38 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:26:38 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:26:38 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:26:38 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19684 expected: 18525
Oct 27 12:26:38 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:26:38 smaug pluto[6181]: |
Oct 27 12:26:38 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:26:38 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:26:38 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:26:38 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:26:38 smaug pluto[6181]: | state hash entry 20
Oct 27 12:26:38 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:26:38 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:26:38 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:26:38 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:26:47 smaug pluto[6181]: |
Oct 27 12:26:47 smaug pluto[6181]: | *time to handle event
Oct 27 12:26:47 smaug pluto[6181]: | event after this is 9?? in 1 seconds
Oct 27 12:26:47 smaug pluto[6181]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:26:47 smaug pluto[6181]: | next event 9?? in 1 seconds for #2
Oct 27 12:26:48 smaug pluto[6181]: |
Oct 27 12:26:48 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:26:48 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:26:48 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:26:48 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:26:48 smaug pluto[6181]: | state hash entry 20
Oct 27 12:26:48 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:26:48 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:26:48 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:26:48 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19685 expected: 0
Oct 27 12:26:48 smaug pluto[6181]: | next event 9?? in 0 seconds for #2
Oct 27 12:26:48 smaug pluto[6181]: |
Oct 27 12:26:48 smaug pluto[6181]: | *time to handle event
Oct 27 12:26:48 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:26:48 smaug pluto[6181]: | not yet time for dpd event: 1098872808 < 1098872818
Oct 27 12:26:48 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:26:48 smaug pluto[6181]: | next event 9?? in 10 seconds for #2
Oct 27 12:26:58 smaug pluto[6181]: |
Oct 27 12:26:58 smaug pluto[6181]: | *time to handle event
Oct 27 12:26:58 smaug pluto[6181]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:26:58 smaug pluto[6181]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:26:58 smaug pluto[6181]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:26:58 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:26:58 smaug pluto[6181]: |
Oct 27 12:26:58 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:26:58 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:26:58 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:26:58 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:26:58 smaug pluto[6181]: | state hash entry 20
Oct 27 12:26:58 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:26:58 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:26:58 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:26:58 smaug pluto[6181]: | R_U_THERE_ACK, seqno received: 19686 expected: 18526
Oct 27 12:26:58 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:26:58 smaug pluto[6181]: |
Oct 27 12:26:58 smaug pluto[6181]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:26:58 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:26:58 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:26:58 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:26:58 smaug pluto[6181]: | state hash entry 20
Oct 27 12:26:58 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:26:58 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:26:58 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:26:58 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:27:01 smaug pluto[6181]: |
Oct 27 12:27:01 smaug pluto[6181]: | *received 68 bytes from I.I.I.I:4500 on eth0
Oct 27 12:27:01 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:27:01 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:27:01 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:27:01 smaug pluto[6181]: | state hash entry 20
Oct 27 12:27:01 smaug pluto[6181]: | peer and cookies match on #2, provided msgid 00000000 vs 656b09e3
Oct 27 12:27:01 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:27:01 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:27:01 smaug pluto[6181]: "albert" #1: received Delete SA(0x5a36b24a) payload: deleting IPSEC State #2
Oct 27 12:27:01 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:27:01 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:27:01 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:27:01 smaug pluto[6181]: | state hash entry 20
Oct 27 12:27:01 smaug pluto[6181]: | executing down-host: 2>&1 PLUTO_VERSION='1.1' PLUTO_VERB='down-host' PLUTO_CONNECTION='albert' PLUTO_NEXT_HOP='192.168.3.1' PLUTO_INTERFACE='eth0' PLUTO_ME='192.168.3.11' PLUTO_MY_ID='@smaug.serialnet.net' PLUTO_MY_CLIENT='192.168.3.11/32' PLUTO_MY_CLIENT_NET='192.168.3.11' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='I.I.I.I' PLUTO_PEER_ID='@glaurung.serialnet.net' PLUTO_PEER_CLIENT='192.168.1.10/32' PLUTO_PEER_CLIENT_NET='192.168.1.10' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_CONN_POLICY='RSASIG+ENCRYPT+TUNNEL+PFS' ipsec _updown
Oct 27 12:27:01 smaug pluto[6181]: | replace with shunt eroute 192.168.1.10/32:0 --0-> 192.168.3.11/32:0 => %trap (raw_eroute)
Oct 27 12:27:01 smaug pluto[6181]: | eroute_connection replace with shunt eroute 192.168.3.11/32:0 --0-> 192.168.1.10/32:0 => %trap (raw_eroute)
Oct 27 12:27:01 smaug pluto[6181]: | delete inbound eroute 192.168.1.10/32:0 --0-> 192.168.3.11/32:0 => unk255.10000 at 192.168.3.11 (raw_eroute)
Oct 27 12:27:01 smaug pluto[6181]: "albert" #1: received and ignored informational message
Oct 27 12:27:01 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 6 seconds
Oct 27 12:27:01 smaug pluto[6181]: |
Oct 27 12:27:01 smaug pluto[6181]: | *received 76 bytes from I.I.I.I:4500 on eth0
Oct 27 12:27:01 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:27:01 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:27:01 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:27:01 smaug pluto[6181]: | state hash entry 20
Oct 27 12:27:01 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:27:01 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:27:01 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:27:01 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:27:01 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:27:01 smaug pluto[6181]: | state hash entry 20
Oct 27 12:27:01 smaug pluto[6181]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:27:01 smaug pluto[6181]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:27:01 smaug pluto[6181]: "albert" #1: received Delete SA payload: deleting ISAKMP State #1
Oct 27 12:27:01 smaug pluto[6181]: | ICOOKIE: fa 95 94 5e 1c e1 82 d7
Oct 27 12:27:01 smaug pluto[6181]: | RCOOKIE: 1d f8 83 46 3a 68 ea 06
Oct 27 12:27:01 smaug pluto[6181]: | peer: 50 1c d8 69
Oct 27 12:27:01 smaug pluto[6181]: | state hash entry 20
Oct 27 12:27:01 smaug pluto[6181]: packet from I.I.I.I:4500: received and ignored informational message
Oct 27 12:27:01 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 6 seconds
Oct 27 12:27:01 smaug pluto[6181]: | rejected packet:
Oct 27 12:27:01 smaug pluto[6181]: | 00 00 00 00 fa 95 94 5e 1c e1 82 d7 1d f8 83 46
Oct 27 12:27:01 smaug pluto[6181]: | 3a 68 ea 06 08 10 05 01 92 cd 3f 51 00 00 00 44
Oct 27 12:27:01 smaug pluto[6181]: | bd b3 b5 25 8e 78 26 71 af d3 a6 eb 45 d3 80 1a
Oct 27 12:27:01 smaug pluto[6181]: | 9c c8 36 cd 70 5d 9e f0 ef 95 7e 89 34 30 18 93
Oct 27 12:27:01 smaug pluto[6181]: | aa 44 cd 73 d3 d6 92 c7
Oct 27 12:27:01 smaug pluto[6181]: | control:
Oct 27 12:27:01 smaug pluto[6181]: | 2c 00 00 00 00 00 00 00 0b 00 00 00 6f 00 00 00
Oct 27 12:27:01 smaug pluto[6181]: | 02 03 03 00 00 00 00 00 00 00 00 00 02 00 00 00
Oct 27 12:27:01 smaug pluto[6181]: | 50 1c d8 69 00 00 00 00 00 00 00 00
Oct 27 12:27:01 smaug pluto[6181]: | name:
Oct 27 12:27:01 smaug pluto[6181]: | 02 00 11 94 50 1c d8 69 00 00 00 00 00 00 00 00
Oct 27 12:27:01 smaug pluto[6181]: ERROR: asynchronous network error report on eth0 for message to I.I.I.I port 4500, complainant I.I.I.I: Connection refused [errno 111, origin ICMP type 3 code 3 (not authenticated)]
Oct 27 12:27:01 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 6 seconds
Oct 27 12:27:01 smaug pluto[6181]: | rejected packet:
Oct 27 12:27:01 smaug pluto[6181]: | 00 00 00 00 fa 95 94 5e 1c e1 82 d7 1d f8 83 46
Oct 27 12:27:01 smaug pluto[6181]: | 3a 68 ea 06 08 10 05 01 32 a6 f4 ed 00 00 00 4c
Oct 27 12:27:01 smaug pluto[6181]: | 4a ed cb ea 9c 6e f9 5b 4c 3d 5e 9c 68 97 f2 ab
Oct 27 12:27:01 smaug pluto[6181]: | 3f ab 54 b6 7d 84 d3 d7 cd c3 89 26 96 93 79 12
Oct 27 12:27:01 smaug pluto[6181]: | 74 40 1d ce be e9 d7 38 1a 23 18 10 2e ca 73 15
Oct 27 12:27:01 smaug pluto[6181]: | control:
Oct 27 12:27:01 smaug pluto[6181]: | 2c 00 00 00 00 00 00 00 0b 00 00 00 6f 00 00 00
Oct 27 12:27:01 smaug pluto[6181]: | 02 03 03 00 00 00 00 00 00 00 00 00 02 00 00 00
Oct 27 12:27:01 smaug pluto[6181]: | 50 1c d8 69 00 00 00 00 00 00 00 00
Oct 27 12:27:01 smaug pluto[6181]: | name:
Oct 27 12:27:01 smaug pluto[6181]: | 02 00 11 94 50 1c d8 69 00 00 00 00 00 00 00 00
Oct 27 12:27:01 smaug pluto[6181]: ERROR: asynchronous network error report on eth0 for message to I.I.I.I port 4500, complainant I.I.I.I: Connection refused [errno 111, origin ICMP type 3 code 3 (not authenticated)]
// ON ABOVE IS THE ACTIONS TAKEN DUED AN /etc/init.d/ipsec restart at INITIATOR END
Oct 27 12:27:01 smaug pluto[6181]: | next event EVENT_NAT_T_KEEPALIVE in 6 seconds
Oct 27 12:27:07 smaug pluto[6181]: |
Oct 27 12:27:07 smaug pluto[6181]: | *time to handle event
Oct 27 12:27:07 smaug pluto[6181]: | event after this is EVENT_REINIT_SECRET in 3214 seconds
Oct 27 12:27:07 smaug pluto[6181]: | next event EVENT_REINIT_SECRET in 3214 seconds
Oct 27 12:28:01 smaug pluto[6181]: |
Oct 27 12:28:01 smaug pluto[6181]: | *received whack message
Oct 27 12:28:01 smaug pluto[6181]: | next event EVENT_REINIT_SECRET in 3160 seconds
// HERE IS THE REACTION WHEN REMOTE INITIATOR TRIES AGAIN TO DO AN "UP"
Oct 27 12:28:42 smaug pluto[6181]: |
Oct 27 12:28:42 smaug pluto[6181]: | *received 256 bytes from I.I.I.I:500 on eth0
Oct 27 12:28:42 smaug pluto[6181]: packet from I.I.I.I:500: received Vendor ID payload [Dead Peer Detection]
Oct 27 12:28:42 smaug pluto[6181]: packet from I.I.I.I:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-03]
Oct 27 12:28:42 smaug pluto[6181]: packet from I.I.I.I:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02] meth=107, but already using method 108
Oct 27 12:28:42 smaug pluto[6181]: packet from I.I.I.I:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-00]
Oct 27 12:28:42 smaug pluto[6181]: packet from I.I.I.I:500: initial Main Mode message received on 192.168.3.11:500 but no connection has been authorized
Oct 27 12:28:42 smaug pluto[6181]: | next event EVENT_REINIT_SECRET in 3119 seconds
Oct 27 12:28:52 smaug pluto[6181]: |
Oct 27 12:28:52 smaug pluto[6181]: | *received 256 bytes from I.I.I.I:500 on eth0
Oct 27 12:28:52 smaug pluto[6181]: packet from I.I.I.I:500: received Vendor ID payload [Dead Peer Detection]
Oct 27 12:28:52 smaug pluto[6181]: packet from I.I.I.I:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-03]
Oct 27 12:28:52 smaug pluto[6181]: packet from I.I.I.I:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02] meth=107, but already using method 108
Oct 27 12:28:52 smaug pluto[6181]: packet from I.I.I.I:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-00]
Oct 27 12:28:52 smaug pluto[6181]: packet from I.I.I.I:500: initial Main Mode message received on 192.168.3.11:500 but no connection has been authorized
Oct 27 12:28:52 smaug pluto[6181]: | next event EVENT_REINIT_SECRET in 3109 seconds
Oct 27 12:29:12 smaug pluto[6181]: |
Oct 27 12:29:12 smaug pluto[6181]: | *received 256 bytes from I.I.I.I:500 on eth0
Oct 27 12:29:12 smaug pluto[6181]: packet from I.I.I.I:500: received Vendor ID payload [Dead Peer Detection]
Oct 27 12:29:12 smaug pluto[6181]: packet from I.I.I.I:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-03]
Oct 27 12:29:12 smaug pluto[6181]: packet from I.I.I.I:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02] meth=107, but already using method 108
Oct 27 12:29:12 smaug pluto[6181]: packet from I.I.I.I:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-00]
Oct 27 12:29:12 smaug pluto[6181]: packet from I.I.I.I:500: initial Main Mode message received on 192.168.3.11:500 but no connection has been authorized
Oct 27 12:29:12 smaug pluto[6181]: | next event EVENT_REINIT_SECRET in 3089 seconds
Oct 27 12:29:24 smaug pluto[6181]: |
Oct 27 12:29:24 smaug pluto[6181]: | *received whack message
Oct 27 12:29:24 smaug pluto[6181]: shutting down
Oct 27 12:29:24 smaug pluto[6181]: forgetting secrets
Oct 27 12:29:24 smaug pluto[6181]: "albert": deleting connection
Oct 27 12:29:24 smaug pluto[6181]: | delete eroute 192.168.1.10/32:0 --0-> 192.168.3.11/32:0 => int.0 at 192.168.3.11 (raw_eroute)
Oct 27 12:29:24 smaug pluto[6181]: | eroute_connection delete eroute 192.168.3.11/32:0 --0-> 192.168.1.10/32:0 => int.0 at 0.0.0.0 (raw_eroute)
Oct 27 12:29:24 smaug pluto[6181]: | route owner of "albert" unrouted: NULL
Oct 27 12:29:24 smaug pluto[6181]: | executing unroute-host: 2>&1 PLUTO_VERSION='1.1' PLUTO_VERB='unroute-host' PLUTO_CONNECTION='albert' PLUTO_NEXT_HOP='192.168.3.1' PLUTO_INTERFACE='eth0' PLUTO_ME='192.168.3.11' PLUTO_MY_ID='@smaug.serialnet.net' PLUTO_MY_CLIENT='192.168.3.11/32' PLUTO_MY_CLIENT_NET='192.168.3.11' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='I.I.I.I' PLUTO_PEER_ID='@glaurung.serialnet.net' PLUTO_PEER_CLIENT='192.168.1.10/32' PLUTO_PEER_CLIENT_NET='192.168.1.10' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_CONN_POLICY='RSASIG+ENCRYPT+TUNNEL+PFS' ipsec _updown
Oct 27 12:29:24 smaug pluto[6181]: | alg_info_delref(0x91e5418)
Oct 27 12:29:24 smaug pluto[6181]: | alg_info_delref(0x91e5418) alg_info->ref_cnt=2
Oct 27 12:29:24 smaug pluto[6181]: | alg_info_delref(0x91e5830)
Oct 27 12:29:24 smaug pluto[6181]: | alg_info_delref(0x91e5830) alg_info->ref_cnt=2
Oct 27 12:29:25 smaug pluto[6181]: shutting down interface lo/lo ::1
Oct 27 12:29:25 smaug pluto[6181]: shutting down interface lo/lo 127.0.0.1
Oct 27 12:29:25 smaug pluto[6181]: shutting down interface lo/lo 127.0.0.1
Oct 27 12:29:25 smaug pluto[6181]: shutting down interface eth0/eth0 192.168.3.11
Oct 27 12:29:25 smaug pluto[6181]: shutting down interface eth0/eth0 192.168.3.11
// I'VE LEFT REMOTE END (INITIATOR) RETRYING MAIN MODE AND DO A /etc/init.d/ipsec restart
// AT THIS HOST AND MAGIC IS THERE BECAUSE IT WORKS FINE
Oct 27 12:29:30 smaug ipsec__plutorun: Starting Pluto subsystem...
Oct 27 12:29:30 smaug pluto[6390]: Starting Pluto (Openswan Version 2.2.0 X.509-1.5.4 PLUTO_USES_KEYRR)
Oct 27 12:29:30 smaug pluto[6390]: including NAT-Traversal patch (Version 0.6c)
Oct 27 12:29:30 smaug pluto[6390]: | inserting event EVENT_REINIT_SECRET, timeout in 3600 seconds
Oct 27 12:29:30 smaug pluto[6390]: ike_alg_register_enc(): Activating OAKLEY_AES_CBC: Ok (ret=0)
Oct 27 12:29:30 smaug pluto[6390]: Using Linux 2.6 IPsec interface code
Oct 27 12:29:30 smaug pluto[6390]: Changing to directory '/etc/ipsec.d/cacerts'
Oct 27 12:29:30 smaug pluto[6390]: Could not change to directory '/etc/ipsec.d/aacerts'
Oct 27 12:29:30 smaug pluto[6390]: Changing to directory '/etc/ipsec.d/ocspcerts'
Oct 27 12:29:30 smaug pluto[6390]: Changing to directory '/etc/ipsec.d/crls'
Oct 27 12:29:30 smaug pluto[6390]: Warning: empty directory
Oct 27 12:29:30 smaug pluto[6390]: | inserting event 11??, timeout in 41430 seconds
Oct 27 12:29:30 smaug pluto[6390]: | next event EVENT_REINIT_SECRET in 3600 seconds
Oct 27 12:29:31 smaug pluto[6390]: |
Oct 27 12:29:31 smaug pluto[6390]: | *received whack message
Oct 27 12:29:31 smaug pluto[6390]: | next event EVENT_REINIT_SECRET in 3599 seconds
Oct 27 12:29:31 smaug pluto[6390]: |
Oct 27 12:29:31 smaug pluto[6390]: | *received whack message
Oct 27 12:29:31 smaug pluto[6390]: | next event EVENT_REINIT_SECRET in 3599 seconds
Oct 27 12:29:31 smaug pluto[6390]: |
Oct 27 12:29:31 smaug pluto[6390]: | *received whack message
Oct 27 12:29:31 smaug pluto[6390]: | Added new connection albert with policy RSASIG+ENCRYPT+TUNNEL+PFS
Oct 27 12:29:31 smaug pluto[6390]: | from whack: got --esp=3des-md5,3des-sha1
Oct 27 12:29:31 smaug pluto[6390]: | esp string values: 3_000-1, 3_000-2, flags=-strict
Oct 27 12:29:31 smaug pluto[6390]: | from whack: got --ike=3des-md5,3des-sha
Oct 27 12:29:31 smaug pluto[6390]: | ike string values: 5_000-1-5, 5_000-1-2, 5_000-2-5, 5_000-2-2, flags=-strict
Oct 27 12:29:31 smaug pluto[6390]: | counting wild cards for @smaug.serialnet.net is 0
Oct 27 12:29:31 smaug pluto[6390]: | sendcert is 3
Oct 27 12:29:31 smaug pluto[6390]: | counting wild cards for @glaurung.serialnet.net is 0
Oct 27 12:29:31 smaug pluto[6390]: | sendcert is 3
Oct 27 12:29:31 smaug pluto[6390]: | alg_info_addref() alg_info->ref_cnt=1
Oct 27 12:29:31 smaug pluto[6390]: | alg_info_addref() alg_info->ref_cnt=1
Oct 27 12:29:31 smaug pluto[6390]: | alg_info_addref() alg_info->ref_cnt=2
Oct 27 12:29:31 smaug pluto[6390]: | alg_info_addref() alg_info->ref_cnt=2
Oct 27 12:29:31 smaug pluto[6390]: added connection description "albert"
Oct 27 12:29:31 smaug pluto[6390]: | 192.168.3.11/32===192.168.3.11[@smaug.serialnet.net]---192.168.3.1...I.I.I.I[@glaurung.serialnet.net]===192.168.1.10/32
Oct 27 12:29:31 smaug pluto[6390]: | ike_life: 3600s; ipsec_life: 28800s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0; policy: RSASIG+ENCRYPT+TUNNEL+PFS
Oct 27 12:29:31 smaug pluto[6390]: | next event EVENT_REINIT_SECRET in 3599 seconds
Oct 27 12:29:31 smaug pluto[6390]: |
Oct 27 12:29:31 smaug pluto[6390]: | *received whack message
Oct 27 12:29:31 smaug pluto[6390]: listening for IKE messages
Oct 27 12:29:31 smaug pluto[6390]: | found lo with address 127.0.0.1
Oct 27 12:29:31 smaug pluto[6390]: | found eth0 with address 192.168.3.11
Oct 27 12:29:31 smaug pluto[6390]: adding interface eth0/eth0 192.168.3.11
Oct 27 12:29:31 smaug pluto[6390]: adding interface eth0/eth0 192.168.3.11:4500
Oct 27 12:29:31 smaug pluto[6390]: adding interface lo/lo 127.0.0.1
Oct 27 12:29:31 smaug pluto[6390]: adding interface lo/lo 127.0.0.1:4500
Oct 27 12:29:31 smaug pluto[6390]: | found lo with address 0000:0000:0000:0000:0000:0000:0000:0001
Oct 27 12:29:31 smaug pluto[6390]: adding interface lo/lo ::1
Oct 27 12:29:31 smaug pluto[6390]: loading secrets from "/etc/ipsec.secrets"
Oct 27 12:29:31 smaug pluto[6390]: | loaded private key for keyid: PPK_RSA:AQNtzdaGd
Oct 27 12:29:31 smaug pluto[6390]: | next event EVENT_REINIT_SECRET in 3599 seconds
Oct 27 12:29:52 smaug pluto[6390]: |
Oct 27 12:29:52 smaug pluto[6390]: | *received 256 bytes from I.I.I.I:500 on eth0
Oct 27 12:29:52 smaug pluto[6390]: packet from I.I.I.I:500: received Vendor ID payload [Dead Peer Detection]
Oct 27 12:29:52 smaug pluto[6390]: packet from I.I.I.I:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-03]
Oct 27 12:29:52 smaug pluto[6390]: packet from I.I.I.I:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02] meth=107, but already using method 108
Oct 27 12:29:52 smaug pluto[6390]: packet from I.I.I.I:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-00]
Oct 27 12:29:52 smaug pluto[6390]: | creating state object #1 at 0x96ae340
Oct 27 12:29:52 smaug pluto[6390]: | ICOOKIE: 7b d9 30 30 b4 62 4a ab
Oct 27 12:29:52 smaug pluto[6390]: | RCOOKIE: 1f 9e a9 67 79 5d 95 76
Oct 27 12:29:52 smaug pluto[6390]: | peer: 50 1c d8 69
Oct 27 12:29:52 smaug pluto[6390]: | state hash entry 4
Oct 27 12:29:52 smaug pluto[6390]: | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #1
Oct 27 12:29:52 smaug pluto[6390]: "albert" #1: responding to Main Mode
Oct 27 12:29:53 smaug pluto[6390]: "albert" #1: transition from state (null) to state STATE_MAIN_R1
Oct 27 12:29:53 smaug pluto[6390]: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
Oct 27 12:29:53 smaug pluto[6390]: | next event EVENT_RETRANSMIT in 10 seconds for #1
Oct 27 12:29:53 smaug pluto[6390]: |
Oct 27 12:29:53 smaug pluto[6390]: | *received 284 bytes from I.I.I.I:500 on eth0
Oct 27 12:29:53 smaug pluto[6390]: | ICOOKIE: 7b d9 30 30 b4 62 4a ab
Oct 27 12:29:53 smaug pluto[6390]: | RCOOKIE: 1f 9e a9 67 79 5d 95 76
Oct 27 12:29:53 smaug pluto[6390]: | peer: 50 1c d8 69
Oct 27 12:29:53 smaug pluto[6390]: | state hash entry 4
Oct 27 12:29:53 smaug pluto[6390]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:29:53 smaug pluto[6390]: | state object #1 found, in STATE_MAIN_R1
Oct 27 12:29:53 smaug pluto[6390]: "albert" #1: NAT-Traversal: Result using draft-ietf-ipsec-nat-t-ike-02/03: both are NATed
Oct 27 12:29:53 smaug pluto[6390]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:29:53 smaug pluto[6390]: "albert" #1: transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
Oct 27 12:29:53 smaug pluto[6390]: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
Oct 27 12:29:53 smaug pluto[6390]: | next event EVENT_RETRANSMIT in 10 seconds for #1
Oct 27 12:29:53 smaug pluto[6390]: |
Oct 27 12:29:53 smaug pluto[6390]: | *received 340 bytes from I.I.I.I:4500 on eth0
Oct 27 12:29:53 smaug pluto[6390]: | ICOOKIE: 7b d9 30 30 b4 62 4a ab
Oct 27 12:29:53 smaug pluto[6390]: | RCOOKIE: 1f 9e a9 67 79 5d 95 76
Oct 27 12:29:53 smaug pluto[6390]: | peer: 50 1c d8 69
Oct 27 12:29:53 smaug pluto[6390]: | state hash entry 4
Oct 27 12:29:53 smaug pluto[6390]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:29:53 smaug pluto[6390]: | state object #1 found, in STATE_MAIN_R2
Oct 27 12:29:53 smaug pluto[6390]: "albert" #1: Peer ID is ID_FQDN: '@glaurung.serialnet.net'
Oct 27 12:29:53 smaug pluto[6390]: | offered CA: '%none'
Oct 27 12:29:53 smaug pluto[6390]: | required CA is '%any'
Oct 27 12:29:53 smaug pluto[6390]: | key issuer CA is '%any'
Oct 27 12:29:53 smaug pluto[6390]: | an RSA Sig check passed with *AQOdUUfRj [preloaded key]
Oct 27 12:29:53 smaug pluto[6390]: | thinking about whether to send my certificate:
Oct 27 12:29:53 smaug pluto[6390]: | I have RSA key: OAKLEY_RSA_SIG cert.type: CERT_NONE
Oct 27 12:29:53 smaug pluto[6390]: | sendcert: CERT_ALWAYSSEND and I did not get a certificate request
Oct 27 12:29:54 smaug pluto[6390]: | so do not send cert.
Oct 27 12:29:54 smaug pluto[6390]: "albert" #1: I did not send a certificate because I do not have one.
Oct 27 12:29:54 smaug pluto[6390]: | looking for secret for @smaug.serialnet.net->@glaurung.serialnet.net of kind PPK_RSA
Oct 27 12:29:54 smaug pluto[6390]: | signing hash with RSA Key *AQNtzdaGd
Oct 27 12:29:54 smaug pluto[6390]: "albert" #1: transition from state STATE_MAIN_R2 to state STATE_MAIN_R3
Oct 27 12:29:54 smaug pluto[6390]: | NAT-T: new mapping I.I.I.I:500/4500)
Oct 27 12:29:54 smaug pluto[6390]: | inserting event EVENT_SA_REPLACE, timeout in 3330 seconds for #1
Oct 27 12:29:54 smaug pluto[6390]: "albert" #1: sent MR3, ISAKMP SA established
Oct 27 12:29:54 smaug pluto[6390]: | next event EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:29:54 smaug pluto[6390]: |
Oct 27 12:29:54 smaug pluto[6390]: | *received 380 bytes from I.I.I.I:4500 on eth0
Oct 27 12:29:54 smaug pluto[6390]: | ICOOKIE: 7b d9 30 30 b4 62 4a ab
Oct 27 12:29:54 smaug pluto[6390]: | RCOOKIE: 1f 9e a9 67 79 5d 95 76
Oct 27 12:29:54 smaug pluto[6390]: | peer: 50 1c d8 69
Oct 27 12:29:54 smaug pluto[6390]: | state hash entry 4
Oct 27 12:29:54 smaug pluto[6390]: | peer and cookies match on #1, provided msgid f3c803a7 vs 00000000
Oct 27 12:29:54 smaug pluto[6390]: | state object not found
Oct 27 12:29:54 smaug pluto[6390]: | ICOOKIE: 7b d9 30 30 b4 62 4a ab
Oct 27 12:29:54 smaug pluto[6390]: | RCOOKIE: 1f 9e a9 67 79 5d 95 76
Oct 27 12:29:54 smaug pluto[6390]: | peer: 50 1c d8 69
Oct 27 12:29:54 smaug pluto[6390]: | state hash entry 4
Oct 27 12:29:54 smaug pluto[6390]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:29:54 smaug pluto[6390]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:29:54 smaug pluto[6390]: | peer client is subnet 192.168.1.10/32
Oct 27 12:29:54 smaug pluto[6390]: | peer client protocol/port is 0/0
Oct 27 12:29:54 smaug pluto[6390]: | our client is subnet 192.168.3.11/32
Oct 27 12:29:54 smaug pluto[6390]: | our client protocol/port is 0/0
Oct 27 12:29:54 smaug pluto[6390]: | duplicating state object #1
Oct 27 12:29:54 smaug pluto[6390]: | creating state object #2 at 0x96af1a8
Oct 27 12:29:54 smaug pluto[6390]: | ICOOKIE: 7b d9 30 30 b4 62 4a ab
Oct 27 12:29:54 smaug pluto[6390]: | RCOOKIE: 1f 9e a9 67 79 5d 95 76
Oct 27 12:29:54 smaug pluto[6390]: | peer: 50 1c d8 69
Oct 27 12:29:54 smaug pluto[6390]: | state hash entry 4
Oct 27 12:29:54 smaug pluto[6390]: | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #2
Oct 27 12:29:54 smaug pluto[6390]: "albert" #2: responding to Quick Mode
Oct 27 12:29:54 smaug pluto[6390]: | route owner of "albert" unrouted: NULL
Oct 27 12:29:54 smaug pluto[6390]: | install_inbound_ipsec_sa() checking if we can route
Oct 27 12:29:54 smaug pluto[6390]: | route owner of "albert" unrouted: NULL; eroute owner: NULL
Oct 27 12:29:54 smaug pluto[6390]: | could_route called for albert (kind=CK_PERMANENT)
Oct 27 12:29:54 smaug pluto[6390]: | add inbound eroute 192.168.1.10/32:0 --0-> 192.168.3.11/32:0 => tun.10000 at 192.168.3.11 (raw_eroute)
Oct 27 12:29:54 smaug pluto[6390]: "albert" #2: transition from state (null) to state STATE_QUICK_R1
Oct 27 12:29:54 smaug pluto[6390]: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #2
Oct 27 12:29:54 smaug pluto[6390]: | next event EVENT_RETRANSMIT in 10 seconds for #2
Oct 27 12:29:54 smaug pluto[6390]: |
Oct 27 12:29:54 smaug pluto[6390]: | *received 52 bytes from I.I.I.I:4500 on eth0
Oct 27 12:29:54 smaug pluto[6390]: | ICOOKIE: 7b d9 30 30 b4 62 4a ab
Oct 27 12:29:54 smaug pluto[6390]: | RCOOKIE: 1f 9e a9 67 79 5d 95 76
Oct 27 12:29:54 smaug pluto[6390]: | peer: 50 1c d8 69
Oct 27 12:29:54 smaug pluto[6390]: | state hash entry 4
Oct 27 12:29:54 smaug pluto[6390]: | peer and cookies match on #2, provided msgid f3c803a7 vs f3c803a7
Oct 27 12:29:54 smaug pluto[6390]: | state object #2 found, in STATE_QUICK_R1
Oct 27 12:29:54 smaug pluto[6390]: | install_ipsec_sa() for #2: outbound only
Oct 27 12:29:54 smaug pluto[6390]: | route owner of "albert" unrouted: NULL; eroute owner: NULL
Oct 27 12:29:54 smaug pluto[6390]: | could_route called for albert (kind=CK_PERMANENT)
Oct 27 12:29:54 smaug pluto[6390]: | sr for #2: unrouted
Oct 27 12:29:54 smaug pluto[6390]: | route owner of "albert" unrouted: NULL; eroute owner: NULL
Oct 27 12:29:54 smaug pluto[6390]: | eroute_connection add eroute 192.168.3.11/32:0 --0-> 192.168.1.10/32:0 => tun.0 at I.I.I.I (raw_eroute)
Oct 27 12:29:54 smaug pluto[6390]: | executing up-host: 2>&1 PLUTO_VERSION='1.1' PLUTO_VERB='up-host' PLUTO_CONNECTION='albert' PLUTO_NEXT_HOP='192.168.3.1' PLUTO_INTERFACE='eth0' PLUTO_ME='192.168.3.11' PLUTO_MY_ID='@smaug.serialnet.net' PLUTO_MY_CLIENT='192.168.3.11/32' PLUTO_MY_CLIENT_NET='192.168.3.11' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='I.I.I.I' PLUTO_PEER_ID='@glaurung.serialnet.net' PLUTO_PEER_CLIENT='192.168.1.10/32' PLUTO_PEER_CLIENT_NET='192.168.1.10' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_CONN_POLICY='RSASIG+ENCRYPT+TUNNEL+PFS' ipsec _updown
Oct 27 12:29:54 smaug pluto[6390]: | route_and_eroute: firewall_notified: true
Oct 27 12:29:54 smaug pluto[6390]: | executing prepare-host: 2>&1 PLUTO_VERSION='1.1' PLUTO_VERB='prepare-host' PLUTO_CONNECTION='albert' PLUTO_NEXT_HOP='192.168.3.1' PLUTO_INTERFACE='eth0' PLUTO_ME='192.168.3.11' PLUTO_MY_ID='@smaug.serialnet.net' PLUTO_MY_CLIENT='192.168.3.11/32' PLUTO_MY_CLIENT_NET='192.168.3.11' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='I.I.I.I' PLUTO_PEER_ID='@glaurung.serialnet.net' PLUTO_PEER_CLIENT='192.168.1.10/32' PLUTO_PEER_CLIENT_NET='192.168.1.10' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_CONN_POLICY='RSASIG+ENCRYPT+TUNNEL+PFS' ipsec _updown
Oct 27 12:29:54 smaug pluto[6390]: | executing route-host: 2>&1 PLUTO_VERSION='1.1' PLUTO_VERB='route-host' PLUTO_CONNECTION='albert' PLUTO_NEXT_HOP='192.168.3.1' PLUTO_INTERFACE='eth0' PLUTO_ME='192.168.3.11' PLUTO_MY_ID='@smaug.serialnet.net' PLUTO_MY_CLIENT='192.168.3.11/32' PLUTO_MY_CLIENT_NET='192.168.3.11' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='I.I.I.I' PLUTO_PEER_ID='@glaurung.serialnet.net' PLUTO_PEER_CLIENT='192.168.1.10/32' PLUTO_PEER_CLIENT_NET='192.168.1.10' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_CONN_POLICY='RSASIG+ENCRYPT+TUNNEL+PFS' ipsec _updown
Oct 27 12:29:54 smaug pluto[6390]: | route_and_eroute: instance "albert", setting eroute_owner {spd=0x96ac1cc,sr=0x96ac1cc} to #2 (was #0) (newest_ipsec_sa=#0)
Oct 27 12:29:54 smaug pluto[6390]: | ICOOKIE: 7b d9 30 30 b4 62 4a ab
Oct 27 12:29:54 smaug pluto[6390]: | RCOOKIE: 1f 9e a9 67 79 5d 95 76
Oct 27 12:29:54 smaug pluto[6390]: | peer: 50 1c d8 69
Oct 27 12:29:54 smaug pluto[6390]: | state hash entry 4
Oct 27 12:29:54 smaug pluto[6390]: | peer and cookies match on #2, provided msgid 00000000 vs f3c803a7
Oct 27 12:29:54 smaug pluto[6390]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:29:54 smaug pluto[6390]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:29:54 smaug pluto[6390]: "albert" #2: Dead Peer Detection (RFC 3706) enabled
Oct 27 12:29:54 smaug pluto[6390]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:29:54 smaug pluto[6390]: "albert" #2: transition from state STATE_QUICK_R1 to state STATE_QUICK_R2
Oct 27 12:29:54 smaug pluto[6390]: | inserting event EVENT_SA_REPLACE, timeout in 28530 seconds for #2
Oct 27 12:29:54 smaug pluto[6390]: "albert" #2: IPsec SA established {ESP=>0xee038d43 <0x7f517b55 NATOA=0.0.0.0}
Oct 27 12:29:54 smaug pluto[6390]: | next event 9?? in 10 seconds for #2
Oct 27 12:30:04 smaug pluto[6390]: |
Oct 27 12:30:04 smaug pluto[6390]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:30:04 smaug pluto[6390]: | ICOOKIE: 7b d9 30 30 b4 62 4a ab
Oct 27 12:30:04 smaug pluto[6390]: | RCOOKIE: 1f 9e a9 67 79 5d 95 76
Oct 27 12:30:04 smaug pluto[6390]: | peer: 50 1c d8 69
Oct 27 12:30:04 smaug pluto[6390]: | state hash entry 4
Oct 27 12:30:04 smaug pluto[6390]: | peer and cookies match on #2, provided msgid 00000000 vs f3c803a7
Oct 27 12:30:04 smaug pluto[6390]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:30:04 smaug pluto[6390]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:30:04 smaug pluto[6390]: | R_U_THERE_ACK, seqno received: 17489 expected: 0
Oct 27 12:30:04 smaug pluto[6390]: | next event 9?? in 0 seconds for #2
Oct 27 12:30:04 smaug pluto[6390]: |
Oct 27 12:30:04 smaug pluto[6390]: | *time to handle event
Oct 27 12:30:04 smaug pluto[6390]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:30:04 smaug pluto[6390]: | not yet time for dpd event: 1098873004 < 1098873014
Oct 27 12:30:04 smaug pluto[6390]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:30:04 smaug pluto[6390]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:30:13 smaug pluto[6390]: |
Oct 27 12:30:13 smaug pluto[6390]: | *time to handle event
Oct 27 12:30:13 smaug pluto[6390]: | event after this is 9?? in 1 seconds
Oct 27 12:30:13 smaug pluto[6390]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:30:13 smaug pluto[6390]: | next event 9?? in 1 seconds for #2
Oct 27 12:30:14 smaug pluto[6390]: |
Oct 27 12:30:14 smaug pluto[6390]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:30:14 smaug pluto[6390]: | ICOOKIE: 7b d9 30 30 b4 62 4a ab
Oct 27 12:30:14 smaug pluto[6390]: | RCOOKIE: 1f 9e a9 67 79 5d 95 76
Oct 27 12:30:14 smaug pluto[6390]: | peer: 50 1c d8 69
Oct 27 12:30:14 smaug pluto[6390]: | state hash entry 4
Oct 27 12:30:14 smaug pluto[6390]: | peer and cookies match on #2, provided msgid 00000000 vs f3c803a7
Oct 27 12:30:14 smaug pluto[6390]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:30:14 smaug pluto[6390]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:30:14 smaug pluto[6390]: | R_U_THERE_ACK, seqno received: 17490 expected: 0
Oct 27 12:30:14 smaug pluto[6390]: | next event 9?? in 0 seconds for #2
Oct 27 12:30:14 smaug pluto[6390]: |
Oct 27 12:30:14 smaug pluto[6390]: | *time to handle event
Oct 27 12:30:14 smaug pluto[6390]: | event after this is EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:30:14 smaug pluto[6390]: | not yet time for dpd event: 1098873014 < 1098873024
Oct 27 12:30:14 smaug pluto[6390]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:30:14 smaug pluto[6390]: | next event 9?? in 10 seconds for #2
Oct 27 12:30:24 smaug pluto[6390]: |
Oct 27 12:30:24 smaug pluto[6390]: | *time to handle event
Oct 27 12:30:24 smaug pluto[6390]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:30:24 smaug pluto[6390]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:30:24 smaug pluto[6390]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:30:24 smaug pluto[6390]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:30:24 smaug pluto[6390]: |
Oct 27 12:30:24 smaug pluto[6390]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:30:24 smaug pluto[6390]: | ICOOKIE: 7b d9 30 30 b4 62 4a ab
Oct 27 12:30:24 smaug pluto[6390]: | RCOOKIE: 1f 9e a9 67 79 5d 95 76
Oct 27 12:30:24 smaug pluto[6390]: | peer: 50 1c d8 69
Oct 27 12:30:24 smaug pluto[6390]: | state hash entry 4
Oct 27 12:30:24 smaug pluto[6390]: | peer and cookies match on #2, provided msgid 00000000 vs f3c803a7
Oct 27 12:30:24 smaug pluto[6390]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:30:24 smaug pluto[6390]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:30:24 smaug pluto[6390]: | R_U_THERE_ACK, seqno received: 17491 expected: 32105
Oct 27 12:30:24 smaug pluto[6390]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:30:24 smaug pluto[6390]: |
Oct 27 12:30:24 smaug pluto[6390]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:30:24 smaug pluto[6390]: | ICOOKIE: 7b d9 30 30 b4 62 4a ab
Oct 27 12:30:24 smaug pluto[6390]: | RCOOKIE: 1f 9e a9 67 79 5d 95 76
Oct 27 12:30:24 smaug pluto[6390]: | peer: 50 1c d8 69
Oct 27 12:30:24 smaug pluto[6390]: | state hash entry 4
Oct 27 12:30:24 smaug pluto[6390]: | peer and cookies match on #2, provided msgid 00000000 vs f3c803a7
Oct 27 12:30:24 smaug pluto[6390]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:30:24 smaug pluto[6390]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:30:24 smaug pluto[6390]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:30:33 smaug pluto[6390]: |
Oct 27 12:30:33 smaug pluto[6390]: | *time to handle event
Oct 27 12:30:33 smaug pluto[6390]: | event after this is 9?? in 1 seconds
Oct 27 12:30:33 smaug pluto[6390]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:30:33 smaug pluto[6390]: | next event 9?? in 1 seconds for #2
Oct 27 12:30:34 smaug pluto[6390]: |
Oct 27 12:30:34 smaug pluto[6390]: | *time to handle event
Oct 27 12:30:34 smaug pluto[6390]: | event after this is EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:30:34 smaug pluto[6390]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:30:34 smaug pluto[6390]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:30:34 smaug pluto[6390]: | next event 9?? in 10 seconds for #2
Oct 27 12:30:34 smaug pluto[6390]: |
Oct 27 12:30:34 smaug pluto[6390]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:30:34 smaug pluto[6390]: | ICOOKIE: 7b d9 30 30 b4 62 4a ab
Oct 27 12:30:34 smaug pluto[6390]: | RCOOKIE: 1f 9e a9 67 79 5d 95 76
Oct 27 12:30:34 smaug pluto[6390]: | peer: 50 1c d8 69
Oct 27 12:30:34 smaug pluto[6390]: | state hash entry 4
Oct 27 12:30:34 smaug pluto[6390]: | peer and cookies match on #2, provided msgid 00000000 vs f3c803a7
Oct 27 12:30:34 smaug pluto[6390]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:30:34 smaug pluto[6390]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:30:34 smaug pluto[6390]: | R_U_THERE_ACK, seqno received: 17492 expected: 32106
Oct 27 12:30:34 smaug pluto[6390]: | next event 9?? in 10 seconds for #2
Oct 27 12:30:34 smaug pluto[6390]: |
Oct 27 12:30:34 smaug pluto[6390]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:30:34 smaug pluto[6390]: | ICOOKIE: 7b d9 30 30 b4 62 4a ab
Oct 27 12:30:34 smaug pluto[6390]: | RCOOKIE: 1f 9e a9 67 79 5d 95 76
Oct 27 12:30:34 smaug pluto[6390]: | peer: 50 1c d8 69
Oct 27 12:30:34 smaug pluto[6390]: | state hash entry 4
Oct 27 12:30:34 smaug pluto[6390]: | peer and cookies match on #2, provided msgid 00000000 vs f3c803a7
Oct 27 12:30:34 smaug pluto[6390]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:30:34 smaug pluto[6390]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:30:34 smaug pluto[6390]: | next event 9?? in 10 seconds for #2
Oct 27 12:30:44 smaug pluto[6390]: |
Oct 27 12:30:44 smaug pluto[6390]: | *time to handle event
Oct 27 12:30:44 smaug pluto[6390]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:30:44 smaug pluto[6390]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:30:44 smaug pluto[6390]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:30:44 smaug pluto[6390]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:30:44 smaug pluto[6390]: |
Oct 27 12:30:44 smaug pluto[6390]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:30:44 smaug pluto[6390]: | ICOOKIE: 7b d9 30 30 b4 62 4a ab
Oct 27 12:30:44 smaug pluto[6390]: | RCOOKIE: 1f 9e a9 67 79 5d 95 76
Oct 27 12:30:44 smaug pluto[6390]: | peer: 50 1c d8 69
Oct 27 12:30:44 smaug pluto[6390]: | state hash entry 4
Oct 27 12:30:44 smaug pluto[6390]: | peer and cookies match on #2, provided msgid 00000000 vs f3c803a7
Oct 27 12:30:44 smaug pluto[6390]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:30:44 smaug pluto[6390]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:30:44 smaug pluto[6390]: | R_U_THERE_ACK, seqno received: 17493 expected: 32107
Oct 27 12:30:44 smaug pluto[6390]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:30:44 smaug pluto[6390]: |
Oct 27 12:30:44 smaug pluto[6390]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:30:44 smaug pluto[6390]: | ICOOKIE: 7b d9 30 30 b4 62 4a ab
Oct 27 12:30:44 smaug pluto[6390]: | RCOOKIE: 1f 9e a9 67 79 5d 95 76
Oct 27 12:30:44 smaug pluto[6390]: | peer: 50 1c d8 69
Oct 27 12:30:44 smaug pluto[6390]: | state hash entry 4
Oct 27 12:30:44 smaug pluto[6390]: | peer and cookies match on #2, provided msgid 00000000 vs f3c803a7
Oct 27 12:30:44 smaug pluto[6390]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:30:44 smaug pluto[6390]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:30:44 smaug pluto[6390]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
Oct 27 12:30:53 smaug pluto[6390]: |
Oct 27 12:30:53 smaug pluto[6390]: | *time to handle event
Oct 27 12:30:53 smaug pluto[6390]: | event after this is 9?? in 1 seconds
Oct 27 12:30:53 smaug pluto[6390]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct 27 12:30:53 smaug pluto[6390]: | next event 9?? in 1 seconds for #2
Oct 27 12:30:54 smaug pluto[6390]: |
Oct 27 12:30:54 smaug pluto[6390]: | *time to handle event
Oct 27 12:30:54 smaug pluto[6390]: | event after this is EVENT_NAT_T_KEEPALIVE in 19 seconds
Oct 27 12:30:54 smaug pluto[6390]: | inserting event 9??, timeout in 10 seconds for #2
Oct 27 12:30:54 smaug pluto[6390]: | inserting event 10??, timeout in 30 seconds for #1
Oct 27 12:30:54 smaug pluto[6390]: | next event 9?? in 10 seconds for #2
Oct 27 12:30:54 smaug pluto[6390]: |
Oct 27 12:30:54 smaug pluto[6390]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:30:54 smaug pluto[6390]: | ICOOKIE: 7b d9 30 30 b4 62 4a ab
Oct 27 12:30:54 smaug pluto[6390]: | RCOOKIE: 1f 9e a9 67 79 5d 95 76
Oct 27 12:30:54 smaug pluto[6390]: | peer: 50 1c d8 69
Oct 27 12:30:54 smaug pluto[6390]: | state hash entry 4
Oct 27 12:30:54 smaug pluto[6390]: | peer and cookies match on #2, provided msgid 00000000 vs f3c803a7
Oct 27 12:30:54 smaug pluto[6390]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:30:54 smaug pluto[6390]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:30:54 smaug pluto[6390]: | R_U_THERE_ACK, seqno received: 17494 expected: 32108
Oct 27 12:30:54 smaug pluto[6390]: | next event 9?? in 10 seconds for #2
Oct 27 12:30:54 smaug pluto[6390]: |
Oct 27 12:30:54 smaug pluto[6390]: | *received 84 bytes from I.I.I.I:4500 on eth0
Oct 27 12:30:54 smaug pluto[6390]: | ICOOKIE: 7b d9 30 30 b4 62 4a ab
Oct 27 12:30:54 smaug pluto[6390]: | RCOOKIE: 1f 9e a9 67 79 5d 95 76
Oct 27 12:30:54 smaug pluto[6390]: | peer: 50 1c d8 69
Oct 27 12:30:54 smaug pluto[6390]: | state hash entry 4
Oct 27 12:30:54 smaug pluto[6390]: | peer and cookies match on #2, provided msgid 00000000 vs f3c803a7
Oct 27 12:30:54 smaug pluto[6390]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000
Oct 27 12:30:54 smaug pluto[6390]: | state object #1 found, in STATE_MAIN_R3
Oct 27 12:30:54 smaug pluto[6390]: | next event 9?? in 10 seconds for #2
Oct 27 12:30:58 smaug pluto[6390]: |
Oct 27 12:30:58 smaug pluto[6390]: | *received whack message
Oct 27 12:30:58 smaug pluto[6390]: shutting down
Oct 27 12:30:58 smaug pluto[6390]: forgetting secrets
Oct 27 12:30:58 smaug pluto[6390]: "albert": deleting connection
Oct 27 12:30:58 smaug pluto[6390]: "albert" #2: deleting state (STATE_QUICK_R2)
Oct 27 12:30:58 smaug pluto[6390]: | ICOOKIE: 7b d9 30 30 b4 62 4a ab
Oct 27 12:30:58 smaug pluto[6390]: | RCOOKIE: 1f 9e a9 67 79 5d 95 76
Oct 27 12:30:58 smaug pluto[6390]: | peer: 50 1c d8 69
Oct 27 12:30:58 smaug pluto[6390]: | state hash entry 4
Oct 27 12:30:58 smaug pluto[6390]: | executing down-host: 2>&1 PLUTO_VERSION='1.1' PLUTO_VERB='down-host' PLUTO_CONNECTION='albert' PLUTO_NEXT_HOP='192.168.3.1' PLUTO_INTERFACE='eth0' PLUTO_ME='192.168.3.11' PLUTO_MY_ID='@smaug.serialnet.net' PLUTO_MY_CLIENT='192.168.3.11/32' PLUTO_MY_CLIENT_NET='192.168.3.11' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='I.I.I.I' PLUTO_PEER_ID='@glaurung.serialnet.net' PLUTO_PEER_CLIENT='192.168.1.10/32' PLUTO_PEER_CLIENT_NET='192.168.1.10' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_CONN_POLICY='RSASIG+ENCRYPT+TUNNEL+PFS' ipsec _updown
Oct 27 12:30:58 smaug pluto[6390]: | replace with shunt eroute 192.168.1.10/32:0 --0-> 192.168.3.11/32:0 => %trap (raw_eroute)
Oct 27 12:30:58 smaug pluto[6390]: | eroute_connection replace with shunt eroute 192.168.3.11/32:0 --0-> 192.168.1.10/32:0 => %trap (raw_eroute)
Oct 27 12:30:58 smaug pluto[6390]: | delete inbound eroute 192.168.1.10/32:0 --0-> 192.168.3.11/32:0 => unk255.10000 at 192.168.3.11 (raw_eroute)
Oct 27 12:30:58 smaug pluto[6390]: "albert" #1: deleting state (STATE_MAIN_R3)
Oct 27 12:30:58 smaug pluto[6390]: | ICOOKIE: 7b d9 30 30 b4 62 4a ab
Oct 27 12:30:58 smaug pluto[6390]: | RCOOKIE: 1f 9e a9 67 79 5d 95 76
Oct 27 12:30:58 smaug pluto[6390]: | peer: 50 1c d8 69
Oct 27 12:30:58 smaug pluto[6390]: | state hash entry 4
Oct 27 12:30:58 smaug pluto[6390]: | delete eroute 192.168.1.10/32:0 --0-> 192.168.3.11/32:0 => int.0 at 192.168.3.11 (raw_eroute)
Oct 27 12:30:58 smaug pluto[6390]: | eroute_connection delete eroute 192.168.3.11/32:0 --0-> 192.168.1.10/32:0 => int.0 at 0.0.0.0 (raw_eroute)
Oct 27 12:30:58 smaug pluto[6390]: | route owner of "albert" unrouted: NULL
Oct 27 12:30:58 smaug pluto[6390]: | executing unroute-host: 2>&1 PLUTO_VERSION='1.1' PLUTO_VERB='unroute-host' PLUTO_CONNECTION='albert' PLUTO_NEXT_HOP='192.168.3.1' PLUTO_INTERFACE='eth0' PLUTO_ME='192.168.3.11' PLUTO_MY_ID='@smaug.serialnet.net' PLUTO_MY_CLIENT='192.168.3.11/32' PLUTO_MY_CLIENT_NET='192.168.3.11' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='I.I.I.I' PLUTO_PEER_ID='@glaurung.serialnet.net' PLUTO_PEER_CLIENT='192.168.1.10/32' PLUTO_PEER_CLIENT_NET='192.168.1.10' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_CONN_POLICY='RSASIG+ENCRYPT+TUNNEL+PFS' ipsec _updown
Oct 27 12:30:58 smaug pluto[6390]: | alg_info_delref(0x96ac418)
Oct 27 12:30:58 smaug pluto[6390]: | alg_info_delref(0x96ac418) alg_info->ref_cnt=2
Oct 27 12:30:58 smaug pluto[6390]: | alg_info_delref(0x96ac830)
Oct 27 12:30:58 smaug pluto[6390]: | alg_info_delref(0x96ac830) alg_info->ref_cnt=2
Oct 27 12:30:58 smaug pluto[6390]: shutting down interface lo/lo ::1
Oct 27 12:30:58 smaug pluto[6390]: shutting down interface lo/lo 127.0.0.1
Oct 27 12:30:58 smaug pluto[6390]: shutting down interface lo/lo 127.0.0.1
Oct 27 12:30:58 smaug pluto[6390]: shutting down interface eth0/eth0 192.168.3.11
More information about the Users
mailing list