IKEv2를 사용하여 vEdge의 서비스 터널에 대한 IPsec 문제 해결

CLI에서 지정된 경로에 대한 현재 로그/디버그 정보를 표시할 수도 있습니다.

monitor start /var/log/messages

IPsec 문제에 대한 트러블슈팅 프로세스 시작 팁

세 가지 서로 다른 IPsec 시나리오를 분리할 수 있습니다. 어떻게 시작해야 할지 알기 위해 더 나은 접근 방식을 취하기 위해 증상을 식별하는 것이 좋은 참고 사항입니다.

1. IPsec 터널이 설정되지 않습니다.
2. IPsec 터널이 다운되어 자동으로 다시 설정되었습니다. (플랩)
3. IPsec 터널이 다운되었으며 다운 상태로 유지됩니다.

IPsec 터널이 증상을 설정하지 않는 경우, IKE 협상의 현재 동작을 확인하기 위해 실시간으로 디버깅해야 합니다.

IPsec 터널이 다운되고 자체 증상(대개 터널 플랩(tunnel Flapped)이라고 함)에 따라 재설정되었으며 근본 원인 분석(root cause analysis, RCA)이 필요합니다. 터널이 다운된 시점이나 디버그를 살펴볼 예상 시간을 아는 것은 필수적입니다.

IPsec 터널이 다운되었고 다운 상태(down state) 증상을 유지한다는 것은 터널이 이전에 작동했지만 어떤 이유로든 다운되었다는 것을 의미하며, 해체 이유와 터널을 다시 성공적으로 설정하는 데 방해가 되는 현재 동작을 알아야 합니다.

트러블슈팅을 시작하기 전에 다음 사항을 확인하십시오.

1. 문제 및 컨피그레이션이 있는 IPsec 터널(번호)입니다.
2. 터널이 다운된 타임스탬프입니다(해당되는 경우).
3. IPsec 피어 IP 주소(터널 대상)입니다.

모든 디버그 및 로그는 /var/log/messages 파일에 저장되지만, 현재 로그의 경우 메시지 파일에 저장되지만, 이 특정 증상으로 플랩 문제가 발생한 지 몇 시간/일 후에 식별될 수 있습니다. 대부분의 관련 디버깅은 messages1,2,3 등에 있을 것입니다. 올바른 메시지 파일을 확인하고 관련된 IPsec 터널의 IKE 협상에 대한 디버깅(charon)을 분석하려면 타임스탬프를 알아야 합니다.

대부분의 디버그는 IPsec 터널 번호를 인쇄하지 않습니다. 협상 및 패킷을 식별하는 가장 빈번한 방법은 원격 피어의 IP 주소 및 터널이 밴드에서 소싱되는 IP 주소를 사용하는 것입니다. IKE 디버깅의 몇 가지 예는 다음과 같습니다.

Jun 18 00:31:22 vedge01 charon: 09[CFG] vici initiate 'child_IPsec2_1'
Jun 18 00:31:22 vedge01 charon: 16[IKE] initiating IKE_SA ipsec2_1[223798] to 10.10.10.1
Jun 18 00:31:22 vedge01 charon: 16[IKE] initiating IKE_SA ipsec2_1[223798] to 10.10.10.1

Jun 18 00:31:22 vedge01 charon: 09[CFG] vici initiate 'child_ipsec2_1'
Jun 18 00:31:22 vedge01 charon: 16[IKE] initiating IKE_SA ipsec2_1[223798] to 10.10.10.1
Jun 18 00:31:22 vedge01 charon: 16[IKE] initiating IKE_SA ipsec2_1[223798] to 10.10.10.1
Jun 18 00:31:22 vedge01 charon: 16[ENC] generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP) N(HASH_ALG) N(REDIR_SUP) ]
Jun 18 00:31:22 vedge01 charon: 16[NET] sending packet: from 10.132.3.92[500] to 10.10.10.1[500] (464 bytes)
Jun 18 00:31:22 vedge01 charon: 12[NET] received packet: from 10.10.10.1[500] to 10.132.3.92[500] (468 bytes)
Jun 18 00:31:22 vedge01 charon: 12[ENC] parsed IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(HTTP_CERT_LOOK) N(FRAG_SUP) V ]
Jun 18 00:31:22 vedge01 charon: 12[ENC] received unknown vendor ID: 4f:85:58:17:1d:21:a0:8d:69:cb:5f:60:9b:3c:06:00
Jun 18 00:31:22 vedge01 charon: 12[IKE] local host is behind NAT, sending keep alives

