Async client stuck in some kind of infinite loop

[arcrose]

I'm working on a project using reqwest's async client to make a couple pretty simple GET requests.

What I'm experiencing when I run my project's tests is that my test appears to kick off okay, and I get to the point where I want to make my first request, but my program halts at the point I linked to above. I'm seeing the following output, tracing through the steps my state machine is going through:

In poll
In fs_to_rs
In vulnerability_summaries about to make request
Requesting URL http://clair:6060/v1/namespaces/debian:8/vulnerabilities?limit=100

At this point, my program halts.

If I sh into the Docker container running Clair and request the same URL above (with clair replaced with localhost), I get a response back with the expected data immediately.

Without diving into reqwest's code at all, I wonder if there is something about the URL I'm requesting that is causing reqwest to choke.

If you'd like to get to the same point I'm at by running my project's tests, here are some simple instructions.

1. Run clair by itself for about 10 or 20 minutes to let it populate its database from sources across the Internet.

docker-compose up -d clair

2. Make sure Clair has some data. You should see some JSON data after the following.

docker exec -it clair_clair sh
wget http://127.0.0.1:6060/v1/namespaces
cat namespaces
rm namespaces
exit

3. Stop Clair

docker-compose down

4. Run my project's tests

make test

You should see everything build and start running. Eventually you'll see the output I'm getting stuck on.

Any help would be appreciated.

[seanmonstar]

Would it be possible to enable logs, including those from hyper? If using something like env-logger, it'd be RUST_LOG=hyper.

[arcrose]

I tried to import the log and env_logger crates, set them both up with env_logger::init() and set ENV RUST_LOG hyper in my Dockerfile, but I don't seem to get any logs from my program or Hyper. The compiler spits out some extra logs though. Same thing when running my tests outside the context of Docker.

[seanmonstar]

Is the environment variable set while the program is run, or only while built? The env_logger crate checks for the variable at runtime.

[arcrose]

I've done some more work to try to isolate the source of the issue. It seems that the future created by the async client is being shutdown or failing to spawn in some way.

extern crate futures;
extern crate reqwest;
#[macro_use] extern crate log;
extern crate env_logger;
extern crate tokio_executor;

use std::error::Error;

use futures::Future;

fn main() {
  env_logger::init();

  let client = reqwest::async::Client::new();

  info!("About to create request future");

  let future = client
    .get("http://127.0.0.1:6060/v1/namespaces/debian:8/vulnerabilities?limit=1")
    .send()
    .map(|res| println!("Got response: {:?}", res))
    .map_err(|err| println!("Got error: {}", err.description()));

  info!("Created future");

  tokio_executor::spawn(future);
}

Running this with RUST_LOG=hyper cargo run, the only output I see is

thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: SpawnError { is_shutdown: true }', libcore/result.rs:1009:5

With RUST_LOG=debug, I see my two info! logs.

Using the standard future's executor, as such:

  let mut handle = futures::executor::spawn(future);
  match handle.wait_future() {
    Ok(_)  => println!("Done"),
    Err(_) => println!("Got error"),
  }

with RUST_LOG=hyper I get

TRACE 2018-11-01T22:09:08Z: hyper::client::pool: checkout waiting for idle connection: ("http://127.0.0.1:6060", Http1)
TRACE 2018-11-01T22:09:08Z: hyper::client::connect::http: Http::connect; scheme=http, host=127.0.0.1, port=Some(6060)
DEBUG 2018-11-01T22:09:08Z: hyper::client::connect::http: connecting to 127.0.0.1:6060
 WARN 2018-11-01T22:09:08Z: hyper::common::exec: executor error: SpawnError { is_shutdown: true }
 WARN 2018-11-01T22:09:08Z: hyper::client: error spawning critical client task: executor failed to spawn task
Got error: executor failed to spawn task
Got error

As before, with Clair loaded up with data, I can do

curl http://127.0.0.1:6060/v1/namespaces/debian:8/vulnerabilities?limit=1
{"Vulnerabilities":[{"Name":"CVE-2014-7300","NamespaceName":"debian:8","Description":"GNOME Shell 3.14.x before 3.14.1, when the Screen Lock feature is used, does not limit the aggregate memory consumption of all active PrtSc requests, which allows physically proximate attackers to execute arbitrary commands on an unattended workstation by making many PrtSc requests and leveraging a temporary lock outage, and the resulting temporary shell availability, caused by the Linux kernel OOM killer.","Link":"https://security-tracker.debian.org/tracker/CVE-2014-7300","Severity":"Low","Metadata":{"NVD":{"CVSSv2":{"Score":7.2,"Vectors":"AV:L/AC:L/Au:N/C:C/I:C"}}}}],"NextPage":"gAAAAABb23nMOwsjMF96bc6vlu_RBxVNdJzgrJQ1E3I2xS1RkFlCH_8gtLkqpa3-BvdwryzseCHn-EIQQG_LJ_0xJ0vHPyRJ2Q=="}

[seanmonstar]

Ohhh! The future can't be spawned into a generic executor, it must be run by a tokio runtime. Either tokio::run, or customizing a tokio::runtime::Runtime or tokio::runtime::current_thread::Runtime.