admin: add an endpoint to dump spawned Tokio tasks (#595)

## Motivation

When debugging proxy issues, it can be useful to inspect the list of
currently spawned Tokio tasks and their states. This can be used
similarly to the thread or coroutine dumps provided by other languages'
runtimes.

## Solution

This branch adds a new endpoint to the proxy's admin server, `/tasks`,
that returns a dump of all tasks currently spawned on the Tokio runtime,
using the new Tracing instrumentation added in tokio-rs/tokio#2655, and
a work-in-progress [`tokio-trace`] crate that provides Tokio-specific
Tracing layers. 

Currently, the `/tasks` admin endpoint records the following information
about each task:

* Whether it is a normal, local, or blocking task (not relevant to us 
  currently, since Linkerd does not use local or blocking tasks...but
  we might eventually!)
* Whether the task is active (currently being polled) or idle (waiting
  to be polled)
* The type of the future that was spawned
* The Tracing span context from which the task was spawned
* The total number of times the task has been polled
* Timing statistics about the task, including:
  - The time in nanoseconds between when the task was spawned and when
    it was first polled (essentially, measuring the Tokio scheduler's
    latency)
  - The total time in nanoseconds the task has existed
  - The task's _busy time_ in nanoseconds (time it was actively being
    polled)
  - The tasks _idle time_ in nanoseconds (time it was _not_ being 
    polled)

In the future, Tokio will likely expose additional Tracing information,
which we'll be able to collect as well.

The task dump can be accessed either as an HTML table or as JSON. JSON
is returned if the request has an `Accept: application/json` header, or
whenever the path `/tasks.json` is requested; otherwise, the data is
rendered as an HTML table. Like the `/proxy-log-level` endpoint, access
is denied to requests coming from sources other than localhost, to help
restrict access to authorized users (since a high volume of requests for
task dumps could be used to starve the proxy).

Example JSON output (in Firefox Dev Edition's extremely nice GUI 
JSON viewer):

