Cisco
L2TPv2/IPsecのデバッグログ
構成図
L2TPv2/IPsecのコンフィグで、IPsecが接続される際のデバッグログを記録します。
RT-2のデバッグログ
RT-2#debug crypto isakmp
Crypto ISAKMP debugging is on
RT-2#
RT-2#debug crypto ipsec
Crypto IPSEC debugging is on
RT-2#
000048: *Mar 12 11:01:36.403: ISAKMP (0): received packet from 11.11.11.11 dport 500 sport 500 Global (N) NEW SA
000049: *Mar 12 11:01:36.403: ISAKMP: Created a peer struct for 11.11.11.11, peer port 500
000050: *Mar 12 11:01:36.403: ISAKMP: New peer created peer = 0x22FA638 peer_handle = 0x80000002
000051: *Mar 12 11:01:36.403: ISAKMP: Locking peer struct 0x22FA638, refcount 1 for crypto_isakmp_process_block
000052: *Mar 12 11:01:36.403: ISAKMP: local port 500, remote port 500
000053: *Mar 12 11:01:36.403: ISAKMP:(0):insert sa successfully sa = 22F9A54
000054: *Mar 12 11:01:36.403: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
000055: *Mar 12 11:01:36.403: ISAKMP:(0):Old State = IKE_READY New State = IKE_R_MM1
000056: *Mar 12 11:01:36.403: ISAKMP:(0): processing SA payload. message ID = 0
000057: *Mar 12 11:01:36.403: ISAKMP:(0): processing vendor id payload
000058: *Mar 12 11:01:36.403: ISAKMP:(0): processing IKE frag vendor id payload
000059: *Mar 12 11:01:36.403: ISAKMP:(0):Support for IKE Fragmentation not enabled
000060: *Mar 12 11:01:36.403: ISAKMP:(0): processing vendor id payload
000061: *Mar 12 11:01:36.403: ISAKMP:(0): processing IKE frag vendor id payload
000062: *Mar 12 11:01:36.403: ISAKMP:(0):Support for IKE Fragmentation not enabled
000063: *Mar 12 11:01:36.403: ISAKMP:(0): processing vendor id payload
000064: *Mar 12 11:01:36.403: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
000065: *Mar 12 11:01:36.403: ISAKMP (0): vendor ID is NAT-T RFC 3947
000066: *Mar 12 11:01:36.403: ISAKMP:(0): processing vendor id payload
000067: *Mar 12 11:01:36.403: ISAKMP:(0): vendor ID seems Unity/DPD but major 123 mismatch
000068: *Mar 12 11:01:36.403: ISAKMP:(0): vendor ID is NAT-T v2
000069: *Mar 12 11:01:36.407: ISAKMP:(0): processing vendor id payload
000070: *Mar 12 11:01:36.407: ISAKMP:(0): vendor ID seems Unity/DPD but major 194 mismatch
000071: *Mar 12 11:01:36.407: ISAKMP:(0): processing vendor id payload
000072: *Mar 12 11:01:36.407: ISAKMP:(0): vendor ID seems Unity/DPD but major 241 mismatch
000073: *Mar 12 11:01:36.407: ISAKMP:(0): processing vendor id payload
000074: *Mar 12 11:01:36.407: ISAKMP:(0): vendor ID seems Unity/DPD but major 184 mismatch
000075: *Mar 12 11:01:36.407: ISAKMP:(0): processing vendor id payload
000076: *Mar 12 11:01:36.407: ISAKMP:(0): vendor ID seems Unity/DPD but major 134 mismatch
000077: *Mar 12 11:01:36.407: ISAKMP:(0):found peer pre-shared key matching 11.11.11.11
000078: *Mar 12 11:01:36.407: ISAKMP:(0): local preshared key found
000079: *Mar 12 11:01:36.407: ISAKMP : Scanning profiles for xauth ...
000080: *Mar 12 11:01:36.407: ISAKMP:(0):Checking ISAKMP transform 1 against priority 110 policy
000081: *Mar 12 11:01:36.407: ISAKMP: encryption AES-CBC
000082: *Mar 12 11:01:36.407: ISAKMP: keylength of 256
000083: *Mar 12 11:01:36.407: ISAKMP: hash SHA
000084: *Mar 12 11:01:36.407: ISAKMP: default group 20
000085: *Mar 12 11:01:36.407: ISAKMP: auth pre-share
000086: *Mar 12 11:01:36.407: ISAKMP: life type in seconds
000087: *Mar 12 11:01:36.407: ISAKMP: life duration (VPI) of 0x0 0x0 0x70 0x80
000088: *Mar 12 11:01:36.407: ISAKMP:(0):Proposed key length does not match policy
000089: *Mar 12 11:01:36.407: ISAKMP:(0):atts are not acceptable. Next payload is 3
000090: *Mar 12 11:01:36.407: ISAKMP:(0):Checking ISAKMP transform 2 against priority 110 policy
000091: *Mar 12 11:01:36.407: ISAKMP: encryption AES-CBC
000092: *Mar 12 11:01:36.407: ISAKMP: keylength of 128
000093: *Mar 12 11:01:36.407: ISAKMP: hash SHA
000094: *Mar 12 11:01:36.407: ISAKMP: default group 19
000095: *Mar 12 11:01:36.407: ISAKMP: auth pre-share
000096: *Mar 12 11:01:36.407: ISAKMP: life type in seconds
000097: *Mar 12 11:01:36.407: ISAKMP: life duration (VPI) of 0x0 0x0 0x70 0x80
000098: *Mar 12 11:01:36.407: ISAKMP:(0):atts are acceptable. Next payload is 3
000099: *Mar 12 11:01:36.407: ISAKMP:(0):Acceptable atts:actual life: 1800
000100: *Mar 12 11:01:36.407: ISAKMP:(0):Acceptable atts:life: 0
000101: *Mar 12 11:01:36.407: ISAKMP:(0):Fill atts in sa vpi_length:4
000102: *Mar 12 11:01:36.407: ISAKMP:(0):Fill atts in sa life_in_seconds:28800
000103: *Mar 12 11:01:36.407: ISAKMP:(0):Returning Actual lifetime: 1800
000104: *Mar 12 11:01:36.407: ISAKMP:(0)::Started lifetime timer: 1800.
000105: *Mar 12 11:01:36.407: ISAKMP:(0): processing vendor id payload
000106: *Mar 12 11:01:36.407: ISAKMP:(0): processing IKE frag vendor id payload
000107: *Mar 12 11:01:36.407: ISAKMP:(0):Support for IKE Fragmentation not enabled
000108: *Mar 12 11:01:36.407: ISAKMP:(0): processing vendor id payload
000109: *Mar 12 11:01:36.407: ISAKMP:(0): processing IKE frag vendor id payload
000110: *Mar 12 11:01:36.407: ISAKMP:(0):Support for IKE Fragmentation not enabled
000111: *Mar 12 11:01:36.407: ISAKMP:(0): processing vendor id payload
000112: *Mar 12 11:01:36.407: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
000113: *Mar 12 11:01:36.407: ISAKMP (0): vendor ID is NAT-T RFC 3947
000114: *Mar 12 11:01:36.407: ISAKMP:(0): processing vendor id payload
000115: *Mar 12 11:01:36.407: ISAKMP:(0): vendor ID seems Unity/DPD but major 123 mismatch
000116: *Mar 12 11:01:36.407: ISAKMP:(0): vendor ID is NAT-T v2
000117: *Mar 12 11:01:36.407: ISAKMP:(0): processing vendor id payload
000118: *Mar 12 11:01:36.407: ISAKMP:(0): vendor ID seems Unity/DPD but major 194 mismatch
000119: *Mar 12 11:01:36.407: ISAKMP:(0): processing vendor id payload
000120: *Mar 12 11:01:36.407: ISAKMP:(0): vendor ID seems Unity/DPD but major 241 mismatch
000121: *Mar 12 11:01:36.407: ISAKMP:(0): processing vendor id payload
000122: *Mar 12 11:01:36.407: ISAKMP:(0): vendor ID seems Unity/DPD but major 184 mismatch
000123: *Mar 12 11:01:36.407: ISAKMP:(0): processing vendor id payload
000124: *Mar 12 11:01:36.407: ISAKMP:(0): vendor ID seems Unity/DPD but major 134 mismatch
000125: *Mar 12 11:01:36.407: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
000126: *Mar 12 11:01:36.407: ISAKMP:(0):Old State = IKE_R_MM1 New State = IKE_R_MM1
000127: *Mar 12 11:01:36.407: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID
000128: *Mar 12 11:01:36.407: ISAKMP:(0): sending packet to 11.11.11.11 my_port 500 peer_port 500 (R) MM_SA_SETUP
000129: *Mar 12 11:01:36.407: ISAKMP:(0):Sending an IKE IPv4 Packet.
000130: *Mar 12 11:01:36.407: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
000131: *Mar 12 11:01:36.407: ISAKMP:(0):Old State = IKE_R_MM1 New State = IKE_R_MM2
000132: *Mar 12 11:01:36.411: ISAKMP (0): received packet from 11.11.11.11 dport 500 sport 500 Global (R) MM_SA_SETUP
000133: *Mar 12 11:01:36.411: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
000134: *Mar 12 11:01:36.411: ISAKMP:(0):Old State = IKE_R_MM2 New State = IKE_R_MM3
000135: *Mar 12 11:01:36.411: ISAKMP:(0): processing KE payload. message ID = 0
000136: *Mar 12 11:01:36.423: ISAKMP:(0): processing NONCE payload. message ID = 0
000137: *Mar 12 11:01:36.423: ISAKMP:(0):found peer pre-shared key matching 11.11.11.11
000138: *Mar 12 11:01:36.423: ISAKMP:received payload type 20
000139: *Mar 12 11:01:36.423: ISAKMP (2001): His hash no match - this node outside NAT
000140: *Mar 12 11:01:36.423: ISAKMP:received payload type 20
000141: *Mar 12 11:01:36.423: ISAKMP (2001): His hash no match - this node outside NAT
000142: *Mar 12 11:01:36.423: ISAKMP:(2001):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
000143: *Mar 12 11:01:36.423: ISAKMP:(2001):Old State = IKE_R_MM3 New State = IKE_R_MM3
000144: *Mar 12 11:01:36.427: ISAKMP:(2001): sending packet to 11.11.11.11 my_port 500 peer_port 500 (R) MM_KEY_EXCH
000145: *Mar 12 11:01:36.427: ISAKMP:(2001):Sending an IKE IPv4 Packet.
000146: *Mar 12 11:01:36.427: ISAKMP:(2001):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
000147: *Mar 12 11:01:36.427: ISAKMP:(2001):Old State = IKE_R_MM3 New State = IKE_R_MM4
000148: *Mar 12 11:01:36.431: ISAKMP (2001): received packet from 11.11.11.11 dport 4500 sport 4500 Global (R) MM_KEY_EXCH
000149: *Mar 12 11:01:36.431: ISAKMP:(2001):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
000150: *Mar 12 11:01:36.431: ISAKMP:(2001):Old State = IKE_R_MM4 New State = IKE_R_MM5
000151: *Mar 12 11:01:36.431: ISAKMP:(2001): processing ID payload. message ID = 0
000152: *Mar 12 11:01:36.431: ISAKMP (2001): ID payload
next-payload : 8
type : 1
address : 10.1.1.1
protocol : 0
port : 0
length : 12
000153: *Mar 12 11:01:36.431: ISAKMP:(0):: peer matches *none* of the profiles
000154: *Mar 12 11:01:36.431: ISAKMP:(2001): processing HASH payload. message ID = 0
000155: *Mar 12 11:01:36.431: ISAKMP:(2001):SA authentication status:
authenticated
000156: *Mar 12 11:01:36.431: ISAKMP:(2001):SA has been authenticated with 11.11.11.11
000157: *Mar 12 11:01:36.431: ISAKMP:(2001):Detected port floating to port = 4500
000158: *Mar 12 11:01:36.431: ISAKMP: Trying to insert a peer 22.22.22.22/11.11.11.11/4500/, and inserted successfully 22FA638.
000159: *Mar 12 11:01:36.431: ISAKMP:(2001):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
000160: *Mar 12 11:01:36.431: ISAKMP:(2001):Old State = IKE_R_MM5 New State = IKE_R_MM5
000161: *Mar 12 11:01:36.431: ISAKMP:(2001):SA is doing pre-shared key authentication using id type ID_IPV4_ADDR
000162: *Mar 12 11:01:36.431: ISAKMP (2001): ID payload
next-payload : 8
type : 1
address : 22.22.22.22
protocol : 17
port : 0
length : 12
000163: *Mar 12 11:01:36.431: ISAKMP:(2001):Total payload length: 12
000164: *Mar 12 11:01:36.431: ISAKMP:(2001): sending packet to 11.11.11.11 my_port 4500 peer_port 4500 (R) MM_KEY_EXCH
000165: *Mar 12 11:01:36.431: ISAKMP:(2001):Sending an IKE IPv4 Packet.
000166: *Mar 12 11:01:36.431: ISAKMP:(2001):Returning Actual lifetime: 1800
000167: *Mar 12 11:01:36.431: ISAKMP: set new node 1109244757 to QM_IDLE
000168: *Mar 12 11:01:36.431: ISAKMP:(2001):Sending NOTIFY RESPONDER_LIFETIME protocol 1
spi 274687284, message ID = 1109244757
000169: *Mar 12 11:01:36.431: ISAKMP:(2001): sending packet to 11.11.11.11 my_port 4500 peer_port 4500 (R) MM_KEY_EXCH
000170: *Mar 12 11:01:36.431: ISAKMP:(2001):Sending an IKE IPv4 Packet.
000171: *Mar 12 11:01:36.431: ISAKMP:(2001):purging node 1109244757
000172: *Mar 12 11:01:36.431: ISAKMP: Sending phase 1 responder lifetime 1800
000173: *Mar 12 11:01:36.431: ISAKMP:(2001):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
000174: *Mar 12 11:01:36.431: ISAKMP:(2001):Old State = IKE_R_MM5 New State = IKE_P1_COMPLETE
000175: *Mar 12 11:01:36.431: ISAKMP:(2001):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
000176: *Mar 12 11:01:36.431: ISAKMP:(2001):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE
000177: *Mar 12 11:01:36.435: ISAKMP (2001): received packet from 11.11.11.11 dport 4500 sport 4500 Global (R) QM_IDLE
000178: *Mar 12 11:01:36.435: ISAKMP: set new node 1 to QM_IDLE
000179: *Mar 12 11:01:36.435: ISAKMP:(2001): processing HASH payload. message ID = 1
000180: *Mar 12 11:01:36.435: ISAKMP:(2001): processing SA payload. message ID = 1
000181: *Mar 12 11:01:36.435: ISAKMP (2001): processing NAT-OAi payload. addr = 10.1.1.1, message ID = 1
000182: *Mar 12 11:01:36.435: ISAKMP (2001): processing NAT-OAr payload. addr = 22.22.22.22, message ID = 1
000183: *Mar 12 11:01:36.435: ISAKMP:(2001):Checking IPSec proposal 1
000184: *Mar 12 11:01:36.435: ISAKMP: transform 1, ESP_AES
000185: *Mar 12 11:01:36.439: ISAKMP: attributes in transform:
000186: *Mar 12 11:01:36.439: ISAKMP: encaps is 4 (Transport-UDP)
000187: *Mar 12 11:01:36.439: ISAKMP: key length is 256
000188: *Mar 12 11:01:36.439: ISAKMP: authenticator is HMAC-SHA
000189: *Mar 12 11:01:36.439: ISAKMP: SA life type in seconds
000190: *Mar 12 11:01:36.439: ISAKMP: SA life duration (VPI) of 0x0 0x0 0xE 0x10
000191: *Mar 12 11:01:36.439: ISAKMP: SA life type in kilobytes
000192: *Mar 12 11:01:36.439: ISAKMP: SA life duration (VPI) of 0x0 0x3 0xD0 0x90
000193: *Mar 12 11:01:36.439: ISAKMP:(2001):atts are acceptable.
000194: *Mar 12 11:01:36.439: IPSEC(validate_proposal_request): proposal part #1
000195: *Mar 12 11:01:36.439: IPSEC(validate_proposal_request): proposal part #1,
(key eng. msg.) INBOUND local= 22.22.22.22:0, remote= 11.11.11.11:0,
local_proxy= 22.22.22.22/255.255.255.255/17/1701,
remote_proxy= 11.11.11.11/255.255.255.255/17/1701,
protocol= ESP, transform= NONE (Transport-UDP),
lifedur= 0s and 0kb,
spi= 0x0(0), conn_id= 0, keysize= 256, flags= 0x0
000196: *Mar 12 11:01:36.439: Cannot find crypto swsb : in ipsec_process_proposal (), 1590
000197: *Mar 12 11:01:36.439: IPSEC(ipsec_process_proposal): transform proposal not supported for identity:
{esp-aes 256 esp-sha-hmac }
000198: *Mar 12 11:01:36.439: ISAKMP:(2001): IPSec policy invalidated proposal with error 256
000199: *Mar 12 11:01:36.439: ISAKMP:(2001):Checking IPSec proposal 2
000200: *Mar 12 11:01:36.439: ISAKMP: transform 1, ESP_AES
000201: *Mar 12 11:01:36.439: ISAKMP: attributes in transform:
000202: *Mar 12 11:01:36.439: ISAKMP: encaps is 4 (Transport-UDP)
000203: *Mar 12 11:01:36.439: ISAKMP: key length is 128
000204: *Mar 12 11:01:36.439: ISAKMP: authenticator is HMAC-SHA
000205: *Mar 12 11:01:36.439: ISAKMP: SA life type in seconds
000206: *Mar 12 11:01:36.439: ISAKMP: SA life duration (VPI) of 0x0 0x0 0xE 0x10
000207: *Mar 12 11:01:36.439: ISAKMP: SA life type in kilobytes
000208: *Mar 12 11:01:36.439: ISAKMP: SA life duration (VPI) of 0x0 0x3 0xD0 0x90
000209: *Mar 12 11:01:36.439: ISAKMP:(2001):atts are acceptable.
000210: *Mar 12 11:01:36.439: IPSEC(validate_proposal_request): proposal part #1
000211: *Mar 12 11:01:36.439: IPSEC(validate_proposal_request): proposal part #1,
(key eng. msg.) INBOUND local= 22.22.22.22:0, remote= 11.11.11.11:0,
local_proxy= 22.22.22.22/255.255.255.255/17/1701,
remote_proxy= 11.11.11.11/255.255.255.255/17/1701,
protocol= ESP, transform= NONE (Transport-UDP),
lifedur= 0s and 0kb,
spi= 0x0(0), conn_id= 0, keysize= 128, flags= 0x0
000212: *Mar 12 11:01:36.439: (ipsec_process_proposal)Map Accepted: DMAP-name, 10
000213: *Mar 12 11:01:36.439: ISAKMP:(2001): processing NONCE payload. message ID = 1
000214: *Mar 12 11:01:36.439: ISAKMP:(2001): processing ID payload. message ID = 1
000215: *Mar 12 11:01:36.439: ISAKMP:(2001): processing ID payload. message ID = 1
000216: *Mar 12 11:01:36.439: ISAKMP:received payload type 21
000217: *Mar 12 11:01:36.439: ISAKMP:received payload type 21
000218: *Mar 12 11:01:36.439: ISAKMP:(2001):QM Responder gets spi
000219: *Mar 12 11:01:36.439: ISAKMP:(2001):Node 1, Input = IKE_MESG_FROM_PEER, IKE_QM_EXCH
000220: *Mar 12 11:01:36.439: ISAKMP:(2001):Old State = IKE_QM_READY New State = IKE_QM_SPI_STARVE
000221: *Mar 12 11:01:36.439: ISAKMP:(2001):Node 1, Input = IKE_MESG_INTERNAL, IKE_GOT_SPI
000222: *Mar 12 11:01:36.439: ISAKMP:(2001):Old State = IKE_QM_SPI_STARVE New State = IKE_QM_IPSEC_INSTALL_AWAIT
000223: *Mar 12 11:01:36.439: IPSEC(key_engine): got a queue event with 1 KMI message(s)
000224: *Mar 12 11:01:36.439: IPSEC(crypto_ipsec_create_ipsec_sas): Map found DMAP-name, 10
000225: *Mar 12 11:01:36.439: IPSEC(create_sa): sa created,
(sa) sa_dest= 22.22.22.22, sa_proto= 50,
sa_spi= 0x2F5BBFC8(794542024),
sa_trans= esp-aes esp-sha-hmac , sa_conn_id= 1
sa_lifetime(k/sec)= (250000/3600),
(identity) local= 22.22.22.22:0, remote= 11.11.11.11:0,
local_proxy= 22.22.22.22/255.255.255.255/17/1701,
remote_proxy= 11.11.11.11/255.255.255.255/17/4500
000226: *Mar 12 11:01:36.439: IPSEC(create_sa): sa created,
(sa) sa_dest= 11.11.11.11, sa_proto= 50,
sa_spi= 0x745599E2(1951767010),
sa_trans= esp-aes esp-sha-hmac , sa_conn_id= 2
sa_lifetime(k/sec)= (250000/3600),
(identity) local= 22.22.22.22:0, remote= 11.11.11.11:0,
local_proxy= 22.22.22.22/255.255.255.255/17/1701,
remote_proxy= 11.11.11.11/255.255.255.255/17/4500
000227: *Mar 12 11:01:36.439: ISAKMP: Failed to find peer index node to update peer_info_list
000228: *Mar 12 11:01:36.439: ISAKMP:(2001):Received IPSec Install callback... proceeding with the negotiation
000229: *Mar 12 11:01:36.439: ISAKMP:(2001):Successfully installed IPSEC SA (SPI:0x2F5BBFC8) on Dialer1
000230: *Mar 12 11:01:36.439: ISAKMP:(2001): sending packet to 11.11.11.11 my_port 4500 peer_port 4500 (R) QM_IDLE
000231: *Mar 12 11:01:36.439: ISAKMP:(2001):Sending an IKE IPv4 Packet.
000232: *Mar 12 11:01:36.439: ISAKMP:(2001):Node 1, Input = IKE_MESG_FROM_IPSEC, IPSEC_INSTALL_DONE
000233: *Mar 12 11:01:36.439: ISAKMP:(2001):Old State = IKE_QM_IPSEC_INSTALL_AWAIT New State = IKE_QM_R_QM2
000234: *Mar 12 11:01:36.447: ISAKMP (2001): received packet from 11.11.11.11 dport 4500 sport 4500 Global (R) QM_IDLE
000235: *Mar 12 11:01:36.447: ISAKMP:(2001):deleting node 1 error FALSE reason "QM done (await)"
000236: *Mar 12 11:01:36.447: ISAKMP:(2001):Node 1, Input = IKE_MESG_FROM_PEER, IKE_QM_EXCH
000237: *Mar 12 11:01:36.447: ISAKMP:(2001):Old State = IKE_QM_R_QM2 New State = IKE_QM_PHASE2_COMPLETE
000238: *Mar 12 11:01:36.447: IPSEC(key_engine): got a queue event with 1 KMI message(s)
000239: *Mar 12 11:01:36.447: IPSEC(key_engine_enable_outbound): rec'd enable notify from ISAKMP
000240: *Mar 12 11:01:36.447: IPSEC: Expand action denied, notify RP
000241: *Mar 12 11:01:37.551: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access4, changed state to up
000242: *Mar 12 11:01:37.551: %LINK-3-UPDOWN: Interface Virtual-Access4, changed state to up
RT-2#
000243: *Mar 12 11:02:26.447: ISAKMP:(2001):purging node 1
RT-2#
RT-2#no debug all
All possible debugging has been turned off
RT-2#