On Thu, Jul 08, 2004 at 02:33:49AM +0700, Ian Zagorskih wrote:
> On Thursday 08 July 2004 02:09, Manuel Bouyer wrote:
> > On Wed, Jul 07, 2004 at 10:55:44PM +0700, Ian Zagorskih wrote:
> > > [...]
> >
> > And tcpdump on a shows that A aserws properly. A tcpdump on B at the same
> > time could be usefull, but see below.
> 
> Ok, let's ping it again: B->A
> 
> A: tcpdump icmp
> B: tcpdump -c30 icmp 2>&1 >dump &
>      ping -c15 -n 192.168.100.37 | tee ping
> 
> ---cut dump A---
> # tcpdump icmp
> tcpdump: listening on rtk0
> 02:26:02.623284 192.168.100.250 > 192.168.100.37: icmp: echo request seq 0
> 02:26:02.623313 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 0
> 02:26:04.525965 192.168.100.250 > 192.168.100.37: icmp: echo request seq 1
> 02:26:04.525993 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 1
> 02:26:05.856013 192.168.100.250 > 192.168.100.37: icmp: echo request seq 2
> 02:26:05.856041 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 2
> 02:26:05.857972 192.168.100.250 > 192.168.100.37: icmp: echo request seq 3
> 02:26:05.857981 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 3
> 02:26:05.946089 192.168.100.250 > 192.168.100.37: icmp: echo request seq 4
> 02:26:05.946117 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 4
> 02:26:05.946439 192.168.100.250 > 192.168.100.37: icmp: echo request seq 5
> 02:26:05.946447 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 5
> 02:26:05.950215 192.168.100.250 > 192.168.100.37: icmp: echo request seq 6
> 02:26:05.950224 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 6
> 02:26:06.326101 192.168.100.250 > 192.168.100.37: icmp: echo request seq 7
> 02:26:06.326131 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 7
> 02:26:06.326471 192.168.100.250 > 192.168.100.37: icmp: echo request seq 8
> 02:26:06.326480 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 8
> 02:26:06.330091 192.168.100.250 > 192.168.100.37: icmp: echo request seq 9
> 02:26:06.330100 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 9
> 02:26:06.696128 192.168.100.250 > 192.168.100.37: icmp: echo request seq 10
> 02:26:06.696157 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 10
> 02:26:06.698555 192.168.100.250 > 192.168.100.37: icmp: echo request seq 11
> 02:26:06.698564 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 11
> 02:26:06.701943 192.168.100.250 > 192.168.100.37: icmp: echo request seq 12
> 02:26:06.701971 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 12
> 02:26:06.705136 192.168.100.250 > 192.168.100.37: icmp: echo request seq 13
> 02:26:06.705158 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 13
> 02:26:06.756116 192.168.100.250 > 192.168.100.37: icmp: echo request seq 14
> 02:26:06.756144 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 14
> ^C
> 506 packets received by filter
> 0 packets dropped by kernel
> ---cut dump A---
> 
> ---dump B---
> 02:25:56.142363 192.168.100.250 > 192.168.100.37: icmp: echo request seq 0
> 02:25:56.143042 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 0
> 02:25:57.151991 192.168.100.250 > 192.168.100.37: icmp: echo request seq 1
> 02:25:57.158842 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 1
> 02:25:59.067633 192.168.100.250 > 192.168.100.37: icmp: echo request seq 2
> 02:25:59.108094 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 2
> 02:25:59.578852 192.168.100.250 > 192.168.100.37: icmp: echo request seq 3
> 02:25:59.611499 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 3
> 02:26:21.206721 192.168.100.250 > 192.168.100.37: icmp: echo request seq 4
> 02:26:21.247170 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 4
> 02:26:21.298334 192.168.100.250 > 192.168.100.37: icmp: echo request seq 5
> 02:26:21.330824 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 5
> 02:26:22.285743 192.168.100.250 > 192.168.100.37: icmp: echo request seq 6
> 02:26:22.317556 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 6
> 02:27:07.251609 192.168.100.250 > 192.168.100.37: icmp: echo request seq 7
> 02:27:07.292308 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 7
> 02:27:07.350448 192.168.100.250 > 192.168.100.37: icmp: echo request seq 8
> 02:27:07.381427 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 8
> 02:27:08.295757 192.168.100.250 > 192.168.100.37: icmp: echo request seq 9
> 02:27:08.327413 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 9
> 02:27:51.988934 192.168.100.250 > 192.168.100.37: icmp: echo request seq 10
> 02:27:52.028174 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 10
> 02:27:52.624867 192.168.100.250 > 192.168.100.37: icmp: echo request seq 11
> 02:27:52.656308 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 11
> 02:27:53.419694 192.168.100.250 > 192.168.100.37: icmp: echo request seq 12
> 02:27:53.556430 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 12
> 02:27:54.342352 192.168.100.250 > 192.168.100.37: icmp: echo request seq 13
> 02:27:54.388528 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 13
> 02:28:07.094151 192.168.100.250 > 192.168.100.37: icmp: echo request seq 14
> 02:28:07.152392 192.168.100.37 > 192.168.100.250: icmp: echo reply seq 14
> ---dump B---
> 
> ---ping B---
> PING 192.168.100.37 (192.168.100.37): 56 data bytes
> 64 bytes from 192.168.100.37: icmp_seq=0 ttl=255 time=2.804 ms
> 64 bytes from 192.168.100.37: icmp_seq=1 ttl=255 time=23.717 ms
> 64 bytes from 192.168.100.37: icmp_seq=2 ttl=255 time=140.364 ms
> 64 bytes from 192.168.100.37: icmp_seq=3 ttl=255 time=114.035 ms
> 64 bytes from 192.168.100.37: icmp_seq=4 ttl=255 time=232.239 ms
> 64 bytes from 192.168.100.37: icmp_seq=5 ttl=255 time=569.915 ms
> 64 bytes from 192.168.100.37: icmp_seq=6 ttl=255 time=134.675 ms
> 64 bytes from 192.168.100.37: icmp_seq=7 ttl=255 time=225.968 ms
> 64 bytes from 192.168.100.37: icmp_seq=8 ttl=255 time=506.654 ms
> 64 bytes from 192.168.100.37: icmp_seq=9 ttl=255 time=130.346 ms
> 64 bytes from 192.168.100.37: icmp_seq=10 ttl=255 time=144.205 ms
> 64 bytes from 192.168.100.37: icmp_seq=11 ttl=255 time=214.833 ms
> 64 bytes from 192.168.100.37: icmp_seq=12 ttl=255 time=254.370 ms
> 64 bytes from 192.168.100.37: icmp_seq=13 ttl=255 time=261.995 ms
> 64 bytes from 192.168.100.37: icmp_seq=14 ttl=255 time=172.053 ms
> 
> ----192.168.100.37 PING Statistics----
> 15 packets transmitted, 15 packets received, 0.0% packet loss
> round-trip min/avg/max/stddev = 2.804/208.545/569.915/154.095 ms
> ---ping B---
> 
> So looks like nothing is changed :)

Ok, it seems the problem is definitively on host B. 
Now, I don't know enouth of the details of BPF to know if it's definitively
a problem at the adapter/adapter driver level, or if it could be an issue
with delayed soft interrupts, or return to userland.

Anyway I would guess it has something to do with the hardware, maybe something
looping at some spl() level, or in an interrupt routine.

-- 
Manuel Bouyer <bouyer@antioche.eu.org>
     NetBSD: 26 ans d'experience feront toujours la difference
--