You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
We reuse the HTTP2 Connection created by hyperium/h2.
However, During the stress testing, an issue of memory leakage occurred, causing a crash and reboot of the system. So I begin the troubleshooting.
1. Start Troubleshooting with the memory growth chart
First, using Jemalloc and Jeprof, I generated memory growth chart at intervals. jeprof_memory_leak.pdf
The largest memory block was finish_grow, which occupied 88.8% of the total allocation on its own. The finish_grow function is related to Vec reallocating new memory when expanding. This may indicate that the memory leak occurred during the process of writing to Vec, where memory was allocated to these Vecs but was not released in a timely manner.
I found the function call chain upstream of finish_grow is tracing_core -> event -> Event -> dispatch, which is related to the subscriber. In our business code, the subscriber specified for tracing_core to use is opentelemetry.
In opentelemetry_api, I found the function call chain finish_grow <- reserve_for_push <- push at function on_event, which includes operations for pushing events onto the events array in a span. tracing_opentelemetry/layer.rs
fn on_event(&self, event: &Event<'_>, ctx: Context<'_, S>) {
if let Some(span) = ctx.lookup_current() {
...
if let Some(ref mut events) = builder.events {
events.push(otel_event);
} else {
builder.events = Some(vec![otel_event]);
}
...
}
2. Start Troubleshooting with Jaeger on the other side
On the other hand, starting from Jaeger, I observed a span that is as long as the pressure test duration. This span is a trace_debug_span that was created when establishing a Connection.h2/src/proto/connection.rs
I've observed that there are many events under the trace_debug_span, as if an event is added for every request that comes in. h2/src/codec/framed_read.rs h2/src/codec/framed_write.rs
To disable the trace_debug_span in the h2 library, you can change the RUST_LOG logging level from debug to info. After doing this and running a stress test again, you can observe that the memory no longer leaks.
In summary
I used the h2 library to create a persistent Connection for reuse, which results in the creation of a trace_debug_span that lasts as long as the lifespan of the connection. When a stress test is conducted with continuous requests, events are constantly added to the events array inside the trace_debug_span. As long as the persistent Connection is not closed, the trace_debug_span will not terminate and be destroyed after reporting. Therefore, the memory used by the trace_debug_span keeps increasing, leading to a memory leak.
Although we normally don't enable RUST_LOG: "debug" in production, sometimes it's necessary to turn it on for troubleshooting business issues based on debug logs. This memory leak issue has been troublesome.
Therefore, when creating a connection by default, is it possible to allow users to set trace_debug_span as an optional feature?
The text was updated successfully, but these errors were encountered:
I don't think this is h2's fault, it rather the subscriber which is growing the events forever. Any subscriber implementation will eventually need to cap its own growth.
We reuse the HTTP2 Connection created by hyperium/h2.
However, During the stress testing, an issue of memory leakage occurred, causing a crash and reboot of the system. So I begin the troubleshooting.
1. Start Troubleshooting with the memory growth chart
First, using
Jemalloc
andJeprof
, I generated memory growth chart at intervals. jeprof_memory_leak.pdfThe largest memory block was
finish_grow
, which occupied 88.8% of the total allocation on its own. Thefinish_grow
function is related to Vec reallocating new memory when expanding. This may indicate that the memory leak occurred during the process of writing to Vec, where memory was allocated to these Vecs but was not released in a timely manner.I found the function call chain upstream of
finish_grow
istracing_core -> event -> Event -> dispatch
, which is related to thesubscriber
. In our business code, thesubscriber
specified for tracing_core to use isopentelemetry
.In
opentelemetry_api
, I found the function call chainfinish_grow <- reserve_for_push <- push
at functionon_event
, which includes operations for pushing events onto theevents
array in a span. tracing_opentelemetry/layer.rs2. Start Troubleshooting with Jaeger on the other side
On the other hand, starting from
![connection.rs](https://private-user-images.githubusercontent.com/20532424/321648324-73b342fd-9be6-42fe-bead-12fff765c81d.png?jwt=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJpc3MiOiJnaXRodWIuY29tIiwiYXVkIjoicmF3LmdpdGh1YnVzZXJjb250ZW50LmNvbSIsImtleSI6ImtleTUiLCJleHAiOjE3MjQ2MTgzNDMsIm5iZiI6MTcyNDYxODA0MywicGF0aCI6Ii8yMDUzMjQyNC8zMjE2NDgzMjQtNzNiMzQyZmQtOWJlNi00MmZlLWJlYWQtMTJmZmY3NjVjODFkLnBuZz9YLUFtei1BbGdvcml0aG09QVdTNC1ITUFDLVNIQTI1NiZYLUFtei1DcmVkZW50aWFsPUFLSUFWQ09EWUxTQTUzUFFLNFpBJTJGMjAyNDA4MjUlMkZ1cy1lYXN0LTElMkZzMyUyRmF3czRfcmVxdWVzdCZYLUFtei1EYXRlPTIwMjQwODI1VDIwMzQwM1omWC1BbXotRXhwaXJlcz0zMDAmWC1BbXotU2lnbmF0dXJlPTlkNzFmYzgyMTA2ZjEwZGRiYjYwZGY3ZWYxMTNhMWM1NjdlMTIyMGRmODdmNmVkNDJiNTU0YTNiNTk2MWE5OWMmWC1BbXotU2lnbmVkSGVhZGVycz1ob3N0JmFjdG9yX2lkPTAma2V5X2lkPTAmcmVwb19pZD0wIn0.-m6wqTBrFNxG45BxrF9tj6y8v2xDTW3JXsMYz_TWeys)
![framed_write](https://private-user-images.githubusercontent.com/20532424/321648753-29b754fd-ed39-46c2-9259-42dfb401b586.png?jwt=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJpc3MiOiJnaXRodWIuY29tIiwiYXVkIjoicmF3LmdpdGh1YnVzZXJjb250ZW50LmNvbSIsImtleSI6ImtleTUiLCJleHAiOjE3MjQ2MTgzNDMsIm5iZiI6MTcyNDYxODA0MywicGF0aCI6Ii8yMDUzMjQyNC8zMjE2NDg3NTMtMjliNzU0ZmQtZWQzOS00NmMyLTkyNTktNDJkZmI0MDFiNTg2LnBuZz9YLUFtei1BbGdvcml0aG09QVdTNC1ITUFDLVNIQTI1NiZYLUFtei1DcmVkZW50aWFsPUFLSUFWQ09EWUxTQTUzUFFLNFpBJTJGMjAyNDA4MjUlMkZ1cy1lYXN0LTElMkZzMyUyRmF3czRfcmVxdWVzdCZYLUFtei1EYXRlPTIwMjQwODI1VDIwMzQwM1omWC1BbXotRXhwaXJlcz0zMDAmWC1BbXotU2lnbmF0dXJlPTAyNTgyOGY2ZTRhYWYxNmU4ZjE5OTQzMzczZDk2ZmY1NjQ2YmI5NGRlOGEyOTA2NzBiYjgyYmNlMTY2YWVhOGUmWC1BbXotU2lnbmVkSGVhZGVycz1ob3N0JmFjdG9yX2lkPTAma2V5X2lkPTAmcmVwb19pZD0wIn0.e9oee3SPXsC_nXHTGpag2xcWLy41ShcL9w87qaVdbRg)
![fine](https://private-user-images.githubusercontent.com/20532424/321649290-e3a9aebb-8420-41a5-ba7a-a11fb05e19cc.png?jwt=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJpc3MiOiJnaXRodWIuY29tIiwiYXVkIjoicmF3LmdpdGh1YnVzZXJjb250ZW50LmNvbSIsImtleSI6ImtleTUiLCJleHAiOjE3MjQ2MTgzNDMsIm5iZiI6MTcyNDYxODA0MywicGF0aCI6Ii8yMDUzMjQyNC8zMjE2NDkyOTAtZTNhOWFlYmItODQyMC00MWE1LWJhN2EtYTExZmIwNWUxOWNjLnBuZz9YLUFtei1BbGdvcml0aG09QVdTNC1ITUFDLVNIQTI1NiZYLUFtei1DcmVkZW50aWFsPUFLSUFWQ09EWUxTQTUzUFFLNFpBJTJGMjAyNDA4MjUlMkZ1cy1lYXN0LTElMkZzMyUyRmF3czRfcmVxdWVzdCZYLUFtei1EYXRlPTIwMjQwODI1VDIwMzQwM1omWC1BbXotRXhwaXJlcz0zMDAmWC1BbXotU2lnbmF0dXJlPWIyYzUxMDU2YWViNjA1OWRmZDM3YmZlYjhhYWEwYjljMjk1ODZkZmMxY2ZjYjQwZGExM2JkNjlhNGQ4YmFhNjEmWC1BbXotU2lnbmVkSGVhZGVycz1ob3N0JmFjdG9yX2lkPTAma2V5X2lkPTAmcmVwb19pZD0wIn0.XK_qYG8PxkXXty_k2aVyRH9w8U-0sUQX_hlLoP7a6Lk)
Jaeger
, I observed a span that is as long as the pressure test duration. This span is atrace_debug_span
that was created when establishing a Connection.h2/src/proto/connection.rsI've observed that there are many
events
under thetrace_debug_span
, as if anevent
is added for every request that comes in.h2/src/codec/framed_read.rs
h2/src/codec/framed_write.rs
To disable the
trace_debug_span
in theh2
library, you can change theRUST_LOG
logging level fromdebug
toinfo
. After doing this and running a stress test again, you can observe that the memory no longer leaks.In summary
I used the
h2
library to create a persistentConnection
for reuse, which results in the creation of atrace_debug_span
that lasts as long as the lifespan of the connection. When a stress test is conducted with continuous requests, events are constantly added to theevents
array inside thetrace_debug_span
. As long as the persistentConnection
is not closed, thetrace_debug_span
will not terminate and be destroyed after reporting. Therefore, the memory used by thetrace_debug_span
keeps increasing, leading to a memory leak.Although we normally don't enable
RUST_LOG: "debug"
in production, sometimes it's necessary to turn it on for troubleshooting business issues based on debug logs. This memory leak issue has been troublesome.Therefore, when creating a connection by default, is it possible to allow users to set
trace_debug_span
as an optional feature?The text was updated successfully, but these errors were encountered: