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
Circuit SVA-0, Load, Successful, Node = 9.15 (MADDY)
File = EWS$LIBRARY:EWS$GAB_075.SYS, Operating system
Ethernet address = 08-00-2B-09-12-F1
MOIRA::CSMELOSKY$
%%%%%%%%%%% OPCOM 10-JUN-2014 20:07:25.38 %%%%%%%%%%%
Message from user AUDIT$SERVER on MOIRA
Security alarm (SECURITY) and security audit (SECURITY) on MOIRA, system id: 9217
Auditable event: Detached process login failure
Event time: 10-JUN-2014 20:07:25.27
PID: 20200123
Process name: _WSA1:
Username: SYSTEM
Process owner: [SYSTEM]
Image name: MOIRA$DKA0:[SYS0.SYSCOMMON.][SYSEXE]LOGINOUT.EXE
Status: %DECW-F-NOMSG, Message number 02DB8204
DECWindows is started...VAXELN loaded...but it still can't open graphics device? WINDOW_SYSTEM is set to 1 in MODPARAMS.DAT
200122 SERVER_00CE LEF 6 186 0 00:00:01.39 1709 312 N
[EWS$SERVER] 156Kb
I can't imagine I need to put the graphics card back in the boot node? That just wouldn't make sense!
--
Cory Smelosky
http://gewt.net Personal stuff
http://gimme-sympathy.org Projects
Mode and or duplex incompatibilities.
This can't be the problem in this case. I'm running both nodes inside
the same VM (VirtualBox), so they share the same NIC.
I have replaced the file copy by a screen copy:
NFT TI:=SNAKE::LB:[1,2]EXECUTIVE.HLP
(EXECUTIVE.HLP is 259. blocks)
and I can see random freezes.
A successful, uninterrupted transfer takes 7 seconds.
It hangs almost every time I write to disk:
NFT FOO=SNAKE::LB:[1,2]EXECUTIVE.HLP
I suppose virtualization needs some extra caution. I have to browse
simh at trailing-edge archive for what have been said about VirtualBox.
--
Johnny Billquist || "I'm on a bus
|| on a psychedelic trip
email: bqt at softjar.se || Reading murder books
pdp is alive! || tryin' to stay hip" - B. Idol
Mode and or duplex incompatibilities.
This can't be the problem in this case. I'm running both nodes inside
the same VM (VirtualBox), so they share the same NIC.
I have replaced the file copy by a screen copy:
NFT TI:=SNAKE::LB:[1,2]EXECUTIVE.HLP
(EXECUTIVE.HLP is 259. blocks)
and I can see random freezes.
A successful, uninterrupted transfer takes 7 seconds.
It hangs almost every time I write to disk:
NFT FOO=SNAKE::LB:[1,2]EXECUTIVE.HLP
I suppose virtualization needs some extra caution. I have to browse
simh at trailing-edge archive for what have been said about VirtualBox.
--
Johnny Billquist || "I'm on a bus
|| on a psychedelic trip
email: bqt at softjar.se || Reading murder books
pdp is alive! || tryin' to stay hip" - B. Idol
Everything else seems ok.
Could be many different reasons. All from general network load affecting things to thing like duplex, which Brian suggested.
Really hard to give a good explanation on why without having good access to all parts of the setup to be able to test and examine things.
Johnny
--
Johnny Billquist || "I'm on a bus
|| on a psychedelic trip
email: bqt at softjar.se || Reading murder books
pdp is alive! || tryin' to stay hip" - B. Idol
