/testing/guestbin/swan-prep
west #
 ipsec start
Redirecting to: [initsystem]
west #
 ../../guestbin/wait-until-pluto-started
west #
 ipsec whack --impair revival
west #
 ipsec whack --impair suppress-retransmits
west #
 ipsec auto --add west-east
002 "west-east/1x0": added IKEv2 connection
002 "west-east/2x0": added IKEv2 connection
002 "west-east/3x0": added IKEv2 connection
002 "west-east/4x0": added IKEv2 connection
west #
 sleep 4
west #
 echo "initdone"
initdone
west #
 # IKE: #1 CHILD: #2, #3, #4, and #5
west #
 ipsec auto --up west-east
000 initiating all conns with alias='west-east'
1v2 "west-east/4x0" #1: initiating IKEv2 connection
000 "west-east/3x0": queue Child SA; waiting on IKE SA "west-east/4x0" #1 negotiating with 192.1.2.23
000 "west-east/2x0": queue Child SA; waiting on IKE SA "west-east/4x0" #1 negotiating with 192.1.2.23
000 "west-east/1x0": queue Child SA; waiting on IKE SA "west-east/4x0" #1 negotiating with 192.1.2.23
1v2 "west-east/4x0" #1: sent IKE_SA_INIT request
002 "west-east/4x0" #1: switching CHILD #2 to pending connection "west-east/1x0"
1v2 "west-east/4x0" #1: sent IKE_AUTH request {cipher=AES_GCM_16_256 integ=n/a prf=HMAC_SHA2_512 group=MODP2048}
003 "west-east/4x0" #1: established IKE SA; authenticated using authby=secret and peer ID_FQDN '@east'
004 "west-east/1x0" #2: established Child SA using #1; IPsec tunnel [192.0.1.254-192.0.1.254:0-65535 0] -> [192.0.2.254-192.0.2.254:0-65535 0] {ESP/ESN=>0xESPESP <0xESPESP xfrm=AES_GCM_16_256-NONE DPD=passive}
002 "west-east/2x0" #3: initiating Child SA using IKE SA #1
002 "west-east/3x0" #4: initiating Child SA using IKE SA #1
002 "west-east/4x0" #5: initiating Child SA using IKE SA #1
1v2 "west-east/2x0" #3: sent CREATE_CHILD_SA request for new IPsec SA
004 "west-east/2x0" #3: established Child SA using #1; IPsec tunnel [192.0.1.253-192.0.1.253:0-65535 0] -> [192.0.2.254-192.0.2.254:0-65535 0] {ESP/ESN=>0xESPESP <0xESPESP xfrm=AES_GCM_16_256-NONE DPD=passive}
1v2 "west-east/3x0" #4: sent CREATE_CHILD_SA request for new IPsec SA
004 "west-east/3x0" #4: established Child SA using #1; IPsec tunnel [192.0.1.252-192.0.1.252:0-65535 0] -> [192.0.2.254-192.0.2.254:0-65535 0] {ESP/ESN=>0xESPESP <0xESPESP xfrm=AES_GCM_16_256-NONE DPD=passive}
1v2 "west-east/4x0" #5: sent CREATE_CHILD_SA request for new IPsec SA
004 "west-east/4x0" #5: established Child SA using #1; IPsec tunnel [192.0.1.251-192.0.1.251:0-65535 0] -> [192.0.2.254-192.0.2.254:0-65535 0] {ESP/ESN=>0xESPESP <0xESPESP xfrm=AES_GCM_16_256-NONE DPD=passive}
west #
 # CHILD #2->#6
west #
 ipsec whack --rekey-ipsec --name west-east/1x0 --async
west #
 # CHILD #3->#7
west #
 ipsec whack --rekey-ipsec --name west-east/2x0 --async
west #
 # CHILD #4->#8
west #
 ipsec whack --rekey-ipsec --name west-east/3x0 --async
west #
 # CHILD #5->#9
west #
 ipsec whack --rekey-ipsec --name west-east/4x0 --async
west #
 sleep 45
