diff options
Diffstat (limited to 'src/core/ext/filters')
7 files changed, 118 insertions, 121 deletions
diff --git a/src/core/ext/filters/client_channel/client_channel.cc b/src/core/ext/filters/client_channel/client_channel.cc index 33cf56519e..875af66168 100644 --- a/src/core/ext/filters/client_channel/client_channel.cc +++ b/src/core/ext/filters/client_channel/client_channel.cc @@ -174,7 +174,7 @@ static void set_channel_connectivity_state_locked(channel_data* chand, } } if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p: setting connectivity state to %s", chand, + gpr_log(GPR_INFO, "chand=%p: setting connectivity state to %s", chand, grpc_connectivity_state_name(state)); } grpc_connectivity_state_set(&chand->state_tracker, state, error, reason); @@ -186,7 +186,7 @@ static void on_lb_policy_state_changed_locked(void* arg, grpc_error* error) { /* check if the notification is for the latest policy */ if (w->lb_policy == w->chand->lb_policy.get()) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p: lb_policy=%p state changed to %s", w->chand, + gpr_log(GPR_INFO, "chand=%p: lb_policy=%p state changed to %s", w->chand, w->lb_policy, grpc_connectivity_state_name(w->state)); } set_channel_connectivity_state_locked(w->chand, w->state, @@ -215,7 +215,7 @@ static void watch_lb_policy_locked(channel_data* chand, static void start_resolving_locked(channel_data* chand) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p: starting name resolution", chand); + gpr_log(GPR_INFO, "chand=%p: starting name resolution", chand); } GPR_ASSERT(!chand->started_resolving); chand->started_resolving = true; @@ -297,7 +297,7 @@ static void request_reresolution_locked(void* arg, grpc_error* error) { return; } if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p: started name re-resolving", chand); + gpr_log(GPR_INFO, "chand=%p: started name re-resolving", chand); } chand->resolver->RequestReresolutionLocked(); // Give back the closure to the LB policy. @@ -311,7 +311,7 @@ static void request_reresolution_locked(void* arg, grpc_error* error) { static void on_resolver_result_changed_locked(void* arg, grpc_error* error) { channel_data* chand = static_cast<channel_data*>(arg); if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p: got resolver result: resolver_result=%p error=%s", chand, chand->resolver_result, grpc_error_string(error)); } @@ -431,7 +431,7 @@ static void on_resolver_result_changed_locked(void* arg, grpc_error* error) { } } if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p: resolver result: lb_policy_name=\"%s\"%s, " "service_config=\"%s\"", chand, lb_policy_name_dup, @@ -466,7 +466,7 @@ static void on_resolver_result_changed_locked(void* arg, grpc_error* error) { chand->resolver == nullptr) { if (chand->lb_policy != nullptr) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p: unreffing lb_policy=%p", chand, + gpr_log(GPR_INFO, "chand=%p: unreffing lb_policy=%p", chand, chand->lb_policy.get()); } grpc_pollset_set_del_pollset_set(chand->lb_policy->interested_parties(), @@ -480,11 +480,11 @@ static void on_resolver_result_changed_locked(void* arg, grpc_error* error) { // error or shutdown. if (error != GRPC_ERROR_NONE || chand->resolver == nullptr) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p: shutting down", chand); + gpr_log(GPR_INFO, "chand=%p: shutting down", chand); } if (chand->resolver != nullptr) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p: shutting down resolver", chand); + gpr_log(GPR_INFO, "chand=%p: shutting down resolver", chand); } chand->resolver.reset(); } @@ -506,7 +506,7 @@ static void on_resolver_result_changed_locked(void* arg, grpc_error* error) { GRPC_ERROR_CREATE_FROM_STATIC_STRING("No load balancing policy"); if (lb_policy_created) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p: initializing new LB policy", chand); + gpr_log(GPR_INFO, "chand=%p: initializing new LB policy", chand); } GRPC_ERROR_UNREF(state_error); state = chand->lb_policy->CheckConnectivityLocked(&state_error); @@ -999,7 +999,7 @@ static void maybe_cache_send_ops_for_batch(call_data* calld, static void free_cached_send_initial_metadata(channel_data* chand, call_data* calld) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: destroying calld->send_initial_metadata", chand, calld); } @@ -1010,7 +1010,7 @@ static void free_cached_send_initial_metadata(channel_data* chand, static void free_cached_send_message(channel_data* chand, call_data* calld, size_t idx) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: destroying calld->send_messages[%" PRIuPTR "]", chand, calld, idx); } @@ -1021,7 +1021,7 @@ static void free_cached_send_message(channel_data* chand, call_data* calld, static void free_cached_send_trailing_metadata(channel_data* chand, call_data* calld) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: destroying calld->send_trailing_metadata", chand, calld); } @@ -1088,7 +1088,7 @@ static void pending_batches_add(grpc_call_element* elem, call_data* calld = static_cast<call_data*>(elem->call_data); const size_t idx = get_batch_index(batch); if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: adding pending batch at index %" PRIuPTR, chand, calld, idx); } @@ -1116,7 +1116,7 @@ static void pending_batches_add(grpc_call_element* elem, } if (calld->bytes_buffered_for_retry > chand->per_rpc_retry_buffer_size) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: exceeded retry buffer size, committing", chand, calld); } @@ -1131,7 +1131,7 @@ static void pending_batches_add(grpc_call_element* elem, // retries are disabled so that we don't bother with retry overhead. if (calld->num_attempts_completed == 0) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: disabling retries before first attempt", chand, calld); } @@ -1178,7 +1178,7 @@ static void pending_batches_fail(grpc_call_element* elem, grpc_error* error, for (size_t i = 0; i < GPR_ARRAY_SIZE(calld->pending_batches); ++i) { if (calld->pending_batches[i].batch != nullptr) ++num_batches; } - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: failing %" PRIuPTR " pending batches: %s", elem->channel_data, calld, num_batches, grpc_error_string(error)); } @@ -1240,7 +1240,7 @@ static void pending_batches_resume(grpc_call_element* elem) { for (size_t i = 0; i < GPR_ARRAY_SIZE(calld->pending_batches); ++i) { if (calld->pending_batches[i].batch != nullptr) ++num_batches; } - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: starting %" PRIuPTR " pending batches on subchannel_call=%p", chand, calld, num_batches, calld->subchannel_call); @@ -1285,7 +1285,7 @@ static void maybe_clear_pending_batch(grpc_call_element* elem, (!batch->recv_message || batch->payload->recv_message.recv_message_ready == nullptr)) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: clearing pending batch", chand, + gpr_log(GPR_INFO, "chand=%p calld=%p: clearing pending batch", chand, calld); } pending_batch_clear(calld, pending); @@ -1375,7 +1375,7 @@ static void retry_commit(grpc_call_element* elem, if (calld->retry_committed) return; calld->retry_committed = true; if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: committing retries", chand, calld); + gpr_log(GPR_INFO, "chand=%p calld=%p: committing retries", chand, calld); } if (retry_state != nullptr) { free_cached_send_op_data_after_commit(elem, retry_state); @@ -1420,7 +1420,7 @@ static void do_retry(grpc_call_element* elem, next_attempt_time = calld->retry_backoff->NextAttemptTime(); } if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: retrying failed call in %" PRIuPTR " ms", chand, calld, next_attempt_time - grpc_core::ExecCtx::Get()->Now()); } @@ -1454,7 +1454,7 @@ static bool maybe_retry(grpc_call_element* elem, batch_data->subchannel_call)); if (retry_state->retry_dispatched) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: retry already dispatched", chand, + gpr_log(GPR_INFO, "chand=%p calld=%p: retry already dispatched", chand, calld); } return true; @@ -1466,14 +1466,14 @@ static bool maybe_retry(grpc_call_element* elem, calld->retry_throttle_data->RecordSuccess(); } if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: call succeeded", chand, calld); + gpr_log(GPR_INFO, "chand=%p calld=%p: call succeeded", chand, calld); } return false; } // Status is not OK. Check whether the status is retryable. if (!retry_policy->retryable_status_codes.Contains(status)) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: status %s not configured as retryable", chand, calld, grpc_status_code_to_string(status)); } @@ -1489,14 +1489,14 @@ static bool maybe_retry(grpc_call_element* elem, if (calld->retry_throttle_data != nullptr && !calld->retry_throttle_data->RecordFailure()) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: retries throttled", chand, calld); + gpr_log(GPR_INFO, "chand=%p calld=%p: retries throttled", chand, calld); } return false; } // Check whether the call is committed. if (calld->retry_committed) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: retries already committed", chand, + gpr_log(GPR_INFO, "chand=%p calld=%p: retries already committed", chand, calld); } return false; @@ -1505,7 +1505,7 @@ static bool maybe_retry(grpc_call_element* elem, ++calld->num_attempts_completed; if (calld->num_attempts_completed >= retry_policy->max_attempts) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: exceeded %d retry attempts", chand, + gpr_log(GPR_INFO, "chand=%p calld=%p: exceeded %d retry attempts", chand, calld, retry_policy->max_attempts); } return false; @@ -1513,7 +1513,7 @@ static bool maybe_retry(grpc_call_element* elem, // If the call was cancelled from the surface, don't retry. if (calld->cancel_error != GRPC_ERROR_NONE) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: call cancelled from surface, not retrying", chand, calld); } @@ -1526,16 +1526,15 @@ static bool maybe_retry(grpc_call_element* elem, uint32_t ms; if (!grpc_parse_slice_to_uint32(GRPC_MDVALUE(*server_pushback_md), &ms)) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: not retrying due to server push-back", chand, calld); } return false; } else { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, - "chand=%p calld=%p: server push-back: retry in %u ms", chand, - calld, ms); + gpr_log(GPR_INFO, "chand=%p calld=%p: server push-back: retry in %u ms", + chand, calld, ms); } server_pushback_ms = (grpc_millis)ms; } @@ -1608,7 +1607,7 @@ static void invoke_recv_initial_metadata_callback(void* arg, batch->payload->recv_initial_metadata.recv_initial_metadata_ready != nullptr) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: invoking recv_initial_metadata_ready for " "pending batch at index %" PRIuPTR, chand, calld, i); @@ -1644,7 +1643,7 @@ static void recv_initial_metadata_ready(void* arg, grpc_error* error) { channel_data* chand = static_cast<channel_data*>(elem->channel_data); call_data* calld = static_cast<call_data*>(elem->call_data); if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: got recv_initial_metadata_ready, error=%s", chand, calld, grpc_error_string(error)); } @@ -1659,7 +1658,7 @@ static void recv_initial_metadata_ready(void* arg, grpc_error* error) { if ((batch_data->trailing_metadata_available || error != GRPC_ERROR_NONE) && !retry_state->completed_recv_trailing_metadata) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: deferring recv_initial_metadata_ready " "(Trailers-Only)", chand, calld); @@ -1701,7 +1700,7 @@ static void invoke_recv_message_callback(void* arg, grpc_error* error) { if (batch != nullptr && batch->recv_message && batch->payload->recv_message.recv_message_ready != nullptr) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: invoking recv_message_ready for " "pending batch at index %" PRIuPTR, chand, calld, i); @@ -1734,7 +1733,7 @@ static void recv_message_ready(void* arg, grpc_error* error) { channel_data* chand = static_cast<channel_data*>(elem->channel_data); call_data* calld = static_cast<call_data*>(elem->call_data); if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: got recv_message_ready, error=%s", + gpr_log(GPR_INFO, "chand=%p calld=%p: got recv_message_ready, error=%s", chand, calld, grpc_error_string(error)); } subchannel_call_retry_state* retry_state = @@ -1748,7 +1747,7 @@ static void recv_message_ready(void* arg, grpc_error* error) { if ((batch_data->recv_message == nullptr || error != GRPC_ERROR_NONE) && !retry_state->completed_recv_trailing_metadata) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: deferring recv_message_ready (nullptr " "message and recv_trailing_metadata pending)", chand, calld); @@ -1796,7 +1795,7 @@ static void execute_closures_in_call_combiner(grpc_call_element* elem, // have to re-enter the call combiner. if (num_closures > 0) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: %s starting closure: %s", chand, + gpr_log(GPR_INFO, "chand=%p calld=%p: %s starting closure: %s", chand, calld, caller, closures[0].reason); } GRPC_CLOSURE_SCHED(closures[0].closure, closures[0].error); @@ -1805,7 +1804,7 @@ static void execute_closures_in_call_combiner(grpc_call_element* elem, } for (size_t i = 1; i < num_closures; ++i) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: %s starting closure in call combiner: %s", chand, calld, caller, closures[i].reason); } @@ -1817,7 +1816,7 @@ static void execute_closures_in_call_combiner(grpc_call_element* elem, } } else { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: no closures to run for %s", chand, + gpr_log(GPR_INFO, "chand=%p calld=%p: no closures to run for %s", chand, calld, caller); } GRPC_CALL_COMBINER_STOP(calld->call_combiner, "no closures to run"); @@ -1912,7 +1911,7 @@ static void add_closures_for_replay_or_pending_send_ops( } if (have_pending_send_message_ops || have_pending_send_trailing_metadata_op) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: starting next batch for pending send op(s)", chand, calld); } @@ -1937,7 +1936,7 @@ static void add_closures_for_completed_pending_batches( pending_batch* pending = &calld->pending_batches[i]; if (pending_batch_is_completed(pending, calld, retry_state)) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: pending batch completed at index %" PRIuPTR, chand, calld, i); } @@ -1970,7 +1969,7 @@ static void add_closures_to_fail_unstarted_pending_batches( pending_batch* pending = &calld->pending_batches[i]; if (pending_batch_is_unstarted(pending, calld, retry_state)) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: failing unstarted pending batch at index " "%" PRIuPTR, chand, calld, i); @@ -2014,7 +2013,7 @@ static void on_complete(void* arg, grpc_error* error) { call_data* calld = static_cast<call_data*>(elem->call_data); if (grpc_client_channel_trace.enabled()) { char* batch_str = grpc_transport_stream_op_batch_string(&batch_data->batch); - gpr_log(GPR_DEBUG, "chand=%p calld=%p: got on_complete, error=%s, batch=%s", + gpr_log(GPR_INFO, "chand=%p calld=%p: got on_complete, error=%s, batch=%s", chand, calld, grpc_error_string(error), batch_str); gpr_free(batch_str); } @@ -2031,7 +2030,7 @@ static void on_complete(void* arg, grpc_error* error) { update_retry_state_for_completed_batch(batch_data, retry_state); if (call_finished) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: call already finished", chand, + gpr_log(GPR_INFO, "chand=%p calld=%p: call already finished", chand, calld); } } else { @@ -2059,7 +2058,7 @@ static void on_complete(void* arg, grpc_error* error) { // If the call just finished, check if we should retry. if (call_finished) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: call finished, status=%s", chand, + gpr_log(GPR_INFO, "chand=%p calld=%p: call finished, status=%s", chand, calld, grpc_status_code_to_string(status)); } if (maybe_retry(elem, batch_data, status, server_pushback_md)) { @@ -2224,7 +2223,7 @@ static void add_retriable_send_message_op( channel_data* chand = static_cast<channel_data*>(elem->channel_data); call_data* calld = static_cast<call_data*>(elem->call_data); if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: starting calld->send_messages[%" PRIuPTR "]", chand, calld, retry_state->started_send_message_count); } @@ -2311,7 +2310,7 @@ static void start_internal_recv_trailing_metadata(grpc_call_element* elem) { channel_data* chand = static_cast<channel_data*>(elem->channel_data); call_data* calld = static_cast<call_data*>(elem->call_data); if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: call failed but recv_trailing_metadata not " "started; starting it internally", chand, calld); @@ -2343,7 +2342,7 @@ static subchannel_batch_data* maybe_create_subchannel_batch_for_replay( !retry_state->started_send_initial_metadata && !calld->pending_send_initial_metadata) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: replaying previously completed " "send_initial_metadata op", chand, calld); @@ -2359,7 +2358,7 @@ static subchannel_batch_data* maybe_create_subchannel_batch_for_replay( retry_state->completed_send_message_count && !calld->pending_send_message) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: replaying previously completed " "send_message op", chand, calld); @@ -2378,7 +2377,7 @@ static subchannel_batch_data* maybe_create_subchannel_batch_for_replay( !retry_state->started_send_trailing_metadata && !calld->pending_send_trailing_metadata) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: replaying previously completed " "send_trailing_metadata op", chand, calld); @@ -2518,7 +2517,7 @@ static void start_retriable_subchannel_batches(void* arg, grpc_error* ignored) { channel_data* chand = static_cast<channel_data*>(elem->channel_data); call_data* calld = static_cast<call_data*>(elem->call_data); if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: constructing retriable batches", + gpr_log(GPR_INFO, "chand=%p calld=%p: constructing retriable batches", chand, calld); } subchannel_call_retry_state* retry_state = @@ -2541,7 +2540,7 @@ static void start_retriable_subchannel_batches(void* arg, grpc_error* ignored) { &num_closures); // Start batches on subchannel call. if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: starting %" PRIuPTR " retriable batches on subchannel_call=%p", chand, calld, num_closures, calld->subchannel_call); @@ -2572,7 +2571,7 @@ static void create_subchannel_call(grpc_call_element* elem, grpc_error* error) { grpc_error* new_error = calld->pick.connected_subchannel->CreateCall( call_args, &calld->subchannel_call); if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: create subchannel_call=%p: error=%s", + gpr_log(GPR_INFO, "chand=%p calld=%p: create subchannel_call=%p: error=%s", chand, calld, calld->subchannel_call, grpc_error_string(new_error)); } if (new_error != GRPC_ERROR_NONE) { @@ -2613,7 +2612,7 @@ static void pick_done(void* arg, grpc_error* error) { : GRPC_ERROR_CREATE_REFERENCING_FROM_STATIC_STRING( "Failed to create subchannel", &error, 1); if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: failed to create subchannel: error=%s", chand, calld, grpc_error_string(new_error)); } @@ -2657,7 +2656,7 @@ static void pick_callback_cancel_locked(void* arg, grpc_error* error) { // the one we started it on. However, this will just be a no-op. if (error != GRPC_ERROR_NONE && chand->lb_policy != nullptr) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: cancelling pick from LB policy %p", + gpr_log(GPR_INFO, "chand=%p calld=%p: cancelling pick from LB policy %p", chand, calld, chand->lb_policy.get()); } chand->lb_policy->CancelPickLocked(&calld->pick, GRPC_ERROR_REF(error)); @@ -2672,8 +2671,8 @@ static void pick_callback_done_locked(void* arg, grpc_error* error) { channel_data* chand = static_cast<channel_data*>(elem->channel_data); call_data* calld = static_cast<call_data*>(elem->call_data); if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: pick completed asynchronously", - chand, calld); + gpr_log(GPR_INFO, "chand=%p calld=%p: pick completed asynchronously", chand, + calld); } async_pick_done_locked(elem, GRPC_ERROR_REF(error)); GRPC_CALL_STACK_UNREF(calld->owning_call, "pick_callback"); @@ -2685,7 +2684,7 @@ static void apply_service_config_to_call_locked(grpc_call_element* elem) { channel_data* chand = static_cast<channel_data*>(elem->channel_data); call_data* calld = static_cast<call_data*>(elem->call_data); if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: applying service config to call", + gpr_log(GPR_INFO, "chand=%p calld=%p: applying service config to call", chand, calld); } if (chand->retry_throttle_data != nullptr) { @@ -2723,8 +2722,8 @@ static bool pick_callback_start_locked(grpc_call_element* elem) { channel_data* chand = static_cast<channel_data*>(elem->channel_data); call_data* calld = static_cast<call_data*>(elem->call_data); if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: starting pick on lb_policy=%p", - chand, calld, chand->lb_policy.get()); + gpr_log(GPR_INFO, "chand=%p calld=%p: starting pick on lb_policy=%p", chand, + calld, chand->lb_policy.get()); } // Only get service config data on the first attempt. if (calld->num_attempts_completed == 0) { @@ -2771,7 +2770,7 @@ static bool pick_callback_start_locked(grpc_call_element* elem) { if (pick_done) { // Pick completed synchronously. if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: pick completed synchronously", + gpr_log(GPR_INFO, "chand=%p calld=%p: pick completed synchronously", chand, calld); } GRPC_CALL_STACK_UNREF(calld->owning_call, "pick_callback"); @@ -2815,7 +2814,7 @@ static void pick_after_resolver_result_cancel_locked(void* arg, channel_data* chand = static_cast<channel_data*>(elem->channel_data); call_data* calld = static_cast<call_data*>(elem->call_data); if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: cancelling pick waiting for resolver result", chand, calld); } @@ -2835,7 +2834,7 @@ static void pick_after_resolver_result_done_locked(void* arg, if (args->finished) { /* cancelled, do nothing */ if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "call cancelled before resolver result"); + gpr_log(GPR_INFO, "call cancelled before resolver result"); } gpr_free(args); return; @@ -2846,14 +2845,14 @@ static void pick_after_resolver_result_done_locked(void* arg, call_data* calld = static_cast<call_data*>(elem->call_data); if (error != GRPC_ERROR_NONE) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: resolver failed to return data", + gpr_log(GPR_INFO, "chand=%p calld=%p: resolver failed to return data", chand, calld); } async_pick_done_locked(elem, GRPC_ERROR_REF(error)); } else if (chand->resolver == nullptr) { // Shutting down. if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: resolver disconnected", chand, + gpr_log(GPR_INFO, "chand=%p calld=%p: resolver disconnected", chand, calld); } async_pick_done_locked( @@ -2869,7 +2868,7 @@ static void pick_after_resolver_result_done_locked(void* arg, .send_initial_metadata_flags; if (send_initial_metadata_flags & GRPC_INITIAL_METADATA_WAIT_FOR_READY) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: resolver returned but no LB policy; " "wait_for_ready=true; trying again", chand, calld); @@ -2877,7 +2876,7 @@ static void pick_after_resolver_result_done_locked(void* arg, pick_after_resolver_result_start_locked(elem); } else { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: resolver returned but no LB policy; " "wait_for_ready=false; failing", chand, calld); @@ -2890,7 +2889,7 @@ static void pick_after_resolver_result_done_locked(void* arg, } } else { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: resolver returned, doing pick", + gpr_log(GPR_INFO, "chand=%p calld=%p: resolver returned, doing pick", chand, calld); } if (pick_callback_start_locked(elem)) { @@ -2908,7 +2907,7 @@ static void pick_after_resolver_result_start_locked(grpc_call_element* elem) { channel_data* chand = static_cast<channel_data*>(elem->channel_data); call_data* calld = static_cast<call_data*>(elem->call_data); if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: deferring pick pending resolver result", chand, calld); } @@ -2975,7 +2974,7 @@ static void cc_start_transport_stream_op_batch( // If we've previously been cancelled, immediately fail any new batches. if (calld->cancel_error != GRPC_ERROR_NONE) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: failing batch with error: %s", + gpr_log(GPR_INFO, "chand=%p calld=%p: failing batch with error: %s", chand, calld, grpc_error_string(calld->cancel_error)); } // Note: This will release the call combiner. @@ -2994,7 +2993,7 @@ static void cc_start_transport_stream_op_batch( calld->cancel_error = GRPC_ERROR_REF(batch->payload->cancel_stream.cancel_error); if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: recording cancel_error=%s", chand, + gpr_log(GPR_INFO, "chand=%p calld=%p: recording cancel_error=%s", chand, calld, grpc_error_string(calld->cancel_error)); } // If we do not have a subchannel call (i.e., a pick has not yet @@ -3020,7 +3019,7 @@ static void cc_start_transport_stream_op_batch( // streaming calls). if (calld->subchannel_call != nullptr) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: starting batch on subchannel_call=%p", chand, calld, calld->subchannel_call); } @@ -3032,7 +3031,7 @@ static void cc_start_transport_stream_op_batch( // combiner to start a pick. if (batch->send_initial_metadata) { if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, "chand=%p calld=%p: entering client_channel combiner", + gpr_log(GPR_INFO, "chand=%p calld=%p: entering client_channel combiner", chand, calld); } GRPC_CLOSURE_SCHED( @@ -3042,7 +3041,7 @@ static void cc_start_transport_stream_op_batch( } else { // For all other batches, release the call combiner. if (grpc_client_channel_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "chand=%p calld=%p: saved batch, yeilding call combiner", chand, calld); } diff --git a/src/core/ext/filters/client_channel/lb_policy.cc b/src/core/ext/filters/client_channel/lb_policy.cc index fa63dd75b5..e065f45639 100644 --- a/src/core/ext/filters/client_channel/lb_policy.cc +++ b/src/core/ext/filters/client_channel/lb_policy.cc @@ -44,13 +44,13 @@ void LoadBalancingPolicy::TryReresolutionLocked( GRPC_CLOSURE_SCHED(request_reresolution_, error); request_reresolution_ = nullptr; if (grpc_lb_trace->enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "%s %p: scheduling re-resolution closure with error=%s.", grpc_lb_trace->name(), this, grpc_error_string(error)); } } else { if (grpc_lb_trace->enabled()) { - gpr_log(GPR_DEBUG, "%s %p: no available re-resolution closure.", + gpr_log(GPR_INFO, "%s %p: no available re-resolution closure.", grpc_lb_trace->name(), this); } } diff --git a/src/core/ext/filters/client_channel/lb_policy/grpclb/grpclb.cc b/src/core/ext/filters/client_channel/lb_policy/grpclb/grpclb.cc index 097ff112f9..1a675476f0 100644 --- a/src/core/ext/filters/client_channel/lb_policy/grpclb/grpclb.cc +++ b/src/core/ext/filters/client_channel/lb_policy/grpclb/grpclb.cc @@ -1247,7 +1247,7 @@ bool GrpcLb::PickLocked(PickState* pick) { } } else { // rr_policy_ == NULL if (grpc_lb_glb_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "[grpclb %p] No RR policy. Adding to grpclb's pending picks", this); } @@ -1413,14 +1413,13 @@ void GrpcLb::OnFallbackTimerLocked(void* arg, grpc_error* error) { void GrpcLb::StartBalancerCallRetryTimerLocked() { grpc_millis next_try = lb_call_backoff_.NextAttemptTime(); if (grpc_lb_glb_trace.enabled()) { - gpr_log(GPR_DEBUG, "[grpclb %p] Connection to LB server lost...", this); + gpr_log(GPR_INFO, "[grpclb %p] Connection to LB server lost...", this); grpc_millis timeout = next_try - ExecCtx::Get()->Now(); if (timeout > 0) { - gpr_log(GPR_DEBUG, - "[grpclb %p] ... retry_timer_active in %" PRIuPTR "ms.", this, - timeout); + gpr_log(GPR_INFO, "[grpclb %p] ... retry_timer_active in %" PRIuPTR "ms.", + this, timeout); } else { - gpr_log(GPR_DEBUG, "[grpclb %p] ... retry_timer_active immediately.", + gpr_log(GPR_INFO, "[grpclb %p] ... retry_timer_active immediately.", this); } } @@ -1728,7 +1727,7 @@ void GrpcLb::CreateOrUpdateRoundRobinPolicyLocked() { GPR_ASSERT(args != nullptr); if (rr_policy_ != nullptr) { if (grpc_lb_glb_trace.enabled()) { - gpr_log(GPR_DEBUG, "[grpclb %p] Updating RR policy %p", this, + gpr_log(GPR_INFO, "[grpclb %p] Updating RR policy %p", this, rr_policy_.get()); } rr_policy_->UpdateLocked(*args); @@ -1739,7 +1738,7 @@ void GrpcLb::CreateOrUpdateRoundRobinPolicyLocked() { lb_policy_args.args = args; CreateRoundRobinPolicyLocked(lb_policy_args); if (grpc_lb_glb_trace.enabled()) { - gpr_log(GPR_DEBUG, "[grpclb %p] Created new RR policy %p", this, + gpr_log(GPR_INFO, "[grpclb %p] Created new RR policy %p", this, rr_policy_.get()); } } @@ -1755,7 +1754,7 @@ void GrpcLb::OnRoundRobinRequestReresolutionLocked(void* arg, } if (grpc_lb_glb_trace.enabled()) { gpr_log( - GPR_DEBUG, + GPR_INFO, "[grpclb %p] Re-resolution requested from the internal RR policy (%p).", grpclb_policy, grpclb_policy->rr_policy_.get()); } diff --git a/src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc b/src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc index 9090c34412..a07e90322c 100644 --- a/src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc +++ b/src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc @@ -95,7 +95,7 @@ PickFirst::PickFirst(const Args& args) : LoadBalancingPolicy(args) { grpc_connectivity_state_init(&state_tracker_, GRPC_CHANNEL_IDLE, "pick_first"); if (grpc_lb_pick_first_trace.enabled()) { - gpr_log(GPR_DEBUG, "Pick First %p created.", this); + gpr_log(GPR_INFO, "Pick First %p created.", this); } UpdateLocked(*args.args); grpc_subchannel_index_ref(); @@ -103,7 +103,7 @@ PickFirst::PickFirst(const Args& args) : LoadBalancingPolicy(args) { PickFirst::~PickFirst() { if (grpc_lb_pick_first_trace.enabled()) { - gpr_log(GPR_DEBUG, "Destroying Pick First %p", this); + gpr_log(GPR_INFO, "Destroying Pick First %p", this); } GPR_ASSERT(subchannel_list_ == nullptr); GPR_ASSERT(latest_pending_subchannel_list_ == nullptr); @@ -126,7 +126,7 @@ void PickFirst::HandOffPendingPicksLocked(LoadBalancingPolicy* new_policy) { void PickFirst::ShutdownLocked() { grpc_error* error = GRPC_ERROR_CREATE_FROM_STATIC_STRING("Channel shutdown"); if (grpc_lb_pick_first_trace.enabled()) { - gpr_log(GPR_DEBUG, "Pick First %p Shutting down", this); + gpr_log(GPR_INFO, "Pick First %p Shutting down", this); } shutdown_ = true; PickState* pick; @@ -372,7 +372,7 @@ void PickFirst::UpdateLocked(const grpc_channel_args& args) { // subchannel list. if (latest_pending_subchannel_list_ != nullptr) { if (grpc_lb_pick_first_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "Pick First %p Shutting down latest pending subchannel list " "%p, about to be replaced by newer latest %p", this, latest_pending_subchannel_list_, subchannel_list); @@ -396,7 +396,7 @@ void PickFirst::OnConnectivityChangedLocked(void* arg, grpc_error* error) { grpc_lb_subchannel_data* sd = static_cast<grpc_lb_subchannel_data*>(arg); PickFirst* p = static_cast<PickFirst*>(sd->subchannel_list->policy); if (grpc_lb_pick_first_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "Pick First %p connectivity changed for subchannel %p (%" PRIuPTR " of %" PRIuPTR "), subchannel_list %p: state=%s p->shutdown_=%d " diff --git a/src/core/ext/filters/client_channel/lb_policy/round_robin/round_robin.cc b/src/core/ext/filters/client_channel/lb_policy/round_robin/round_robin.cc index e534131c02..b470016bd9 100644 --- a/src/core/ext/filters/client_channel/lb_policy/round_robin/round_robin.cc +++ b/src/core/ext/filters/client_channel/lb_policy/round_robin/round_robin.cc @@ -114,7 +114,7 @@ RoundRobin::RoundRobin(const Args& args) : LoadBalancingPolicy(args) { "round_robin"); UpdateLocked(*args.args); if (grpc_lb_round_robin_trace.enabled()) { - gpr_log(GPR_DEBUG, "[RR %p] Created with %" PRIuPTR " subchannels", this, + gpr_log(GPR_INFO, "[RR %p] Created with %" PRIuPTR " subchannels", this, subchannel_list_->num_subchannels); } grpc_subchannel_index_ref(); @@ -122,7 +122,7 @@ RoundRobin::RoundRobin(const Args& args) : LoadBalancingPolicy(args) { RoundRobin::~RoundRobin() { if (grpc_lb_round_robin_trace.enabled()) { - gpr_log(GPR_DEBUG, "[RR %p] Destroying Round Robin policy", this); + gpr_log(GPR_INFO, "[RR %p] Destroying Round Robin policy", this); } GPR_ASSERT(subchannel_list_ == nullptr); GPR_ASSERT(latest_pending_subchannel_list_ == nullptr); @@ -152,7 +152,7 @@ size_t RoundRobin::GetNextReadySubchannelIndexLocked() { subchannel_list_->num_subchannels; if (grpc_lb_round_robin_trace.enabled()) { gpr_log( - GPR_DEBUG, + GPR_INFO, "[RR %p] checking subchannel %p, subchannel_list %p, index %" PRIuPTR ": state=%s", this, subchannel_list_->subchannels[index].subchannel, @@ -163,7 +163,7 @@ size_t RoundRobin::GetNextReadySubchannelIndexLocked() { if (subchannel_list_->subchannels[index].curr_connectivity_state == GRPC_CHANNEL_READY) { if (grpc_lb_round_robin_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "[RR %p] found next ready subchannel (%p) at index %" PRIuPTR " of subchannel_list %p", this, subchannel_list_->subchannels[index].subchannel, index, @@ -173,7 +173,7 @@ size_t RoundRobin::GetNextReadySubchannelIndexLocked() { } } if (grpc_lb_round_robin_trace.enabled()) { - gpr_log(GPR_DEBUG, "[RR %p] no subchannels in ready state", this); + gpr_log(GPR_INFO, "[RR %p] no subchannels in ready state", this); } return subchannel_list_->num_subchannels; } @@ -183,7 +183,7 @@ void RoundRobin::UpdateLastReadySubchannelIndexLocked(size_t last_ready_index) { GPR_ASSERT(last_ready_index < subchannel_list_->num_subchannels); last_ready_subchannel_index_ = last_ready_index; if (grpc_lb_round_robin_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "[RR %p] setting last_ready_subchannel_index=%" PRIuPTR " (SC %p, CSC %p)", this, last_ready_index, @@ -207,7 +207,7 @@ void RoundRobin::HandOffPendingPicksLocked(LoadBalancingPolicy* new_policy) { void RoundRobin::ShutdownLocked() { grpc_error* error = GRPC_ERROR_CREATE_FROM_STATIC_STRING("Channel shutdown"); if (grpc_lb_round_robin_trace.enabled()) { - gpr_log(GPR_DEBUG, "[RR %p] Shutting down", this); + gpr_log(GPR_INFO, "[RR %p] Shutting down", this); } shutdown_ = true; PickState* pick; @@ -311,8 +311,7 @@ void RoundRobin::ExitIdleLocked() { bool RoundRobin::PickLocked(PickState* pick) { if (grpc_lb_round_robin_trace.enabled()) { - gpr_log(GPR_DEBUG, "[RR %p] Trying to pick (shutdown: %d)", this, - shutdown_); + gpr_log(GPR_INFO, "[RR %p] Trying to pick (shutdown: %d)", this, shutdown_); } GPR_ASSERT(!shutdown_); if (subchannel_list_ != nullptr) { @@ -327,7 +326,7 @@ bool RoundRobin::PickLocked(PickState* pick) { } if (grpc_lb_round_robin_trace.enabled()) { gpr_log( - GPR_DEBUG, + GPR_INFO, "[RR %p] Picked target <-- Subchannel %p (connected %p) (sl %p, " "index %" PRIuPTR ")", this, sd->subchannel, pick->connected_subchannel.get(), @@ -416,7 +415,7 @@ void RoundRobin::OnConnectivityChangedLocked(void* arg, grpc_error* error) { RoundRobin* p = static_cast<RoundRobin*>(sd->subchannel_list->policy); if (grpc_lb_round_robin_trace.enabled()) { gpr_log( - GPR_DEBUG, + GPR_INFO, "[RR %p] connectivity changed for subchannel %p, subchannel_list %p: " "prev_state=%s new_state=%s p->shutdown=%d " "sd->subchannel_list->shutting_down=%d error=%s", @@ -458,7 +457,7 @@ void RoundRobin::OnConnectivityChangedLocked(void* arg, grpc_error* error) { case GRPC_CHANNEL_TRANSIENT_FAILURE: { sd->connected_subchannel.reset(); if (grpc_lb_round_robin_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "[RR %p] Subchannel %p has gone into TRANSIENT_FAILURE. " "Requesting re-resolution", p, sd->subchannel); @@ -483,7 +482,7 @@ void RoundRobin::OnConnectivityChangedLocked(void* arg, grpc_error* error) { p->subchannel_list_ != nullptr ? p->subchannel_list_->num_subchannels : 0; - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "[RR %p] phasing out subchannel list %p (size %" PRIuPTR ") in favor of %p (size %" PRIuPTR ")", p, p->subchannel_list_, num_subchannels, sd->subchannel_list, @@ -517,7 +516,7 @@ void RoundRobin::OnConnectivityChangedLocked(void* arg, grpc_error* error) { *pick->user_data = selected->user_data; } if (grpc_lb_round_robin_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "[RR %p] Fulfilling pending pick. Target <-- subchannel %p " "(subchannel_list %p, index %" PRIuPTR ")", p, selected->subchannel, p->subchannel_list_, @@ -584,7 +583,7 @@ void RoundRobin::UpdateLocked(const grpc_channel_args& args) { } grpc_lb_addresses* addresses = (grpc_lb_addresses*)arg->value.pointer.p; if (grpc_lb_round_robin_trace.enabled()) { - gpr_log(GPR_DEBUG, "[RR %p] received update with %" PRIuPTR " addresses", + gpr_log(GPR_INFO, "[RR %p] received update with %" PRIuPTR " addresses", this, addresses->num_addresses); } grpc_lb_subchannel_list* subchannel_list = grpc_lb_subchannel_list_create( @@ -629,7 +628,7 @@ void RoundRobin::UpdateLocked(const grpc_channel_args& args) { } if (latest_pending_subchannel_list_ != nullptr) { if (grpc_lb_round_robin_trace.enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "[RR %p] Shutting down latest pending subchannel list %p, " "about to be replaced by newer latest %p", this, latest_pending_subchannel_list_, subchannel_list); diff --git a/src/core/ext/filters/client_channel/lb_policy/subchannel_list.cc b/src/core/ext/filters/client_channel/lb_policy/subchannel_list.cc index 79cb64c6c6..257db57575 100644 --- a/src/core/ext/filters/client_channel/lb_policy/subchannel_list.cc +++ b/src/core/ext/filters/client_channel/lb_policy/subchannel_list.cc @@ -34,7 +34,7 @@ void grpc_lb_subchannel_data_unref_subchannel(grpc_lb_subchannel_data* sd, const char* reason) { if (sd->subchannel != nullptr) { if (sd->subchannel_list->tracer->enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "[%s %p] subchannel list %p index %" PRIuPTR " of %" PRIuPTR " (subchannel %p): unreffing subchannel", sd->subchannel_list->tracer->name(), sd->subchannel_list->policy, @@ -57,7 +57,7 @@ void grpc_lb_subchannel_data_start_connectivity_watch( grpc_lb_subchannel_data* sd) { if (sd->subchannel_list->tracer->enabled()) { gpr_log( - GPR_DEBUG, + GPR_INFO, "[%s %p] subchannel list %p index %" PRIuPTR " of %" PRIuPTR " (subchannel %p): requesting connectivity change " "notification (from %s)", @@ -77,7 +77,7 @@ void grpc_lb_subchannel_data_start_connectivity_watch( void grpc_lb_subchannel_data_stop_connectivity_watch( grpc_lb_subchannel_data* sd) { if (sd->subchannel_list->tracer->enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "[%s %p] subchannel list %p index %" PRIuPTR " of %" PRIuPTR " (subchannel %p): stopping connectivity watch", sd->subchannel_list->tracer->name(), sd->subchannel_list->policy, @@ -98,7 +98,7 @@ grpc_lb_subchannel_list* grpc_lb_subchannel_list_create( static_cast<grpc_lb_subchannel_list*>( gpr_zalloc(sizeof(*subchannel_list))); if (tracer->enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "[%s %p] Creating subchannel list %p for %" PRIuPTR " subchannels", tracer->name(), p, subchannel_list, addresses->num_addresses); } @@ -132,7 +132,7 @@ grpc_lb_subchannel_list* grpc_lb_subchannel_list_create( if (tracer->enabled()) { char* address_uri = grpc_sockaddr_to_uri(&addresses->addresses[i].address); - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "[%s %p] could not create subchannel for address uri %s, " "ignoring", tracer->name(), subchannel_list->policy, address_uri); @@ -143,7 +143,7 @@ grpc_lb_subchannel_list* grpc_lb_subchannel_list_create( if (tracer->enabled()) { char* address_uri = grpc_sockaddr_to_uri(&addresses->addresses[i].address); - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "[%s %p] subchannel list %p index %" PRIuPTR ": Created subchannel %p for address uri %s", tracer->name(), p, subchannel_list, subchannel_index, subchannel, @@ -175,7 +175,7 @@ grpc_lb_subchannel_list* grpc_lb_subchannel_list_create( static void subchannel_list_destroy(grpc_lb_subchannel_list* subchannel_list) { if (subchannel_list->tracer->enabled()) { - gpr_log(GPR_DEBUG, "[%s %p] Destroying subchannel_list %p", + gpr_log(GPR_INFO, "[%s %p] Destroying subchannel_list %p", subchannel_list->tracer->name(), subchannel_list->policy, subchannel_list); } @@ -192,7 +192,7 @@ void grpc_lb_subchannel_list_ref(grpc_lb_subchannel_list* subchannel_list, gpr_ref_non_zero(&subchannel_list->refcount); if (subchannel_list->tracer->enabled()) { const gpr_atm count = gpr_atm_acq_load(&subchannel_list->refcount.count); - gpr_log(GPR_DEBUG, "[%s %p] subchannel_list %p REF %lu->%lu (%s)", + gpr_log(GPR_INFO, "[%s %p] subchannel_list %p REF %lu->%lu (%s)", subchannel_list->tracer->name(), subchannel_list->policy, subchannel_list, static_cast<unsigned long>(count - 1), static_cast<unsigned long>(count), reason); @@ -204,7 +204,7 @@ void grpc_lb_subchannel_list_unref(grpc_lb_subchannel_list* subchannel_list, const bool done = gpr_unref(&subchannel_list->refcount); if (subchannel_list->tracer->enabled()) { const gpr_atm count = gpr_atm_acq_load(&subchannel_list->refcount.count); - gpr_log(GPR_DEBUG, "[%s %p] subchannel_list %p UNREF %lu->%lu (%s)", + gpr_log(GPR_INFO, "[%s %p] subchannel_list %p UNREF %lu->%lu (%s)", subchannel_list->tracer->name(), subchannel_list->policy, subchannel_list, static_cast<unsigned long>(count + 1), static_cast<unsigned long>(count), reason); @@ -217,7 +217,7 @@ void grpc_lb_subchannel_list_unref(grpc_lb_subchannel_list* subchannel_list, static void subchannel_data_cancel_connectivity_watch( grpc_lb_subchannel_data* sd, const char* reason) { if (sd->subchannel_list->tracer->enabled()) { - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "[%s %p] subchannel list %p index %" PRIuPTR " of %" PRIuPTR " (subchannel %p): canceling connectivity watch (%s)", sd->subchannel_list->tracer->name(), sd->subchannel_list->policy, @@ -232,7 +232,7 @@ static void subchannel_data_cancel_connectivity_watch( void grpc_lb_subchannel_list_shutdown_and_unref( grpc_lb_subchannel_list* subchannel_list, const char* reason) { if (subchannel_list->tracer->enabled()) { - gpr_log(GPR_DEBUG, "[%s %p] Shutting down subchannel_list %p (%s)", + gpr_log(GPR_INFO, "[%s %p] Shutting down subchannel_list %p (%s)", subchannel_list->tracer->name(), subchannel_list->policy, subchannel_list, reason); } diff --git a/src/core/ext/filters/http/message_compress/message_compress_filter.cc b/src/core/ext/filters/http/message_compress/message_compress_filter.cc index e7d9949386..f8f478b6c0 100644 --- a/src/core/ext/filters/http/message_compress/message_compress_filter.cc +++ b/src/core/ext/filters/http/message_compress/message_compress_filter.cc @@ -234,7 +234,7 @@ static void finish_send_message(grpc_call_element* elem) { static_cast<float>(before_size); GPR_ASSERT(grpc_message_compression_algorithm_name( calld->message_compression_algorithm, &algo_name)); - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "Compressed[%s] %" PRIuPTR " bytes vs. %" PRIuPTR " bytes (%.2f%% savings)", algo_name, before_size, after_size, 100 * savings_ratio); @@ -246,7 +246,7 @@ static void finish_send_message(grpc_call_element* elem) { const char* algo_name; GPR_ASSERT(grpc_message_compression_algorithm_name( calld->message_compression_algorithm, &algo_name)); - gpr_log(GPR_DEBUG, + gpr_log(GPR_INFO, "Algorithm '%s' enabled but decided not to compress. Input size: " "%" PRIuPTR, algo_name, calld->slices.length); |