-
Notifications
You must be signed in to change notification settings - Fork 10.6k
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
grpclb: Improved logging #13332
grpclb: Improved logging #13332
Conversation
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Comments are all cosmetic. Feel free to merge after addressing.
@@ -175,6 +175,9 @@ typedef struct wrapped_rr_closure_arg { | |||
/* The RR instance related to the closure */ | |||
grpc_lb_policy* rr_policy; | |||
|
|||
/* The grpclb instance that created the wrapping */ |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Might be a good idea to note that we're not holding a ref to the LB policy; the field is just here to provide the pointer value for log messages.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Done
@@ -647,7 +654,7 @@ static bool pick_from_internal_rr_locked( | |||
if (server->drop) { | |||
// Not using the RR policy, so unref it. | |||
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) { | |||
gpr_log(GPR_INFO, "Unreffing RR for drop (0x%" PRIxPTR ")", | |||
gpr_log(GPR_INFO, "[grpclb %p] Unreffing RR %p for drop", glb_policy, | |||
(intptr_t)wc_arg->rr_policy); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I don't think we need the intptr_t
cast here.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Done
(unsigned long)glb_policy->serverlist->num_servers, | ||
(void*)glb_policy->rr_policy); | ||
"[grpclb %p] Failure creating a RoundRobin policy for serverlist " | ||
"update with %lu entries. The previous RR instance (%p), if any, " |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Suggest using PRIuPTR
here to avoid the cast.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Done
@@ -1708,10 +1726,11 @@ static void lb_on_server_status_received_locked(grpc_exec_ctx* exec_ctx, | |||
char* status_details = | |||
grpc_slice_to_c_string(glb_policy->lb_call_status_details); | |||
gpr_log(GPR_INFO, | |||
"Status from LB server received. Status = %d, Details = '%s', " | |||
"[grpclb %p] Status from LB server received. Status = %d, Details " | |||
"= '%s', " | |||
"(call: %p), error %p", |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Logging the address of the error doesn't seem very useful. Why not log grpc_error_string(error)
instead?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Done
@@ -213,7 +217,8 @@ static void wrapped_rr_closure(grpc_exec_ctx* exec_ctx, void* arg, | |||
grpc_grpclb_client_stats_unref(wc_arg->client_stats); | |||
} | |||
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) { | |||
gpr_log(GPR_INFO, "Unreffing RR %p", (void*)wc_arg->rr_policy); | |||
gpr_log(GPR_INFO, "[grpclb %p] Unreffing RR %p", wc_arg->glb_policy, |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think that all of the gpr_log()
calls inside of a if (GRPC_TRACER_ON(grpc_lb_glb_trace))
block should use GPR_DEBUG
instead of GPR_INFO
.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Do we have any guideline about this? I think those concerns are independent.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I don't think we've historically paid enough attention to this, but in general I think trace information belongs at the debug log level. But we certainly don't need to hold up this PR for that if you don't want to.
@@ -1261,8 +1270,7 @@ static void lb_call_on_retry_timer_locked(grpc_exec_ctx* exec_ctx, void* arg, | |||
glb_policy->retry_timer_active = false; | |||
if (!glb_policy->shutting_down && error == GRPC_ERROR_NONE) { | |||
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) { | |||
gpr_log(GPR_INFO, "Restaring call to LB server (grpclb %p)", | |||
(void*)glb_policy); | |||
gpr_log(GPR_INFO, "[grpclb %p] Restaring call to LB server", glb_policy); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
typo: "Restaring" instead of "Restarting"
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Done
@@ -175,7 +175,8 @@ typedef struct wrapped_rr_closure_arg { | |||
/* The RR instance related to the closure */ | |||
grpc_lb_policy* rr_policy; | |||
|
|||
/* The grpclb instance that created the wrapping */ | |||
/* The grpclb instance that created the wrapping. This instance is not owned, | |||
* reference counts are untouched. Its used only for logging purposes. */ |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
s/Its/It's/
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Uuuugh, one of my pet peeves. The shame... fixed.
@@ -213,7 +217,8 @@ static void wrapped_rr_closure(grpc_exec_ctx* exec_ctx, void* arg, | |||
grpc_grpclb_client_stats_unref(wc_arg->client_stats); | |||
} | |||
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) { | |||
gpr_log(GPR_INFO, "Unreffing RR %p", (void*)wc_arg->rr_policy); | |||
gpr_log(GPR_INFO, "[grpclb %p] Unreffing RR %p", wc_arg->glb_policy, |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I don't think we've historically paid enough attention to this, but in general I think trace information belongs at the debug log level. But we certainly don't need to hold up this PR for that if you don't want to.
"to be used. Future updates from the LB will attempt to create new " | ||
"[grpclb %p] Failure creating a RoundRobin policy for serverlist " | ||
"update with %" PRIuPTR | ||
" entries. The previous RR instance (%p), if any, will continue to " |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Nit: This line can be moved up to the end of the previous line.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I tried. Clang-format insists on putting it there :/
|
|
|
No description provided.