Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[BUG] invehicle-digital-twin sometimes becomes unresponsive after calling the register API with the managed_subscribe feature #73

Open
1 task
wilyle opened this issue Nov 22, 2023 · 1 comment
Labels
bug Something isn't working

Comments

@wilyle
Copy link
Contributor

wilyle commented Nov 22, 2023

Description

Steps to reproduce:

  1. Build Ibeji with the managed_subscribe feature enabled
  2. Run Agemo (might not actually be required)
  3. Start a provider. This step might need to be repeated multiple times before Ibeji becomes unresponsive. The register request does not need to succeed, so this can be done by attempting to start one of the sample providers repeatedly

This is sometimes also observed when the application starts up without external stimulus, though this is not well investigated and repro steps are not yet available.

Workarounds

  • Enabling trace logging for Ibeji seems to make the problem very difficult or impossible to reproduce. If noisy logging can be tolerated, this may help with this issue

What has been tried so far:

  • The initial theory was that the issue was a conflict when using futures::executor::block_on in a tokio async context here, but this is now considered unlikely based on work in the wilyle/block_on branch which replaces this with a tokio equivalent.
  • Wrapping the call with tokio::time::timeout does not appear to solve the issue either. It's suspected that something is hogging the tokio runtime and not yielding to the timeout task, making it unable to exit even when time has expired.

Other observations:

When enabling the tokio console (which has been done in the linked wilyle/block_on branch), the following state is noted when Ibeji becomes unresponsive:

image

Of particular note is the first task, which will persist in the busy state indefinitely and never be polled again. This behavior is indicative of a task that's blocking the thread. It's unclear what is originating the call to hyper::common::exec, but based on trace logs from a successful request it's believed to be related to the service interceptor infrastructure. In a successful API call, there are two calls to this function: one at the very beginning of request processing, and another sometime after the GrpcInterceptorService has completed its processing (though the exact timing is unknown). The full trace log will be added in a comment to prevent an already very verbose issue from getting longer (see #73 (comment)).

As mentioned in the workarounds, enabling trace logging to try to get more information makes the issue very difficult to reproduce, and I've been unable to do so with trace logging enabled. This suggests some kind of race condition that's affected by I/O side effects. The highest log level that yields consistently reproducible behavior is debug, at least when logs go to stdout. It may be worth trying again with logs going somewhere else. Note however that when using the tokio console integration, trace logs appear to be redirected to the tokio console and will not appear elsewhere, so trace logs might not be viewable while using this tool.

Next steps:

