ramosbugs / oauth2-rs

Extensible, strongly-typed Rust OAuth2 client library
Apache License 2.0
939 stars 163 forks source link

feat(logging): instrument tracing into http clients #252

Closed seanpianka closed 8 months ago

seanpianka commented 9 months ago

This commit adds logging for consuming crates which enable and opt-in to tracing. These logs are configurable via the usual means, but can be tuned if other details are necessary or should be excluded.

Perhaps some of the request and response details should be omitted, however I have had difficulty troubleshooting my SSO integrations as the oauth2 library only returns "Server returned an error response" rather than the actual response details such as "invalid_grant" with related details. The HTTP response is printed out in a Vec and has to be converted to ASCII manually, but this at least opens the possibility for further debugging in-code.

ramosbugs commented 9 months ago

I'm open to considering trace instrumentation, but I think it should be behind a non-default feature flag to avoid adding more required dependencies, which some users are sensitive to. We also need to be careful about which fields will be logged; access/refresh/CSRF tokens and any other secrets must never be logged by this instrumentation (if users want secrets to be logged, they'll need to do it explicitly within their code).

I have had difficulty troubleshooting my SSO integrations as the oauth2 library only returns "Server returned an error response" rather than the actual response details such as "invalid_grant" with related details.

The RequestTokenError variants are public, so users can pretty easily match on RequestTokenError::ServerResponse in their error handling code to inspect the contents of the server's error response. That response is a generic type for extensibility (i.e., some servers might return additional fields that users can access by using custom types instead of StandardErrorResponse), which is why its fields aren't printed as part of RequestTokenError's Display trait implementation.

I'd be open to adding some new trait methods to ErrorResponse that would allow RequestTokenError's Display implementation to access the error/error_description/error_uri fields for better output, but that would be a breaking change. Still, it's probably worth doing since that would help users debug the majority of errors they're likely to run into. I'll see if I can make this change soon.

The HTTP response is printed out in a Vec and has to be converted to ASCII manually, but this at least opens the possibility for further debugging in-code.

Are you referring to the Debug trait's output for RequestTokenError::Parse? That's represented as a byte sequence because the UTF-8 conversion may have failed to parse, and all Rust strings must be valid UTF-8. Users are free to match on the error variants in their own code and convert the output to any format they find useful. Even if it were a String, it wouldn't be safe to print as part of the Display implementation (the typical trait used for printing errors returned by libraries) because it may contain secrets.

For debugging parse errors (or really, any errors), I highly recommend walking over the Error::source chain to access each underlying error, which is a conventional error handling approach in Rust. Each error represents an exception at one layer of abstraction, and the source method returns the underlying cause from next layer of abstraction down (serde, I/O errors, etc.). See example. I'd recommend something like this when printing any errors in Rust. With this approach, you end up with more useful output such as:

ERROR: Failed to parse server response
    caused by: expires_in: invalid type: string "3599", expected u64 at line 1 column 42
    caused by: invalid type: string "3599", expected u64 at line 1 column 42
ramosbugs commented 9 months ago

I made some improvements to the RequestTokenError::ServerResponse output in 96c6f9b17b5fdea98a6a7b84bec8e420671342eb. Feel free to test out the latest version of the main branch and let me know if that resolves some of your issues. This will be part of the next major release, which will probably wait for some other pending breaking changes to be merged (e.g., #237)

seanpianka commented 8 months ago

I appreciate your thoughtful responses so quickly after I opened this PR. Were you to add tracing, it certainly makes sense to gate it with a feature flag if you know there's performance sensitive consumers of this package.

It hadn't occurred to me to match on the error type until you mentioned it, but I see that there's considerably more detail available in doing so. The AWS SDK has this same pattern, and your comments helped me debug my code elsewhere with your explanation of this pattern!

I've not used the chaining of an Error's source for my debugging much either, that's another thing I'll have to explore and understand. Thanks your example and all your help, I'll leave the proper implementation of this instrumentation to you 🙂