[Openswan Users] Road Warrior behind NAT - Aggressive Mode: wrong NAT-T decision

[hiren joshi]

Many thanks for your reply.

> Did you enable forceecaps?
No.

> Looks like it might be a mixup of connections. can you upgrade to
The debug output I am sending is taken with only one connection defined.

> Looks like it might be a mixup of connections. can you upgrade to
> 2.4.12 and see if the problem persists. If it does, provide a link
> with plutodebug=all output?
I am attaching debug logs taken with 2.4.8 as currently I am not able
to switch to 2.4.12 :-(

Thanks again.

------------------------------------- plutodebug=all output
----------------------------------
Jun 27 18:11:50 1214570510 pluto[4537]: | *received 324 bytes from
172.16.1.151:500 on eth1 (port=500)
Jun 27 18:11:50 1214570510 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
00 00 00 00  00 00 00 00
Jun 27 18:11:50 1214570510 pluto[4537]: |   01 10 04 00  00 00 00 00
00 00 01 44  0d 00 00 34
Jun 27 18:11:50 1214570510 pluto[4537]: |   00 00 00 01  00 00 00 01
00 00 00 28  01 01 00 01
Jun 27 18:11:50 1214570510 pluto[4537]: |   00 00 00 20  00 01 00 00
80 01 00 05  80 02 00 01
Jun 27 18:11:50 1214570510 pluto[4537]: |   80 03 00 01  80 04 00 02
80 0b 00 01  80 0c 0e 10
Jun 27 18:11:50 1214570510 pluto[4537]: |   0d 00 00 14  44 85 15 2d
18 b6 bb cd  0b e8 a8 46
Jun 27 18:11:50 1214570510 pluto[4537]: |   95 79 dd cc  0d 00 00 14
90 cb 80 91  3e bb 69 6e
Jun 27 18:11:50 1214570510 pluto[4537]: |   08 63 81 b5  ec 42 7b 1f
0d 00 00 14  7d 94 19 a6
Jun 27 18:11:50 1214570510 pluto[4537]: |   53 10 ca 6f  2c 17 9d 92
15 52 9d 56  04 00 00 14
Jun 27 18:11:50 1214570510 pluto[4537]: |   af ca d7 13  68 a1 f1 c9
6b 86 96 fc  77 57 01 00
Jun 27 18:11:50 1214570510 pluto[4537]: |   0a 00 00 84  19 7c 50 02
e1 64 51 37  1a dd 1d d0
Jun 27 18:11:50 1214570510 pluto[4537]: |   cc 4d 4d c3  65 7a 9a d6
7f fc ad f1  66 a9 91 e3
Jun 27 18:11:50 1214570510 pluto[4537]: |   66 3b f6 96  05 7b ee 7c
6f 21 a0 b9  d3 0f 5e 02
Jun 27 18:11:50 1214570510 pluto[4537]: |   72 92 6e 0f  15 ce db 24
78 3c df a9  87 09 b9 b8
Jun 27 18:11:50 1214570510 pluto[4537]: |   ae 88 0a fa  d9 a1 a0 77
fb cc fa c5  f7 8b 7b 88
Jun 27 18:11:50 1214570510 pluto[4537]: |   ed da 16 f6  59 25 52 23
bc 61 f1 7b  d9 dd e4 74
Jun 27 18:11:50 1214570510 pluto[4537]: |   d5 a9 e8 24  ab fc 3f 4a
8a b3 63 c2  54 c7 23 78
Jun 27 18:11:50 1214570510 pluto[4537]: |   02 1f 3f d6  f3 48 6c 42
83 4f b7 13  95 51 90 68
Jun 27 18:11:50 1214570510 pluto[4537]: |   7b 30 07 ee  05 00 00 14
26 22 15 85  40 90 ca e1
Jun 27 18:11:50 1214570510 pluto[4537]: |   c7 d5 b0 1f  f9 37 27 53
00 00 00 0c  01 00 00 00
Jun 27 18:11:50 1214570510 pluto[4537]: |   00 00 00 00
Jun 27 18:11:50 1214570510 pluto[4537]: | **parse ISAKMP Message:
Jun 27 18:11:50 1214570510 pluto[4537]: |    initiator cookie:
Jun 27 18:11:50 1214570510 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
Jun 27 18:11:50 1214570510 pluto[4537]: |    responder cookie:
Jun 27 18:11:50 1214570510 pluto[4537]: |   00 00 00 00  00 00 00 00
Jun 27 18:11:50 1214570510 pluto[4537]: |    next payload type: ISAKMP_NEXT_SA
Jun 27 18:11:50 1214570510 pluto[4537]: |    ISAKMP version: ISAKMP Version 1.0
Jun 27 18:11:50 1214570510 pluto[4537]: |    exchange type: ISAKMP_XCHG_AGGR
Jun 27 18:11:50 1214570510 pluto[4537]: |    flags: none
Jun 27 18:11:50 1214570510 pluto[4537]: |    message ID:  00 00 00 00
Jun 27 18:11:50 1214570510 pluto[4537]: |    length: 324
Jun 27 18:11:50 1214570510 pluto[4537]: |  processing packet with
exchange type=ISAKMP_XCHG_AGGR (4)
Jun 27 18:11:50 1214570510 pluto[4537]: | ***parse ISAKMP Security
Association Payload:
Jun 27 18:11:50 1214570510 pluto[4537]: |    next payload type: ISAKMP_NEXT_VID
Jun 27 18:11:50 1214570510 pluto[4537]: |    length: 52
Jun 27 18:11:50 1214570510 pluto[4537]: |    DOI: ISAKMP_DOI_IPSEC
Jun 27 18:11:50 1214570510 pluto[4537]: | ***parse ISAKMP Vendor ID Payload:
Jun 27 18:11:50 1214570510 pluto[4537]: |    next payload type: ISAKMP_NEXT_VID
Jun 27 18:11:50 1214570510 pluto[4537]: |    length: 20
Jun 27 18:11:50 1214570510 pluto[4537]: | ***parse ISAKMP Vendor ID Payload:
Jun 27 18:11:50 1214570510 pluto[4537]: |    next payload type: ISAKMP_NEXT_VID
Jun 27 18:11:50 1214570510 pluto[4537]: |    length: 20
Jun 27 18:11:50 1214570510 pluto[4537]: | ***parse ISAKMP Vendor ID Payload:
Jun 27 18:11:50 1214570510 pluto[4537]: |    next payload type: ISAKMP_NEXT_VID
Jun 27 18:11:50 1214570510 pluto[4537]: |    length: 20
Jun 27 18:11:50 1214570510 pluto[4537]: | ***parse ISAKMP Vendor ID Payload:
Jun 27 18:11:50 1214570510 pluto[4537]: |    next payload type: ISAKMP_NEXT_KE
Jun 27 18:11:50 1214570510 pluto[4537]: |    length: 20
Jun 27 18:11:50 1214570510 pluto[4537]: | ***parse ISAKMP Key Exchange Payload:
Jun 27 18:11:50 1214570510 pluto[4537]: |    next payload type:
ISAKMP_NEXT_NONCE
Jun 27 18:11:50 1214570510 pluto[4537]: |    length: 132
Jun 27 18:11:50 1214570510 pluto[4537]: | ***parse ISAKMP Nonce Payload:
Jun 27 18:11:50 1214570510 pluto[4537]: |    next payload type: ISAKMP_NEXT_ID
Jun 27 18:11:50 1214570510 pluto[4537]: |    length: 20
Jun 27 18:11:50 1214570510 pluto[4537]: | ***parse ISAKMP
Identification Payload:
Jun 27 18:11:50 1214570510 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:11:50 1214570510 pluto[4537]: |    length: 12
Jun 27 18:11:50 1214570510 pluto[4537]: |    ID type: ID_IPV4_ADDR
Jun 27 18:11:50 1214570510 pluto[4537]: |    DOI specific A: 0
Jun 27 18:11:50 1214570510 pluto[4537]: |    DOI specific B: 0
Jun 27 18:11:50 1214570510 pluto[4537]: packet from 172.16.1.151:500:
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-00]
Jun 27 18:11:50 1214570510 pluto[4537]: packet from 172.16.1.151:500:
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n] method
set to=106
Jun 27 18:11:50 1214570510 pluto[4537]: packet from 172.16.1.151:500:
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-03] method set
to=108
Jun 27 18:11:50 1214570510 pluto[4537]: packet from 172.16.1.151:500:
received Vendor ID payload [Dead Peer Detection]
Jun 27 18:11:50 1214570510 pluto[4537]: | find_host_connection called
from aggr_inI1_outR1_common
Jun 27 18:11:50 1214570510 pluto[4537]: | find_host_pair: comparing to
172.16.2.115:500 172.16.1.151:500
Jun 27 18:11:50 1214570510 pluto[4537]: | find_host_pair_conn
(find_host_connection2): 172.16.2.115:500 172.16.1.151:500 -> hp:rw-1
Jun 27 18:11:50 1214570510 pluto[4537]: | creating state object #77 at 0x810d250
Jun 27 18:11:50 1214570510 pluto[4537]: "rw-1"[4] 172.16.1.151 #77:
Aggressive mode peer ID is ID_IPV4_ADDR: '0.0.0.0'
Jun 27 18:11:50 1214570510 pluto[4537]: | refine_connection: starting with rw-1
Jun 27 18:11:50 1214570510 pluto[4537]: |   trusted_ca called with
a=(empty) b=(empty)
Jun 27 18:11:50 1214570510 pluto[4537]: | refine_connection: happy
with starting point: rw-1
Jun 27 18:11:50 1214570510 pluto[4537]: | offered CA: '%none'
Jun 27 18:11:50 1214570510 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:11:50 1214570510 pluto[4537]: | ICOOKIE:  c0 ba 41 b2  8e 08 66 93
Jun 27 18:11:50 1214570510 pluto[4537]: | RCOOKIE:  d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:50 1214570510 pluto[4537]: | peer:  ac 10 01 97
Jun 27 18:11:50 1214570510 pluto[4537]: | state hash entry 18
Jun 27 18:11:50 1214570510 pluto[4537]: | inserting event
EVENT_SO_DISCARD, timeout in 0 seconds for #77
Jun 27 18:11:50 1214570510 pluto[4537]: "rw-1"[4] 172.16.1.151 #77:
responding to Aggressive Mode, state #77, connection "rw-1" from
172.16.1.151
Jun 27 18:11:50 1214570510 pluto[4537]: | ****parse IPsec DOI SIT:
Jun 27 18:11:50 1214570510 pluto[4537]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Jun 27 18:11:50 1214570510 pluto[4537]: | ****parse ISAKMP Proposal Payload:
Jun 27 18:11:50 1214570510 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:11:50 1214570510 pluto[4537]: |    length: 40
Jun 27 18:11:50 1214570510 pluto[4537]: |    proposal number: 1
Jun 27 18:11:50 1214570510 pluto[4537]: |    protocol ID: PROTO_ISAKMP
Jun 27 18:11:50 1214570510 pluto[4537]: |    SPI size: 0
Jun 27 18:11:50 1214570510 pluto[4537]: |    number of transforms: 1
Jun 27 18:11:50 1214570510 pluto[4537]: | *****parse ISAKMP Transform
Payload (ISAKMP):
Jun 27 18:11:50 1214570510 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:11:50 1214570510 pluto[4537]: |    length: 32
Jun 27 18:11:50 1214570510 pluto[4537]: |    transform number: 0
Jun 27 18:11:50 1214570510 pluto[4537]: |    transform ID: KEY_IKE
Jun 27 18:11:50 1214570510 pluto[4537]: | ******parse ISAKMP Oakley attribute:
Jun 27 18:11:50 1214570510 pluto[4537]: |    af+type:
OAKLEY_ENCRYPTION_ALGORITHM
Jun 27 18:11:50 1214570510 pluto[4537]: |    length/value: 5
Jun 27 18:11:50 1214570510 pluto[4537]: |    [5 is OAKLEY_3DES_CBC]
Jun 27 18:11:50 1214570510 pluto[4537]: |
ike_alg_enc_ok(ealg=5,key_len=0): blocksize=8, keyminlen=192,
keydeflen=192, keymaxlen=192, ret=1
Jun 27 18:11:50 1214570510 pluto[4537]: | ******parse ISAKMP Oakley attribute:
Jun 27 18:11:50 1214570510 pluto[4537]: |    af+type: OAKLEY_HASH_ALGORITHM
Jun 27 18:11:50 1214570510 pluto[4537]: |    length/value: 1
Jun 27 18:11:50 1214570510 pluto[4537]: |    [1 is OAKLEY_MD5]
Jun 27 18:11:50 1214570510 pluto[4537]: | ******parse ISAKMP Oakley attribute:
Jun 27 18:11:50 1214570510 pluto[4537]: |    af+type:
OAKLEY_AUTHENTICATION_METHOD
Jun 27 18:11:50 1214570510 pluto[4537]: |    length/value: 1
Jun 27 18:11:50 1214570510 pluto[4537]: |    [1 is OAKLEY_PRESHARED_KEY]
Jun 27 18:11:50 1214570510 pluto[4537]: | started looking for secret
for 172.16.2.115->0.0.0.0 of kind PPK_PSK
Jun 27 18:11:50 1214570510 pluto[4537]: | replace him to 0.0.0.0
Jun 27 18:11:50 1214570510 pluto[4537]: | actually looking for secret
for 172.16.2.115->0.0.0.0 of kind PPK_PSK
Jun 27 18:11:50 1214570510 pluto[4537]: | 1: compared PSK 0.0.0.0 to
172.16.2.115 / 0.0.0.0 -> 2
Jun 27 18:11:50 1214570510 pluto[4537]: | 2: compared PSK 172.16.2.115
to 172.16.2.115 / 0.0.0.0 -> 6
Jun 27 18:11:50 1214570510 pluto[4537]: | best_match 0>6 best=0x8106e48 (line=7)
Jun 27 18:11:50 1214570510 pluto[4537]: | concluding with best_match=6
best=0x8106e48 (lineno=7)
Jun 27 18:11:50 1214570510 pluto[4537]: | ******parse ISAKMP Oakley attribute:
Jun 27 18:11:50 1214570510 pluto[4537]: |    af+type: OAKLEY_GROUP_DESCRIPTION
Jun 27 18:11:50 1214570510 pluto[4537]: |    length/value: 2
Jun 27 18:11:50 1214570510 pluto[4537]: |    [2 is OAKLEY_GROUP_MODP1024]
Jun 27 18:11:50 1214570510 pluto[4537]: | ******parse ISAKMP Oakley attribute:
Jun 27 18:11:50 1214570510 pluto[4537]: |    af+type: OAKLEY_LIFE_TYPE
Jun 27 18:11:50 1214570510 pluto[4537]: |    length/value: 1
Jun 27 18:11:50 1214570510 pluto[4537]: |    [1 is OAKLEY_LIFE_SECONDS]
Jun 27 18:11:50 1214570510 pluto[4537]: | ******parse ISAKMP Oakley attribute:
Jun 27 18:11:50 1214570510 pluto[4537]: |    af+type: OAKLEY_LIFE_DURATION
Jun 27 18:11:50 1214570510 pluto[4537]: |    length/value: 3600
Jun 27 18:11:50 1214570510 pluto[4537]: | Oakley Transform 0 accepted
Jun 27 18:11:50 1214570510 pluto[4537]: | DH public value received:
Jun 27 18:11:50 1214570510 pluto[4537]: |   19 7c 50 02  e1 64 51 37
1a dd 1d d0  cc 4d 4d c3
Jun 27 18:11:50 1214570510 pluto[4537]: |   65 7a 9a d6  7f fc ad f1
66 a9 91 e3  66 3b f6 96
Jun 27 18:11:50 1214570510 pluto[4537]: |   05 7b ee 7c  6f 21 a0 b9
d3 0f 5e 02  72 92 6e 0f
Jun 27 18:11:50 1214570510 pluto[4537]: |   15 ce db 24  78 3c df a9
87 09 b9 b8  ae 88 0a fa
Jun 27 18:11:50 1214570510 pluto[4537]: |   d9 a1 a0 77  fb cc fa c5
f7 8b 7b 88  ed da 16 f6
Jun 27 18:11:50 1214570510 pluto[4537]: |   59 25 52 23  bc 61 f1 7b
d9 dd e4 74  d5 a9 e8 24
Jun 27 18:11:50 1214570510 pluto[4537]: |   ab fc 3f 4a  8a b3 63 c2
54 c7 23 78  02 1f 3f d6
Jun 27 18:11:50 1214570510 pluto[4537]: |   f3 48 6c 42  83 4f b7 13
95 51 90 68  7b 30 07 ee
Jun 27 18:11:50 1214570510 pluto[4537]: | helper -1 doing build_kenonce op id: 0
Jun 27 18:11:50 1214570510 pluto[4537]: | Local DH secret:
Jun 27 18:11:50 1214570510 pluto[4537]: |   54 3a 31 5d  2c 25 22 86
41 5c 55 99  c4 5c 97 a4
Jun 27 18:11:50 1214570510 pluto[4537]: |   02 b0 fc d0  93 d8 96 30
2c be 7b 11  53 f3 09 e0
Jun 27 18:11:50 1214570510 pluto[4537]: | Public DH value sent:
Jun 27 18:11:50 1214570510 pluto[4537]: |   c2 16 16 e9  56 3c 74 b4
f8 24 f3 57  4a 67 81 80
Jun 27 18:11:50 1214570510 pluto[4537]: |   d7 8b 25 b1  30 4a be 4e
71 70 4b e5  62 35 6f ba
Jun 27 18:11:50 1214570510 pluto[4537]: |   84 d4 86 e5  97 a5 59 93
9a 6d 71 de  07 46 d8 d4
Jun 27 18:11:50 1214570510 pluto[4537]: |   f9 1f a7 27  3c 6d fc e7
9d 14 33 32  1e 25 84 b9
Jun 27 18:11:50 1214570510 pluto[4537]: |   8c 21 24 b8  1d c8 de 1b
59 40 6c a0  38 ea 15 ff
Jun 27 18:11:50 1214570510 pluto[4537]: |   d0 4e ea 1e  75 d9 35 93
48 b0 02 1c  7d 23 09 11
Jun 27 18:11:50 1214570510 pluto[4537]: |   dc a6 54 7c  f9 7a c1 f6
49 5b e6 af  3b 99 cb a4
Jun 27 18:11:50 1214570510 pluto[4537]: |   ea ac ac 31  1e d6 b8 6c
c5 42 ce e0  30 61 c3 32
Jun 27 18:11:50 1214570510 pluto[4537]: | Generated nonce:
Jun 27 18:11:50 1214570510 pluto[4537]: |   a2 ce bf 00  96 23 8a 62
c3 7b af 83  a4 ff 4f ad
Jun 27 18:11:50 1214570510 pluto[4537]: | aggr inI1_outR1: calculated
ke+nonce, sending R1
Jun 27 18:11:50 1214570510 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:11:50 1214570510 pluto[4537]: | **emit ISAKMP Message:
Jun 27 18:11:50 1214570510 pluto[4537]: |    initiator cookie:
Jun 27 18:11:50 1214570510 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
Jun 27 18:11:50 1214570510 pluto[4537]: |    responder cookie:
Jun 27 18:11:50 1214570510 pluto[4537]: |   d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:50 1214570510 pluto[4537]: |    next payload type: ISAKMP_NEXT_SA
Jun 27 18:11:50 1214570510 pluto[4537]: |    ISAKMP version: ISAKMP Version 1.0
Jun 27 18:11:50 1214570510 pluto[4537]: |    exchange type: ISAKMP_XCHG_AGGR
Jun 27 18:11:50 1214570510 pluto[4537]: |    flags: none
Jun 27 18:11:50 1214570510 pluto[4537]: |    message ID:  00 00 00 00
Jun 27 18:11:50 1214570510 pluto[4537]: | ***emit ISAKMP Security
Association Payload:
Jun 27 18:11:50 1214570510 pluto[4537]: |    next payload type: ISAKMP_NEXT_KE
Jun 27 18:11:50 1214570510 pluto[4537]: |    DOI: ISAKMP_DOI_IPSEC
Jun 27 18:11:50 1214570510 pluto[4537]: | ****parse IPsec DOI SIT:
Jun 27 18:11:50 1214570510 pluto[4537]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Jun 27 18:11:50 1214570510 pluto[4537]: | ****parse ISAKMP Proposal Payload:
Jun 27 18:11:50 1214570510 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:11:50 1214570510 pluto[4537]: |    length: 40
Jun 27 18:11:50 1214570510 pluto[4537]: |    proposal number: 1
Jun 27 18:11:50 1214570510 pluto[4537]: |    protocol ID: PROTO_ISAKMP
Jun 27 18:11:50 1214570510 pluto[4537]: |    SPI size: 0
Jun 27 18:11:50 1214570510 pluto[4537]: |    number of transforms: 1
Jun 27 18:11:50 1214570510 pluto[4537]: | *****parse ISAKMP Transform
Payload (ISAKMP):
Jun 27 18:11:50 1214570510 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:11:50 1214570510 pluto[4537]: |    length: 32
Jun 27 18:11:50 1214570510 pluto[4537]: |    transform number: 0
Jun 27 18:11:50 1214570510 pluto[4537]: |    transform ID: KEY_IKE
Jun 27 18:11:50 1214570510 pluto[4537]: | ******parse ISAKMP Oakley attribute:
Jun 27 18:11:50 1214570510 pluto[4537]: |    af+type:
OAKLEY_ENCRYPTION_ALGORITHM
Jun 27 18:11:50 1214570510 pluto[4537]: |    length/value: 5
Jun 27 18:11:50 1214570510 pluto[4537]: |    [5 is OAKLEY_3DES_CBC]
Jun 27 18:11:50 1214570510 pluto[4537]: |
ike_alg_enc_ok(ealg=5,key_len=0): blocksize=8, keyminlen=192,
keydeflen=192, keymaxlen=192, ret=1
Jun 27 18:11:50 1214570510 pluto[4537]: | ******parse ISAKMP Oakley attribute:
Jun 27 18:11:50 1214570510 pluto[4537]: |    af+type: OAKLEY_HASH_ALGORITHM
Jun 27 18:11:50 1214570510 pluto[4537]: |    length/value: 1
Jun 27 18:11:50 1214570510 pluto[4537]: |    [1 is OAKLEY_MD5]
Jun 27 18:11:50 1214570510 pluto[4537]: | ******parse ISAKMP Oakley attribute:
Jun 27 18:11:50 1214570510 pluto[4537]: |    af+type:
OAKLEY_AUTHENTICATION_METHOD
Jun 27 18:11:50 1214570510 pluto[4537]: |    length/value: 1
Jun 27 18:11:50 1214570510 pluto[4537]: |    [1 is OAKLEY_PRESHARED_KEY]
Jun 27 18:11:50 1214570510 pluto[4537]: | started looking for secret
for 172.16.2.115->0.0.0.0 of kind PPK_PSK
Jun 27 18:11:50 1214570510 pluto[4537]: | replace him to 0.0.0.0
Jun 27 18:11:50 1214570510 pluto[4537]: | actually looking for secret
for 172.16.2.115->0.0.0.0 of kind PPK_PSK
Jun 27 18:11:50 1214570510 pluto[4537]: | 1: compared PSK 0.0.0.0 to
172.16.2.115 / 0.0.0.0 -> 2
Jun 27 18:11:50 1214570510 pluto[4537]: | 2: compared PSK 172.16.2.115
to 172.16.2.115 / 0.0.0.0 -> 6
Jun 27 18:11:50 1214570510 pluto[4537]: | best_match 0>6 best=0x8106e48 (line=7)
Jun 27 18:11:50 1214570510 pluto[4537]: | concluding with best_match=6
best=0x8106e48 (lineno=7)
Jun 27 18:11:50 1214570510 pluto[4537]: | ******parse ISAKMP Oakley attribute:
Jun 27 18:11:50 1214570510 pluto[4537]: |    af+type: OAKLEY_GROUP_DESCRIPTION
Jun 27 18:11:50 1214570510 pluto[4537]: |    length/value: 2
Jun 27 18:11:51 1214570511 pluto[4537]: |    [2 is OAKLEY_GROUP_MODP1024]
Jun 27 18:11:51 1214570511 pluto[4537]: | ******parse ISAKMP Oakley attribute:
Jun 27 18:11:51 1214570511 pluto[4537]: |    af+type: OAKLEY_LIFE_TYPE
Jun 27 18:11:51 1214570511 pluto[4537]: |    length/value: 1
Jun 27 18:11:51 1214570511 pluto[4537]: |    [1 is OAKLEY_LIFE_SECONDS]
Jun 27 18:11:51 1214570511 pluto[4537]: | ******parse ISAKMP Oakley attribute:
Jun 27 18:11:51 1214570511 pluto[4537]: |    af+type: OAKLEY_LIFE_DURATION
Jun 27 18:11:51 1214570511 pluto[4537]: |    length/value: 3600
Jun 27 18:11:51 1214570511 pluto[4537]: | Oakley Transform 0 accepted
Jun 27 18:11:51 1214570511 pluto[4537]: | ****emit IPsec DOI SIT:
Jun 27 18:11:51 1214570511 pluto[4537]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Jun 27 18:11:51 1214570511 pluto[4537]: | ****emit ISAKMP Proposal Payload:
Jun 27 18:11:51 1214570511 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:11:51 1214570511 pluto[4537]: |    proposal number: 1
Jun 27 18:11:51 1214570511 pluto[4537]: |    protocol ID: PROTO_ISAKMP
Jun 27 18:11:51 1214570511 pluto[4537]: |    SPI size: 0
Jun 27 18:11:51 1214570511 pluto[4537]: |    number of transforms: 1
Jun 27 18:11:51 1214570511 pluto[4537]: | *****emit ISAKMP Transform
Payload (ISAKMP):
Jun 27 18:11:51 1214570511 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:11:51 1214570511 pluto[4537]: |    transform number: 0
Jun 27 18:11:51 1214570511 pluto[4537]: |    transform ID: KEY_IKE
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting 24 raw bytes of
attributes into ISAKMP Transform Payload (ISAKMP)
Jun 27 18:11:51 1214570511 pluto[4537]: | attributes  80 01 00 05  80
02 00 01  80 03 00 01  80 04 00 02
Jun 27 18:11:51 1214570511 pluto[4537]: |   80 0b 00 01  80 0c 0e 10
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting length of ISAKMP
Transform Payload (ISAKMP): 32
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting length of ISAKMP
Proposal Payload: 40
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting length of ISAKMP
Security Association Payload: 52
Jun 27 18:11:51 1214570511 pluto[4537]: | ***emit ISAKMP Key Exchange Payload:
Jun 27 18:11:51 1214570511 pluto[4537]: |    next payload type:
ISAKMP_NEXT_NONCE
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting 128 raw bytes of
keyex value into ISAKMP Key Exchange Payload
Jun 27 18:11:51 1214570511 pluto[4537]: | keyex value  c2 16 16 e9  56
3c 74 b4  f8 24 f3 57  4a 67 81 80
Jun 27 18:11:51 1214570511 pluto[4537]: |   d7 8b 25 b1  30 4a be 4e
71 70 4b e5  62 35 6f ba
Jun 27 18:11:51 1214570511 pluto[4537]: |   84 d4 86 e5  97 a5 59 93
9a 6d 71 de  07 46 d8 d4
Jun 27 18:11:51 1214570511 pluto[4537]: |   f9 1f a7 27  3c 6d fc e7
9d 14 33 32  1e 25 84 b9
Jun 27 18:11:51 1214570511 pluto[4537]: |   8c 21 24 b8  1d c8 de 1b
59 40 6c a0  38 ea 15 ff
Jun 27 18:11:51 1214570511 pluto[4537]: |   d0 4e ea 1e  75 d9 35 93
48 b0 02 1c  7d 23 09 11
Jun 27 18:11:51 1214570511 pluto[4537]: |   dc a6 54 7c  f9 7a c1 f6
49 5b e6 af  3b 99 cb a4
Jun 27 18:11:51 1214570511 pluto[4537]: |   ea ac ac 31  1e d6 b8 6c
c5 42 ce e0  30 61 c3 32
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting length of ISAKMP
Key Exchange Payload: 132
Jun 27 18:11:51 1214570511 pluto[4537]: | ***emit ISAKMP Nonce Payload:
Jun 27 18:11:51 1214570511 pluto[4537]: |    next payload type: ISAKMP_NEXT_ID
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting 16 raw bytes of Nr
into ISAKMP Nonce Payload
Jun 27 18:11:51 1214570511 pluto[4537]: | Nr  a2 ce bf 00  96 23 8a 62
 c3 7b af 83  a4 ff 4f ad
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting length of ISAKMP
Nonce Payload: 20
Jun 27 18:11:51 1214570511 pluto[4537]: | ***emit ISAKMP
Identification Payload (IPsec DOI):
Jun 27 18:11:51 1214570511 pluto[4537]: |    next payload type: ISAKMP_NEXT_HASH
Jun 27 18:11:51 1214570511 pluto[4537]: |    ID type: ID_IPV4_ADDR
Jun 27 18:11:51 1214570511 pluto[4537]: |    Protocol ID: 0
Jun 27 18:11:51 1214570511 pluto[4537]: |    port: 0
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting 4 raw bytes of my
identity into ISAKMP Identification Payload (IPsec DOI)
Jun 27 18:11:51 1214570511 pluto[4537]: | my identity  ac 10 02 73
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting length of ISAKMP
Identification Payload (IPsec DOI): 12
Jun 27 18:11:51 1214570511 pluto[4537]: | started looking for secret
for 172.16.2.115->0.0.0.0 of kind PPK_PSK
Jun 27 18:11:51 1214570511 pluto[4537]: | replace him to 0.0.0.0
Jun 27 18:11:51 1214570511 pluto[4537]: | actually looking for secret
for 172.16.2.115->0.0.0.0 of kind PPK_PSK
Jun 27 18:11:51 1214570511 pluto[4537]: | 1: compared PSK 0.0.0.0 to
172.16.2.115 / 0.0.0.0 -> 2
Jun 27 18:11:51 1214570511 pluto[4537]: | 2: compared PSK 172.16.2.115
to 172.16.2.115 / 0.0.0.0 -> 6
Jun 27 18:11:51 1214570511 pluto[4537]: | best_match 0>6 best=0x8106e48 (line=7)
Jun 27 18:11:51 1214570511 pluto[4537]: | concluding with best_match=6
best=0x8106e48 (lineno=7)
Jun 27 18:11:51 1214570511 pluto[4537]: | calc_dh_shared(): time
elapsed (OAKLEY_GROUP_MODP1024): 8881 usec
Jun 27 18:11:51 1214570511 pluto[4537]: | DH shared secret:
Jun 27 18:11:51 1214570511 pluto[4537]: |   19 3a 6a 7f  f2 1c 5d ba
01 25 3d 4c  25 97 d4 3c
Jun 27 18:11:51 1214570511 pluto[4537]: |   14 08 9b 0f  c7 04 95 bf
8a ec 9f a5  1b e8 5d c3
Jun 27 18:11:51 1214570511 pluto[4537]: |   80 23 0f b5  e8 f9 a5 d4
8f 47 d6 a3  11 6b da 3b
Jun 27 18:11:51 1214570511 pluto[4537]: |   93 52 f5 a3  6e 68 6c da
a3 a6 7f 18  9a 82 e3 b5
Jun 27 18:11:51 1214570511 pluto[4537]: |   83 fd a5 90  46 86 67 e6
81 33 76 bf  31 ba 1d c6
Jun 27 18:11:51 1214570511 pluto[4537]: |   0b 85 0b 67  ce 4f 8f 1b
67 f3 59 69  16 9c c3 2e
Jun 27 18:11:51 1214570511 pluto[4537]: |   50 4d 08 1b  d3 51 9d a2
14 6c 9a e1  a9 23 f2 cd
Jun 27 18:11:51 1214570511 pluto[4537]: |   56 69 90 7e  3c d2 37 ee
54 65 e6 46  2a 33 32 fa
Jun 27 18:11:51 1214570511 pluto[4537]: | Skey inputs (PSK+NI+NR)
Jun 27 18:11:51 1214570511 pluto[4537]: | ni:   26 22 15 85  40 90 ca
e1  c7 d5 b0 1f  f9 37 27 53
Jun 27 18:11:51 1214570511 pluto[4537]: | nr:   a2 ce bf 00  96 23 8a
62  c3 7b af 83  a4 ff 4f ad
Jun 27 18:11:51 1214570511 pluto[4537]: | keyid:   6f f8 08 b9  01 c7
9c be  96 43 04 42  a5 fe a9 74
Jun 27 18:11:51 1214570511 pluto[4537]: | DH_i:  19 7c 50 02  e1 64 51
37  1a dd 1d d0  cc 4d 4d c3
Jun 27 18:11:51 1214570511 pluto[4537]: |   65 7a 9a d6  7f fc ad f1
66 a9 91 e3  66 3b f6 96
Jun 27 18:11:51 1214570511 pluto[4537]: |   05 7b ee 7c  6f 21 a0 b9
d3 0f 5e 02  72 92 6e 0f
Jun 27 18:11:51 1214570511 pluto[4537]: |   15 ce db 24  78 3c df a9
87 09 b9 b8  ae 88 0a fa
Jun 27 18:11:51 1214570511 pluto[4537]: |   d9 a1 a0 77  fb cc fa c5
f7 8b 7b 88  ed da 16 f6
Jun 27 18:11:51 1214570511 pluto[4537]: |   59 25 52 23  bc 61 f1 7b
d9 dd e4 74  d5 a9 e8 24
Jun 27 18:11:51 1214570511 pluto[4537]: |   ab fc 3f 4a  8a b3 63 c2
54 c7 23 78  02 1f 3f d6
Jun 27 18:11:51 1214570511 pluto[4537]: |   f3 48 6c 42  83 4f b7 13
95 51 90 68  7b 30 07 ee
Jun 27 18:11:51 1214570511 pluto[4537]: | DH_r:  c2 16 16 e9  56 3c 74
b4  f8 24 f3 57  4a 67 81 80
Jun 27 18:11:51 1214570511 pluto[4537]: |   d7 8b 25 b1  30 4a be 4e
71 70 4b e5  62 35 6f ba
Jun 27 18:11:51 1214570511 pluto[4537]: |   84 d4 86 e5  97 a5 59 93
9a 6d 71 de  07 46 d8 d4
Jun 27 18:11:51 1214570511 pluto[4537]: |   f9 1f a7 27  3c 6d fc e7
9d 14 33 32  1e 25 84 b9
Jun 27 18:11:51 1214570511 pluto[4537]: |   8c 21 24 b8  1d c8 de 1b
59 40 6c a0  38 ea 15 ff
Jun 27 18:11:51 1214570511 pluto[4537]: |   d0 4e ea 1e  75 d9 35 93
48 b0 02 1c  7d 23 09 11
Jun 27 18:11:51 1214570511 pluto[4537]: |   dc a6 54 7c  f9 7a c1 f6
49 5b e6 af  3b 99 cb a4
Jun 27 18:11:51 1214570511 pluto[4537]: |   ea ac ac 31  1e d6 b8 6c
c5 42 ce e0  30 61 c3 32
Jun 27 18:11:51 1214570511 pluto[4537]: | Skeyid:    6f f8 08 b9  01
c7 9c be  96 43 04 42  a5 fe a9 74
Jun 27 18:11:51 1214570511 pluto[4537]: | Skeyid_d:  91 85 2c 37  b4
22 ab 60  06 8a 3b 27  fd c7 5b 90
Jun 27 18:11:51 1214570511 pluto[4537]: | Skeyid_a:  0b ff 64 04  82
9e 7b 4e  18 f3 92 45  cf 68 9b 6e
Jun 27 18:11:51 1214570511 pluto[4537]: | Skeyid_e:  91 b3 37 a7  54
6a 3a 7c  3a 6d c0 96  46 69 19 a9
Jun 27 18:11:51 1214570511 pluto[4537]: | enc key:  f3 f5 e9 2e  3d fd
f9 79  0b c1 a4 04  5e c4 d3 e9
Jun 27 18:11:51 1214570511 pluto[4537]: |   c7 0c ea 01  fb 52 00 86
Jun 27 18:11:51 1214570511 pluto[4537]: | IV:  43 09 c5 93  29 63 07
1c  31 e7 32 89  a4 dc 1d b3
Jun 27 18:11:51 1214570511 pluto[4537]: | hashing 48 bytes of SA
Jun 27 18:11:51 1214570511 pluto[4537]: | ***emit ISAKMP Hash Payload:
Jun 27 18:11:51 1214570511 pluto[4537]: |    next payload type: ISAKMP_NEXT_VID
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting 16 raw bytes of
HASH_R into ISAKMP Hash Payload
Jun 27 18:11:51 1214570511 pluto[4537]: | HASH_R  87 ec 58 ea  30 d9
ba ee  83 8d 8a 9a  5a a1 bd 00
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting length of ISAKMP
Hash Payload: 20
Jun 27 18:11:51 1214570511 pluto[4537]: | ***emit ISAKMP Vendor ID Payload:
Jun 27 18:11:51 1214570511 pluto[4537]: |    next payload type: ISAKMP_NEXT_VID
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting 16 raw bytes of DPP
Vendor ID into ISAKMP Vendor ID Payload
Jun 27 18:11:51 1214570511 pluto[4537]: | DPP Vendor ID  af ca d7 13
68 a1 f1 c9  6b 86 96 fc  77 57 01 00
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting length of ISAKMP
Vendor ID Payload: 20
Jun 27 18:11:51 1214570511 pluto[4537]: | out_vendorid(): sending
[draft-ietf-ipsec-nat-t-ike-03]
Jun 27 18:11:51 1214570511 pluto[4537]: | ***emit ISAKMP Vendor ID Payload:
Jun 27 18:11:51 1214570511 pluto[4537]: |    next payload type: ISAKMP_NEXT_HASH
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting 16 raw bytes of
V_ID into ISAKMP Vendor ID Payload
Jun 27 18:11:51 1214570511 pluto[4537]: | V_ID  7d 94 19 a6  53 10 ca
6f  2c 17 9d 92  15 52 9d 56
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting length of ISAKMP
Vendor ID Payload: 20
Jun 27 18:11:51 1214570511 pluto[4537]: | sending NATD payloads
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: hasher=0x80e67c0(16)
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: icookie=
Jun 27 18:11:51 1214570511 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: rcookie=
Jun 27 18:11:51 1214570511 pluto[4537]: |   d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: ip=  ac 10 01 97
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: port=500
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: hash=  42 3d d1
27  cd 5e d9 25  ab b5 b2 db  e3 76 3f 06
Jun 27 18:11:51 1214570511 pluto[4537]: | ***emit ISAKMP NAT-D Payload:
Jun 27 18:11:51 1214570511 pluto[4537]: |    next payload type:
ISAKMP_NEXT_NAT-D
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting 16 raw bytes of
NAT-D into ISAKMP NAT-D Payload
Jun 27 18:11:51 1214570511 pluto[4537]: | NAT-D  42 3d d1 27  cd 5e d9
25  ab b5 b2 db  e3 76 3f 06
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting length of ISAKMP
NAT-D Payload: 20
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: hasher=0x80e67c0(16)
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: icookie=
Jun 27 18:11:51 1214570511 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: rcookie=
Jun 27 18:11:51 1214570511 pluto[4537]: |   d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: ip=  ac 10 02 73
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: port=500
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: hash=  a5 6e a8
6e  bf f1 eb 2d  cb 63 39 4b  e4 e6 3b f8
Jun 27 18:11:51 1214570511 pluto[4537]: | ***emit ISAKMP NAT-D Payload:
Jun 27 18:11:51 1214570511 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting 16 raw bytes of
NAT-D into ISAKMP NAT-D Payload
Jun 27 18:11:51 1214570511 pluto[4537]: | NAT-D  a5 6e a8 6e  bf f1 eb
2d  cb 63 39 4b  e4 e6 3b f8
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting length of ISAKMP
NAT-D Payload: 20
Jun 27 18:11:51 1214570511 pluto[4537]: | emitting length of ISAKMP Message: 344
Jun 27 18:11:51 1214570511 pluto[4537]: | complete state transition with STF_OK
Jun 27 18:11:51 1214570511 pluto[4537]: "rw-1"[4] 172.16.1.151 #77:
transition from state STATE_AGGR_R0 to state STATE_AGGR_R1
Jun 27 18:11:51 1214570511 pluto[4537]: | sending reply packet to
172.16.1.151:500 (from port=500)
Jun 27 18:11:51 1214570511 pluto[4537]: | sending 344 bytes for
STATE_AGGR_R0 through eth1:500 to 172.16.1.151:500:
Jun 27 18:11:51 1214570511 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:51 1214570511 pluto[4537]: |   01 10 04 00  00 00 00 00
00 00 01 58  04 00 00 34
Jun 27 18:11:51 1214570511 pluto[4537]: |   00 00 00 01  00 00 00 01
00 00 00 28  01 01 00 01
Jun 27 18:11:51 1214570511 pluto[4537]: |   00 00 00 20  00 01 00 00
80 01 00 05  80 02 00 01
Jun 27 18:11:51 1214570511 pluto[4537]: |   80 03 00 01  80 04 00 02
80 0b 00 01  80 0c 0e 10
Jun 27 18:11:51 1214570511 pluto[4537]: |   0a 00 00 84  c2 16 16 e9
56 3c 74 b4  f8 24 f3 57
Jun 27 18:11:51 1214570511 pluto[4537]: |   4a 67 81 80  d7 8b 25 b1
30 4a be 4e  71 70 4b e5
Jun 27 18:11:51 1214570511 pluto[4537]: |   62 35 6f ba  84 d4 86 e5
97 a5 59 93  9a 6d 71 de
Jun 27 18:11:51 1214570511 pluto[4537]: |   07 46 d8 d4  f9 1f a7 27
3c 6d fc e7  9d 14 33 32
Jun 27 18:11:51 1214570511 pluto[4537]: |   1e 25 84 b9  8c 21 24 b8
1d c8 de 1b  59 40 6c a0
Jun 27 18:11:51 1214570511 pluto[4537]: |   38 ea 15 ff  d0 4e ea 1e
75 d9 35 93  48 b0 02 1c
Jun 27 18:11:51 1214570511 pluto[4537]: |   7d 23 09 11  dc a6 54 7c
f9 7a c1 f6  49 5b e6 af
Jun 27 18:11:51 1214570511 pluto[4537]: |   3b 99 cb a4  ea ac ac 31
1e d6 b8 6c  c5 42 ce e0
Jun 27 18:11:51 1214570511 pluto[4537]: |   30 61 c3 32  05 00 00 14
a2 ce bf 00  96 23 8a 62
Jun 27 18:11:51 1214570511 pluto[4537]: |   c3 7b af 83  a4 ff 4f ad
08 00 00 0c  01 00 00 00
Jun 27 18:11:51 1214570511 pluto[4537]: |   ac 10 02 73  0d 00 00 14
87 ec 58 ea  30 d9 ba ee
Jun 27 18:11:51 1214570511 pluto[4537]: |   83 8d 8a 9a  5a a1 bd 00
0d 00 00 14  af ca d7 13
Jun 27 18:11:51 1214570511 pluto[4537]: |   68 a1 f1 c9  6b 86 96 fc
77 57 01 00  82 00 00 14
Jun 27 18:11:51 1214570511 pluto[4537]: |   7d 94 19 a6  53 10 ca 6f
2c 17 9d 92  15 52 9d 56
Jun 27 18:11:51 1214570511 pluto[4537]: |   82 00 00 14  42 3d d1 27
cd 5e d9 25  ab b5 b2 db
Jun 27 18:11:51 1214570511 pluto[4537]: |   e3 76 3f 06  00 00 00 14
a5 6e a8 6e  bf f1 eb 2d
Jun 27 18:11:51 1214570511 pluto[4537]: |   cb 63 39 4b  e4 e6 3b f8
Jun 27 18:11:51 1214570511 pluto[4537]: | inserting event
EVENT_RETRANSMIT, timeout in 10 seconds for #77
Jun 27 18:11:51 1214570511 pluto[4537]: "rw-1"[4] 172.16.1.151 #77:
STATE_AGGR_R1: sent AR1, expecting AI2
Jun 27 18:11:51 1214570511 pluto[4537]: | modecfg pull: noquirk
policy:push not-client
Jun 27 18:11:51 1214570511 pluto[4537]: | phase 1 is done, looking for
phase 1 to unpend
Jun 27 18:11:51 1214570511 pluto[4537]: | complete state transition
with STF_INLINE
Jun 27 18:11:51 1214570511 pluto[4537]: | next event
EVENT_NAT_T_KEEPALIVE in 0 seconds
Jun 27 18:11:51 1214570511 pluto[4537]: |
Jun 27 18:11:51 1214570511 pluto[4537]: | *time to handle event
Jun 27 18:11:51 1214570511 pluto[4537]: | handling event EVENT_NAT_T_KEEPALIVE
Jun 27 18:11:51 1214570511 pluto[4537]: | event after this is
EVENT_RETRANSMIT in 10 seconds
Jun 27 18:11:51 1214570511 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:11:51 1214570511 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:11:51 1214570511 pluto[4537]: | ka_event: send NAT-KA to
172.16.1.151:4500 (state=#74)
Jun 27 18:11:51 1214570511 pluto[4537]: | sending 1 bytes for NAT-T
Keep Alive through eth1:4500 to 172.16.1.151:4500:
Jun 27 18:11:51 1214570511 pluto[4537]: |   ff
Jun 27 18:11:51 1214570511 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:11:51 1214570511 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:11:51 1214570511 pluto[4537]: | ka_event: send NAT-KA to
172.16.1.151:4500 (state=#73)
Jun 27 18:11:51 1214570511 pluto[4537]: | sending 1 bytes for NAT-T
Keep Alive through eth1:500 to 172.16.1.151:4500:
Jun 27 18:11:51 1214570511 pluto[4537]: |   ff
Jun 27 18:11:51 1214570511 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:11:51 1214570511 pluto[4537]: | inserting event
EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Jun 27 18:11:51 1214570511 pluto[4537]: | next event EVENT_RETRANSMIT
in 10 seconds for #77
Jun 27 18:11:51 1214570511 pluto[4537]: |
Jun 27 18:11:51 1214570511 pluto[4537]: | *received 92 bytes from
172.16.1.151:4500 on eth1 (port=4500)
Jun 27 18:11:51 1214570511 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:51 1214570511 pluto[4537]: |   08 10 04 01  00 00 00 00
00 00 00 5c  54 cc c4 9f
Jun 27 18:11:51 1214570511 pluto[4537]: |   a8 fd f9 8c  7d 7e 45 52
c7 38 c9 87  e3 8f 47 01
Jun 27 18:11:51 1214570511 pluto[4537]: |   23 f3 ce 75  ed 20 72 8c
85 2b 3b 84  17 40 1d 40
Jun 27 18:11:51 1214570511 pluto[4537]: |   e7 82 44 dc  7c 1b 84 34
32 24 f4 14  51 5b 1d a8
Jun 27 18:11:51 1214570511 pluto[4537]: |   d1 0e b4 4b  6a 6c b8 98
b3 85 52 58
Jun 27 18:11:51 1214570511 pluto[4537]: | **parse ISAKMP Message:
Jun 27 18:11:51 1214570511 pluto[4537]: |    initiator cookie:
Jun 27 18:11:51 1214570511 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
Jun 27 18:11:51 1214570511 pluto[4537]: |    responder cookie:
Jun 27 18:11:51 1214570511 pluto[4537]: |   d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:51 1214570511 pluto[4537]: |    next payload type: ISAKMP_NEXT_HASH
Jun 27 18:11:51 1214570511 pluto[4537]: |    ISAKMP version: ISAKMP Version 1.0
Jun 27 18:11:51 1214570511 pluto[4537]: |    exchange type: ISAKMP_XCHG_AGGR
Jun 27 18:11:51 1214570511 pluto[4537]: |    flags: ISAKMP_FLAG_ENCRYPTION
Jun 27 18:11:51 1214570511 pluto[4537]: |    message ID:  00 00 00 00
Jun 27 18:11:51 1214570511 pluto[4537]: |    length: 92
Jun 27 18:11:51 1214570511 pluto[4537]: |  processing packet with
exchange type=ISAKMP_XCHG_AGGR (4)
Jun 27 18:11:51 1214570511 pluto[4537]: | ICOOKIE:  c0 ba 41 b2  8e 08 66 93
Jun 27 18:11:51 1214570511 pluto[4537]: | RCOOKIE:  d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:51 1214570511 pluto[4537]: | peer:  ac 10 01 97
Jun 27 18:11:51 1214570511 pluto[4537]: | state hash entry 18
Jun 27 18:11:51 1214570511 pluto[4537]: | peer and cookies match on
#77, provided msgid 00000000 vs 00000000
Jun 27 18:11:51 1214570511 pluto[4537]: | state object #77 found, in
STATE_AGGR_R1
Jun 27 18:11:51 1214570511 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:11:51 1214570511 pluto[4537]: | received encrypted packet
from 172.16.1.151:4500
Jun 27 18:11:51 1214570511 pluto[4537]: | decrypting 64 bytes using
algorithm OAKLEY_3DES_CBC
Jun 27 18:11:51 1214570511 pluto[4537]: | decrypted:
Jun 27 18:11:51 1214570511 pluto[4537]: |   82 00 00 14  f0 0e 00 fc
9b 8b 06 28  b8 94 3a 06
Jun 27 18:11:51 1214570511 pluto[4537]: |   83 1d c9 26  82 00 00 14
a5 6e a8 6e  bf f1 eb 2d
Jun 27 18:11:51 1214570511 pluto[4537]: |   cb 63 39 4b  e4 e6 3b f8
00 00 00 14  64 4c 27 9d
Jun 27 18:11:51 1214570511 pluto[4537]: |   34 70 24 5e  e5 4b 69 d0
3b 51 a1 4a  00 00 00 00
Jun 27 18:11:51 1214570511 pluto[4537]: | next IV:  6a 6c b8 98  b3 85 52 58
Jun 27 18:11:51 1214570511 pluto[4537]: | ***parse ISAKMP Hash Payload:
Jun 27 18:11:51 1214570511 pluto[4537]: |    next payload type:
ISAKMP_NEXT_NAT-D
Jun 27 18:11:51 1214570511 pluto[4537]: |    length: 20
Jun 27 18:11:51 1214570511 pluto[4537]: | ***parse ISAKMP NAT-D Payload:
Jun 27 18:11:51 1214570511 pluto[4537]: |    next payload type:
ISAKMP_NEXT_NAT-D
Jun 27 18:11:51 1214570511 pluto[4537]: |    length: 20
Jun 27 18:11:51 1214570511 pluto[4537]: | ***parse ISAKMP NAT-D Payload:
Jun 27 18:11:51 1214570511 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:11:51 1214570511 pluto[4537]: |    length: 20
Jun 27 18:11:51 1214570511 pluto[4537]: | removing 4 bytes of padding
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: hasher=0x80e67c0(16)
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: icookie=
Jun 27 18:11:51 1214570511 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: rcookie=
Jun 27 18:11:51 1214570511 pluto[4537]: |   d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: ip=  ac 10 02 73
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: port=4500
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: hash=  64 bd 68
02  6a 94 cd 72  b7 2d e2 f6  13 b9 ec 9c
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: hasher=0x80e67c0(16)
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: icookie=
Jun 27 18:11:51 1214570511 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
Jun 27 18:11:51 1214570511 pluto[4537]: | _natd_hash: rcookie=
Jun 27 18:11:51 1214570511 pluto[4537]: |   d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:52 1214570512 pluto[4537]: | _natd_hash: ip=  ac 10 01 97
Jun 27 18:11:52 1214570512 pluto[4537]: | _natd_hash: port=4500
Jun 27 18:11:52 1214570512 pluto[4537]: | _natd_hash: hash=  d3 55 29
6a  74 e2 5c e6  9b a2 a7 e5  d1 94 b9 f6
Jun 27 18:11:52 1214570512 pluto[4537]: | NAT_TRAVERSAL hash=0 (me:0) (him:0)
Jun 27 18:11:52 1214570512 pluto[4537]: | expected NAT-D(me):  64 bd
68 02  6a 94 cd 72  b7 2d e2 f6  13 b9 ec 9c
Jun 27 18:11:52 1214570512 pluto[4537]: | expected NAT-D(him):
Jun 27 18:11:52 1214570512 pluto[4537]: |   d3 55 29 6a  74 e2 5c e6
9b a2 a7 e5  d1 94 b9 f6
Jun 27 18:11:52 1214570512 pluto[4537]: | received NAT-D:  a5 6e a8 6e
 bf f1 eb 2d  cb 63 39 4b  e4 e6 3b f8
Jun 27 18:11:52 1214570512 pluto[4537]: | NAT_TRAVERSAL hash=1 (me:0) (him:0)
Jun 27 18:11:52 1214570512 pluto[4537]: | expected NAT-D(me):  64 bd
68 02  6a 94 cd 72  b7 2d e2 f6  13 b9 ec 9c
Jun 27 18:11:52 1214570512 pluto[4537]: | expected NAT-D(him):
Jun 27 18:11:52 1214570512 pluto[4537]: |   d3 55 29 6a  74 e2 5c e6
9b a2 a7 e5  d1 94 b9 f6
Jun 27 18:11:52 1214570512 pluto[4537]: | received NAT-D:  64 4c 27 9d
 34 70 24 5e  e5 4b 69 d0  3b 51 a1 4a
Jun 27 18:11:52 1214570512 pluto[4537]: | NAT_TRAVERSAL hash=2 (me:0) (him:0)
Jun 27 18:11:52 1214570512 pluto[4537]: "rw-1"[4] 172.16.1.151 #77:
NAT-Traversal: Result using draft-ietf-ipsec-nat-t-ike-02/03: both are
NATed
Jun 27 18:11:52 1214570512 pluto[4537]: | **emit ISAKMP Identification
Payload (IPsec DOI):
Jun 27 18:11:52 1214570512 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:11:52 1214570512 pluto[4537]: |    ID type: ID_IPV4_ADDR
Jun 27 18:11:52 1214570512 pluto[4537]: |    Protocol ID: 0
Jun 27 18:11:52 1214570512 pluto[4537]: |    port: 0
Jun 27 18:11:52 1214570512 pluto[4537]: | emitting 4 raw bytes of my
identity into ISAKMP Identification Payload (IPsec DOI)
Jun 27 18:11:52 1214570512 pluto[4537]: | my identity  00 00 00 00
Jun 27 18:11:52 1214570512 pluto[4537]: | emitting length of ISAKMP
Identification Payload (IPsec DOI): 12
Jun 27 18:11:52 1214570512 pluto[4537]: | ***parse ISAKMP
Identification Payload:
Jun 27 18:11:52 1214570512 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:11:52 1214570512 pluto[4537]: |    length: 12
Jun 27 18:11:52 1214570512 pluto[4537]: |    ID type: ID_IPV4_ADDR
Jun 27 18:11:52 1214570512 pluto[4537]: |    DOI specific A: 0
Jun 27 18:11:52 1214570512 pluto[4537]: |    DOI specific B: 0
Jun 27 18:11:52 1214570512 pluto[4537]: "rw-1"[4] 172.16.1.151 #77:
Aggressive mode peer ID is ID_IPV4_ADDR: '0.0.0.0'
Jun 27 18:11:52 1214570512 pluto[4537]: | refine_connection: starting with rw-1
Jun 27 18:11:52 1214570512 pluto[4537]: |   trusted_ca called with
a=(empty) b=(empty)
Jun 27 18:11:52 1214570512 pluto[4537]: | refine_connection: happy
with starting point: rw-1
Jun 27 18:11:52 1214570512 pluto[4537]: | offered CA: '%none'
Jun 27 18:11:52 1214570512 pluto[4537]: | hashing 48 bytes of SA
Jun 27 18:11:52 1214570512 pluto[4537]: | authentication succeeded
Jun 27 18:11:52 1214570512 pluto[4537]: | phase 1 complete
Jun 27 18:11:52 1214570512 pluto[4537]: | complete state transition with STF_OK
Jun 27 18:11:52 1214570512 pluto[4537]: "rw-1"[4] 172.16.1.151 #77:
transition from state STATE_AGGR_R1 to state STATE_AGGR_R2
Jun 27 18:11:52 1214570512 pluto[4537]: | inserting event
EVENT_SA_EXPIRE, timeout in 3600 seconds for #77
Jun 27 18:11:52 1214570512 pluto[4537]: "rw-1"[4] 172.16.1.151 #77:
STATE_AGGR_R2: ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY
cipher=oakley_3des_cbc_192 prf=oakley_md5 group=modp1024}
Jun 27 18:11:52 1214570512 pluto[4537]: | ICOOKIE:  c0 ba 41 b2  8e 08 66 93
Jun 27 18:11:52 1214570512 pluto[4537]: | RCOOKIE:  d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:52 1214570512 pluto[4537]: | peer:  ac 10 01 97
Jun 27 18:11:52 1214570512 pluto[4537]: | state hash entry 18
Jun 27 18:11:52 1214570512 pluto[4537]: | peer and cookies match on
#77, provided msgid 00000000 vs 00000000
Jun 27 18:11:52 1214570512 pluto[4537]: | state object #77 found, in
STATE_AGGR_R2
Jun 27 18:11:52 1214570512 pluto[4537]: "rw-1"[4] 172.16.1.151 #77:
Dead Peer Detection (RFC 3706): enabled
Jun 27 18:11:52 1214570512 pluto[4537]: | state: 77 requesting event
none to be deleted by dpd.c:160
Jun 27 18:11:52 1214570512 pluto[4537]: | inserting event EVENT_DPD,
timeout in 30 seconds for #77
Jun 27 18:11:52 1214570512 pluto[4537]: | modecfg pull: noquirk
policy:push not-client
Jun 27 18:11:52 1214570512 pluto[4537]: | phase 1 is done, looking for
phase 1 to unpend
Jun 27 18:11:52 1214570512 pluto[4537]: | next event
EVENT_NAT_T_KEEPALIVE in 19 seconds
Jun 27 18:11:52 1214570512 pluto[4537]: |
Jun 27 18:11:52 1214570512 pluto[4537]: | *received 284 bytes from
172.16.1.151:4500 on eth1 (port=4500)
Jun 27 18:11:52 1214570512 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:52 1214570512 pluto[4537]: |   08 10 20 01  66 d4 4d 99
00 00 01 1c  7f 50 53 b2
Jun 27 18:11:52 1214570512 pluto[4537]: |   01 0d 3a bc  a3 88 fc bb
e9 06 f9 17  39 22 a6 92
Jun 27 18:11:52 1214570512 pluto[4537]: |   35 4f cf dc  6c 63 8b 15
8f 62 02 ab  eb e3 2e 6a
Jun 27 18:11:52 1214570512 pluto[4537]: |   38 c8 cd 10  fb df 70 76
41 19 d5 55  27 bb d6 8c
Jun 27 18:11:52 1214570512 pluto[4537]: |   c6 be 1c 5d  29 26 1e 21
44 74 71 cf  c8 f8 f4 7a
Jun 27 18:11:52 1214570512 pluto[4537]: |   7b db f0 47  8f 1f ff df
11 05 a6 35  c8 03 6d f6
Jun 27 18:11:52 1214570512 pluto[4537]: |   7c 34 9f ad  74 cd 22 6c
89 87 9c d3  67 ce 9a 3d
Jun 27 18:11:52 1214570512 pluto[4537]: |   6c d8 ec d7  1d e2 88 13
bb f6 d7 aa  50 e8 ea 7f
Jun 27 18:11:52 1214570512 pluto[4537]: |   03 85 21 db  81 d3 44 f5
3d 0c 6e bc  20 03 ef 77
Jun 27 18:11:52 1214570512 pluto[4537]: |   59 90 ab d9  f9 2f 71 97
02 31 ed ec  4e 5a 3f 85
Jun 27 18:11:52 1214570512 pluto[4537]: |   61 76 61 83  72 d0 1d 59
da 36 fc a6  b7 9d 8d 25
Jun 27 18:11:52 1214570512 pluto[4537]: |   14 ce 9a a4  d6 cc fb f0
dc 95 bf fb  70 72 d8 6d
Jun 27 18:11:52 1214570512 pluto[4537]: |   5e c6 55 83  09 02 ae 22
61 16 ce da  62 02 71 fd
Jun 27 18:11:52 1214570512 pluto[4537]: |   45 9c 37 75  06 ea c4 bd
15 78 b5 32  ba 7e fe 41
Jun 27 18:11:52 1214570512 pluto[4537]: |   51 b5 5b 6a  60 8c 86 03
5e a9 ee 7d  1f f7 43 6a
Jun 27 18:11:52 1214570512 pluto[4537]: |   e5 ff b0 62  10 03 78 b8
b8 db 7f b8  0a 23 94 87
Jun 27 18:11:52 1214570512 pluto[4537]: |   98 c3 34 f0  d3 d3 d8 3e
d1 b5 a7 52
Jun 27 18:11:52 1214570512 pluto[4537]: | **parse ISAKMP Message:
Jun 27 18:11:52 1214570512 pluto[4537]: |    initiator cookie:
Jun 27 18:11:52 1214570512 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
Jun 27 18:11:52 1214570512 pluto[4537]: |    responder cookie:
Jun 27 18:11:52 1214570512 pluto[4537]: |   d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:52 1214570512 pluto[4537]: |    next payload type: ISAKMP_NEXT_HASH
Jun 27 18:11:52 1214570512 pluto[4537]: |    ISAKMP version: ISAKMP Version 1.0
Jun 27 18:11:52 1214570512 pluto[4537]: |    exchange type: ISAKMP_XCHG_QUICK
Jun 27 18:11:52 1214570512 pluto[4537]: |    flags: ISAKMP_FLAG_ENCRYPTION
Jun 27 18:11:52 1214570512 pluto[4537]: |    message ID:  66 d4 4d 99
Jun 27 18:11:52 1214570512 pluto[4537]: |    length: 284
Jun 27 18:11:52 1214570512 pluto[4537]: |  processing packet with
exchange type=ISAKMP_XCHG_QUICK (32)
Jun 27 18:11:52 1214570512 pluto[4537]: | ICOOKIE:  c0 ba 41 b2  8e 08 66 93
Jun 27 18:11:52 1214570512 pluto[4537]: | RCOOKIE:  d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:52 1214570512 pluto[4537]: | peer:  ac 10 01 97
Jun 27 18:11:52 1214570512 pluto[4537]: | state hash entry 18
Jun 27 18:11:52 1214570512 pluto[4537]: | peer and cookies match on
#77, provided msgid 66d44d99 vs 00000000
Jun 27 18:11:52 1214570512 pluto[4537]: | state object not found
Jun 27 18:11:52 1214570512 pluto[4537]: | ICOOKIE:  c0 ba 41 b2  8e 08 66 93
Jun 27 18:11:52 1214570512 pluto[4537]: | RCOOKIE:  d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:52 1214570512 pluto[4537]: | peer:  ac 10 01 97
Jun 27 18:11:52 1214570512 pluto[4537]: | state hash entry 18
Jun 27 18:11:52 1214570512 pluto[4537]: | peer and cookies match on
#77, provided msgid 00000000 vs 00000000
Jun 27 18:11:52 1214570512 pluto[4537]: | state object #77 found, in
STATE_AGGR_R2
Jun 27 18:11:52 1214570512 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:11:52 1214570512 pluto[4537]: | last Phase 1 IV:  6a 6c b8
98  b3 85 52 58
Jun 27 18:11:52 1214570512 pluto[4537]: | current Phase 1 IV:  6a 6c
b8 98  b3 85 52 58
Jun 27 18:11:52 1214570512 pluto[4537]: | computed Phase 2 IV:
Jun 27 18:11:52 1214570512 pluto[4537]: |   e4 4d e3 43  b6 f3 66 39
34 15 f7 bd  b3 a8 74 5a
Jun 27 18:11:52 1214570512 pluto[4537]: | received encrypted packet
from 172.16.1.151:4500
Jun 27 18:11:52 1214570512 pluto[4537]: | decrypting 256 bytes using
algorithm OAKLEY_3DES_CBC
Jun 27 18:11:52 1214570512 pluto[4537]: | decrypted:
Jun 27 18:11:52 1214570512 pluto[4537]: |   01 00 00 14  82 18 35 a6
43 e6 e7 28  66 98 25 4c
Jun 27 18:11:52 1214570512 pluto[4537]: |   14 26 05 39  0a 00 00 34
00 00 00 01  00 00 00 01
Jun 27 18:11:52 1214570512 pluto[4537]: |   00 00 00 28  01 03 04 01
b0 74 c8 8e  00 00 00 1c
Jun 27 18:11:52 1214570512 pluto[4537]: |   01 03 00 00  80 01 00 01
80 02 0e 10  80 04 f0 03
Jun 27 18:11:52 1214570512 pluto[4537]: |   80 05 00 01  80 03 00 02
04 00 00 14  e1 0a e5 84
Jun 27 18:11:52 1214570512 pluto[4537]: |   52 22 82 81  3f 0f 7d df
de f5 14 97  05 00 00 84
Jun 27 18:11:52 1214570512 pluto[4537]: |   48 b2 54 95  5e 5f f8 ba
e0 82 27 20  d1 c9 ae 3a
Jun 27 18:11:52 1214570512 pluto[4537]: |   14 bf 09 41  06 c9 be 37
bc 11 e9 f6  3b 0a 66 38
Jun 27 18:11:52 1214570512 pluto[4537]: |   e7 70 bb 52  4e 50 7a f0
5c 57 0b db  3b d9 aa 88
Jun 27 18:11:52 1214570512 pluto[4537]: |   d2 d4 86 a2  b1 6e a6 4f
45 42 b7 e1  f2 0d 11 b4
Jun 27 18:11:52 1214570512 pluto[4537]: |   4f 65 df 85  be e9 0b 38
fd 1f b7 2a  a5 e5 b8 8e
Jun 27 18:11:52 1214570512 pluto[4537]: |   58 86 f2 c3  56 c5 08 e8
76 e6 8a cb  47 f2 fe 1b
Jun 27 18:11:52 1214570512 pluto[4537]: |   74 11 57 a1  70 07 13 b0
66 70 84 1a  bb 6b ae ec
Jun 27 18:11:52 1214570512 pluto[4537]: |   e6 15 34 d0  b5 51 b8 7f
6e 5a 2a bc  47 f9 a7 5d
Jun 27 18:11:52 1214570512 pluto[4537]: |   05 00 00 0c  01 00 00 00
0a 14 14 39  00 00 00 10
Jun 27 18:11:52 1214570512 pluto[4537]: |   04 00 00 00  14 14 14 00
ff ff ff 00  00 00 00 00
Jun 27 18:11:52 1214570512 pluto[4537]: | next IV:  d3 d3 d8 3e  d1 b5 a7 52
Jun 27 18:11:52 1214570512 pluto[4537]: | ***parse ISAKMP Hash Payload:
Jun 27 18:11:52 1214570512 pluto[4537]: |    next payload type: ISAKMP_NEXT_SA
Jun 27 18:11:52 1214570512 pluto[4537]: |    length: 20
Jun 27 18:11:52 1214570512 pluto[4537]: | ***parse ISAKMP Security
Association Payload:
Jun 27 18:11:52 1214570512 pluto[4537]: |    next payload type:
ISAKMP_NEXT_NONCE
Jun 27 18:11:52 1214570512 pluto[4537]: |    length: 52
Jun 27 18:11:52 1214570512 pluto[4537]: |    DOI: ISAKMP_DOI_IPSEC
Jun 27 18:11:52 1214570512 pluto[4537]: | ***parse ISAKMP Nonce Payload:
Jun 27 18:11:52 1214570512 pluto[4537]: |    next payload type: ISAKMP_NEXT_KE
Jun 27 18:11:52 1214570512 pluto[4537]: |    length: 20
Jun 27 18:11:52 1214570512 pluto[4537]: | ***parse ISAKMP Key Exchange Payload:
Jun 27 18:11:52 1214570512 pluto[4537]: |    next payload type: ISAKMP_NEXT_ID
Jun 27 18:11:52 1214570512 pluto[4537]: |    length: 132
Jun 27 18:11:52 1214570512 pluto[4537]: | ***parse ISAKMP
Identification Payload (IPsec DOI):
Jun 27 18:11:52 1214570512 pluto[4537]: |    next payload type: ISAKMP_NEXT_ID
Jun 27 18:11:52 1214570512 pluto[4537]: |    length: 12
Jun 27 18:11:52 1214570512 pluto[4537]: |    ID type: ID_IPV4_ADDR
Jun 27 18:11:52 1214570512 pluto[4537]: |    Protocol ID: 0
Jun 27 18:11:52 1214570512 pluto[4537]: |    port: 0
Jun 27 18:11:52 1214570512 pluto[4537]: | ***parse ISAKMP
Identification Payload (IPsec DOI):
Jun 27 18:11:52 1214570512 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:11:52 1214570512 pluto[4537]: |    length: 16
Jun 27 18:11:52 1214570512 pluto[4537]: |    ID type: ID_IPV4_ADDR_SUBNET
Jun 27 18:11:52 1214570512 pluto[4537]: |    Protocol ID: 0
Jun 27 18:11:52 1214570512 pluto[4537]: |    port: 0
Jun 27 18:11:52 1214570512 pluto[4537]: | removing 4 bytes of padding
Jun 27 18:11:52 1214570512 pluto[4537]: | HASH(1) computed:
Jun 27 18:11:52 1214570512 pluto[4537]: |   82 18 35 a6  43 e6 e7 28
66 98 25 4c  14 26 05 39
Jun 27 18:11:52 1214570512 pluto[4537]: | peer client is 10.20.20.57
Jun 27 18:11:52 1214570512 pluto[4537]: | peer client protocol/port is 0/0
Jun 27 18:11:52 1214570512 pluto[4537]: | our client is subnet 20.20.20.0/24
Jun 27 18:11:52 1214570512 pluto[4537]: | our client protocol/port is 0/0
Jun 27 18:11:52 1214570512 pluto[4537]: | find_client_connection
starting with rw-1
Jun 27 18:11:52 1214570512 pluto[4537]: |   looking for
20.20.20.0/24:0/0 -> 10.20.20.57/32:0/0
Jun 27 18:11:52 1214570512 pluto[4537]: |   concrete checking against
sr#0 20.20.20.0/24 -> 10.20.20.57/32
Jun 27 18:11:52 1214570512 pluto[4537]: |    match_id a=0.0.0.0
Jun 27 18:11:52 1214570512 pluto[4537]: |             b=0.0.0.0
Jun 27 18:11:52 1214570512 pluto[4537]: |    results  matched
Jun 27 18:11:52 1214570512 pluto[4537]: |   trusted_ca called with
a=(empty) b=(empty)
Jun 27 18:11:52 1214570512 pluto[4537]: |   fc_try trying
rw-1:20.20.20.0/24:0/0 -> 10.20.20.57/32:0/0 vs rw-1:20.20.20.0/24:0/0
-> 10.20.20.57/32:0/0
Jun 27 18:11:52 1214570512 pluto[4537]: |   fc_try concluding with rw-1 [128]
Jun 27 18:11:52 1214570512 pluto[4537]: |   fc_try rw-1 gives rw-1
Jun 27 18:11:52 1214570512 pluto[4537]: |   concluding with d = rw-1
Jun 27 18:11:52 1214570512 pluto[4537]: | duplicating state object #77
Jun 27 18:11:52 1214570512 pluto[4537]: | creating state object #78 at 0x810c868
Jun 27 18:11:52 1214570512 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:11:52 1214570512 pluto[4537]: | ICOOKIE:  c0 ba 41 b2  8e 08 66 93
Jun 27 18:11:52 1214570512 pluto[4537]: | RCOOKIE:  d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:52 1214570512 pluto[4537]: | peer:  ac 10 01 97
Jun 27 18:11:52 1214570512 pluto[4537]: | state hash entry 18
Jun 27 18:11:52 1214570512 pluto[4537]: | inserting event
EVENT_SO_DISCARD, timeout in 0 seconds for #78
Jun 27 18:11:52 1214570512 pluto[4537]: | NAT-T: new mapping
172.16.1.151:500/4500)
Jun 27 18:11:52 1214570512 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:11:52 1214570512 last message repeated 3 times
Jun 27 18:11:52 1214570512 pluto[4537]: | NAT-T: updating local port to 4500
Jun 27 18:11:52 1214570512 pluto[4537]: | NAT-T connection has wrong
interface definition 172.16.2.115:4500 vs 172.16.2.115:500
Jun 27 18:11:52 1214570512 pluto[4537]: | NAT-T: using interface eth1:4500
Jun 27 18:11:52 1214570512 pluto[4537]: | NAT-Traversal: received 0 NAT-OA.
Jun 27 18:11:52 1214570512 pluto[4537]: | ****parse IPsec DOI SIT:
Jun 27 18:11:52 1214570512 pluto[4537]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Jun 27 18:11:52 1214570512 pluto[4537]: | ****parse ISAKMP Proposal Payload:
Jun 27 18:11:52 1214570512 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:11:52 1214570512 pluto[4537]: |    length: 40
Jun 27 18:11:52 1214570512 pluto[4537]: |    proposal number: 1
Jun 27 18:11:52 1214570512 pluto[4537]: |    protocol ID: PROTO_IPSEC_ESP
Jun 27 18:11:52 1214570512 pluto[4537]: |    SPI size: 4
Jun 27 18:11:52 1214570512 pluto[4537]: |    number of transforms: 1
Jun 27 18:11:52 1214570512 pluto[4537]: | parsing 4 raw bytes of
ISAKMP Proposal Payload into SPI
Jun 27 18:11:52 1214570512 pluto[4537]: | SPI  b0 74 c8 8e
Jun 27 18:11:52 1214570512 pluto[4537]: | *****parse ISAKMP Transform
Payload (ESP):
Jun 27 18:11:52 1214570512 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:11:52 1214570512 pluto[4537]: |    length: 28
Jun 27 18:11:52 1214570512 pluto[4537]: |    transform number: 1
Jun 27 18:11:52 1214570512 pluto[4537]: |    transform ID: ESP_3DES
Jun 27 18:11:52 1214570512 pluto[4537]: | ******parse ISAKMP IPsec DOI
attribute:
Jun 27 18:11:52 1214570512 pluto[4537]: |    af+type: SA_LIFE_TYPE
Jun 27 18:11:52 1214570512 pluto[4537]: |    length/value: 1
Jun 27 18:11:52 1214570512 pluto[4537]: |    [1 is SA_LIFE_TYPE_SECONDS]
Jun 27 18:11:52 1214570512 pluto[4537]: | ******parse ISAKMP IPsec DOI
attribute:
Jun 27 18:11:52 1214570512 pluto[4537]: |    af+type: SA_LIFE_DURATION
Jun 27 18:11:52 1214570512 pluto[4537]: |    length/value: 3600
Jun 27 18:11:52 1214570512 pluto[4537]: | ******parse ISAKMP IPsec DOI
attribute:
Jun 27 18:11:52 1214570512 pluto[4537]: |    af+type: ENCAPSULATION_MODE
Jun 27 18:11:52 1214570512 pluto[4537]: |    length/value: 61443
Jun 27 18:11:52 1214570512 pluto[4537]: |    [61443 is
ENCAPSULATION_MODE_UDP_TUNNEL]
Jun 27 18:11:52 1214570512 pluto[4537]: | ******parse ISAKMP IPsec DOI
attribute:
Jun 27 18:11:52 1214570512 pluto[4537]: |    af+type: AUTH_ALGORITHM
Jun 27 18:11:52 1214570512 pluto[4537]: |    length/value: 1
Jun 27 18:11:52 1214570512 pluto[4537]: |    [1 is AUTH_ALGORITHM_HMAC_MD5]
Jun 27 18:11:52 1214570512 pluto[4537]: | ******parse ISAKMP IPsec DOI
attribute:
Jun 27 18:11:52 1214570512 pluto[4537]: |    af+type: GROUP_DESCRIPTION
Jun 27 18:11:52 1214570512 pluto[4537]: |    length/value: 2
Jun 27 18:11:52 1214570512 pluto[4537]: |    [2 is OAKLEY_GROUP_MODP1024]
Jun 27 18:11:52 1214570512 pluto[4537]: | kernel_alg_esp_enc_ok(3,0):
alg_id=3, alg_ivlen=64, alg_minbits=192, alg_maxbits=192, res=0, ret=1
Jun 27 18:11:52 1214570512 pluto[4537]: |
kernel_alg_esp_enc_keylen():alg_id=3, keylen=24
Jun 27 18:11:52 1214570512 pluto[4537]: | DH public value received:
Jun 27 18:11:52 1214570512 pluto[4537]: |   48 b2 54 95  5e 5f f8 ba
e0 82 27 20  d1 c9 ae 3a
Jun 27 18:11:52 1214570512 pluto[4537]: |   14 bf 09 41  06 c9 be 37
bc 11 e9 f6  3b 0a 66 38
Jun 27 18:11:52 1214570512 pluto[4537]: |   e7 70 bb 52  4e 50 7a f0
5c 57 0b db  3b d9 aa 88
Jun 27 18:11:52 1214570512 pluto[4537]: |   d2 d4 86 a2  b1 6e a6 4f
45 42 b7 e1  f2 0d 11 b4
Jun 27 18:11:52 1214570512 pluto[4537]: |   4f 65 df 85  be e9 0b 38
fd 1f b7 2a  a5 e5 b8 8e
Jun 27 18:11:52 1214570512 pluto[4537]: |   58 86 f2 c3  56 c5 08 e8
76 e6 8a cb  47 f2 fe 1b
Jun 27 18:11:52 1214570512 pluto[4537]: |   74 11 57 a1  70 07 13 b0
66 70 84 1a  bb 6b ae ec
Jun 27 18:11:52 1214570512 pluto[4537]: |   e6 15 34 d0  b5 51 b8 7f
6e 5a 2a bc  47 f9 a7 5d
Jun 27 18:11:52 1214570512 pluto[4537]: | helper -1 doing build_kenonce op id: 0
Jun 27 18:11:52 1214570512 pluto[4537]: | Local DH secret:
Jun 27 18:11:52 1214570512 pluto[4537]: |   25 0a de 51  2b fa 18 9e
b9 e5 4e 62  79 44 0b 7f
Jun 27 18:11:52 1214570512 pluto[4537]: |   cf 5f 30 60  d2 01 00 3c
e4 3d 8a fc  bf 2e 47 6c
Jun 27 18:11:52 1214570512 pluto[4537]: | Public DH value sent:
Jun 27 18:11:52 1214570512 pluto[4537]: |   94 c7 2d 6b  51 ae 5b db
3c 46 67 25  d4 d4 9a 0f
Jun 27 18:11:52 1214570512 pluto[4537]: |   c0 d1 52 f5  45 58 4e 30
02 48 ab 24  17 6c 94 ee
Jun 27 18:11:52 1214570512 pluto[4537]: |   6a e6 bf 14  83 d2 21 80
41 dc bc c5  5a c7 0d 2a
Jun 27 18:11:52 1214570512 pluto[4537]: |   65 af 96 ec  e2 3d 92 c3
a1 86 fd ad  ad dd a9 f5
Jun 27 18:11:52 1214570512 pluto[4537]: |   09 c1 f2 93  e1 5e f6 55
2f ed 80 d3  63 d7 4d 83
Jun 27 18:11:52 1214570512 pluto[4537]: |   38 35 2b db  43 b1 c6 57
17 18 c8 cc  37 69 ef a0
Jun 27 18:11:52 1214570512 pluto[4537]: |   c9 db 94 e2  7c 8d fe 93
00 80 4f 59  9f ce 74 ef
Jun 27 18:11:52 1214570512 pluto[4537]: |   98 90 ab fe  b4 95 01 56
e0 b2 d2 24  40 62 e9 e1
Jun 27 18:11:52 1214570512 pluto[4537]: | Generated nonce:
Jun 27 18:11:52 1214570512 pluto[4537]: |   16 66 81 de  30 06 a7 b1
ff db ae f2  b6 96 ff 27
Jun 27 18:11:52 1214570512 pluto[4537]: | quick inI1_outR1: calculated
ke+nonce, sending R1
Jun 27 18:11:52 1214570512 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:11:52 1214570512 pluto[4537]: | **emit ISAKMP Message:
Jun 27 18:11:52 1214570512 pluto[4537]: |    initiator cookie:
Jun 27 18:11:52 1214570512 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
Jun 27 18:11:52 1214570512 pluto[4537]: |    responder cookie:
Jun 27 18:11:52 1214570512 pluto[4537]: |   d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:53 1214570513 pluto[4537]: |    next payload type: ISAKMP_NEXT_HASH
Jun 27 18:11:53 1214570513 pluto[4537]: |    ISAKMP version: ISAKMP Version 1.0
Jun 27 18:11:53 1214570513 pluto[4537]: |    exchange type: ISAKMP_XCHG_QUICK
Jun 27 18:11:53 1214570513 pluto[4537]: |    flags: ISAKMP_FLAG_ENCRYPTION
Jun 27 18:11:53 1214570513 pluto[4537]: |    message ID:  66 d4 4d 99
Jun 27 18:11:53 1214570513 pluto[4537]: | ***emit ISAKMP Hash Payload:
Jun 27 18:11:53 1214570513 pluto[4537]: |    next payload type: ISAKMP_NEXT_SA
Jun 27 18:11:53 1214570513 pluto[4537]: | emitting 16 zero bytes of
HASH into ISAKMP Hash Payload
Jun 27 18:11:53 1214570513 pluto[4537]: | emitting length of ISAKMP
Hash Payload: 20
Jun 27 18:11:53 1214570513 pluto[4537]: | ***emit ISAKMP Security
Association Payload:
Jun 27 18:11:53 1214570513 pluto[4537]: |    next payload type:
ISAKMP_NEXT_NONCE
Jun 27 18:11:53 1214570513 pluto[4537]: |    DOI: ISAKMP_DOI_IPSEC
Jun 27 18:11:53 1214570513 pluto[4537]: | ****parse IPsec DOI SIT:
Jun 27 18:11:53 1214570513 pluto[4537]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Jun 27 18:11:53 1214570513 pluto[4537]: | ****parse ISAKMP Proposal Payload:
Jun 27 18:11:53 1214570513 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:11:53 1214570513 pluto[4537]: |    length: 40
Jun 27 18:11:53 1214570513 pluto[4537]: |    proposal number: 1
Jun 27 18:11:53 1214570513 pluto[4537]: |    protocol ID: PROTO_IPSEC_ESP
Jun 27 18:11:53 1214570513 pluto[4537]: |    SPI size: 4
Jun 27 18:11:53 1214570513 pluto[4537]: |    number of transforms: 1
Jun 27 18:11:53 1214570513 pluto[4537]: | parsing 4 raw bytes of
ISAKMP Proposal Payload into SPI
Jun 27 18:11:53 1214570513 pluto[4537]: | SPI  b0 74 c8 8e
Jun 27 18:11:53 1214570513 pluto[4537]: | *****parse ISAKMP Transform
Payload (ESP):
Jun 27 18:11:53 1214570513 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:11:53 1214570513 pluto[4537]: |    length: 28
Jun 27 18:11:53 1214570513 pluto[4537]: |    transform number: 1
Jun 27 18:11:53 1214570513 pluto[4537]: |    transform ID: ESP_3DES
Jun 27 18:11:53 1214570513 pluto[4537]: | ******parse ISAKMP IPsec DOI
attribute:
Jun 27 18:11:53 1214570513 pluto[4537]: |    af+type: SA_LIFE_TYPE
Jun 27 18:11:53 1214570513 pluto[4537]: |    length/value: 1
Jun 27 18:11:53 1214570513 pluto[4537]: |    [1 is SA_LIFE_TYPE_SECONDS]
Jun 27 18:11:53 1214570513 pluto[4537]: | ******parse ISAKMP IPsec DOI
attribute:
Jun 27 18:11:53 1214570513 pluto[4537]: |    af+type: SA_LIFE_DURATION
Jun 27 18:11:53 1214570513 pluto[4537]: |    length/value: 3600
Jun 27 18:11:53 1214570513 pluto[4537]: | ******parse ISAKMP IPsec DOI
attribute:
Jun 27 18:11:53 1214570513 pluto[4537]: |    af+type: ENCAPSULATION_MODE
Jun 27 18:11:53 1214570513 pluto[4537]: |    length/value: 61443
Jun 27 18:11:53 1214570513 pluto[4537]: |    [61443 is
ENCAPSULATION_MODE_UDP_TUNNEL]
Jun 27 18:11:53 1214570513 pluto[4537]: | ******parse ISAKMP IPsec DOI
attribute:
Jun 27 18:11:53 1214570513 pluto[4537]: |    af+type: AUTH_ALGORITHM
Jun 27 18:11:53 1214570513 pluto[4537]: |    length/value: 1
Jun 27 18:11:53 1214570513 pluto[4537]: |    [1 is AUTH_ALGORITHM_HMAC_MD5]
Jun 27 18:11:53 1214570513 pluto[4537]: | ******parse ISAKMP IPsec DOI
attribute:
Jun 27 18:11:53 1214570513 pluto[4537]: |    af+type: GROUP_DESCRIPTION
Jun 27 18:11:53 1214570513 pluto[4537]: |    length/value: 2
Jun 27 18:11:53 1214570513 pluto[4537]: |    [2 is OAKLEY_GROUP_MODP1024]
Jun 27 18:11:53 1214570513 pluto[4537]: | kernel_alg_esp_enc_ok(3,0):
alg_id=3, alg_ivlen=64, alg_minbits=192, alg_maxbits=192, res=0, ret=1
Jun 27 18:11:53 1214570513 pluto[4537]: |
kernel_alg_esp_enc_keylen():alg_id=3, keylen=24
Jun 27 18:11:53 1214570513 pluto[4537]: | ****emit IPsec DOI SIT:
Jun 27 18:11:53 1214570513 pluto[4537]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Jun 27 18:11:53 1214570513 pluto[4537]: | ****emit ISAKMP Proposal Payload:
Jun 27 18:11:53 1214570513 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:11:53 1214570513 pluto[4537]: |    proposal number: 1
Jun 27 18:11:53 1214570513 pluto[4537]: |    protocol ID: PROTO_IPSEC_ESP
Jun 27 18:11:53 1214570513 pluto[4537]: |    SPI size: 4
Jun 27 18:11:53 1214570513 pluto[4537]: |    number of transforms: 1
Jun 27 18:11:53 1214570513 pluto[4537]: | generate SPI:  9e c1 22 56
Jun 27 18:11:53 1214570513 pluto[4537]: | emitting 4 raw bytes of SPI
into ISAKMP Proposal Payload
Jun 27 18:11:53 1214570513 pluto[4537]: | SPI  9e c1 22 56
Jun 27 18:11:53 1214570513 pluto[4537]: | *****emit ISAKMP Transform
Payload (ESP):
Jun 27 18:11:53 1214570513 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:11:53 1214570513 pluto[4537]: |    transform number: 1
Jun 27 18:11:53 1214570513 pluto[4537]: |    transform ID: ESP_3DES
Jun 27 18:11:53 1214570513 pluto[4537]: | emitting 20 raw bytes of
attributes into ISAKMP Transform Payload (ESP)
Jun 27 18:11:53 1214570513 pluto[4537]: | attributes  80 01 00 01  80
02 0e 10  80 04 f0 03  80 05 00 01
Jun 27 18:11:53 1214570513 pluto[4537]: |   80 03 00 02
Jun 27 18:11:53 1214570513 pluto[4537]: | emitting length of ISAKMP
Transform Payload (ESP): 28
Jun 27 18:11:53 1214570513 pluto[4537]: | emitting length of ISAKMP
Proposal Payload: 40
Jun 27 18:11:53 1214570513 pluto[4537]: | emitting length of ISAKMP
Security Association Payload: 52
Jun 27 18:11:53 1214570513 pluto[4537]: "rw-1"[4] 172.16.1.151 #78:
responding to Quick Mode {msgid:994dd466}
Jun 27 18:11:53 1214570513 pluto[4537]: | ***emit ISAKMP Nonce Payload:
Jun 27 18:11:53 1214570513 pluto[4537]: |    next payload type: ISAKMP_NEXT_KE
Jun 27 18:11:53 1214570513 pluto[4537]: | emitting 16 raw bytes of Nr
into ISAKMP Nonce Payload
Jun 27 18:11:53 1214570513 pluto[4537]: | Nr  16 66 81 de  30 06 a7 b1
 ff db ae f2  b6 96 ff 27
