LISP debug traffic between two EIDs
This is the topology:
You can see the following debug with these debug commands:
debug lisp control-plane alldebug lisp detail
We send a ping from H1 to H1. This is the debug output on XTR1:
XTR1# *Oct 4 15:00:36.878: LISP-0: AF IID 0 IPv4, 192.168.2.102 does not match configured dyn-EID groups. *Oct 4 15:00:36.879: LISP: FWD message queue event. *Oct 4 15:00:36.880: LISP: Processing data signal for EID prefix IID 0 192.168.2.102/32 *Oct 4 15:00:36.880: LISP-0: Remote EID IID 0 prefix 192.168.2.102/32, Created (sources: <>, state: unknown, rlocs: 0). *Oct 4 15:00:36.880: LISP-0: Remote EID IID 0 prefix 192.168.2.102/32, Added source transient (sources: , state: unknown, rlocs: 0). *Oct 4 15:00:36.880: LISP-0: Remote EID IID 0 prefix 192.168.2.102/32, Schedule forwarding table update (sources: , state: unknown, rlocs: 0). *Oct 4 15:00:36.881: LISP-0: Remote EID IID 0 prefix 192.168.2.102/32, Source transient has no async callback (sources: , state: unknown, rlocs: 0). *Oct 4 15:00:36.881: LISP-0: Remote EID IID 0 prefix 192.168.2.102/32, forwarding data signal for 192.168.2.102 (local EID 192.168.1.101) (sources: , state: unknown, rlocs: 0). *Oct 4 15:00:36.881: LISP-0: Remote EID IID 0 prefix 192.168.2.102/32, Change state to incomplete (sources: , state: unknown, rlocs: 0). *Oct 4 15:00:36.881: LISP-0: Remote EID IID 0 prefix 192.168.2.102/32, Schedule forwarding table update, on queue (sources: , state: incomplete, rlocs: 0). *Oct 4 15:00:36.882: LISP-0: Remote EID IID 0 prefix 192.168.2.102/32, [incomplete] Scheduling map requests delay 00:00:00 min_elapsed 00:00:01 (sources: , state: incomplete, rlocs: 0). *Oct 4 15:00:36.882: LISP-0: Map Request IID 0 prefix 192.168.2.102/32 remote EID prefix[LL], Starting request timer with delay of 00:00:00. *Oct 4 15:00:36.882: LISP-0: Remote EID IID 0 prefix 192.168.2.102/32, Placing on idle queue (sources: , state: incomplete, rlocs: 0). *Oct 4 15:00:36.882: LISP-0: Remote EID IID 0 prefix 192.168.2.102/32, Schedule expiration timer at 00:01:00 (sources: , state: incomplete, rlocs: 0). *Oct 4 15:00:36.882: LISP: Processed 1 global IPC messages. *Oct 4 15:00:36.883: LISP-0: AF IID 0 IPv4, Checkpointed 1 remote EID entries. *Oct 4 15:00:36.883: LISP-0: Remote EID IID 0 prefix 192.168.2.102/32, Update forwarding state (sources: , state: incomplete, rlocs: 0). *Oct 4 15:00:36.885: LISP-0: AF IID 0 IPv4, Updated 1 remote EID entries in forwarding table. *Oct 4 15:00:37.014: LISP: Timer event (map request). *Oct 4 15:00:37.014: LISP-0: AF IID 0 IPv4, Local map request source address not cached, using dest. *Oct 4 15:00:37.014: LISP-0: Map Request IID 0 prefix 192.168.2.102/32 remote EID prefix[LL], Queueing remote EID prefix map request on IPv4 queue (1/4). *Oct 4 15:00:37.015: LISP-0: IID 0 Request processing of remote EID prefix map requests to IPv4. *Oct 4 15:00:37.015: LISP: Send map request type remote EID prefix *Oct 4 15:00:37.015: LISP: Send map request for EID prefix IID 0 192.168.2.102/32 *Oct 4 15:00:37.016: LISP-0: Remote EID IID 0 prefix 192.168.2.102/32, Send map request (1) (sources: , state: incomplete, rlocs: 0). *Oct 4 15:00:37.016: LISP-0: AF IID 0 IPv4, Local map request source address not cached, using dest. *Oct 4 15:00:37.016: LISP: TOPO default IPv4, Route locator 192.168.123.3 resolved via /24 pfx, src 192.168.123.1 nh 192.168.123.3 if GigabitEthernet0/1 (state: UP). *Oct 4 15:00:37.016: LISP-0: Added mapping record locator 192.168.123.1 (priority 10, weight 10, local, reachable). *Oct 4 15:00:37.017: LISP-0: Built mapping. Prefix = 192.168.1.0/24, #locators = 1, TTL = 1440, action = none. *Oct 4 15:00:37.017: LISP-0: EID-AF IPv4, Sending map-request from 192.168.2.102 to 192.168.2.102 for EID 192.168.2.102/32, ITR-RLOCs 1, nonce 0x9FE013E1-0x15CA7DBD (encap src 192.168.123.1, dst 192.168.123.3). *Oct 4 15:00:37.017: LISP: IPv4, Sending control packet out of GigabitEthernet0/1 with next hop 192.168.123.3. *Oct 4 15:00:37.017: LISP: Set initial min output if hold queue size to 40 (intf GigabitEthernet0/1). *Oct 4 15:00:37.020: LISP-0: Map Request IID 0 prefix 192.168.2.102/32 remote EID prefix[LL], Starting request timer with delay of 00:00:01. *Oct 4 15:00:37.020: LISP-0: Processed 1 map requests. *Oct 4 15:00:38.106: LISP: Timer event (map request). *Oct 4 15:00:38.106: LISP-0: AF IID 0 IPv4, Local map request source address not cached, using dest. *Oct 4 15:00:38.106: LISP-0: Map Request IID 0 prefix 192.168.2.102/32 remote EID prefix[LL], Queueing remote EID prefix map request on IPv4 queue (2/4). *Oct 4 15:00:38.107: LISP-0: IID 0 Request processing of remote EID prefix map requests to IPv4. *Oct 4 15:00:38.107: LISP: Send map request type remote EID prefix *Oct 4 15:00:38.107: LISP: Send map request for EID prefix IID 0 192.168.2.102/32 *Oct 4 15:00:38.107: LISP-0: Remote EID IID 0 prefix 192.168.2.102/32, Send map request (2) (sources: , state: incomplete, rlocs: 0). *Oct 4 15:00:38.107: LISP-0: AF IID 0 IPv4, Local map request source address not cached, using dest. *Oct 4 15:00:38.108: LISP: TOPO default IPv4, Route locator 192.168.123.3 resolved via /24 pfx, src 192.168.123.1 nh 192.168.123.3 if GigabitEthernet0/1 (state: UP). *Oct 4 15:00:38.108: LISP-0: Added mapping record locator 192.168.123.1 (priority 10, weight 10, local, reachable). *Oct 4 15:00:38.108: LISP-0: Built mapping. Prefix = 192.168.1.0/24, #locators = 1, TTL = 1440, action = none. *Oct 4 15:00:38.108: LISP-0: EID-AF IPv4, Sending map-request from 192.168.2.102 to 192.168.2.102 for EID 192.168.2.102/32, ITR-RLOCs 1, nonce 0x9FE013E1-0x15CA7DBD (encap src 192.168.123.1, dst 192.168.123.3). *Oct 4 15:00:38.109: LISP: IPv4, Sending control packet out of GigabitEthernet0/1 with next hop 192.168.123.3. *Oct 4 15:00:38.109: LISP: Set initial min output if hold queue size to 40 (intf GigabitEthernet0/1). *Oct 4 15:00:38.110: LISP-0: Map Request IID 0 prefix 192.168.2.102/32 remote EID prefix[LL], Starting request timer with delay of 00:00:02. *Oct 4 15:00:38.110: LISP-0: Processed 1 map requests. *Oct 4 15:00:38.119: LISP: Net receive queuing packet for LISP process. *Oct 4 15:00:38.120: LISP-0: Received packet datagramsize 68, encsize 0, size 68. *Oct 4 15:00:38.120: LISP: Processing received Map-Reply(2) message on GigabitEthernet0/1 from 192.168.123.2:4342 to 192.168.123.1:4342 *Oct 4 15:00:38.120: LISP: Received map reply nonce 0x9FE013E1-0x15CA7DBD, records 1 *Oct 4 15:00:38.121: LISP: Parsing mapping record for EID prefix IID 0 192.168.2.0/24 *Oct 4 15:00:38.121: LISP-0: Mapping Record has 1 locators (action none). *Oct 4 15:00:38.121: LISP: Processing Map-Reply mapping record for IID 0 192.168.2.0/24, ttl 1440, action none, authoritative, 1 locator 192.168.123.2 pri/wei=10/10 LpR *Oct 4 15:00:38.121: LISP-0: Map Request IID 0 prefix 192.168.2.102/32 remote EID prefix[LL], Received reply with rtt 12ms. *Oct 4 15:00:38.122: LISP: Processing mapping information for EID prefix IID 0 192.168.2.0/24 *Oct 4 15:00:38.122: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Created (sources: <>, state: unknown, rlocs: 0). *Oct 4 15:00:38.122: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Added source transient (sources: , state: unknown, rlocs: 0). *Oct 4 15:00:38.122: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Schedule forwarding table update (sources: , state: unknown, rlocs: 0). *Oct 4 15:00:38.122: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Source transient has no async callback (sources: , state: unknown, rlocs: 0). *Oct 4 15:00:38.123: LISP-0: AF IID 0 IPv4, Persistent db: ignore writing request, disabled. *Oct 4 15:00:38.123: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Change state to complete (sources: , state: unknown, rlocs: 0). *Oct 4 15:00:38.123: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Schedule forwarding table update, on queue (sources: , state: complete, rlocs: 0). *Oct 4 15:00:38.123: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Starting idle timer (delay 00:02:30) (sources: , state: complete, rlocs: 0). *Oct 4 15:00:38.124: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Placing on active queue (sources: , state: complete, rlocs: 0). *Oct 4 15:00:38.124: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Deleting more specific incomplete entries (sources: , state: complete, rlocs: 0). *Oct 4 15:00:38.124: LISP-0: Remote EID IID 0 prefix 192.168.2.102/32, Removing source transient (sources: , state: incomplete, rlocs: 0). *Oct 4 15:00:38.124: LISP-0: Remote EID IID 0 prefix 192.168.2.102/32, Change state to deleted (sources: <>, state: incomplete, rlocs: 0). *Oct 4 15:00:38.124: LISP-0: Remote EID IID 0 prefix 192.168.2.102/32, Schedule forwarding table update (sources: <>, state: deleted, rlocs: 0). *Oct 4 15:00:38.125: LISP-0: Remote EID IID 0 prefix 192.168.2.102/32, Schedule forwarding table update, on queue (sources: <>, state: deleted, rlocs: 0). *Oct 4 15:00:38.125: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Skip entry (sources: , state: complete, rlocs: 0). *Oct 4 15:00:38.125: LISP-0: Remote shrRLOC 192.168.123.2, Schedule update of dependent rrloc_set_elems. *Oct 4 15:00:38.125: LISP: RIB Watch Group default 192.168.123.2/32 , created. *Oct 4 15:00:38.126: LISP: RIB Watch Group default 192.168.123.2/32 , scheduling RIB update. *Oct 4 15:00:38.126: LISP-0: Remote shrRLOC 192.168.123.2, Created. *Oct 4 15:00:38.126: LISP-0: Remote RLOCset 0xD0BF678 1 RLOCs, Created 192.168.123.2 pri/wei=10/10. *Oct 4 15:00:38.126: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Changing RLOC set 0x0 -> 0xD0BF678 (sources: , state: complete, rlocs: 0). *Oct 4 15:00:38.126: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, RLOCs pending rwatch update, defer fwd update (sources: , state: complete, rlocs: 0). *Oct 4 15:00:38.126: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, 1 RLOCs pending rwatch update, defer fwd update (sources: , state: complete, rlocs: 0). *Oct 4 15:00:38.127: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Change RLOC set elem NULL -> [RRLOCset 0xD0BF678 1/1] 192.168.123.2 pri/wei=10/10 (sources: , state: complete, rlocs: 1). *Oct 4 15:00:38.127: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24 [RRLOCset 0xD0BF678 1/1] 192.168.123.2 pri/wei=10/10, No probe local R (sources: , state: complete, rlocs: 1). *Oct 4 15:00:38.127: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24 [RRLOCset 0xD0BF678 1/1] 192.168.123.2 pri/wei=10/10, [none] Setting locator last reported state to up, was unknown (sources: , state: complete, rlocs: 1). *Oct 4 15:00:38.127: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24 [RRLOCset 0xD0BF678 1/1] 192.168.123.2 pri/wei=10/10, Setting locator reported state to up (sources: , state: complete, rlocs: 1). *Oct 4 15:00:38.128: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Recalculated RLOC status bits from 0x0 to 0x1 (sources: , state: complete, rlocs: 1). *Oct 4 15:00:38.128: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, 1 RLOCs pending rwatch update, defer fwd update (sources: , state: complete, rlocs: 1). *Oct 4 15:00:38.128: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24 [RRLOCset 0xD0BF678 1/1] 192.168.123.2 pri/wei=10/10, Created (sources: , state: complete, rlocs: 1). *Oct 4 15:00:38.128: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Schedule expiration timer at 23:59:52 (+refresh) (sources: , state: complete, rlocs: 1). *Oct 4 15:00:38.129: LISP-0: Remote EID IID 0 prefix 192.168.2.102/32, Map-reply from 192.168.123.2 returned less specific 192.168.2.0/24 (sources: <>, state: deleted, rlocs: 0). *Oct 4 15:00:38.129: LISP: Processed 1 control packets. *Oct 4 15:00:38.129: LISP-0: AF IID 0 IPv4, Checkpointed 2 remote EID entries. *Oct 4 15:00:38.129: LISP-0: Remote EID IID 0 prefix 192.168.2.102/32, Remove from forwarding (sources: <>, state: deleted, rlocs: 0). *Oct 4 15:00:38.130: LISP-0: Remote EID IID 0 prefix 192.168.2.102/32, Delete (sources: <>, state: deleted, rlocs: 0). *Oct 4 15:00:38.131: LISP-0: AF IID 0 IPv4, Updated 1 remote EID entries in forwarding table. *Oct 4 15:00:38.131: LISP: RIB Watch Group default 192.168.123.2/32 , installing in RIB. *Oct 4 15:00:38.132: LISP: Route watch OS notification. *Oct 4 15:00:38.132: LISP: TOPO default IPv4, Updated 1 watch groups in RIB done (state: UP). *Oct 4 15:00:38.132: LISP: RIB Next-hop default GigabitEthernet0/1 192.168.123.2 lcl UNSPEC, created. *Oct 4 15:00:38.132: LISP: RIB Next-hop default GigabitEthernet0/1 192.168.123.2 lcl 192.168.123.1, notified. *Oct 4 15:00:38.132: LISP: Processed 1 RIB watch group OS notifications. *Oct 4 15:00:38.133: LISP: Processed 1 next-hop watch-group notifications. *Oct 4 15:00:38.133: LISP-0: Remote shrRLOC 192.168.123.2, Schedule update of dependent rrloc_set_elems. *Oct 4 15:00:38.133: LISP-0: Remote shrRLOC 192.168.123.2, Reachability notification, up* allow* remote. *Oct 4 15:00:38.133: LISP-0: Remote shrRLOC 192.168.123.2, Schedule update of all dependent rrloc. *Oct 4 15:00:38.133: LISP-0: Remote shrRLOC 192.168.123.2, Schedule update of dependent rrloc_set_elems. *Oct 4 15:00:38.134: LISP-0: Remote shrRLOC 192.168.123.2, Next-hop interface address changed. *Oct 4 15:00:38.134: LISP: Processed 1 RIB watch notifications. *Oct 4 15:00:38.134: LISP-0: Remote RLOCset elem [RRLOCset 0xD0BF678 1/1] 192.168.123.2 pri/wei=10/10, Updating from shared RLOC. *Oct 4 15:00:38.134: LISP-0: Remote RLOCset 0xD0BF678 1 RLOCs, Schedule update 192.168.123.2 pri/wei=10/10. *Oct 4 15:00:38.134: LISP-0: Remote RLOCset 0xD0BF678 1 RLOCs, Schedule update 192.168.123.2 pri/wei=10/10. *Oct 4 15:00:38.135: LISP-0: Updated 1 remote RLOC set elements. *Oct 4 15:00:38.135: LISP-0: Updated 1 dependent RLOCs. *Oct 4 15:00:38.135: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, No more RLOCs pending rwatch update, schedule deferred fwd update (sources: , state: complete, rlocs: 1). *Oct 4 15:00:38.135: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Schedule forwarding table update (sources: , state: complete, rlocs: 1). *Oct 4 15:00:38.136: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Schedule forwarding table update, on queue (sources: , state: complete, rlocs: 1). *Oct 4 15:00:38.136: LISP-0: Updated 1 remote RLOC EID prefixes from RLOC set. *Oct 4 15:00:38.136: LISP-0: AF IID 0 IPv4, Checkpointed 1 remote EID entries. *Oct 4 15:00:38.136: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Update forwarding state (sources: , state: complete, rlocs: 1). *Oct 4 15:00:38.136: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Changing best usable locator priority from 255 to 10 (sources: , state: complete, rlocs: 1). *Oct 4 15:00:38.142: LISP-0: AF IID 0 IPv4, Updated 1 remote EID entries in forwarding table. *Oct 4 15:00:42.034: LISP: Net receive queuing packet for LISP process. *Oct 4 15:00:42.034: LISP-0: Received packet datagramsize 120, encsize 0, size 120. *Oct 4 15:00:42.035: LISP: Processing received Encap-Control(8) message on GigabitEthernet0/1 from 192.168.123.3:4342 to 192.168.123.1:4342 *Oct 4 15:00:42.035: LISP-0: decapsulating LISP control packet. *Oct 4 15:00:42.035: LISP: Processing received Map-Request(1) message on GigabitEthernet0/1 from 192.168.1.101:4342 to 192.168.1.101:4342 *Oct 4 15:00:42.035: LISP: Allocating map request parsing buffer for 1 prefixes. *Oct 4 15:00:42.036: LISP-0: Map request record parse, EID prefix 192.168.1.101/32. *Oct 4 15:00:42.036: LISP: Received map request for IID 0 192.168.1.101/32, source_eid IID 0 192.168.2.102, ITR-RLOCs: 192.168.123.2, records 1, nonce 0x72D96C94-0x06EB3997 *Oct 4 15:00:42.036: LISP: Parsing mapping record for EID prefix IID 0 192.168.2.0/24 *Oct 4 15:00:42.036: LISP-0: Mapping Record has 1 locators (action none). *Oct 4 15:00:42.036: LISP: Processing map request record for EID prefix IID 0 192.168.1.101/32 *Oct 4 15:00:42.037: LISP: TOPO default IPv4, Route locator 192.168.123.2 resolved via /24 pfx, src 192.168.123.1 nh 192.168.123.2 if GigabitEthernet0/1 (state: UP). *Oct 4 15:00:42.037: LISP-0: Added mapping record locator 192.168.123.1 (priority 10, weight 10, local, reachable). *Oct 4 15:00:42.037: LISP-0: Built mapping. Prefix = 192.168.1.0/24, #locators = 1, TTL = 1440, action = none. *Oct 4 15:00:42.038: LISP-0: Sending map-reply from 192.168.123.1 to 192.168.123.2. *Oct 4 15:00:42.038: LISP: IPv4, Sending control packet out of GigabitEthernet0/1 with next hop 192.168.123.2. *Oct 4 15:00:42.038: LISP: Set initial min output if hold queue size to 40 (intf GigabitEthernet0/1). *Oct 4 15:00:42.039: LISP: Processing mapping information for EID prefix IID 0 192.168.2.0/24 *Oct 4 15:00:42.039: LISP-0: AF IID 0 IPv4, Not configured to accept unsolicited mapping. *Oct 4 15:00:42.040: LISP: Processed 1 control packets. *Oct 4 15:01:00.926: LISP: Timer event (AF remote EID activity). *Oct 4 15:01:00.926: LISP-0: AF IID 0 IPv4, Remote EID prefix activity check timer fired. *Oct 4 15:01:00.926: LISP-0: Remote EID IID 0 prefix 0.0.0.0/0, Data out activity (0 -> 1) (sources: , state: send-map-request, rlocs: 0). *Oct 4 15:01:00.927: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Data out activity (0 -> 3) (sources: , state: complete, rlocs: 1). *Oct 4 15:01:00.927: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Resetting idle timer (delay 00:02:30) (sources: , state: complete, rlocs: 1). *Oct 4 15:01:00.927: LISP-0: Remote EID IID 0 prefix 192.168.2.0/24, Placing on active queue (sources: , state: complete, rlocs: 1). *Oct 4 15:01:00.927: LISP-0: AF IID 0 IPv4, Updated activity of 2 remote EID entries.