Plutorun started on Sat Jul 23 16:32:37 GMT 2005
Starting Pluto (Libreswan Version cvs2005Jul22_10:11:19 X.509-1.5.4 PLUTO_SENDS_VENDORID PLUTO_USES_KEYRR; Vendor ID OECWKUoQJnw\134)
Setting port floating to off
port floating activate 0/1
  including NAT-Traversal patch (Version 0.6c) [disabled]
ike_alg_register_enc(): Activating OAKLEY_AES_CBC: Ok (ret=0)
starting up 1 cryptographic helpers
started helper pid=162 (fd:5)
Using KLIPS IPsec interface code on 2.6.11.2
Changing to directory '/tmp/iv-01/ipsec.d/cacerts'
  loaded CA cert file 'caCert.pem' (4854 bytes)
Changing to directory '/tmp/iv-01/ipsec.d/aacerts'
Changing to directory '/tmp/iv-01/ipsec.d/ocspcerts'
Changing to directory '/tmp/iv-01/ipsec.d/crls'
  loaded crl file 'nic.crl' (642 bytes)
  loaded crl file 'crashcrl-3.pem' (690 bytes)
crl issuer cacert not found for (file:///tmp/iv-01/ipsec.d/crls/crashcrl-3.pem)
  loaded crl file 'crashcrl-2.pem' (528 bytes)
crl issuer cacert not found for (file:///tmp/iv-01/ipsec.d/crls/crashcrl-2.pem)
  loaded crl file 'crashcrl-1.pem' (1053 bytes)
crl issuer cacert not found for (file:///tmp/iv-01/ipsec.d/crls/crashcrl-1.pem)
added connection description "westnet-eastnet"
| base debugging = crypt+control+controlmore+impair-jacob-two-two
| next event EVENT_PENDING_PHASE2 in 116 seconds
|  
| *received whack message
listening for IKE messages
| found eth0 with address 192.0.2.254
| found eth1 with address 192.1.2.23
| found eth2 with address 192.9.2.23
| found lo with address 127.0.0.1
| found ipsec0 with address 192.1.2.23
| IP interface lo 127.0.0.1 has no matching ipsec* interface -- ignored
| IP interface eth2 192.9.2.23 has no matching ipsec* interface -- ignored
adding interface ipsec0/eth1 192.1.2.23:500
| IP interface eth0 192.0.2.254 has no matching ipsec* interface -- ignored
| could not open /proc/net/if_inet6
| connect_to_host_pair: 192.1.2.23:500 192.1.2.45:500 -> hp:none 
loading secrets from "/tmp/iv-01/ipsec.secrets"
| loaded private key for keyid: PPK_RSA:AQN3cn11F
  loaded private key file '/etc/ipsec.d/private/east.pem' (963 bytes)
|   decrypting file using 'DES-EDE3-CBC'
| loaded private key for keyid: PPK_RSA:AwEAAaFHY
| next event EVENT_PENDING_PHASE2 in 116 seconds
|  
| *received whack message
| find_host_pair: comparing to 192.1.2.23:500 192.1.2.45:500 
| find_host_pair_conn (check_connection_end): 192.1.2.23:500 %any:500 -> hp:none 
| Added new connection packetdefault with policy RSASIG+ENCRYPT+TUNNEL+PFS+DONTREKEY+OPPORTUNISTIC+failurePASS
| counting wild cards for (none) is 0
| counting wild cards for (none) is 15
| based upon policy, the connection is a template.
| find_host_pair: comparing to 192.1.2.23:500 192.1.2.45:500 
| connect_to_host_pair: 192.1.2.23:500 0.0.0.0:500 -> hp:none 
added connection description "packetdefault"
| 0.0.0.0/0===192.1.2.23[%myid]---192.1.2.254...%opportunistic
| ike_life: 3600s; ipsec_life: 3600s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 3; policy: RSASIG+ENCRYPT+TUNNEL+PFS+DONTREKEY+OPPORTUNISTIC+failurePASS
| next event EVENT_PENDING_PHASE2 in 112 seconds
|  
| *received whack message
listening for IKE messages
| found eth0 with address 192.0.2.254
| found eth1 with address 192.1.2.23
| found eth2 with address 192.9.2.23
| found lo with address 127.0.0.1
| found ipsec0 with address 192.1.2.23
| IP interface lo 127.0.0.1 has no matching ipsec* interface -- ignored
| IP interface eth2 192.9.2.23 has no matching ipsec* interface -- ignored
| IP interface eth0 192.0.2.254 has no matching ipsec* interface -- ignored
| could not open /proc/net/if_inet6
forgetting secrets
loading secrets from "/tmp/iv-01/ipsec.secrets"
| loaded private key for keyid: PPK_RSA:AQN3cn11F
  loaded private key file '/etc/ipsec.d/private/east.pem' (963 bytes)
|   decrypting file using 'DES-EDE3-CBC'
| loaded private key for keyid: PPK_RSA:AwEAAaFHY
| next event EVENT_PENDING_PHASE2 in 112 seconds
|  
| *received whack message
| processing connection packetdefault
| route owner of "packetdefault" unrouted: NULL; eroute owner: NULL
| Jacob two two says that the SA will fail
| next event EVENT_PENDING_PHASE2 in 111 seconds
|  
| *received 212 bytes from 192.1.2.45:500 on eth1 (port=500)
packet from 192.1.2.45:500: received Vendor ID payload [Libreswan (this version) cvs2005Jul22_10:11:19  X.509-1.5.4 PLUTO_SENDS_VENDORID PLUTO_USES_KEYRR]
packet from 192.1.2.45:500: received Vendor ID payload [Dead Peer Detection]
| find_host_connection called from main_inI1_outR1
| find_host_pair: comparing to 192.1.2.23:500 0.0.0.0:500 
| find_host_pair: comparing to 192.1.2.23:500 192.1.2.45:500 
| find_host_pair_conn (find_host_connection2): 192.1.2.23:500 192.1.2.45:500 -> hp:westnet-eastnet 
| creating state object #1 at 0x8105b48
| processing connection westnet-eastnet
| ICOOKIE:  57 7e 39 e6  d5 b0 99 72
| RCOOKIE:  5d 0b 5b 27  07 43 62 f7
| peer:  c0 01 02 2d
| state hash entry 27
| inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #1
"westnet-eastnet" #1: responding to Main Mode
| Oakley Transform 0 accepted
| sender checking NAT-t: 0 and 0
| complete state transition with STF_OK
"westnet-eastnet" #1: transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
| sending reply packet to 192.1.2.45:500 (from port=500)
| sending 116 bytes for STATE_MAIN_R0 through eth1:500 to 192.1.2.45:500:
| JACOB 2-2: resending 116 bytes for STATE_MAIN_R0 through eth1:500 to 192.1.2.45:500:
| inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
"westnet-eastnet" #1: STATE_MAIN_R1: sent MR1, expecting MI2
| modecfg pull: noquirk policy:push not-client
| phase 1 is done, looking for phase 1 to unpend
| next event EVENT_PENDING_PHASE2 in -12 seconds
|  
| *time to handle event
| handling event EVENT_PENDING_PHASE2
| event after this is EVENT_SHUNT_SCAN in -11 seconds
| inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
| pending review: connection "packetdefault" was not up, skipped
| pending review: connection "westnet-eastnet" was not up, skipped
| next event EVENT_SHUNT_SCAN in -11 seconds
|  
| *time to handle event
| handling event EVENT_SHUNT_SCAN
| event after this is EVENT_RETRANSMIT in 10 seconds
| inserting event EVENT_SHUNT_SCAN, timeout in 120 seconds
| scanning for shunt eroutes
| next event EVENT_RETRANSMIT in 10 seconds for #1
|  
| *received 212 bytes from 192.1.2.45:500 on eth1 (port=500)
packet from 192.1.2.45:500: received Vendor ID payload [Libreswan (this version) cvs2005Jul22_10:11:19  X.509-1.5.4 PLUTO_SENDS_VENDORID PLUTO_USES_KEYRR]
packet from 192.1.2.45:500: received Vendor ID payload [Dead Peer Detection]
| find_host_connection called from main_inI1_outR1
| find_host_pair: comparing to 192.1.2.23:500 192.1.2.45:500 
| find_host_pair_conn (find_host_connection2): 192.1.2.23:500 192.1.2.45:500 -> hp:westnet-eastnet 
| creating state object #2 at 0x8105fb8
| processing connection westnet-eastnet
| ICOOKIE:  57 7e 39 e6  d5 b0 99 72
| RCOOKIE:  f5 78 dd ff  c8 1f 3f dc
| peer:  c0 01 02 2d
| state hash entry 9
| inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #2
"westnet-eastnet" #2: responding to Main Mode
| Oakley Transform 0 accepted
| sender checking NAT-t: 0 and 0
| complete state transition with STF_OK
"westnet-eastnet" #2: transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
| sending reply packet to 192.1.2.45:500 (from port=500)
| sending 116 bytes for STATE_MAIN_R0 through eth1:500 to 192.1.2.45:500:
| JACOB 2-2: resending 116 bytes for STATE_MAIN_R0 through eth1:500 to 192.1.2.45:500:
| inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #2
"westnet-eastnet" #2: STATE_MAIN_R1: sent MR1, expecting MI2
| modecfg pull: noquirk policy:push not-client
| phase 1 is done, looking for phase 1 to unpend
| next event EVENT_RETRANSMIT in 10 seconds for #2
|  
| *received 244 bytes from 192.1.2.45:500 on eth1 (port=500)
| ICOOKIE:  57 7e 39 e6  d5 b0 99 72
| RCOOKIE:  5d 0b 5b 27  07 43 62 f7
| peer:  c0 01 02 2d
| state hash entry 27
| peer and cookies match on #1, provided msgid 00000000 vs 00000000
| state object #1 found, in STATE_MAIN_R1
| processing connection westnet-eastnet
| DH public value received:
|   d8 ee 19 3e  b9 c7 d7 46  1e a0 af 4c  61 44 33 80
|   e7 b9 4d 8f  4a 04 01 8a  6d 86 73 1f  8e e0 98 56
|   23 a7 2c f0  06 e2 73 51  25 a4 cd cf  ee 9a 21 ae
|   54 83 f8 99  f4 dc bc 4b  ad d8 7f 9a  b7 c4 85 f7
|   96 8f 5d 2d  cf 3c 33 77  ac 05 e9 47  b3 3d 07 d2
|   3b 6f 9b df  d3 9b 72 a9  62 aa a5 86  f3 76 43 5f
|   00 b6 25 96  b2 3b 7b d0  e5 da ea 91  5a 7c 78 9b
|   e4 a4 13 71  10 bc e3 f1  38 59 e7 47  ef 22 ab 6a
|   31 e5 3b 62  d0 36 7a 91  f9 ac e1 85  1c fc f4 59
|   10 e9 33 78  76 5d c4 33  f0 b6 44 67  3c 78 3e d7
|   9d 35 a6 42  48 07 f9 e9  75 79 b8 55  d6 8c 7a 59
|   d9 3c 5f 04  01 d3 70 4d  e1 24 a0 e0  66 5b f4 e4
| inI2: checking NAT-t: 0 and 0
| 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1
| asking helper 0 to do build_kenonce op on seq: 1
| inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #1
| complete state transition with STF_SUSPEND
| next event EVENT_RETRANSMIT in 10 seconds for #2
| helper 0 has work (cnt now 0)
| helper 0 replies to sequence 1
| calling callback function 0x8068850
| main inI2_outR2: calculated ke+nonce, sending R2
| processing connection westnet-eastnet
| started looking for secret for @east->@west of kind PPK_PSK
| actually looking for secret for @east->@west of kind PPK_PSK
| concluding with best_match=0 best=(nil) (lineno=-1)
| calc_dh_shared(): time elapsed (OAKLEY_GROUP_MODP1536): 17211 usec
| DH shared secret:
|   4d e6 8b d7  a6 51 1e 09  89 95 d4 0e  71 c3 c9 7f
|   7a 1b c2 d4  cd ce 17 9c  b9 65 d6 42  38 49 3d 5a
|   9c 24 4b f8  0c 8b a7 2f  a6 0f b6 63  93 d1 06 e6
|   a6 e4 20 df  29 24 b1 57  55 e5 3c 0b  0a 48 7a 48
|   9d 4f 9f 46  07 1b 22 3d  2d e2 05 8f  50 b2 a3 22
|   3b c1 25 b6  dc 2f 6d a3  79 a7 ce 66  af ad ca 36
|   9f 3e 03 39  53 9d 38 18  d0 a9 a4 59  74 7f 11 16
|   71 86 de 79  4c 5f 85 bb  7a 28 57 fb  4d 6f 37 43
|   1b 99 aa 34  fe fa bb 84  52 10 54 d9  83 80 e8 ca
|   d6 d8 5c 6e  d5 5f 77 c9  e4 73 53 74  30 f9 4e 8e
|   ed 6d cf 6b  78 65 57 ef  a3 0d 8a 2a  b1 cb da 5b
|   91 9f 30 10  08 a8 ea 98  38 22 2f da  e1 87 f8 83
| skeyid inputs (digi+NI+NR+shared) hasher: oakley_md5
| shared:   4d e6 8b d7  a6 51 1e 09  89 95 d4 0e  71 c3 c9 7f
|   7a 1b c2 d4  cd ce 17 9c  b9 65 d6 42  38 49 3d 5a
|   9c 24 4b f8  0c 8b a7 2f  a6 0f b6 63  93 d1 06 e6
|   a6 e4 20 df  29 24 b1 57  55 e5 3c 0b  0a 48 7a 48
|   9d 4f 9f 46  07 1b 22 3d  2d e2 05 8f  50 b2 a3 22
|   3b c1 25 b6  dc 2f 6d a3  79 a7 ce 66  af ad ca 36
|   9f 3e 03 39  53 9d 38 18  d0 a9 a4 59  74 7f 11 16
|   71 86 de 79  4c 5f 85 bb  7a 28 57 fb  4d 6f 37 43
|   1b 99 aa 34  fe fa bb 84  52 10 54 d9  83 80 e8 ca
|   d6 d8 5c 6e  d5 5f 77 c9  e4 73 53 74  30 f9 4e 8e
|   ed 6d cf 6b  78 65 57 ef  a3 0d 8a 2a  b1 cb da 5b
|   91 9f 30 10  08 a8 ea 98  38 22 2f da  e1 87 f8 83
| ni:   b5 d0 71 ec  bc 8c 4e a2  ed 85 5b 22  7b 0e 42 14
| nr:   96 94 ce 8e  f1 5f 82 19  7c 08 f9 c4  96 f8 8c e3
| keyid:   19 f1 37 de  67 9f a8 67  40 1a d1 a0  56 a5 f0 df
| DH_i:  d8 ee 19 3e  b9 c7 d7 46  1e a0 af 4c  61 44 33 80
|   e7 b9 4d 8f  4a 04 01 8a  6d 86 73 1f  8e e0 98 56
|   23 a7 2c f0  06 e2 73 51  25 a4 cd cf  ee 9a 21 ae
|   54 83 f8 99  f4 dc bc 4b  ad d8 7f 9a  b7 c4 85 f7
|   96 8f 5d 2d  cf 3c 33 77  ac 05 e9 47  b3 3d 07 d2
|   3b 6f 9b df  d3 9b 72 a9  62 aa a5 86  f3 76 43 5f
|   00 b6 25 96  b2 3b 7b d0  e5 da ea 91  5a 7c 78 9b
|   e4 a4 13 71  10 bc e3 f1  38 59 e7 47  ef 22 ab 6a
|   31 e5 3b 62  d0 36 7a 91  f9 ac e1 85  1c fc f4 59
|   10 e9 33 78  76 5d c4 33  f0 b6 44 67  3c 78 3e d7
|   9d 35 a6 42  48 07 f9 e9  75 79 b8 55  d6 8c 7a 59
|   d9 3c 5f 04  01 d3 70 4d  e1 24 a0 e0  66 5b f4 e4
| DH_r:  93 85 3c 2b  eb 4c 93 25  f9 3f f2 51  89 17 5c f2
|   bc c6 8f 0a  d2 aa b2 39  d7 a3 80 34  ed c6 ab 41
|   c7 85 25 6c  d5 1b 38 bb  ee a4 06 e5  d6 71 a8 9d
|   c9 94 51 41  1c c4 80 c8  99 08 09 f7  aa 20 96 5a
|   16 ad ef 14  84 35 45 1b  45 42 8c 88  f7 5a 9a 7d
|   84 20 c3 be  0d 20 8d ec  7c a1 0e 11  9a 60 05 e0
|   a9 9a 57 99  be 13 dd 6f  76 1d 51 a6  55 96 e8 13
|   f2 a4 37 d8  42 7e 6b 04  bf a4 b8 54  39 6f 52 dc
|   2d 99 69 7d  67 93 5c 86  06 26 29 95  be a3 e5 bd
|   6d 30 27 5f  dd 75 89 0e  85 ab 41 ea  c2 95 89 a2
|   8f 52 f0 62  b6 9a 58 d0  2e bf 8a 0a  2a 56 1a 3b
|   d8 e9 b0 81  16 57 2a 3d  1e bc aa 0e  ad 0b 59 6b
| Skeyid:    19 f1 37 de  67 9f a8 67  40 1a d1 a0  56 a5 f0 df
| Skeyid_d:  70 eb f4 67  ae b0 74 42  37 b1 e5 ce  0a 3d c7 b8
| Skeyid_a:  99 2b e9 d2  2e ac 7f 27  6c d8 3e ee  47 97 24 be
| Skeyid_e:  a9 39 5a ca  25 e6 bb 07  26 c6 30 bd  1d 6e d7 38
| enc key:  77 4d 33 93  51 78 8a 5d  6d 34 6d 16  a4 9d 9a cd
|   ff e8 22 b2  18 05 1d 3d
| IV:  a7 00 4c 74  70 72 c6 9d  b9 ce 7b 44  3f 30 b8 dd
| complete state transition with STF_OK
"westnet-eastnet" #1: transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
| sending reply packet to 192.1.2.45:500 (from port=500)
| sending 244 bytes for STATE_MAIN_R1 through eth1:500 to 192.1.2.45:500:
| JACOB 2-2: resending 244 bytes for STATE_MAIN_R1 through eth1:500 to 192.1.2.45:500:
| inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
"westnet-eastnet" #1: STATE_MAIN_R2: sent MR2, expecting MI3
| modecfg pull: noquirk policy:push not-client
| phase 1 is done, looking for phase 1 to unpend
| next event EVENT_RETRANSMIT in 9 seconds for #2
|  
| *received 244 bytes from 192.1.2.45:500 on eth1 (port=500)
| ICOOKIE:  57 7e 39 e6  d5 b0 99 72
| RCOOKIE:  5d 0b 5b 27  07 43 62 f7
| peer:  c0 01 02 2d
| state hash entry 27
| peer and cookies match on #1, provided msgid 00000000 vs 00000000
| state object #1 found, in STATE_MAIN_R2
| processing connection westnet-eastnet
"westnet-eastnet" #1: discarding duplicate packet; already STATE_MAIN_R2
| next event EVENT_RETRANSMIT in 9 seconds for #2
|  
| *received 300 bytes from 192.1.2.45:500 on eth1 (port=500)
| ICOOKIE:  57 7e 39 e6  d5 b0 99 72
| RCOOKIE:  5d 0b 5b 27  07 43 62 f7
| peer:  c0 01 02 2d
| state hash entry 27
| peer and cookies match on #1, provided msgid 00000000 vs 00000000
| state object #1 found, in STATE_MAIN_R2
| processing connection westnet-eastnet
| received encrypted packet from 192.1.2.45:500
| decrypting 272 bytes using algorithm OAKLEY_3DES_CBC
| decrypted:
|   09 00 00 0c  02 00 00 00  77 65 73 74  00 00 01 04
|   72 db 06 e6  22 7a 21 dd  4d a9 03 c6  a8 d0 3d d7
|   57 b1 7d f4  08 b7 a4 61  e4 e4 6a ad  be 3a 10 17
|   65 07 ef 1c  13 f1 2b a5  d1 bd 3d b9  e7 b1 e0 f4
|   fe 6a 36 58  8d 75 ee 59  2f fa 4d 39  36 38 40 87
|   11 3e 47 9b  51 50 a5 24  48 ed ac 56  44 17 3a 46
|   bf 13 de b8  00 db a0 1c  22 3e 29 f3  87 f0 eb 68
|   a8 bb 36 06  7e 02 f3 c7  8b ac dd 7e  79 b8 34 db
|   d9 73 b3 fe  9d 9a 2e e3  4a 65 60 37  ed 6d 20 eb
|   b6 9e 8d ac  ba 9c 09 fa  6b bb b8 62  3d bd 81 1d
|   ef d3 29 bc  09 a2 eb ee  2b b6 b4 e2  3a b1 f8 16
|   5b cf 7f b8  d9 52 74 11  21 9f 0c 3d  d9 29 dc 37
|   bf b5 1a 25  0b 96 12 42  6d 1f b3 c0  d9 9f a5 7f
|   9d 3e 86 09  5f a1 55 40  d2 7a 85 65  8c 21 71 f6
|   98 e6 fb 54  8e 96 37 f9  39 22 b9 86  13 38 3e ee
|   c0 39 50 fe  b8 f2 bd d7  9a 14 8b ee  89 32 4e fa
|   ec 03 90 2f  06 d1 4a e3  32 0e 7d 20  70 b2 61 4f
| next IV:  40 3a 3e b8  50 87 28 1a
"westnet-eastnet" #1: Main mode peer ID is ID_FQDN: '@west'
| refine_connection: starting with westnet-eastnet
|   trusted_ca called with a=(empty) b=(empty)
| refine_connection: happy with starting point: westnet-eastnet
| offered CA: '%none'
| hashing 144 bytes of SA
| required CA is '%any'
|   trusted_ca called with a=(empty) b=(empty)
| key issuer CA is '%any'
| an RSA Sig check passed with *AQNzGEFs1 [preloaded key]
| authentication succeeded
| thinking about whether to send my certificate:
|   I have RSA key: OAKLEY_RSA_SIG cert.type: CERT_NONE 
|   sendcert: CERT_ALWAYSSEND and I did not get a certificate request 
|   so do not send cert.
"westnet-eastnet" #1: I did not send a certificate because I do not have one.
| hashing 144 bytes of SA
| started looking for secret for @east->@west of kind PPK_RSA
| actually looking for secret for @east->@west of kind PPK_RSA
| 1: compared PSK 0.0.0.0 to @east / @west -> 0
| 2: compared PSK C=CA, ST=Ontario, O=Libreswan, CN=east.uml.freeswan.org, E=east@libreswan.org to @east / @west -> 0
| best_match 0>1 best=0x8104b58 (line=8)
| concluding with best_match=1 best=0x8104b58 (lineno=8)
| signing hash with RSA Key *AQN3cn11F
| encrypting:
|   09 00 00 0c  02 00 00 00  65 61 73 74  00 00 01 04
|   64 45 26 c3  49 dc 4c b1  2e b7 f8 d0  29 41 4d de
|   2a a3 a2 ad  c2 42 fb 88  15 89 18 cd  c5 c4 8f c1
|   4c 36 d0 70  a9 43 67 37  da fd 12 12  3a 7a 5a df
|   36 ba ef 81  4b 0d 14 60  d5 64 ef 85  cc 3e 8c a7
|   65 e5 cb c8  d5 77 a8 1d  4f b8 e2 0e  32 13 e8 23
|   15 f7 60 18  c1 3e f1 d5  0c 7a a7 24  4d 3e eb 5f
|   02 70 53 c0  fa 43 13 ab  fa 6f a0 28  05 39 0b 4b
|   fb 9b 3b 09  7a 94 b7 9d  06 9a 15 ee  b3 e8 bd f0
|   85 36 1b 1d  e6 cf 3e 8d  16 e0 37 ac  9e b5 09 74
|   6c 83 14 3a  f2 07 1e 24  31 3c 9e 38  fb 45 01 fd
|   59 c0 3a 9f  6c 74 36 01  2e 5a f8 fa  05 ce 1e ce
|   e5 9a ee 69  66 8c cf 57  b7 bf 24 ee  76 8c 7f 60
|   53 3e 7c ad  63 df cf ca  0a c9 82 c6  d1 b9 bb d5
|   40 77 88 f8  da 64 47 e1  41 ae 44 71  4e 88 f7 d4
|   b4 c1 d6 f4  ba f2 be 01  fe 25 a2 5a  ac c2 6d 46
|   16 66 2f 38  e5 14 89 71  bd 3f 3c 0b  29 66 c0 6c
| IV:
|   40 3a 3e b8  50 87 28 1a
| encrypting using OAKLEY_3DES_CBC
| next IV:  ec e5 58 f4  6a 06 70 49
| last encrypted block of Phase 1:
|   ec e5 58 f4  6a 06 70 49
| complete state transition with STF_OK
"westnet-eastnet" #1: transition from state STATE_MAIN_R2 to state STATE_MAIN_R3
| sending reply packet to 192.1.2.45:500 (from port=500)
| sending 300 bytes for STATE_MAIN_R2 through eth1:500 to 192.1.2.45:500:
| JACOB 2-2: resending 300 bytes for STATE_MAIN_R2 through eth1:500 to 192.1.2.45:500:
| inserting event EVENT_SA_REPLACE, timeout in 3330 seconds for #1
"westnet-eastnet" #1: STATE_MAIN_R3: sent MR3, ISAKMP SA established {auth=OAKLEY_RSA_SIG cipher=oakley_3des_cbc_192 prf=oakley_md5 group=modp1536}
| modecfg pull: noquirk policy:push not-client
| phase 1 is done, looking for phase 1 to unpend
| next event EVENT_RETRANSMIT in 9 seconds for #2
|  
| *received 300 bytes from 192.1.2.45:500 on eth1 (port=500)
| ICOOKIE:  57 7e 39 e6  d5 b0 99 72
| RCOOKIE:  5d 0b 5b 27  07 43 62 f7
| peer:  c0 01 02 2d
| state hash entry 27
| peer and cookies match on #1, provided msgid 00000000 vs 00000000
| state object #1 found, in STATE_MAIN_R3
| processing connection westnet-eastnet
"westnet-eastnet" #1: retransmitting in response to duplicate packet; already STATE_MAIN_R3
| sending 300 bytes for retransmit in response to duplicate through eth1:500 to 192.1.2.45:500:
| JACOB 2-2: resending 300 bytes for retransmit in response to duplicate through eth1:500 to 192.1.2.45:500:
| next event EVENT_RETRANSMIT in 8 seconds for #2
|  
| *received 348 bytes from 192.1.2.45:500 on eth1 (port=500)
| ICOOKIE:  57 7e 39 e6  d5 b0 99 72
| RCOOKIE:  5d 0b 5b 27  07 43 62 f7
| peer:  c0 01 02 2d
| state hash entry 27
| peer and cookies match on #1, provided msgid bb47fe55 vs 00000000
| state object not found
| ICOOKIE:  57 7e 39 e6  d5 b0 99 72
| RCOOKIE:  5d 0b 5b 27  07 43 62 f7
| peer:  c0 01 02 2d
| state hash entry 27
| peer and cookies match on #1, provided msgid 00000000 vs 00000000
| state object #1 found, in STATE_MAIN_R3
| processing connection westnet-eastnet
| last Phase 1 IV:  ec e5 58 f4  6a 06 70 49
| current Phase 1 IV:  ec e5 58 f4  6a 06 70 49
| computed Phase 2 IV:
|   82 ad 05 3b  03 50 bd f0  fe 2c a6 0a  2e e2 77 6d
| received encrypted packet from 192.1.2.45:500
| decrypting 320 bytes using algorithm OAKLEY_3DES_CBC
| decrypted:
|   01 00 00 14  4c fb e5 79  a1 4e 1b 60  d3 74 1b 00
|   91 0f 94 67  0a 00 00 34  00 00 00 01  00 00 00 01
|   00 00 00 28  00 03 04 01  c1 28 c9 1a  00 00 00 1c
|   00 03 00 00  80 03 00 05  80 04 00 01  80 01 00 01
|   80 02 70 80  80 05 00 01  04 00 00 14  05 9e 59 13
|   c1 f3 c6 d3  6f 9a 7b 7b  c4 67 e7 fc  05 00 00 c4
|   d5 67 df 99  f5 a5 bd 30  51 2b c6 cf  91 77 be ac
|   e2 57 34 b6  e4 f3 2e af  65 43 b6 68  4a 08 10 14
|   c0 8d 33 8f  b3 1b c7 90  c2 02 b5 26  f8 98 79 d8
|   fe 78 5e b2  5c a6 5c c5  7e 3f 02 c2  1d 59 0f ae
|   0f ad bc e7  f2 c8 67 c1  24 3c 1c 3b  fb c5 82 e2
|   59 94 8f a5  ef 53 fb a2  06 1f 98 ed  a0 07 45 ee
|   ea 99 1d 55  88 35 d9 1b  13 ea 21 64  8d 27 dd e6
|   c0 89 ee 96  bb a2 d5 bf  04 86 02 a3  25 24 10 bb
|   ba 31 2e 1e  af 70 ed 0e  8c 69 76 73  80 f7 e4 04
|   f8 1f 09 8e  03 2a 0f 67  ac 9a 65 0f  f0 b4 5c b4
|   6f 7d e0 86  cb b2 bc a4  8b a9 43 a8  f6 a2 b5 04
|   99 30 79 c3  08 fd ea 44  af 94 2e 93  55 5b ef e6
|   05 00 00 10  04 00 00 00  c0 00 01 00  ff ff ff 00
|   00 00 00 10  04 00 00 00  c0 00 02 00  ff ff ff 00
| next IV:  61 ca 4b ce  5f 4b d9 64
| HASH(1) computed:
|   4c fb e5 79  a1 4e 1b 60  d3 74 1b 00  91 0f 94 67
| peer client is subnet 192.0.1.0/24
| peer client protocol/port is 0/0
| our client is subnet 192.0.2.0/24
| our client protocol/port is 0/0
| find_client_connection starting with westnet-eastnet
|   looking for 192.0.2.0/24:0/0 -> 192.0.1.0/24:0/0
|   concrete checking against sr#0 192.0.2.0/24 -> 192.0.1.0/24
|    match_id a=@west
|             b=@west
|    results  matched
|   trusted_ca called with a=(empty) b=(empty)
|   fc_try trying westnet-eastnet:192.0.2.0/24:0/0 -> 192.0.1.0/24:0/0 vs westnet-eastnet:192.0.2.0/24:0/0 -> 192.0.1.0/24:0/0
|   fc_try concluding with westnet-eastnet [128]
|   fc_try westnet-eastnet gives westnet-eastnet
|   concluding with d = westnet-eastnet
| duplicating state object #1
| creating state object #3 at 0x8107740
| processing connection westnet-eastnet
| ICOOKIE:  57 7e 39 e6  d5 b0 99 72
| RCOOKIE:  5d 0b 5b 27  07 43 62 f7
| peer:  c0 01 02 2d
| state hash entry 27
| inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #3
| DH public value received:
|   d5 67 df 99  f5 a5 bd 30  51 2b c6 cf  91 77 be ac
|   e2 57 34 b6  e4 f3 2e af  65 43 b6 68  4a 08 10 14
|   c0 8d 33 8f  b3 1b c7 90  c2 02 b5 26  f8 98 79 d8
|   fe 78 5e b2  5c a6 5c c5  7e 3f 02 c2  1d 59 0f ae
|   0f ad bc e7  f2 c8 67 c1  24 3c 1c 3b  fb c5 82 e2
|   59 94 8f a5  ef 53 fb a2  06 1f 98 ed  a0 07 45 ee
|   ea 99 1d 55  88 35 d9 1b  13 ea 21 64  8d 27 dd e6
|   c0 89 ee 96  bb a2 d5 bf  04 86 02 a3  25 24 10 bb
|   ba 31 2e 1e  af 70 ed 0e  8c 69 76 73  80 f7 e4 04
|   f8 1f 09 8e  03 2a 0f 67  ac 9a 65 0f  f0 b4 5c b4
|   6f 7d e0 86  cb b2 bc a4  8b a9 43 a8  f6 a2 b5 04
|   99 30 79 c3  08 fd ea 44  af 94 2e 93  55 5b ef e6
| 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1
| asking helper 0 to do build_kenonce op on seq: 2
| inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #3
| complete state transition with STF_SUSPEND
| next event EVENT_RETRANSMIT in 8 seconds for #2
|  
| *received 348 bytes from 192.1.2.45:500 on eth1 (port=500)
| ICOOKIE:  57 7e 39 e6  d5 b0 99 72
| RCOOKIE:  5d 0b 5b 27  07 43 62 f7
| peer:  c0 01 02 2d
| state hash entry 27
| peer and cookies match on #3, provided msgid bb47fe55 vs bb47fe55
| state object #3 found, in STATE_QUICK_R0
| processing connection westnet-eastnet
"westnet-eastnet" #3: message received while calculating. Ignored.
| next event EVENT_RETRANSMIT in 8 seconds for #2
| helper 0 has work (cnt now 0)
| helper 0 replies to sequence 2
| calling callback function 0x806e860
| quick inI1_outR1: calculated ke+nonce, sending R1
| processing connection westnet-eastnet
| generate SPI:  32 93 b5 10
"westnet-eastnet" #3: responding to Quick Mode {msgid:55fe47bb}
| started looking for secret for @east->@west of kind PPK_PSK
| actually looking for secret for @east->@west of kind PPK_PSK
| concluding with best_match=0 best=(nil) (lineno=-1)
| calc_dh_shared(): time elapsed (OAKLEY_GROUP_MODP1536): 60219 usec
| DH shared secret:
|   33 f5 52 e2  c5 b2 9c ea  20 e4 4a 9c  04 35 34 93
|   e4 3f 6d cf  18 25 19 c6  f1 60 0a a9  21 54 7b 95
|   bd e5 24 de  25 6a 56 2c  7b 47 2e 71  be 8d 85 0e
|   ea e3 92 8e  9c cf c3 cc  2a 00 76 d4  d7 d7 6d 06
|   14 13 74 7b  6e 45 34 3c  a3 38 f6 6a  58 b7 43 f7
|   e9 a1 98 94  a8 ef 65 1b  a5 65 ff 25  ba ec 0d fd
|   b5 0d 5d 10  bb 54 df d8  f6 a2 bd 02  a1 63 1c e7
|   5c 3f fb 06  c9 2d 1c 41  44 a6 32 4c  60 f3 f2 b6
|   3e 1c 96 14  79 82 d2 d7  d0 54 43 ee  e4 73 4d 36
|   af 08 57 6e  73 bf 29 b5  b4 c2 1f 5a  c9 db 2d 41
|   a9 2a 7e 5c  0c 0e 01 6c  7b c7 20 06  f3 ea 72 89
|   ef b7 7b d3  af d9 60 cd  8b 46 b0 09  18 ae 2b af
| HASH(2) computed:
|   25 cb 3b 12  91 01 ce e5  20 82 54 d8  4a 9a 9f b1
| KEYMAT computed:
|   87 33 9d ae  d9 f3 0d 88  a8 36 fa 91  b0 c7 02 d7
|   01 f7 86 94  d6 00 67 7c  d9 b1 aa 93  91 20 26 ce
|   e3 ff d2 fc  b2 84 18 7f
| Peer KEYMAT computed:
|   24 6e b5 b8  73 27 80 f9  3b 62 fd 46  5c ef 4a 80
|   b6 2f a9 68  2e 3c 56 34  60 7d 0c bb  4b 40 9e 54
|   d5 33 73 33  e7 d9 fb 0d
| route owner of "westnet-eastnet" unrouted: NULL
| install_inbound_ipsec_sa() checking if we can route
| route owner of "westnet-eastnet" unrouted: NULL; eroute owner: NULL
| Jacob two two says that the SA will fail
| complete state transition with STF_INTERNAL_ERROR
| state transition function for STATE_QUICK_R0 had internal error
| next event EVENT_RETRANSMIT in 8 seconds for #2
|  
| *time to handle event
| handling event EVENT_RETRANSMIT
| event after this is EVENT_SHUNT_SCAN in 109 seconds
| processing connection westnet-eastnet
| handling event EVENT_RETRANSMIT for 192.1.2.45 "westnet-eastnet" #2
| sending 116 bytes for EVENT_RETRANSMIT through eth1:500 to 192.1.2.45:500:
| JACOB 2-2: resending 116 bytes for EVENT_RETRANSMIT through eth1:500 to 192.1.2.45:500:
| inserting event EVENT_RETRANSMIT, timeout in 20 seconds for #2
| next event EVENT_RETRANSMIT in 20 seconds for #2
|  
| *received 348 bytes from 192.1.2.45:500 on eth1 (port=500)
| ICOOKIE:  57 7e 39 e6  d5 b0 99 72
| RCOOKIE:  5d 0b 5b 27  07 43 62 f7
| peer:  c0 01 02 2d
| state hash entry 27
| peer and cookies match on #3, provided msgid bb47fe55 vs bb47fe55
| state object #3 found, in STATE_QUICK_R0
| processing connection westnet-eastnet
| received encrypted packet from 192.1.2.45:500
| decrypting 320 bytes using algorithm OAKLEY_3DES_CBC
| last Phase 1 IV:
| current Phase 1 IV:
| computed Phase 2 IV:
|   a8 76 81 53  73 2b 6d ff  13 68 d0 74  d7 a3 16 f2
| decrypted:
|   2b db 84 7c  3c 80 35 76  a1 4e 1b 60  d3 74 1b 00
|   91 0f 94 67  0a 00 00 34  00 00 00 01  00 00 00 01
|   00 00 00 28  00 03 04 01  c1 28 c9 1a  00 00 00 1c
|   00 03 00 00  80 03 00 05  80 04 00 01  80 01 00 01
|   80 02 70 80  80 05 00 01  04 00 00 14  05 9e 59 13
|   c1 f3 c6 d3  6f 9a 7b 7b  c4 67 e7 fc  05 00 00 c4
|   d5 67 df 99  f5 a5 bd 30  51 2b c6 cf  91 77 be ac
|   e2 57 34 b6  e4 f3 2e af  65 43 b6 68  4a 08 10 14
|   c0 8d 33 8f  b3 1b c7 90  c2 02 b5 26  f8 98 79 d8
|   fe 78 5e b2  5c a6 5c c5  7e 3f 02 c2  1d 59 0f ae
|   0f ad bc e7  f2 c8 67 c1  24 3c 1c 3b  fb c5 82 e2
|   59 94 8f a5  ef 53 fb a2  06 1f 98 ed  a0 07 45 ee
|   ea 99 1d 55  88 35 d9 1b  13 ea 21 64  8d 27 dd e6
|   c0 89 ee 96  bb a2 d5 bf  04 86 02 a3  25 24 10 bb
|   ba 31 2e 1e  af 70 ed 0e  8c 69 76 73  80 f7 e4 04
|   f8 1f 09 8e  03 2a 0f 67  ac 9a 65 0f  f0 b4 5c b4
|   6f 7d e0 86  cb b2 bc a4  8b a9 43 a8  f6 a2 b5 04
|   99 30 79 c3  08 fd ea 44  af 94 2e 93  55 5b ef e6
|   05 00 00 10  04 00 00 00  c0 00 01 00  ff ff ff 00
|   00 00 00 10  04 00 00 00  c0 00 02 00  ff ff ff 00
| next IV:  61 ca 4b ce  5f 4b d9 64
"westnet-eastnet" #3: next payload type of ISAKMP Hash Payload has an unknown value: 43
"westnet-eastnet" #3: malformed payload in packet
"westnet-eastnet" #3: sending notification PAYLOAD_MALFORMED to 192.1.2.45:500
| sending 40 bytes for notification packet through eth1:500 to 192.1.2.45:500:
| JACOB 2-2: resending 40 bytes for notification packet through eth1:500 to 192.1.2.45:500:
| next event EVENT_RETRANSMIT in 20 seconds for #2
|  
| *received 348 bytes from 192.1.2.45:500 on eth1 (port=500)
| ICOOKIE:  57 7e 39 e6  d5 b0 99 72
| RCOOKIE:  5d 0b 5b 27  07 43 62 f7
| peer:  c0 01 02 2d
| state hash entry 27
| peer and cookies match on #3, provided msgid bb47fe55 vs bb47fe55
| state object #3 found, in STATE_QUICK_R0
| processing connection westnet-eastnet
| received encrypted packet from 192.1.2.45:500
| decrypting 320 bytes using algorithm OAKLEY_3DES_CBC
| last Phase 1 IV:
| current Phase 1 IV:
| computed Phase 2 IV:
|   a8 76 81 53  73 2b 6d ff  13 68 d0 74  d7 a3 16 f2
| decrypted:
|   2b db 84 7c  3c 80 35 76  a1 4e 1b 60  d3 74 1b 00
|   91 0f 94 67  0a 00 00 34  00 00 00 01  00 00 00 01
|   00 00 00 28  00 03 04 01  c1 28 c9 1a  00 00 00 1c
|   00 03 00 00  80 03 00 05  80 04 00 01  80 01 00 01
|   80 02 70 80  80 05 00 01  04 00 00 14  05 9e 59 13
|   c1 f3 c6 d3  6f 9a 7b 7b  c4 67 e7 fc  05 00 00 c4
|   d5 67 df 99  f5 a5 bd 30  51 2b c6 cf  91 77 be ac
|   e2 57 34 b6  e4 f3 2e af  65 43 b6 68  4a 08 10 14
|   c0 8d 33 8f  b3 1b c7 90  c2 02 b5 26  f8 98 79 d8
|   fe 78 5e b2  5c a6 5c c5  7e 3f 02 c2  1d 59 0f ae
|   0f ad bc e7  f2 c8 67 c1  24 3c 1c 3b  fb c5 82 e2
|   59 94 8f a5  ef 53 fb a2  06 1f 98 ed  a0 07 45 ee
|   ea 99 1d 55  88 35 d9 1b  13 ea 21 64  8d 27 dd e6
|   c0 89 ee 96  bb a2 d5 bf  04 86 02 a3  25 24 10 bb
|   ba 31 2e 1e  af 70 ed 0e  8c 69 76 73  80 f7 e4 04
|   f8 1f 09 8e  03 2a 0f 67  ac 9a 65 0f  f0 b4 5c b4
|   6f 7d e0 86  cb b2 bc a4  8b a9 43 a8  f6 a2 b5 04
|   99 30 79 c3  08 fd ea 44  af 94 2e 93  55 5b ef e6
|   05 00 00 10  04 00 00 00  c0 00 01 00  ff ff ff 00
|   00 00 00 10  04 00 00 00  c0 00 02 00  ff ff ff 00
| next IV:  61 ca 4b ce  5f 4b d9 64
"westnet-eastnet" #3: next payload type of ISAKMP Hash Payload has an unknown value: 43
"westnet-eastnet" #3: malformed payload in packet
| next event EVENT_RETRANSMIT in 20 seconds for #2
