Eliza Weisman b9e3d2edde
task: add Tracing instrumentation to spawned tasks (#2655)
## Motivation

When debugging asynchronous systems, it can be very valuable to inspect
what tasks are currently active (see #2510). The [`tracing` crate] and
related libraries provide an interface for Rust libraries and
applications to emit and consume structured, contextual, and async-aware
diagnostic information. Because this diagnostic information is
structured and machine-readable, it is a better fit for the
task-tracking use case than textual logging — `tracing` spans can be
consumed to generate metrics ranging from a simple counter of active
tasks to histograms of poll durations, idle durations, and total task
lifetimes. This information is potentially valuable to both Tokio users
*and* to maintainers.

Additionally, `tracing` is maintained by the Tokio project and is
becoming widely adopted by other libraries in the "Tokio stack", such as
[`hyper`], [`h2`], and [`tonic`] and in [other] [parts] of the broader Rust
ecosystem. Therefore, it is suitable for use in Tokio itself.

[`tracing` crate]: https://github.com/tokio-rs/tracing
[`hyper`]: https://github.com/hyperium/hyper/pull/2204
[`h2`]: https://github.com/hyperium/h2/pull/475
[`tonic`]: 570c606397/tonic/Cargo.toml (L48)
[other]: https://github.com/rust-lang/chalk/pull/525
[parts]: https://github.com/rust-lang/compiler-team/issues/331

## Solution

This PR is an MVP for instrumenting Tokio with `tracing` spans. When the
"tracing" optional dependency is enabled, every spawned future will be
instrumented with a `tracing` span.

The generated spans are at the `TRACE` verbosity level, and have the
target "tokio::task", which may be used by consumers to filter whether
they should be recorded. They include fields for the type name of the
spawned future and for what kind of task the span corresponds to (a
standard `spawn`ed task, a local task spawned by `spawn_local`, or a
`blocking` task spawned by `spawn_blocking`). Because `tracing` has
separate concepts of "opening/closing" and "entering/exiting" a span, we
enter these spans every time the spawned task is polled. This allows
collecting data such as:

 - the total lifetime of the task from `spawn` to `drop`
 - the number of times the task was polled before it completed
 - the duration of each individual time that the span was polled (and
   therefore, aggregated metrics like histograms or averages of poll
   durations)
 - the total time a span was actively being polled, and the total time
   it was alive but **not** being polled
 - the time between when the task was `spawn`ed and the first poll

As an example, here is the output of a version of the `chat` example
instrumented with `tracing`:
![image](https://user-images.githubusercontent.com/2796466/87231927-e50f6900-c36f-11ea-8a90-6da9b93b9601.png)
And, with multiple connections actually sending messages:
![trace_example_1](https://user-images.githubusercontent.com/2796466/87231876-8d70fd80-c36f-11ea-91f1-0ad1a5b3112f.png)


I haven't added any `tracing` spans in the example, only converted the
existing `println!`s to `tracing::info` and `tracing::error` for
consistency. The span durations in the above output are generated by
`tracing-subscriber`. Of course, a Tokio-specific subscriber could
generate even more detailed statistics, but that's follow-up work once
basic tracing support has been added.

Note that the `Instrumented` type from `tracing-futures`, which attaches
a `tracing` span to a future, was reimplemented inside of Tokio to avoid
a dependency on that crate. `tracing-futures` has a feature flag that
enables an optional dependency on Tokio, and I believe that if another
crate in a dependency graph enables that feature while Tokio's `tracing`
support is also enabled, it would create a circular dependency that
Cargo wouldn't be able to handle. Also, it avoids a dependency for a
very small amount of code that is unlikely to ever change.

There is, of course, room for plenty of future work here. This might 
include:

 - instrumenting other parts of `tokio`, such as I/O resources and 
   channels (possibly via waker instrumentation)
 - instrumenting the threadpool so that the state of worker threads
   can be inspected
 - writing `tracing-subscriber` `Layer`s to collect and display
   Tokio-specific data from these traces
 - using `track_caller` (when it's stable) to record _where_ a task 
   was `spawn`ed from

However, this is intended as an MVP to get us started on that path.

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
2020-07-13 16:46:59 -07:00
2019-01-06 23:25:55 -08:00
2020-04-03 09:00:18 -04:00

Tokio

A runtime for writing reliable, asynchronous, and slim applications with the Rust programming language. It is:

  • Fast: Tokio's zero-cost abstractions give you bare-metal performance.

  • Reliable: Tokio leverages Rust's ownership, type system, and concurrency model to reduce bugs and ensure thread safety.

  • Scalable: Tokio has a minimal footprint, and handles backpressure and cancellation naturally.

Crates.io MIT licensed Build Status Discord chat

Website | Guides | API Docs | Roadmap | Chat

Overview

Tokio is an event-driven, non-blocking I/O platform for writing asynchronous applications with the Rust programming language. At a high level, it provides a few major components:

  • A multithreaded, work-stealing based task scheduler.
  • A reactor backed by the operating system's event queue (epoll, kqueue, IOCP, etc...).
  • Asynchronous TCP and UDP sockets.

These components provide the runtime components necessary for building an asynchronous application.

Example

A basic TCP echo server with Tokio:

use tokio::net::TcpListener;
use tokio::prelude::*;

#[tokio::main]
async fn main() -> Result<(), Box<dyn std::error::Error>> {
    let mut listener = TcpListener::bind("127.0.0.1:8080").await?;

    loop {
        let (mut socket, _) = listener.accept().await?;

        tokio::spawn(async move {
            let mut buf = [0; 1024];

            // In a loop, read data from the socket and write the data back.
            loop {
                let n = match socket.read(&mut buf).await {
                    // socket closed
                    Ok(n) if n == 0 => return,
                    Ok(n) => n,
                    Err(e) => {
                        eprintln!("failed to read from socket; err = {:?}", e);
                        return;
                    }
                };

                // Write the data back
                if let Err(e) = socket.write_all(&buf[0..n]).await {
                    eprintln!("failed to write to socket; err = {:?}", e);
                    return;
                }
            }
        });
    }
}

More examples can be found here.

Getting Help

First, see if the answer to your question can be found in the Guides or the API documentation. If the answer is not there, there is an active community in the Tokio Discord server. We would be happy to try to answer your question. Last, if that doesn't work, try opening an issue with the question.

Contributing

🎈 Thanks for your help improving the project! We are so happy to have you! We have a contributing guide to help you get involved in the Tokio project.

In addition to the crates in this repository, the Tokio project also maintains several other libraries, including:

  • hyper: A fast and correct HTTP/1.1 and HTTP/2 implementation for Rust.

  • tonic: A gRPC over HTTP/2 implementation focused on high performance, interoperability, and flexibility.

  • warp: A super-easy, composable, web server framework for warp speeds.

  • tower: A library of modular and reusable components for building robust networking clients and servers.

  • tracing (formerly tokio-trace): A framework for application-level tracing and async-aware diagnostics.

  • rdbc: A Rust database connectivity library for MySQL, Postgres and SQLite.

  • mio: A low-level, cross-platform abstraction over OS I/O APIs that powers tokio.

  • bytes: Utilities for working with bytes, including efficient byte buffers.

  • loom: A testing tool for concurrent Rust code

Supported Rust Versions

Tokio is built against the latest stable, nightly, and beta Rust releases. The minimum version supported is the stable release from three months before the current stable release version. For example, if the latest stable Rust is 1.29, the minimum version supported is 1.26. The current Tokio version is not guaranteed to build on Rust versions earlier than the minimum supported version.

License

This project is licensed under the MIT license.

Contribution

Unless you explicitly state otherwise, any contribution intentionally submitted for inclusion in Tokio by you, shall be licensed as MIT, without any additional terms or conditions.

Description
A runtime for writing reliable asynchronous applications with Rust. Provides I/O, networking, scheduling, timers, ...
Readme MIT 75 MiB
Languages
Rust 100%