Jun 27 18:11:53 1214570513 pluto[4537]: | emitting length of ISAKMP
Nonce Payload: 20
Jun 27 18:11:53 1214570513 pluto[4537]: | ***emit ISAKMP Key Exchange Payload:
Jun 27 18:11:53 1214570513 pluto[4537]: |    next payload type: ISAKMP_NEXT_ID
Jun 27 18:11:53 1214570513 pluto[4537]: | emitting 128 raw bytes of
keyex value into ISAKMP Key Exchange Payload
Jun 27 18:11:53 1214570513 pluto[4537]: | keyex value  94 c7 2d 6b  51
ae 5b db  3c 46 67 25  d4 d4 9a 0f
Jun 27 18:11:53 1214570513 pluto[4537]: |   c0 d1 52 f5  45 58 4e 30
02 48 ab 24  17 6c 94 ee
Jun 27 18:11:53 1214570513 pluto[4537]: |   6a e6 bf 14  83 d2 21 80
41 dc bc c5  5a c7 0d 2a
Jun 27 18:11:53 1214570513 pluto[4537]: |   65 af 96 ec  e2 3d 92 c3
a1 86 fd ad  ad dd a9 f5
Jun 27 18:11:53 1214570513 pluto[4537]: |   09 c1 f2 93  e1 5e f6 55
2f ed 80 d3  63 d7 4d 83
Jun 27 18:11:53 1214570513 pluto[4537]: |   38 35 2b db  43 b1 c6 57
17 18 c8 cc  37 69 ef a0
Jun 27 18:11:53 1214570513 pluto[4537]: |   c9 db 94 e2  7c 8d fe 93
00 80 4f 59  9f ce 74 ef
Jun 27 18:11:53 1214570513 pluto[4537]: |   98 90 ab fe  b4 95 01 56
e0 b2 d2 24  40 62 e9 e1
Jun 27 18:11:53 1214570513 pluto[4537]: | emitting length of ISAKMP
Key Exchange Payload: 132
Jun 27 18:11:53 1214570513 pluto[4537]: | started looking for secret
for 172.16.2.115->0.0.0.0 of kind PPK_PSK
Jun 27 18:11:53 1214570513 pluto[4537]: | replace him to 0.0.0.0
Jun 27 18:11:53 1214570513 pluto[4537]: | actually looking for secret
for 172.16.2.115->0.0.0.0 of kind PPK_PSK
Jun 27 18:11:53 1214570513 pluto[4537]: | 1: compared PSK 0.0.0.0 to
172.16.2.115 / 0.0.0.0 -> 2
Jun 27 18:11:53 1214570513 pluto[4537]: | 2: compared PSK 172.16.2.115
to 172.16.2.115 / 0.0.0.0 -> 6
Jun 27 18:11:53 1214570513 pluto[4537]: | best_match 0>6 best=0x8106e48 (line=7)
Jun 27 18:11:53 1214570513 pluto[4537]: | concluding with best_match=6
best=0x8106e48 (lineno=7)
Jun 27 18:11:53 1214570513 pluto[4537]: | calc_dh_shared(): time
elapsed (OAKLEY_GROUP_MODP1024): 8960 usec
Jun 27 18:11:53 1214570513 pluto[4537]: | DH shared secret:
Jun 27 18:11:53 1214570513 pluto[4537]: |   a2 3c c7 f0  0d c7 29 23
c7 e0 fb 49  3a 99 f0 72
Jun 27 18:11:53 1214570513 pluto[4537]: |   5c af e9 9e  6e f8 ea 62
65 bc 7a bb  f7 74 c9 6b
Jun 27 18:11:53 1214570513 pluto[4537]: |   90 21 48 3c  f6 e8 6c aa
b3 dd c2 47  f1 a8 c4 83
Jun 27 18:11:53 1214570513 pluto[4537]: |   d5 dd 0d 32  6b a9 ef 27
de fd d3 cb  57 6c 04 7f
Jun 27 18:11:53 1214570513 pluto[4537]: |   3f 38 8f f8  7c 44 1f 72
d7 4c e9 7a  01 81 2a 95
Jun 27 18:11:53 1214570513 pluto[4537]: |   cb 17 5a 3a  95 b7 96 fd
f4 46 64 d4  a0 6a 69 27
Jun 27 18:11:53 1214570513 pluto[4537]: |   d7 59 5a 5f  f3 8e a6 6a
29 8b 4e be  b4 92 8e b7
Jun 27 18:11:53 1214570513 pluto[4537]: |   89 fa ac a3  0b a7 cb 77
2f 39 b3 56  ce 59 7c 57
Jun 27 18:11:53 1214570513 pluto[4537]: | emitting 12 raw bytes of
IDci into ISAKMP Message
Jun 27 18:11:53 1214570513 pluto[4537]: | IDci  05 00 00 0c  01 00 00
00  0a 14 14 39
Jun 27 18:11:53 1214570513 pluto[4537]: | emitting 16 raw bytes of
IDcr into ISAKMP Message
Jun 27 18:11:53 1214570513 pluto[4537]: | IDcr  00 00 00 10  04 00 00
00  14 14 14 00  ff ff ff 00
Jun 27 18:11:53 1214570513 pluto[4537]: | HASH(2) computed:
Jun 27 18:11:53 1214570513 pluto[4537]: |   64 e8 9a e3  a7 a8 9c 3f
c7 2e d0 f5  70 67 92 30
Jun 27 18:11:53 1214570513 pluto[4537]: |
compute_proto_keymat:needed_len (after ESP enc)=24
Jun 27 18:11:53 1214570513 pluto[4537]: |
compute_proto_keymat:needed_len (after ESP auth)=40
Jun 27 18:11:53 1214570513 pluto[4537]: | KEYMAT computed:
Jun 27 18:11:53 1214570513 pluto[4537]: |   ae fa a1 0e  a0 af c6 49
a7 71 d5 42  2c aa a0 bb
Jun 27 18:11:53 1214570513 pluto[4537]: |   8b 80 d7 dc  d3 f0 1c 71
bc 4d fb 59  19 7d ee ea
Jun 27 18:11:53 1214570513 pluto[4537]: |   92 76 c9 85  1e 25 f7 9f
Jun 27 18:11:53 1214570513 pluto[4537]: | Peer KEYMAT computed:
Jun 27 18:11:53 1214570513 pluto[4537]: |   fe 22 e5 60  19 a2 93 d9
e9 0e 58 21  9f de 4c 11
Jun 27 18:11:53 1214570513 pluto[4537]: |   bf d0 31 85  08 68 9c ef
5d 98 7d 6d  9d ca ab da
Jun 27 18:11:53 1214570513 pluto[4537]: |   2d 4d 01 a0  4b 43 da 6d
Jun 27 18:11:53 1214570513 pluto[4537]: | route owner of "rw-1"[4]
172.16.1.151 unrouted: NULL
Jun 27 18:11:53 1214570513 pluto[4537]: | install_inbound_ipsec_sa()
checking if we can route
Jun 27 18:11:53 1214570513 pluto[4537]: | route owner of "rw-1"[4]
172.16.1.151 unrouted: NULL; eroute owner: NULL
Jun 27 18:11:53 1214570513 pluto[4537]: | could_route called for rw-1
(kind=CK_INSTANCE)
Jun 27 18:11:53 1214570513 pluto[4537]: | pfkey_lib_debug:pfkey_msg_hdr_build:
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_hdr_build: on_entry &pfkey_ext=0p0xbff4e490
pfkey_ext=0p0xbff4e4f0 *pfkey_ext=0p(nil).
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_hdr_build: on_exit &pfkey_ext=0p0xbff4e490
pfkey_ext=0p0xbff4e4f0 *pfkey_ext=0p0x8107ab8.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_sa_build: spi=00001010 replay=0 sa_state=1
auth=0 encrypt=0 flags=0
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=5 proto=0 prefixlen=0
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=172.16.1.151:0.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=6 proto=0 prefixlen=0
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=172.16.2.115:0.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: pfkey_msg=0p0x8107b30 allocated 88
bytes, &(extensions[0])=0p0xbff4e4f0
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[1]
(type=1)
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[5]
(type=5)
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[6]
(type=6)
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: extensions permitted=78001ffb,
seen=00000063, required=00000063.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing message ver=2, type=3(add),
errno=0, satype=9(IPIP), len=11, res=0, seq=90, pid=4537.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: satype 9(IPIP) conversion to proto
gives 4 for msg_type 3(add).
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=9
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=78001ffb,
required=00000063.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=1(security-association) remain=9.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=9
ext_type=1(security-association) ext_len=3 parsing ext 0p0x8107b40
with parser pfkey_sa_parse.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_sa_parse: successfully found len=3
exttype=1(security-association) spi=00001010 replay=0 state=1 auth=0
encrypt=0 flags=0 ref=-1.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 1(security-association)
parsed.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=5(source-address)
remain=6.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=6 ext_type=5(source-address)
ext_len=3 parsing ext 0p0x8107b58 with parser pfkey_address_parse.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found exttype=5(source-address)
family=2(AF_INET) address=172.16.1.151 proto=0 port=0.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 5(source-address) parsed.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=6(destination-address) remain=3.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=3
ext_type=6(destination-address) ext_len=3 parsing ext 0p0x8107b70 with
parser pfkey_address_parse.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found
exttype=6(destination-address) family=2(AF_INET) address=172.16.2.115
proto=0 port=0.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 6(destination-address)
parsed.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=78001ffb,
seen=00000063, required=00000063.
Jun 27 18:11:53 1214570513 pluto[4537]: | finish_pfkey_msg: SADB_ADD
message 90 for Add SA tun.1010 at 172.16.1.151
Jun 27 18:11:53 1214570513 pluto[4537]: |   02 03 00 09  0b 00 00 00
5a 00 00 00  b9 11 00 00
Jun 27 18:11:53 1214570513 pluto[4537]: |   03 00 01 00  00 00 10 10
00 01 00 00  00 00 00 00
Jun 27 18:11:53 1214570513 pluto[4537]: |   ff ff ff ff  00 00 00 00
03 00 05 00  00 00 00 00
Jun 27 18:11:53 1214570513 pluto[4537]: |   02 00 00 00  ac 10 01 97
00 00 00 00  00 00 00 00
Jun 27 18:11:53 1214570513 pluto[4537]: |   03 00 06 00  00 00 00 00
02 00 00 00  ac 10 02 73
Jun 27 18:11:53 1214570513 pluto[4537]: |   00 00 00 00  00 00 00 00
Jun 27 18:11:53 1214570513 pluto[4537]: | pfkey_get: SADB_ADD message 90
Jun 27 18:11:53 1214570513 pluto[4537]: | looking for alg with
transid: 3 keylen: 0 auth: 1
Jun 27 18:11:53 1214570513 pluto[4537]: | checking transid: 11 keylen:
0 auth: 1
Jun 27 18:11:53 1214570513 pluto[4537]: | checking transid: 11 keylen:
0 auth: 2
Jun 27 18:11:53 1214570513 pluto[4537]: | checking transid: 2 keylen: 8 auth: 0
Jun 27 18:11:53 1214570513 pluto[4537]: | checking transid: 2 keylen: 8 auth: 1
Jun 27 18:11:53 1214570513 pluto[4537]: | checking transid: 2 keylen: 8 auth: 2
Jun 27 18:11:53 1214570513 pluto[4537]: | checking transid: 3 keylen:
24 auth: 0
Jun 27 18:11:53 1214570513 pluto[4537]: | checking transid: 3 keylen:
24 auth: 1
Jun 27 18:11:53 1214570513 pluto[4537]: | pfkey_lib_debug:pfkey_msg_hdr_build:
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_hdr_build: on_entry &pfkey_ext=0p0xbff4e490
pfkey_ext=0p0xbff4e4f0 *pfkey_ext=0p(nil).
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_hdr_build: on_exit &pfkey_ext=0p0xbff4e490
pfkey_ext=0p0xbff4e4f0 *pfkey_ext=0p0x8107ab8.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_sa_build: spi=9ec12256 replay=64 sa_state=1
auth=2 encrypt=3 flags=0
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=5 proto=0 prefixlen=0
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=172.16.1.151:0.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=6 proto=0 prefixlen=0
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=172.16.2.115:0.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:53 1214570513 pluto[4537]: | pfkey_lib_debug:pfkey_key_build:
Jun 27 18:11:53 1214570513 pluto[4537]: | pfkey_lib_debug:pfkey_key_build:
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_x_nat_t_type_build:
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_x_nat_t_type_build: type=2
Jun 27 18:11:53 1214570513 pluto[4537]: | setting natt_type to 2
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_x_nat_t_port_build:
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_x_nat_t_port_build: ext=28, port=4500
Jun 27 18:11:53 1214570513 pluto[4537]: | setting natt_sport to 4500
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_x_nat_t_port_build:
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_x_nat_t_port_build: ext=29, port=4500
Jun 27 18:11:53 1214570513 pluto[4537]: | setting natt_dport to 4500
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: pfkey_msg=0p0x8107b78 allocated 168
bytes, &(extensions[0])=0p0xbff4e4f0
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[1]
(type=1)
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[5]
(type=5)
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[6]
(type=6)
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[8]
(type=8)
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 32 bytes from extensions[9]
(type=9)
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 8 bytes from extensions[27]
(type=27)
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 8 bytes from extensions[28]
(type=28)
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 8 bytes from extensions[29]
(type=29)
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: extensions permitted=78001ffb,
seen=38000363, required=00000063.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing message ver=2, type=3(add),
errno=0, satype=3(ESP), len=21, res=0, seq=91, pid=4537.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: satype 3(ESP) conversion to proto
gives 50 for msg_type 3(add).
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=19
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=78001ffb,
required=00000063.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=1(security-association) remain=19.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=19
ext_type=1(security-association) ext_len=3 parsing ext 0p0x8107b88
with parser pfkey_sa_parse.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_sa_parse: successfully found len=3
exttype=1(security-association) spi=9ec12256 replay=64 state=1 auth=2
encrypt=3 flags=0 ref=-1.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 1(security-association)
parsed.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=5(source-address)
remain=16.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=16 ext_type=5(source-address)
ext_len=3 parsing ext 0p0x8107ba0 with parser pfkey_address_parse.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found exttype=5(source-address)
family=2(AF_INET) address=172.16.1.151 proto=0 port=0.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 5(source-address) parsed.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=6(destination-address) remain=13.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=13
ext_type=6(destination-address) ext_len=3 parsing ext 0p0x8107bb8 with
parser pfkey_address_parse.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found
exttype=6(destination-address) family=2(AF_INET) address=172.16.2.115
proto=0 port=0.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 6(destination-address)
parsed.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=8(authentication-key) remain=10.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=10
ext_type=8(authentication-key) ext_len=3 parsing ext 0p0x8107bd0 with
parser pfkey_key_parse.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_key_parse: success, found len=3
exttype=8(authentication-key) bits=128 reserved=0.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 8(authentication-key)
parsed.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=9(cipher-key)
remain=7.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=7 ext_type=9(cipher-key)
ext_len=4 parsing ext 0p0x8107be8 with parser pfkey_key_parse.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_key_parse: success, found len=4
exttype=9(cipher-key) bits=192 reserved=0.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 9(cipher-key) parsed.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=27(X-NAT-T-sport)
remain=3.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=3 ext_type=27(X-NAT-T-sport)
ext_len=1 parsing ext 0p0x8107c08 with parser
pfkey_x_ext_nat_t_type_parse.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 27(X-NAT-T-sport) parsed.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=28(X-NAT-T-dport)
remain=2.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=2 ext_type=28(X-NAT-T-dport)
ext_len=1 parsing ext 0p0x8107c10 with parser
pfkey_x_ext_nat_t_port_parse.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 28(X-NAT-T-dport) parsed.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=29(X-NAT-T-OA)
remain=1.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=1 ext_type=29(X-NAT-T-OA)
ext_len=1 parsing ext 0p0x8107c18 with parser
pfkey_x_ext_nat_t_port_parse.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 29(X-NAT-T-OA) parsed.
Jun 27 18:11:53 1214570513 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=78001ffb,
seen=38000363, required=00000063.
Jun 27 18:11:53 1214570513 pluto[4537]: | finish_pfkey_msg: SADB_ADD
message 91 for Add SA esp.9ec12256 at 172.16.2.115
Jun 27 18:11:53 1214570513 pluto[4537]: |   02 03 00 03  15 00 00 00
5b 00 00 00  b9 11 00 00
Jun 27 18:11:54 1214570514 pluto[4537]: |   03 00 01 00  9e c1 22 56
40 01 02 03  00 00 00 00
Jun 27 18:11:54 1214570514 pluto[4537]: |   ff ff ff ff  00 00 00 00
03 00 05 00  00 00 00 00
Jun 27 18:11:54 1214570514 pluto[4537]: |   02 00 00 00  ac 10 01 97
00 00 00 00  00 00 00 00
Jun 27 18:11:54 1214570514 pluto[4537]: |   03 00 06 00  00 00 00 00
02 00 00 00  ac 10 02 73
Jun 27 18:11:54 1214570514 pluto[4537]: |   00 00 00 00  00 00 00 00
03 00 08 00  80 00 00 00
Jun 27 18:11:54 1214570514 pluto[4537]: |   bc 4d fb 59  19 7d ee ea
92 76 c9 85  1e 25 f7 9f
Jun 27 18:11:54 1214570514 pluto[4537]: |   04 00 09 00  c0 00 00 00
ae fa a1 0e  a0 af c6 49
Jun 27 18:11:54 1214570514 pluto[4537]: |   a7 71 d5 42  2c aa a0 bb
8b 80 d7 dc  d3 f0 1c 71
Jun 27 18:11:54 1214570514 pluto[4537]: |   01 00 1b 00  02 00 00 00
01 00 1c 00  94 11 00 00
Jun 27 18:11:54 1214570514 pluto[4537]: |   01 00 1d 00  94 11 00 00
Jun 27 18:11:54 1214570514 pluto[4537]: | pfkey_get: SADB_ADD message 91
Jun 27 18:11:54 1214570514 pluto[4537]: | add inbound eroute
10.20.20.57/32:0 --0-> 20.20.20.0/24:0 => tun.1010 at 172.16.2.115
(raw_eroute)
Jun 27 18:11:54 1214570514 pluto[4537]: | pfkey_lib_debug:pfkey_msg_hdr_build:
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_hdr_build: on_entry &pfkey_ext=0p0xbff4e270
pfkey_ext=0p0xbff4e360 *pfkey_ext=0p(nil).
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_hdr_build: on_exit &pfkey_ext=0p0xbff4e270
pfkey_ext=0p0xbff4e360 *pfkey_ext=0p0x8107ab8.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_sa_build: spi=00001010 replay=0 sa_state=0
auth=0 encrypt=0 flags=8
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=5 proto=0 prefixlen=0
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=172.16.1.151:0.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=6 proto=0 prefixlen=0
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=172.16.2.115:0.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=21 proto=0 prefixlen=0
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=10.20.20.57:0.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=22 proto=0 prefixlen=0
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=20.20.20.0:0.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=23 proto=0 prefixlen=0
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=255.255.255.255:0.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=24 proto=0 prefixlen=0
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=255.255.255.0:0.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: pfkey_msg=0p0x8107bb0 allocated 184
bytes, &(extensions[0])=0p0xbff4e360
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[1]
(type=1)
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[5]
(type=5)
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[6]
(type=6)
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[21]
(type=21)
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[22]
(type=22)
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[23]
(type=23)
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[24]
(type=24)
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: extensions permitted=05e00c63,
seen=01e00063, required=01e00043.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing message ver=2,
type=14(x-addflow(eroute)), errno=0, satype=9(IPIP), len=23, res=0,
seq=92, pid=4537.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: satype 9(IPIP) conversion to proto
gives 4 for msg_type 14(x-addflow(eroute)).
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=21
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=05e00c63,
required=01e00043.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=1(security-association) remain=21.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=21
ext_type=1(security-association) ext_len=3 parsing ext 0p0x8107bc0
with parser pfkey_sa_parse.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_sa_parse: successfully found len=3
exttype=1(security-association) spi=00001010 replay=0 state=0 auth=0
encrypt=0 flags=8 ref=-1.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 1(security-association)
parsed.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=5(source-address)
remain=18.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=18 ext_type=5(source-address)
ext_len=3 parsing ext 0p0x8107bd8 with parser pfkey_address_parse.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found exttype=5(source-address)
family=2(AF_INET) address=172.16.1.151 proto=0 port=0.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 5(source-address) parsed.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=6(destination-address) remain=15.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=15
ext_type=6(destination-address) ext_len=3 parsing ext 0p0x8107bf0 with
parser pfkey_address_parse.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found
exttype=6(destination-address) family=2(AF_INET) address=172.16.2.115
proto=0 port=0.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 6(destination-address)
parsed.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=21(X-source-flow-address) remain=12.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=12
ext_type=21(X-source-flow-address) ext_len=3 parsing ext 0p0x8107c08
with parser pfkey_address_parse.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found
exttype=21(X-source-flow-address) family=2(AF_INET)
address=10.20.20.57 proto=0 port=0.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 21(X-source-flow-address)
parsed.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=22(X-dest-flow-address) remain=9.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=9
ext_type=22(X-dest-flow-address) ext_len=3 parsing ext 0p0x8107c20
with parser pfkey_address_parse.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found
exttype=22(X-dest-flow-address) family=2(AF_INET) address=20.20.20.0
proto=0 port=0.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 22(X-dest-flow-address)
parsed.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=23(X-source-mask)
remain=6.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=6 ext_type=23(X-source-mask)
ext_len=3 parsing ext 0p0x8107c38 with parser pfkey_address_parse.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found exttype=23(X-source-mask)
family=2(AF_INET) address=255.255.255.255 proto=0 port=0.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 23(X-source-mask) parsed.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=24(X-dest-mask)
remain=3.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=3 ext_type=24(X-dest-mask)
ext_len=3 parsing ext 0p0x8107c50 with parser pfkey_address_parse.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found exttype=24(X-dest-mask)
family=2(AF_INET) address=255.255.255.0 proto=0 port=0.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 24(X-dest-mask) parsed.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=05e00c63,
seen=01e00063, required=01e00043.
Jun 27 18:11:54 1214570514 pluto[4537]: | finish_pfkey_msg:
SADB_X_ADDFLOW message 92 for flow tun.1010 at 172.16.2.115
Jun 27 18:11:54 1214570514 pluto[4537]: |   02 0e 00 09  17 00 00 00
5c 00 00 00  b9 11 00 00
Jun 27 18:11:54 1214570514 pluto[4537]: |   03 00 01 00  00 00 10 10
00 00 00 00  08 00 00 00
Jun 27 18:11:54 1214570514 pluto[4537]: |   ff ff ff ff  00 00 00 00
03 00 05 00  00 00 00 00
Jun 27 18:11:54 1214570514 pluto[4537]: |   02 00 00 00  ac 10 01 97
00 00 00 00  00 00 00 00
Jun 27 18:11:54 1214570514 pluto[4537]: |   03 00 06 00  00 00 00 00
02 00 00 00  ac 10 02 73
Jun 27 18:11:54 1214570514 pluto[4537]: |   00 00 00 00  00 00 00 00
03 00 15 00  00 00 00 00
Jun 27 18:11:54 1214570514 pluto[4537]: |   02 00 00 00  0a 14 14 39
b8 f3 f4 bf  c4 d2 09 08
Jun 27 18:11:54 1214570514 pluto[4537]: |   03 00 16 00  00 00 00 00
02 00 00 00  14 14 14 00
Jun 27 18:11:54 1214570514 pluto[4537]: |   b8 2d cb bf  aa 79 f3 b7
03 00 17 00  00 00 00 00
Jun 27 18:11:54 1214570514 pluto[4537]: |   02 00 00 00  ff ff ff ff
ff e3 35 37  79 e3 f4 bf
Jun 27 18:11:54 1214570514 pluto[4537]: |   03 00 18 00  00 00 00 00
02 00 00 00  ff ff ff 00
Jun 27 18:11:54 1214570514 pluto[4537]: |   28 e3 f4 bf  da 66 0a 08
Jun 27 18:11:54 1214570514 pluto[4537]: | pfkey_get: SADB_X_ADDFLOW message 92
Jun 27 18:11:54 1214570514 pluto[4537]: | grouping
unk0.9ec12256 at 172.16.2.115 and unk0.1010 at 172.16.2.115
Jun 27 18:11:54 1214570514 pluto[4537]: | pfkey_lib_debug:pfkey_msg_hdr_build:
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_hdr_build: on_entry &pfkey_ext=0p0xbff4e480
pfkey_ext=0p0xbff4e4f0 *pfkey_ext=0p(nil).
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_hdr_build: on_exit &pfkey_ext=0p0xbff4e480
pfkey_ext=0p0xbff4e4f0 *pfkey_ext=0p0x8107ab8.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_sa_build: spi=00001010 replay=0 sa_state=0
auth=0 encrypt=0 flags=0
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=6 proto=0 prefixlen=0
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=172.16.2.115:0.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:54 1214570514 pluto[4537]: | pfkey_lib_debug:pfkey_x_satype_build:
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_sa_build: spi=9ec12256 replay=0 sa_state=0
auth=0 encrypt=0 flags=0
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=20 proto=0 prefixlen=0
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=172.16.2.115:0.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: pfkey_msg=0p0x8107b50 allocated 120
bytes, &(extensions[0])=0p0xbff4e4f0
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[1]
(type=1)
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[6]
(type=6)
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 8 bytes from extensions[18]
(type=18)
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[19]
(type=19)
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[20]
(type=20)
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: extensions permitted=001c0043,
seen=001c0043, required=00000043.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing message ver=2,
type=13(x-groupsa), errno=0, satype=9(IPIP), len=15, res=0, seq=93,
pid=4537.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: satype 9(IPIP) conversion to proto
gives 4 for msg_type 13(x-groupsa).
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=13
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=001c0043,
required=00000043.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=1(security-association) remain=13.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=13
ext_type=1(security-association) ext_len=3 parsing ext 0p0x8107b60
with parser pfkey_sa_parse.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_sa_parse: successfully found len=3
exttype=1(security-association) spi=00001010 replay=0 state=0 auth=0
encrypt=0 flags=0 ref=-1.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 1(security-association)
parsed.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=6(destination-address) remain=10.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=10
ext_type=6(destination-address) ext_len=3 parsing ext 0p0x8107b78 with
parser pfkey_address_parse.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found
exttype=6(destination-address) family=2(AF_INET) address=172.16.2.115
proto=0 port=0.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 6(destination-address)
parsed.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=18(X-satype2)
remain=7.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=7 ext_type=18(X-satype2)
ext_len=1 parsing ext 0p0x8107b90 with parser pfkey_x_satype_parse.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_x_satype_parse: enter
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_x_satype_parse: len=1 ext=18(X-satype2)
satype=3(ESP) res=0,0,0.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 18(X-satype2) parsed.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=19(X-security-association) remain=6.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=6
ext_type=19(X-security-association) ext_len=3 parsing ext 0p0x8107b98
with parser pfkey_sa_parse.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_sa_parse: successfully found len=3
exttype=19(X-security-association) spi=9ec12256 replay=0 state=0
auth=0 encrypt=0 flags=0 ref=-1.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 19(X-security-association)
parsed.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=20(X-destination-address2) remain=3.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=3
ext_type=20(X-destination-address2) ext_len=3 parsing ext 0p0x8107bb0
with parser pfkey_address_parse.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found
exttype=20(X-destination-address2) family=2(AF_INET)
address=172.16.2.115 proto=0 port=0.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 20(X-destination-address2)
parsed.
Jun 27 18:11:54 1214570514 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=001c0043,
seen=001c0043, required=00000043.
Jun 27 18:11:54 1214570514 pluto[4537]: | finish_pfkey_msg:
SADB_X_GRPSA message 93 for group unk0.1010 at 172.16.2.115
Jun 27 18:11:54 1214570514 pluto[4537]: |   02 0d 00 09  0f 00 00 00
5d 00 00 00  b9 11 00 00
Jun 27 18:11:54 1214570514 pluto[4537]: |   03 00 01 00  00 00 10 10
00 00 00 00  00 00 00 00
Jun 27 18:11:54 1214570514 pluto[4537]: |   ff ff ff ff  00 00 00 00
03 00 06 00  00 00 00 00
Jun 27 18:11:54 1214570514 pluto[4537]: |   02 00 00 00  ac 10 02 73
00 00 00 00  00 00 00 00
Jun 27 18:11:54 1214570514 pluto[4537]: |   01 00 12 00  03 00 00 00
03 00 13 00  9e c1 22 56
Jun 27 18:11:54 1214570514 pluto[4537]: |   00 00 00 00  00 00 00 00
ff ff ff ff  00 00 00 00
Jun 27 18:11:54 1214570514 pluto[4537]: |   03 00 14 00  00 00 00 00
02 00 00 00  ac 10 02 73
Jun 27 18:11:54 1214570514 pluto[4537]: |   00 00 00 00  00 00 00 00
Jun 27 18:11:54 1214570514 pluto[4537]: | pfkey_get: SADB_X_GRPSA message 93
Jun 27 18:11:54 1214570514 pluto[4537]: | encrypting:
Jun 27 18:11:54 1214570514 pluto[4537]: |   01 00 00 14  64 e8 9a e3
a7 a8 9c 3f  c7 2e d0 f5
Jun 27 18:11:54 1214570514 pluto[4537]: |   70 67 92 30  0a 00 00 34
00 00 00 01  00 00 00 01
Jun 27 18:11:54 1214570514 pluto[4537]: |   00 00 00 28  01 03 04 01
9e c1 22 56  00 00 00 1c
Jun 27 18:11:54 1214570514 pluto[4537]: |   01 03 00 00  80 01 00 01
80 02 0e 10  80 04 f0 03
Jun 27 18:11:54 1214570514 pluto[4537]: |   80 05 00 01  80 03 00 02
04 00 00 14  16 66 81 de
Jun 27 18:11:54 1214570514 pluto[4537]: |   30 06 a7 b1  ff db ae f2
b6 96 ff 27  05 00 00 84
Jun 27 18:11:54 1214570514 pluto[4537]: |   94 c7 2d 6b  51 ae 5b db
3c 46 67 25  d4 d4 9a 0f
Jun 27 18:11:54 1214570514 pluto[4537]: |   c0 d1 52 f5  45 58 4e 30
02 48 ab 24  17 6c 94 ee
Jun 27 18:11:54 1214570514 pluto[4537]: |   6a e6 bf 14  83 d2 21 80
41 dc bc c5  5a c7 0d 2a
Jun 27 18:11:54 1214570514 pluto[4537]: |   65 af 96 ec  e2 3d 92 c3
a1 86 fd ad  ad dd a9 f5
Jun 27 18:11:54 1214570514 pluto[4537]: |   09 c1 f2 93  e1 5e f6 55
2f ed 80 d3  63 d7 4d 83
Jun 27 18:11:54 1214570514 pluto[4537]: |   38 35 2b db  43 b1 c6 57
17 18 c8 cc  37 69 ef a0
Jun 27 18:11:54 1214570514 pluto[4537]: |   c9 db 94 e2  7c 8d fe 93
00 80 4f 59  9f ce 74 ef
Jun 27 18:11:54 1214570514 pluto[4537]: |   98 90 ab fe  b4 95 01 56
e0 b2 d2 24  40 62 e9 e1
Jun 27 18:11:54 1214570514 pluto[4537]: |   05 00 00 0c  01 00 00 00
0a 14 14 39  00 00 00 10
Jun 27 18:11:54 1214570514 pluto[4537]: |   04 00 00 00  14 14 14 00
ff ff ff 00
Jun 27 18:11:54 1214570514 pluto[4537]: | IV:
Jun 27 18:11:54 1214570514 pluto[4537]: |   d3 d3 d8 3e  d1 b5 a7 52
Jun 27 18:11:54 1214570514 pluto[4537]: | emitting 4 zero bytes of
encryption padding into ISAKMP Message
Jun 27 18:11:54 1214570514 pluto[4537]: | encrypting using OAKLEY_3DES_CBC
Jun 27 18:11:54 1214570514 pluto[4537]: | next IV:  fd 4a 15 ec  ce 82 c8 63
Jun 27 18:11:54 1214570514 pluto[4537]: | emitting length of ISAKMP Message: 284
Jun 27 18:11:54 1214570514 pluto[4537]: | finished processing quick inI1
Jun 27 18:11:54 1214570514 pluto[4537]: | complete state transition with STF_OK
Jun 27 18:11:54 1214570514 pluto[4537]: "rw-1"[4] 172.16.1.151 #78:
transition from state STATE_QUICK_R0 to state STATE_QUICK_R1
Jun 27 18:11:54 1214570514 pluto[4537]: | sending reply packet to
172.16.1.151:4500 (from port=4500)
Jun 27 18:11:54 1214570514 pluto[4537]: | sending 284 bytes for
STATE_QUICK_R0 through eth1:4500 to 172.16.1.151:4500:
Jun 27 18:11:54 1214570514 pluto[4537]: |   00 00 00 00  c0 ba 41 b2
8e 08 66 93  d9 f6 ec 58
Jun 27 18:11:54 1214570514 pluto[4537]: |   c5 89 d0 23  08 10 20 01
66 d4 4d 99  00 00 01 1c
Jun 27 18:11:54 1214570514 pluto[4537]: |   98 2c e2 e7  f7 48 d5 26
80 84 b1 f4  f9 2b 6f ea
Jun 27 18:11:54 1214570514 pluto[4537]: |   d4 d5 94 49  b2 f5 4c 75
bf 85 0b 4e  bc 23 7d d1
Jun 27 18:11:54 1214570514 pluto[4537]: |   cb 1e b8 01  c9 e5 19 6f
89 0a c8 22  c7 a1 24 f8
Jun 27 18:11:54 1214570514 pluto[4537]: |   6c d9 f5 b8  8a b6 97 e8
71 f5 28 27  d7 07 fa ab
Jun 27 18:11:54 1214570514 pluto[4537]: |   6a f9 fa ad  c1 cf f3 b3
ec ee 0b a1  b9 53 7d 19
Jun 27 18:11:54 1214570514 pluto[4537]: |   85 6b 30 9a  48 8e fb 38
cb 2a bf d7  10 ef 17 45
Jun 27 18:11:54 1214570514 pluto[4537]: |   e9 b3 5c e1  74 aa 7f 38
c0 4e 68 86  99 cf 9f 1b
Jun 27 18:11:54 1214570514 pluto[4537]: |   49 ec 1b 73  44 3c 7a 49
ea aa a7 d3  7f a4 de 8d
Jun 27 18:11:54 1214570514 pluto[4537]: |   73 ec 60 af  5b 24 8e a1
5d 14 7d bc  cd 44 e6 4d
Jun 27 18:11:54 1214570514 pluto[4537]: |   91 56 de 31  db 01 71 26
cf 5c 2b 83  56 a5 95 39
Jun 27 18:11:54 1214570514 pluto[4537]: |   b6 9a 31 b7  4b ac 2b f3
97 64 03 d7  bb b2 33 0b
Jun 27 18:11:54 1214570514 pluto[4537]: |   13 c2 63 86  21 d7 a0 85
a9 4c 85 cb  55 88 72 a7
Jun 27 18:11:54 1214570514 pluto[4537]: |   28 b9 13 28  59 0d 44 6b
2f 99 b8 ea  bd 29 5d 41
Jun 27 18:11:54 1214570514 pluto[4537]: |   46 ce 0e 76  4d 09 0c 29
f9 1f 0e 4f  51 c6 34 1b
Jun 27 18:11:54 1214570514 pluto[4537]: |   68 7b ae 6d  e5 d8 b0 14
ae ea e6 47  b4 89 c8 0d
Jun 27 18:11:54 1214570514 pluto[4537]: |   b2 7c 99 b0  dc ce bd ab
fd 4a 15 ec  ce 82 c8 63
Jun 27 18:11:54 1214570514 pluto[4537]: | inserting event
EVENT_RETRANSMIT, timeout in 10 seconds for #78
Jun 27 18:11:54 1214570514 pluto[4537]: "rw-1"[4] 172.16.1.151 #78:
STATE_QUICK_R1: sent QR1, inbound IPsec SA installed, expecting QI2
Jun 27 18:11:54 1214570514 pluto[4537]: | modecfg pull: noquirk
policy:push not-client
Jun 27 18:11:54 1214570514 pluto[4537]: | phase 1 is done, looking for
phase 1 to unpend
Jun 27 18:11:54 1214570514 pluto[4537]: | complete state transition
with STF_INLINE
Jun 27 18:11:54 1214570514 pluto[4537]: | next event EVENT_RETRANSMIT
in 10 seconds for #78
Jun 27 18:11:54 1214570514 pluto[4537]: |
Jun 27 18:11:54 1214570514 pluto[4537]: | *received 52 bytes from
172.16.1.151:4500 on eth1 (port=4500)
Jun 27 18:11:54 1214570514 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:54 1214570514 pluto[4537]: |   08 10 20 01  66 d4 4d 99
00 00 00 34  65 41 80 f9
Jun 27 18:11:54 1214570514 pluto[4537]: |   27 d0 aa 2b  17 e9 d6 c9
41 f2 6a fb  21 72 23 c1
Jun 27 18:11:54 1214570514 pluto[4537]: |   e1 7a 3a 3f
Jun 27 18:11:54 1214570514 pluto[4537]: | **parse ISAKMP Message:
Jun 27 18:11:54 1214570514 pluto[4537]: |    initiator cookie:
Jun 27 18:11:54 1214570514 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
Jun 27 18:11:54 1214570514 pluto[4537]: |    responder cookie:
Jun 27 18:11:54 1214570514 pluto[4537]: |   d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:54 1214570514 pluto[4537]: |    next payload type: ISAKMP_NEXT_HASH
Jun 27 18:11:54 1214570514 pluto[4537]: |    ISAKMP version: ISAKMP Version 1.0
Jun 27 18:11:54 1214570514 pluto[4537]: |    exchange type: ISAKMP_XCHG_QUICK
Jun 27 18:11:54 1214570514 pluto[4537]: |    flags: ISAKMP_FLAG_ENCRYPTION
Jun 27 18:11:54 1214570514 pluto[4537]: |    message ID:  66 d4 4d 99
Jun 27 18:11:54 1214570514 pluto[4537]: |    length: 52
Jun 27 18:11:54 1214570514 pluto[4537]: |  processing packet with
exchange type=ISAKMP_XCHG_QUICK (32)
Jun 27 18:11:54 1214570514 pluto[4537]: | ICOOKIE:  c0 ba 41 b2  8e 08 66 93
Jun 27 18:11:54 1214570514 pluto[4537]: | RCOOKIE:  d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:54 1214570514 pluto[4537]: | peer:  ac 10 01 97
Jun 27 18:11:54 1214570514 pluto[4537]: | state hash entry 18
Jun 27 18:11:54 1214570514 pluto[4537]: | peer and cookies match on
#78, provided msgid 66d44d99 vs 66d44d99
Jun 27 18:11:54 1214570514 pluto[4537]: | state object #78 found, in
STATE_QUICK_R1
Jun 27 18:11:54 1214570514 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:11:54 1214570514 pluto[4537]: | received encrypted packet
from 172.16.1.151:4500
Jun 27 18:11:54 1214570514 pluto[4537]: | decrypting 24 bytes using
algorithm OAKLEY_3DES_CBC
Jun 27 18:11:54 1214570514 pluto[4537]: | decrypted:
Jun 27 18:11:54 1214570514 pluto[4537]: |   00 00 00 14  45 42 02 eb
0c 11 90 8f  9a a7 19 45
Jun 27 18:11:54 1214570514 pluto[4537]: |   6b 70 31 b4  00 00 00 00
Jun 27 18:11:54 1214570514 pluto[4537]: | next IV:  21 72 23 c1  e1 7a 3a 3f
Jun 27 18:11:54 1214570514 pluto[4537]: | ***parse ISAKMP Hash Payload:
Jun 27 18:11:54 1214570514 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:11:54 1214570514 pluto[4537]: |    length: 20
Jun 27 18:11:55 1214570515 pluto[4537]: | removing 4 bytes of padding
Jun 27 18:11:55 1214570515 pluto[4537]: | HASH(3) computed:  45 42 02
eb  0c 11 90 8f  9a a7 19 45  6b 70 31 b4
Jun 27 18:11:55 1214570515 pluto[4537]: | install_ipsec_sa() for #78:
outbound only
Jun 27 18:11:55 1214570515 pluto[4537]: | route owner of "rw-1"[4]
172.16.1.151 unrouted: NULL; eroute owner: NULL
Jun 27 18:11:55 1214570515 pluto[4537]: | could_route called for rw-1
(kind=CK_INSTANCE)
Jun 27 18:11:55 1214570515 pluto[4537]: | pfkey_lib_debug:pfkey_msg_hdr_build:
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_hdr_build: on_entry &pfkey_ext=0p0xbff4ef80
pfkey_ext=0p0xbff4efe0 *pfkey_ext=0p(nil).
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_hdr_build: on_exit &pfkey_ext=0p0xbff4ef80
pfkey_ext=0p0xbff4efe0 *pfkey_ext=0p0x8105468.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_sa_build: spi=00001011 replay=0 sa_state=1
auth=0 encrypt=0 flags=0
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=5 proto=0 prefixlen=0
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=172.16.2.115:0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=6 proto=0 prefixlen=0
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=172.16.1.151:0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: pfkey_msg=0p0x81091e0 allocated 88
bytes, &(extensions[0])=0p0xbff4efe0
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[1]
(type=1)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[5]
(type=5)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[6]
(type=6)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: extensions permitted=78001ffb,
seen=00000063, required=00000063.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing message ver=2, type=3(add),
errno=0, satype=9(IPIP), len=11, res=0, seq=94, pid=4537.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: satype 9(IPIP) conversion to proto
gives 4 for msg_type 3(add).
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=9
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=78001ffb,
required=00000063.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=1(security-association) remain=9.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=9
ext_type=1(security-association) ext_len=3 parsing ext 0p0x81091f0
with parser pfkey_sa_parse.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_sa_parse: successfully found len=3
exttype=1(security-association) spi=00001011 replay=0 state=1 auth=0
encrypt=0 flags=0 ref=-1.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 1(security-association)
parsed.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=5(source-address)
remain=6.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=6 ext_type=5(source-address)
ext_len=3 parsing ext 0p0x8109208 with parser pfkey_address_parse.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found exttype=5(source-address)
family=2(AF_INET) address=172.16.2.115 proto=0 port=0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 5(source-address) parsed.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=6(destination-address) remain=3.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=3
ext_type=6(destination-address) ext_len=3 parsing ext 0p0x8109220 with
parser pfkey_address_parse.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found
exttype=6(destination-address) family=2(AF_INET) address=172.16.1.151
proto=0 port=0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 6(destination-address)
parsed.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=78001ffb,
seen=00000063, required=00000063.
Jun 27 18:11:55 1214570515 pluto[4537]: | finish_pfkey_msg: SADB_ADD
message 94 for Add SA tun.1011 at 172.16.1.151
Jun 27 18:11:55 1214570515 pluto[4537]: |   02 03 00 09  0b 00 00 00
5e 00 00 00  b9 11 00 00
Jun 27 18:11:55 1214570515 pluto[4537]: |   03 00 01 00  00 00 10 11
00 01 00 00  00 00 00 00
Jun 27 18:11:55 1214570515 pluto[4537]: |   ff ff ff ff  00 00 00 00
03 00 05 00  00 00 00 00
Jun 27 18:11:55 1214570515 pluto[4537]: |   02 00 00 00  ac 10 02 73
00 00 00 00  00 00 00 00
Jun 27 18:11:55 1214570515 pluto[4537]: |   03 00 06 00  00 00 00 00
02 00 00 00  ac 10 01 97
Jun 27 18:11:55 1214570515 pluto[4537]: |   00 00 00 00  00 00 00 00
Jun 27 18:11:55 1214570515 pluto[4537]: | pfkey_get: SADB_ADD message 94
Jun 27 18:11:55 1214570515 pluto[4537]: | looking for alg with
transid: 3 keylen: 0 auth: 1
Jun 27 18:11:55 1214570515 pluto[4537]: | checking transid: 11 keylen:
0 auth: 1
Jun 27 18:11:55 1214570515 pluto[4537]: | checking transid: 11 keylen:
0 auth: 2
Jun 27 18:11:55 1214570515 pluto[4537]: | checking transid: 2 keylen: 8 auth: 0
Jun 27 18:11:55 1214570515 pluto[4537]: | checking transid: 2 keylen: 8 auth: 1
Jun 27 18:11:55 1214570515 pluto[4537]: | checking transid: 2 keylen: 8 auth: 2
Jun 27 18:11:55 1214570515 pluto[4537]: | checking transid: 3 keylen:
24 auth: 0
Jun 27 18:11:55 1214570515 pluto[4537]: | checking transid: 3 keylen:
24 auth: 1
Jun 27 18:11:55 1214570515 pluto[4537]: | pfkey_lib_debug:pfkey_msg_hdr_build:
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_hdr_build: on_entry &pfkey_ext=0p0xbff4ef80
pfkey_ext=0p0xbff4efe0 *pfkey_ext=0p(nil).
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_hdr_build: on_exit &pfkey_ext=0p0xbff4ef80
pfkey_ext=0p0xbff4efe0 *pfkey_ext=0p0x8105468.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_sa_build: spi=b074c88e replay=64 sa_state=1
auth=2 encrypt=3 flags=0
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=5 proto=0 prefixlen=0
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=172.16.2.115:0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=6 proto=0 prefixlen=0
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=172.16.1.151:0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:55 1214570515 pluto[4537]: | pfkey_lib_debug:pfkey_key_build:
Jun 27 18:11:55 1214570515 pluto[4537]: | pfkey_lib_debug:pfkey_key_build:
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_x_nat_t_type_build:
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_x_nat_t_type_build: type=2
Jun 27 18:11:55 1214570515 pluto[4537]: | setting natt_type to 2
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_x_nat_t_port_build:
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_x_nat_t_port_build: ext=28, port=4500
Jun 27 18:11:55 1214570515 pluto[4537]: | setting natt_sport to 4500
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_x_nat_t_port_build:
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_x_nat_t_port_build: ext=29, port=4500
Jun 27 18:11:55 1214570515 pluto[4537]: | setting natt_dport to 4500
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: pfkey_msg=0p0x8109228 allocated 168
bytes, &(extensions[0])=0p0xbff4efe0
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[1]
(type=1)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[5]
(type=5)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[6]
(type=6)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[8]
(type=8)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 32 bytes from extensions[9]
(type=9)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 8 bytes from extensions[27]
(type=27)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 8 bytes from extensions[28]
(type=28)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 8 bytes from extensions[29]
(type=29)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: extensions permitted=78001ffb,
seen=38000363, required=00000063.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing message ver=2, type=3(add),
errno=0, satype=3(ESP), len=21, res=0, seq=95, pid=4537.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: satype 3(ESP) conversion to proto
gives 50 for msg_type 3(add).
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=19
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=78001ffb,
required=00000063.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=1(security-association) remain=19.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=19
ext_type=1(security-association) ext_len=3 parsing ext 0p0x8109238
with parser pfkey_sa_parse.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_sa_parse: successfully found len=3
exttype=1(security-association) spi=b074c88e replay=64 state=1 auth=2
encrypt=3 flags=0 ref=-1.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 1(security-association)
parsed.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=5(source-address)
remain=16.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=16 ext_type=5(source-address)
ext_len=3 parsing ext 0p0x8109250 with parser pfkey_address_parse.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found exttype=5(source-address)
family=2(AF_INET) address=172.16.2.115 proto=0 port=0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 5(source-address) parsed.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=6(destination-address) remain=13.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=13
ext_type=6(destination-address) ext_len=3 parsing ext 0p0x8109268 with
parser pfkey_address_parse.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found
exttype=6(destination-address) family=2(AF_INET) address=172.16.1.151
proto=0 port=0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 6(destination-address)
parsed.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=8(authentication-key) remain=10.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=10
ext_type=8(authentication-key) ext_len=3 parsing ext 0p0x8109280 with
parser pfkey_key_parse.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_key_parse: success, found len=3
exttype=8(authentication-key) bits=128 reserved=0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 8(authentication-key)
parsed.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=9(cipher-key)
remain=7.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=7 ext_type=9(cipher-key)
ext_len=4 parsing ext 0p0x8109298 with parser pfkey_key_parse.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_key_parse: success, found len=4
exttype=9(cipher-key) bits=192 reserved=0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 9(cipher-key) parsed.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=27(X-NAT-T-sport)
remain=3.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=3 ext_type=27(X-NAT-T-sport)
ext_len=1 parsing ext 0p0x81092b8 with parser
pfkey_x_ext_nat_t_type_parse.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 27(X-NAT-T-sport) parsed.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=28(X-NAT-T-dport)
remain=2.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=2 ext_type=28(X-NAT-T-dport)
ext_len=1 parsing ext 0p0x81092c0 with parser
pfkey_x_ext_nat_t_port_parse.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 28(X-NAT-T-dport) parsed.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=29(X-NAT-T-OA)
remain=1.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=1 ext_type=29(X-NAT-T-OA)
ext_len=1 parsing ext 0p0x81092c8 with parser
pfkey_x_ext_nat_t_port_parse.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 29(X-NAT-T-OA) parsed.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=78001ffb,
seen=38000363, required=00000063.
Jun 27 18:11:55 1214570515 pluto[4537]: | finish_pfkey_msg: SADB_ADD
message 95 for Add SA esp.b074c88e at 172.16.1.151
Jun 27 18:11:55 1214570515 pluto[4537]: |   02 03 00 03  15 00 00 00
5f 00 00 00  b9 11 00 00
Jun 27 18:11:55 1214570515 pluto[4537]: |   03 00 01 00  b0 74 c8 8e
40 01 02 03  00 00 00 00
Jun 27 18:11:55 1214570515 pluto[4537]: |   ff ff ff ff  00 00 00 00
03 00 05 00  00 00 00 00
Jun 27 18:11:55 1214570515 pluto[4537]: |   02 00 00 00  ac 10 02 73
00 00 00 00  00 00 00 00
Jun 27 18:11:55 1214570515 pluto[4537]: |   03 00 06 00  00 00 00 00
02 00 00 00  ac 10 01 97
Jun 27 18:11:55 1214570515 pluto[4537]: |   00 00 00 00  00 00 00 00
03 00 08 00  80 00 00 00
Jun 27 18:11:55 1214570515 pluto[4537]: |   5d 98 7d 6d  9d ca ab da
2d 4d 01 a0  4b 43 da 6d
Jun 27 18:11:55 1214570515 pluto[4537]: |   04 00 09 00  c0 00 00 00
fe 22 e5 60  19 a2 93 d9
Jun 27 18:11:55 1214570515 pluto[4537]: |   e9 0e 58 21  9f de 4c 11
bf d0 31 85  08 68 9c ef
Jun 27 18:11:55 1214570515 pluto[4537]: |   01 00 1b 00  02 00 00 00
01 00 1c 00  94 11 00 00
Jun 27 18:11:55 1214570515 pluto[4537]: |   01 00 1d 00  94 11 00 00
Jun 27 18:11:55 1214570515 pluto[4537]: | pfkey_get: SADB_ADD message 95
Jun 27 18:11:55 1214570515 pluto[4537]: | grouping
unk0.b074c88e at 172.16.1.151 and unk0.1011 at 172.16.1.151
Jun 27 18:11:55 1214570515 pluto[4537]: | pfkey_lib_debug:pfkey_msg_hdr_build:
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_hdr_build: on_entry &pfkey_ext=0p0xbff4ef70
pfkey_ext=0p0xbff4efe0 *pfkey_ext=0p(nil).
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_hdr_build: on_exit &pfkey_ext=0p0xbff4ef70
pfkey_ext=0p0xbff4efe0 *pfkey_ext=0p0x8105468.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_sa_build: spi=00001011 replay=0 sa_state=0
auth=0 encrypt=0 flags=0
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=6 proto=0 prefixlen=0
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=172.16.1.151:0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:55 1214570515 pluto[4537]: | pfkey_lib_debug:pfkey_x_satype_build:
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_sa_build: spi=b074c88e replay=0 sa_state=0
auth=0 encrypt=0 flags=0
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=20 proto=0 prefixlen=0
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=172.16.1.151:0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: pfkey_msg=0p0x8109200 allocated 120
bytes, &(extensions[0])=0p0xbff4efe0
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[1]
(type=1)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[6]
(type=6)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 8 bytes from extensions[18]
(type=18)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[19]
(type=19)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[20]
(type=20)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: extensions permitted=001c0043,
seen=001c0043, required=00000043.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing message ver=2,
type=13(x-groupsa), errno=0, satype=9(IPIP), len=15, res=0, seq=96,
pid=4537.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: satype 9(IPIP) conversion to proto
gives 4 for msg_type 13(x-groupsa).
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=13
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=001c0043,
required=00000043.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=1(security-association) remain=13.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=13
ext_type=1(security-association) ext_len=3 parsing ext 0p0x8109210
with parser pfkey_sa_parse.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_sa_parse: successfully found len=3
exttype=1(security-association) spi=00001011 replay=0 state=0 auth=0
encrypt=0 flags=0 ref=-1.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 1(security-association)
parsed.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=6(destination-address) remain=10.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=10
ext_type=6(destination-address) ext_len=3 parsing ext 0p0x8109228 with
parser pfkey_address_parse.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found
exttype=6(destination-address) family=2(AF_INET) address=172.16.1.151
proto=0 port=0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 6(destination-address)
parsed.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=18(X-satype2)
remain=7.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=7 ext_type=18(X-satype2)
ext_len=1 parsing ext 0p0x8109240 with parser pfkey_x_satype_parse.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_x_satype_parse: enter
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_x_satype_parse: len=1 ext=18(X-satype2)
satype=3(ESP) res=0,0,0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 18(X-satype2) parsed.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=19(X-security-association) remain=6.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=6
ext_type=19(X-security-association) ext_len=3 parsing ext 0p0x8109248
with parser pfkey_sa_parse.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_sa_parse: successfully found len=3
exttype=19(X-security-association) spi=b074c88e replay=0 state=0
auth=0 encrypt=0 flags=0 ref=-1.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 19(X-security-association)
parsed.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=20(X-destination-address2) remain=3.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=3
ext_type=20(X-destination-address2) ext_len=3 parsing ext 0p0x8109260
with parser pfkey_address_parse.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found
exttype=20(X-destination-address2) family=2(AF_INET)
address=172.16.1.151 proto=0 port=0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 20(X-destination-address2)
parsed.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=001c0043,
seen=001c0043, required=00000043.
Jun 27 18:11:55 1214570515 pluto[4537]: | finish_pfkey_msg:
SADB_X_GRPSA message 96 for group unk0.1011 at 172.16.1.151
Jun 27 18:11:55 1214570515 pluto[4537]: |   02 0d 00 09  0f 00 00 00
60 00 00 00  b9 11 00 00
Jun 27 18:11:55 1214570515 pluto[4537]: |   03 00 01 00  00 00 10 11
00 00 00 00  00 00 00 00
Jun 27 18:11:55 1214570515 pluto[4537]: |   ff ff ff ff  00 00 00 00
03 00 06 00  00 00 00 00
Jun 27 18:11:55 1214570515 pluto[4537]: |   02 00 00 00  ac 10 01 97
00 00 00 00  00 00 00 00
Jun 27 18:11:55 1214570515 pluto[4537]: |   01 00 12 00  03 00 00 00
03 00 13 00  b0 74 c8 8e
Jun 27 18:11:55 1214570515 pluto[4537]: |   00 00 00 00  00 00 00 00
ff ff ff ff  00 00 00 00
Jun 27 18:11:55 1214570515 pluto[4537]: |   03 00 14 00  00 00 00 00
02 00 00 00  ac 10 01 97
Jun 27 18:11:55 1214570515 pluto[4537]: |   00 00 00 00  00 00 00 00
Jun 27 18:11:55 1214570515 pluto[4537]: | pfkey_get: SADB_X_GRPSA message 96
Jun 27 18:11:55 1214570515 pluto[4537]: | sr for #78: unrouted
Jun 27 18:11:55 1214570515 pluto[4537]: | route owner of "rw-1"[4]
172.16.1.151 unrouted: NULL; eroute owner: NULL
Jun 27 18:11:55 1214570515 pluto[4537]: | route_and_eroute with c:
rw-1 (next: none) ero:null esr:{(nil)} ro:null rosr:{(nil)} and state:
78
Jun 27 18:11:55 1214570515 pluto[4537]: | eroute_connection add eroute
20.20.20.0/24:0 --0-> 10.20.20.57/32:0 => tun.1011 at 172.16.1.151
(raw_eroute)
Jun 27 18:11:55 1214570515 pluto[4537]: | pfkey_lib_debug:pfkey_msg_hdr_build:
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_hdr_build: on_entry &pfkey_ext=0p0xbff4ee30
pfkey_ext=0p0xbff4ef20 *pfkey_ext=0p(nil).
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_hdr_build: on_exit &pfkey_ext=0p0xbff4ee30
pfkey_ext=0p0xbff4ef20 *pfkey_ext=0p0x8105468.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_sa_build: spi=00001011 replay=0 sa_state=0
auth=0 encrypt=0 flags=0
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=5 proto=0 prefixlen=0
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=172.16.2.115:0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=6 proto=0 prefixlen=0
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=172.16.1.151:0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=21 proto=0 prefixlen=0
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=20.20.20.0:0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=22 proto=0 prefixlen=0
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=10.20.20.57:0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=23 proto=0 prefixlen=0
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=255.255.255.0:0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: exttype=24 proto=0 prefixlen=0
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address family AF_INET.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: found address=255.255.255.255:0.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_address_build: successful created len: 3.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: pfkey_msg=0p0x810cc08 allocated 184
bytes, &(extensions[0])=0p0xbff4ef20
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[1]
(type=1)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[5]
(type=5)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[6]
(type=6)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[21]
(type=21)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[22]
(type=22)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[23]
(type=23)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: copying 24 bytes from extensions[24]
(type=24)
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_build: extensions permitted=05e00c63,
seen=01e00063, required=01e00043.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing message ver=2,
type=14(x-addflow(eroute)), errno=0, satype=9(IPIP), len=23, res=0,
seq=97, pid=4537.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: satype 9(IPIP) conversion to proto
gives 4 for msg_type 14(x-addflow(eroute)).
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=21
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=05e00c63,
required=01e00043.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=1(security-association) remain=21.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=21
ext_type=1(security-association) ext_len=3 parsing ext 0p0x810cc18
with parser pfkey_sa_parse.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_sa_parse: successfully found len=3
exttype=1(security-association) spi=00001011 replay=0 state=0 auth=0
encrypt=0 flags=0 ref=-1.
Jun 27 18:11:55 1214570515 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 1(security-association)
parsed.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=5(source-address)
remain=18.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=18 ext_type=5(source-address)
ext_len=3 parsing ext 0p0x810cc30 with parser pfkey_address_parse.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found exttype=5(source-address)
family=2(AF_INET) address=172.16.2.115 proto=0 port=0.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 5(source-address) parsed.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=6(destination-address) remain=15.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=15
ext_type=6(destination-address) ext_len=3 parsing ext 0p0x810cc48 with
parser pfkey_address_parse.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found
exttype=6(destination-address) family=2(AF_INET) address=172.16.1.151
proto=0 port=0.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 6(destination-address)
parsed.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=21(X-source-flow-address) remain=12.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=12
ext_type=21(X-source-flow-address) ext_len=3 parsing ext 0p0x810cc60
with parser pfkey_address_parse.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found
exttype=21(X-source-flow-address) family=2(AF_INET) address=20.20.20.0
proto=0 port=0.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 21(X-source-flow-address)
parsed.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext
type=22(X-dest-flow-address) remain=9.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=9
ext_type=22(X-dest-flow-address) ext_len=3 parsing ext 0p0x810cc78
with parser pfkey_address_parse.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found
exttype=22(X-dest-flow-address) family=2(AF_INET) address=10.20.20.57
proto=0 port=0.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 22(X-dest-flow-address)
parsed.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=23(X-source-mask)
remain=6.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=6 ext_type=23(X-source-mask)
ext_len=3 parsing ext 0p0x810cc90 with parser pfkey_address_parse.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found exttype=23(X-source-mask)
family=2(AF_INET) address=255.255.255.0 proto=0 port=0.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 23(X-source-mask) parsed.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=24(X-dest-mask)
remain=3.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: remain=3 ext_type=24(X-dest-mask)
ext_len=3 parsing ext 0p0x810cca8 with parser pfkey_address_parse.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: found exttype=24(X-dest-mask)
family=2(AF_INET) address=255.255.255.255 proto=0 port=0.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_address_parse: successful.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: Extension 24(X-dest-mask) parsed.
Jun 27 18:11:56 1214570516 pluto[4537]: |
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=05e00c63,
seen=01e00063, required=01e00043.
Jun 27 18:11:56 1214570516 pluto[4537]: | finish_pfkey_msg:
SADB_X_ADDFLOW message 97 for flow tun.1011 at 172.16.1.151
Jun 27 18:11:56 1214570516 pluto[4537]: |   02 0e 00 09  17 00 00 00
61 00 00 00  b9 11 00 00
Jun 27 18:11:56 1214570516 pluto[4537]: |   03 00 01 00  00 00 10 11
00 00 00 00  00 00 00 00
Jun 27 18:11:56 1214570516 pluto[4537]: |   ff ff ff ff  00 00 00 00
03 00 05 00  00 00 00 00
Jun 27 18:11:56 1214570516 pluto[4537]: |   02 00 00 00  ac 10 02 73
00 00 00 00  00 00 00 00
Jun 27 18:11:56 1214570516 pluto[4537]: |   03 00 06 00  00 00 00 00
02 00 00 00  ac 10 01 97
Jun 27 18:11:56 1214570516 pluto[4537]: |   00 00 00 00  00 00 00 00
03 00 15 00  00 00 00 00
Jun 27 18:11:56 1214570516 pluto[4537]: |   02 00 00 00  14 14 14 00
b8 2d cb bf  aa 79 f3 b7
Jun 27 18:11:56 1214570516 pluto[4537]: |   03 00 16 00  00 00 00 00
02 00 00 00  0a 14 14 39
Jun 27 18:11:56 1214570516 pluto[4537]: |   b8 f3 f4 bf  c4 d2 09 08
03 00 17 00  00 00 00 00
Jun 27 18:11:56 1214570516 pluto[4537]: |   02 00 00 00  ff ff ff 00
7c 00 32 30  39 ef f4 bf
Jun 27 18:11:56 1214570516 pluto[4537]: |   03 00 18 00  00 00 00 00
02 00 00 00  ff ff ff ff
Jun 27 18:11:56 1214570516 pluto[4537]: |   e8 ee f4 bf  da 66 0a 08
Jun 27 18:11:56 1214570516 pluto[4537]: | pfkey_get: SADB_X_ADDFLOW message 97
Jun 27 18:11:56 1214570516 pluto[4537]: | command executing up-client
Jun 27 18:11:56 1214570516 pluto[4537]: | executing up-client: 2>&1
PLUTO_VERSION='1.1' PLUTO_VERB='up-client' PLUTO_CONNECTION='rw-1'
PLUTO_NEXT_HOP='172.16.2.1' PLUTO_INTERFACE='ipsec0'
PLUTO_ME='172.16.2.115' PLUTO_MY_ID='172.16.2.115'
PLUTO_MY_CLIENT='20.20.20.0/24' PLUTO_MY_CLIENT_NET='20.20.20.0'
PLUTO_MY_CLIENT_MASK='255.255.255.0' PLUTO_MY_PORT='0'
PLUTO_MY_PROTOCOL='0' PLUTO_PEER='172.16.1.151'
PLUTO_PEER_ID='0.0.0.0' PLUTO_PEER_CLIENT='10.20.20.57/32'
PLUTO_PEER_CLIENT_NET='10.20.20.57'
PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0'
PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA=''
PLUTO_CONN_POLICY='PSK+ENCRYPT+COMPRESS+TUNNEL+PFS+DONTREKEY+AGGRESSIVE+failureDROP'
  /usr/lib/ipsec/_updown
