search

FRRouting / frr

The FRRouting Protocol Suite
https://frrouting.org/
Other
3.27k stars 1.24k forks source link

EIGRP PROC OUT EOT: NENastavujem metriku (ggl translate: Do not set the metric) #765

Closed lucize closed 7 years ago

lucize commented 7 years ago

on a centos server and a cisco 3285 router

2017/06/29 02:29:44 EIGRP: eigrpd 3.1-dev starting: vty@2613
2017/06/29 02:29:44 EIGRP: interface 10.160.21.104 [15] join EIGRP Multicast group.
2017/06/29 02:29:44 EIGRP: interface 10.160.1.253 [7] join EIGRP Multicast group.
2017/06/29 02:29:44 EIGRP: interface 10.160.11.253 [5] join EIGRP Multicast group.
2017/06/29 02:29:47 EIGRP: Neighbor 10.160.1.100 (brsrv) is pending: new adjacency
2017/06/29 02:29:49 EIGRP: Neighbor adjacency became full
2017/06/29 02:29:49 EIGRP: PROC OUT EOT: NENastavujem metriku
2017/06/29 02:29:49 EIGRP: PROC OUT EOT: NENastavujem metriku
2017/06/29 02:29:49 EIGRP: PROC OUT EOT: NENastavujem metriku
2017/06/29 02:33:03 EIGRP: Neighbor 10.160.1.100 (brsrv) is down: Interface PEER-TERMINATION received
2017/06/29 02:33:04 EIGRP: Neighbor 10.160.1.100 (brsrv) is pending: new adjacency

the centos settings

! -*- eigrpd -*-
!
! EIGRPDd sample configuration file
!
!
hostname eigrpd
password zebra
!enable password please-set-at-here
!
!
interface brsrv
!
router eigrp 1
  network 192.168.123.0/24
  network 10.0.0.0/8
!
log file /var/log/frr/eigrpd.log
!
log stdout

regards

donaldsharp commented 7 years ago

@lucize -> eigrp believes it has received a goodbye from the other side. What does the 3285 router state as the reason why it is shutting down the connection?

lucize commented 7 years ago

on simple log I have this

015683: Jun 29 02:27:20: %DUAL-5-NBRCHANGE: EIGRP-IPv4 1: Neighbor 10.160.1.253 (GigabitEthernet0/0.15) is up: new adjacency
015684: Jun 29 02:28:15: %DUAL-5-NBRCHANGE: EIGRP-IPv4 1: Neighbor 10.160.1.253 (GigabitEthernet0/0.15) is down: retry limit exceeded
015685: Jun 29 02:28:15: %DUAL-5-NBRCHANGE: EIGRP-IPv4 1: Neighbor 10.160.1.253 (GigabitEthernet0/0.15) is up: new adjacency
015686: Jun 29 02:29:10: %DUAL-5-NBRCHANGE: EIGRP-IPv4 1: Neighbor 10.160.1.253 (GigabitEthernet0/0.15) is down: retry limit exceeded
015687: Jun 29 02:29:10: %DUAL-5-NBRCHANGE: EIGRP-IPv4 1: Neighbor 10.160.1.253 (GigabitEthernet0/0.15) is up: new adjacency
015688: Jun 29 02:29:14: %DUAL-5-NBRCHANGE: EIGRP-IPv4 1: Neighbor 10.160.1.253 (GigabitEthernet0/0.15) is down: peer restarted
015689: Jun 29 02:29:14: %DUAL-5-NBRCHANGE: EIGRP-IPv4 1: Neighbor 10.160.1.253 (GigabitEthernet0/0.15) is up: new adjacency

should it be the linux firewall ? regards

donaldsharp commented 7 years ago

@lucize EIGRP needs both unicast and multicast connectivity. I would add a linux firewall rule to allow unicast network connectivity. I know I had problems testing EIGRP on my home box due to the firewall installed on it at that time, in which I had to turn it off to get it to work.

lucize commented 7 years ago

I disabled the firewall (eigrp uses protocol 88)

enabled some debug