![Screenshot_20200715_121938](https://user-images.githubusercontent.com/2796466/87598059-b9f68380-c6a7-11ea-8f21-842b57793baa.png)

Zoomed in on the timing data for a single task:
![Screenshot_20200715_122047](https://user-images.githubusercontent.com/2796466/87598089-c4b11880-c6a7-11ea-93ac-895f7ecee0f0.png)

And HTML:

![Screenshot_20200715_143155](https://user-images.githubusercontent.com/2796466/87598414-fe821f00-c6a7-11ea-93b8-d18e4837346c.png)


Because the task data is generated from Tracing spans emitted by Tokio,
the task spans must be enabled for it to be used. This can be done by
setting a trace filter that enables the `trace` level for the target
`tokio::task`, e.g.:
```
tokio::task=trace
```
or 
```
tokio=trace
```

## Notes

* This branch depends on unreleased code from upstream, including a
  Tokio change that has merged to master but not been published, and my
  unreleased work-in-progress [`tokio-trace`] crate. Therefore, I've
  pinned these upstreams to fixed Git SHAs, to guard against
  dependencies changing under us unexpectedly.
* I considered requiring a build-time feature flag to enable this
  feature, the way we do for the mock SO_ORIG_DST implementation for
  testing. However, this would make it harder to use task tracking to
  debug issues in proxies not built with the flag. I'm happy to change
  this code to be feature flagged if we think that's the right approach.

[`tokio-trace`]: https://github.com/hawkw/tokio-trace

Closes linkerd/linkerd2#3803

Signed-off-by: Eliza Weisman <[email protected]>

Author: hawkw

Cargo.lock

@@ -26,9 +26,9 @@ dependencies = [
 
 [[package]]
 name = "aho-corasick"
-version = "0.6.4"
+version = "0.7.13"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "d6531d44de723825aa81398a6415283229725a00fa30713812ab9323faa82fc4"
+checksum = "043164d8ba5c4c3035fec9bbee8647c0261d788f3474306f93bb65901cae0e86"
 dependencies = [
  "memchr 2.3.3",
 ]
@@ -541,6 +541,15 @@ dependencies = [
  "winapi 0.3.8",
 ]
 
+[[package]]
+name = "html-escape"
+version = "0.2.5"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "7c185ca7c57375b4d21eb5a1343a152099b9ea3e7e776971fce80f8d907a7ffb"
+dependencies = [
+ "utf8-width",
+]
+
 [[package]]
 name = "http"
 version = "0.1.21"
@@ -752,6 +761,7 @@ dependencies = [
  "bytes 0.5.4",
  "futures 0.3.5",
  "h2 0.2.6",
+ "html-escape",
  "http 0.2.1",
  "http-body",
  "hyper",
@@ -767,7 +777,7 @@ dependencies = [
  "linkerd2-proxy-api",
  "net2",
  "quickcheck",
- "regex 1.0.0",
+ "regex 1.2.1",
  "ring",
  "rustls",
  "tokio",
@@ -789,6 +799,7 @@ dependencies = [
  "async-trait",
  "bytes 0.5.4",
  "futures 0.3.5",
+ "html-escape",
  "http 0.2.1",
  "http-body",
  "hyper",
@@ -838,10 +849,12 @@ dependencies = [
  "prost-types",
  "quickcheck",
  "rand 0.7.2",
- "regex 1.0.0",
+ "regex 1.2.1",
+ "serde_json",
  "tokio",
  "tokio-test",
  "tokio-timer",
+ "tokio-trace",
  "tonic",
  "tower",
  "tower-request-modifier",
@@ -1456,7 +1469,7 @@ dependencies = [
  "prost-types",
  "quickcheck",
  "rand 0.7.2",
- "regex 1.0.0",
+ "regex 1.2.1",
  "tokio",
  "tonic",
  "tower",
@@ -2155,15 +2168,14 @@ dependencies = [
 
 [[package]]
 name = "regex"
-version = "1.0.0"
+version = "1.2.1"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "75ecf88252dce580404a22444fc7d626c01815debba56a7f4f536772a5ff19d3"
+checksum = "88c3d9193984285d544df4a30c23a4e62ead42edf70a4452ceb76dac1ce05c26"
 dependencies = [
- "aho-corasick 0.6.4",
+ "aho-corasick 0.7.13",
  "memchr 2.3.3",
  "regex-syntax 0.6.11",
- "thread_local 0.3.5",
- "utf8-ranges 1.0.0",
+ "thread_local 0.3.6",
 ]
 
 [[package]]
@@ -2457,12 +2469,11 @@ dependencies = [
 
 [[package]]
 name = "thread_local"
-version = "0.3.5"
+version = "0.3.6"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "279ef31c19ededf577bfd12dfae728040a21f635b06a24cd670ff510edd38963"
+checksum = "c6b53e329000edc2b34dbe8545fd20e55a333362d0a321909685a19bd28c3f1b"
 dependencies = [
  "lazy_static",
- "unreachable",
 ]
 
 [[package]]
@@ -2478,9 +2489,9 @@ dependencies = [
 
 [[package]]
 name = "tokio"
-version = "0.2.21"
+version = "0.2.22"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "d099fa27b9702bed751524694adbe393e18b36b204da91eb1cbbbbb4a5ee2d58"
+checksum = "5d34ca54d84bf2b5b4d7d31e901a8464f7b60ac145a284fba25ceb801f2ddccd"
 dependencies = [
  "bytes 0.5.4",
  "fnv",
@@ -2497,6 +2508,7 @@ dependencies = [
  "signal-hook-registry",
  "slab",
  "tokio-macros",
+ "tracing",
  "winapi 0.3.8",
 ]
 
@@ -2586,6 +2598,18 @@ dependencies = [
  "tokio-executor",
 ]
 
+[[package]]
+name = "tokio-trace"
+version = "0.1.0"
+source = "git+https://github.com/hawkw/tokio-trace?rev=a8240c5cbb4ff981def84920d4087ef23b5edb93#a8240c5cbb4ff981def84920d4087ef23b5edb93"
+dependencies = [
+ "num_cpus",
+ "serde",
+ "tokio",
+ "tracing-core",
+ "tracing-subscriber",
+]
+
 [[package]]
 name = "tokio-util"
 version = "0.3.1"
@@ -2706,9 +2730,9 @@ dependencies = [
 
 [[package]]
 name = "tracing"
-version = "0.1.15"
+version = "0.1.16"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "a41f40ed0e162c911ac6fcb53ecdc8134c46905fdbbae8c50add462a538b495f"
+checksum = "c2e2a2de6b0d5cbb13fc21193a2296888eaab62b6044479aafb3c54c01c29fcd"
 dependencies = [
  "cfg-if",
  "log",
@@ -2718,9 +2742,9 @@ dependencies = [
 
 [[package]]
 name = "tracing-attributes"
-version = "0.1.8"
+version = "0.1.9"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "99bbad0de3fd923c9c3232ead88510b783e5a4d16a6154adffa3d53308de984c"
+checksum = "f0693bf8d6f2bf22c690fc61a9d21ac69efdbb894a17ed596b9af0f01e64b84b"
 dependencies = [
  "proc-macro2 1.0.10",
  "quote 1.0.2",
@@ -2729,9 +2753,9 @@ dependencies = [
 
 [[package]]
 name = "tracing-core"
-version = "0.1.10"
+version = "0.1.11"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "0aa83a9a47081cd522c09c81b31aec2c9273424976f922ad61c053b58350b715"
+checksum = "94ae75f0d28ae10786f3b1895c55fe72e79928fd5ccdebb5438c75e93fec178f"
 dependencies = [
  "lazy_static",
 ]
@@ -2778,7 +2802,7 @@ dependencies = [
  "lazy_static",
  "matchers",
  "parking_lot",
- "regex 1.0.0",
+ "regex 1.2.1",
  "serde",
  "serde_json",
  "sharded-slab",
@@ -2867,15 +2891,6 @@ version = "0.2.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "826e7639553986605ec5979c7dd957c7895e93eabed50ab2ffa7f6128a75097c"
 
-[[package]]
-name = "unreachable"
-version = "1.0.0"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "382810877fe448991dfc7f0dd6e3ae5d58088fd0ea5e35189655f84e6814fa56"
-dependencies = [
- "void",
-]
-
 [[package]]
 name = "untrusted"
 version = "0.7.0"
@@ -2906,16 +2921,16 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "662fab6525a98beff2921d7f61a39e7d59e0b425ebc7d0d9e66d316e55124122"
 
 [[package]]
-name = "version_check"
-version = "0.1.5"
+name = "utf8-width"
+version = "0.1.3"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "914b1a6776c4c929a602fafd8bc742e06365d4bcbe48c30f9cca5824f70dc9dd"
+checksum = "6f2c54fe5e8d6907c60dc6fba532cc8529245d97ff4e26cb490cb462de114ba4"
 
 [[package]]
-name = "void"
-version = "1.0.2"
+name = "version_check"
+version = "0.1.5"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "6a02e4885ed3bc0f2de90ea6dd45ebcbb66dacffe03547fadbb0eeae2770887d"
+checksum = "914b1a6776c4c929a602fafd8bc742e06365d4bcbe48c30f9cca5824f70dc9dd"
 
 [[package]]
 name = "want"

Dockerfile

@@ -37,21 +37,21 @@ ARG PROXY_UNOPTIMIZED
 ARG PROXY_FEATURES
 
 RUN --mount=type=cache,target=/var/lib/apt/lists \
-    --mount=type=cache,target=/var/tmp \
-    apt update && apt install -y time cmake
+  --mount=type=cache,target=/var/tmp \
+  apt update && apt install -y time cmake
 
 WORKDIR /usr/src/linkerd2-proxy
 COPY . .
 RUN --mount=type=cache,target=target \
-    --mount=type=cache,from=rust:1.44.1-buster,source=/usr/local/cargo,target=/usr/local/cargo \
-    mkdir -p /out && \
-    if [ -n "$PROXY_UNOPTIMIZED" ]; then \
-      (cd linkerd2-proxy && /usr/bin/time -v cargo build --locked --features="$PROXY_FEATURES") && \
-      mv target/debug/linkerd2-proxy /out/linkerd2-proxy ; \
-    else \
-      (cd linkerd2-proxy && /usr/bin/time -v cargo build --locked --release --features="$PROXY_FEATURES") && \
-      mv target/release/linkerd2-proxy /out/linkerd2-proxy ; \
-    fi
+  --mount=type=cache,from=rust:1.44.1-buster,source=/usr/local/cargo,target=/usr/local/cargo \
+  mkdir -p /out && \
+  if [ -n "$PROXY_UNOPTIMIZED" ]; then \
+  (cd linkerd2-proxy && /usr/bin/time -v cargo build --locked --features="$PROXY_FEATURES") && \
+  mv target/debug/linkerd2-proxy /out/linkerd2-proxy ; \
+  else \
+  (cd linkerd2-proxy && /usr/bin/time -v cargo build --locked --release --features="$PROXY_FEATURES") && \
+  mv target/release/linkerd2-proxy /out/linkerd2-proxy ; \
+  fi
 
 ## Install the proxy binary into the base runtime image.
 FROM $RUNTIME_IMAGE as runtime

linkerd/app/Cargo.toml

@@ -30,6 +30,7 @@ tonic = { version = "0.2", default-features = false, features = ["prost"] }
 tower = "0.3"
 tracing = "0.1.9"
 tracing-futures = { version = "0.2", features = ["std-future"]}
+html-escape = "0.2.5"
 
 [dev-dependencies]
 bytes = "0.5"

linkerd/app/core/Cargo.toml

@@ -63,7 +63,7 @@ linkerd2-stack-tracing = { path = "../../stack/tracing" }
 linkerd2-trace-context = { path = "../../trace-context" }
 rand = { version = "0.7", features = ["small_rng"] }
 regex = "1.0.0"
-tokio = { version = "0.2", features = ["macros", "sync", "parking_lot"]}
+tokio = { version = "0.2.22", features = ["macros", "sync", "parking_lot"]}
 tokio-timer = "0.2"
 tower-request-modifier = { git = "https://github.com/tower-rs/tower-http" }
 tonic = { version = "0.2", default-features = false, features = ["prost"] }
@@ -72,11 +72,16 @@ tracing-futures = { version = "0.2", features = ["std-future"] }
 tracing-log = "0.1"
 pin-project = "0.4"
 
+# task tracking
+html-escape = "0.2.5"
+tokio-trace = { git = "https://github.com/hawkw/tokio-trace", rev = "a8240c5cbb4ff981def84920d4087ef23b5edb93", features = ["serde"] }
+serde_json = "1"
+
 [dependencies.tracing-subscriber]
 version = "0.2.8"
-# we don't need `chrono` time formatting
+# we don't need `chrono` time formatting or ANSI colored output
 default-features = false
-features = ["env-filter", "fmt", "smallvec", "tracing-log", "ansi", "json", "parking_lot"]
+features = ["env-filter", "fmt", "smallvec", "tracing-log", "json", "parking_lot"]
 
 [dependencies.tower]
 version = "0.3"

linkerd/app/core/src/admin/mod.rs

@@ -3,7 +3,7 @@
 //! * `/metrics` -- reports prometheus-formatted metrics.
 //! * `/ready` -- returns 200 when the proxy is ready to participate in meshed traffic.
 
-use crate::{svc, transport::tls::accept::Connection};
+use crate::{svc, trace, transport::tls::accept::Connection};
 use futures::{future, TryFutureExt};
 use http::StatusCode;
 use hyper::{Body, Request, Response};
@@ -16,15 +16,17 @@ use std::task::{Context, Poll};
 use tower::{service_fn, Service};
 
 mod readiness;
+mod tasks;
 mod trace_level;
 
 pub use self::readiness::{Latch, Readiness};
-use self::trace_level::TraceLevel;
+use self::{tasks::Tasks, trace_level::TraceLevel};
 
 #[derive(Debug, Clone)]
 pub struct Admin<M: FmtMetrics> {
     metrics: metrics::Serve<M>,
     trace_level: TraceLevel,
+    tasks: Tasks,
     ready: Readiness,
 }
 
@@ -38,10 +40,18 @@ pub type ResponseFuture =
     Pin<Box<dyn Future<Output = Result<Response<Body>, io::Error>> + Send + 'static>>;
 
 impl<M: FmtMetrics> Admin<M> {
-    pub fn new(m: M, ready: Readiness, trace_level: TraceLevel) -> Self {
+    pub fn new(
+        m: M,
+        ready: Readiness,
+        trace::Handle {
+            level: trace_level,
+            tasks,
+        }: trace::Handle,
+    ) -> Self {
         Self {
             metrics: metrics::Serve::new(m),
             trace_level,
+            tasks: tasks.into(),
             ready,
         }
     }
@@ -87,6 +97,7 @@ impl<M: FmtMetrics> Service<Request<Body>> for Admin<M> {
             "/proxy-log-level" => self.trace_level.call(req),
             "/ready" => Box::pin(future::ok(self.ready_rsp())),
             "/live" => Box::pin(future::ok(self.live_rsp())),
+            path if path.starts_with("/tasks") => Box::pin(self.tasks.call(req)),
             _ => Box::pin(future::ok(rsp(StatusCode::NOT_FOUND, Body::empty()))),
         }
     }
@@ -130,6 +141,25 @@ fn rsp(status: StatusCode, body: impl Into<Body>) -> Response<Body> {
         .expect("builder with known status code must not fail")
 }
 
+fn check_loopback<B>(req: &Request<B>) -> Result<(), Response<Body>> {
+    if let Some(addr) = req.extensions().get::<ClientAddr>() {
+        let addr = addr.addr();
+        if addr.ip().is_loopback() {
+            return Ok(());
+        }
+        tracing::warn!(%addr, "denying request from non-loopback IP");
+        Err(rsp(
+            StatusCode::FORBIDDEN,
+            "access to /proxy-log-level and /trace only allowed from loopback interface",
+        ))
+    } else {
+        // TODO: should we panic if this was unset? It's a bug, but should
+        // it crash the proxy?
+        tracing::error!("ClientAddr extension should always be set");
+        Err(rsp(StatusCode::INTERNAL_SERVER_ERROR, Body::empty()))
+    }
+}
+
 #[cfg(test)]
 mod tests {
     use super::*;
@@ -144,7 +174,7 @@ mod tests {
         let (r, l0) = Readiness::new();
         let l1 = l0.clone();
 
-        let mut srv = Admin::new((), r, TraceLevel::dangling());
+        let mut srv = Admin::new((), r, trace::Handle::dangling());
         macro_rules! call {
             () => {{
                 let r = Request::builder()