Debug a un túnel IPsec (en Fortigate)

      Comentarios desactivados en Debug a un túnel IPsec (en Fortigate)

Continuando con el anterior post, ( y como ya dije, gracias I.G.B 🙂 ),  si un túnel no levanta siempre podemos hacer un debug para, sabiendo lo que hemos de tener en cuenta, ver en qué parte del proceso está fallando, para darle la solución mejor y más eficiente posible.

Como existen muchos fabricantes o soluciones, en este caso el debug lo muestro de un Fortigate. Los mensajes son de su consola pero los parámetros nos los podemos encontrar también en Cisco, PaloAlto, CheckPoint, SonicWall… o cualquier otro sistema.

Así que habilitamos el debug:

  • #diagnose debug application ike 255 ⇐ con esto habilitamos el debug a IKE y con el máximo nivel de “verbosity”. Podíamos haber elegido otro nivel, pero con este lo vemos prácticamente todo.
  • #diagnose debug enable ⇐ Y con este especificamos que lo queremos ver en nuestro terminal

Así que comenzaremos a recibir mensajes de IKE, muchos, siempre que se produzcan eventos del proceso en sí mismo. Decir que los datos se han ocultado/modificado y todos los parámetros son irreales, ya que sólo buscan ser un ejemplo, tal como este:

id=ff00000000000000/0000000011000000:30719c02
ike 0: comes Y.Y.Y.Y:4500->X.X.X.X:4500,ifindex=5….
ike 0: IKEv1 exchange=Aggressive id=abc123d6a0d3ab8c165a/abc32196f53892bc34e len=448
ike 0: in ABCABCABCBABCBACBACBACBABC0040000000000000001C00400003800000001000000010000002C0101000100000024010100XYXYXYXYXYXYXYXYXYXYXYXYXYXYXYXYXF1E508C071183E55A12C38B2ACE67FC7A8260A497AE77217F283F65A0B15A704EE4C18BBF2C5B2EBFF4C537651C10578A388036D9F0B435142C9701EC7F24E98105B63EF092516D40921D0221F6852BDF89E41DAF48080884A9702C3E0888F9C0A712B789FF2D0DA5461F0A7305000014DA7FB88838955FBD8D32473EEBF5E63E0800000C010000003E5198A50D000018E5EFE141785177E1FBA90C0D73CFCDE11310EEBE140000144A131C81070358455C5728F20E95452F140000185BFB9F2E0630956115A56356D9EC0435A24E9CF90D00001888D2FD65BF0A0FDE360F5A968E5916C15622B9BA0D0000184048B7D56EBCE88525E7DE7F00D6C2D38000000000000014A9B9B1034F7E50A2513B47B100BB85A9
ike 0:VPN_ZXYZXYZXY:23353: initiator: aggressive mode get 1st response…
ike 0:VPN_ZXYZXYZXY:23353: VID RFC 3947 AAAAAAAAAAAAA5C5728F20E95452F
ike 0:VPN_ZXYZXYZXY:23353: VID FRAGMENTATION AAAAAAAAAAAAAA5E7DE7F00D6C2D380000000
ike 0:VPN_ZXYZXYZXY:23353: VID unknown (16): AAAAAAAAAAAAAAA3B47B100BB85A9
ike 0:VPN_ZXYZXYZXY:23353: negotiation result
ike 0:VPN_ZXYZXYZXY:23353: proposal id = 1:
ike 0:VPN_ZXYZXYZXY:23353:   protocol id = ISAKMP:
ike 0:VPN_ZXYZXYZXY:23353:      trans_id = KEY_IKE.
ike 0:VPN_ZXYZXYZXY:23353:      encapsulation = IKE/none
ike 0:VPN_ZXYZXYZXY:23353:         type=OAKLEY_ENCRYPT_ALG, val=AES_CBC.
ike 0:VPN_ZXYZXYZXY:23353:         type=OAKLEY_HASH_ALG, val=SHA.
ike 0:VPN_ZXYZXYZXY:23353:         type=AUTH_METHOD, val=PRESHARED_KEY.
ike 0:VPN_ZXYZXYZXY:23353:         type=OAKLEY_GROUP, val=1536.
ike 0:VPN_ZXYZXYZXY:23353: ISAKMP SA lifetime=8640
ike 0:VPN_ZXYZXYZXY:23353: selected NAT-T version: RFC 3947
ike 0:VPN_ZXYZXYZXY:23353: NAT detected: ME
ike 0:VPN_ZXYZXYZXY:23353: ISAKMP SA abc123d6a0d3ab8c165a/abc32196f53892bc34e key 32:AAAAAAAAAAAAAAAAAAAAAA3356A56DBB204F39
ike 0:VPN_ZXYZXYZXY:23353: PSK authentication succeeded
ike 0:VPN_ZXYZXYZXY:23353: authentication OK
ike 0:VPN_ZXYZXYZXY:23353: NAT-T float port 4500
ike 0:VPN_ZXYZXYZXY:23353: enc ABCABCABCBABCBACBACBACBABC53892BC34E08100401000000000000006414000018E5B5E204AD20DA780C50603ED1BA6E58B6C0EBFA1400001888D2FD65BF0A0FDE360F5A968E5916C15622B9BA00000018905A7DDB49D71571CF23795276B9755D45F7B856
ike 0:VPN_ZXYZXYZXY:23353: out ABCABCABCBABCBACBACBACBABC53892BC34E08100401000000000000006C937A51C4730389FB77A2C994FA079C172126AB67B953EE9AAEE5863CA3C2439716F569EB19C12AEE42A3B8816382849E45E18E33B4DC5F2C0E4016617EB0413A5BDDA3EDA9D7624131B24FD49C8B0045
ike 0:VPN_ZXYZXYZXY:23353: sent IKE msg (agg_i2send): X.X.X.X:4500->Y.Y.Y.Y:4500, len=108, id=abc123d6a0d3ab8c165a/abc32196f53892bc34e
ike 0:VPN_ZXYZXYZXY:23353: established IKE SA abc123d6a0d3ab8c165a/abc32196f53892bc34e
ike 0:VPN_ZXYZXYZXY:23353: HA send IKE SA abc123d6a0d3ab8c165a/abc32196f53892bc34e
ike 0:VPN_ZXYZXYZXY:23353: HA send IKE SA add abc123d6a0d3ab8c165a/abc32196f53892bc34e