The following are potential steps to consider for further investigation or resolution:

  • Redirect trace logs to a location other than stdout to see if the issue can be reproduced at higher log levels
  • Investigate when the hyper::common::exec calls are made. How is it related to the service interceptor infrastructure? What operations could potentially hang indefinitely?
  • Update dependency major versions (Bump the dev-dependencies group with 3 updates #72)
  • Change the Agemo integration model to not use service layering to avoid having to switch between sync and async contexts, which seems to be a potential cause for this issue
  • Change the block_on pattern to use some form of polling for completion or a one-shot channel for receiving the result

Acceptance criteria

  • TBD, this bug is still under investigation
@wilyle wilyle added the bug Something isn't working label Nov 22, 2023
@wilyle
Copy link
Contributor Author

wilyle commented Nov 22, 2023

Here are trace-level logs from starting up Ibeji and submitting a single successful register call. Note the inclusion of 3 warning level logs from the wilyle/block_on branch, which are not present in the main branch. These messages were logged at warning level just to improve their visibility when reading through verbose logs to determine the system state and are not indicative of a problematic state:

args: {"--log-level": Some("trace")}
[2023-11-22T21:57:49Z INFO  invehicle_digital_twin] The In-Vehicle Digital Twin Service has started.
[2023-11-22T21:57:49Z INFO  invehicle_digital_twin] The HTTP server is listening on address 'http://0.0.0.0:5010'
[2023-11-22T21:57:49Z INFO  invehicle_digital_twin] This service is not using Chariott.
[2023-11-22T21:57:49Z INFO  managed_subscribe::managed_subscribe_module] Getting Managed Subscribe URI.
[2023-11-22T21:57:49Z INFO  common::utils] URI set in settings.
[2023-11-22T21:57:49Z INFO  invehicle_digital_twin] Initialized Managed Subscribe module.
[2023-11-22T21:57:49Z TRACE tracing::span::active] <- runtime.spawn;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> runtime.spawn;
[2023-11-22T21:57:51Z TRACE tokio::task] runtime.spawn; kind=task task.name= task.id=14 loc.file="/home/wilyle/.cargo/registry/src/index.crates.io-6f17d22bba15001f/hyper-0.14.27/src/common/exec.rs" loc.line=49 loc.col=21
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- runtime.spawn;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> runtime.spawn;
[2023-11-22T21:57:51Z TRACE tracing::span] server_handshake;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> server_handshake;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_write] FramedWrite::buffer; frame=Settings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384, max_header_list_size: 16777216 }
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedWrite::buffer;
[2023-11-22T21:57:51Z DEBUG h2::codec::framed_write] send frame=Settings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384, max_header_list_size: 16777216 }
[2023-11-22T21:57:51Z TRACE h2::frame::settings] encoding SETTINGS; len=18
[2023-11-22T21:57:51Z TRACE h2::frame::settings] encoding setting; val=InitialWindowSize(1048576)
[2023-11-22T21:57:51Z TRACE h2::frame::settings] encoding setting; val=MaxFrameSize(16384)
[2023-11-22T21:57:51Z TRACE h2::frame::settings] encoding setting; val=MaxHeaderListSize(16777216)
[2023-11-22T21:57:51Z TRACE h2::codec::framed_write] encoded settings rem=27
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedWrite::buffer;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedWrite::buffer;
[2023-11-22T21:57:51Z TRACE tracing::span] flush;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- server_handshake;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> server_handshake;
[2023-11-22T21:57:51Z TRACE h2::server] state=Flushing(_)
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> flush;
[2023-11-22T21:57:51Z TRACE tracing::span] FramedWrite::flush;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedWrite::flush;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_write] queued_data_frame=false
[2023-11-22T21:57:51Z TRACE h2::codec::framed_write] flushing buffer
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedWrite::flush;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedWrite::flush;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- flush;
[2023-11-22T21:57:51Z TRACE h2::server] flush.poll=Ready
[2023-11-22T21:57:51Z TRACE tracing::span] read_preface;
[2023-11-22T21:57:51Z TRACE tracing::span] -- flush;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> read_preface;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- read_preface;
[2023-11-22T21:57:51Z TRACE tracing::span] -- read_preface;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::flow_control] inc_window; sz=65535; old=0; new=65535
[2023-11-22T21:57:51Z TRACE h2::proto::streams::flow_control] inc_window; sz=65535; old=0; new=65535
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] Prioritize::new; flow=FlowControl { window_size: Window(65535), available: Window(65535) }
[2023-11-22T21:57:51Z DEBUG h2::proto::connection] Connection; peer=Server
[2023-11-22T21:57:51Z TRACE h2::server] connection established!
[2023-11-22T21:57:51Z TRACE h2::proto::streams::recv] set_target_connection_window; target=1048576; available=65535, reserved=0
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- server_handshake;
[2023-11-22T21:57:51Z TRACE tracing::span] -- server_handshake;
[2023-11-22T21:57:51Z TRACE tracing::span] -- server_handshake;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] poll;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> poll;
[2023-11-22T21:57:51Z TRACE h2::proto::connection] connection.state=Open
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span] -- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] poll
[2023-11-22T21:57:51Z TRACE tokio_util::codec::framed_impl] attempting to decode a frame
[2023-11-22T21:57:51Z TRACE tokio_util::codec::framed_impl] frame decoded from buffer
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] read.bytes=27
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] FramedRead::decode_frame; offset=27
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedRead::decode_frame;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] decoding frame from 27B
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] frame.kind=Settings
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedRead::decode_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedRead::decode_frame;
[2023-11-22T21:57:51Z DEBUG h2::codec::framed_read] received frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 }
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE h2::proto::connection] recv SETTINGS frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 }
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> poll_ready;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_write] FramedWrite::buffer; frame=Settings { flags: (0x1: ACK) }
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedWrite::buffer;
[2023-11-22T21:57:51Z DEBUG h2::codec::framed_write] send frame=Settings { flags: (0x1: ACK) }
[2023-11-22T21:57:51Z TRACE h2::frame::settings] encoding SETTINGS; len=0
[2023-11-22T21:57:51Z TRACE h2::codec::framed_write] encoded settings rem=9
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedWrite::buffer;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedWrite::buffer;
[2023-11-22T21:57:51Z TRACE h2::proto::settings] ACK sent; applying settings
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span] -- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] poll
[2023-11-22T21:57:51Z TRACE tokio_util::codec::framed_impl] attempting to decode a frame
[2023-11-22T21:57:51Z TRACE tokio_util::codec::framed_impl] frame decoded from buffer
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] read.bytes=13
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] FramedRead::decode_frame; offset=13
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedRead::decode_frame;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] decoding frame from 13B
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] frame.kind=WindowUpdate
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedRead::decode_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedRead::decode_frame;
[2023-11-22T21:57:51Z DEBUG h2::codec::framed_read] received frame=WindowUpdate { stream_id: StreamId(0), size_increment: 5177345 }
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE h2::proto::connection] recv WINDOW_UPDATE frame=WindowUpdate { stream_id: StreamId(0), size_increment: 5177345 }
[2023-11-22T21:57:51Z TRACE h2::proto::streams::flow_control] inc_window; sz=5177345; old=65535; new=5242880
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] assign_connection_capacity; inc=5177345
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> assign_connection_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- assign_connection_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span] -- assign_connection_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span] -- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] poll
[2023-11-22T21:57:51Z TRACE tokio_util::codec::framed_impl] attempting to decode a frame
[2023-11-22T21:57:51Z TRACE tokio_util::codec::framed_impl] frame decoded from buffer
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] read.bytes=9
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] FramedRead::decode_frame; offset=9
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedRead::decode_frame;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] decoding frame from 9B
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] frame.kind=Settings
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedRead::decode_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedRead::decode_frame;
[2023-11-22T21:57:51Z DEBUG h2::codec::framed_read] received frame=Settings { flags: (0x1: ACK) }
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE h2::proto::connection] recv SETTINGS frame=Settings { flags: (0x1: ACK) }
[2023-11-22T21:57:51Z DEBUG h2::proto::settings] received settings ACK; applying Settings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384, max_header_list_size: 16777216 }
[2023-11-22T21:57:51Z TRACE h2::proto::streams::recv] update_initial_window_size; new=1048576; old=1048576
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span] -- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] poll
[2023-11-22T21:57:51Z TRACE tokio_util::codec::framed_impl] attempting to decode a frame
[2023-11-22T21:57:51Z TRACE tokio_util::codec::framed_impl] frame decoded from buffer
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] read.bytes=96
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] FramedRead::decode_frame; offset=96
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedRead::decode_frame;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] decoding frame from 96B
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] frame.kind=Headers
[2023-11-22T21:57:51Z TRACE h2::frame::headers] loading headers; flags=(0x4: END_HEADERS)
[2023-11-22T21:57:51Z TRACE tracing::span] hpack::decode;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> hpack::decode;
[2023-11-22T21:57:51Z TRACE h2::hpack::decoder] decode
[2023-11-22T21:57:51Z TRACE h2::hpack::decoder] rem=87 kind=Indexed
[2023-11-22T21:57:51Z TRACE h2::hpack::decoder] rem=86 kind=Indexed
[2023-11-22T21:57:51Z TRACE h2::hpack::decoder] rem=85 kind=LiteralWithIndexing
[2023-11-22T21:57:51Z TRACE h2::hpack::decoder] rem=74 kind=LiteralWithoutIndexing
[2023-11-22T21:57:51Z TRACE h2::hpack::decoder] rem=34 kind=LiteralWithIndexing
[2023-11-22T21:57:51Z TRACE h2::hpack::decoder] rem=23 kind=LiteralWithIndexing
[2023-11-22T21:57:51Z TRACE h2::hpack::decoder] rem=10 kind=LiteralWithIndexing
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- hpack::decode;
[2023-11-22T21:57:51Z TRACE tracing::span] -- hpack::decode;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedRead::decode_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedRead::decode_frame;
[2023-11-22T21:57:51Z DEBUG h2::codec::framed_read] received frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE h2::proto::connection] recv HEADERS frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[2023-11-22T21:57:51Z TRACE h2::proto::streams::flow_control] inc_window; sz=1048576; old=0; new=1048576
[2023-11-22T21:57:51Z TRACE h2::proto::streams::flow_control] inc_window; sz=2097152; old=0; new=2097152
[2023-11-22T21:57:51Z TRACE h2::proto::streams::streams] recv_headers; stream=StreamId(1); state=State { inner: Idle }
[2023-11-22T21:57:51Z TRACE h2::proto::streams::recv] opening stream; init_window=1048576
[2023-11-22T21:57:51Z TRACE h2::proto::streams::store] Queue::push
[2023-11-22T21:57:51Z TRACE h2::proto::streams::store]  -> first entry
[2023-11-22T21:57:51Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: Open { local: AwaitingHeaders, remote: Streaming } }; is_closed=false; pending_send_empty=true; buffered_send_data=0; num_recv=1; num_send=0
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span] -- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] poll
[2023-11-22T21:57:51Z TRACE tokio_util::codec::framed_impl] attempting to decode a frame
[2023-11-22T21:57:51Z TRACE tokio_util::codec::framed_impl] frame decoded from buffer
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] read.bytes=213
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] FramedRead::decode_frame; offset=213
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedRead::decode_frame;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] decoding frame from 213B
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] frame.kind=Data
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedRead::decode_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedRead::decode_frame;
[2023-11-22T21:57:51Z DEBUG h2::codec::framed_read] received frame=Data { stream_id: StreamId(1) }
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE h2::proto::connection] recv DATA frame=Data { stream_id: StreamId(1) }
[2023-11-22T21:57:51Z TRACE h2::proto::streams::recv] recv_data; size=204; connection=65535; stream=1048576
[2023-11-22T21:57:51Z TRACE h2::proto::streams::flow_control] send_data; sz=204; window=65535; available=1048576
[2023-11-22T21:57:51Z TRACE h2::proto::streams::flow_control] send_data; sz=204; window=1048576; available=1048576
[2023-11-22T21:57:51Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: Open { local: AwaitingHeaders, remote: Streaming } }; is_closed=false; pending_send_empty=true; buffered_send_data=0; num_recv=1; num_send=0
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span] -- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] poll
[2023-11-22T21:57:51Z TRACE tokio_util::codec::framed_impl] attempting to decode a frame
[2023-11-22T21:57:51Z TRACE tokio_util::codec::framed_impl] frame decoded from buffer
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] read.bytes=9
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] FramedRead::decode_frame; offset=9
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedRead::decode_frame;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] decoding frame from 9B
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] frame.kind=Data
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedRead::decode_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedRead::decode_frame;
[2023-11-22T21:57:51Z DEBUG h2::codec::framed_read] received frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE h2::proto::connection] recv DATA frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
[2023-11-22T21:57:51Z TRACE h2::proto::streams::recv] recv_data; size=0; connection=65331; stream=1048372
[2023-11-22T21:57:51Z TRACE h2::proto::streams::flow_control] send_data; sz=0; window=65331; available=1048372
[2023-11-22T21:57:51Z TRACE h2::proto::streams::state] recv_close: Open => HalfClosedRemote(AwaitingHeaders)
[2023-11-22T21:57:51Z TRACE h2::proto::streams::flow_control] send_data; sz=0; window=1048372; available=1048372
[2023-11-22T21:57:51Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: HalfClosedRemote(AwaitingHeaders) }; is_closed=false; pending_send_empty=true; buffered_send_data=0; num_recv=1; num_send=0
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span] -- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] poll
[2023-11-22T21:57:51Z TRACE tokio_util::codec::framed_impl] attempting to decode a frame
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_write] FramedWrite::buffer; frame=WindowUpdate { stream_id: StreamId(0), size_increment: 983041 }
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedWrite::buffer;
[2023-11-22T21:57:51Z DEBUG h2::codec::framed_write] send frame=WindowUpdate { stream_id: StreamId(0), size_increment: 983041 }
[2023-11-22T21:57:51Z TRACE h2::frame::window_update] encoding WINDOW_UPDATE; id=StreamId(0)
[2023-11-22T21:57:51Z TRACE h2::codec::framed_write] encoded window_update rem=22
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedWrite::buffer;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedWrite::buffer;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::flow_control] inc_window; sz=983041; old=65331; new=1048372
[2023-11-22T21:57:51Z TRACE tracing::span] try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] poll_complete
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] schedule_pending_open
[2023-11-22T21:57:51Z TRACE tracing::span] pop_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> pop_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- pop_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- pop_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] FramedWrite::flush;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedWrite::flush;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_write] queued_data_frame=false
[2023-11-22T21:57:51Z TRACE h2::codec::framed_write] flushing buffer
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedWrite::flush;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedWrite::flush;
[2023-11-22T21:57:51Z TRACE tracing::span] try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- poll;
[2023-11-22T21:57:51Z TRACE tracing::span] -- poll;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] -- Connection;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::streams] next_incoming; id=StreamId(1), state=State { inner: HalfClosedRemote(AwaitingHeaders) }
[2023-11-22T21:57:51Z TRACE h2::server] received incoming
[2023-11-22T21:57:51Z TRACE hyper::proto::h2::server] incoming request
[2023-11-22T21:57:51Z WARN  common::grpc_interceptor] Request intercepted
[2023-11-22T21:57:51Z TRACE tokio::task] runtime.spawn; kind=block_on task.name= task.id=15 loc.file="/home/wilyle/repos/ibeji/core/common/src/utils.rs" loc.line=244 loc.col=16
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> runtime.spawn;
[2023-11-22T21:57:51Z TRACE tokio::time::sleep] runtime.resource; concrete_type="Sleep" kind="timer" loc.file="/home/wilyle/repos/ibeji/core/common/src/utils.rs" loc.line=245 loc.col=13
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> runtime.resource;
[2023-11-22T21:57:51Z TRACE runtime::resource::state_update] duration=10001 duration.unit="ms" duration.op="override"
[2023-11-22T21:57:51Z TRACE tokio::time::sleep] runtime.resource.async_op; source="Sleep::new_timeout"
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- runtime.resource;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> runtime.resource.async_op;
[2023-11-22T21:57:51Z TRACE tracing::span] runtime.resource.async_op.poll;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- runtime.resource.async_op;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::recv] release_capacity; size=204
[2023-11-22T21:57:51Z TRACE h2::proto::streams::recv] release_connection_capacity; size=204, connection in_flight_data=204
[2023-11-22T21:57:51Z TRACE h2::proto::streams::recv] release_capacity; size=0
[2023-11-22T21:57:51Z TRACE h2::proto::streams::recv] release_connection_capacity; size=0, connection in_flight_data=0
[2023-11-22T21:57:51Z TRACE h2::proto::streams::streams] drop_stream_ref; stream=Stream { id: StreamId(1), state: State { inner: HalfClosedRemote(AwaitingHeaders) }, is_counted: true, ref_count: 2, next_pending_send: None, is_pending_send: false, send_flow: FlowControl { window_size: Window(2097152), available: Window(0) }, requested_send_capacity: 0, buffered_send_data: 0, send_task: None, pending_send: Deque { indices: None }, next_pending_send_capacity: None, is_pending_send_capacity: false, send_capacity_inc: false, next_open: None, is_pending_open: false, is_pending_push: false, next_pending_accept: None, is_pending_accept: false, recv_flow: FlowControl { window_size: Window(1048372), available: Window(1048576) }, in_flight_recv_data: 0, next_window_update: None, is_pending_window_update: false, reset_at: None, next_reset_expire: None, pending_recv: Deque { indices: None }, is_recv: false, recv_task: None, pending_push_promises: Queue { indices: None, _p: PhantomData<h2::proto::streams::stream::NextAccept> }, content_length: Omitted }
[2023-11-22T21:57:51Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: HalfClosedRemote(AwaitingHeaders) }; is_closed=false; pending_send_empty=true; buffered_send_data=0; num_recv=1; num_send=0
[2023-11-22T21:57:51Z TRACE tracing::span] -- runtime.resource.async_op;
[2023-11-22T21:57:51Z TRACE tracing::span] -- runtime.resource.async_op.poll;
[2023-11-22T21:57:51Z TRACE tracing::span] -- runtime.resource;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- runtime.spawn;
[2023-11-22T21:57:51Z TRACE tracing::span] -- runtime.spawn;
[2023-11-22T21:57:51Z WARN  common::grpc_interceptor] Body parsed
[2023-11-22T21:57:51Z INFO  managed_subscribe::managed_subscribe_interceptor] register_request = RegisterRequest { entity_access_info_list: [EntityAccessInfo { name: "AmbientAirTemperature", id: "dtmi:sdv:HVAC:AmbientAirTemperature;1", description: "The immediate surroundings air temperature (in Fahrenheit).", endpoint_info_list: [EndpointInfo { protocol: "mqtt", operations: ["Subscribe"], uri: "tcp://0.0.0.0:4010", context: "sdv/HVAC/AmbientAirTemperature/1" }] }] }
[2023-11-22T21:57:51Z WARN  common::grpc_interceptor] Finished handling request
[2023-11-22T21:57:51Z TRACE tokio::task] runtime.spawn; kind=task task.name= task.id=16 loc.file="/home/wilyle/.cargo/registry/src/index.crates.io-6f17d22bba15001f/hyper-0.14.27/src/common/exec.rs" loc.line=49 loc.col=21
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] poll;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> poll;
[2023-11-22T21:57:51Z TRACE h2::proto::connection] connection.state=Open
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span] -- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] poll
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span] try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] poll_complete
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] schedule_pending_open
[2023-11-22T21:57:51Z TRACE tracing::span] pop_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> pop_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- pop_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- pop_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] FramedWrite::flush;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedWrite::flush;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_write] flushing buffer
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedWrite::flush;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedWrite::flush;
[2023-11-22T21:57:51Z TRACE tracing::span] try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- poll;
[2023-11-22T21:57:51Z TRACE tracing::span] -- poll;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] -- Connection;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- runtime.spawn;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> runtime.spawn;
[2023-11-22T21:57:51Z INFO  invehicle_digital_twin::invehicle_digital_twin_impl] Received a register request for the the entity:
    dtmi:sdv:HVAC:AmbientAirTemperature;1
