Phase 1 ike logs cookie:ff4e9af69a787ea4:0000000000000000

[MP18]

does 0000000000000000  mean that PA is not able to communicate with partner?

[reaper]

what are the system and traffic logs telling you about the connection?

this is a cookie where one side is missing but that can be for all kinds of reasons

[MP18]

system log says

and ( description contains 'IKE phase-2 negotiation is failed as initiator, quick mode. Failed SA: 1.x.x.x[500]-1x.x.1[500] message id:0xF5861F94. Due to negotiation timeout.' )

when i enable debug on gateway  i see

=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2019.05.06 16:46:31 =~=~=~=~=~=~=~=~=~=~=~=
NGFW-1(active)> tail follow yes mp-log ikemgr.log
2019-05-06 16:46:38.169 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:46:38.169 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:38.169 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:46:38.169 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:46:38.169 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:46:38.169 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:46:38.169 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:46:38.169 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:46:38.169 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:46:38.169 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:46:43.219 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:46:43.219 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:46:48.481 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:46:48.482 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:48.482 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:46:48.482 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:48.482 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:46:48.482 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:46:48.482 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:46:48.482 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:46:48.482 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:46:48.482 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:46:48.482 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:46:48.482 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:46:53.837 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:46:53.837 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:46:59.194 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:46:59.194 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:47:04.551 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:47:04.552 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:04.552 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:04.552 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:04.552 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:04.552 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:04.552 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:04.552 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:04.552 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:47:04.552 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:04.552 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:47:04.552 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:04.552 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:04.552 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:47:04.552 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:47:04.552 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:47:04.552 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:47:04.552 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:47:04.552 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:47:04.552 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:47:09.901 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:47:09.901 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:47:15.087 -0600 [DEBG]: { 12: 94}: processing acquire for IKEv1
2019-05-06 16:47:15.087 -0600 [PNTF]: { 12: 94}: ====> PHASE-2 NEGOTIATION STARTED AS INITIATOR, (QUICK MODE) <====
====> Initiated SA: 198.160.x.x[500]-173.x.x.x[500] message id:0x76B787D1 <====
2019-05-06 16:47:15.088 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:15.088 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:15.088 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:15.088 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:15.088 -0600 [DEBG]: { 12: 94}: pfkey getspi sent.
2019-05-06 16:47:15.089 -0600 [DEBG]: { 12: 94}: IDci:
2019-05-06 16:47:15.089 -0600 [DEBG]: { 12: 94}: IDcr:
2019-05-06 16:47:15.089 -0600 [DEBG]: { 12: 94}: add payload of len 52, next type 10(nonce)
2019-05-06 16:47:15.089 -0600 [DEBG]: { 12: 94}: add payload of len 16, next type 4(ke)
2019-05-06 16:47:15.089 -0600 [DEBG]: { 12: 94}: add payload of len 256, next type 5(id)
2019-05-06 16:47:15.089 -0600 [DEBG]: { 12: 94}: add payload of len 12, next type 5(id)
2019-05-06 16:47:15.089 -0600 [DEBG]: { 12: 94}: add payload of len 12, next type 0(none)
2019-05-06 16:47:15.089 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:15.089 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:15.089 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:15.089 -0600 [DEBG]: { 12: 94}: add payload of len 20, next type 1(sa)
2019-05-06 16:47:15.089 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:47:15.089 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:15.089 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:47:15.089 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:15.089 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:15.089 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:47:15.089 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:47:15.089 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:47:15.089 -0600 [DEBG]: { 12: }: 428 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:47:15.669 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:47:15.669 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:47:17.000 -0600 [DEBG]: { 12: }: 428 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: 428 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: DPD monitoring.... ip 0 0
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: DPD R-U-There sent (0)
2019-05-06 16:47:20.000 -0600 [DEBG]: { 12: }: rescheduling send_r_u (5).
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: DPD R-U-There-Ack received
2019-05-06 16:47:20.038 -0600 [DEBG]: { 12: }: received an R-U-THERE-ACK
2019-05-06 16:47:20.038 -0600 [PNTF]: { 12: }: notification message 36137:R-U-THERE-ACK, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:47:20.717 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:47:20.717 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:20.717 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:20.717 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:20.717 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:20.717 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:47:20.717 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:20.717 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:47:20.717 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:20.717 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:20.717 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:47:20.717 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:47:20.717 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:47:20.717 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:47:20.717 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:20.717 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:20.717 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:20.717 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:47:20.718 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:47:20.718 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:47:25.000 -0600 [DEBG]: { 12: }: 428 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:47:25.757 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:47:25.757 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:25.757 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:25.757 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:25.757 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:25.757 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:47:25.757 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:25.757 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:47:25.757 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:25.757 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:25.757 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:47:25.757 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:47:25.757 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:47:25.757 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:47:25.757 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:25.757 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:25.757 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:25.757 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:47:25.757 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:47:25.758 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:47:25.758 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:47:30.797 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:47:30.797 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:30.797 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:30.797 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:30.797 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:30.797 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:47:30.797 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:30.797 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:47:30.797 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:30.797 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:30.797 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:47:30.797 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:47:30.797 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:47:30.797 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:47:30.798 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:47:30.798 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:47:33.000 -0600 [DEBG]: { 12: }: 428 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:47:35.837 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:47:35.837 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:35.837 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:35.837 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:35.837 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:35.837 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:47:35.837 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:35.837 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:47:35.837 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:47:35.838 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:47:35.838 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: encryption(aes)

[MP18]

2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:47:40.878 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:47:40.878 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:47:45.000 -0600 [PNTF]: { : 94}: ====> PHASE-2 NEGOTIATION FAILED AS INITIATOR, (QUICK MODE) <====
====> Failed SA: 198.160.x.x[500]-173.x.x.x[500] message id:0x76B787D1 <==== Due to negotiation timeout.
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:47:46.152 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:47:46.152 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THE

[MP18]

2019-05-06 16:47:46.152 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:47:50.000 -0600 [DEBG]: { 12: }: DPD monitoring.... ip 0 0
2019-05-06 16:47:50.000 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:50.000 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:50.000 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:50.000 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:50.000 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:50.000 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:50.000 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:50.000 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:47:50.000 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:50.000 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:47:50.000 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:50.000 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:50.000 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:47:50.000 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:47:50.000 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:47:50.000 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:47:50.000 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:47:50.000 -0600 [DEBG]: { 12: }: DPD R-U-There sent (0)
2019-05-06 16:47:50.000 -0600 [DEBG]: { 12: }: rescheduling send_r_u (5).
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: DPD R-U-There-Ack received
2019-05-06 16:47:50.403 -0600 [DEBG]: { 12: }: received an R-U-THERE-ACK
2019-05-06 16:47:50.403 -0600 [PNTF]: { 12: }: notification message 36137:R-U-THERE-ACK, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:51.463 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:51.464 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:47:51.464 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:51.464 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:47:51.464 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:51.464 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:51.464 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:47:51.464 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:47:51.464 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:47:51.464 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:47:51.464 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:47:51.464 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:47:51.464 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:47:56.754 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:47:56.754 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:48:02.061 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:48:02.061 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: encryption(aes)

[MP18]

2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:48:07.349 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:48:07.349 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:48:12.646 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:48:12.646 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:48:17.951 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:48:17.951 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:48:17.951 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:48:17.951 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:17.951 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:48:17.951 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:48:17.951 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:17.951 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:48:17.951 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:17.951 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:48:17.951 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:48:17.951 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:48:17.951 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:48:17.952 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:48:17.952 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:48:23.682 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:48:23.682 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: pad length = 8
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: encrypted payload by IV:
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: save IV for next:
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: encrypted.
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: 92 bytes from 198.160.x.x[500] to 173.x.x.x[500]
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: sendto Information notify.
2019-05-06 16:48:28.732 -0600 [DEBG]: { 12: }: received a valid R-U-THERE, ACK sent
2019-05-06 16:48:28.732 -0600 [PNTF]: { 12: }: notification message 36136:R-U-THERE, doi=1 proto_id=1 spi=0f3d10d89d9d9fa8 e32a771bf0534997 (size=16).
2019-05-06 16:48:33.946 -0600 [DEBG]: { 12: }: receive Information.
2019-05-06 16:48:33.946 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:48:33.946 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:48:33.946 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:33.946 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:48:33.946 -0600 [DEBG]: { 12: }: begin decryption.
2019-05-06 16:48:33.946 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:33.946 -0600 [DEBG]: { 12: }: IV was saved for next processing:
2019-05-06 16:48:33.946 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:33.946 -0600 [DEBG]: { 12: }: with key:
2019-05-06 16:48:33.946 -0600 [DEBG]: { 12: }: decrypted payload by IV:
2019-05-06 16:48:33.946 -0600 [DEBG]: { 12: }: decrypted payload, but not trimed.
2019-05-06 16:48:33.946 -0600 [DEBG]: { 12: }: padding len=8
2019-05-06 16:48:33.946 -0600 [DEBG]: { 12: }: decrypted.
2019-05-06 16:48:33.946 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:48:33.946 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:48:33.946 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:48:33.947 -0600 [DEBG]: { 12: }: hash validated.
2019-05-06 16:48:33.947 -0600 [DEBG]: { 12: }: begin.
2019-05-06 16:48:33.947 -0600 [DEBG]: { 12: }: seen nptype=8(hash)
2019-05-06 16:48:33.947 -0600 [DEBG]: { 12: }: seen nptype=11(notify)
2019-05-06 16:48:33.947 -0600 [DEBG]: { 12: }: succeed.
2019-05-06 16:48:33.947 -0600 [DEBG]: { 12: }: DPD R-U-There received
2019-05-06 16:48:33.947 -0600 [DEBG]: { 12: }: compute IV for phase2
2019-05-06 16:48:33.947 -0600 [DEBG]: { 12: }: phase1 last IV:
2019-05-06 16:48:33.947 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:33.947 -0600 [DEBG]: { 12: }: phase2 IV computed:
2019-05-06 16:48:33.947 -0600 [DEBG]: { 12: }: HASH with:
2019-05-06 16:48:33.947 -0600 [DEBG]: { 12: }: hmac(hmac_sha1)
2019-05-06 16:48:33.947 -0600 [DEBG]: { 12: }: HASH computed:
2019-05-06 16:48:33.947 -0600 [DEBG]: { 12: }: begin encryption.
2019-05-06 16:48:33.947 -0600 [DEBG]: { 12: }: encryption(aes)
2019-05-06 16:48:33.947 -0600 [DEBG]: { 12: }: pad length = 8

[MP18]

vendor is blaming us for this issue.

Really need to point what the issue is as per these debug logs?

[reaper · Accepted solution]

What are the issues you're experiencing

At first glance, everything looks alright. You're the initiator which means all the most valuable logs will be at the vendor's end for troubleshooting

Are they seeing any particular error messages? would it be possible to have them try to initiate the tunnel to see if you can glean more information from the incoming connection?

[MP18]

we  were seeing tunnel peridically getting down time to time.

Thanks for your info.

Should i configure PA as passive so that we can be the responder?

if tunnel is down and i have continous ping to vendor LAN IP  and vendor reboots it devices and tunnel comes up then

PA will be initator as we were sending the pings to vendor LAN IP?

[MP18]

Will ask the vendor to try the connection from their end

[reaper · Accepted solution]

Thats right, usually the initiator is the firewall that firat receives a packet from a local.client destined for a remote server. This will trigger it tonstart negitiating a vpn tunnel