We've adopted `tracing` for diagnostics, but currently, it is just being
used as a drop-in replacement for the `log` crate. Ideally, we would
want to start emitting more structured diagnostics, using `tracing`'s
`Span`s and structured key-value fields.
A lot of the logging in `h2` is already written in a style that imitates
the formatting of structured key-value logs, but as textual log
messages. Migrating the logs to structured `tracing` events therefore is
pretty easy to do. I've also started adding spans, mostly in the read
path.
Finally, I've updated the tests to use `tracing` rather than
`env_logger`. The tracing setup happens in a macro, so that a span for
each test with the test's name can be generated and entered. This will
make the test output easier to read if multiple tests are run
concurrently with `--nocapture`.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
This adds a `SendRequestExt` trait to h2-support, with a `get` method
that does a lot of the repeated request building stuff many test cases
were doing.
As a first step, the cleans up stream_states tests to use it.
Previously, any streams that were dropped or closed while not having
consumed the inflight received window capacity would simply leak that
capacity for the connection. This could easily happen if a `RecvStream`
were dropped before fully consuming the data, and therefore a user would
have no idea how much capacity to release in the first place. This
resulted in stalled connections that would never have capacity again.
I believe this was an oversight - a stream that is reset can still have some
capacity assigned to it (e.g. if said capacity was assigned in the same poll as
the reset), which should be redistributed.
Because `send_reset` called `recv_err`, which calls `reclaim_all_capacity`,
which eventually calls `transition(stream, ..)` -- all of which happens _before_
the RESET frame is enqueued -- it was possible for the stream to get unlinked
from the store (if there was any connection-level capacity to reassign). This
could then cause the stream to get "leaked" on drop/EOF since it would no longer
be iterated.
Fix this by delaying the call to `reclaim_all_capacity` _after_ enqueueing the
RESET frame.
A test demonstrating the issue is included.
* Prevent `pending_open` streams from being released.
This fixes a panic that would otherwise occur in some cases. A test
demonstrating said panic is included.
* Clear the pending_open queue together with everything else.
There was a race condition in the test where the server connection
sometimes closed before the final client opereation. This triggered an
unwrap in the test.
This patch updates the test to ensuree that the mock server connection
stays open until the client test is complete.
Because `self.pending` doesn't necessarily get cleaned up in a timely fashion -
rather, only when the user calls `poll_ready()` - it was possible for it to
refer to a stream that has already been closed. This would lead to a panic the
next time that `poll_ready()` was called.
Instead, use an `OpaqueStreamRef`, bumping the refcount.
A change to an existing test is included which demonstrates the issue.
Previously, monotonic stream IDs (spec 5.1.1) for push promises were not
enforced. This was due to push promises going through an entirely
separate code path than normally initiated streams.
This patch unifies the code path for initializing streams via both
HEADERS and PUSH_PROMISE. This is done by first calling `recv.open` in
both cases.
Closes#272