Jun 27 18:11:56 1214570516 pluto[4537]: | route_and_eroute:
firewall_notified: true
Jun 27 18:11:56 1214570516 pluto[4537]: | command executing prepare-client
Jun 27 18:11:56 1214570516 pluto[4537]: | executing prepare-client:
2>&1 PLUTO_VERSION='1.1' PLUTO_VERB='prepare-client'
PLUTO_CONNECTION='rw-1' PLUTO_NEXT_HOP='172.16.2.1'
PLUTO_INTERFACE='ipsec0' PLUTO_ME='172.16.2.115'
PLUTO_MY_ID='172.16.2.115' PLUTO_MY_CLIENT='20.20.20.0/24'
PLUTO_MY_CLIENT_NET='20.20.20.0' PLUTO_MY_CLIENT_MASK='255.255.255.0'
PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='172.16.1.151'
PLUTO_PEER_ID='0.0.0.0' PLUTO_PEER_CLIENT='10.20.20.57/32'
PLUTO_PEER_CLIENT_NET='10.20.20.57'
PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0'
PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA=''
PLUTO_CONN_POLICY='PSK+ENCRYPT+COMPRESS+TUNNEL+PFS+DONTREKEY+AGGRESSIVE+failureDROP'
  /usr/lib/ipsec/_updown
