ping round-trip time to BQ E4.5 depends on trafic from the device
-
When I SSH into a BQ E4.5 (running OTA-10) over Wifi often I see a certain latency when pressing keys until the echo is coming. I was digging into this and encounter the following dependency:
If I run from the SSH session in the BQ a ping to some IP in Internet and ping the BQ at the same time from another xterm in the laptop I see the following:
64 bytes from 192.168.2.117: icmp_seq=91 ttl=64 time=3.135 ms 64 bytes from 192.168.2.117: icmp_seq=92 ttl=64 time=3.150 ms 64 bytes from 192.168.2.117: icmp_seq=93 ttl=64 time=3.277 ms 64 bytes from 192.168.2.117: icmp_seq=94 ttl=64 time=3.293 ms 64 bytes from 192.168.2.117: icmp_seq=95 ttl=64 time=3.564 ms 64 bytes from 192.168.2.117: icmp_seq=96 ttl=64 time=3.511 ms 64 bytes from 192.168.2.117: icmp_seq=97 ttl=64 time=5.737 ms 64 bytes from 192.168.2.117: icmp_seq=98 ttl=64 time=33.449 ms 64 bytes from 192.168.2.117: icmp_seq=99 ttl=64 time=43.060 ms 64 bytes from 192.168.2.117: icmp_seq=100 ttl=64 time=61.158 ms 64 bytes from 192.168.2.117: icmp_seq=101 ttl=64 time=75.874 ms 64 bytes from 192.168.2.117: icmp_seq=102 ttl=64 time=85.156 ms 64 bytes from 192.168.2.117: icmp_seq=103 ttl=64 time=105.871 msi.e. the RTT is constant around 3-5ms from the laptop to the BQ. The jump to 30-100ms happens, when I cancel the ping from the BQ to Internet.
This is reproducible with:
- any other BQ device I own (I have four)
- within many Wifi reds I have access to
Any ideas what could cause this before looking with
tcpdumpinto the delays?Thanks.
-
Interesting.
I experienced the same SSH latency with my Nexus5.
But I didn't pinpoint the origin.For now (I haven't tested much) OTA11 is behaving normally. I'll update this post if I experience SSH slow downs.
-
I have right now updated the BQ to OTA-11. The picture stays the same. Here you see it the other way around, the marked point is when I started from inside the BQ ping something in Internet, the RT goes down from 75ms to 3ms:
64 bytes from 192.168.2.117: icmp_seq=7 ttl=64 time=42.784 ms 64 bytes from 192.168.2.117: icmp_seq=8 ttl=64 time=63.679 ms 64 bytes from 192.168.2.117: icmp_seq=9 ttl=64 time=75.800 ms 64 bytes from 192.168.2.117: icmp_seq=10 ttl=64 time=3.412 ms <********* 64 bytes from 192.168.2.117: icmp_seq=11 ttl=64 time=3.513 ms 64 bytes from 192.168.2.117: icmp_seq=12 ttl=64 time=3.339 ms 64 bytes from 192.168.2.117: icmp_seq=13 ttl=64 time=3.759 ms 64 bytes from 192.168.2.117: icmp_seq=14 ttl=64 time=7.803 ms 64 bytes from 192.168.2.117: icmp_seq=15 ttl=64 time=3.674 msI don't think, that it has to do with the OTA-nn of UBports, because I see the same with a device still running OTA-15 of Canonical. Perhaps it is some issue in the Android kernel below.
-
Can someone else please check this, It only takes having SSH enabled and 2 minutes. Where I should file a bug issue about this as it isn't on app level? Thx
-
Runned pinging from notebook to phone and while running, runned and trminated pinging from phone to net (ping 8.8.8.8). This was the outcome for first run.
$ ping 192.168.88.250 PING 192.168.88.250 (192.168.88.250) 56(84) bytes of data. 64 bytes from 192.168.88.250: icmp_seq=1 ttl=64 time=57.0 ms 64 bytes from 192.168.88.250: icmp_seq=2 ttl=64 time=243 ms 64 bytes from 192.168.88.250: icmp_seq=3 ttl=64 time=98.5 ms 64 bytes from 192.168.88.250: icmp_seq=4 ttl=64 time=119 ms 64 bytes from 192.168.88.250: icmp_seq=5 ttl=64 time=42.0 ms 64 bytes from 192.168.88.250: icmp_seq=6 ttl=64 time=63.1 ms 64 bytes from 192.168.88.250: icmp_seq=7 ttl=64 time=89.4 ms 64 bytes from 192.168.88.250: icmp_seq=8 ttl=64 time=14.2 ms 64 bytes from 192.168.88.250: icmp_seq=9 ttl=64 time=5.66 ms <-- turned on pinging from phone to net 64 bytes from 192.168.88.250: icmp_seq=10 ttl=64 time=5.52 ms 64 bytes from 192.168.88.250: icmp_seq=11 ttl=64 time=3.06 ms 64 bytes from 192.168.88.250: icmp_seq=12 ttl=64 time=5.70 ms 64 bytes from 192.168.88.250: icmp_seq=13 ttl=64 time=8.30 ms 64 bytes from 192.168.88.250: icmp_seq=14 ttl=64 time=9.16 ms 64 bytes from 192.168.88.250: icmp_seq=15 ttl=64 time=6.26 ms 64 bytes from 192.168.88.250: icmp_seq=16 ttl=64 time=3.13 ms 64 bytes from 192.168.88.250: icmp_seq=17 ttl=64 time=3.09 ms 64 bytes from 192.168.88.250: icmp_seq=18 ttl=64 time=6.24 ms 64 bytes from 192.168.88.250: icmp_seq=19 ttl=64 time=9.07 ms 64 bytes from 192.168.88.250: icmp_seq=20 ttl=64 time=3.10 ms 64 bytes from 192.168.88.250: icmp_seq=21 ttl=64 time=3.06 ms 64 bytes from 192.168.88.250: icmp_seq=22 ttl=64 time=23.3 ms <-- turned off pinging from phone to net 64 bytes from 192.168.88.250: icmp_seq=23 ttl=64 time=69.1 ms 64 bytes from 192.168.88.250: icmp_seq=24 ttl=64 time=60.9 ms 64 bytes from 192.168.88.250: icmp_seq=25 ttl=64 time=91.4 ms 64 bytes from 192.168.88.250: icmp_seq=26 ttl=64 time=109 ms 64 bytes from 192.168.88.250: icmp_seq=27 ttl=64 time=26.5 ms 64 bytes from 192.168.88.250: icmp_seq=28 ttl=64 time=50.7 ms 64 bytes from 192.168.88.250: icmp_seq=29 ttl=64 time=107 ms ^C --- 192.168.88.250 ping statistics --- 29 packets transmitted, 29 received, 0% packet loss, time 28038ms rtt min/avg/max/mdev = 3.065/46.122/243.244/53.585 msHowever, that happened only one time (the first time). Other runs were not that convincing.
ping 192.168.88.250 130 ↵ PING 192.168.88.250 (192.168.88.250) 56(84) bytes of data. 64 bytes from 192.168.88.250: icmp_seq=1 ttl=64 time=101 ms 64 bytes from 192.168.88.250: icmp_seq=2 ttl=64 time=114 ms 64 bytes from 192.168.88.250: icmp_seq=3 ttl=64 time=377 ms 64 bytes from 192.168.88.250: icmp_seq=4 ttl=64 time=38.5 ms 64 bytes from 192.168.88.250: icmp_seq=5 ttl=64 time=165 ms 64 bytes from 192.168.88.250: icmp_seq=6 ttl=64 time=80.5 ms 64 bytes from 192.168.88.250: icmp_seq=7 ttl=64 time=146 ms 64 bytes from 192.168.88.250: icmp_seq=8 ttl=64 time=36.0 ms 64 bytes from 192.168.88.250: icmp_seq=9 ttl=64 time=6.09 ms 64 bytes from 192.168.88.250: icmp_seq=10 ttl=64 time=94.2 ms <-- turned on pinging from phone to net 64 bytes from 192.168.88.250: icmp_seq=11 ttl=64 time=97.7 ms 64 bytes from 192.168.88.250: icmp_seq=12 ttl=64 time=3675 ms 64 bytes from 192.168.88.250: icmp_seq=13 ttl=64 time=2670 ms 64 bytes from 192.168.88.250: icmp_seq=14 ttl=64 time=1670 ms 64 bytes from 192.168.88.250: icmp_seq=15 ttl=64 time=670 ms 64 bytes from 192.168.88.250: icmp_seq=16 ttl=64 time=58.6 ms 64 bytes from 192.168.88.250: icmp_seq=17 ttl=64 time=51.5 ms 64 bytes from 192.168.88.250: icmp_seq=18 ttl=64 time=54.6 ms 64 bytes from 192.168.88.250: icmp_seq=19 ttl=64 time=80.5 ms <-- turned off pinging from phone to net 64 bytes from 192.168.88.250: icmp_seq=20 ttl=64 time=148 ms 64 bytes from 192.168.88.250: icmp_seq=21 ttl=64 time=130 ms 64 bytes from 192.168.88.250: icmp_seq=22 ttl=64 time=51.5 ms 64 bytes from 192.168.88.250: icmp_seq=23 ttl=64 time=92.0 ms 64 bytes from 192.168.88.250: icmp_seq=24 ttl=64 time=87.0 ms 64 bytes from 192.168.88.250: icmp_seq=25 ttl=64 time=115 ms 64 bytes from 192.168.88.250: icmp_seq=26 ttl=64 time=49.3 ms 64 bytes from 192.168.88.250: icmp_seq=27 ttl=64 time=64.7 ms 64 bytes from 192.168.88.250: icmp_seq=28 ttl=64 time=114 ms 64 bytes from 192.168.88.250: icmp_seq=29 ttl=64 time=138 ms 64 bytes from 192.168.88.250: icmp_seq=30 ttl=64 time=125 ms 64 bytes from 192.168.88.250: icmp_seq=31 ttl=64 time=179 ms ^C --- 192.168.88.250 ping statistics --- 31 packets transmitted, 31 received, 0% packet loss, time 30030ms rtt min/avg/max/mdev = 6.094/370.601/3675.571/804.042 ms, pipe 4 -
jEzEk, thanks for undertaking the tests. They show two things:
- the RT values are as high as mine, up 100++ ms
- in one test (the first) they went down to a normal value of 2-3ms
I think the problem in general is reverse DNS or ARP related. When I ping from my laptop my AP 192.168.178.1 I see constant values of 2-3 ms. When I ping some other laptop (an Ubuntu 18.04) I see this:
guru@c720-r342378 ~]$ ping 192.168.178.36 PING 192.168.178.36 (192.168.178.36): 56 data bytes 64 bytes from 192.168.178.36: icmp_seq=0 ttl=64 time=2.897 ms 64 bytes from 192.168.178.36: icmp_seq=1 ttl=64 time=2.993 ms 64 bytes from 192.168.178.36: icmp_seq=2 ttl=64 time=3.610 ms 64 bytes from 192.168.178.36: icmp_seq=3 ttl=64 time=2.852 ms 64 bytes from 192.168.178.36: icmp_seq=4 ttl=64 time=3.022 ms 64 bytes from 192.168.178.36: icmp_seq=5 ttl=64 time=3.024 ms 64 bytes from 192.168.178.36: icmp_seq=6 ttl=64 time=5.926 ms 64 bytes from 192.168.178.36: icmp_seq=7 ttl=64 time=3.230 ms 64 bytes from 192.168.178.36: icmp_seq=8 ttl=64 time=3.015 ms 64 bytes from 192.168.178.36: icmp_seq=9 ttl=64 time=343.706 ms 64 bytes from 192.168.178.36: icmp_seq=10 ttl=64 time=2.999 ms 64 bytes from 192.168.178.36: icmp_seq=11 ttl=64 time=3.006 ms 64 bytes from 192.168.178.36: icmp_seq=12 ttl=64 time=2.923 ms 64 bytes from 192.168.178.36: icmp_seq=13 ttl=64 time=5.357 ms 64 bytes from 192.168.178.36: icmp_seq=14 ttl=64 time=12.376 ms 64 bytes from 192.168.178.36: icmp_seq=15 ttl=64 time=2.988 ms 64 bytes from 192.168.178.36: icmp_seq=16 ttl=64 time=3.066 ms 64 bytes from 192.168.178.36: icmp_seq=17 ttl=64 time=3.007 ms 64 bytes from 192.168.178.36: icmp_seq=18 ttl=64 time=2.986 ms 64 bytes from 192.168.178.36: icmp_seq=19 ttl=64 time=317.896 ms 64 bytes from 192.168.178.36: icmp_seq=20 ttl=64 time=634.518 msi.e. only a few peeks up to 600 ms.
Now I went to the other laptop in question and inserted a line for my source IP 192.168.178.22 and for the laptop itself 192.168.178.36 in the
/etc/hostsfile as:guru@m4400:~$ cat /etc/hosts 127.0.0.1 localhost 127.0.1.1 m4400 192.168.178.1 fritz 192.168.178.22 ubguru 192.168.178.36 ubuntuand magically, the RT goes down to normal:
[guru@c720-r342378 ~]$ ping 192.168.178.36 PING 192.168.178.36 (192.168.178.36): 56 data bytes 64 bytes from 192.168.178.36: icmp_seq=0 ttl=64 time=3.010 ms 64 bytes from 192.168.178.36: icmp_seq=1 ttl=64 time=2.900 ms 64 bytes from 192.168.178.36: icmp_seq=2 ttl=64 time=3.124 ms 64 bytes from 192.168.178.36: icmp_seq=3 ttl=64 time=3.141 ms 64 bytes from 192.168.178.36: icmp_seq=4 ttl=64 time=3.422 ms 64 bytes from 192.168.178.36: icmp_seq=5 ttl=64 time=3.081 ms 64 bytes from 192.168.178.36: icmp_seq=6 ttl=64 time=2.919 ms 64 bytes from 192.168.178.36: icmp_seq=7 ttl=64 time=2.897 ms 64 bytes from 192.168.178.36: icmp_seq=8 ttl=64 time=3.005 ms 64 bytes from 192.168.178.36: icmp_seq=9 ttl=64 time=3.016 ms 64 bytes from 192.168.178.36: icmp_seq=10 ttl=64 time=2.888 ms 64 bytes from 192.168.178.36: icmp_seq=11 ttl=64 time=3.011 ms 64 bytes from 192.168.178.36: icmp_seq=12 ttl=64 time=2.923 ms 64 bytes from 192.168.178.36: icmp_seq=13 ttl=64 time=2.867 msTo be investigated further ...
