dev-bio / ekko Goto Github PK

use ekko::Ekko;

fn main() {
    let mut e = Ekko::with_target([127, 0, 0, 1]).unwrap();
    println!("{:?}", e.send(1).unwrap());
}

Unexpected((EkkoData { timepoint: Instant { tv_sec: 101850, tv_nsec: 776870355 }, elapsed: 62.953µs, address: Some(127.0.0.1), identifier: 56444, sequence: 0, hops: 1 }, (8, 0)))

Looks like it is receiving its own request packet. Perhaps those could be filtered?

Describe the bug

Hi! Firstly thanks for the crate, very useful! I am using this in https://github.com/chrisheib/STStat to do a ping every second to measure network quality. It looks like ekko blocks on sending pings, wasting a lot of cycles - is that correct? Would implementing the networking with async abstraction like tokio solve this?

Steps to reproduce the bug

1. Be on a really bad network with ping times > 500ms
2. Send a ping
3. Watch the CPU spike

Expected behavior

Ekko yields, not using a lot of ressources until the response or timeout occured.

Parse and include data sections on the following.

https://github.com/dev-bio/Ekko/blob/f2e6cb6ea901850df634fdcc73db74a35fd53d70/src/sender.rs#L159
https://github.com/dev-bio/Ekko/blob/f2e6cb6ea901850df634fdcc73db74a35fd53d70/src/sender.rs#L220

Sending the packet on linux seems to fail with the above error. Windows it works fine.

There seems to be some kind of race condition somewhere when sending a request from different tokio task: the response for one request shows the target of the request in another task, and reported durations are off (more below). Here is a minimal reproducible example:

#![feature(async_closure)]

use ekko::Ekko;
use futures::future;
use std::{time::Duration, u8};

async fn run(delay: bool) {
    if delay {
        println!("\nRunning suite with delay...");
    } else {
        println!("\nRunning suite without delay...");
    }

    let ok_cf = tokio::spawn(async move {
        let mut ping = Ekko::with_target("1.1.1.1").unwrap();

        if delay {
            tokio::time::delay_for(Duration::from_secs(2)).await;
        }

        println!("1.1.1.1: {:?}", ping.send(u8::MAX));
    });

    let ok_go = tokio::spawn(async move {
        let mut ping = Ekko::with_target("8.8.8.8").unwrap();

        println!("8.8.8.8: {:?}", ping.send(u8::MAX));
    });

    let ko = tokio::spawn(async move {
        let mut ping = Ekko::with_target("1.2.3.4").unwrap();

        if delay {
            tokio::time::delay_for(Duration::from_secs(2)).await;
        }

        println!("1.2.3.4: {:?}", ping.send(std::u8::MAX));
    });

    let _ = future::join3(ok_cf, ok_go, ko).await;
}

#[tokio::main]
async fn main() {
    run(false).await;
    run(true).await;
}

In a nutshell, this runs two series of three echo requests, each in a different tokio task, the first suite running all three ping without any added delays, and the second suite adding a 2-second delay to two of the three requests (before send()).

This is the output to the previous program:

Running suite without delay...
1.1.1.1: Ok(DestinationResponse(EkkoData { timepoint: Instant { tv_sec: 49823, tv_nsec: 704938815 }, elapsed: 5.554973ms, address: Some(1.1.1.1), hops: 255 }))
8.8.8.8: Ok(DestinationResponse(EkkoData { timepoint: Instant { tv_sec: 49823, tv_nsec: 710572997 }, elapsed: 3.094855ms, address: Some(8.8.8.8), hops: 255 }))
1.2.3.4: Ok(LackingResponse(EkkoData { timepoint: Instant { tv_sec: 49823, tv_nsec: 713698551 }, elapsed: 103.754019ms, address: None, hops: 255 }))

Running suite with delay...
8.8.8.8: Ok(DestinationResponse(EkkoData { timepoint: Instant { tv_sec: 49828, tv_nsec: 819549407 }, elapsed: 4.444311ms, address: Some(8.8.8.8), hops: 255 }))
1.1.1.1: Ok(DestinationResponse(EkkoData { timepoint: Instant { tv_sec: 49830, tv_nsec: 820347648 }, elapsed: 350.68µs, address: Some(8.8.8.8), hops: 255 }))
1.2.3.4: Ok(DestinationResponse(EkkoData { timepoint: Instant { tv_sec: 49830, tv_nsec: 825041469 }, elapsed: 975.481µs, address: Some(1.1.1.1), hops: 255 }))

As can be seen, when the task run somewhat concurrently (without artificial delays), each answer matches with the requests, whereas when waiting an arbitrary duration between Ekko::with_target and send(), responses get shifted (the first response to come in is OK, the second response is the same as the first one, and the last one is the second one).

On top of that, the reported response time for 1.1.1.1 (with delays) is ~350µs, which does not seem possible, and the reported time for 1.2.3.4 should be the default timeout of ~100ms, but is ~975µs instead.

The first part of the example shows that the same code, without the delays, works perfectly.

My actual code obviously does not use delays between the two operations, but might try and send echo requests from two different tasks without any kind of syncronization. This has the effect of some OK responses being reported as failing and vice versa, on top of the target address in the response being wrong.

tcpdump shows that all requests leave my computer and receive an expected response:

# Without delays
22:44:47.928181 wlan  Out IP [me] > one.one.one.one: ICMP echo request, id 4841, seq 0, length 64
22:44:47.932891 wlan  In  IP one.one.one.one > [me]: ICMP echo reply, id 4841, seq 0, length 64
22:44:47.933069 wlan  Out IP [me] > dns.google: ICMP echo request, id 4410, seq 0, length 64
22:44:47.936025 wlan  In  IP dns.google > [me]: ICMP echo reply, id 4410, seq 0, length 64
22:44:47.936211 wlan  Out IP [me] > 1.2.3.4: ICMP echo request, id 12491, seq 0, length 64

# With delays
22:44:53.041778 wlan  Out IP [me] > dns.google: ICMP echo request, id 55270, seq 0, length 64
22:44:53.046243 wlan  In  IP dns.google > [me]: ICMP echo reply, id 55270, seq 0, length 64
22:44:55.042463 wlan  Out IP [me] > one.one.one.one: ICMP echo request, id 47074, seq 0, length 64
22:44:55.047163 wlan  In  IP one.one.one.one > [me]: ICMP echo reply, id 47074, seq 0, length 64
22:44:55.047495 wlan  Out IP [me] > 1.2.3.4: ICMP echo request, id 21320, seq 0, length 64

If you need it, here is the Cargo.toml's dependencies:

[dependencies]
ekko = "0.2"
futures = "*"
tokio = { version = "0.2", features = ["macros", "rt-core", "time"] }

If you need any more information or testing on my part, do not hesitate to ask.

It's useful for long running pings to handle out of order packets among other things that can occur. I may try to put together a PR for this later.