015736: Jun 29 03:07:50.520 EET: EIGRP: Packet from ourselves ignored
015737: Jun 29 03:07:51.620 EET: EIGRP: Retransmission retry limit exceeded
015738: Jun 29 03:07:51.624 EET: EIGRP: Holdtime expired
015739: Jun 29 03:07:51: %DUAL-5-NBRCHANGE: EIGRP-IPv4 1: Neighbor 10.160.1.253 (GigabitEthernet0/0.15) is down: retry limit exceeded
015740: Jun 29 03:07:51.624 EET: Going down: Peer 10.160.1.253 total=30 stub 0, iidb-stub=0 iid-all=0
015741: Jun 29 03:07:51.624 EET: EIGRP(0:1):[bfd_reg] state:2 iidb:Gi0/0.15 peer:10.160.1.253
015742: Jun 29 03:07:51.624 EET: EIGRP: Handle deallocation failure [30]
015743: Jun 29 03:07:51.624 EET: EIGRP: Neighbor 10.160.1.253 went down on GigabitEthernet0/0.15
015744: Jun 29 03:07:51.756 EET: EIGRP: New peer 10.160.1.253
015749: Jun 29 03:08:46: %DUAL-5-NBRCHANGE: EIGRP-IPv4 1: Neighbor 10.160.1.253 (GigabitEthernet0/0.15) is down: retry limit exceeded
015750: Jun 29 03:08:46: %DUAL-5-NBRCHANGE: EIGRP-IPv4 1: Neighbor 10.160.1.253 (GigabitEthernet0/0.15) is up: new adjacency

and more verbose