[…]

ike 0:VPN_ZXYZXYZXY: NAT keep-alive 5 X.X.X.X->Y.Y.Y.Y:4500.
ike 0:VPN_ZXYZXYZXY:23352: out FF
ike 0:VPN_ZXYZXYZXY:23352: sent IKE msg (keepalive): X.X.X.X:4500->Y.Y.Y.Y:4500, len=1,

Se trata de una serie de mensajes (filtrados a propósito de todos los que salen) que nos indican una negociación correcta del túnel, con todas sus particularidades. Evidentemente hemos de aplicar la suficiente inteligencia para desmenuzar estos mensajes puesto que no todos los túneles son iguales ni tienen las mismas caracteristicas (pueden ser de diferente modo… no usar NAT-T… etc). Todos y cada uno de ellos nos dicen algo, pero me voy a centrar en los más relevantes haciendo un troubleshooting por capas:

Lo primero fijarnos en el modo de negociación del túnel, en el que se indica que el túnel se ha comenzado a negociar en modo “aggressive” y mediante NAT-T (RFC3947):

ike 0: IKEv1 exchange=Aggressive id=abc123d6a0d3ab8c165a/abc32196f53892bc34e len=448
ike 0:VPN_ZXYZXYZXY:23353: initiator: aggressive mode get 1st response…
ike 0:VPN_ZXYZXYZXY:23353: VID RFC 3947 AAAAAAAAAAAAA5C5728F20E95452F

Después, vemos resultados de la negociación ISAKMP, viendo el tipo de cifrado (AES), hash de autenticación (SHA), modo de autenticación (PSK), y grupo DH, viendo como se establece la Security Association y con el hash de la clave cifrado mediante DH. El resto de datos los podéis ir intuyendo:

ike 0:VPN_ZXYZXYZXY:23353: negotiation result
ike 0:VPN_ZXYZXYZXY:23353: proposal id = 1:
ike 0:VPN_ZXYZXYZXY:23353:   protocol id = ISAKMP:
ike 0:VPN_ZXYZXYZXY:23353:      trans_id = KEY_IKE.
ike 0:VPN_ZXYZXYZXY:23353:      encapsulation = IKE/none
ike 0:VPN_ZXYZXYZXY:23353:         type=OAKLEY_ENCRYPT_ALG, val=AES_CBC.
ike 0:VPN_ZXYZXYZXY:23353:         type=OAKLEY_HASH_ALG, val=SHA.
ike 0:VPN_ZXYZXYZXY:23353:         type=AUTH_METHOD, val=PRESHARED_KEY.
ike 0:VPN_ZXYZXYZXY:23353:         type=OAKLEY_GROUP, val=1536.
ike 0:VPN_ZXYZXYZXY:23353: ISAKMP SA lifetime=8640
ike 0:VPN_ZXYZXYZXY:23353: selected NAT-T version: RFC 3947
ike 0:VPN_ZXYZXYZXY:23353: NAT detected: ME
ike 0:VPN_ZXYZXYZXY:23353: ISAKMP SA abc123d6a0d3ab8c165a/abc32196f53892bc34e key 32:AAAAAAAAAAAAAAAAAAAAAA3356A56DBB204F39
ike 0:VPN_ZXYZXYZXY:23353: PSK authentication succeeded
ike 0:VPN_ZXYZXYZXY:23353: authentication OK

Ya tendríamos la fase 1. Luego aparte de los churros que solo sirven para seguir unas trazas, veremos como se establecen las SA para la fase 2, aunque los mensajes en este caso son escasos.

ike 0:VPN_ZXYZXYZXY:23353: sent IKE msg (agg_i2send): X.X.X.X:4500->Y.Y.Y.Y:4500, len=108, id=abc123d6a0d3ab8c165a/abc32196f53892bc34e
ike 0:VPN_ZXYZXYZXY:23353: established IKE SA abc123d6a0d3ab8c165a/abc32196f53892bc34e
ike 0:VPN_ZXYZXYZXY:23353: HA send IKE SA abc123d6a0d3ab8c165a/abc32196f53892bc34e
ike 0:VPN_ZXYZXYZXY:23353: HA send IKE SA add abc123d6a0d3ab8c165a/abc32196f53892bc34e

Por último, algunos mensajes que podemos esperar cuando existe NAT-T, pues si hemos activado Keep-Alive, cada X segundos se mandará un paquete para mantener la sesión NAT activa en el dispositivo intermedio.

ike 0:VPN_ZXYZXYZXY: NAT keep-alive 5 X.X.X.X->Y.Y.Y.Y:4500.
ike 0:VPN_ZXYZXYZXY:23352: out FF
ike 0:VPN_ZXYZXYZXY:23352: sent IKE msg (keepalive): X.X.X.X:4500->Y.Y.Y.Y:4500, len=1,

Evidentemente, si nos encontramos con fallos en estas fases, nos encontraremos con mensajes que indican que el proceso ha fallado y en qué punto, para así hacer un troubleshooting de cada momento puntual.