west #
 # state #1 in STATE_V2_ESTABLISHED_IKE_SA, and #6, #7, #8 and #9 in STATE_V2_ESTABLISHED_CHILD_SA
west #
 # anything other state is a sign of regression
west #
 ipsec status | grep STATE_
000 #6: "west-east/1x0":500 STATE_V2_ESTABLISHED_CHILD_SA (established Child SA); REKEY in XXs; REPLACE in XXs; newest; eroute owner; IKE SA #1; idle;
000 #7: "west-east/2x0":500 STATE_V2_ESTABLISHED_CHILD_SA (established Child SA); REKEY in XXs; REPLACE in XXs; newest; eroute owner; IKE SA #1; idle;
000 #8: "west-east/3x0":500 STATE_V2_ESTABLISHED_CHILD_SA (established Child SA); REKEY in XXs; REPLACE in XXs; newest; eroute owner; IKE SA #1; idle;
000 #1: "west-east/4x0":500 STATE_V2_ESTABLISHED_IKE_SA (established IKE SA); REKEY in XXs; REPLACE in XXs; newest; idle;
000 #9: "west-east/4x0":500 STATE_V2_ESTABLISHED_CHILD_SA (established Child SA); REKEY in XXs; REPLACE in XXs; newest; eroute owner; IKE SA #1; idle;
west #
 # this is complex grep line susceptible to changes to log lines.
west #
 # until we find better one keep this.
west #
 # May be once the bug is fixed comment it out?
west #
 grep -E  "Message ID:|emit IKEv2 Delete Payload|exchange type:|**emit ISAKMP Message|**parse ISAKMP Message" /tmp/pluto.log