015759: Jun 29 03:11:16.670 EET: EIGRP: Sending UPDATE on GigabitEthernet0/0.15 nbr 10.160.1.253, retry 14, RTO 5000 tid 0
015760: Jun 29 03:11:16.670 EET:   AS 1, Flags 0x0:(NULL), Seq 17428/14 interfaceQ 0/0 iidbQ un/rely 0/0 peerQ un/rely 0/1 serno 5-28627
015761: Jun 29 03:11:16.810 EET: EIGRP: Received HELLO on GigabitEthernet0/0.15 nbr 10.160.1.253
015762: Jun 29 03:11:16.810 EET:   AS 1, Flags 0x0:(NULL), Seq 0/0 interfaceQ 0/0 iidbQ un/rely 0/0 peerQ un/rely 0/1
015763: Jun 29 03:11:21.670 EET: EIGRP: Sending UPDATE on GigabitEthernet0/0.15 nbr 10.160.1.253, retry 15, RTO 5000 tid 0
015764: Jun 29 03:11:21.670 EET:   AS 1, Flags 0x0:(NULL), Seq 17428/14 interfaceQ 0/0 iidbQ un/rely 0/0 peerQ un/rely 0/1 serno 5-28627
015765: Jun 29 03:11:21.810 EET: EIGRP: Received HELLO on GigabitEthernet0/0.15 nbr 10.160.1.253
015766: Jun 29 03:11:21.814 EET:   AS 1, Flags 0x0:(NULL), Seq 0/0 interfaceQ 0/0 iidbQ un/rely 0/0 peerQ un/rely 0/1
015767: Jun 29 03:11:26.670 EET: EIGRP: Sending UPDATE on GigabitEthernet0/0.15 nbr 10.160.1.253, retry 16, RTO 5000 tid 0
015768: Jun 29 03:11:26.670 EET:   AS 1, Flags 0x0:(NULL), Seq 17428/14 interfaceQ 0/0 iidbQ un/rely 0/0 peerQ un/rely 0/1 serno 5-28627
015769: Jun 29 03:11:26.814 EET: EIGRP: Received HELLO on GigabitEthernet0/0.15 nbr 10.160.1.253
015770: Jun 29 03:11:26.814 EET:   AS 1, Flags 0x0:(NULL), Seq 0/0 interfaceQ 0/0 iidbQ un/rely 0/0 peerQ un/rely 0/1
015771: Jun 29 03:11:31.670 EET: EIGRP: Retransmission retry limit exceeded
015772: Jun 29 03:11:31: %DUAL-5-NBRCHANGE: EIGRP-IPv4 1: Neighbor 10.160.1.253 (GigabitEthernet0/0.15) is down: retry limit exceeded
015773: Jun 29 03:11:31.674 EET: EIGRP: Lost Version2 Peer (1 Peers, 0 V2 Peers)
015774: Jun 29 03:11:31.814 EET: EIGRP: Received HELLO on GigabitEthernet0/0.15 nbr 10.160.1.253
015775: Jun 29 03:11:31.814 EET:   AS 1, Flags 0x0:(NULL), Seq 0/0 interfaceQ 0/0
015776: Jun 29 03:11:31.818 EET: EIGRP: Adding Version2 Peer (1 Peers, 1 V2 Peers)
015777: Jun 29 03:11:31: %DUAL-5-NBRCHANGE: EIGRP-IPv4 1: Neighbor 10.160.1.253 (GigabitEthernet0/0.15) is up: new adjacency
015778: Jun 29 03:11:31.818 EET: EIGRP: Enqueueing UPDATE on GigabitEthernet0/0.15 nbr 10.160.1.253 tid 0 iidbQ un/rely 0/1 peerQ un/rely 0/0
015779: Jun 29 03:11:31.822 EET: EIGRP: Received UPDATE on GigabitEthernet0/0.15 nbr 10.160.1.253
015780: Jun 29 03:11:31.822 EET:   AS 1, Flags 0x1:(INIT), Seq 15/0 interfaceQ 0/0 iidbQ un/rely 0/0 peerQ un/rely 0/1
015781: Jun 29 03:11:31.822 EET: EIGRP: Received HELLO on GigabitEthernet0/0.15 nbr 10.160.1.253
015782: Jun 29 03:11:31.822 EET:   AS 1, Flags 0x0:(NULL), Seq 0/0 interfaceQ 0/0 iidbQ un/rely 0/0 peerQ un/rely 0/1
015783: Jun 29 03:11:31.826 EET: EIGRP: Sending UPDATE on GigabitEthernet0/0.15 nbr 10.160.1.253 tid 0
015784: Jun 29 03:11:31.826 EET:   AS 1, Flags 0x1:(INIT), Seq 17429/15 interfaceQ 0/0 iidbQ un/rely 0/0 peerQ un/rely 0/1
015785: Jun 29 03:11:31.826 EET: EIGRP: Received UPDATE on GigabitEthernet0/0.15 nbr 10.160.1.253
015786: Jun 29 03:11:31.826 EET:   AS 1, Flags 0x8:(EOT), Seq 16/17429 interfaceQ 0/0 iidbQ un/rely 0/0 peerQ un/rely 0/1
015787: Jun 29 03:11:31.826 EET: EIGRP: Enqueueing ACK on GigabitEthernet0/0.15 nbr 10.160.1.253 tid 0
015788: Jun 29 03:11:31.826 EET:   Ack seq 16 iidbQ un/rely 0/1 peerQ un/rely 1/0
015789: Jun 29 03:11:31.834 EET: EIGRP: Sending ACK on GigabitEthernet0/0.15 nbr 10.160.1.253 tid 0
015790: Jun 29 03:11:31.834 EET:   AS 1, Flags 0x0:(NULL), Seq 0/16 interfaceQ 0/0 iidbQ un/rely 0/0 peerQ un/rely 1/1
015791: Jun 29 03:11:32.030 EET: EIGRP: Sending UPDATE on GigabitEthernet0/0.15 nbr 10.160.1.253, retry 1, RTO 300 tid 0
015792: Jun 29 03:11:32.030 EET:   AS 1, Flags 0x0:(NULL), Seq 17430/16 interfaceQ 0/0 iidbQ un/rely 0/0 peerQ un/rely 0/1 serno 5-28627
015793: Jun 29 03:11:32.330 EET: EIGRP: Sending UPDATE on GigabitEthernet0/0.15 nbr 10.160.1.253, retry 2, RTO 450 tid 0
015794: Jun 29 03:11:32.330 EET:   AS 1, Flags 0x0:(NULL), Seq 17430/16 interfaceQ 0/0 iidbQ un/rely 0/0 peerQ un/rely 0/1 serno 5-28627
015795: Jun 29 03:11:32.782 EET: EIGRP: Sending UPDATE on GigabitEthernet0/0.15 nbr 10.160.1.253, retry 3, RTO 675 tid 0
015796: Jun 29 03:11:32.782 EET:   AS 1, Flags 0x0:(NULL), Seq 17430/16 interfaceQ 0/0 iidbQ un/rely 0/0 peerQ un/rely 0/1 serno 5-28627
015797: Jun 29 03:11:33.458 EET: EIGRP: Sending UPDATE on GigabitEthernet0/0.15 nbr 10.160.1.253, retry 4, RTO 1012 tid 0
015798: Jun 29 03:11:33.458 EET:   AS 1, Flags 0x0:(NULL), Seq 17430/16 interfaceQ 0/0 iidbQ un/rely 0/0 peerQ un/rely 0/1 serno 5-28627
015799: Jun 29 03:11:34.470 EET: EIGRP: Sending UPDATE on GigabitEthernet0/0.15 nbr 10.160.1.253, retry 5, RTO 1518 tid 0
015800: Jun 29 03:11:34.470 EET:   AS 1, Flags 0x0:(NULL), Seq 17430/16 interfaceQ 0/0 iidbQ un/rely 0/0 peerQ un/rely 0/1 serno 5-28627
015801: Jun 29 03:11:35.990 EET: EIGRP: Sending UPDATE on GigabitEthernet0/0.15 nbr 10.160.1.253, retry 6, RTO 2277 tid 0
015802: Jun 29 03:11:35.990 EET:   AS 1, Flags 0x0:(NULL), Seq 17430/16 interfaceQ 0/0 iidbQ un/rely 0/0 peerQ un/rely 0/1 serno 5-28627
015803: Jun 29 03:11:36.818 EET: EIGRP: Received HELLO on GigabitEthernet0/0.15 nbr 10.160.1.253
015804: Jun 29 03:11:36.818 EET:   AS 1, Flags 0x0:(NULL), Seq 0/0 interfaceQ 0/0 iidbQ un/rely 0/0 peerQ un/rely 0/1

