[GH-ISSUE #2127] Additional error context #894

Open
opened 2026-03-16 00:46:30 +03:00 by kerem · 7 comments
Owner

Originally created by @andrewbaxter on GitHub (Jan 13, 2024).
Original GitHub issue: https://github.com/hickory-dns/hickory-dns/issues/2127

Is your feature request related to a problem? Please describe.
I'm calling a method in the library and it returns proto error: io error: invalid input parameter - AFAICT this is a core io error, and as this is a networking library I believe it's probably making io calls all over the place. I don't have enough details to identify the cause on my own.

Describe the solution you'd like
Maybe additional context could be added to the error type? Ex when wrapping IoError a static string describing what was going on at the time. If there's a lot of layers this too might not narrow down the context enough, but it'd be a start...

Since there's a lot of indirection here (resolver layers, pools, etc) I think ideally there'd be that much more context in the error messages.

Obviously performant error handling makes difficult tradeoffs, but right now I think there's too little context in bubbled errors.

Describe alternatives you've considered
Running a debugger. Unfortunately this is in an environment where it's hard to attach a debugger.

Debug-build only print statements? Or something that could be optionally enabled in debug builds? To print out everything it's doing.

Originally created by @andrewbaxter on GitHub (Jan 13, 2024). Original GitHub issue: https://github.com/hickory-dns/hickory-dns/issues/2127 **Is your feature request related to a problem? Please describe.** I'm calling a method in the library and it returns `proto error: io error: invalid input parameter` - AFAICT this is a core io error, and as this is a networking library I believe it's probably making io calls all over the place. I don't have enough details to identify the cause on my own. **Describe the solution you'd like** Maybe additional context could be added to the error type? Ex when wrapping IoError a static string describing what was going on at the time. If there's a lot of layers this too might not narrow down the context enough, but it'd be a start... Since there's a lot of indirection here (resolver layers, pools, etc) I think ideally there'd be that much more context in the error messages. Obviously performant error handling makes difficult tradeoffs, but right now I think there's too little context in bubbled errors. **Describe alternatives you've considered** Running a debugger. Unfortunately this is in an environment where it's hard to attach a debugger. Debug-build only print statements? Or something that could be optionally enabled in debug builds? To print out everything it's doing.
Author
Owner

@andrewbaxter commented on GitHub (Jan 13, 2024):

I just found the backtrace feature in proto - I guess the idea is that would provide context in debug builds. I actually went through the documentation before posting this and didn't see it mentioned anywhere.

It adds debug information to error objects when RUST_BACKTRACE=1, both {} and {:?}. I don't know if this is debug builds only.

That said, I just tried it and the backtrace dies in the middle of async land:

 0: <hickory_proto::error::ProtoError as core::convert::From<E>>::from
		   at .../.cargo/registry/src/index.crates.io-6f17d22bba15001f/hickory-proto-0.24.0/src/error.rs:359:24
 1: core::ops::function::FnOnce::call_once
		   at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/ops/function.rs:250:5
 2: <T as futures_util::fns::FnOnce1<A>>::call_once
		   at .../.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.30/src/fns.rs:15:9
 3: <futures_util::fns::MapErrFn<F> as futures_util::fns::FnOnce1<core::result::Result<T,E>>>::call_once::{{closure}}
		   at .../.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.30/src/fns.rs:219:25
 4: core::result::Result<T,E>::map_err
		   at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/result.rs:829:27
 5: <futures_util::fns::MapErrFn<F> as futures_util::fns::FnOnce1<core::result::Result<T,E>>>::call_once
		   at .../.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.30/src/fns.rs:219:9
 6: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
		   at .../.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.30/src/future/future/map.rs:57:73
 7: <futures_util::future::future::Map<Fut,F> as core::future::future::Future>::poll
		   at .../.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.30/src/lib.rs:91:13
 8: <futures_util::future::try_future::MapErr<Fut,F> as core::future::future::Future>::poll
		   at .../.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.30/src/lib.rs:91:13
 9: <core::pin::Pin<P> as core::future::future::Future>::poll
		   at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/future/future.rs:125:9
10: <core::pin::Pin<P> as core::future::future::Future>::poll
		   at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/future/future.rs:125:9
11: futures_util::future::future::FutureExt::poll_unpin
		   at .../.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.30/src/future/future/mod.rs:558:9
12: <hickory_proto::xfer::dns_multiplexer::DnsMultiplexerConnect<F,S,MF> as core::future::future::Future>::poll
		   at .../.cargo/registry/src/index.crates.io-6f17d22bba15001f/hickory-proto-0.24.0/src/xfer/dns_multiplexer.rs:241:32
13: <hickory_proto::xfer::dns_exchange::DnsExchangeConnectInner<F,S,TE> as core::future::future::Future>::poll
		   at .../.cargo/registry/src/index.crates.io-6f17d22bba15001f/hickory-proto-0.24.0/src/xfer/dns_exchange.rs:322:27
14: futures_util::future::future::FutureExt::poll_unpin

Perhaps this is an internal error, but I feel like it should say something like "error trying to call connect" or something that could tie it to the a specific call or point in the source.

<!-- gh-comment-id:1890410521 --> @andrewbaxter commented on GitHub (Jan 13, 2024): I just found the `backtrace` feature in `proto` - I guess the idea is that would provide context in debug builds. I actually went through the documentation before posting this and didn't see it mentioned anywhere. It adds debug information to error objects when `RUST_BACKTRACE=1`, both `{}` and `{:?}`. I don't know if this is debug builds only. That said, I just tried it and the backtrace dies in the middle of async land: ``` 0: <hickory_proto::error::ProtoError as core::convert::From<E>>::from at .../.cargo/registry/src/index.crates.io-6f17d22bba15001f/hickory-proto-0.24.0/src/error.rs:359:24 1: core::ops::function::FnOnce::call_once at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/ops/function.rs:250:5 2: <T as futures_util::fns::FnOnce1<A>>::call_once at .../.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.30/src/fns.rs:15:9 3: <futures_util::fns::MapErrFn<F> as futures_util::fns::FnOnce1<core::result::Result<T,E>>>::call_once::{{closure}} at .../.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.30/src/fns.rs:219:25 4: core::result::Result<T,E>::map_err at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/result.rs:829:27 5: <futures_util::fns::MapErrFn<F> as futures_util::fns::FnOnce1<core::result::Result<T,E>>>::call_once at .../.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.30/src/fns.rs:219:9 6: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll at .../.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.30/src/future/future/map.rs:57:73 7: <futures_util::future::future::Map<Fut,F> as core::future::future::Future>::poll at .../.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.30/src/lib.rs:91:13 8: <futures_util::future::try_future::MapErr<Fut,F> as core::future::future::Future>::poll at .../.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.30/src/lib.rs:91:13 9: <core::pin::Pin<P> as core::future::future::Future>::poll at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/future/future.rs:125:9 10: <core::pin::Pin<P> as core::future::future::Future>::poll at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/future/future.rs:125:9 11: futures_util::future::future::FutureExt::poll_unpin at .../.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.30/src/future/future/mod.rs:558:9 12: <hickory_proto::xfer::dns_multiplexer::DnsMultiplexerConnect<F,S,MF> as core::future::future::Future>::poll at .../.cargo/registry/src/index.crates.io-6f17d22bba15001f/hickory-proto-0.24.0/src/xfer/dns_multiplexer.rs:241:32 13: <hickory_proto::xfer::dns_exchange::DnsExchangeConnectInner<F,S,TE> as core::future::future::Future>::poll at .../.cargo/registry/src/index.crates.io-6f17d22bba15001f/hickory-proto-0.24.0/src/xfer/dns_exchange.rs:322:27 14: futures_util::future::future::FutureExt::poll_unpin ``` Perhaps this is an internal error, but I feel like it should say something like "error trying to call `connect`" or something that could tie it to the a specific call or point in the source.
Author
Owner

@andrewbaxter commented on GitHub (Jan 13, 2024):

It looks like there actually is context associated with io::Error, but it's discarded when converted to ProtoError (only kind is kept).

<!-- gh-comment-id:1890430219 --> @andrewbaxter commented on GitHub (Jan 13, 2024): It looks like there actually is context associated with `io::Error`, but it's discarded when converted to `ProtoError` (only `kind` is kept).
Author
Owner

@djc commented on GitHub (Jan 15, 2024):

I think I looked into this once, and std actually doesn't provide APIs to keep the context around?

<!-- gh-comment-id:1891726099 --> @djc commented on GitHub (Jan 15, 2024): I think I looked into this once, and std actually doesn't provide APIs to keep the context around?
Author
Owner

@andrewbaxter commented on GitHub (Jan 18, 2024):

Oops, my brain purged my cache. I'm trying to remember what I found when I was digging in...

std::io::Error wraps an error in addition to the Kind, ex Error::new(ErrorKind::Other, "oh no!"). Looking at the docs I think this may be exposed by into_inner?

In this case I believe the error conversion path was io::Error -> ProtoErrorKind -> ProtoError which discards the inner error... I think there were any other error conversions before it was returned.

It looks like the standard library mostly uses const_io_error! macro which is exposed in .description(). Edit: description is deprecated and it says to use Display methods now.

But in any case the more context that could be preserved (and possibly supplemented) in ProtoError the easier it'd make troubleshooting.

<!-- gh-comment-id:1898291567 --> @andrewbaxter commented on GitHub (Jan 18, 2024): Oops, my brain purged my cache. I'm trying to remember what I found when I was digging in... `std::io::Error` wraps an error in addition to the `Kind`, ex `Error::new(ErrorKind::Other, "oh no!")`. Looking at the docs I _think_ this may be exposed by `into_inner`? In this case I believe the error conversion path was `io::Error` -> `ProtoErrorKind` -> `ProtoError` which discards the inner error... I think there were any other error conversions before it was returned. It looks like the standard library mostly uses `const_io_error!` macro which is exposed in `.description()`. Edit: `description` is deprecated and it says to use `Display` methods now. But in any case the more context that could be preserved (and possibly supplemented) in `ProtoError` the easier it'd make troubleshooting.
Author
Owner

@andrewbaxter commented on GitHub (Sep 1, 2024):

FWIW I'm now getting proto error: io error: connection refused and I see the tls connection traffic both ways over the net so I know the dot upstream isn't refusing the connection, and I don't have an inkling where to start looking for where this error occurred.

<!-- gh-comment-id:2323341216 --> @andrewbaxter commented on GitHub (Sep 1, 2024): FWIW I'm now getting `proto error: io error: connection refused` and I _see_ the tls connection traffic both ways over the net so I know the dot upstream isn't refusing the connection, and I don't have an inkling where to start looking for where this error occurred.
Author
Owner

@cpu commented on GitHub (Sep 1, 2024):

In this case I believe the error conversion path was io::Error -> ProtoErrorKind -> ProtoError which discards the inner error...

I made some progress here w/ https://github.com/hickory-dns/hickory-dns/pull/2181 and in 0.25.0-alpha.2 ProtoErrorKind maintains the inner error.

FWIW I'm now getting proto error: io error: connection refused

Are you testing w/ 0.24.x?

<!-- gh-comment-id:2323346976 --> @cpu commented on GitHub (Sep 1, 2024): > In this case I believe the error conversion path was io::Error -> ProtoErrorKind -> ProtoError which discards the inner error... I made some progress here w/ https://github.com/hickory-dns/hickory-dns/pull/2181 and in `0.25.0-alpha.2` [`ProtoErrorKind`](https://docs.rs/hickory-proto/0.25.0-alpha.2/hickory_proto/error/enum.ProtoErrorKind.html#variant.Io) maintains the inner error. > FWIW I'm now getting proto error: io error: connection refused Are you testing w/ 0.24.x?
Author
Owner

@andrewbaxter commented on GitHub (Sep 1, 2024):

Oh awesome!! That's great to hear!

Yeah, while looking into status of the rulstls dep + 0.25 I stumbled upon https://github.com/hickory-dns/hickory-dns/issues/2066 . Trying the "native-certs" feature now to see if that helps.

<!-- gh-comment-id:2323350454 --> @andrewbaxter commented on GitHub (Sep 1, 2024): Oh awesome!! That's great to hear! Yeah, while looking into status of the rulstls dep + 0.25 I stumbled upon https://github.com/hickory-dns/hickory-dns/issues/2066 . Trying the `"native-certs"` feature now to see if that helps.
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
starred/hickory-dns#894
No description provided.