interface ipsec2
  ip address 192.168.1.9/30
  tunnel-source      10.132.3.92
  tunnel-destination 10.10.10.1
  dead-peer-detection interval 30
  ike
   version      2
   rekey        86400
   cipher-suite aes256-cbc-sha1
   group        14
   authentication-type
    pre-shared-key
     pre-shared-secret $8$wgrs/Cw6tX0na34yF4Fga0B62mGBpHFdOzFaRmoYfnBioWVO3s3efFPBbkaZqvoN
    !
   !
  !
  ipsec
   rekey                   3600
   replay-window           512
   cipher-suite            aes256-gcm
   perfect-forward-secrecy group-14
  !

증상 1.  IPsec 터널이 설정되지 않음

터널의 첫 번째 구현이 문제가 될 수 있으므로 아직 실행되지 않았으며 IKE 디버그가 최상의 옵션입니다.

Jun 18 00:31:17 vedge01 FTMD[1472]: %Viptela-vedge01-FTMD-6-INFO-1000001: VPN 1 Interface ipsec2 DOWN
Jun 18 00:31:17 vedge01 FTMD[1472]: %Viptela-vedge01-ftmd-6-INFO-1400002: Notification: interface-state-change severity-level:major host-name:"vedge01" system-ip:4.0.5.1 vpn-id:1 if-name:"ipsec2" new-state:down 

Jun 18 00:31:17 vedge01 charon: 11[IKE] giving up after 3 retransmits

Jun 18 00:28:22 vedge01 charon: 08[IKE] retransmit 3 of request with message ID 543 (tries=3, timeout=30, exchange=37, state=2) 
Jun 18 00:28:22 vedge01 charon: 08[NET] sending packet: from 10.132.3.92[4500] to 10.10.10.1[4500] (76 bytes)  

Jun 18 00:26:45 vedge01 charon: 06[IKE] retransmit 2 of request with message ID 543 (tries=3, timeout=30, exchange=37, state=2) 
Jun 18 00:26:45 vedge01 charon: 06[NET] sending packet: from 10.132.3.92[4500] to 10.10.10.1[4500] (76 bytes) 

Jun 18 00:25:21 vedge01 charon: 08[IKE] sending DPD request 
Jun 18 00:25:21 vedge01 charon: 08[ENC] generating INFORMATIONAL request 543 [ ] 
Jun 18 00:25:21 vedge01 charon: 08[NET] sending packet: from 10.132.3.92[4500] to 10.10.10.1[4500] (76 bytes) 
Jun 18 00:25:51 vedge01 charon: 05[IKE] retransmit 1 of request with message ID 543 (tries=3, timeout=30, exchange=37, state=2) 
Jun 18 00:25:51 vedge01 charon: 05[NET] sending packet: from 10.132.3.92[4500] to 10.10.10.1[4500] (76 bytes)

마지막으로 성공한 DPD 패킷 교환은 요청 # 542로 설명됩니다.

Jun 18 00:24:08 vedge01 charon: 11[ENC] generating INFORMATIONAL request 542 [ ] 
Jun 18 00:24:08 vedge01 charon: 11[NET] sending packet: from 10.132.3.92[4500] to 10.10.10.1[4500] (76 bytes) 
Jun 18 00:24:08 vedge01 charon: 07[NET] received packet: from 13.51.17.190[4500] to 10.10.10.1[4500] (76 bytes) 
Jun 18 00:24:08 vedge01 charon: 07[ENC] parsed INFORMATIONAL response 542 [ ] 

 2단계. 모든 정보를 올바른 순서로 정렬합니다.

Jun 18 00:24:08 vedge01 charon: 11[ENC] generating INFORMATIONAL request 542 [ ] 
Jun 18 00:24:08 vedge01 charon: 11[NET] sending packet: from 10.132.3.92[4500] to 10.10.10.1[4500] (76 bytes) 
Jun 18 00:24:08 vedge01 charon: 07[NET] received packet: from 10.10.10.1[4500] to 10.132.3.92[4500] (76 bytes) 
Jun 18 00:24:08 vedge01 charon: 07[ENC] parsed INFORMATIONAL response 542 [ ] 

Jun 18 00:25:21 vedge01 charon: 08[IKE] sending DPD request 
Jun 18 00:25:21 vedge01 charon: 08[ENC] generating INFORMATIONAL request 543 [ ] 
Jun 18 00:25:21 vedge01 charon: 08[NET] sending packet: from 10.132.3.92[4500] to 10.10.10.1[4500] (76 bytes) 
Jun 18 00:25:51 vedge01 charon: 05[IKE] retransmit 1 of request with message ID 543 (tries=3, timeout=30, exchange=37, state=2) 
Jun 18 00:25:51 vedge01 charon: 05[NET] sending packet: from 10.132.3.92[4500] to 10.10.10.1[4500] (76 bytes)

Jun 18 00:26:45 vedge01 charon: 06[IKE] retransmit 2 of request with message ID 543 (tries=3, timeout=30, exchange=37, state=2) 
Jun 18 00:26:45 vedge01 charon: 06[NET] sending packet: from 10.132.3.92[4500] to 10.10.10.1[4500] (76 bytes) 

Jun 18 00:28:22 vedge01 charon: 08[IKE] retransmit 3 of request with message ID 543 (tries=3, timeout=30, exchange=37, state=2) 
Jun 18 00:28:22 Lvedge01 charon: 08[NET] sending packet: from 10.132.3.92[4500] to 10.10.10.1[4500] (76 bytes) 

Jun 18 00:31:17 vedge01 charon: 11[IKE] giving up after 3 retransmits
Jun 18 00:31:17 vedge01 FTMD[1472]: %Viptela-LONDSR01-FTMD-6-INFO-1000001: VPN 1 Interface ipsec2 DOWN
Jun 18 00:31:17 vedge01 FTMD[1472]: %Viptela-LONDSR01-ftmd-6-INFO-1400002: Notification: interface-state-change severity-level:major host-name:"LONDSR01" system-ip:4.0.5.1 vpn-id:1 if-name:"ipsec2" new-state:down 

설명한 예에서 vEdge01은 10.10.10.1에서 DPD 패킷을 수신하지 않으므로 터널이 다운됩니다. IPsec 피어가 "lost"로 설정되고 터널이 다운되면 3개의 DPD가 다시 전송되어야 합니다. 이러한 동작에는 여러 가지 이유가 있으며, 일반적으로 패킷이 경로에서 손실되거나 삭제되는 ISP와 관련이 있습니다. 문제가 한 번 발생하면 손실된 트래픽을 추적할 방법이 없지만, 문제가 지속되면 vEdge, 원격 IPSec 피어 및 ISP에서 캡처를 사용하여 패킷을 추적할 수 있습니다.

증상 3. IPsec 터널이 다운되었으며 다운 상태를 유지합니다.

이 증상에 앞서 언급한 것처럼 터널은 이전에는 잘 작동했지만 어떤 이유에서든 굴이 내려오면서 터널을 다시 성공적으로 구축할 수 없었다. 이 시나리오에서는 네트워크에 대한 영향이 있습니다.

트러블슈팅을 시작하기 전에 다음 사항을 확인하십시오.

1. 문제 및 컨피그레이션이 있는 IPsec 터널(번호)입니다.
2. 터널이 다운된 타임스탬프입니다.
3. IPsec 피어 IP 주소(터널 대상)

PFS 불일치

이 예에서는 터널이 다운될 때 타임스탬프로 트러블슈팅이 시작되지 않습니다. 문제가 지속되면 IKE 디버깅이 최상의 옵션입니다. 

interface ipsec1
  description             VWAN_VPN
  ip address 192.168.0.101/30
  tunnel-source-interface ge0/0
  tunnel-destination      10.10.10.1
  ike
   version      2
   rekey        28800
   cipher-suite aes256-cbc-sha1
   group        2
   authentication-type
    pre-shared-key
     pre-shared-secret "$8$njK2pLLjgKWNQu0KecNtY3+fo3hbTs0/7iJy6unNtersmCGjGB38kIPjsoqqXZdVmtizLu79\naQdjt2POM242Yw=="
    !
   !
  !
  ipsec
   rekey                   3600
   replay-window           512
   cipher-suite            aes256-cbc-sha1
   perfect-forward-secrecy group-16 
  !
  mtu                     1400
  no shutdown

디버그 링크가 활성화되고 협상이 표시됩니다.

daemon.info: Apr 27 05:12:56 vedge01 charon: 16[NET] received packet: from 10.10.10.1[4500] to 172.28.0.36[4500] (508 bytes) 
daemon.info: Apr 27 05:12:56 vedge01 charon: 16[ENC] parsed CREATE_CHILD_SA request 557 [ SA No TSi TSr ] 
daemon.info: Apr 27 05:12:56 vedge01 charon: 16[CFG] received proposals: ESP:AES_GCM_16_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/NO_EXT_SEQ, ESP:3DES_CBC/HMAC_SHA1_96/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_256_128/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/NO_EXT_SEQ, ESP:3DES_CBC/HMAC_SHA2_256_128/NO_EXT_SEQ 
daemon.info: Apr 27 05:12:56 vedge01 charon: 16[CFG] configured proposals: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_4096/NO_EXT_SEQ 
daemon.info: Apr 27 05:12:56 vedge01 charon: 16[IKE] no acceptable proposal found 
daemon.info: Apr 27 05:12:56 vedge01 charon: 16[IKE] failed to establish CHILD_SA, keeping IKE_SA 
daemon.info: Apr 27 05:12:56 vedge01 charon: 16[ENC] generating CREATE_CHILD_SA response 557 [ N(NO_PROP) ] 
daemon.info: Apr 27 05:12:56 vedge01 charon: 16[NET] sending packet: from 172.28.0.36[4500] to 10.10.10.1[4500] (76 bytes) 

daemon.info: Apr 27 05:12:57 vedge01 charon: 08[NET] received packet: from 10.10.10.1[4500] to 172.28.0.36[4500] (76 bytes) 
daemon.info: Apr 27 05:12:57 vedge01 charon: 08[ENC] parsed INFORMATIONAL request 558 [ ] 
daemon.info: Apr 27 05:12:57 vedge01 charon: 08[ENC] generating INFORMATIONAL response 558 [ ] 
daemon.info: Apr 27 05:12:57 vedge01 charon: 08[NET] sending packet: from 172.28.0.36[4500] to 10.10.10.1[4500] (76 bytes) 
daemon.info: Apr 27 05:12:58 vedge01 charon: 07[NET] received packet: from 10.10.10.1[4500] to 172.28.0.36[4500] (396 bytes) 
daemon.info: Apr 27 05:12:58 vedge01 charon: 07[ENC] parsed CREATE_CHILD_SA request 559 [ SA No TSi TSr ] 
daemon.info: Apr 27 05:12:58 vedge01 charon: 07[CFG] received proposals: ESP:AES_GCM_16_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/NO_EXT_SEQ, ESP:3DES_CBC/HMAC_SHA1_96/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_256_128/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/NO_EXT_SEQ, ESP:3DES_CBC/HMAC_SHA2_256_128/NO_EXT_SEQ 
daemon.info: Apr 27 05:12:58 vedge01 charon: 07[CFG] configured proposals: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_4096/NO_EXT_SEQ 
daemon.info: Apr 27 05:12:58 Avedge01 charon: 07[IKE] no acceptable proposal found 
daemon.info: Apr 27 05:12:58 vedge01 charon: 07[IKE] failed to establish CHILD_SA, keeping IKE_SA 

참고:  CREATE_CHILD_SA 패킷은 모든 키 재설정 또는 새 SA에 대해 교환됩니다. 추가 참조를 보려면 Understanding IKEv2 Packet Exchange(IKEv2 패킷 교환 이해)로 이동합니다

IKE 디버그는 동일한 동작을 보여주며 지속적으로 반복되므로 정보의 일부를 가져와 분석할 수 있습니다. 

CREATE_CHILD_SA는 IPsec 엔드포인트 간에 새 SPI를 생성하고 교환하기 위한 목적으로 재키를 의미합니다.

• 베지는 10.10.10.1에서 CREATE_CHILD_SA 요청 패킷을 수신합니다.
• 베지는 요청을 처리하고 피어 10.10.10.1에서 보낸 제안(SA)을 확인합니다
• 베지는 피어가 전송한 수신된 제안을 구성된 제안과 비교합니다.
• 교환된 CREATE_CHILD_SA가 " 허용 가능한 제안을 찾을 수 없음"과 함께 실패합니다.

이 시점에서 문제는 다음과 같습니다. 터널이 이전에 작동하고 변경 사항이 없는 경우 컨피그레이션이 일치하지 않는 이유는 무엇입니까?

세부적으로 분석하면 피어가 보내지 않는 구성된 제안서에 추가 필드가 있습니다.

구성된 제안: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_4096/NO_EXT_SEQ