016006: Jun 29 03:14:31.736 EET: Building multicast STARTUP packet for GigabitEthernet0/0.15, serno 5-28627 for tid 0
016007: Jun 29 03:14:31.736 EET:   Items:  5 6 262 299 300 S301 6096 6097 6098 6176 6177 6180 6181 6193 6194 6199 6200 6205 6206 6207 6208 6209 6210 6211 6214 6215 6216 6217 6218 6219 6230 6231 6232 6233 6235 6238 6243 6248 6249 9592 9593 10016 10017 10619 10620 10621 10622 11010 11011 11294 11295 11296 13044 13045 15518 15519 15920 15921 16444 16445 17132 17133 17269 17445 17446 17447 17562 17563 19469 19470 19471 19474 19661 19662 28555 28560 28561 28562 28563 28564 28565 28566 28567 28568 28581 28582 28584 28585 28586 28587 28588 28589 28590 28591 28592

don't know if it helps regards !

donaldsharp commented 7 years ago

The linux side does not appear to be sending ack's to update packets from the cisco side. Can you turn on 'debug eigrp packets all' and debug eigrp transmit all and upload the resulting log file?

lucize commented 7 years ago

yes, I'll try later, now is late :) regards

donaldsharp commented 7 years ago

@diivious or @janovic Can you help us out here? Looks like we have a situation that could use your expertise

lucize commented 7 years ago

executing debug eigrp packets all and debug eigrp transmit all I see noting on linux side, or I don't know how to enable the debug to stdout issuing sh log I have this:

Logging configuration for zebra:
Syslog logging: disabled
Stdout logging: disabled
Monitor logging: level debugging
File logging: disabled
Protocol name: ZEBRA
Record priority: disabled
Timestamp precision: 0

Logging configuration for ripd:
Syslog logging: disabled
Stdout logging: level debugging
Monitor logging: level debugging
File logging: level debugging, filename /var/log/frr/ripd.log
Protocol name: RIP
Record priority: disabled
Timestamp precision: 0

Logging configuration for eigrpd:
Syslog logging: disabled
Stdout logging: level debugging
Monitor logging: level debugging
File logging: level debugging, filename /var/log/frr/eigrpd.log
Protocol name: EIGRP
Record priority: disabled
Timestamp precision: 0

nothing more

donaldsharp commented 7 years ago

from your above config the log file is saved in /var/log/frr/eigrpd.log attach that here

lucize commented 7 years ago

nothing more than the previous output

