Skip to content

reduce log level on requests that will not be retried #1031

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 3 commits into from
Aug 23, 2022

Conversation

bmc-msft
Copy link
Contributor

This log entry generates errors on multiple common patterns that should not result in the SDK generating error logs.

As an example, the recommended method for checking if a blob exists is to read it's properties. If a blob does not exist, it generates a 404 response, which causes an error here.

Given the SDK returns an error, this should be left up to the SDK consumer if these warrants logging an error.

This log entry generates errors on multiple common patterns that should not result in the SDK generating error logs.

As an example, the recommended method for checking if a blob exists is to read it's properties.  If a blob does not exist, it generates a 404 response, which causes an error here.

Given the SDK returns an error, this should be left up to the SDK consumer if this warrants logging an error.
@@ -101,7 +101,7 @@ where
);
error
} else {
log::error!("non-io error occurred which will not be retried: {}", error);
log::debug!("non-io error occurred which will not be retried: {}", error);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The change above makes a lot of sense. But the errors here are all non-HTTP errors. Wouldn't logging at an error level still make sense?

@gorzell
Copy link
Contributor

gorzell commented Aug 22, 2022

I am actually wondering if the SDK should log at all in the case where it is returning a Result? Shouldn't the caller get to decide if they want to log then, that way the SDK isn't polluting the applications logs. A lower level is a step in the right direction, but unless there is some information in the log that isn't available in the error, I am not sure I see the point, and even then I would think it would be better to just that information in the Error.

As an example, we haven't found the SDK logs to be terribly helpful because we use the tracing library for logging and include a number of extra fields for more context and easier searching, these are always missing on the SDK logs, and we usually log the error ourselves, making the SDK logs duplicative.

@rylev
Copy link
Contributor

rylev commented Aug 22, 2022

Shouldn't the caller get to decide if they want to log then, that way the SDK isn't polluting the applications logs

The caller can trivially filter out the SDKs logs - e.g., log_env allows the user to set which crates they want logs from. I think the SDK should be giving enough information for users of the SDK to have a good idea of what's happening.

The logs here give additional information about what is happening inside of the retry policy. It can be helpful to know what the state of the retry policy is. I've personally used these logs to understand which errors were being retried.

@gorzell
Copy link
Contributor

gorzell commented Aug 22, 2022

The logs here give additional information about what is happening inside of the retry policy. It can be helpful to know what the state of the retry policy is. I've personally used these logs to understand which errors were being retried.

Sorry, I wasn't suggesting that all logging should be removed. Retry state is a really good example of something that is useful because it can present internal state the caller wouldn't otherwise see. I just think that the pattern of logging an Error right before you return that error and with no extra information in the log message is perhaps a bit excessive.

@bmc-msft
Copy link
Contributor Author

The logs here give additional information about what is happening inside of the retry policy. It can be helpful to know what the state of the retry policy is. I've personally used these logs to understand which errors were being retried.

Sorry, I wasn't suggesting that all logging should be removed. Retry state is a really good example of something that is useful because it can present internal state the caller wouldn't otherwise see. I just think that the pattern of logging an Error right before you return that error and with no extra information in the log message is perhaps a bit excessive.

@gorzell identifies the specific concern I was trying to address with this PR.

My thought is that logging an error condition and returning an Error with the same detail isn't needed. The must use requirement of Results means users will get this information that would have been logged.

@rylev
Copy link
Contributor

rylev commented Aug 22, 2022

I believe that the logs do encode additional information. The user won't necessarily be familiar with the workings on the retry policy, and thus they may not know that for example, a 419 does not get retried by a 503 does. These logs alert the user that an error has occurred (something they may already know) which will not be retried (potentially new information).

@bmc-msft
Copy link
Contributor Author

Would it be an acceptable compromise to add that information as context to the error such that the control as to what to do with the information is in the hands of the consumer, including acting on the issue?

@gorzell
Copy link
Contributor

gorzell commented Aug 22, 2022

Would it be an acceptable compromise to add that information as context to the error such that the control as to what to do with the information is in the hands of the consumer, including acting on the issue?

Improving the information/context in the Error would be my strong preference for providing additional information to the caller (when possible/practical).

@rylev
Copy link
Contributor

rylev commented Aug 23, 2022

Would it be an acceptable compromise to add that information as context to the error such that the control as to what to do with the information is in the hands of the consumer, including acting on the issue?

I suppose so? I still don't quite understand why this log is problematic. It provides additional context in a way that can trivially filtered from logs if users don't want that level of detail. The fact that the error won't be retried isn't really context about the error but rather context to understand how your operation is being processed. It makes more sense to me that it would be logged and not attached to the error, but I'm obviously missing something here 😊

@bmc-msft bmc-msft requested a review from rylev August 23, 2022 18:13
Copy link
Contributor

@rylev rylev left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I still think logging makes more sense, but I'm happy to see this land if that's what everyone else thinks is the right path forward.

@bmc-msft bmc-msft merged commit 05afb87 into Azure:main Aug 23, 2022
@bmc-msft bmc-msft deleted the reduce-error-logging-on-no-retry branch August 23, 2022 19:38
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants