[GH-ISSUE #1880] WARNs emitted on TCP disconnects #804

New issue

Closed

opened 2026-03-16 00:18:41 +03:00 by kerem · 4 comments

kerem commented

2026-03-16 00:18:41 +03:00

Owner

Originally created by @olix0r on GitHub (Jan 11, 2023).
Original GitHub issue: https://github.com/hickory-dns/hickory-dns/issues/1880

We had users report WARNs being emitted in application logs. When looking more closely at debug logs we see something like:

[ 656.276898s] DEBUG ThreadId(01) trust_dns_proto::tcp::tcp_stream: zero bytes read, stream closed?
[ 656.276905s] WARN ThreadId(01) trust_dns_proto::xfer::dns_multiplexer: stream TCP(10.100.0.10:53) error: stream closed

It seems inappropriate to surface WARNs on such an innocuous internal event to me. As a workaround, we're going to add trust_dns=ERROR to our default log filter to exclude these types of things.

Would PRs be accepted to reduce log level for these types of innocuous events?

Originally created by @olix0r on GitHub (Jan 11, 2023). Original GitHub issue: https://github.com/hickory-dns/hickory-dns/issues/1880 We had users report WARNs being emitted in application logs. When looking more closely at debug logs we see something like: ``` [ 656.276898s] DEBUG ThreadId(01) trust_dns_proto::tcp::tcp_stream: zero bytes read, stream closed? [ 656.276905s] WARN ThreadId(01) trust_dns_proto::xfer::dns_multiplexer: stream TCP(10.100.0.10:53) error: stream closed ``` It seems inappropriate to surface WARNs on such an innocuous internal event to me. As a workaround, we're going to add `trust_dns=ERROR` to our default log filter to exclude these types of things. Would PRs be accepted to reduce log level for these types of innocuous events?

kerem closed this issue

2026-03-16 00:18:47 +03:00

kerem commented

2026-03-16 00:18:52 +03:00

Author

Owner

@djc commented on GitHub (Jan 11, 2023):

In principle, yes!

@djc commented on GitHub (Jan 11, 2023): In principle, yes!

kerem commented

2026-03-16 00:18:57 +03:00

Author

Owner

@bluejekyll commented on GitHub (Jan 11, 2023):

Yeah, I think it's safe to make all of these DEBUG statements, or were you thinking TRACE?

@bluejekyll commented on GitHub (Jan 11, 2023): Yeah, I think it's safe to make all of these DEBUG statements, or were you thinking TRACE?

kerem commented

2026-03-16 00:19:03 +03:00

Author

Owner

@olix0r commented on GitHub (Jan 11, 2023):

DEBUG seems appropriate to me, too. I think @hawkw is going to take a look at fixing this.

@olix0r commented on GitHub (Jan 11, 2023): `DEBUG` seems appropriate to me, too. I think @hawkw is going to take a look at fixing this.

kerem commented

2026-03-16 00:19:08 +03:00

Author

Owner

@hawkw commented on GitHub (Jan 11, 2023):

It looks like the error is already logged at DEBUG if there are no pending requests, and it's only logged at WARN if there are: github.com/bluejekyll/trust-dns@3235d2b3f6/crates/proto/src/xfer/dns_multiplexer.rs (L201-L205)

It looks like this error is being logged because it's handled by returning None from the Stream impl, ~~rather than by returning an error, so the error itself isn't actually propagated to user code~~: github.com/bluejekyll/trust-dns@3235d2b3f6/crates/proto/src/xfer/dns_multiplexer.rs (L417)

Edit: oh, the error is passed to the active requests on the stream, just not returned from the stream impl itself. Just logging this at debug is probably reasonable.

Changing this code to just always log at DEBUG seems reasonable to me. However, if there is a desire to log some errors at WARN, perhaps we ought to make that decision based on the error kind as well as whether there are pending requests? That way, there's not a warning for TCP streams closing, but there could still be a warning for protocol errors that are less likely to occur...

@hawkw commented on GitHub (Jan 11, 2023): It looks like the error is already logged at `DEBUG` if there are no pending requests, and it's only logged at `WARN` if there are: https://github.com/bluejekyll/trust-dns/blob/3235d2b3f6433271f71780963936edab541c2ff3/crates/proto/src/xfer/dns_multiplexer.rs#L201-L205 It looks like this error is being logged because it's handled by returning `None` from the `Stream` impl, ~~rather than by returning an error, so the error itself isn't actually propagated to user code~~: https://github.com/bluejekyll/trust-dns/blob/3235d2b3f6433271f71780963936edab541c2ff3/crates/proto/src/xfer/dns_multiplexer.rs#L417 **Edit**: oh, the error *is* passed to the active requests on the stream, just not returned from the stream impl itself. Just logging this at debug is probably reasonable. Changing this code to just always log at `DEBUG` seems reasonable to me. However, if there is a desire to log some errors at `WARN`, perhaps we ought to make that decision based on the error kind as well as whether there are pending requests? That way, there's not a warning for TCP streams closing, but there could still be a warning for protocol errors that are less likely to occur...

kerem referenced this issue

2026-03-16 02:20:35 +03:00

[PR #804] [MERGED] Update h2 dep (patch version bump). #1696