Guest User!

You are not Sophos Staff.

This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

Azure VPN disconnects about every 50 seconds?

All:

   I've got a sophos UTM 9 firewall that has a site to site VPN setup with Azure.  It shows as connected and I can vpn to my server in azure.  On the Azure side it does show a couple of megs of traffic have passed.  However, about every 50 seconds the tunnel seems to go down....and then about 5 seconds later it comes back up.  It seems to do this endlessly.  I've screwed around with just about every setting an, while I might get a few different errors, the dropping behaviour never changes.  I've included some logs below.  Any help would be appreciated.

2016:06:22-14:36:30 remote pluto[10755]: | Notify Message Type: INVALID_MESSAGE_ID

2016:06:22-14:36:30 remote pluto[10755]: | emitting 0 raw bytes of spi into ISAKMP Notification Payload
2016:06:22-14:36:30 remote pluto[10755]: | spi
2016:06:22-14:36:30 remote pluto[10755]: | emitting length of ISAKMP Notification Payload: 12
2016:06:22-14:36:30 remote pluto[10755]: | emitting length of ISAKMP Message: 76
2016:06:22-14:36:30 remote pluto[10755]: | next event EVENT_SA_REPLACE in 5 seconds for #36
2016:06:22-14:36:30 remote pluto[10755]: |
2016:06:22-14:36:30 remote pluto[10755]: | *received 396 bytes from 40.114.5.51:500 on eth0
2016:06:22-14:36:30 remote pluto[10755]: | **parse ISAKMP Message:
2016:06:22-14:36:30 remote pluto[10755]: | initiator cookie:
2016:06:22-14:36:30 remote pluto[10755]: | 1f c4 eb 77 c8 28 86 a9
2016:06:22-14:36:30 remote pluto[10755]: | responder cookie:
2016:06:22-14:36:30 remote pluto[10755]: | 9f 12 22 6c dd 08 ca b8
2016:06:22-14:36:30 remote pluto[10755]: | next payload type: ISAKMP_NEXT_HASH
2016:06:22-14:36:30 remote pluto[10755]: | ISAKMP version: ISAKMP Version 1.0
2016:06:22-14:36:30 remote pluto[10755]: | exchange type: ISAKMP_XCHG_QUICK
2016:06:22-14:36:30 remote pluto[10755]: | flags: ISAKMP_FLAG_ENCRYPTION
2016:06:22-14:36:30 remote pluto[10755]: | message ID: 00 00 00 02
2016:06:22-14:36:30 remote pluto[10755]: | length: 396
2016:06:22-14:36:30 remote pluto[10755]: | ICOOKIE: 1f c4 eb 77 c8 28 86 a9
2016:06:22-14:36:30 remote pluto[10755]: | RCOOKIE: 9f 12 22 6c dd 08 ca b8
2016:06:22-14:36:30 remote pluto[10755]: | peer: 28 72 05 33
2016:06:22-14:36:30 remote pluto[10755]: | state hash entry 16
2016:06:22-14:36:30 remote pluto[10755]: | state object not found
2016:06:22-14:36:30 remote pluto[10755]: | ICOOKIE: 1f c4 eb 77 c8 28 86 a9
2016:06:22-14:36:30 remote pluto[10755]: | RCOOKIE: 9f 12 22 6c dd 08 ca b8
2016:06:22-14:36:30 remote pluto[10755]: | peer: 28 72 05 33
2016:06:22-14:36:30 remote pluto[10755]: | state hash entry 16
2016:06:22-14:36:30 remote pluto[10755]: | state object #37 found, in STATE_MAIN_R3
2016:06:22-14:36:30 remote pluto[10755]: "S_Azure" #37: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0x02000000 (perhaps this is a duplicated packet)
2016:06:22-14:36:30 remote pluto[10755]: "S_Azure" #37: sending encrypted notification INVALID_MESSAGE_ID to 40.114.5.51:500
2016:06:22-14:36:30 remote pluto[10755]: | **emit ISAKMP Message:
2016:06:22-14:36:30 remote pluto[10755]: | initiator cookie:
2016:06:22-14:36:30 remote pluto[10755]: | 1f c4 eb 77 c8 28 86 a9
2016:06:22-14:36:30 remote pluto[10755]: | responder cookie:
2016:06:22-14:36:30 remote pluto[10755]: | 9f 12 22 6c dd 08 ca b8
2016:06:22-14:36:30 remote pluto[10755]: | next payload type: ISAKMP_NEXT_HASH
2016:06:22-14:36:30 remote pluto[10755]: | ISAKMP version: ISAKMP Version 1.0
2016:06:22-14:36:30 remote pluto[10755]: | exchange type: ISAKMP_XCHG_INFO
2016:06:22-14:36:30 remote pluto[10755]: | flags: ISAKMP_FLAG_ENCRYPTION
2016:06:22-14:36:30 remote pluto[10755]: | message ID: f5 40 05 00
2016:06:22-14:36:30 remote pluto[10755]: | ***emit ISAKMP Hash Payload:
2016:06:22-14:36:30 remote pluto[10755]: | next payload type: ISAKMP_NEXT_N
2016:06:22-14:36:30 remote pluto[10755]: | emitting 32 zero bytes of HASH into ISAKMP Hash Payload
2016:06:22-14:36:30 remote pluto[10755]: | emitting length of ISAKMP Hash Payload: 36
2016:06:22-14:36:30 remote pluto[10755]: | ***emit ISAKMP Notification Payload:
2016:06:22-14:36:30 remote pluto[10755]: | next payload type: ISAKMP_NEXT_NONE
2016:06:22-14:36:30 remote pluto[10755]: | DOI: ISAKMP_DOI_IPSEC
2016:06:22-14:36:30 remote pluto[10755]: | protocol ID: 1
2016:06:22-14:36:30 remote pluto[10755]: | SPI size: 0
2016:06:22-14:36:30 remote pluto[10755]: | Notify Message Type: INVALID_MESSAGE_ID
2016:06:22-14:36:30 remote pluto[10755]: | emitting 0 raw bytes of spi into ISAKMP Notification Payload
2016:06:22-14:36:30 remote pluto[10755]: | spi
2016:06:22-14:36:30 remote pluto[10755]: | emitting length of ISAKMP Notification Payload: 12
2016:06:22-14:36:30 remote pluto[10755]: | emitting length of ISAKMP Message: 76
2016:06:22-14:36:30 remote pluto[10755]: | next event EVENT_SA_REPLACE in 5 seconds for #36
2016:06:22-14:36:31 remote pluto[10755]: |
2016:06:22-14:36:31 remote pluto[10755]: | *received 396 bytes from 40.114.5.51:500 on eth0
2016:06:22-14:36:31 remote pluto[10755]: | **parse ISAKMP Message:
2016:06:22-14:36:31 remote pluto[10755]: | initiator cookie:
2016:06:22-14:36:31 remote pluto[10755]: | 1f c4 eb 77 c8 28 86 a9
2016:06:22-14:36:31 remote pluto[10755]: | responder cookie:
2016:06:22-14:36:31 remote pluto[10755]: | 9f 12 22 6c dd 08 ca b8
2016:06:22-14:36:31 remote pluto[10755]: | next payload type: ISAKMP_NEXT_HASH
2016:06:22-14:36:31 remote pluto[10755]: | ISAKMP version: ISAKMP Version 1.0
2016:06:22-14:36:31 remote pluto[10755]: | exchange type: ISAKMP_XCHG_QUICK
2016:06:22-14:36:31 remote pluto[10755]: | flags: ISAKMP_FLAG_ENCRYPTION
2016:06:22-14:36:31 remote pluto[10755]: | message ID: 00 00 00 03
2016:06:22-14:36:31 remote pluto[10755]: | length: 396
2016:06:22-14:36:31 remote pluto[10755]: | ICOOKIE: 1f c4 eb 77 c8 28 86 a9
2016:06:22-14:36:31 remote pluto[10755]: | RCOOKIE: 9f 12 22 6c dd 08 ca b8
2016:06:22-14:36:31 remote pluto[10755]: | peer: 28 72 05 33
2016:06:22-14:36:31 remote pluto[10755]: | state hash entry 16
2016:06:22-14:36:31 remote pluto[10755]: | state object not found
2016:06:22-14:36:31 remote pluto[10755]: | ICOOKIE: 1f c4 eb 77 c8 28 86 a9
2016:06:22-14:36:31 remote pluto[10755]: | RCOOKIE: 9f 12 22 6c dd 08 ca b8
2016:06:22-14:36:31 remote pluto[10755]: | peer: 28 72 05 33
2016:06:22-14:36:31 remote pluto[10755]: | state hash entry 16
2016:06:22-14:36:31 remote pluto[10755]: | state object #37 found, in STATE_MAIN_R3
2016:06:22-14:36:31 remote pluto[10755]: "S_Azure" #37: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0x03000000 (perhaps this is a duplicated packet)
2016:06:22-14:36:31 remote pluto[10755]: "S_Azure" #37: sending encrypted notification INVALID_MESSAGE_ID to 40.114.5.51:500
2016:06:22-14:36:31 remote pluto[10755]: | **emit ISAKMP Message:
2016:06:22-14:36:31 remote pluto[10755]: | initiator cookie:
2016:06:22-14:36:31 remote pluto[10755]: | 1f c4 eb 77 c8 28 86 a9
2016:06:22-14:36:31 remote pluto[10755]: | responder cookie:
2016:06:22-14:36:31 remote pluto[10755]: | 9f 12 22 6c dd 08 ca b8
2016:06:22-14:36:31 remote pluto[10755]: | next payload type: ISAKMP_NEXT_HASH
2016:06:22-14:36:31 remote pluto[10755]: | ISAKMP version: ISAKMP Version 1.0
2016:06:22-14:36:31 remote pluto[10755]: | exchange type: ISAKMP_XCHG_INFO
2016:06:22-14:36:31 remote pluto[10755]: | flags: ISAKMP_FLAG_ENCRYPTION
2016:06:22-14:36:31 remote pluto[10755]: | message ID: 30 b7 b1 29
2016:06:22-14:36:31 remote pluto[10755]: | ***emit ISAKMP Hash Payload:
2016:06:22-14:36:31 remote pluto[10755]: | next payload type: ISAKMP_NEXT_N
2016:06:22-14:36:31 remote pluto[10755]: | emitting 32 zero bytes of HASH into ISAKMP Hash Payload
2016:06:22-14:36:31 remote pluto[10755]: | emitting length of ISAKMP Hash Payload: 36
2016:06:22-14:36:31 remote pluto[10755]: | ***emit ISAKMP Notification Payload:
2016:06:22-14:36:31 remote pluto[10755]: | next payload type: ISAKMP_NEXT_NONE
2016:06:22-14:36:31 remote pluto[10755]: | DOI: ISAKMP_DOI_IPSEC
2016:06:22-14:36:31 remote pluto[10755]: | protocol ID: 1
2016:06:22-14:36:31 remote pluto[10755]: | SPI size: 0
2016:06:22-14:36:31 remote pluto[10755]: | Notify Message Type: INVALID_MESSAGE_ID
2016:06:22-14:36:31 remote pluto[10755]: | emitting 0 raw bytes of spi into ISAKMP Notification Payload
2016:06:22-14:36:31 remote pluto[10755]: | spi
2016:06:22-14:36:31 remote pluto[10755]: | emitting length of ISAKMP Notification Payload: 12
2016:06:22-14:36:31 remote pluto[10755]: | emitting length of ISAKMP Message: 76
2016:06:22-14:36:31 remote pluto[10755]: | next event EVENT_SA_REPLACE in 4 seconds for #36
2016:06:22-14:36:35 remote pluto[10755]: |
2016:06:22-14:36:35 remote pluto[10755]: | *time to handle event
2016:06:22-14:36:35 remote pluto[10755]: | event after this is EVENT_NAT_T_KEEPALIVE in 50 seconds
2016:06:22-14:36:35 remote pluto[10755]: | duplicating state object #37
2016:06:22-14:36:35 remote pluto[10755]: | creating state object #38 at 0x8da2968
2016:06:22-14:36:35 remote pluto[10755]: | ICOOKIE: 1f c4 eb 77 c8 28 86 a9
2016:06:22-14:36:35 remote pluto[10755]: | RCOOKIE: 9f 12 22 6c dd 08 ca b8
2016:06:22-14:36:35 remote pluto[10755]: | peer: 28 72 05 33
2016:06:22-14:36:35 remote pluto[10755]: | state hash entry 16
2016:06:22-14:36:35 remote pluto[10755]: | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #38
2016:06:22-14:36:35 remote pluto[10755]: "S_Azure" #38: initiating Quick Mode PSK+ENCRYPT+TUNNEL+UP to replace #36 {using isakmp#37}
2016:06:22-14:36:35 remote pluto[10755]: | **emit ISAKMP Message:
2016:06:22-14:36:35 remote pluto[10755]: | initiator cookie:
2016:06:22-14:36:35 remote pluto[10755]: | 1f c4 eb 77 c8 28 86 a9
2016:06:22-14:36:35 remote pluto[10755]: | responder cookie:
2016:06:22-14:36:35 remote pluto[10755]: | 9f 12 22 6c dd 08 ca b8
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_HASH
2016:06:22-14:36:35 remote pluto[10755]: | ISAKMP version: ISAKMP Version 1.0
2016:06:22-14:36:35 remote pluto[10755]: | exchange type: ISAKMP_XCHG_QUICK
2016:06:22-14:36:35 remote pluto[10755]: | flags: ISAKMP_FLAG_ENCRYPTION
2016:06:22-14:36:35 remote pluto[10755]: | message ID: 80 74 6c f3
2016:06:22-14:36:35 remote pluto[10755]: | ***emit ISAKMP Hash Payload:
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_SA
2016:06:22-14:36:35 remote pluto[10755]: | emitting 32 zero bytes of HASH into ISAKMP Hash Payload
2016:06:22-14:36:35 remote pluto[10755]: | emitting length of ISAKMP Hash Payload: 36
2016:06:22-14:36:35 remote pluto[10755]: | ***emit ISAKMP Security Association Payload:
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_NONCE
2016:06:22-14:36:35 remote pluto[10755]: | DOI: ISAKMP_DOI_IPSEC
2016:06:22-14:36:35 remote pluto[10755]: | ****emit IPsec DOI SIT:
2016:06:22-14:36:35 remote pluto[10755]: | IPsec DOI SIT: SIT_IDENTITY_ONLY
2016:06:22-14:36:35 remote pluto[10755]: | esp proposal: AES_CBC_256/HMAC_SHA1,
2016:06:22-14:36:35 remote pluto[10755]: | ****emit ISAKMP Proposal Payload:
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_NONE
2016:06:22-14:36:35 remote pluto[10755]: | proposal number: 0
2016:06:22-14:36:35 remote pluto[10755]: | protocol ID: PROTO_IPSEC_ESP
2016:06:22-14:36:35 remote pluto[10755]: | SPI size: 4
2016:06:22-14:36:35 remote pluto[10755]: | number of transforms: 1
2016:06:22-14:36:35 remote pluto[10755]: | netlink_get_spi: allocated 0xb45aabab for esp.0@96.255.31.2
2016:06:22-14:36:35 remote pluto[10755]: | emitting 4 raw bytes of SPI into ISAKMP Proposal Payload
2016:06:22-14:36:35 remote pluto[10755]: | SPI b4 5a ab ab
2016:06:22-14:36:35 remote pluto[10755]: | *****emit ISAKMP Transform Payload (ESP):
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_NONE
2016:06:22-14:36:35 remote pluto[10755]: | transform number: 0
2016:06:22-14:36:35 remote pluto[10755]: | transform ID: AES_CBC
2016:06:22-14:36:35 remote pluto[10755]: | ******emit ISAKMP IPsec DOI attribute:
2016:06:22-14:36:35 remote pluto[10755]: | af+type: ENCAPSULATION_MODE
2016:06:22-14:36:35 remote pluto[10755]: | length/value: 1
2016:06:22-14:36:35 remote pluto[10755]: | [1 is ENCAPSULATION_MODE_TUNNEL]
2016:06:22-14:36:35 remote pluto[10755]: | ******emit ISAKMP IPsec DOI attribute:
2016:06:22-14:36:35 remote pluto[10755]: | af+type: SA_LIFE_TYPE
2016:06:22-14:36:35 remote pluto[10755]: | length/value: 1
2016:06:22-14:36:35 remote pluto[10755]: | [1 is SA_LIFE_TYPE_SECONDS]
2016:06:22-14:36:35 remote pluto[10755]: | ******emit ISAKMP IPsec DOI attribute:
2016:06:22-14:36:35 remote pluto[10755]: | af+type: SA_LIFE_DURATION
2016:06:22-14:36:35 remote pluto[10755]: | length/value: 3600
2016:06:22-14:36:35 remote pluto[10755]: | ******emit ISAKMP IPsec DOI attribute:
2016:06:22-14:36:35 remote pluto[10755]: | af+type: AUTH_ALGORITHM
2016:06:22-14:36:35 remote pluto[10755]: | length/value: 2
2016:06:22-14:36:35 remote pluto[10755]: | [2 is HMAC_SHA1]
2016:06:22-14:36:35 remote pluto[10755]: | ******emit ISAKMP IPsec DOI attribute:
2016:06:22-14:36:35 remote pluto[10755]: | af+type: KEY_LENGTH
2016:06:22-14:36:35 remote pluto[10755]: | length/value: 256
2016:06:22-14:36:35 remote pluto[10755]: | emitting length of ISAKMP Transform Payload (ESP): 28
2016:06:22-14:36:35 remote pluto[10755]: | emitting length of ISAKMP Proposal Payload: 40
2016:06:22-14:36:35 remote pluto[10755]: | emitting length of ISAKMP Security Association Payload: 52
2016:06:22-14:36:35 remote pluto[10755]: | ***emit ISAKMP Nonce Payload:
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_ID
2016:06:22-14:36:35 remote pluto[10755]: | emitting 16 raw bytes of Ni into ISAKMP Nonce Payload
2016:06:22-14:36:35 remote pluto[10755]: | Ni af 79 a0 0a 5f f7 dd 18 99 58 5c 88 ce 3b 14 26
2016:06:22-14:36:35 remote pluto[10755]: | emitting length of ISAKMP Nonce Payload: 20
2016:06:22-14:36:35 remote pluto[10755]: | ***emit ISAKMP Identification Payload (IPsec DOI):
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_ID
2016:06:22-14:36:35 remote pluto[10755]: | ID type: ID_IPV4_ADDR_SUBNET
2016:06:22-14:36:35 remote pluto[10755]: | Protocol ID: 0
2016:06:22-14:36:35 remote pluto[10755]: | port: 0
2016:06:22-14:36:35 remote pluto[10755]: | emitting 4 raw bytes of client network into ISAKMP Identification Payload (IPsec DOI)
2016:06:22-14:36:35 remote pluto[10755]: | client network c0 a8 25 00
2016:06:22-14:36:35 remote pluto[10755]: | emitting 4 raw bytes of client mask into ISAKMP Identification Payload (IPsec DOI)
2016:06:22-14:36:35 remote pluto[10755]: | client mask ff ff ff 00
2016:06:22-14:36:35 remote pluto[10755]: | emitting length of ISAKMP Identification Payload (IPsec DOI): 16
2016:06:22-14:36:35 remote pluto[10755]: | ***emit ISAKMP Identification Payload (IPsec DOI):
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_NONE
2016:06:22-14:36:35 remote pluto[10755]: | ID type: ID_IPV4_ADDR_SUBNET
2016:06:22-14:36:35 remote pluto[10755]: | Protocol ID: 0
2016:06:22-14:36:35 remote pluto[10755]: | port: 0
2016:06:22-14:36:35 remote pluto[10755]: | emitting 4 raw bytes of client network into ISAKMP Identification Payload (IPsec DOI)
2016:06:22-14:36:35 remote pluto[10755]: | client network 0a 0d 00 00
2016:06:22-14:36:35 remote pluto[10755]: | emitting 4 raw bytes of client mask into ISAKMP Identification Payload (IPsec DOI)
2016:06:22-14:36:35 remote pluto[10755]: | client mask ff ff ff 00
2016:06:22-14:36:35 remote pluto[10755]: | emitting length of ISAKMP Identification Payload (IPsec DOI): 16
2016:06:22-14:36:35 remote pluto[10755]: | emitting 4 zero bytes of encryption padding into ISAKMP Message
2016:06:22-14:36:35 remote pluto[10755]: | emitting length of ISAKMP Message: 172
2016:06:22-14:36:35 remote pluto[10755]: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #38
2016:06:22-14:36:35 remote pluto[10755]: | inserting event EVENT_SA_EXPIRE, timeout in 10 seconds for #36
2016:06:22-14:36:35 remote pluto[10755]: | next event EVENT_SA_EXPIRE in 10 seconds for #36
2016:06:22-14:36:35 remote pluto[10755]: |
2016:06:22-14:36:35 remote pluto[10755]: | *received 220 bytes from 40.114.5.51:500 on eth0
2016:06:22-14:36:35 remote pluto[10755]: | **parse ISAKMP Message:
2016:06:22-14:36:35 remote pluto[10755]: | initiator cookie:
2016:06:22-14:36:35 remote pluto[10755]: | 1f c4 eb 77 c8 28 86 a9
2016:06:22-14:36:35 remote pluto[10755]: | responder cookie:
2016:06:22-14:36:35 remote pluto[10755]: | 9f 12 22 6c dd 08 ca b8
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_HASH
2016:06:22-14:36:35 remote pluto[10755]: | ISAKMP version: ISAKMP Version 1.0
2016:06:22-14:36:35 remote pluto[10755]: | exchange type: ISAKMP_XCHG_QUICK
2016:06:22-14:36:35 remote pluto[10755]: | flags: ISAKMP_FLAG_ENCRYPTION+ISAKMP_FLAG_COMMIT
2016:06:22-14:36:35 remote pluto[10755]: | message ID: 80 74 6c f3
2016:06:22-14:36:35 remote pluto[10755]: | length: 220
2016:06:22-14:36:35 remote pluto[10755]: | ICOOKIE: 1f c4 eb 77 c8 28 86 a9
2016:06:22-14:36:35 remote pluto[10755]: | RCOOKIE: 9f 12 22 6c dd 08 ca b8
2016:06:22-14:36:35 remote pluto[10755]: | peer: 28 72 05 33
2016:06:22-14:36:35 remote pluto[10755]: | state hash entry 16
2016:06:22-14:36:35 remote pluto[10755]: | state object #38 found, in STATE_QUICK_I1
2016:06:22-14:36:35 remote pluto[10755]: "S_Azure" #38: IKE message has the Commit Flag set but Pluto doesn't implement this feature; ignoring flag
2016:06:22-14:36:35 remote pluto[10755]: | ***parse ISAKMP Hash Payload:
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_SA
2016:06:22-14:36:35 remote pluto[10755]: | length: 36
2016:06:22-14:36:35 remote pluto[10755]: | ***parse ISAKMP Security Association Payload:
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_NONCE
2016:06:22-14:36:35 remote pluto[10755]: | length: 56
2016:06:22-14:36:35 remote pluto[10755]: | DOI: ISAKMP_DOI_IPSEC
2016:06:22-14:36:35 remote pluto[10755]: | ***parse ISAKMP Nonce Payload:
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_ID
2016:06:22-14:36:35 remote pluto[10755]: | length: 52
2016:06:22-14:36:35 remote pluto[10755]: | ***parse ISAKMP Identification Payload (IPsec DOI):
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_ID
2016:06:22-14:36:35 remote pluto[10755]: | length: 16
2016:06:22-14:36:35 remote pluto[10755]: | ID type: ID_IPV4_ADDR_SUBNET
2016:06:22-14:36:35 remote pluto[10755]: | Protocol ID: 0
2016:06:22-14:36:35 remote pluto[10755]: | port: 0
2016:06:22-14:36:35 remote pluto[10755]: | ***parse ISAKMP Identification Payload (IPsec DOI):
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_NONE
2016:06:22-14:36:35 remote pluto[10755]: | length: 16
2016:06:22-14:36:35 remote pluto[10755]: | ID type: ID_IPV4_ADDR_SUBNET
2016:06:22-14:36:35 remote pluto[10755]: | Protocol ID: 0
2016:06:22-14:36:35 remote pluto[10755]: | port: 0
2016:06:22-14:36:35 remote pluto[10755]: | removing 16 bytes of padding
2016:06:22-14:36:35 remote pluto[10755]: | **emit ISAKMP Message:
2016:06:22-14:36:35 remote pluto[10755]: | initiator cookie:
2016:06:22-14:36:35 remote pluto[10755]: | 1f c4 eb 77 c8 28 86 a9
2016:06:22-14:36:35 remote pluto[10755]: | responder cookie:
2016:06:22-14:36:35 remote pluto[10755]: | 9f 12 22 6c dd 08 ca b8
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_HASH
2016:06:22-14:36:35 remote pluto[10755]: | ISAKMP version: ISAKMP Version 1.0
2016:06:22-14:36:35 remote pluto[10755]: | exchange type: ISAKMP_XCHG_QUICK
2016:06:22-14:36:35 remote pluto[10755]: | flags: ISAKMP_FLAG_ENCRYPTION
2016:06:22-14:36:35 remote pluto[10755]: | message ID: 80 74 6c f3
2016:06:22-14:36:35 remote pluto[10755]: | ****parse IPsec DOI SIT:
2016:06:22-14:36:35 remote pluto[10755]: | IPsec DOI SIT: SIT_IDENTITY_ONLY
2016:06:22-14:36:35 remote pluto[10755]: | ****parse ISAKMP Proposal Payload:
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_NONE
2016:06:22-14:36:35 remote pluto[10755]: | length: 44
2016:06:22-14:36:35 remote pluto[10755]: | proposal number: 0
2016:06:22-14:36:35 remote pluto[10755]: | protocol ID: PROTO_IPSEC_ESP
2016:06:22-14:36:35 remote pluto[10755]: | SPI size: 4
2016:06:22-14:36:35 remote pluto[10755]: | number of transforms: 1
2016:06:22-14:36:35 remote pluto[10755]: | parsing 4 raw bytes of ISAKMP Proposal Payload into SPI
2016:06:22-14:36:35 remote pluto[10755]: | SPI 4b a1 88 d2
2016:06:22-14:36:35 remote pluto[10755]: | *****parse ISAKMP Transform Payload (ESP):
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_NONE
2016:06:22-14:36:35 remote pluto[10755]: | length: 32
2016:06:22-14:36:35 remote pluto[10755]: | transform number: 0
2016:06:22-14:36:35 remote pluto[10755]: | transform ID: AES_CBC
2016:06:22-14:36:35 remote pluto[10755]: | ******parse ISAKMP IPsec DOI attribute:
2016:06:22-14:36:35 remote pluto[10755]: | af+type: ENCAPSULATION_MODE
2016:06:22-14:36:35 remote pluto[10755]: | length/value: 1
2016:06:22-14:36:35 remote pluto[10755]: | [1 is ENCAPSULATION_MODE_TUNNEL]
2016:06:22-14:36:35 remote pluto[10755]: | ******parse ISAKMP IPsec DOI attribute:
2016:06:22-14:36:35 remote pluto[10755]: | af+type: KEY_LENGTH
2016:06:22-14:36:35 remote pluto[10755]: | length/value: 256
2016:06:22-14:36:35 remote pluto[10755]: | ******parse ISAKMP IPsec DOI attribute:
2016:06:22-14:36:35 remote pluto[10755]: | af+type: AUTH_ALGORITHM
2016:06:22-14:36:35 remote pluto[10755]: | length/value: 2
2016:06:22-14:36:35 remote pluto[10755]: | [2 is HMAC_SHA1]
2016:06:22-14:36:35 remote pluto[10755]: | ******parse ISAKMP IPsec DOI attribute:
2016:06:22-14:36:35 remote pluto[10755]: | af+type: SA_LIFE_TYPE
2016:06:22-14:36:35 remote pluto[10755]: | length/value: 1
2016:06:22-14:36:35 remote pluto[10755]: | [1 is SA_LIFE_TYPE_SECONDS]
2016:06:22-14:36:35 remote pluto[10755]: | ******parse ISAKMP IPsec DOI attribute:
2016:06:22-14:36:35 remote pluto[10755]: | af+type: SA_LIFE_DURATION (variable length)
2016:06:22-14:36:35 remote pluto[10755]: | length/value: 4
2016:06:22-14:36:35 remote pluto[10755]: | long duration: 3600
2016:06:22-14:36:35 remote pluto[10755]: | kernel_alg_esp_enc_ok(12,256): alg_id=12, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
2016:06:22-14:36:35 remote pluto[10755]: | our client is subnet 192.168.37.0/24
2016:06:22-14:36:35 remote pluto[10755]: | our client protocol/port is 0/0
2016:06:22-14:36:35 remote pluto[10755]: | peer client is subnet 10.13.0.0/24
2016:06:22-14:36:35 remote pluto[10755]: | peer client protocol/port is 0/0
2016:06:22-14:36:35 remote pluto[10755]: | ***emit ISAKMP Hash Payload:
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_NONE
2016:06:22-14:36:35 remote pluto[10755]: | emitting 32 zero bytes of HASH into ISAKMP Hash Payload
2016:06:22-14:36:35 remote pluto[10755]: | emitting length of ISAKMP Hash Payload: 36
2016:06:22-14:36:35 remote pluto[10755]: | kernel_alg_esp_enc_keylen(): alg_id=12, keylen=16
2016:06:22-14:36:35 remote pluto[10755]: | kernel_alg_esp_auth_keylen(auth=2, sadb_aalg=3): a_keylen=20
2016:06:22-14:36:35 remote pluto[10755]: | install_ipsec_sas() for #38: inbound and outbound
2016:06:22-14:36:35 remote pluto[10755]: | route owner of "S_Azure" erouted: self; eroute owner: self
2016:06:22-14:36:35 remote pluto[10755]: | kernel_alg_esp_info():transid=12, auth=2, ei=0x80e0a48, enckeylen=32, authkeylen=20, encryptalg=12, authalg=3
2016:06:22-14:36:35 remote pluto[10755]: | kernel_alg_esp_info():transid=12, auth=2, ei=0x80e0a48, enckeylen=32, authkeylen=20, encryptalg=12, authalg=3
2016:06:22-14:36:35 remote pluto[10755]: | sr for #38: erouted
2016:06:22-14:36:35 remote pluto[10755]: | route owner of "S_Azure" erouted: self; eroute owner: self
2016:06:22-14:36:35 remote pluto[10755]: | route_and_eroute with c: S_Azure (next: none) ero:S_Azure esr:{(nil)} ro:S_Azure rosr:{(nil)} and state: 38
2016:06:22-14:36:35 remote pluto[10755]: | eroute_connection replace eroute 192.168.37.0/24:0 -> 10.13.0.0/24:0 => tun.0@40.114.5.51:0
2016:06:22-14:36:35 remote pluto[10755]: | route_and_eroute: firewall_notified: true
2016:06:22-14:36:35 remote pluto[10755]: | route_and_eroute: instance "S_Azure", setting eroute_owner {spd=0x8d9a9b8,sr=0x8d9a9b8} to #38 (was #36) (newest_ipsec_sa=#36)
2016:06:22-14:36:35 remote pluto[10755]: | emitting 12 zero bytes of encryption padding into ISAKMP Message
2016:06:22-14:36:35 remote pluto[10755]: | emitting length of ISAKMP Message: 76
2016:06:22-14:36:35 remote pluto[10755]: | inR1_outI2: instance S_Azure[0], setting newest_ipsec_sa to #38 (was #36) (spd.eroute=#38)
2016:06:22-14:36:35 remote pluto[10755]: | ICOOKIE: 1f c4 eb 77 c8 28 86 a9
2016:06:22-14:36:35 remote pluto[10755]: | RCOOKIE: 9f 12 22 6c dd 08 ca b8
2016:06:22-14:36:35 remote pluto[10755]: | peer: 28 72 05 33
2016:06:22-14:36:35 remote pluto[10755]: | state hash entry 16
2016:06:22-14:36:35 remote pluto[10755]: | state object #37 found, in STATE_MAIN_R3
2016:06:22-14:36:35 remote pluto[10755]: | inserting event EVENT_SA_REPLACE, timeout in 2733 seconds for #38
2016:06:22-14:36:35 remote pluto[10755]: "S_Azure" #38: sent QI2, IPsec SA established {ESP=>0x4ba188d2 <0xb45aabab}
2016:06:22-14:36:35 remote pluto[10755]: | next event EVENT_SA_EXPIRE in 10 seconds for #36
2016:06:22-14:36:35 remote pluto[10755]: |
2016:06:22-14:36:35 remote pluto[10755]: | *received 92 bytes from 40.114.5.51:500 on eth0
2016:06:22-14:36:35 remote pluto[10755]: | **parse ISAKMP Message:
2016:06:22-14:36:35 remote pluto[10755]: | initiator cookie:
2016:06:22-14:36:35 remote pluto[10755]: | 1f c4 eb 77 c8 28 86 a9
2016:06:22-14:36:35 remote pluto[10755]: | responder cookie:
2016:06:22-14:36:35 remote pluto[10755]: | 9f 12 22 6c dd 08 ca b8
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_HASH
2016:06:22-14:36:35 remote pluto[10755]: | ISAKMP version: ISAKMP Version 1.0
2016:06:22-14:36:35 remote pluto[10755]: | exchange type: ISAKMP_XCHG_QUICK
2016:06:22-14:36:35 remote pluto[10755]: | flags: ISAKMP_FLAG_ENCRYPTION+ISAKMP_FLAG_COMMIT
2016:06:22-14:36:35 remote pluto[10755]: | message ID: 80 74 6c f3
2016:06:22-14:36:35 remote pluto[10755]: | length: 92
2016:06:22-14:36:35 remote pluto[10755]: | ICOOKIE: 1f c4 eb 77 c8 28 86 a9
2016:06:22-14:36:35 remote pluto[10755]: | RCOOKIE: 9f 12 22 6c dd 08 ca b8
2016:06:22-14:36:35 remote pluto[10755]: | peer: 28 72 05 33
2016:06:22-14:36:35 remote pluto[10755]: | state hash entry 16
2016:06:22-14:36:35 remote pluto[10755]: | state object #38 found, in STATE_QUICK_I2
2016:06:22-14:36:35 remote pluto[10755]: "S_Azure" #38: IKE message has the Commit Flag set but Pluto doesn't implement this feature; ignoring flag
2016:06:22-14:36:35 remote pluto[10755]: "S_Azure" #38: message ignored because it contains an unexpected payload type (ISAKMP_NEXT_HASH)
2016:06:22-14:36:35 remote pluto[10755]: "S_Azure" #38: sending encrypted notification INVALID_PAYLOAD_TYPE to 40.114.5.51:500
2016:06:22-14:36:35 remote pluto[10755]: | **emit ISAKMP Message:
2016:06:22-14:36:35 remote pluto[10755]: | initiator cookie:
2016:06:22-14:36:35 remote pluto[10755]: | 1f c4 eb 77 c8 28 86 a9
2016:06:22-14:36:35 remote pluto[10755]: | responder cookie:
2016:06:22-14:36:35 remote pluto[10755]: | 9f 12 22 6c dd 08 ca b8
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_HASH
2016:06:22-14:36:35 remote pluto[10755]: | ISAKMP version: ISAKMP Version 1.0
2016:06:22-14:36:35 remote pluto[10755]: | exchange type: ISAKMP_XCHG_INFO
2016:06:22-14:36:35 remote pluto[10755]: | flags: ISAKMP_FLAG_ENCRYPTION
2016:06:22-14:36:35 remote pluto[10755]: | message ID: dd 57 17 5a
2016:06:22-14:36:35 remote pluto[10755]: | ***emit ISAKMP Hash Payload:
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_N
2016:06:22-14:36:35 remote pluto[10755]: | emitting 32 zero bytes of HASH into ISAKMP Hash Payload
2016:06:22-14:36:35 remote pluto[10755]: | emitting length of ISAKMP Hash Payload: 36
2016:06:22-14:36:35 remote pluto[10755]: | ***emit ISAKMP Notification Payload:
2016:06:22-14:36:35 remote pluto[10755]: | next payload type: ISAKMP_NEXT_NONE
2016:06:22-14:36:35 remote pluto[10755]: | DOI: ISAKMP_DOI_IPSEC
2016:06:22-14:36:35 remote pluto[10755]: | protocol ID: 1
2016:06:22-14:36:35 remote pluto[10755]: | SPI size: 0
2016:06:22-14:36:35 remote pluto[10755]: | Notify Message Type: INVALID_PAYLOAD_TYPE
2016:06:22-14:36:35 remote pluto[10755]: | emitting 0 raw bytes of spi into ISAKMP Notification Payload
2016:06:22-14:36:35 remote pluto[10755]: | spi
2016:06:22-14:36:35 remote pluto[10755]: | emitting length of ISAKMP Notification Payload: 12
2016:06:22-14:36:35 remote pluto[10755]: | emitting length of ISAKMP Message: 76
2016:06:22-14:36:35 remote pluto[10755]: | next event EVENT_SA_EXPIRE in 10 seconds for #36
2016:06:22-14:36:40 remote pluto[10755]: |
2016:06:22-14:36:40 remote pluto[10755]: | *received whack message
2016:06:22-14:36:40 remote pluto[10755]: | get esp.4ba188d2@40.114.5.51
2016:06:22-14:36:40 remote pluto[10755]: | current: 108214 bytes
2016:06:22-14:36:40 remote pluto[10755]: | get outbound policy with reqid 16389
2016:06:22-14:36:40 remote pluto[10755]: | use_time: Jun 22 14:36:40 2016
2016:06:22-14:36:40 remote pluto[10755]: | get esp.b45aabab@96.255.31.2
2016:06:22-14:36:40 remote pluto[10755]: | current: 85442 bytes
2016:06:22-14:36:40 remote pluto[10755]: | get inbound policy with reqid 16389
2016:06:22-14:36:40 remote pluto[10755]: | use_time: Jun 22 14:36:40 2016
2016:06:22-14:36:40 remote pluto[10755]: | get esp.4fcf3b64@40.114.5.51
2016:06:22-14:36:40 remote pluto[10755]: | current: 124208 bytes
2016:06:22-14:36:40 remote pluto[10755]: | get esp.94389e20@96.255.31.2
2016:06:22-14:36:40 remote pluto[10755]: | current: 122167 bytes
2016:06:22-14:36:40 remote pluto[10755]: | next event EVENT_SA_EXPIRE in 5 seconds for #36
2016:06:22-14:36:45 remote pluto[10755]: |
2016:06:22-14:36:45 remote pluto[10755]: | *time to handle event
2016:06:22-14:36:45 remote pluto[10755]: | event after this is EVENT_NAT_T_KEEPALIVE in 40 seconds
2016:06:22-14:36:45 remote pluto[10755]: | **emit ISAKMP Message:
2016:06:22-14:36:45 remote pluto[10755]: | initiator cookie:
2016:06:22-14:36:45 remote pluto[10755]: | 1f c4 eb 77 c8 28 86 a9
2016:06:22-14:36:45 remote pluto[10755]: | responder cookie:
2016:06:22-14:36:45 remote pluto[10755]: | 9f 12 22 6c dd 08 ca b8
2016:06:22-14:36:45 remote pluto[10755]: | next payload type: ISAKMP_NEXT_HASH
2016:06:22-14:36:45 remote pluto[10755]: | ISAKMP version: ISAKMP Version 1.0
2016:06:22-14:36:45 remote pluto[10755]: | exchange type: ISAKMP_XCHG_INFO
2016:06:22-14:36:45 remote pluto[10755]: | flags: ISAKMP_FLAG_ENCRYPTION
2016:06:22-14:36:45 remote pluto[10755]: | message ID: 77 5f c1 36
2016:06:22-14:36:45 remote pluto[10755]: | ***emit ISAKMP Hash Payload:
2016:06:22-14:36:45 remote pluto[10755]: | next payload type: ISAKMP_NEXT_D
2016:06:22-14:36:45 remote pluto[10755]: | emitting 32 zero bytes of HASH(1) into ISAKMP Hash Payload
2016:06:22-14:36:45 remote pluto[10755]: | emitting length of ISAKMP Hash Payload: 36
2016:06:22-14:36:45 remote pluto[10755]: | ***emit ISAKMP Delete Payload:
2016:06:22-14:36:45 remote pluto[10755]: | next payload type: ISAKMP_NEXT_NONE
2016:06:22-14:36:45 remote pluto[10755]: | DOI: ISAKMP_DOI_IPSEC
2016:06:22-14:36:45 remote pluto[10755]: | protocol ID: 3
2016:06:22-14:36:45 remote pluto[10755]: | SPI size: 4
2016:06:22-14:36:45 remote pluto[10755]: | number of SPIs: 1
2016:06:22-14:36:45 remote pluto[10755]: | emitting 4 raw bytes of delete payload into ISAKMP Delete Payload
2016:06:22-14:36:45 remote pluto[10755]: | delete payload 94 38 9e 20
2016:06:22-14:36:45 remote pluto[10755]: | emitting length of ISAKMP Delete Payload: 16
2016:06:22-14:36:45 remote pluto[10755]: | emitting 12 zero bytes of encryption padding into ISAKMP Message
2016:06:22-14:36:45 remote pluto[10755]: | emitting length of ISAKMP Message: 92
2016:06:22-14:36:45 remote pluto[10755]: | ICOOKIE: 22 b8 3c 6c 77 6f 0e ba
2016:06:22-14:36:45 remote pluto[10755]: | RCOOKIE: ef 53 7e 64 d7 ef c4 a3
2016:06:22-14:36:45 remote pluto[10755]: | peer: 28 72 05 33
2016:06:22-14:36:45 remote pluto[10755]: | state hash entry 25
2016:06:22-14:36:45 remote pluto[10755]: | delete esp.4fcf3b64@40.114.5.51
2016:06:22-14:36:45 remote pluto[10755]: | delete esp.94389e20@96.255.31.2
2016:06:22-14:36:45 remote pluto[10755]: | next event EVENT_NAT_T_KEEPALIVE in 40

EINIT_SECRET in 2612 seconds



This thread was automatically locked due to age.
Parents
  • Hi, Andrew, and welcome to the UTM Community!

    Please turn off Debug, Disable the IPsec Connection, start the IPsec Live Log and, after a few lines show in the log, enable the IPsec Connection.  Post approximately 60 lines from a single connection attempt.

    Cheers - Bob

     
    Sophos UTM Community Moderator
    Sophos Certified Architect - UTM
    Sophos Certified Engineer - XG
    Gold Solution Partner since 2005
    MediaSoft, Inc. USA
Reply
  • Hi, Andrew, and welcome to the UTM Community!

    Please turn off Debug, Disable the IPsec Connection, start the IPsec Live Log and, after a few lines show in the log, enable the IPsec Connection.  Post approximately 60 lines from a single connection attempt.

    Cheers - Bob

     
    Sophos UTM Community Moderator
    Sophos Certified Architect - UTM
    Sophos Certified Engineer - XG
    Gold Solution Partner since 2005
    MediaSoft, Inc. USA
Children
  • I've deleted my entire Azure config and rebuilt it but get the same error.  Here are the log lines:

    2016:06:29-12:30:38 remote pluto[9737]: Using Linux 2.6 IPsec interface code

    2016:06:29-12:30:38 remote ipsec_starter[9731]: pluto (9737) started after 20 ms
    2016:06:29-12:30:38 remote pluto[9737]: loading ca certificates from '/etc/ipsec.d/cacerts'
    2016:06:29-12:30:38 remote pluto[9737]: loaded ca certificate from '/etc/ipsec.d/cacerts/VPN Signing CA.pem'
    2016:06:29-12:30:38 remote pluto[9737]: loading aa certificates from '/etc/ipsec.d/aacerts'
    2016:06:29-12:30:38 remote pluto[9737]: loading ocsp certificates from '/etc/ipsec.d/ocspcerts'
    2016:06:29-12:30:38 remote pluto[9737]: Changing to directory '/etc/ipsec.d/crls'
    2016:06:29-12:30:38 remote pluto[9737]: loading attribute certificates from '/etc/ipsec.d/acerts'
    2016:06:29-12:30:38 remote pluto[9737]: adding interface tun0/tun0 10.242.2.1:500
    2016:06:29-12:30:38 remote pluto[9737]: adding interface tun0/tun0 10.242.2.1:4500
    2016:06:29-12:30:38 remote pluto[9737]: adding interface eth1/eth1 192.168.37.2:500
    2016:06:29-12:30:38 remote pluto[9737]: adding interface eth1/eth1 192.168.37.2:4500
    2016:06:29-12:30:38 remote pluto[9737]: adding interface eth0/eth0 96.255.31.2:500
    2016:06:29-12:30:38 remote pluto[9737]: adding interface eth0/eth0 96.255.31.2:4500
    2016:06:29-12:30:38 remote pluto[9737]: adding interface lo/lo 127.0.0.1:500
    2016:06:29-12:30:38 remote pluto[9737]: adding interface lo/lo 127.0.0.1:4500
    2016:06:29-12:30:38 remote pluto[9737]: adding interface lo/lo ::1:500
    2016:06:29-12:30:38 remote pluto[9737]: loading secrets from "/etc/ipsec.secrets"
    2016:06:29-12:30:38 remote pluto[9737]: loaded PSK secret for 96.255.31.2 40.121.56.222
    2016:06:29-12:30:38 remote pluto[9737]: listening for IKE messages
    2016:06:29-12:30:38 remote pluto[9737]: added connection description "S_Matrix Azure"
    2016:06:29-12:30:38 remote pluto[9737]: "S_Matrix Azure" #1: initiating Main Mode
    2016:06:29-12:30:38 remote pluto[9737]: ERROR: "S_Matrix Azure" #1: sendto on eth0 to 40.121.56.222:500 failed in main_outI1. Errno 1: Operation not permitted
    2016:06:29-12:30:47 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [01528bbbc00696121849ab9a1c5b2a5100000001]
    2016:06:29-12:30:47 remote pluto[9737]: packet from 40.121.56.222:500: received Vendor ID payload [MS NT5 ISAKMPOAKLEY 00000009]
    2016:06:29-12:30:47 remote pluto[9737]: packet from 40.121.56.222:500: received Vendor ID payload [RFC 3947]
    2016:06:29-12:30:47 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n]
    2016:06:29-12:30:47 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [FRAGMENTATION]
    2016:06:29-12:30:47 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [MS-Negotiation Discovery Capable]
    2016:06:29-12:30:47 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [Vid-Initial-Contact]
    2016:06:29-12:30:47 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [IKE CGA version 1]
    2016:06:29-12:30:47 remote pluto[9737]: "S_Matrix Azure" #2: responding to Main Mode
    2016:06:29-12:30:48 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [01528bbbc00696121849ab9a1c5b2a5100000001]
    2016:06:29-12:30:48 remote pluto[9737]: packet from 40.121.56.222:500: received Vendor ID payload [MS NT5 ISAKMPOAKLEY 00000009]
    2016:06:29-12:30:48 remote pluto[9737]: packet from 40.121.56.222:500: received Vendor ID payload [RFC 3947]
    2016:06:29-12:30:48 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n]
    2016:06:29-12:30:48 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [FRAGMENTATION]
    2016:06:29-12:30:48 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [MS-Negotiation Discovery Capable]
    2016:06:29-12:30:48 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [Vid-Initial-Contact]
    2016:06:29-12:30:48 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [IKE CGA version 1]
    2016:06:29-12:30:48 remote pluto[9737]: "S_Matrix Azure" #3: responding to Main Mode
    2016:06:29-12:30:48 remote pluto[9737]: "S_Matrix Azure" #1: received Vendor ID payload [MS NT5 ISAKMPOAKLEY 00000009]
    2016:06:29-12:30:48 remote pluto[9737]: "S_Matrix Azure" #1: received Vendor ID payload [RFC 3947]
    2016:06:29-12:30:48 remote pluto[9737]: "S_Matrix Azure" #1: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n]
    2016:06:29-12:30:48 remote pluto[9737]: "S_Matrix Azure" #1: ignoring Vendor ID payload [FRAGMENTATION]
    2016:06:29-12:30:48 remote pluto[9737]: "S_Matrix Azure" #1: ignoring Vendor ID payload [MS-Negotiation Discovery Capable]
    2016:06:29-12:30:48 remote pluto[9737]: "S_Matrix Azure" #1: ignoring Vendor ID payload [IKE CGA version 1]
    2016:06:29-12:30:48 remote pluto[9737]: "S_Matrix Azure" #1: enabling possible NAT-traversal with method 3
    2016:06:29-12:30:48 remote pluto[9737]: "S_Matrix Azure" #1: NAT-Traversal: Result using RFC 3947: no NAT detected
    2016:06:29-12:30:48 remote pluto[9737]: "S_Matrix Azure" #1: Peer ID is ID_IPV4_ADDR: '40.121.56.222'
    2016:06:29-12:30:48 remote pluto[9737]: "S_Matrix Azure" #1: ISAKMP SA established
    2016:06:29-12:30:48 remote pluto[9737]: "S_Matrix Azure" #4: initiating Quick Mode PSK+ENCRYPT+TUNNEL+UP {using isakmp#1}
    2016:06:29-12:30:48 remote pluto[9737]: "S_Matrix Azure" #4: IKE message has the Commit Flag set but Pluto doesn't implement this feature; ignoring flag
    2016:06:29-12:30:48 remote pluto[9737]: id="2203" severity="info" sys="SecureNet" sub="vpn" event="Site-to-site VPN up" variant="ipsec" connection="Matrix Azure" address="96.255.31.2" local_net="192.168.37.0/24" remote_net="10.0.0.0/24"
    2016:06:29-12:30:48 remote pluto[9737]: "S_Matrix Azure" #4: sent QI2, IPsec SA established {ESP=>0x92327d5e <0xd53852e9}
    2016:06:29-12:30:48 remote pluto[9737]: "S_Matrix Azure" #4: IKE message has the Commit Flag set but Pluto doesn't implement this feature; ignoring flag
    2016:06:29-12:30:48 remote pluto[9737]: "S_Matrix Azure" #4: message ignored because it contains an unexpected payload type (ISAKMP_NEXT_HASH)
    2016:06:29-12:30:48 remote pluto[9737]: "S_Matrix Azure" #4: sending encrypted notification INVALID_PAYLOAD_TYPE to 40.121.56.222:500
    2016:06:29-12:30:49 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [01528bbbc00696121849ab9a1c5b2a5100000001]
    2016:06:29-12:30:49 remote pluto[9737]: packet from 40.121.56.222:500: received Vendor ID payload [MS NT5 ISAKMPOAKLEY 00000009]
    2016:06:29-12:30:49 remote pluto[9737]: packet from 40.121.56.222:500: received Vendor ID payload [RFC 3947]
    2016:06:29-12:30:49 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n]
    2016:06:29-12:30:49 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [FRAGMENTATION]
    2016:06:29-12:30:49 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [MS-Negotiation Discovery Capable]
    2016:06:29-12:30:49 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [Vid-Initial-Contact]
    2016:06:29-12:30:49 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [IKE CGA version 1]
    2016:06:29-12:30:49 remote pluto[9737]: "S_Matrix Azure" #5: responding to Main Mode
    2016:06:29-12:30:52 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [01528bbbc00696121849ab9a1c5b2a5100000001]
    2016:06:29-12:30:52 remote pluto[9737]: packet from 40.121.56.222:500: received Vendor ID payload [MS NT5 ISAKMPOAKLEY 00000009]
    2016:06:29-12:30:52 remote pluto[9737]: packet from 40.121.56.222:500: received Vendor ID payload [RFC 3947]
    2016:06:29-12:30:52 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n]
    2016:06:29-12:30:52 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [FRAGMENTATION]
    2016:06:29-12:30:52 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [MS-Negotiation Discovery Capable]
    2016:06:29-12:30:52 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [Vid-Initial-Contact]
    2016:06:29-12:30:52 remote pluto[9737]: packet from 40.121.56.222:500: ignoring Vendor ID payload [IKE CGA version 1]
    2016:06:29-12:30:52 remote pluto[9737]: "S_Matrix Azure" #6: responding to Main Mode
  • Hi Andrew,

    2016:06:29-12:30:38 remote pluto[9737]: ERROR: "S_Matrix Azure" #1: sendto on eth0 to 40.121.56.222:500 failed in main_outI1. Errno 1: Operation not permitted

    If this is the next line after Initiating Main Mode, the most likely is that one of the two endpoints is behind an NAT. Do you have any NAT device before UTM and Azure?

    Thanks

    Sachin Gurung
    Team Lead | Sophos Technical Support
    Knowledge Base  |  @SophosSupport  |  Video tutorials
    Remember to like a post.  If a post (on a question thread) solves your question use the 'This helped me' link.