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 ms
    

    i.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 tcpdump into 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 ms
    

    I 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 ms
    
    

    However, 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 ms
    

    i.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/hosts file 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  ubuntu
    

    and 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 ms
    

    To be investigated further ...


Log in to reply