hyper::Error prints its first cause in its Display impl, causes duplicate printing in many scenarios

[lilyball]

Version
hyper v0.14.17

Description
hyper::Error's Display impl will print its immediate cause in a "{description}: {cause}" format. The problem is this screws with anything else that tries to print an error along with its causes, as the immediate cause is also the returned value from .source().

For example, if I were to print an error with tracing's built-in support, e.g. error!(err as &dyn StdError, "message"), the resulting log line includes err=error trying to connect: tcp connect error: Connection refused (os error 61) err.sources=[tcp connect error: Connection refused (os error 61), Connection refused (os error 61)]. Or if I wrap this in an eyre::Report and print that with {:#} (which includes the cause chain), I get error trying to connect: tcp connect error: Connection refused (os error 61): tcp connect error: Connection refused (os error 61): Connection refused (os error 61) which is even more confusing.

This appears to be an intentional decision, especially as it has a .message() accessor that returns an impl Display that is just the message. But it's one that is very frustrating. Ideally hyper::Error would just not include its cause, relying on the user to opt in to showing causes. Alternatively it could just skip the first cause in the .source() accessor, though that means users who want to actually inspect that cause (e.g. to downcast it) can't (though in the case of the quoted error, its cause is not a public type and so there's nothing I can reasonably do with it besides just printing it).

Changing this behavior will surprise anyone who is currently working around it, though I suspect it will simply produce better behavior for most users who just log the error and move on. My preferred solution of "just don't print the cause" does make the message() accessor pointless, though that could simply be deprecated without having to do a breaking change.

If you really don't want to make this change, then at least please change the message() accessor to actually be an impl StdError + Send + Sync such that I can then pass that to whatever I'm using that logs causes. The resulting error from this would of course retain the initial cause as the source(). Please also do this even if you decide the right solution is to just skip the initial cause in source(), so I can still get the formatting I want without having to reinvent error chains (especially when dealing with stuff like eyre::Report's {:?} printing).

[olix0r]

Note that #2737 added a message helper

[lilyball]

Note my last paragraph. The existence of message() as it is today requires me to write my own Error wrapper just to get proper behavior. And it also doesn't justify the fact that printing the error chain duplicates the source.

To summarize the two reasonable options here:

1. Stop printing the cause in Display. Leave that up to the user to choose to do.
2. Or change source() to skip the immediate cause and return cause.source() instead. Additionally, change message() to return an impl Error + Send + Sync + 'static instead that retains the current cause as its source. That way I can just pass that to my error reporting infrastructure and I will get proper handling of the error chain.

[davidpdrsn]

This was previously discussed here #2732

[lilyball]

It was, but the "fix" there did not address the actual issue. The issue as filed is the same thing I'm complaining about: it should either not print the immediate cause in Display or it should skip that cause in source(). The "fix" was to add the message() accessor, except that's not even an Error type and so can't be used in contexts that are trying to print the source chain without having to wrap it in a new custom error type. That issue also points out that solutions like this require everyone handling generic errors to depend on hyper and downcast to hyper::Error just to detect and fix its output.

The basic requirement is hyper::Error should not be duplicating information in its Display and source() impls. And yet it is. This is unequivocally a bug.

[seanmonstar]

I provide the rationale in this comment here. The short answer is that I believe the more common case is users that are simply debug!("{}", error) printing, and not using one of the fancier error reporting crates. Those users would lose out if the behavior were changed.

The basic requirement ... And yet it is. This is unequivocally a bug.

Please give the benefit of the doubt. We all want what's best, even when what's best isn't crystal clear yet.

[lilyball]

@seanmonstar Your stated rationale supports the idea of changing the behavior of source(), which was one of the two options I've listed. Right now it returns inner.cause, if you want to keep the Display impl as-is then it needs to return something like inner.cause.and_then(|c| c.source()) instead.

As previously mentioned, if the immediate cause is a public error type then this will break downcasting of that cause, but hyper doesn't seem to make any guarantee as to what the underlying error source is anyway and reporting error chains is vastly more common than downcasting sources. If someone actually needs downcasting then hyper::Error could add a .cause()¹ that returns Option<&dyn StdError + Send + Sync> that doesn't skip the immediate cause (like .into_cause() but without consuming the error). This has the potential to be mildly confusing but cause()/into_cause() can explicit document that they may return a different value than source() does.

Footnotes

1. Not the deprecated Error::cause() but an inherent method. ↩

[seanmonstar]

Sorry for the confusion, I was in fact advocating for the way hyper currently is. I think the solution is instead that the errors working group and error reporting crates figure out a way to indicate they are going to crawl the source chain and print each out. As I mentioned, I believe it is more common for users to just print the Display of the error and be done with it, so I that's why I propose it should be the default.

I explored that some in seanmonstar/errors#1. Re-reading that issue, I see it disagrees slightly with my current opinion on what is default. But the rest is still good.

[Noah-Kennedy]

I'm in agreement here with @seanmonstar. Very few users actually crawl the chain as opposed to just logging the error. The common case works best if behavior remains as it currently is.

[lilyball]

Logging the error often involves crawling the chain.

slog supports a #err modifier that crawls the chain automatically and prints a message like description: source1: source2: source3.

tracing crawls the chain automatically for any field of type dyn Error + 'static that is logged and prints it like name=description, name.sources=[source1, source2, source3].

anyhow::Error and eyre::Report crawl the chain automatically when printed with {:#} or {:?}, the former printing like description: source1: source2: source3 and the latter printing in a multi-line format.

These are just what I know off the top of my head. Printing the whole chain is extremely common when logging errors.

And I don't see how this is in conflict with what you want. Your rationale only matters for the Display impl, it does not justify the current behavior of source(). You want users who just print the error and not the whole chain to see the immediate cause, I get that. And you can still do that, just fix source() to skip that immediate cause and instead print the next one (if any). With that changed, everyone who prints just the error will see the same behavior as today, and anyone who prints the chain will stop seeing duplicated causes.

[lilyball]

I just realized that the error I quoted above (err=error trying to connect: tcp connect error: Connection refused (os error 61) err.sources=[tcp connect error: Connection refused (os error 61), Connection refused (os error 61)]¹) actually demonstrates that hyper::client::connect::http::ConnectError (which is not publicly exported) has this exact same behavior, where it prints the cause with its description. And there's no way to work around this, there's no way to get the equivalent of calling hyper::Error::message(), since I can't name the type, and even if I could I would have no way of knowing the full set of possible underlying errors that do this same thing.

I understand your rationale for this behavior on hyper::Error, but that rationale does not hold up for nested error types. ConnectError must not cause with its description. This type is never handed back to the user directly (it's always wrapped in hyper::Error) which means it doesn't need special behavior. I assume you would still like hyper::Error's description here to print the full error trying to connect: tcp connect error: Connection refused (os error 61), but you can handle that internally². Regardless of what hyper::Error does with its own description, its source() must be usable for error chain processing.

Footnotes

1. This looks even worse with how I'm actually printing errors. What I'm actually seeing in my logs is error trying to connect: tcp connect error: Connection refused (os error 61): tcp connect error: Connection refused (os error 61): Connection refused (os error 61) since I'm not using the default tracing-subscriber field formatter. ↩

2. Either just walk the whole chain in <hyper::Error as Display>::fmt(), or downcast if you only want to do this for specific internal errors, or even introduce an internal trait that controls this process and use a transparent wrapper struct for any possible causes you don't want to do this for. ↩

[davidpdrsn]

I work around that like so

struct DedupHyperErrorSources {
    error: hyper::Error,
}

impl DedupHyperErrorSources {
    fn new(error: hyper::Error) -> Self {
        Self { error }
    }
}

impl fmt::Debug for DedupHyperErrorSources {
    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
        self.error.fmt(f)
    }
}

impl fmt::Display for DedupHyperErrorSources {
    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
        write!(f, "{}", self.error.message())
    }
}

impl std::error::Error for DedupHyperErrorSources {
    fn source(&self) -> Option<&(dyn std::error::Error + 'static)> {
        if self.error.is_connect() {
            // hyper's internal `ConnectError` also includes the source in its `Display` impl but
            // otherwise doesn't add anything valuable to the source chain. So we can just skip it.
            self.error.source()?.source()
        } else {
            self.error.source()
        }
    }
}

[lilyball]

@davidpdrsn Have you confirmed that no other wrapped error has the same behavior? Since hyper::Error internally wraps a Box<dyn StdError + Send + Sync> it's not easy to audit the full set of potential wrapped errors. I'm also concerned that this approach isn't future-proof (and also that users are required to do this at all).

I'm tempted to just accept the current Display and use a wrapper type that makes source() return None, except I can't even do that because any wrapped errors that don't print their source too (like ConnectError) would then result in losing access to those underlying errors.

Edit: Also, by skipping the ConnectError, you're actually omitting that from the display chain entirely. The way that one has to be handled is by using another wrapper error type that formats it and then skips its immediate source. Because it's a private type there's no possibility of having an analogous message() accessor and so there's no way around its Display impl.

[lilyball]

Also digging through this now, it appears as though the is_connected() type is not actually guaranteed to be ConnectError at all. It is in fact the error type from the associated connector service. hyper::client::HttpConnector returns this ConnectError type, but other connectors can return different types. And in particular, hyper_rustls::HttpsConnector returns a Box<dyn StdError + Send + Sync>. The error it returns may be the error from its underlying connector (which is likely HttpConnector and therefore ConnectError), or it may be a std::io::Error (which may or may not itself be wrapping another error).

Which is to say, assuming that is_connected() means it's a ConnectError is not safe. For now I can downcast it to std::io::Error first, but this is fragile as it's making assumptions about my connector.

[davidpdrsn]

Have you confirmed that no other wrapped error has the same behavior?

I looked through hyper's errors and didn't find other errors that did this. Whether there are errors elsewhere that exists in hyper's error chain, I'm not certain off. But what I posted works for my use case.

[lilyball]

@davidpdrsn I just looked myself as well and ConnectError does appear to be the only one, though is_connect() doesn't guarantee ConnectError.

In any case, your solution will lose the message "tcp connect error".

Unfortunately I can't wrap this error in another error type that formats the ConnectError but skips its first source, unless I want to wrap the hyper::Error in something like struct Wrapper { inner: Arc<hyper::Error>, cause: Option<Wrapper2> } where the second wrapper indirects into the source (the reason being that source() returns a reference and so I can't construct the wrapper on the spot, which means I need to pre-construct it with access to the error). This is very awkward. It would be easier if hyper::Error::message() didn't keep a borrow on the error (which it doesn't even need, it's actually returning a static string, but the declared types don't reflect that).

Edit: I suppose I overlooked the idea of just pre-formatting the message into a String and holding onto that, thus allowing us to wrap the hyper::Error for the ConnectError workaround up front without using Arc. Still, this is super awkward.

Edit 2: Oh, even better, my wrapper can just contain another wrapper around the error and access the message through that second wrapper, and that second wrapper can then do the ConnectInfo workaround. Still, super hacky.

[julianskartor]

I've also run into this issue. I'm indirectly using hyper through tonic and simply wrapping it in anyhow::Error and logging with {:#} to get the whole chain produces this error.

[seanmonstar]

To wrap up here, this behavior was changed in 1.0. It now only prints the current error, not the source too.