[2023-11-22T21:57:51Z DEBUG invehicle_digital_twin::invehicle_digital_twin_impl] Registered entity dtmi:sdv:HVAC:AmbientAirTemperature;1
[2023-11-22T21:57:51Z DEBUG invehicle_digital_twin::invehicle_digital_twin_impl] Completed the register request.
[2023-11-22T21:57:51Z TRACE h2::proto::streams::send] send_headers; frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }; init_window=2097152
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] Prioritize::queue_frame; stream.id=StreamId(1)
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> Prioritize::queue_frame;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] schedule_send stream.id=StreamId(1)
[2023-11-22T21:57:51Z TRACE h2::proto::streams::store] Queue::push
[2023-11-22T21:57:51Z TRACE h2::proto::streams::store]  -> first entry
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- Prioritize::queue_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- Prioritize::queue_frame;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: HalfClosedRemote(Streaming) }; is_closed=false; pending_send_empty=false; buffered_send_data=0; num_recv=1; num_send=0
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] reserve_capacity; stream.id=StreamId(1) requested=1 effective=1 curr=0
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> reserve_capacity;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] try_assign_capacity; stream.id=StreamId(1)
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> try_assign_capacity;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] requested=1 additional=1 buffered=0 window=2097152 conn=5242880
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] assigning capacity=1
[2023-11-22T21:57:51Z TRACE h2::proto::streams::stream]   assigned capacity to stream; available=1; buffered=0; id=StreamId(1); max_buffer_size=409600 prev=0
[2023-11-22T21:57:51Z TRACE h2::proto::streams::stream]   notifying task
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] available=1 requested=1 buffered=0 has_unavailable=true
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- try_assign_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span] -- try_assign_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- reserve_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span] -- reserve_capacity;
[2023-11-22T21:57:51Z TRACE hyper::proto::h2] send body chunk: 5 bytes, eos=false
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] send_data; sz=5 requested=1
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> send_data;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] buffered=5
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] try_assign_capacity; stream.id=StreamId(1)
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> try_assign_capacity;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] requested=5 additional=4 buffered=5 window=2097152 conn=5242879
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] assigning capacity=4
[2023-11-22T21:57:51Z TRACE h2::proto::streams::stream]   assigned capacity to stream; available=5; buffered=5; id=StreamId(1); max_buffer_size=409600 prev=0
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] available=5 requested=5 buffered=5 has_unavailable=true
[2023-11-22T21:57:51Z TRACE h2::proto::streams::store] Queue::push
[2023-11-22T21:57:51Z TRACE h2::proto::streams::store]  -> already queued
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- try_assign_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span] -- try_assign_capacity;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] available=5 buffered=5
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] Prioritize::queue_frame; stream.id=StreamId(1)
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> Prioritize::queue_frame;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] schedule_send stream.id=StreamId(1)
[2023-11-22T21:57:51Z TRACE h2::proto::streams::store] Queue::push
[2023-11-22T21:57:51Z TRACE h2::proto::streams::store]  -> already queued
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- Prioritize::queue_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- Prioritize::queue_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- send_data;
[2023-11-22T21:57:51Z TRACE tracing::span] -- send_data;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: HalfClosedRemote(Streaming) }; is_closed=false; pending_send_empty=false; buffered_send_data=5; num_recv=1; num_send=0
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] reserve_capacity; stream.id=StreamId(1) requested=1 effective=6 curr=5
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> reserve_capacity;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] try_assign_capacity; stream.id=StreamId(1)
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> try_assign_capacity;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] requested=6 additional=1 buffered=5 window=2097152 conn=5242875
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] assigning capacity=1
[2023-11-22T21:57:51Z TRACE h2::proto::streams::stream]   assigned capacity to stream; available=6; buffered=5; id=StreamId(1); max_buffer_size=409600 prev=0
[2023-11-22T21:57:51Z TRACE h2::proto::streams::stream]   notifying task
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] available=6 requested=6 buffered=5 has_unavailable=true
[2023-11-22T21:57:51Z TRACE h2::proto::streams::store] Queue::push
[2023-11-22T21:57:51Z TRACE h2::proto::streams::store]  -> already queued
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- try_assign_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span] -- try_assign_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- reserve_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span] -- reserve_capacity;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] reserve_capacity; stream.id=StreamId(1) requested=0 effective=5 curr=6
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> reserve_capacity;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] assign_connection_capacity; inc=1
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> assign_connection_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- assign_connection_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span] -- assign_connection_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- reserve_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span] -- reserve_capacity;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::state] send_close: HalfClosedRemote => Closed
[2023-11-22T21:57:51Z TRACE h2::proto::streams::send] send_trailers -- queuing; frame=Headers { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) }
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] Prioritize::queue_frame; stream.id=StreamId(1)
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> Prioritize::queue_frame;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] schedule_send stream.id=StreamId(1)
[2023-11-22T21:57:51Z TRACE h2::proto::streams::store] Queue::push
[2023-11-22T21:57:51Z TRACE h2::proto::streams::store]  -> already queued
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- Prioritize::queue_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- Prioritize::queue_frame;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] reserve_capacity; stream.id=StreamId(1) requested=0 effective=5 curr=5
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> reserve_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- reserve_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span] -- reserve_capacity;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: Closed(EndStream) }; is_closed=false; pending_send_empty=false; buffered_send_data=5; num_recv=1; num_send=0
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- runtime.spawn;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::streams] drop_stream_ref; stream=Stream { id: StreamId(1), state: State { inner: Closed(EndStream) }, is_counted: true, ref_count: 2, next_pending_send: None, is_pending_send: true, send_flow: FlowControl { window_size: Window(2097152), available: Window(5) }, requested_send_capacity: 5, buffered_send_data: 5, send_task: Some(Waker { data: 0x7f6cdc00e680, vtable: 0x555759a77710 }), pending_send: Deque { indices: Some(Indices { head: 0, tail: 2 }) }, next_pending_send_capacity: None, is_pending_send_capacity: false, send_capacity_inc: true, next_open: None, is_pending_open: false, is_pending_push: false, next_pending_accept: None, is_pending_accept: false, recv_flow: FlowControl { window_size: Window(1048372), available: Window(1048576) }, in_flight_recv_data: 0, next_window_update: None, is_pending_window_update: false, reset_at: None, next_reset_expire: None, pending_recv: Deque { indices: None }, is_recv: false, recv_task: None, pending_push_promises: Queue { indices: None, _p: PhantomData<h2::proto::streams::stream::NextAccept> }, content_length: Omitted }
[2023-11-22T21:57:51Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: Closed(EndStream) }; is_closed=false; pending_send_empty=false; buffered_send_data=5; num_recv=1; num_send=0
[2023-11-22T21:57:51Z TRACE h2::proto::streams::streams] drop_stream_ref; stream=Stream { id: StreamId(1), state: State { inner: Closed(EndStream) }, is_counted: true, ref_count: 1, next_pending_send: None, is_pending_send: true, send_flow: FlowControl { window_size: Window(2097152), available: Window(5) }, requested_send_capacity: 5, buffered_send_data: 5, send_task: Some(Waker { data: 0x7f6cdc00e680, vtable: 0x555759a77710 }), pending_send: Deque { indices: Some(Indices { head: 0, tail: 2 }) }, next_pending_send_capacity: None, is_pending_send_capacity: false, send_capacity_inc: true, next_open: None, is_pending_open: false, is_pending_push: false, next_pending_accept: None, is_pending_accept: false, recv_flow: FlowControl { window_size: Window(1048372), available: Window(1048576) }, in_flight_recv_data: 0, next_window_update: None, is_pending_window_update: false, reset_at: None, next_reset_expire: None, pending_recv: Deque { indices: None }, is_recv: false, recv_task: None, pending_push_promises: Queue { indices: None, _p: PhantomData<h2::proto::streams::stream::NextAccept> }, content_length: Omitted }
[2023-11-22T21:57:51Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: Closed(EndStream) }; is_closed=false; pending_send_empty=false; buffered_send_data=5; num_recv=1; num_send=0
[2023-11-22T21:57:51Z TRACE tracing::span] -- runtime.spawn;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> runtime.spawn;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] poll;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> poll;
[2023-11-22T21:57:51Z TRACE h2::proto::connection] connection.state=Open
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span] -- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] poll
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span] try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] poll_complete
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] schedule_pending_open
[2023-11-22T21:57:51Z TRACE tracing::span] pop_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> pop_frame;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] popped; stream.id=StreamId(1) stream.state=State { inner: Closed(EndStream) }
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> popped;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] is_pending_reset=false
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] pop_frame; frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[2023-11-22T21:57:51Z TRACE h2::proto::streams::store] Queue::push
[2023-11-22T21:57:51Z TRACE h2::proto::streams::store]  -> first entry
[2023-11-22T21:57:51Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: Closed(EndStream) }; is_closed=false; pending_send_empty=false; buffered_send_data=5; num_recv=1; num_send=0
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- popped;
[2023-11-22T21:57:51Z TRACE tracing::span] -- popped;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- pop_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- pop_frame;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] writing frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[2023-11-22T21:57:51Z TRACE h2::codec::framed_write] FramedWrite::buffer; frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedWrite::buffer;
[2023-11-22T21:57:51Z DEBUG h2::codec::framed_write] send frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[2023-11-22T21:57:51Z TRACE tracing::span] hpack::encode;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> hpack::encode;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- hpack::encode;
[2023-11-22T21:57:51Z TRACE tracing::span] -- hpack::encode;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedWrite::buffer;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedWrite::buffer;
[2023-11-22T21:57:51Z TRACE tracing::span] try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] schedule_pending_open
[2023-11-22T21:57:51Z TRACE tracing::span] pop_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> pop_frame;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] popped; stream.id=StreamId(1) stream.state=State { inner: Closed(EndStream) }
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> popped;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] is_pending_reset=false
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] data frame sz=5 eos=false window=5 available=5 requested=5 buffered=5
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] sending data frame len=5
[2023-11-22T21:57:51Z TRACE tracing::span] updating stream flow;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> updating stream flow;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::flow_control] send_data; sz=5; window=2097152; available=5
[2023-11-22T21:57:51Z TRACE h2::proto::streams::stream]   sent stream data; available=0; buffered=0; id=StreamId(1); max_buffer_size=409600 prev=0
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- updating stream flow;
[2023-11-22T21:57:51Z TRACE tracing::span] -- updating stream flow;
[2023-11-22T21:57:51Z TRACE tracing::span] updating connection flow;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> updating connection flow;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::flow_control] send_data; sz=5; window=5242880; available=5242880
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- updating connection flow;
[2023-11-22T21:57:51Z TRACE tracing::span] -- updating connection flow;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] pop_frame; frame=Data { stream_id: StreamId(1) }
[2023-11-22T21:57:51Z TRACE h2::proto::streams::store] Queue::push
[2023-11-22T21:57:51Z TRACE h2::proto::streams::store]  -> first entry
[2023-11-22T21:57:51Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: Closed(EndStream) }; is_closed=false; pending_send_empty=false; buffered_send_data=0; num_recv=1; num_send=0
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- popped;
[2023-11-22T21:57:51Z TRACE tracing::span] -- popped;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- pop_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- pop_frame;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] writing frame=Data { stream_id: StreamId(1) }
[2023-11-22T21:57:51Z TRACE h2::codec::framed_write] FramedWrite::buffer; frame=Data { stream_id: StreamId(1) }
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedWrite::buffer;
[2023-11-22T21:57:51Z DEBUG h2::codec::framed_write] send frame=Data { stream_id: StreamId(1) }
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedWrite::buffer;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedWrite::buffer;
[2023-11-22T21:57:51Z TRACE tracing::span] try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] reclaimed frame=Data { stream_id: StreamId(1) } sz=0
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] schedule_pending_open
[2023-11-22T21:57:51Z TRACE tracing::span] pop_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> pop_frame;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] popped; stream.id=StreamId(1) stream.state=State { inner: Closed(EndStream) }
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> popped;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] is_pending_reset=false
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] pop_frame; frame=Headers { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) }
[2023-11-22T21:57:51Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: Closed(EndStream) }; is_closed=true; pending_send_empty=true; buffered_send_data=0; num_recv=1; num_send=0
[2023-11-22T21:57:51Z TRACE h2::proto::streams::counts] dec_num_streams; stream=StreamId(1)
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- popped;
[2023-11-22T21:57:51Z TRACE tracing::span] -- popped;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- pop_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- pop_frame;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] writing frame=Headers { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) }
[2023-11-22T21:57:51Z TRACE h2::codec::framed_write] FramedWrite::buffer; frame=Headers { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) }
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedWrite::buffer;
[2023-11-22T21:57:51Z DEBUG h2::codec::framed_write] send frame=Headers { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) }
[2023-11-22T21:57:51Z TRACE tracing::span] hpack::encode;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> hpack::encode;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- hpack::encode;
[2023-11-22T21:57:51Z TRACE tracing::span] -- hpack::encode;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedWrite::buffer;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedWrite::buffer;
[2023-11-22T21:57:51Z TRACE tracing::span] try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::prioritize] schedule_pending_open
[2023-11-22T21:57:51Z TRACE tracing::span] pop_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> pop_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- pop_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- pop_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] FramedWrite::flush;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedWrite::flush;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_write] queued_data_frame=false
[2023-11-22T21:57:51Z TRACE h2::codec::framed_write] flushing buffer
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedWrite::flush;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedWrite::flush;
[2023-11-22T21:57:51Z TRACE tracing::span] try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- try_reclaim_frame;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- poll;
[2023-11-22T21:57:51Z TRACE tracing::span] -- poll;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] -- Connection;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- runtime.spawn;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> runtime.spawn;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] poll;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> poll;
[2023-11-22T21:57:51Z TRACE h2::proto::connection] connection.state=Open
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span] -- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] poll
[2023-11-22T21:57:51Z TRACE tokio_util::codec::framed_impl] attempting to decode a frame
[2023-11-22T21:57:51Z TRACE tokio_util::codec::framed_impl] frame decoded from buffer
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] read.bytes=17
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] FramedRead::decode_frame; offset=17
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedRead::decode_frame;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] decoding frame from 17B
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] frame.kind=GoAway
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedRead::decode_frame;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedRead::decode_frame;
[2023-11-22T21:57:51Z DEBUG h2::codec::framed_read] received frame=GoAway { error_code: NO_ERROR, last_stream_id: StreamId(0) }
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE h2::proto::connection] recv GOAWAY frame=GoAway { error_code: NO_ERROR, last_stream_id: StreamId(0) }
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span] -- poll_ready;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_read] poll
[2023-11-22T21:57:51Z TRACE tokio_util::codec::framed_impl] attempting to decode a frame
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedRead::poll_next;
[2023-11-22T21:57:51Z TRACE h2::proto::connection] codec closed
[2023-11-22T21:57:51Z TRACE h2::proto::streams::streams] Streams::recv_eof
[2023-11-22T21:57:51Z TRACE tracing::span] clear_pending_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> clear_pending_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- clear_pending_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span] -- clear_pending_capacity;
[2023-11-22T21:57:51Z TRACE h2::proto::connection] connection.state=Closing(NO_ERROR, Library)
[2023-11-22T21:57:51Z TRACE h2::proto::connection] connection closing after flush
[2023-11-22T21:57:51Z TRACE tracing::span] FramedWrite::flush;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> FramedWrite::flush;
[2023-11-22T21:57:51Z TRACE h2::codec::framed_write] flushing buffer
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- FramedWrite::flush;
[2023-11-22T21:57:51Z TRACE tracing::span] -- FramedWrite::flush;
[2023-11-22T21:57:51Z TRACE h2::proto::connection] connection.state=Closed(NO_ERROR, Library)
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- poll;
[2023-11-22T21:57:51Z TRACE tracing::span] -- poll;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] -- Connection;
[2023-11-22T21:57:51Z TRACE hyper::proto::h2::server] incoming connection complete
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- runtime.spawn;
[2023-11-22T21:57:51Z TRACE h2::proto::streams::streams] Streams::recv_eof
[2023-11-22T21:57:51Z TRACE tracing::span] clear_pending_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span::active] -> clear_pending_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span::active] <- clear_pending_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span] -- clear_pending_capacity;
[2023-11-22T21:57:51Z TRACE tracing::span] -- Connection;
[2023-11-22T21:57:51Z TRACE tracing::span] -- runtime.spawn;

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

When branches are created from issues, their pull requests are automatically linked.

1 participant