접수된 제안:
ESP:AES_GCM_16_256/NO_EXT_SEQ,
ESP: AES_CBC_256/HMAC_SHA1_96/NO_EXT_SEQ,
ESP:3DES_CBC/HMAC_SHA1_96/NO_EXT_SEQ,
ESP: AES_CBC_256/HMAC_SHA2_256_128/NO_EXT_SEQ,
ESP:AES_CBC_128/HMAC_SHA1_96/NO_EXT_SEQ,
ESP:3DES_CBC/HMAC_SHA2_256_128/NO_EXT_SEQ

MODP_4096은 DH 그룹 16이며, Vedges는 Phase 2(IPsec 섹션)에서 PFS(Perfect-Forward-Secrecy)에 대해 구성했습니다.

PFS는 IKE 협상의 initiator 또는 responder가 누구인지에 따라 터널을 성공적으로 설정하거나 설정할 수 있는 유일한 불일치 컨피그레이션입니다. 그러나 rekey가 시작되면 터널을 계속할 수 없으며 이 증상이 나타나거나 관련될 수 있습니다.

vEdge IPSec/Ikev2 터널이 DELETE 이벤트로 인해 제거된 후 다시 시작되지 않음

이 동작에 대한 자세한 내용은 Cisco 버그 ID CSCvx86427을 참조하십시오.

문제가 지속되면 IKE 디버깅이 최상의 옵션입니다. 그러나 이 특정 버그에 대해 디버그가 활성화된 경우 터미널이나 메시지 파일 모두에 정보가 표시되지 않습니다.

이 문제의 범위를 좁히고 vEdge가 Cisco 버그 ID CSCvx86427에 도달했는지 확인하려면 터널이 다운되는 순간을 찾아야 합니다.

트러블슈팅을 시작하기 전에 다음 사항을 확인하십시오.

1. 문제 및 컨피그레이션이 있는 IPsec 터널(번호)입니다.
2. 터널이 다운된 타임스탬프입니다.
3. IPsec 피어 IP 주소(터널 대상)

타임스탬프가 식별되고 시간 및 로그가 상관되면 터널이 중단되기 직전에 로그를 검토합니다.

Apr 13 22:05:21 vedge01 charon: 12[IKE] received DELETE for IKE_SA ipsec1_1[217] 
Apr 13 22:05:21 vedge01 charon: 12[IKE] deleting IKE_SA ipsec1_1[217] between 10.16.0.5[10.16.0.5]...10.10.10.1[10.10.10.1] 
Apr 13 22:05:21 vedge01 charon: 12[IKE] deleting IKE_SA ipsec1_1[217] between 10.16.0.5[10.16.0.5]...10.10.10.1[10.10.10.1] 
Apr 13 22:05:21 vedge01 charon: 12[IKE] IKE_SA deleted 
Apr 13 22:05:21 vedge01 charon: 12[IKE] IKE_SA deleted 
Apr 13 22:05:21 vedge01 charon: 12[ENC] generating INFORMATIONAL response 4586 [ ] 
Apr 13 22:05:21 vedge01 charon: 12[NET] sending packet: from 10.16.0.5[4500] to 10.10.10.1[4500] (80 bytes) 
Apr 13 22:05:21 vedge01 charon: 12[KNL] Deleting SAD entry with SPI 00000e77 
Apr 13 22:05:21 vedge01 FTMD[1269]: %Viptela-AZGDSR01-FTMD-6-INFO-1000001: VPN 1 Interface ipsec1 DOWN
Apr 13 22:05:21 vedge01 FTMD[1269]: %Viptela-AZGDSR01-ftmd-6-INFO-1400002: Notification: interface-state-change severity-level:major host-name:"vedge01" system-ip:4.1.0.1 vpn-id:1 if-name:"ipsec1" new-state:down 

참고:  IPsec 협상에는 여러 개의 DELETE 패킷이 있으며, CHILD_SA에 대한 DELETE는 REKEY 프로세스에 필요한 DELETE입니다. 이 문제는 특정 IPsec 협상 없이 순수 IKE_SA DELETE 패킷을 수신할 때 나타납니다. 이 DELETE는 모든 IPsec/IKE 터널을 제거합니다.

관련 정보

• KEv2 패킷 교환 및 프로토콜 레벨 디버깅
• IKE(Internet Key Exchange) - RFC 2409
• IKEv2 - RFC 7296
• vEdge와 Cisco IOS 간의 사이트 대 사이트 LAN 대 LAN IPSec
• 기술 지원 및 문서 − Cisco Systems