Circuit QNA-0, Dropped by adjacent node, Adjacent node = 5.1023 (A5RTR)
%<----------%<---------%<----------
followed some time later by...
%<----------%<---------%<----------
%%%%%%%%%%% OPCOM 22-SEP-2014 08:46:14.06 %%%%%%%%%%%
Message from user DECNET on SIMVAX
DECnet event 4.15, adjacency up
Circuit QNA-0, Adjacent node = 5.1023 (A5RTR)
%<----------%<---------%<----------
During the up/down cycle I do see messages being generated by the brige:
%<----------%<---------%<----------
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
%<----------%<---------%<----------
The bridge is connected to the outside world via a NAT rule in my
Mikrotik router.
Sorry for the long post! I've tried to be as comprehensive as I can be!
Thanks for the help, Mark.
Circuit QNA-0, Dropped by adjacent node, Adjacent node = 5.1023 (A5RTR)
%<----------%<---------%<----------
followed some time later by...
%<----------%<---------%<----------
%%%%%%%%%%% OPCOM 22-SEP-2014 08:46:14.06 %%%%%%%%%%%
Message from user DECNET on SIMVAX
DECnet event 4.15, adjacency up
Circuit QNA-0, Adjacent node = 5.1023 (A5RTR)
%<----------%<---------%<----------
During the up/down cycle I do see messages being generated by the brige:
%<----------%<---------%<----------
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
%<----------%<---------%<----------
The bridge is connected to the outside world via a NAT rule in my
Mikrotik router.
Sorry for the long post! I've tried to be as comprehensive as I can be!
Thanks for the help, Mark.
Circuit QNA-0, Dropped by adjacent node, Adjacent node = 5.1023 (A5RTR)
%<----------%<---------%<----------
followed some time later by...
%<----------%<---------%<----------
%%%%%%%%%%% OPCOM 22-SEP-2014 08:46:14.06 %%%%%%%%%%%
Message from user DECNET on SIMVAX
DECnet event 4.15, adjacency up
Circuit QNA-0, Adjacent node = 5.1023 (A5RTR)
%<----------%<---------%<----------
During the up/down cycle I do see messages being generated by the brige:
%<----------%<---------%<----------
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
Setting existing hash to bridge 1
%<----------%<---------%<----------
The bridge is connected to the outside world via a NAT rule in my Mikrotik router.
Sorry for the long post! I've tried to be as comprehensive as I can be!
Thanks for the help, Mark.
However the packet sniffer sees extra packets inserted. I have no
idea where these packets are coming from (although my suspicion is
winpcap, see later).
2. 8.400 seems to send its Ethernet Router Hello every 15 seconds,
but repeats them several times at 1-second intervals. In the extract
above it is repeated 3 times, then 3 times, then 5 times.
3. For a node to decide to drop an adjacency (ie to exclude it from
the Ethernet Router Hello message), it must fail to see an Ethernet
Router Hello for 3xHello Timer (Hello Timer is 15 seconds by default,
so 45 seconds). Clearly my side has sent several Ethernet Router
Hello messages in that time. If this was UDP dropping packets, then I
would have hoped that it would not drop my particular ones 3 times in
a row over a period of 45 seconds.
So, somehow, my Ethernet Router Hello messages are being dropped on
their way to 8.400. However, this can t be outbound from 5.1023,
because if that was the case then all my adjacencies would all go
down at the same time. At any one time, only adjacency goes down.
This suggests that the packet is somehow getting lost towards the end
of its journey to 8.400.
What kind of node is 8.400? 47.556 is another one that appears to
have this problem, I see that one is SIMH.
I am wondering if pcap/winpcap might be implicated here. The reason
is that I noticed winpcap seems to drop incoming packets if you have
sent a burst of outbound packets. In my router I was sending all the
DECnet Level 1 Routing messages, all at the same time and getting
some problems similar to this with a node local to my network,
because my router did not see the packets coming from the other node,
even though the sniffer could see them. I changed my router code to
send the Level 1 Routing messages with a 1-second delay between them,
and that problem went away.
So, I am wondering if the remote nodes I have this problem with are
SIMH nodes?
I do also see, less frequently, timeouts on my side. These are when I
fail to see an Ethernet Router Hello from the other node for 45 seconds.
I have not analysed this scenario.
Any ideas?
Regards
Rob
2014-06-28 15:00:50 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-28 15:42:04 Adjacency timeout 8.400 (Slot 23)
2014-06-28 15:42:04 Adjacency down 8.400 (Slot 23)
2014-06-28 15:42:06 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-28 16:37:12 Adjacency timeout 8.400 (Slot 23)
2014-06-28 16:37:12 Adjacency down 8.400 (Slot 23)
2014-06-28 16:37:17 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-28 18:11:46 Adjacency timeout 8.400 (Slot 23)
2014-06-28 18:11:46 Adjacency down 8.400 (Slot 23)
2014-06-28 18:12:04 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-28 18:15:11 Adjacency timeout 47.556 (Slot 25)
2014-06-28 18:15:11 Adjacency down 47.556 (Slot 25)
2014-06-28 18:15:14 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-28 18:33:15 Adjacency timeout 47.556 (Slot 25)
2014-06-28 18:33:15 Adjacency down 47.556 (Slot 25)
2014-06-28 18:33:18 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-28 18:33:19 Adjacency down 47.556 (Slot 25)
2014-06-28 18:33:42 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-28 18:54:37 Adjacency timeout 47.556 (Slot 25)
2014-06-28 18:54:37 Adjacency down 47.556 (Slot 25)
2014-06-28 18:54:43 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-28 19:36:02 Adjacency timeout 47.556 (Slot 25)
2014-06-28 19:36:02 Adjacency down 47.556 (Slot 25)
2014-06-28 19:36:20 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-28 19:44:36 Adjacency timeout 28.41 (Slot 24)
2014-06-28 19:44:36 Adjacency down 28.41 (Slot 24)
2014-06-28 19:53:04 Adjacency up 28.41 (Slot 24) on
psilo.update.uu.se
2014-06-28 19:55:08 Adjacency timeout 28.41 (Slot 24)
2014-06-28 19:55:08 Adjacency down 28.41 (Slot 24)
2014-06-28 19:57:20 Adjacency up 28.41 (Slot 24) on
psilo.update.uu.se
2014-06-28 20:00:03 Adjacency down 8.400 (Slot 23)
2014-06-28 20:00:03 Adjacency down 47.556 (Slot 25)
2014-06-28 20:00:04 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-28 20:00:05 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-28 20:18:08 Adjacency timeout 8.400 (Slot 23)
2014-06-28 20:18:08 Adjacency down 8.400 (Slot 23)
2014-06-28 20:18:12 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-28 20:47:46 Adjacency down 8.400 (Slot 23)
2014-06-28 20:47:46 Adjacency down 47.556 (Slot 25)
2014-06-28 20:47:49 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-28 20:47:49 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-28 22:04:03 Adjacency down 8.400 (Slot 23)
2014-06-28 22:04:04 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-28 23:10:26 Adjacency timeout 5.99 (Slot 30)
2014-06-28 23:10:26 Adjacency down 5.99 (Slot 30)
2014-06-28 23:18:28 Adjacency down 8.400 (Slot 23)
2014-06-28 23:18:28 Adjacency down 47.556 (Slot 25)
2014-06-28 23:18:34 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-28 23:18:35 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-28 23:25:50 Adjacency timeout 47.556 (Slot 25)
2014-06-28 23:25:50 Adjacency down 47.556 (Slot 25)
2014-06-28 23:25:54 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-29 00:06:52 Adjacency timeout 8.400 (Slot 23)
2014-06-29 00:06:52 Adjacency down 8.400 (Slot 23)
2014-06-29 00:06:58 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-29 00:10:47 Adjacency timeout 47.556 (Slot 25)
2014-06-29 00:10:47 Adjacency down 47.556 (Slot 25)
2014-06-29 00:10:47 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-29 00:28:21 Adjacency timeout 8.400 (Slot 23)
2014-06-29 00:28:21 Adjacency down 8.400 (Slot 23)
2014-06-29 00:28:26 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-29 00:30:54 Adjacency down 8.400 (Slot 23)
2014-06-29 00:31:18 Adjacency timeout 47.556 (Slot 25)
2014-06-29 00:31:18 Adjacency down 47.556 (Slot 25)
2014-06-29 00:31:21 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-29 00:31:21 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-29 00:45:41 Adjacency timeout 8.400 (Slot 23)
2014-06-29 00:45:41 Adjacency down 8.400 (Slot 23)
2014-06-29 00:46:04 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-29 00:53:57 Adjacency down 11.2 (Slot 21)
2014-06-29 00:54:05 Adjacency up 11.2 (Slot 21) on psilo.update.uu.se
2014-06-29 04:45:36 Adjacency timeout 47.556 (Slot 25)
2014-06-29 04:45:36 Adjacency down 47.556 (Slot 25)
2014-06-29 04:45:38 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-29 04:49:49 Adjacency timeout 47.556 (Slot 25)
2014-06-29 04:49:49 Adjacency down 47.556 (Slot 25)
2014-06-29 04:53:19 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-29 06:46:04 Adjacency up 62.637 (Slot 29) on
psilo.update.uu.se
2014-06-29 08:01:32 Adjacency timeout 47.556 (Slot 25)
2014-06-29 08:01:32 Adjacency down 47.556 (Slot 25)
2014-06-29 08:01:33 Adjacency timeout 8.400 (Slot 23)
2014-06-29 08:01:33 Adjacency down 8.400 (Slot 23)
2014-06-29 08:03:04 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-29 08:03:51 Adjacency timeout 8.400 (Slot 23)
2014-06-29 08:03:51 Adjacency down 8.400 (Slot 23)
2014-06-29 08:04:39 Adjacency timeout 47.556 (Slot 23)
2014-06-29 08:04:49 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-29 08:04:50 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-29 08:05:52 Adjacency timeout 47.556 (Slot 25)
2014-06-29 08:05:52 Adjacency down 47.556 (Slot 25)
2014-06-29 08:08:06 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-29 08:10:02 Adjacency timeout 8.400 (Slot 23)
2014-06-29 08:10:02 Adjacency down 8.400 (Slot 23)
2014-06-29 08:10:18 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
However the packet sniffer sees extra packets inserted. I have no
idea where these packets are coming from (although my suspicion is
winpcap, see later).
2. 8.400 seems to send its Ethernet Router Hello every 15 seconds,
but repeats them several times at 1-second intervals. In the extract
above it is repeated 3 times, then 3 times, then 5 times.
3. For a node to decide to drop an adjacency (ie to exclude it from
the Ethernet Router Hello message), it must fail to see an Ethernet
Router Hello for 3xHello Timer (Hello Timer is 15 seconds by default,
so 45 seconds). Clearly my side has sent several Ethernet Router
Hello messages in that time. If this was UDP dropping packets, then I
would have hoped that it would not drop my particular ones 3 times in
a row over a period of 45 seconds.
So, somehow, my Ethernet Router Hello messages are being dropped on
their way to 8.400. However, this can t be outbound from 5.1023,
because if that was the case then all my adjacencies would all go
down at the same time. At any one time, only adjacency goes down.
This suggests that the packet is somehow getting lost towards the end
of its journey to 8.400.
What kind of node is 8.400? 47.556 is another one that appears to
have this problem, I see that one is SIMH.
I am wondering if pcap/winpcap might be implicated here. The reason
is that I noticed winpcap seems to drop incoming packets if you have
sent a burst of outbound packets. In my router I was sending all the
DECnet Level 1 Routing messages, all at the same time and getting
some problems similar to this with a node local to my network,
because my router did not see the packets coming from the other node,
even though the sniffer could see them. I changed my router code to
send the Level 1 Routing messages with a 1-second delay between them,
and that problem went away.
So, I am wondering if the remote nodes I have this problem with are
SIMH nodes?
I do also see, less frequently, timeouts on my side. These are when I
fail to see an Ethernet Router Hello from the other node for 45 seconds.
I have not analysed this scenario.
Any ideas?
Regards
Rob
2014-06-28 15:00:50 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-28 15:42:04 Adjacency timeout 8.400 (Slot 23)
2014-06-28 15:42:04 Adjacency down 8.400 (Slot 23)
2014-06-28 15:42:06 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-28 16:37:12 Adjacency timeout 8.400 (Slot 23)
2014-06-28 16:37:12 Adjacency down 8.400 (Slot 23)
2014-06-28 16:37:17 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-28 18:11:46 Adjacency timeout 8.400 (Slot 23)
2014-06-28 18:11:46 Adjacency down 8.400 (Slot 23)
2014-06-28 18:12:04 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-28 18:15:11 Adjacency timeout 47.556 (Slot 25)
2014-06-28 18:15:11 Adjacency down 47.556 (Slot 25)
2014-06-28 18:15:14 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-28 18:33:15 Adjacency timeout 47.556 (Slot 25)
2014-06-28 18:33:15 Adjacency down 47.556 (Slot 25)
2014-06-28 18:33:18 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-28 18:33:19 Adjacency down 47.556 (Slot 25)
2014-06-28 18:33:42 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-28 18:54:37 Adjacency timeout 47.556 (Slot 25)
2014-06-28 18:54:37 Adjacency down 47.556 (Slot 25)
2014-06-28 18:54:43 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-28 19:36:02 Adjacency timeout 47.556 (Slot 25)
2014-06-28 19:36:02 Adjacency down 47.556 (Slot 25)
2014-06-28 19:36:20 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-28 19:44:36 Adjacency timeout 28.41 (Slot 24)
2014-06-28 19:44:36 Adjacency down 28.41 (Slot 24)
2014-06-28 19:53:04 Adjacency up 28.41 (Slot 24) on
psilo.update.uu.se
2014-06-28 19:55:08 Adjacency timeout 28.41 (Slot 24)
2014-06-28 19:55:08 Adjacency down 28.41 (Slot 24)
2014-06-28 19:57:20 Adjacency up 28.41 (Slot 24) on
psilo.update.uu.se
2014-06-28 20:00:03 Adjacency down 8.400 (Slot 23)
2014-06-28 20:00:03 Adjacency down 47.556 (Slot 25)
2014-06-28 20:00:04 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-28 20:00:05 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-28 20:18:08 Adjacency timeout 8.400 (Slot 23)
2014-06-28 20:18:08 Adjacency down 8.400 (Slot 23)
2014-06-28 20:18:12 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-28 20:47:46 Adjacency down 8.400 (Slot 23)
2014-06-28 20:47:46 Adjacency down 47.556 (Slot 25)
2014-06-28 20:47:49 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-28 20:47:49 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-28 22:04:03 Adjacency down 8.400 (Slot 23)
2014-06-28 22:04:04 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-28 23:10:26 Adjacency timeout 5.99 (Slot 30)
2014-06-28 23:10:26 Adjacency down 5.99 (Slot 30)
2014-06-28 23:18:28 Adjacency down 8.400 (Slot 23)
2014-06-28 23:18:28 Adjacency down 47.556 (Slot 25)
2014-06-28 23:18:34 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-28 23:18:35 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-28 23:25:50 Adjacency timeout 47.556 (Slot 25)
2014-06-28 23:25:50 Adjacency down 47.556 (Slot 25)
2014-06-28 23:25:54 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-29 00:06:52 Adjacency timeout 8.400 (Slot 23)
2014-06-29 00:06:52 Adjacency down 8.400 (Slot 23)
2014-06-29 00:06:58 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-29 00:10:47 Adjacency timeout 47.556 (Slot 25)
2014-06-29 00:10:47 Adjacency down 47.556 (Slot 25)
2014-06-29 00:10:47 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-29 00:28:21 Adjacency timeout 8.400 (Slot 23)
2014-06-29 00:28:21 Adjacency down 8.400 (Slot 23)
2014-06-29 00:28:26 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-29 00:30:54 Adjacency down 8.400 (Slot 23)
2014-06-29 00:31:18 Adjacency timeout 47.556 (Slot 25)
2014-06-29 00:31:18 Adjacency down 47.556 (Slot 25)
2014-06-29 00:31:21 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-29 00:31:21 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-29 00:45:41 Adjacency timeout 8.400 (Slot 23)
2014-06-29 00:45:41 Adjacency down 8.400 (Slot 23)
2014-06-29 00:46:04 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-29 00:53:57 Adjacency down 11.2 (Slot 21)
2014-06-29 00:54:05 Adjacency up 11.2 (Slot 21) on psilo.update.uu.se
2014-06-29 04:45:36 Adjacency timeout 47.556 (Slot 25)
2014-06-29 04:45:36 Adjacency down 47.556 (Slot 25)
2014-06-29 04:45:38 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-29 04:49:49 Adjacency timeout 47.556 (Slot 25)
2014-06-29 04:49:49 Adjacency down 47.556 (Slot 25)
2014-06-29 04:53:19 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-29 06:46:04 Adjacency up 62.637 (Slot 29) on
psilo.update.uu.se
2014-06-29 08:01:32 Adjacency timeout 47.556 (Slot 25)
2014-06-29 08:01:32 Adjacency down 47.556 (Slot 25)
2014-06-29 08:01:33 Adjacency timeout 8.400 (Slot 23)
2014-06-29 08:01:33 Adjacency down 8.400 (Slot 23)
2014-06-29 08:03:04 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-29 08:03:51 Adjacency timeout 8.400 (Slot 23)
2014-06-29 08:03:51 Adjacency down 8.400 (Slot 23)
2014-06-29 08:04:39 Adjacency timeout 47.556 (Slot 23)
2014-06-29 08:04:49 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
2014-06-29 08:04:50 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-29 08:05:52 Adjacency timeout 47.556 (Slot 25)
2014-06-29 08:05:52 Adjacency down 47.556 (Slot 25)
2014-06-29 08:08:06 Adjacency up 47.556 (Slot 25) on
psilo.update.uu.se
2014-06-29 08:10:02 Adjacency timeout 8.400 (Slot 23)
2014-06-29 08:10:02 Adjacency down 8.400 (Slot 23)
2014-06-29 08:10:18 Adjacency up 8.400 (Slot 23) on
psilo.update.uu.se
However the packet sniffer sees extra packets inserted. I have no idea
where these packets are coming from (although my suspicion is winpcap,
see later).
2. 8.400 seems to send its Ethernet Router Hello every 15 seconds, but
repeats them several times at 1-second intervals. In the extract above
it is repeated 3 times, then 3 times, then 5 times.
3. For a node to decide to drop an adjacency (ie to exclude it from the
Ethernet Router Hello message), it must fail to see an Ethernet Router
Hello for 3xHello Timer (Hello Timer is 15 seconds by default, so 45
seconds). Clearly my side has sent several Ethernet Router Hello
messages in that time. If this was UDP dropping packets, then I would
have hoped that it would not drop my particular ones 3 times in a row
over a period of 45 seconds.
So, somehow, my Ethernet Router Hello messages are being dropped on
their way to 8.400. However, this can t be outbound from 5.1023, because
if that was the case then all my adjacencies would all go down at the
same time. At any one time, only adjacency goes down. This suggests that
the packet is somehow getting lost towards the end of its journey to
8.400.
What kind of node is 8.400? 47.556 is another one that appears to have
this problem, I see that one is SIMH.
I am wondering if pcap/winpcap might be implicated here. The reason is
that I noticed winpcap seems to drop incoming packets if you have sent a
burst of outbound packets. In my router I was sending all the DECnet
Level 1 Routing messages, all at the same time and getting some problems
similar to this with a node local to my network, because my router did
not see the packets coming from the other node, even though the sniffer
could see them. I changed my router code to send the Level 1 Routing
messages with a 1-second delay between them, and that problem went away.
So, I am wondering if the remote nodes I have this problem with are SIMH
nodes?
I do also see, less frequently, timeouts on my side. These are when I
fail to see an Ethernet Router Hello from the other node for 45 seconds.
I have not analysed this scenario.
Any ideas?
Regards
Rob
2014-06-28 15:00:50 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-28 15:42:04 Adjacency timeout 8.400 (Slot 23)
2014-06-28 15:42:04 Adjacency down 8.400 (Slot 23)
2014-06-28 15:42:06 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-28 16:37:12 Adjacency timeout 8.400 (Slot 23)
2014-06-28 16:37:12 Adjacency down 8.400 (Slot 23)
2014-06-28 16:37:17 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-28 18:11:46 Adjacency timeout 8.400 (Slot 23)
2014-06-28 18:11:46 Adjacency down 8.400 (Slot 23)
2014-06-28 18:12:04 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-28 18:15:11 Adjacency timeout 47.556 (Slot 25)
2014-06-28 18:15:11 Adjacency down 47.556 (Slot 25)
2014-06-28 18:15:14 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-28 18:33:15 Adjacency timeout 47.556 (Slot 25)
2014-06-28 18:33:15 Adjacency down 47.556 (Slot 25)
2014-06-28 18:33:18 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-28 18:33:19 Adjacency down 47.556 (Slot 25)
2014-06-28 18:33:42 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-28 18:54:37 Adjacency timeout 47.556 (Slot 25)
2014-06-28 18:54:37 Adjacency down 47.556 (Slot 25)
2014-06-28 18:54:43 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-28 19:36:02 Adjacency timeout 47.556 (Slot 25)
2014-06-28 19:36:02 Adjacency down 47.556 (Slot 25)
2014-06-28 19:36:20 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-28 19:44:36 Adjacency timeout 28.41 (Slot 24)
2014-06-28 19:44:36 Adjacency down 28.41 (Slot 24)
2014-06-28 19:53:04 Adjacency up 28.41 (Slot 24) on psilo.update.uu.se
2014-06-28 19:55:08 Adjacency timeout 28.41 (Slot 24)
2014-06-28 19:55:08 Adjacency down 28.41 (Slot 24)
2014-06-28 19:57:20 Adjacency up 28.41 (Slot 24) on psilo.update.uu.se
2014-06-28 20:00:03 Adjacency down 8.400 (Slot 23)
2014-06-28 20:00:03 Adjacency down 47.556 (Slot 25)
2014-06-28 20:00:04 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-28 20:00:05 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-28 20:18:08 Adjacency timeout 8.400 (Slot 23)
2014-06-28 20:18:08 Adjacency down 8.400 (Slot 23)
2014-06-28 20:18:12 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-28 20:47:46 Adjacency down 8.400 (Slot 23)
2014-06-28 20:47:46 Adjacency down 47.556 (Slot 25)
2014-06-28 20:47:49 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-28 20:47:49 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-28 22:04:03 Adjacency down 8.400 (Slot 23)
2014-06-28 22:04:04 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-28 23:10:26 Adjacency timeout 5.99 (Slot 30)
2014-06-28 23:10:26 Adjacency down 5.99 (Slot 30)
2014-06-28 23:18:28 Adjacency down 8.400 (Slot 23)
2014-06-28 23:18:28 Adjacency down 47.556 (Slot 25)
2014-06-28 23:18:34 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-28 23:18:35 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-28 23:25:50 Adjacency timeout 47.556 (Slot 25)
2014-06-28 23:25:50 Adjacency down 47.556 (Slot 25)
2014-06-28 23:25:54 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-29 00:06:52 Adjacency timeout 8.400 (Slot 23)
2014-06-29 00:06:52 Adjacency down 8.400 (Slot 23)
2014-06-29 00:06:58 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-29 00:10:47 Adjacency timeout 47.556 (Slot 25)
2014-06-29 00:10:47 Adjacency down 47.556 (Slot 25)
2014-06-29 00:10:47 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-29 00:28:21 Adjacency timeout 8.400 (Slot 23)
2014-06-29 00:28:21 Adjacency down 8.400 (Slot 23)
2014-06-29 00:28:26 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-29 00:30:54 Adjacency down 8.400 (Slot 23)
2014-06-29 00:31:18 Adjacency timeout 47.556 (Slot 25)
2014-06-29 00:31:18 Adjacency down 47.556 (Slot 25)
2014-06-29 00:31:21 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-29 00:31:21 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-29 00:45:41 Adjacency timeout 8.400 (Slot 23)
2014-06-29 00:45:41 Adjacency down 8.400 (Slot 23)
2014-06-29 00:46:04 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-29 00:53:57 Adjacency down 11.2 (Slot 21)
2014-06-29 00:54:05 Adjacency up 11.2 (Slot 21) on psilo.update.uu.se
2014-06-29 04:45:36 Adjacency timeout 47.556 (Slot 25)
2014-06-29 04:45:36 Adjacency down 47.556 (Slot 25)
2014-06-29 04:45:38 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-29 04:49:49 Adjacency timeout 47.556 (Slot 25)
2014-06-29 04:49:49 Adjacency down 47.556 (Slot 25)
2014-06-29 04:53:19 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-29 06:46:04 Adjacency up 62.637 (Slot 29) on psilo.update.uu.se
2014-06-29 08:01:32 Adjacency timeout 47.556 (Slot 25)
2014-06-29 08:01:32 Adjacency down 47.556 (Slot 25)
2014-06-29 08:01:33 Adjacency timeout 8.400 (Slot 23)
2014-06-29 08:01:33 Adjacency down 8.400 (Slot 23)
2014-06-29 08:03:04 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-29 08:03:51 Adjacency timeout 8.400 (Slot 23)
2014-06-29 08:03:51 Adjacency down 8.400 (Slot 23)
2014-06-29 08:04:39 Adjacency timeout 47.556 (Slot 23)
2014-06-29 08:04:49 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-29 08:04:50 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-29 08:05:52 Adjacency timeout 47.556 (Slot 25)
2014-06-29 08:05:52 Adjacency down 47.556 (Slot 25)
2014-06-29 08:08:06 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-29 08:10:02 Adjacency timeout 8.400 (Slot 23)
2014-06-29 08:10:02 Adjacency down 8.400 (Slot 23)
2014-06-29 08:10:18 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
However the packet sniffer sees extra packets inserted. I have no idea
where these packets are coming from (although my suspicion is winpcap,
see later).
2. 8.400 seems to send its Ethernet Router Hello every 15 seconds, but
repeats them several times at 1-second intervals. In the extract above
it is repeated 3 times, then 3 times, then 5 times.
3. For a node to decide to drop an adjacency (ie to exclude it from the
Ethernet Router Hello message), it must fail to see an Ethernet Router
Hello for 3xHello Timer (Hello Timer is 15 seconds by default, so 45
seconds). Clearly my side has sent several Ethernet Router Hello
messages in that time. If this was UDP dropping packets, then I would
have hoped that it would not drop my particular ones 3 times in a row
over a period of 45 seconds.
So, somehow, my Ethernet Router Hello messages are being dropped on
their way to 8.400. However, this can t be outbound from 5.1023, because
if that was the case then all my adjacencies would all go down at the
same time. At any one time, only adjacency goes down. This suggests that
the packet is somehow getting lost towards the end of its journey to 8.400.
What kind of node is 8.400? 47.556 is another one that appears to have
this problem, I see that one is SIMH.
I am wondering if pcap/winpcap might be implicated here. The reason is
that I noticed winpcap seems to drop incoming packets if you have sent a
burst of outbound packets. In my router I was sending all the DECnet
Level 1 Routing messages, all at the same time and getting some problems
similar to this with a node local to my network, because my router did
not see the packets coming from the other node, even though the sniffer
could see them. I changed my router code to send the Level 1 Routing
messages with a 1-second delay between them, and that problem went away.
So, I am wondering if the remote nodes I have this problem with are SIMH
nodes?
I do also see, less frequently, timeouts on my side. These are when I
fail to see an Ethernet Router Hello from the other node for 45 seconds.
I have not analysed this scenario.
Any ideas?
Regards
Rob
2014-06-28 15:00:50 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-28 15:42:04 Adjacency timeout 8.400 (Slot 23)
2014-06-28 15:42:04 Adjacency down 8.400 (Slot 23)
2014-06-28 15:42:06 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-28 16:37:12 Adjacency timeout 8.400 (Slot 23)
2014-06-28 16:37:12 Adjacency down 8.400 (Slot 23)
2014-06-28 16:37:17 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-28 18:11:46 Adjacency timeout 8.400 (Slot 23)
2014-06-28 18:11:46 Adjacency down 8.400 (Slot 23)
2014-06-28 18:12:04 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-28 18:15:11 Adjacency timeout 47.556 (Slot 25)
2014-06-28 18:15:11 Adjacency down 47.556 (Slot 25)
2014-06-28 18:15:14 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-28 18:33:15 Adjacency timeout 47.556 (Slot 25)
2014-06-28 18:33:15 Adjacency down 47.556 (Slot 25)
2014-06-28 18:33:18 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-28 18:33:19 Adjacency down 47.556 (Slot 25)
2014-06-28 18:33:42 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-28 18:54:37 Adjacency timeout 47.556 (Slot 25)
2014-06-28 18:54:37 Adjacency down 47.556 (Slot 25)
2014-06-28 18:54:43 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-28 19:36:02 Adjacency timeout 47.556 (Slot 25)
2014-06-28 19:36:02 Adjacency down 47.556 (Slot 25)
2014-06-28 19:36:20 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-28 19:44:36 Adjacency timeout 28.41 (Slot 24)
2014-06-28 19:44:36 Adjacency down 28.41 (Slot 24)
2014-06-28 19:53:04 Adjacency up 28.41 (Slot 24) on psilo.update.uu.se
2014-06-28 19:55:08 Adjacency timeout 28.41 (Slot 24)
2014-06-28 19:55:08 Adjacency down 28.41 (Slot 24)
2014-06-28 19:57:20 Adjacency up 28.41 (Slot 24) on psilo.update.uu.se
2014-06-28 20:00:03 Adjacency down 8.400 (Slot 23)
2014-06-28 20:00:03 Adjacency down 47.556 (Slot 25)
2014-06-28 20:00:04 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-28 20:00:05 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-28 20:18:08 Adjacency timeout 8.400 (Slot 23)
2014-06-28 20:18:08 Adjacency down 8.400 (Slot 23)
2014-06-28 20:18:12 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-28 20:47:46 Adjacency down 8.400 (Slot 23)
2014-06-28 20:47:46 Adjacency down 47.556 (Slot 25)
2014-06-28 20:47:49 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-28 20:47:49 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-28 22:04:03 Adjacency down 8.400 (Slot 23)
2014-06-28 22:04:04 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-28 23:10:26 Adjacency timeout 5.99 (Slot 30)
2014-06-28 23:10:26 Adjacency down 5.99 (Slot 30)
2014-06-28 23:18:28 Adjacency down 8.400 (Slot 23)
2014-06-28 23:18:28 Adjacency down 47.556 (Slot 25)
2014-06-28 23:18:34 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-28 23:18:35 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-28 23:25:50 Adjacency timeout 47.556 (Slot 25)
2014-06-28 23:25:50 Adjacency down 47.556 (Slot 25)
2014-06-28 23:25:54 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-29 00:06:52 Adjacency timeout 8.400 (Slot 23)
2014-06-29 00:06:52 Adjacency down 8.400 (Slot 23)
2014-06-29 00:06:58 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-29 00:10:47 Adjacency timeout 47.556 (Slot 25)
2014-06-29 00:10:47 Adjacency down 47.556 (Slot 25)
2014-06-29 00:10:47 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-29 00:28:21 Adjacency timeout 8.400 (Slot 23)
2014-06-29 00:28:21 Adjacency down 8.400 (Slot 23)
2014-06-29 00:28:26 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-29 00:30:54 Adjacency down 8.400 (Slot 23)
2014-06-29 00:31:18 Adjacency timeout 47.556 (Slot 25)
2014-06-29 00:31:18 Adjacency down 47.556 (Slot 25)
2014-06-29 00:31:21 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-29 00:31:21 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-29 00:45:41 Adjacency timeout 8.400 (Slot 23)
2014-06-29 00:45:41 Adjacency down 8.400 (Slot 23)
2014-06-29 00:46:04 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-29 00:53:57 Adjacency down 11.2 (Slot 21)
2014-06-29 00:54:05 Adjacency up 11.2 (Slot 21) on psilo.update.uu.se
2014-06-29 04:45:36 Adjacency timeout 47.556 (Slot 25)
2014-06-29 04:45:36 Adjacency down 47.556 (Slot 25)
2014-06-29 04:45:38 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-29 04:49:49 Adjacency timeout 47.556 (Slot 25)
2014-06-29 04:49:49 Adjacency down 47.556 (Slot 25)
2014-06-29 04:53:19 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-29 06:46:04 Adjacency up 62.637 (Slot 29) on psilo.update.uu.se
2014-06-29 08:01:32 Adjacency timeout 47.556 (Slot 25)
2014-06-29 08:01:32 Adjacency down 47.556 (Slot 25)
2014-06-29 08:01:33 Adjacency timeout 8.400 (Slot 23)
2014-06-29 08:01:33 Adjacency down 8.400 (Slot 23)
2014-06-29 08:03:04 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-29 08:03:51 Adjacency timeout 8.400 (Slot 23)
2014-06-29 08:03:51 Adjacency down 8.400 (Slot 23)
2014-06-29 08:04:39 Adjacency timeout 47.556 (Slot 23)
2014-06-29 08:04:49 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
2014-06-29 08:04:50 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-29 08:05:52 Adjacency timeout 47.556 (Slot 25)
2014-06-29 08:05:52 Adjacency down 47.556 (Slot 25)
2014-06-29 08:08:06 Adjacency up 47.556 (Slot 25) on psilo.update.uu.se
2014-06-29 08:10:02 Adjacency timeout 8.400 (Slot 23)
2014-06-29 08:10:02 Adjacency down 8.400 (Slot 23)
2014-06-29 08:10:18 Adjacency up 8.400 (Slot 23) on psilo.update.uu.se