| Message ID: IKE #1 initializing (IKE SA): ike.initiator .sent=0->-1 .recv=0->-1 .recv_frags=0 .recv_wip=0->-1 .last_contact=0->XX.XXX ike.responder .sent=0->-1 .recv=0->-1 .recv_frags=0 .recv_wip=0->-1 .last_contact=0->XX.XXX ike.wip.initiator=0->-1
| **emit ISAKMP Message:
|    exchange type: ISAKMP_v2_IKE_SA_INIT (0x22)
|    Message ID: 0 (00 00 00 00)
| Message ID: updating counters for #1
| Message ID: IKE #1 skipping update_recv as MD is fake
| Message ID: IKE #1 scheduling EVENT_RETRANSMIT: ike.initiator .sent=0 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=0
| Message ID: IKE #1 updating initiator sent message request 0: ike.initiator .sent=-1->0 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1->0
| Message ID: IKE #1 no pending message initiators to schedule: ike.initiator .sent=0 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=0
| **parse ISAKMP Message:
|    exchange type: ISAKMP_v2_IKE_SA_INIT (0x22)
|    Message ID: 0 (00 00 00 00)
| **emit ISAKMP Message:
|    exchange type: ISAKMP_v2_IKE_AUTH (0x23)
|    Message ID: 1 (00 00 00 01)
| Message ID: CHILD #1.#2 initializing (CHILD SA): ike.initiator .sent=0 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=0->-1
| Message ID: updating counters for #1
| Message ID: IKE #1 XXX: no EVENT_RETRANSMIT to clear; suspect IKE->CHILD switch: ike.initiator .sent=0 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| Message ID: IKE #1 updating initiator received message response 0: ike.initiator .sent=0 .recv=-1->0 .recv_frags=0 .last_contact=XX.XXX->XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=0->-1
| Message ID: IKE #1 scheduling EVENT_RETRANSMIT: ike.initiator .sent=1 .recv=0 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=1
| Message ID: IKE #1 updating initiator sent message request 1: ike.initiator .sent=0->1 .recv=0 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1->1
| Message ID: IKE #1 no pending message initiators to schedule: ike.initiator .sent=1 .recv=0 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=1
| **parse ISAKMP Message:
|    exchange type: ISAKMP_v2_IKE_AUTH (0x23)
|    Message ID: 1 (00 00 00 01)
| Message ID: CHILD #1.#3 initializing (CHILD SA): ike.initiator .sent=1 .recv=0 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=0->-1
| Message ID: CHILD #1.#4 initializing (CHILD SA): ike.initiator .sent=1 .recv=0 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=0->-1
| Message ID: CHILD #1.#5 initializing (CHILD SA): ike.initiator .sent=1 .recv=0 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=0->-1
| Message ID: updating counters for #1
| Message ID: IKE #1 clearing EVENT_RETRANSMIT as response received: ike.initiator .sent=1 .recv=0 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| Message ID: IKE #1 updating initiator received message response 1: ike.initiator .sent=1 .recv=0->1 .recv_frags=0 .last_contact=XX.XXX->XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=1->-1
| Message ID: IKE #1 skipping update_send as nothing to send: ike.initiator .sent=1 .recv=1 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| Message ID: IKE #1 no pending message initiators to schedule: ike.initiator .sent=1 .recv=1 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| Message ID: CHILD #1.#3 wakeing IKE SA for next initiator (unack 0): ike.initiator .sent=1 .recv=1 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#3 wakeing IKE SA for next initiator (unack 0): ike.initiator .sent=1 .recv=1 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#3 wakeing IKE SA for next initiator (unack 0): ike.initiator .sent=1 .recv=1 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#3 resuming SA using IKE SA (unack 0): ike.initiator .sent=1 .recv=1 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| **emit ISAKMP Message:
|    exchange type: ISAKMP_v2_CREATE_CHILD_SA (0x24)
|    Message ID: 2 (00 00 00 02)
| Message ID: updating counters for #3
| Message ID: IKE #1 skipping update_recv as MD is fake
| Message ID: CHILD #1.#3 scheduling EVENT_RETRANSMIT: ike.initiator .sent=2 .recv=1 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=2
| Message ID: CHILD #1.#3 updating initiator sent message request 2: ike.initiator .sent=1->2 .recv=1 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1->2
| Message ID: CHILD #1.#4 next initiator blocked by outstanding response (unack 1): ike.initiator .sent=2 .recv=1 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| **parse ISAKMP Message:
|    exchange type: ISAKMP_v2_CREATE_CHILD_SA (0x24)
|    Message ID: 2 (00 00 00 02)
| Message ID: updating counters for #3
| Message ID: CHILD #1.#3 clearing EVENT_RETRANSMIT as response received: ike.initiator .sent=2 .recv=1 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#3 updating initiator received message response 2: ike.initiator .sent=2 .recv=1->2 .recv_frags=0 .last_contact=XX.XXX->XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=2->-1
| Message ID: CHILD #1.#3 skipping update_send as nothing to send: ike.initiator .sent=2 .recv=2 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#4 wakeing IKE SA for next initiator (unack 0): ike.initiator .sent=2 .recv=2 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#4 resuming SA using IKE SA (unack 0): ike.initiator .sent=2 .recv=2 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| **emit ISAKMP Message:
|    exchange type: ISAKMP_v2_CREATE_CHILD_SA (0x24)
|    Message ID: 3 (00 00 00 03)
| Message ID: updating counters for #4
| Message ID: IKE #1 skipping update_recv as MD is fake
| Message ID: CHILD #1.#4 scheduling EVENT_RETRANSMIT: ike.initiator .sent=3 .recv=2 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=3
| Message ID: CHILD #1.#4 updating initiator sent message request 3: ike.initiator .sent=2->3 .recv=2 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1->3
| Message ID: CHILD #1.#5 next initiator blocked by outstanding response (unack 1): ike.initiator .sent=3 .recv=2 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| **parse ISAKMP Message:
|    exchange type: ISAKMP_v2_CREATE_CHILD_SA (0x24)
|    Message ID: 3 (00 00 00 03)
| Message ID: updating counters for #4
| Message ID: CHILD #1.#4 clearing EVENT_RETRANSMIT as response received: ike.initiator .sent=3 .recv=2 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#4 updating initiator received message response 3: ike.initiator .sent=3 .recv=2->3 .recv_frags=0 .last_contact=XX.XXX->XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=3->-1
| Message ID: CHILD #1.#4 skipping update_send as nothing to send: ike.initiator .sent=3 .recv=3 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#5 wakeing IKE SA for next initiator (unack 0): ike.initiator .sent=3 .recv=3 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#5 resuming SA using IKE SA (unack 0): ike.initiator .sent=3 .recv=3 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| **emit ISAKMP Message:
|    exchange type: ISAKMP_v2_CREATE_CHILD_SA (0x24)
|    Message ID: 4 (00 00 00 04)
| Message ID: updating counters for #5
| Message ID: IKE #1 skipping update_recv as MD is fake
| Message ID: CHILD #1.#5 scheduling EVENT_RETRANSMIT: ike.initiator .sent=4 .recv=3 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=4
| Message ID: CHILD #1.#5 updating initiator sent message request 4: ike.initiator .sent=3->4 .recv=3 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1->4
| Message ID: IKE #1 no pending message initiators to schedule: ike.initiator .sent=4 .recv=3 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| **parse ISAKMP Message:
|    exchange type: ISAKMP_v2_CREATE_CHILD_SA (0x24)
|    Message ID: 4 (00 00 00 04)
| Message ID: updating counters for #5
| Message ID: CHILD #1.#5 clearing EVENT_RETRANSMIT as response received: ike.initiator .sent=4 .recv=3 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#5 updating initiator received message response 4: ike.initiator .sent=4 .recv=3->4 .recv_frags=0 .last_contact=XX.XXX->XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=4->-1
| Message ID: CHILD #1.#5 skipping update_send as nothing to send: ike.initiator .sent=4 .recv=4 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: IKE #1 no pending message initiators to schedule: ike.initiator .sent=4 .recv=4 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| Message ID: CHILD #1.#6 initializing (CHILD SA): ike.initiator .sent=4 .recv=4 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=0->-1
| Message ID: CHILD #1.#6 wakeing IKE SA for next initiator (unack 0): ike.initiator .sent=4 .recv=4 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#6 resuming SA using IKE SA (unack 0): ike.initiator .sent=4 .recv=4 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| **emit ISAKMP Message:
|    exchange type: ISAKMP_v2_CREATE_CHILD_SA (0x24)
|    Message ID: 5 (00 00 00 05)
| Message ID: updating counters for #6
| Message ID: IKE #1 skipping update_recv as MD is fake
| Message ID: CHILD #1.#6 scheduling EVENT_RETRANSMIT: ike.initiator .sent=5 .recv=4 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=5
| Message ID: CHILD #1.#6 updating initiator sent message request 5: ike.initiator .sent=4->5 .recv=4 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1->5
| Message ID: IKE #1 no pending message initiators to schedule: ike.initiator .sent=5 .recv=4 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| Message ID: CHILD #1.#7 initializing (CHILD SA): ike.initiator .sent=5 .recv=4 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=0->-1
| Message ID: CHILD #1.#7 next initiator blocked by outstanding response (unack 1): ike.initiator .sent=5 .recv=4 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#8 initializing (CHILD SA): ike.initiator .sent=5 .recv=4 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=0->-1
| Message ID: CHILD #1.#7 next initiator blocked by outstanding response (unack 1): ike.initiator .sent=5 .recv=4 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#9 initializing (CHILD SA): ike.initiator .sent=5 .recv=4 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=0->-1
| Message ID: CHILD #1.#7 next initiator blocked by outstanding response (unack 1): ike.initiator .sent=5 .recv=4 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| **parse ISAKMP Message:
|    exchange type: ISAKMP_v2_CREATE_CHILD_SA (0x24)
|    Message ID: 5 (00 00 00 05)
| Message ID: updating counters for #6
| Message ID: CHILD #1.#6 clearing EVENT_RETRANSMIT as response received: ike.initiator .sent=5 .recv=4 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#6 updating initiator received message response 5: ike.initiator .sent=5 .recv=4->5 .recv_frags=0 .last_contact=XX.XXX->XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=5->-1
| Message ID: CHILD #1.#6 skipping update_send as nothing to send: ike.initiator .sent=5 .recv=5 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#7 wakeing IKE SA for next initiator (unack 0): ike.initiator .sent=5 .recv=5 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#7 resuming SA using IKE SA (unack 0): ike.initiator .sent=5 .recv=5 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| **emit ISAKMP Message:
|    exchange type: ISAKMP_v2_CREATE_CHILD_SA (0x24)
|    Message ID: 6 (00 00 00 06)
| Message ID: updating counters for #7
| Message ID: IKE #1 skipping update_recv as MD is fake
| Message ID: CHILD #1.#7 scheduling EVENT_RETRANSMIT: ike.initiator .sent=6 .recv=5 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=6
| Message ID: CHILD #1.#7 updating initiator sent message request 6: ike.initiator .sent=5->6 .recv=5 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1->6
| Message ID: CHILD #1.#8 next initiator blocked by outstanding response (unack 1): ike.initiator .sent=6 .recv=5 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#2 next initiator blocked by outstanding response (unack 1): ike.initiator .sent=6 .recv=5 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| **parse ISAKMP Message:
|    exchange type: ISAKMP_v2_CREATE_CHILD_SA (0x24)
|    Message ID: 6 (00 00 00 06)
| Message ID: updating counters for #7
| Message ID: CHILD #1.#7 clearing EVENT_RETRANSMIT as response received: ike.initiator .sent=6 .recv=5 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#7 updating initiator received message response 6: ike.initiator .sent=6 .recv=5->6 .recv_frags=0 .last_contact=XX.XXX->XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=6->-1
| Message ID: CHILD #1.#7 skipping update_send as nothing to send: ike.initiator .sent=6 .recv=6 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#2 wakeing IKE SA for next initiator (unack 0): ike.initiator .sent=6 .recv=6 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: IKE #1 resuming SA using IKE SA (unack 0): ike.initiator .sent=6 .recv=6 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| **emit ISAKMP Message:
|    exchange type: ISAKMP_v2_INFORMATIONAL (0x25)
|    Message ID: 7 (00 00 00 07)
| ****emit IKEv2 Delete Payload:
| Message ID: updating counters for #1
| Message ID: IKE #1 skipping update_recv as MD is fake
| Message ID: IKE #1 scheduling EVENT_RETRANSMIT: ike.initiator .sent=7 .recv=6 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=7
| Message ID: IKE #1 updating initiator sent message request 7: ike.initiator .sent=6->7 .recv=6 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1->7
| Message ID: CHILD #1.#8 next initiator blocked by outstanding response (unack 1): ike.initiator .sent=7 .recv=6 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| **parse ISAKMP Message:
|    exchange type: ISAKMP_v2_INFORMATIONAL (0x25)
|    Message ID: 7 (00 00 00 07)
| Message ID: updating counters for #1
| Message ID: IKE #1 clearing EVENT_RETRANSMIT as response received: ike.initiator .sent=7 .recv=6 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| Message ID: IKE #1 updating initiator received message response 7: ike.initiator .sent=7 .recv=6->7 .recv_frags=0 .last_contact=XX.XXX->XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=7->-1
| Message ID: IKE #1 skipping update_send as nothing to send: ike.initiator .sent=7 .recv=7 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| Message ID: CHILD #1.#8 wakeing IKE SA for next initiator (unack 0): ike.initiator .sent=7 .recv=7 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#8 resuming SA using IKE SA (unack 0): ike.initiator .sent=7 .recv=7 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| **emit ISAKMP Message:
|    exchange type: ISAKMP_v2_CREATE_CHILD_SA (0x24)
|    Message ID: 8 (00 00 00 08)
| Message ID: updating counters for #8
| Message ID: IKE #1 skipping update_recv as MD is fake
| Message ID: CHILD #1.#8 scheduling EVENT_RETRANSMIT: ike.initiator .sent=8 .recv=7 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=8
| Message ID: CHILD #1.#8 updating initiator sent message request 8: ike.initiator .sent=7->8 .recv=7 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1->8
| Message ID: CHILD #1.#9 next initiator blocked by outstanding response (unack 1): ike.initiator .sent=8 .recv=7 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#3 next initiator blocked by outstanding response (unack 1): ike.initiator .sent=8 .recv=7 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| **parse ISAKMP Message:
|    exchange type: ISAKMP_v2_CREATE_CHILD_SA (0x24)
|    Message ID: 8 (00 00 00 08)
| Message ID: updating counters for #8
| Message ID: CHILD #1.#8 clearing EVENT_RETRANSMIT as response received: ike.initiator .sent=8 .recv=7 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#8 updating initiator received message response 8: ike.initiator .sent=8 .recv=7->8 .recv_frags=0 .last_contact=XX.XXX->XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=8->-1
| Message ID: CHILD #1.#8 skipping update_send as nothing to send: ike.initiator .sent=8 .recv=8 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#3 wakeing IKE SA for next initiator (unack 0): ike.initiator .sent=8 .recv=8 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: IKE #1 resuming SA using IKE SA (unack 0): ike.initiator .sent=8 .recv=8 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| **emit ISAKMP Message:
|    exchange type: ISAKMP_v2_INFORMATIONAL (0x25)
|    Message ID: 9 (00 00 00 09)
| ****emit IKEv2 Delete Payload:
| Message ID: updating counters for #1
| Message ID: IKE #1 skipping update_recv as MD is fake
| Message ID: IKE #1 scheduling EVENT_RETRANSMIT: ike.initiator .sent=9 .recv=8 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=9
| Message ID: IKE #1 updating initiator sent message request 9: ike.initiator .sent=8->9 .recv=8 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1->9
| Message ID: CHILD #1.#9 next initiator blocked by outstanding response (unack 1): ike.initiator .sent=9 .recv=8 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| **parse ISAKMP Message:
|    exchange type: ISAKMP_v2_INFORMATIONAL (0x25)
|    Message ID: 9 (00 00 00 09)
| Message ID: updating counters for #1
| Message ID: IKE #1 clearing EVENT_RETRANSMIT as response received: ike.initiator .sent=9 .recv=8 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| Message ID: IKE #1 updating initiator received message response 9: ike.initiator .sent=9 .recv=8->9 .recv_frags=0 .last_contact=XX.XXX->XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=9->-1
| Message ID: IKE #1 skipping update_send as nothing to send: ike.initiator .sent=9 .recv=9 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| Message ID: CHILD #1.#9 wakeing IKE SA for next initiator (unack 0): ike.initiator .sent=9 .recv=9 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#9 resuming SA using IKE SA (unack 0): ike.initiator .sent=9 .recv=9 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| **emit ISAKMP Message:
|    exchange type: ISAKMP_v2_CREATE_CHILD_SA (0x24)
|    Message ID: 10 (00 00 00 0a)
| Message ID: updating counters for #9
| Message ID: IKE #1 skipping update_recv as MD is fake
| Message ID: CHILD #1.#9 scheduling EVENT_RETRANSMIT: ike.initiator .sent=10 .recv=9 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=10
| Message ID: CHILD #1.#9 updating initiator sent message request 10: ike.initiator .sent=9->10 .recv=9 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1->10
| Message ID: IKE #1 no pending message initiators to schedule: ike.initiator .sent=10 .recv=9 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| Message ID: CHILD #1.#4 next initiator blocked by outstanding response (unack 1): ike.initiator .sent=10 .recv=9 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| **parse ISAKMP Message:
|    exchange type: ISAKMP_v2_CREATE_CHILD_SA (0x24)
|    Message ID: 10 (00 00 00 0a)
| Message ID: updating counters for #9
| Message ID: CHILD #1.#9 clearing EVENT_RETRANSMIT as response received: ike.initiator .sent=10 .recv=9 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#9 updating initiator received message response 10: ike.initiator .sent=10 .recv=9->10 .recv_frags=0 .last_contact=XX.XXX->XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=10->-1
| Message ID: CHILD #1.#9 skipping update_send as nothing to send: ike.initiator .sent=10 .recv=10 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: CHILD #1.#4 wakeing IKE SA for next initiator (unack 0): ike.initiator .sent=10 .recv=10 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: IKE #1 resuming SA using IKE SA (unack 0): ike.initiator .sent=10 .recv=10 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| **emit ISAKMP Message:
|    exchange type: ISAKMP_v2_INFORMATIONAL (0x25)
|    Message ID: 11 (00 00 00 0b)
| ****emit IKEv2 Delete Payload:
| Message ID: updating counters for #1
| Message ID: IKE #1 skipping update_recv as MD is fake
| Message ID: IKE #1 scheduling EVENT_RETRANSMIT: ike.initiator .sent=11 .recv=10 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=11
| Message ID: IKE #1 updating initiator sent message request 11: ike.initiator .sent=10->11 .recv=10 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1->11
| Message ID: IKE #1 no pending message initiators to schedule: ike.initiator .sent=11 .recv=10 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=11
| **parse ISAKMP Message:
|    exchange type: ISAKMP_v2_INFORMATIONAL (0x25)
|    Message ID: 11 (00 00 00 0b)
| Message ID: updating counters for #1
| Message ID: IKE #1 clearing EVENT_RETRANSMIT as response received: ike.initiator .sent=11 .recv=10 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| Message ID: IKE #1 updating initiator received message response 11: ike.initiator .sent=11 .recv=10->11 .recv_frags=0 .last_contact=XX.XXX->XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=11->-1
| Message ID: IKE #1 skipping update_send as nothing to send: ike.initiator .sent=11 .recv=11 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| Message ID: IKE #1 no pending message initiators to schedule: ike.initiator .sent=11 .recv=11 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| Message ID: CHILD #1.#5 wakeing IKE SA for next initiator (unack 0): ike.initiator .sent=11 .recv=11 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX child.wip.initiator=-1
| Message ID: IKE #1 resuming SA using IKE SA (unack 0): ike.initiator .sent=11 .recv=11 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| **emit ISAKMP Message:
|    exchange type: ISAKMP_v2_INFORMATIONAL (0x25)
|    Message ID: 12 (00 00 00 0c)
| ****emit IKEv2 Delete Payload:
| Message ID: updating counters for #1
| Message ID: IKE #1 skipping update_recv as MD is fake
| Message ID: IKE #1 scheduling EVENT_RETRANSMIT: ike.initiator .sent=12 .recv=11 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=12
| Message ID: IKE #1 updating initiator sent message request 12: ike.initiator .sent=11->12 .recv=11 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1->12
| Message ID: IKE #1 no pending message initiators to schedule: ike.initiator .sent=12 .recv=11 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=12
| **parse ISAKMP Message:
|    exchange type: ISAKMP_v2_INFORMATIONAL (0x25)
|    Message ID: 12 (00 00 00 0c)
| Message ID: updating counters for #1
| Message ID: IKE #1 clearing EVENT_RETRANSMIT as response received: ike.initiator .sent=12 .recv=11 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| Message ID: IKE #1 updating initiator received message response 12: ike.initiator .sent=12 .recv=11->12 .recv_frags=0 .last_contact=XX.XXX->XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=12->-1
| Message ID: IKE #1 skipping update_send as nothing to send: ike.initiator .sent=12 .recv=12 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
| Message ID: IKE #1 no pending message initiators to schedule: ike.initiator .sent=12 .recv=12 .recv_frags=0 .last_contact=XX.XXX ike.responder .sent=-1 .recv=-1 .recv_frags=0 .last_contact=XX.XXX ike.wip.initiator=-1
west #
 echo done
done
west #
 ipsec whack --trafficstatus
006 #6: "west-east/1x0", type=ESP, add_time=1234567890, inBytes=0, outBytes=0, id='@east'
006 #7: "west-east/2x0", type=ESP, add_time=1234567890, inBytes=0, outBytes=0, id='@east'
006 #8: "west-east/3x0", type=ESP, add_time=1234567890, inBytes=0, outBytes=0, id='@east'
006 #9: "west-east/4x0", type=ESP, add_time=1234567890, inBytes=0, outBytes=0, id='@east'
west #
 # policies and state should be multiple
west #
 