Jun 27 18:11:56 1214570516 pluto[4537]: | command executing route-client
Jun 27 18:11:56 1214570516 pluto[4537]: | executing route-client: 2>&1
PLUTO_VERSION='1.1' PLUTO_VERB='route-client' PLUTO_CONNECTION='rw-1'
PLUTO_NEXT_HOP='172.16.2.1' PLUTO_INTERFACE='ipsec0'
PLUTO_ME='172.16.2.115' PLUTO_MY_ID='172.16.2.115'
PLUTO_MY_CLIENT='20.20.20.0/24' PLUTO_MY_CLIENT_NET='20.20.20.0'
PLUTO_MY_CLIENT_MASK='255.255.255.0' PLUTO_MY_PORT='0'
PLUTO_MY_PROTOCOL='0' PLUTO_PEER='172.16.1.151'
PLUTO_PEER_ID='0.0.0.0' PLUTO_PEER_CLIENT='10.20.20.57/32'
PLUTO_PEER_CLIENT_NET='10.20.20.57'
PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0'
PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA=''
PLUTO_CONN_POLICY='PSK+ENCRYPT+COMPRESS+TUNNEL+PFS+DONTREKEY+AGGRESSIVE+failureDROP'
  /usr/lib/ipsec/_updown
Jun 27 18:11:56 1214570516 pluto[4537]: | route_and_eroute: instance
"rw-1"[4] 172.16.1.151, setting eroute_owner
{spd=0x810ad8c,sr=0x810ad8c} to #78 (was #0) (newest_ipsec_sa=#0)
Jun 27 18:11:56 1214570516 pluto[4537]: | inI2: instance rw-1[4],
setting newest_ipsec_sa to #78 (was #0) (spd.eroute=#78)
Jun 27 18:11:56 1214570516 pluto[4537]: | ICOOKIE:  c0 ba 41 b2  8e 08 66 93
Jun 27 18:11:56 1214570516 pluto[4537]: | RCOOKIE:  d9 f6 ec 58  c5 89 d0 23
Jun 27 18:11:56 1214570516 pluto[4537]: | peer:  ac 10 01 97
Jun 27 18:11:56 1214570516 pluto[4537]: | state hash entry 18
Jun 27 18:11:56 1214570516 pluto[4537]: | peer and cookies match on
#78, provided msgid 00000000 vs 66d44d99
Jun 27 18:11:56 1214570516 pluto[4537]: | peer and cookies match on
#77, provided msgid 00000000 vs 00000000
Jun 27 18:11:56 1214570516 pluto[4537]: | state object #77 found, in
STATE_AGGR_R2
Jun 27 18:11:56 1214570516 pluto[4537]: "rw-1"[4] 172.16.1.151 #78:
Dead Peer Detection (RFC 3706): enabled
Jun 27 18:11:56 1214570516 pluto[4537]: | state: 78 requesting event
none to be deleted by dpd.c:160
Jun 27 18:11:56 1214570516 pluto[4537]: | inserting event EVENT_DPD,
timeout in 30 seconds for #78
Jun 27 18:11:56 1214570516 pluto[4537]: | state: 77 requesting event
EVENT_DPD to be deleted by dpd.c:172
Jun 27 18:11:56 1214570516 pluto[4537]: | complete state transition with STF_OK
Jun 27 18:11:56 1214570516 pluto[4537]: "rw-1"[4] 172.16.1.151 #78:
transition from state STATE_QUICK_R1 to state STATE_QUICK_R2
Jun 27 18:11:56 1214570516 pluto[4537]: | inserting event
EVENT_SA_EXPIRE, timeout in 3600 seconds for #78
Jun 27 18:11:56 1214570516 pluto[4537]: "rw-1"[4] 172.16.1.151 #78:
STATE_QUICK_R2: IPsec SA established {ESP=>0xb074c88e <0x9ec12256
xfrm=3DES_0-HMAC_MD5 NATD=172.16.1.151:4500 DPD=enabled}
Jun 27 18:11:56 1214570516 pluto[4537]: | modecfg pull: noquirk
policy:push not-client
Jun 27 18:11:56 1214570516 pluto[4537]: | phase 1 is done, looking for
phase 1 to unpend
Jun 27 18:11:56 1214570516 pluto[4537]: | next event
EVENT_NAT_T_KEEPALIVE in 15 seconds
Jun 27 18:12:06 1214570526 pluto[4537]: |
Jun 27 18:12:06 1214570526 pluto[4537]: | *received 84 bytes from
172.16.1.151:4500 on eth1 (port=4500)
Jun 27 18:12:06 1214570526 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
d9 f6 ec 58  c5 89 d0 23
Jun 27 18:12:06 1214570526 pluto[4537]: |   08 10 05 01  a2 bb a6 c4
00 00 00 54  32 bf d7 b4
Jun 27 18:12:06 1214570526 pluto[4537]: |   99 e3 2c d1  6b 8f de 90
a0 08 3b 79  fb 5d f9 20
Jun 27 18:12:06 1214570526 pluto[4537]: |   6d 84 09 3a  9b 55 61 d6
94 d2 17 45  59 7f b7 1c
Jun 27 18:12:06 1214570526 pluto[4537]: |   58 84 54 45  f3 23 e0 3b
3b 34 59 50  9d e5 bb 10
Jun 27 18:12:06 1214570526 pluto[4537]: |   87 93 8d e9
Jun 27 18:12:06 1214570526 pluto[4537]: | **parse ISAKMP Message:
Jun 27 18:12:06 1214570526 pluto[4537]: |    initiator cookie:
Jun 27 18:12:06 1214570526 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
Jun 27 18:12:06 1214570526 pluto[4537]: |    responder cookie:
Jun 27 18:12:06 1214570526 pluto[4537]: |   d9 f6 ec 58  c5 89 d0 23
Jun 27 18:12:06 1214570526 pluto[4537]: |    next payload type: ISAKMP_NEXT_HASH
Jun 27 18:12:06 1214570526 pluto[4537]: |    ISAKMP version: ISAKMP Version 1.0
Jun 27 18:12:06 1214570526 pluto[4537]: |    exchange type: ISAKMP_XCHG_INFO
Jun 27 18:12:06 1214570526 pluto[4537]: |    flags: ISAKMP_FLAG_ENCRYPTION
Jun 27 18:12:06 1214570526 pluto[4537]: |    message ID:  a2 bb a6 c4
Jun 27 18:12:06 1214570526 pluto[4537]: |    length: 84
Jun 27 18:12:06 1214570526 pluto[4537]: |  processing packet with
exchange type=ISAKMP_XCHG_INFO (5)
Jun 27 18:12:06 1214570526 pluto[4537]: | ICOOKIE:  c0 ba 41 b2  8e 08 66 93
Jun 27 18:12:06 1214570526 pluto[4537]: | RCOOKIE:  d9 f6 ec 58  c5 89 d0 23
Jun 27 18:12:06 1214570526 pluto[4537]: | peer:  ac 10 01 97
Jun 27 18:12:06 1214570526 pluto[4537]: | state hash entry 18
Jun 27 18:12:06 1214570526 pluto[4537]: | peer and cookies match on
#78, provided msgid 00000000 vs 66d44d99/00000000
Jun 27 18:12:06 1214570526 pluto[4537]: | peer and cookies match on
#77, provided msgid 00000000 vs 00000000/00000000
Jun 27 18:12:06 1214570526 pluto[4537]: | p15 state object #77 found,
in STATE_AGGR_R2
Jun 27 18:12:06 1214570526 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:12:06 1214570526 pluto[4537]: | last Phase 1 IV:  6a 6c b8
98  b3 85 52 58
Jun 27 18:12:06 1214570526 pluto[4537]: | current Phase 1 IV:  6a 6c
b8 98  b3 85 52 58
Jun 27 18:12:06 1214570526 pluto[4537]: | computed Phase 2 IV:
Jun 27 18:12:06 1214570526 pluto[4537]: |   99 94 b0 8e  d8 2f 8b 9c
7f 2d c9 a3  91 29 c8 87
Jun 27 18:12:06 1214570526 pluto[4537]: | received encrypted packet
from 172.16.1.151:4500
Jun 27 18:12:06 1214570526 pluto[4537]: | decrypting 56 bytes using
algorithm OAKLEY_3DES_CBC
Jun 27 18:12:06 1214570526 pluto[4537]: | decrypted:
Jun 27 18:12:06 1214570526 pluto[4537]: |   0b 00 00 14  17 4e 29 bc
71 88 27 39  77 46 af 53
Jun 27 18:12:06 1214570526 pluto[4537]: |   a1 bb c0 67  00 00 00 20
00 00 00 01  01 10 8d 28
Jun 27 18:12:06 1214570526 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
d9 f6 ec 58  c5 89 d0 23
Jun 27 18:12:06 1214570526 pluto[4537]: |   00 00 21 6e  00 00 00 00
Jun 27 18:12:06 1214570526 pluto[4537]: | next IV:  9d e5 bb 10  87 93 8d e9
Jun 27 18:12:06 1214570526 pluto[4537]: | ***parse ISAKMP Hash Payload:
Jun 27 18:12:06 1214570526 pluto[4537]: |    next payload type: ISAKMP_NEXT_N
Jun 27 18:12:06 1214570526 pluto[4537]: |    length: 20
Jun 27 18:12:06 1214570526 pluto[4537]: | ***parse ISAKMP Notification Payload:
Jun 27 18:12:06 1214570526 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:12:07 1214570527 pluto[4537]: |    length: 32
Jun 27 18:12:07 1214570527 pluto[4537]: |    DOI: ISAKMP_DOI_IPSEC
Jun 27 18:12:07 1214570527 pluto[4537]: |    protocol ID: 1
Jun 27 18:12:07 1214570527 pluto[4537]: |    SPI size: 16
Jun 27 18:12:07 1214570527 pluto[4537]: |    Notify Message Type: R_U_THERE
Jun 27 18:12:07 1214570527 pluto[4537]: | removing 4 bytes of padding
Jun 27 18:12:07 1214570527 pluto[4537]: | info:  c0 ba 41 b2  8e 08 66
93  d9 f6 ec 58  c5 89 d0 23
Jun 27 18:12:07 1214570527 pluto[4537]: |   00 00 21 6e
Jun 27 18:12:07 1214570527 pluto[4537]: | processing informational
R_U_THERE (36136)
Jun 27 18:12:07 1214570527 pluto[4537]: | **emit ISAKMP Message:
Jun 27 18:12:07 1214570527 pluto[4537]: |    initiator cookie:
Jun 27 18:12:07 1214570527 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
Jun 27 18:12:07 1214570527 pluto[4537]: |    responder cookie:
Jun 27 18:12:07 1214570527 pluto[4537]: |   d9 f6 ec 58  c5 89 d0 23
Jun 27 18:12:07 1214570527 pluto[4537]: |    next payload type: ISAKMP_NEXT_HASH
Jun 27 18:12:07 1214570527 pluto[4537]: |    ISAKMP version: ISAKMP Version 1.0
Jun 27 18:12:07 1214570527 pluto[4537]: |    exchange type: ISAKMP_XCHG_INFO
Jun 27 18:12:07 1214570527 pluto[4537]: |    flags: ISAKMP_FLAG_ENCRYPTION
Jun 27 18:12:07 1214570527 pluto[4537]: |    message ID:  e0 1d 23 6a
Jun 27 18:12:07 1214570527 pluto[4537]: | ***emit ISAKMP Hash Payload:
Jun 27 18:12:07 1214570527 pluto[4537]: |    next payload type: ISAKMP_NEXT_N
Jun 27 18:12:07 1214570527 pluto[4537]: | emitting 16 zero bytes of
HASH into ISAKMP Hash Payload
Jun 27 18:12:07 1214570527 pluto[4537]: | emitting length of ISAKMP
Hash Payload: 20
Jun 27 18:12:07 1214570527 pluto[4537]: | ***emit ISAKMP Notification Payload:
Jun 27 18:12:07 1214570527 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:12:07 1214570527 pluto[4537]: |    DOI: ISAKMP_DOI_IPSEC
Jun 27 18:12:07 1214570527 pluto[4537]: |    protocol ID: 1
Jun 27 18:12:07 1214570527 pluto[4537]: |    SPI size: 16
Jun 27 18:12:07 1214570527 pluto[4537]: |    Notify Message Type: R_U_THERE_ACK
Jun 27 18:12:07 1214570527 pluto[4537]: | emitting 8 raw bytes of
notify icookie into ISAKMP Notification Payload
Jun 27 18:12:07 1214570527 pluto[4537]: | notify icookie  c0 ba 41 b2
8e 08 66 93
Jun 27 18:12:07 1214570527 pluto[4537]: | emitting 8 raw bytes of
notify rcookie into ISAKMP Notification Payload
Jun 27 18:12:07 1214570527 pluto[4537]: | notify rcookie  d9 f6 ec 58
c5 89 d0 23
Jun 27 18:12:07 1214570527 pluto[4537]: | emitting 4 raw bytes of
notify data into ISAKMP Notification Payload
Jun 27 18:12:07 1214570527 pluto[4537]: | notify data  00 00 21 6e
Jun 27 18:12:07 1214570527 pluto[4537]: | emitting length of ISAKMP
Notification Payload: 32
Jun 27 18:12:07 1214570527 pluto[4537]: | HASH computed:
Jun 27 18:12:07 1214570527 pluto[4537]: |   54 1b 05 b2  63 a0 9f 2f
1e 16 e1 6e  25 80 b0 b6
Jun 27 18:12:07 1214570527 pluto[4537]: | last Phase 1 IV:  6a 6c b8
98  b3 85 52 58
Jun 27 18:12:07 1214570527 pluto[4537]: | current Phase 1 IV:  6a 6c
b8 98  b3 85 52 58
Jun 27 18:12:07 1214570527 pluto[4537]: | computed Phase 2 IV:
Jun 27 18:12:07 1214570527 pluto[4537]: |   9a 61 97 93  d4 ed 28 d2
71 72 4f 0a  9b 82 1a 31
Jun 27 18:12:07 1214570527 pluto[4537]: | encrypting:
Jun 27 18:12:07 1214570527 pluto[4537]: |   0b 00 00 14  54 1b 05 b2
63 a0 9f 2f  1e 16 e1 6e
Jun 27 18:12:07 1214570527 pluto[4537]: |   25 80 b0 b6  00 00 00 20
00 00 00 01  01 10 8d 29
Jun 27 18:12:07 1214570527 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
d9 f6 ec 58  c5 89 d0 23
Jun 27 18:12:07 1214570527 pluto[4537]: |   00 00 21 6e
Jun 27 18:12:07 1214570527 pluto[4537]: | IV:
Jun 27 18:12:07 1214570527 pluto[4537]: |   9a 61 97 93  d4 ed 28 d2
71 72 4f 0a  9b 82 1a 31
Jun 27 18:12:07 1214570527 pluto[4537]: | emitting 4 zero bytes of
encryption padding into ISAKMP Message
Jun 27 18:12:07 1214570527 pluto[4537]: | encrypting using OAKLEY_3DES_CBC
Jun 27 18:12:07 1214570527 pluto[4537]: | next IV:  48 5f 0e f8  d1 38 7e 0c
Jun 27 18:12:07 1214570527 pluto[4537]: | emitting length of ISAKMP Message: 84
Jun 27 18:12:07 1214570527 pluto[4537]: | sending 84 bytes for ISAKMP
notify through eth1:500 to 172.16.1.151:4500:
Jun 27 18:12:07 1214570527 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
d9 f6 ec 58  c5 89 d0 23
Jun 27 18:12:07 1214570527 pluto[4537]: |   08 10 05 01  e0 1d 23 6a
00 00 00 54  9e f7 03 49
Jun 27 18:12:07 1214570527 pluto[4537]: |   5d b2 3a e0  14 94 4f a4
46 18 d3 98  d4 a6 1f 0f
Jun 27 18:12:07 1214570527 pluto[4537]: |   4c b3 76 b8  2c df 48 6f
df 47 b0 c0  2c 25 a9 78
Jun 27 18:12:07 1214570527 pluto[4537]: |   a0 90 f4 28  ae 9b 4e a7
71 c4 ef 29  48 5f 0e f8
Jun 27 18:12:07 1214570527 pluto[4537]: |   d1 38 7e 0c
Jun 27 18:12:07 1214570527 pluto[4537]: | complete state transition
with STF_IGNORE
Jun 27 18:12:07 1214570527 pluto[4537]: | next event
EVENT_NAT_T_KEEPALIVE in 4 seconds
Jun 27 18:12:11 1214570531 pluto[4537]: |
Jun 27 18:12:11 1214570531 pluto[4537]: | *time to handle event
Jun 27 18:12:11 1214570531 pluto[4537]: | handling event EVENT_NAT_T_KEEPALIVE
Jun 27 18:12:11 1214570531 pluto[4537]: | event after this is
EVENT_DPD in 15 seconds
Jun 27 18:12:11 1214570531 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:12:11 1214570531 last message repeated 3 times
Jun 27 18:12:11 1214570531 pluto[4537]: | ka_event: send NAT-KA to
172.16.1.151:4500 (state=#78)
Jun 27 18:12:11 1214570531 pluto[4537]: | sending 1 bytes for NAT-T
Keep Alive through eth1:4500 to 172.16.1.151:4500:
Jun 27 18:12:11 1214570531 pluto[4537]: |   ff
Jun 27 18:12:11 1214570531 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:12:11 1214570531 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:12:11 1214570531 pluto[4537]: | ka_event: send NAT-KA to
172.16.1.151:4500 (state=#77)
Jun 27 18:12:11 1214570531 pluto[4537]: | sending 1 bytes for NAT-T
Keep Alive through eth1:500 to 172.16.1.151:4500:
Jun 27 18:12:11 1214570531 pluto[4537]: |   ff
Jun 27 18:12:11 1214570531 pluto[4537]: | inserting event
EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Jun 27 18:12:11 1214570531 pluto[4537]: | next event EVENT_DPD in 15
seconds for #78
Jun 27 18:12:26 1214570546 pluto[4537]: |
Jun 27 18:12:26 1214570546 pluto[4537]: | *time to handle event
Jun 27 18:12:26 1214570546 pluto[4537]: | handling event EVENT_DPD
Jun 27 18:12:26 1214570546 pluto[4537]: | event after this is
EVENT_NAT_T_KEEPALIVE in 5 seconds
Jun 27 18:12:26 1214570546 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:12:26 1214570546 pluto[4537]: "rw-1"[4] 172.16.1.151 #78:
DPD: Serious: could not find newest phase 1 state
Jun 27 18:12:26 1214570546 pluto[4537]: | next event
EVENT_NAT_T_KEEPALIVE in 5 seconds
Jun 27 18:12:31 1214570551 pluto[4537]: |
Jun 27 18:12:31 1214570551 pluto[4537]: | *time to handle event
Jun 27 18:12:31 1214570551 pluto[4537]: | handling event EVENT_NAT_T_KEEPALIVE
Jun 27 18:12:31 1214570551 pluto[4537]: | event after this is
EVENT_SHUNT_SCAN in 49 seconds
Jun 27 18:12:31 1214570551 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:12:31 1214570551 last message repeated 3 times
Jun 27 18:12:31 1214570551 pluto[4537]: | ka_event: send NAT-KA to
172.16.1.151:4500 (state=#78)
Jun 27 18:12:31 1214570551 pluto[4537]: | sending 1 bytes for NAT-T
Keep Alive through eth1:4500 to 172.16.1.151:4500:
Jun 27 18:12:31 1214570551 pluto[4537]: |   ff
Jun 27 18:12:31 1214570551 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:12:31 1214570551 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:12:31 1214570551 pluto[4537]: | ka_event: send NAT-KA to
172.16.1.151:4500 (state=#77)
Jun 27 18:12:31 1214570551 pluto[4537]: | sending 1 bytes for NAT-T
Keep Alive through eth1:500 to 172.16.1.151:4500:
Jun 27 18:12:31 1214570551 pluto[4537]: |   ff
Jun 27 18:12:31 1214570551 pluto[4537]: | inserting event
EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Jun 27 18:12:31 1214570551 pluto[4537]: | next event
EVENT_NAT_T_KEEPALIVE in 20 seconds
Jun 27 18:12:36 1214570556 pluto[4537]: |
Jun 27 18:12:36 1214570556 pluto[4537]: | *received 84 bytes from
172.16.1.151:4500 on eth1 (port=4500)
Jun 27 18:12:36 1214570556 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
d9 f6 ec 58  c5 89 d0 23
Jun 27 18:12:36 1214570556 pluto[4537]: |   08 10 05 01  1b aa 03 0f
00 00 00 54  9c 09 22 f6
Jun 27 18:12:36 1214570556 pluto[4537]: |   d8 d9 54 ce  67 85 72 91
e3 b5 de 95  f8 df 42 ca
Jun 27 18:12:36 1214570556 pluto[4537]: |   0c 7a 17 cf  8d 7a 01 0f
79 49 21 14  1d 2e 60 a8
Jun 27 18:12:36 1214570556 pluto[4537]: |   60 e8 68 ef  f4 3d 84 5d
51 78 2c bf  07 3d bb 26
Jun 27 18:12:36 1214570556 pluto[4537]: |   ff 5d 37 0b
Jun 27 18:12:36 1214570556 pluto[4537]: | **parse ISAKMP Message:
Jun 27 18:12:36 1214570556 pluto[4537]: |    initiator cookie:
Jun 27 18:12:36 1214570556 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
Jun 27 18:12:36 1214570556 pluto[4537]: |    responder cookie:
Jun 27 18:12:36 1214570556 pluto[4537]: |   d9 f6 ec 58  c5 89 d0 23
Jun 27 18:12:36 1214570556 pluto[4537]: |    next payload type: ISAKMP_NEXT_HASH
Jun 27 18:12:36 1214570556 pluto[4537]: |    ISAKMP version: ISAKMP Version 1.0
Jun 27 18:12:36 1214570556 pluto[4537]: |    exchange type: ISAKMP_XCHG_INFO
Jun 27 18:12:36 1214570556 pluto[4537]: |    flags: ISAKMP_FLAG_ENCRYPTION
Jun 27 18:12:36 1214570556 pluto[4537]: |    message ID:  1b aa 03 0f
Jun 27 18:12:36 1214570556 pluto[4537]: |    length: 84
Jun 27 18:12:36 1214570556 pluto[4537]: |  processing packet with
exchange type=ISAKMP_XCHG_INFO (5)
Jun 27 18:12:36 1214570556 pluto[4537]: | ICOOKIE:  c0 ba 41 b2  8e 08 66 93
Jun 27 18:12:36 1214570556 pluto[4537]: | RCOOKIE:  d9 f6 ec 58  c5 89 d0 23
Jun 27 18:12:36 1214570556 pluto[4537]: | peer:  ac 10 01 97
Jun 27 18:12:36 1214570556 pluto[4537]: | state hash entry 18
Jun 27 18:12:36 1214570556 pluto[4537]: | peer and cookies match on
#78, provided msgid 00000000 vs 66d44d99/00000000
Jun 27 18:12:36 1214570556 pluto[4537]: | peer and cookies match on
#77, provided msgid 00000000 vs 00000000/00000000
Jun 27 18:12:36 1214570556 pluto[4537]: | p15 state object #77 found,
in STATE_AGGR_R2
Jun 27 18:12:36 1214570556 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:12:36 1214570556 pluto[4537]: | last Phase 1 IV:  6a 6c b8
98  b3 85 52 58
Jun 27 18:12:36 1214570556 pluto[4537]: | current Phase 1 IV:  6a 6c
b8 98  b3 85 52 58
Jun 27 18:12:36 1214570556 pluto[4537]: | computed Phase 2 IV:
Jun 27 18:12:36 1214570556 pluto[4537]: |   4b 5f a7 7c  22 a0 da 8e
bc b1 11 94  36 65 79 d7
Jun 27 18:12:36 1214570556 pluto[4537]: | received encrypted packet
from 172.16.1.151:4500
Jun 27 18:12:36 1214570556 pluto[4537]: | decrypting 56 bytes using
algorithm OAKLEY_3DES_CBC
Jun 27 18:12:36 1214570556 pluto[4537]: | decrypted:
Jun 27 18:12:36 1214570556 pluto[4537]: |   0b 00 00 14  04 a6 b1 35
6c 13 fe a5  77 bd 90 6d
Jun 27 18:12:36 1214570556 pluto[4537]: |   66 62 ea 8a  00 00 00 20
00 00 00 01  01 10 8d 28
Jun 27 18:12:36 1214570556 pluto[4537]: |   c0 ba 41 b2  8e 08 66 93
d9 f6 ec 58  c5 89 d0 23
Jun 27 18:12:36 1214570556 pluto[4537]: |   00 00 21 6e  00 00 00 00
Jun 27 18:12:36 1214570556 pluto[4537]: | next IV:  07 3d bb 26  ff 5d 37 0b
Jun 27 18:12:36 1214570556 pluto[4537]: | ***parse ISAKMP Hash Payload:
Jun 27 18:12:36 1214570556 pluto[4537]: |    next payload type: ISAKMP_NEXT_N
Jun 27 18:12:37 1214570557 pluto[4537]: |    length: 20
Jun 27 18:12:37 1214570557 pluto[4537]: | ***parse ISAKMP Notification Payload:
Jun 27 18:12:37 1214570557 pluto[4537]: |    next payload type: ISAKMP_NEXT_NONE
Jun 27 18:12:37 1214570557 pluto[4537]: |    length: 32
Jun 27 18:12:37 1214570557 pluto[4537]: |    DOI: ISAKMP_DOI_IPSEC
Jun 27 18:12:37 1214570557 pluto[4537]: |    protocol ID: 1
Jun 27 18:12:37 1214570557 pluto[4537]: |    SPI size: 16
Jun 27 18:12:37 1214570557 pluto[4537]: |    Notify Message Type: R_U_THERE
Jun 27 18:12:37 1214570557 pluto[4537]: | removing 4 bytes of padding
Jun 27 18:12:37 1214570557 pluto[4537]: | info:  c0 ba 41 b2  8e 08 66
93  d9 f6 ec 58  c5 89 d0 23
Jun 27 18:12:37 1214570557 pluto[4537]: |   00 00 21 6e
Jun 27 18:12:37 1214570557 pluto[4537]: | processing informational
R_U_THERE (36136)
Jun 27 18:12:37 1214570557 pluto[4537]: "rw-1"[4] 172.16.1.151 #77:
DPD: Warning: received old or duplicate R_U_THERE
Jun 27 18:12:37 1214570557 pluto[4537]: | complete state transition
with STF_IGNORE
Jun 27 18:12:37 1214570557 pluto[4537]: | next event
EVENT_NAT_T_KEEPALIVE in 14 seconds
Jun 27 18:12:51 1214570571 pluto[4537]: |
Jun 27 18:12:51 1214570571 pluto[4537]: | *time to handle event
Jun 27 18:12:51 1214570571 pluto[4537]: | handling event EVENT_NAT_T_KEEPALIVE
Jun 27 18:12:51 1214570571 pluto[4537]: | event after this is
EVENT_SHUNT_SCAN in 29 seconds
Jun 27 18:12:51 1214570571 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:12:51 1214570571 last message repeated 3 times
Jun 27 18:12:51 1214570571 pluto[4537]: | ka_event: send NAT-KA to
172.16.1.151:4500 (state=#78)
Jun 27 18:12:51 1214570571 pluto[4537]: | sending 1 bytes for NAT-T
Keep Alive through eth1:4500 to 172.16.1.151:4500:
Jun 27 18:12:51 1214570571 pluto[4537]: |   ff
Jun 27 18:12:51 1214570571 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:12:51 1214570571 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:12:51 1214570571 pluto[4537]: | ka_event: send NAT-KA to
172.16.1.151:4500 (state=#77)
Jun 27 18:12:51 1214570571 pluto[4537]: | sending 1 bytes for NAT-T
Keep Alive through eth1:500 to 172.16.1.151:4500:
Jun 27 18:12:51 1214570571 pluto[4537]: |   ff
Jun 27 18:12:51 1214570571 pluto[4537]: | inserting event
EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Jun 27 18:12:51 1214570571 pluto[4537]: | next event
EVENT_NAT_T_KEEPALIVE in 20 seconds
Jun 27 18:13:11 1214570591 pluto[4537]: |
Jun 27 18:13:11 1214570591 pluto[4537]: | *time to handle event
Jun 27 18:13:11 1214570591 pluto[4537]: | handling event EVENT_NAT_T_KEEPALIVE
Jun 27 18:13:11 1214570591 pluto[4537]: | event after this is
EVENT_SHUNT_SCAN in 9 seconds
Jun 27 18:13:11 1214570591 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:13:11 1214570591 last message repeated 3 times
Jun 27 18:13:11 1214570591 pluto[4537]: | ka_event: send NAT-KA to
172.16.1.151:4500 (state=#78)
Jun 27 18:13:11 1214570591 pluto[4537]: | sending 1 bytes for NAT-T
Keep Alive through eth1:4500 to 172.16.1.151:4500:
Jun 27 18:13:11 1214570591 pluto[4537]: |   ff
Jun 27 18:13:11 1214570591 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:13:11 1214570591 pluto[4537]: | processing connection
rw-1[4] 172.16.1.151
Jun 27 18:13:11 1214570591 pluto[4537]: | ka_event: send NAT-KA to
172.16.1.151:4500 (state=#77)
Jun 27 18:13:11 1214570591 pluto[4537]: | sending 1 bytes for NAT-T
Keep Alive through eth1:500 to 172.16.1.151:4500:
Jun 27 18:13:11 1214570591 pluto[4537]: |   ff
Jun 27 18:13:11 1214570591 pluto[4537]: | inserting event
EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Jun 27 18:13:11 1214570591 pluto[4537]: | next event EVENT_SHUNT_SCAN
in 9 seconds
Jun 27 18:13:17 1214570597 pluto[4537]: |
Jun 27 18:13:17 1214570597 pluto[4537]: | *received whack message
Jun 27 18:13:17 1214570597 pluto[4537]: | base debugging = none