2017/06/29 15:41:19 EIGRP: Neighbor 10.160.1.100 (brsrv) is down: Interface PEER-TERMINATION received
2017/06/29 15:41:19 EIGRP: Neighbor 10.160.1.100 (brsrv) is pending: new adjacency
2017/06/29 15:41:19 EIGRP: Neighbor adjacency became full
2017/06/29 15:41:19 EIGRP: PROC OUT EOT: NENastavujem metriku
2017/06/29 15:41:19 EIGRP: PROC OUT EOT: NENastavujem metriku
2017/06/29 15:41:19 EIGRP: PROC OUT EOT: NENastavujem metriku
2017/06/29 15:42:14 EIGRP: Neighbor 10.160.1.100 (brsrv) is down: Interface PEER-TERMINATION received
2017/06/29 15:42:14 EIGRP: Neighbor 10.160.1.100 (brsrv) is pending: new adjacency
2017/06/29 15:42:14 EIGRP: Neighbor adjacency became full
2017/06/29 15:42:14 EIGRP: PROC OUT EOT: NENastavujem metriku
2017/06/29 15:42:14 EIGRP: PROC OUT EOT: NENastavujem metriku
2017/06/29 15:42:14 EIGRP: PROC OUT EOT: NENastavujem metriku
2017/06/29 15:43:09 EIGRP: Neighbor 10.160.1.100 (brsrv) is down: Interface PEER-TERMINATION received
2017/06/29 15:43:09 EIGRP: Neighbor 10.160.1.100 (brsrv) is pending: new adjacency
2017/06/29 15:43:09 EIGRP: Neighbor adjacency became full
2017/06/29 15:43:09 EIGRP: PROC OUT EOT: NENastavujem metriku
2017/06/29 15:43:09 EIGRP: PROC OUT EOT: NENastavujem metriku
2017/06/29 15:43:09 EIGRP: PROC OUT EOT: NENastavujem metriku
lucize commented 7 years ago

@donaldsharp so I tried to migrate to ospf and it warned me about metric mismatch the router had 9000 the server had 1500 (ospf was't working) after changing the MTU on the server interface ospf started working

but now I have this on eigrp:

2017/07/14 13:33:15 EIGRP: Neighbor adjacency became full
2017/07/14 13:33:15 EIGRP: PROC OUT EOT: NENastavujem metriku
2017/07/14 13:33:15 EIGRP: PROC OUT EOT: NENastavujem metriku
2017/07/14 13:33:15 EIGRP: PROC OUT EOT: NENastavujem metriku
2017/07/14 13:33:15 EIGRP: PROC OUT EOT: NENastavujem metriku
2017/07/14 13:33:15 EIGRP: EIGRP AS: 1 State: 0  Event: 7 Network: 10.160.21.0

2017/07/14 13:33:15 EIGRP: EIGRP AS: 1 State: 0  Event: 7 Network: 10.160.11.0

2017/07/14 13:33:15 EIGRP: prefix_copy(): Unknown address family 1
2017/07/14 13:33:15 EIGRP: Assertion `0' failed in file prefix.c, line 318, function prefix_copy
2017/07/14 13:33:15 EIGRP: Backtrace for 10 stack frames:
2017/07/14 13:33:15 EIGRP: [bt 0] /usr/lib64/libfrr.so.0(zlog_backtrace+0x32) [0x3eaac45052]
2017/07/14 13:33:15 EIGRP: [bt 1] /usr/lib64/libfrr.so.0(_zlog_assert_failed+0x69) [0x3eaac451c9]
2017/07/14 13:33:15 EIGRP: [bt 2] /usr/lib64/libfrr.so.0() [0x3eaac2f962]
2017/07/14 13:33:15 EIGRP: [bt 3] /usr/lib/frr/eigrpd(eigrp_update_receive+0x588) [0x413928]
2017/07/14 13:33:15 EIGRP: [bt 4] /usr/lib/frr/eigrpd(eigrp_read+0x6c7) [0x40f547]
2017/07/14 13:33:15 EIGRP: [bt 5] /usr/lib64/libfrr.so.0(thread_call+0x43) [0x3eaac31ab3]
2017/07/14 13:33:15 EIGRP: [bt 6] /usr/lib64/libfrr.so.0(frr_run+0x88) [0x3eaac5f0f8]
2017/07/14 13:33:15 EIGRP: [bt 7] /usr/lib/frr/eigrpd(main+0x116) [0x406c56]
2017/07/14 13:33:15 EIGRP: [bt 8] /lib64/libc.so.6(__libc_start_main+0xfd) [0x3f54a1f63d]
2017/07/14 13:33:15 EIGRP: [bt 9] /usr/lib/frr/eigrpd() [0x406a49]
2017/07/14 13:33:15 EIGRP: Current thread function eigrp_read, scheduled from file eigrp_packet.c, line 481

PROC OUT EOT: NENastavujem metriku maybe this was telling about MTU mismatch

regards

donaldsharp commented 7 years ago

@lucize that crash is fixed in #818 Should be in the code base in the next couple of days

lucize commented 7 years ago

thank a lot, it seems that is working maybe a translate for the MTU message so others could see if there is a mismatch ? for the moment I don't have redistribution on frr side I will close this regards

donaldsharp commented 7 years ago

@lucize the cleanup of eigrp messages is on my long term list of things to do.

lucize commented 7 years ago

I'll fork and make a PR after I scan the source regards