[grpc][Gpr_To_Absl_Logging] Migrating from gpr to absl logging - gpr_log (#36585)

[grpc][Gpr_To_Absl_Logging] Migrating from gpr to absl logging - gpr_log
In this CL we are migrating from gRPCs own gpr logging mechanism to absl logging mechanism. The intention is to deprecate gpr_log in the future.
We have the following mapping
1. gpr_log(GPR_INFO,...) -> LOG(INFO)
2. gpr_log(GPR_ERROR,...) -> LOG(ERROR)
3. gpr_log(GPR_DEBUG,...) -> VLOG(2)
Reviewers need to check :
1. If the above mapping is correct.
2. The content of the log is as before.
gpr_log format strings did not use string_view or std::string . absl LOG accepts these. So there will be some elimination of string_view and std::string related conversions. This is expected.

Closes #36585

COPYBARA_INTEGRATE_REVIEW=https://github.com/grpc/grpc/pull/36585 from tanvi-jagtap:large_file_regex_conv 2ca173855a
PiperOrigin-RevId: 633069869
pull/36592/head^2
Tanvi Jagtap 7 months ago committed by Copybara-Service
parent 06b097691e
commit 5a99b7ea82
  1. 29
      src/core/ext/transport/binder/transport/binder_transport.cc
  2. 21
      src/core/ext/transport/binder/wire_format/wire_reader_impl.cc
  3. 3
      src/core/ext/transport/chttp2/transport/chttp2_transport.cc
  4. 25
      src/core/lib/iomgr/ev_epoll1_linux.cc
  5. 27
      src/core/lib/iomgr/tcp_posix.cc
  6. 58
      src/core/lib/security/credentials/jwt/jwt_verifier.cc
  7. 4
      src/core/lib/surface/call.cc
  8. 7
      src/core/load_balancing/xds/xds_override_host.cc
  9. 65
      src/core/tsi/alts/handshaker/alts_tsi_handshaker.cc

@ -24,6 +24,7 @@
#include <utility>
#include "absl/log/check.h"
#include "absl/log/log.h"
#include "absl/memory/memory.h"
#include "absl/strings/str_cat.h"
#include "absl/strings/substitute.h"
@ -141,7 +142,7 @@ static void AssignMetadata(grpc_metadata_batch* mb,
static void cancel_stream_locked(grpc_binder_transport* transport,
grpc_binder_stream* stream,
grpc_error_handle error) {
gpr_log(GPR_INFO, "cancel_stream_locked");
LOG(INFO) << "cancel_stream_locked";
if (!stream->is_closed) {
CHECK(stream->cancel_self_error.ok());
stream->is_closed = true;
@ -200,7 +201,7 @@ static void recv_initial_metadata_locked(void* arg,
CHECK(stream->recv_initial_metadata);
CHECK(stream->recv_initial_metadata_ready);
if (!args->initial_metadata.ok()) {
gpr_log(GPR_ERROR, "Failed to parse initial metadata");
LOG(ERROR) << "Failed to parse initial metadata";
return absl_status_to_grpc_error(args->initial_metadata.status());
}
if (!stream->is_client) {
@ -237,11 +238,11 @@ static void recv_message_locked(void* arg, grpc_error_handle /*error*/) {
CHECK(stream->recv_message);
CHECK(stream->recv_message_ready);
if (!args->message.ok()) {
gpr_log(GPR_ERROR, "Failed to receive message");
LOG(ERROR) << "Failed to receive message";
if (args->message.status().message() ==
grpc_binder::TransportStreamReceiver::
kGrpcBinderTransportCancelledGracefully) {
gpr_log(GPR_ERROR, "message cancelled gracefully");
LOG(ERROR) << "message cancelled gracefully";
// Cancelled because we've already received trailing metadata.
// It's not an error in this case.
return absl::OkStatus();
@ -281,13 +282,13 @@ static void recv_trailing_metadata_locked(void* arg,
CHECK(stream->recv_trailing_metadata);
CHECK(stream->recv_trailing_metadata_finished);
if (!args->trailing_metadata.ok()) {
gpr_log(GPR_ERROR, "Failed to receive trailing metadata");
LOG(ERROR) << "Failed to receive trailing metadata";
return absl_status_to_grpc_error(args->trailing_metadata.status());
}
if (!stream->is_client) {
// Client will not send non-empty trailing metadata.
if (!args->trailing_metadata.value().empty()) {
gpr_log(GPR_ERROR, "Server receives non-empty trailing metadata.");
LOG(ERROR) << "Server receives non-empty trailing metadata.";
return absl::CancelledError();
}
} else {
@ -371,7 +372,7 @@ class MetadataEncoder {
static void accept_stream_locked(void* gt, grpc_error_handle /*error*/) {
grpc_binder_transport* transport = static_cast<grpc_binder_transport*>(gt);
if (transport->accept_stream_fn) {
gpr_log(GPR_INFO, "Accepting a stream");
LOG(INFO) << "Accepting a stream";
// must pass in a non-null value.
(*transport->accept_stream_fn)(transport->accept_stream_user_data,
transport, transport);
@ -449,7 +450,7 @@ static void perform_stream_op_locked(void* stream_op,
std::make_unique<grpc_binder::Transaction>(tx_code, transport->is_client);
if (op->send_initial_metadata) {
gpr_log(GPR_INFO, "send_initial_metadata");
LOG(INFO) << "send_initial_metadata";
grpc_binder::Metadata init_md;
auto batch = op->payload->send_initial_metadata.send_initial_metadata;
@ -459,12 +460,12 @@ static void perform_stream_op_locked(void* stream_op,
tx->SetPrefix(init_md);
}
if (op->send_message) {
gpr_log(GPR_INFO, "send_message");
LOG(INFO) << "send_message";
tx->SetData(op->payload->send_message.send_message->JoinIntoString());
}
if (op->send_trailing_metadata) {
gpr_log(GPR_INFO, "send_trailing_metadata");
LOG(INFO) << "send_trailing_metadata";
auto batch = op->payload->send_trailing_metadata.send_trailing_metadata;
grpc_binder::Metadata trailing_metadata;
@ -477,7 +478,7 @@ static void perform_stream_op_locked(void* stream_op,
tx->SetSuffix(trailing_metadata);
}
if (op->recv_initial_metadata) {
gpr_log(GPR_INFO, "recv_initial_metadata");
LOG(INFO) << "recv_initial_metadata";
stream->recv_initial_metadata_ready =
op->payload->recv_initial_metadata.recv_initial_metadata_ready;
stream->recv_initial_metadata =
@ -500,7 +501,7 @@ static void perform_stream_op_locked(void* stream_op,
});
}
if (op->recv_message) {
gpr_log(GPR_INFO, "recv_message");
LOG(INFO) << "recv_message";
stream->recv_message_ready = op->payload->recv_message.recv_message_ready;
stream->recv_message = op->payload->recv_message.recv_message;
stream->call_failed_before_recv_message =
@ -523,7 +524,7 @@ static void perform_stream_op_locked(void* stream_op,
});
}
if (op->recv_trailing_metadata) {
gpr_log(GPR_INFO, "recv_trailing_metadata");
LOG(INFO) << "recv_trailing_metadata";
stream->recv_trailing_metadata_finished =
op->payload->recv_trailing_metadata.recv_trailing_metadata_ready;
stream->recv_trailing_metadata =
@ -571,7 +572,7 @@ static void perform_stream_op_locked(void* stream_op,
if (op->on_complete != nullptr) {
grpc_core::ExecCtx::Run(DEBUG_LOCATION, op->on_complete,
absl_status_to_grpc_error(status));
gpr_log(GPR_INFO, "on_complete closure scheduled");
LOG(INFO) << "on_complete closure scheduled";
}
GRPC_BINDER_STREAM_UNREF(stream, "perform_stream_op");
}

@ -26,6 +26,7 @@
#include "absl/functional/any_invocable.h"
#include "absl/log/check.h"
#include "absl/log/log.h"
#include "absl/memory/memory.h"
#include "absl/status/statusor.h"
@ -136,9 +137,9 @@ void WireReaderImpl::SendSetupTransport(Binder* binder) {
std::unique_ptr<Binder> WireReaderImpl::RecvSetupTransport() {
// TODO(b/191941760): avoid blocking, handle wire_writer_noti lifetime
// better
gpr_log(GPR_DEBUG, "start waiting for noti");
VLOG(2) << "start waiting for noti";
connection_noti_.WaitForNotification();
gpr_log(GPR_DEBUG, "end waiting for noti");
VLOG(2) << "end waiting for noti";
return std::move(other_end_binder_);
}
@ -153,8 +154,8 @@ absl::Status WireReaderImpl::ProcessTransaction(transaction_code_t code,
BinderTransportTxCode::SETUP_TRANSPORT) &&
code <= static_cast<transaction_code_t>(
BinderTransportTxCode::PING_RESPONSE))) {
gpr_log(GPR_INFO,
"Received unknown control message. Shutdown transport gracefully.");
LOG(INFO)
<< "Received unknown control message. Shutdown transport gracefully.";
// TODO(waynetu): Shutdown transport gracefully.
return absl::OkStatus();
}
@ -210,8 +211,8 @@ absl::Status WireReaderImpl::ProcessTransaction(transaction_code_t code,
break;
}
case BinderTransportTxCode::SHUTDOWN_TRANSPORT: {
gpr_log(GPR_ERROR,
"Received SHUTDOWN_TRANSPORT request but not implemented yet.");
LOG(ERROR)
<< "Received SHUTDOWN_TRANSPORT request but not implemented yet.";
return absl::UnimplementedError("SHUTDOWN_TRANSPORT");
}
case BinderTransportTxCode::ACKNOWLEDGE_BYTES: {
@ -286,16 +287,16 @@ absl::Status WireReaderImpl::ProcessStreamingTransaction(
tx_process_result.ToString().c_str());
// Something went wrong when receiving transaction. Cancel failed requests.
if (cancellation_flags & kFlagPrefix) {
gpr_log(GPR_INFO, "cancelling initial metadata");
LOG(INFO) << "cancelling initial metadata";
transport_stream_receiver_->NotifyRecvInitialMetadata(code,
tx_process_result);
}
if (cancellation_flags & kFlagMessageData) {
gpr_log(GPR_INFO, "cancelling message data");
LOG(INFO) << "cancelling message data";
transport_stream_receiver_->NotifyRecvMessage(code, tx_process_result);
}
if (cancellation_flags & kFlagSuffix) {
gpr_log(GPR_INFO, "cancelling trailing metadata");
LOG(INFO) << "cancelling trailing metadata";
transport_stream_receiver_->NotifyRecvTrailingMetadata(
code, tx_process_result, 0);
}
@ -338,7 +339,7 @@ absl::Status WireReaderImpl::ProcessStreamingTransactionImpl(
// intended behavior.
// TODO(waynetu): What should be returned here?
if (flags == 0) {
gpr_log(GPR_INFO, "[WARNING] Receive empty transaction. Ignored.");
LOG(INFO) << "[WARNING] Receive empty transaction. Ignored.";
return absl::OkStatus();
}

@ -35,6 +35,7 @@
#include "absl/container/flat_hash_map.h"
#include "absl/hash/hash.h"
#include "absl/log/check.h"
#include "absl/log/log.h"
#include "absl/meta/type_traits.h"
#include "absl/random/random.h"
#include "absl/status/status.h"
@ -1324,7 +1325,7 @@ static bool contains_non_ok_status(grpc_metadata_batch* batch) {
static void log_metadata(const grpc_metadata_batch* md_batch, uint32_t id,
bool is_client, bool is_initial) {
gpr_log(GPR_INFO, "--metadata--");
LOG(INFO) << "--metadata--";
const std::string prefix = absl::StrCat(
"HTTP:", id, is_initial ? ":HDR" : ":TRL", is_client ? ":CLI:" : ":SVR:");
md_batch->Log([&prefix](absl::string_view key, absl::string_view value) {

@ -41,6 +41,7 @@
#include <string>
#include <vector>
#include "absl/log/log.h"
#include "absl/strings/str_cat.h"
#include "absl/strings/str_format.h"
#include "absl/strings/str_join.h"
@ -100,14 +101,14 @@ static int epoll_create_and_cloexec() {
#ifdef GRPC_LINUX_EPOLL_CREATE1
int fd = epoll_create1(EPOLL_CLOEXEC);
if (fd < 0) {
gpr_log(GPR_ERROR, "epoll_create1 unavailable");
LOG(ERROR) << "epoll_create1 unavailable";
}
#else
int fd = epoll_create(MAX_EPOLL_EVENTS);
if (fd < 0) {
gpr_log(GPR_ERROR, "epoll_create unavailable");
LOG(ERROR) << "epoll_create unavailable";
} else if (fcntl(fd, F_SETFD, FD_CLOEXEC) != 0) {
gpr_log(GPR_ERROR, "fcntl following epoll_create failed");
LOG(ERROR) << "fcntl following epoll_create failed";
return -1;
}
#endif
@ -891,7 +892,7 @@ static bool check_neighborhood_for_available_poller(
}
} else {
if (GRPC_TRACE_FLAG_ENABLED(grpc_polling_trace)) {
gpr_log(GPR_INFO, " .. beaten to choose next poller");
LOG(INFO) << " .. beaten to choose next poller";
}
}
// even if we didn't win the cas, there's a worker, we can stop
@ -990,7 +991,7 @@ static void end_worker(grpc_pollset* pollset, grpc_pollset_worker* worker,
gpr_cv_destroy(&worker->cv);
}
if (GRPC_TRACE_FLAG_ENABLED(grpc_polling_trace)) {
gpr_log(GPR_INFO, " .. remove worker");
LOG(INFO) << " .. remove worker";
}
if (EMPTIED == worker_remove(pollset, worker)) {
pollset_maybe_finish_shutdown(pollset);
@ -1081,7 +1082,7 @@ static grpc_error_handle pollset_kick(grpc_pollset* pollset,
if (root_worker == nullptr) {
pollset->kicked_without_poller = true;
if (GRPC_TRACE_FLAG_ENABLED(grpc_polling_trace)) {
gpr_log(GPR_INFO, " .. kicked_without_poller");
LOG(INFO) << " .. kicked_without_poller";
}
goto done;
}
@ -1146,7 +1147,7 @@ static grpc_error_handle pollset_kick(grpc_pollset* pollset,
}
} else {
if (GRPC_TRACE_FLAG_ENABLED(grpc_polling_trace)) {
gpr_log(GPR_INFO, " .. kicked while waking up");
LOG(INFO) << " .. kicked while waking up";
}
goto done;
}
@ -1156,7 +1157,7 @@ static grpc_error_handle pollset_kick(grpc_pollset* pollset,
if (specific_worker->state == KICKED) {
if (GRPC_TRACE_FLAG_ENABLED(grpc_polling_trace)) {
gpr_log(GPR_INFO, " .. specific worker already kicked");
LOG(INFO) << " .. specific worker already kicked";
}
goto done;
} else if (g_current_thread_worker == specific_worker) {
@ -1169,21 +1170,21 @@ static grpc_error_handle pollset_kick(grpc_pollset* pollset,
reinterpret_cast<grpc_pollset_worker*>(
gpr_atm_no_barrier_load(&g_active_poller))) {
if (GRPC_TRACE_FLAG_ENABLED(grpc_polling_trace)) {
gpr_log(GPR_INFO, " .. kick active poller");
LOG(INFO) << " .. kick active poller";
}
SET_KICK_STATE(specific_worker, KICKED);
ret_err = grpc_wakeup_fd_wakeup(&global_wakeup_fd);
goto done;
} else if (specific_worker->initialized_cv) {
if (GRPC_TRACE_FLAG_ENABLED(grpc_polling_trace)) {
gpr_log(GPR_INFO, " .. kick waiting worker");
LOG(INFO) << " .. kick waiting worker";
}
SET_KICK_STATE(specific_worker, KICKED);
gpr_cv_signal(&specific_worker->cv);
goto done;
} else {
if (GRPC_TRACE_FLAG_ENABLED(grpc_polling_trace)) {
gpr_log(GPR_INFO, " .. kick non-waiting worker");
LOG(INFO) << " .. kick non-waiting worker";
}
SET_KICK_STATE(specific_worker, KICKED);
goto done;
@ -1311,7 +1312,7 @@ static void reset_event_manager_on_fork() {
static bool init_epoll1_linux() {
if (!g_is_shutdown) return true;
if (!grpc_has_wakeup_fd()) {
gpr_log(GPR_ERROR, "Skipping epoll1 because of no wakeup fd.");
LOG(ERROR) << "Skipping epoll1 because of no wakeup fd.";
return false;
}

@ -46,6 +46,7 @@
#include <unordered_map>
#include "absl/log/check.h"
#include "absl/log/log.h"
#include <grpc/slice.h>
#include <grpc/support/alloc.h>
@ -212,7 +213,7 @@ class TcpZerocopySendCtx {
if (send_records_ == nullptr || free_send_records_ == nullptr) {
gpr_free(send_records_);
gpr_free(free_send_records_);
gpr_log(GPR_INFO, "Disabling TCP TX zerocopy due to memory pressure.\n");
LOG(INFO) << "Disabling TCP TX zerocopy due to memory pressure.\n";
memory_limited_ = true;
} else {
for (int idx = 0; idx < max_sends_; ++idx) {
@ -836,7 +837,7 @@ static void tcp_destroy(grpc_endpoint* ep) {
static void perform_reclamation(grpc_tcp* tcp)
ABSL_LOCKS_EXCLUDED(tcp->read_mu) {
if (GRPC_TRACE_FLAG_ENABLED(grpc_resource_quota_trace)) {
gpr_log(GPR_INFO, "TCP: benign reclamation to free memory");
LOG(INFO) << "TCP: benign reclamation to free memory";
}
tcp->read_mu.Lock();
if (tcp->incoming_buffer != nullptr) {
@ -1294,7 +1295,7 @@ static bool tcp_write_with_timestamps(grpc_tcp* tcp, struct msghdr* msg,
if (setsockopt(tcp->fd, SOL_SOCKET, SO_TIMESTAMPING,
static_cast<void*>(&opt), sizeof(opt)) != 0) {
if (GRPC_TRACE_FLAG_ENABLED(grpc_tcp_trace)) {
gpr_log(GPR_ERROR, "Failed to set timestamping options on the socket.");
LOG(ERROR) << "Failed to set timestamping options on the socket.";
}
return false;
}
@ -1380,7 +1381,7 @@ struct cmsghdr* process_timestamp(grpc_tcp* tcp, msghdr* msg,
cmsghdr* opt_stats = nullptr;
if (next_cmsg == nullptr) {
if (GRPC_TRACE_FLAG_ENABLED(grpc_tcp_trace)) {
gpr_log(GPR_ERROR, "Received timestamp without extended error");
LOG(ERROR) << "Received timestamp without extended error";
}
return cmsg;
}
@ -1392,7 +1393,7 @@ struct cmsghdr* process_timestamp(grpc_tcp* tcp, msghdr* msg,
next_cmsg = CMSG_NXTHDR(msg, opt_stats);
if (next_cmsg == nullptr) {
if (GRPC_TRACE_FLAG_ENABLED(grpc_tcp_trace)) {
gpr_log(GPR_ERROR, "Received timestamp without extended error");
LOG(ERROR) << "Received timestamp without extended error";
}
return opt_stats;
}
@ -1402,7 +1403,7 @@ struct cmsghdr* process_timestamp(grpc_tcp* tcp, msghdr* msg,
!(next_cmsg->cmsg_type == IP_RECVERR ||
next_cmsg->cmsg_type == IPV6_RECVERR)) {
if (GRPC_TRACE_FLAG_ENABLED(grpc_tcp_trace)) {
gpr_log(GPR_ERROR, "Unexpected control message");
LOG(ERROR) << "Unexpected control message";
}
return cmsg;
}
@ -1412,7 +1413,7 @@ struct cmsghdr* process_timestamp(grpc_tcp* tcp, msghdr* msg,
auto serr = reinterpret_cast<struct sock_extended_err*>(CMSG_DATA(next_cmsg));
if (serr->ee_errno != ENOMSG ||
serr->ee_origin != SO_EE_ORIGIN_TIMESTAMPING) {
gpr_log(GPR_ERROR, "Unexpected control message");
LOG(ERROR) << "Unexpected control message";
return cmsg;
}
tcp->tb_list.ProcessTimestamp(serr, opt_stats, tss);
@ -1462,7 +1463,7 @@ static bool process_errors(grpc_tcp* tcp) {
return processed_err;
}
if (GPR_UNLIKELY((msg.msg_flags & MSG_CTRUNC) != 0)) {
gpr_log(GPR_ERROR, "Error message was truncated.");
LOG(ERROR) << "Error message was truncated.";
}
if (msg.msg_controllen == 0) {
@ -1539,14 +1540,14 @@ static bool tcp_write_with_timestamps(grpc_tcp* /*tcp*/, struct msghdr* /*msg*/,
ssize_t* /*sent_length*/,
int* /* saved_errno */,
int /*additional_flags*/) {
gpr_log(GPR_ERROR, "Write with timestamps not supported for this platform");
LOG(ERROR) << "Write with timestamps not supported for this platform";
CHECK(0);
return false;
}
static void tcp_handle_error(void* /*arg*/ /* grpc_tcp */,
grpc_error_handle /*error*/) {
gpr_log(GPR_ERROR, "Error handling is not supported for this platform");
LOG(ERROR) << "Error handling is not supported for this platform";
CHECK(0);
}
#endif // GRPC_LINUX_ERRQUEUE
@ -1842,7 +1843,7 @@ static void tcp_handle_write(void* arg /* grpc_tcp */,
: tcp_flush(tcp, &error);
if (!flush_result) {
if (GRPC_TRACE_FLAG_ENABLED(grpc_tcp_trace)) {
gpr_log(GPR_INFO, "write: delayed");
LOG(INFO) << "write: delayed";
}
notify_on_write(tcp);
// tcp_flush does not populate error if it has returned false.
@ -1915,7 +1916,7 @@ static void tcp_write(grpc_endpoint* ep, grpc_slice_buffer* buf,
tcp->write_cb = cb;
tcp->current_zerocopy_send = zerocopy_send_record;
if (GRPC_TRACE_FLAG_ENABLED(grpc_tcp_trace)) {
gpr_log(GPR_INFO, "write: delayed");
LOG(INFO) << "write: delayed";
}
notify_on_write(tcp);
} else {
@ -2029,7 +2030,7 @@ grpc_endpoint* grpc_tcp_create(grpc_fd* em_fd,
if (err == 0) {
tcp->tcp_zerocopy_send_ctx.set_enabled(true);
} else {
gpr_log(GPR_ERROR, "Failed to set zerocopy options on the socket.");
LOG(ERROR) << "Failed to set zerocopy options on the socket.";
}
#endif
}

@ -42,6 +42,7 @@
#endif
#include "absl/log/check.h"
#include "absl/log/log.h"
#include "absl/status/status.h"
#include "absl/status/statusor.h"
#include "absl/strings/escaping.h"
@ -114,7 +115,7 @@ static const EVP_MD* evp_md_from_alg(const char* alg) {
static Json parse_json_part_from_jwt(const char* str, size_t len) {
std::string string;
if (!absl::WebSafeBase64Unescape(absl::string_view(str, len), &string)) {
gpr_log(GPR_ERROR, "Invalid base64.");
LOG(ERROR) << "Invalid base64.";
return Json(); // JSON null
}
auto json = grpc_core::JsonParse(string);
@ -163,13 +164,13 @@ static jose_header* jose_header_from_json(Json json) {
Json::Object::const_iterator it;
jose_header* h = grpc_core::Zalloc<jose_header>();
if (json.type() != Json::Type::kObject) {
gpr_log(GPR_ERROR, "JSON value is not an object");
LOG(ERROR) << "JSON value is not an object";
goto error;
}
// Check alg field.
it = json.object().find("alg");
if (it == json.object().end()) {
gpr_log(GPR_ERROR, "Missing alg field.");
LOG(ERROR) << "Missing alg field.";
goto error;
}
// We only support RSA-1.5 signatures for now.
@ -180,7 +181,7 @@ static jose_header* jose_header_from_json(Json json) {
if (it->second.type() != Json::Type::kString ||
strncmp(alg_value, "RS", 2) != 0 ||
evp_md_from_alg(alg_value) == nullptr) {
gpr_log(GPR_ERROR, "Invalid alg field");
LOG(ERROR) << "Invalid alg field";
goto error;
}
h->alg = alg_value;
@ -319,13 +320,13 @@ grpc_jwt_verifier_status grpc_jwt_claims_check(const grpc_jwt_claims* claims,
skewed_now =
gpr_time_add(gpr_now(GPR_CLOCK_REALTIME), grpc_jwt_verifier_clock_skew);
if (gpr_time_cmp(skewed_now, claims->nbf) < 0) {
gpr_log(GPR_ERROR, "JWT is not valid yet.");
LOG(ERROR) << "JWT is not valid yet.";
return GRPC_JWT_VERIFIER_TIME_CONSTRAINT_FAILURE;
}
skewed_now =
gpr_time_sub(gpr_now(GPR_CLOCK_REALTIME), grpc_jwt_verifier_clock_skew);
if (gpr_time_cmp(skewed_now, claims->exp) > 0) {
gpr_log(GPR_ERROR, "JWT is expired.");
LOG(ERROR) << "JWT is expired.";
return GRPC_JWT_VERIFIER_TIME_CONSTRAINT_FAILURE;
}
@ -430,7 +431,7 @@ struct grpc_jwt_verifier {
static Json json_from_http(const grpc_http_response* response) {
if (response == nullptr) {
gpr_log(GPR_ERROR, "HTTP response is NULL.");
LOG(ERROR) << "HTTP response is NULL.";
return Json(); // JSON null
}
if (response->status != 200) {
@ -441,7 +442,7 @@ static Json json_from_http(const grpc_http_response* response) {
auto json = grpc_core::JsonParse(
absl::string_view(response->body, response->body_length));
if (!json.ok()) {
gpr_log(GPR_ERROR, "Invalid JSON found in response.");
LOG(ERROR) << "Invalid JSON found in response.";
return Json(); // JSON null
}
return std::move(*json);
@ -464,12 +465,12 @@ static EVP_PKEY* extract_pkey_from_x509(const char* x509_str) {
BIO_write(bio, x509_str, static_cast<int>(len));
x509 = PEM_read_bio_X509(bio, nullptr, nullptr, nullptr);
if (x509 == nullptr) {
gpr_log(GPR_ERROR, "Unable to parse x509 cert.");
LOG(ERROR) << "Unable to parse x509 cert.";
goto end;
}
result = X509_get_pubkey(x509);
if (result == nullptr) {
gpr_log(GPR_ERROR, "Cannot find public key in X509 cert.");
LOG(ERROR) << "Cannot find public key in X509 cert.";
}
end:
@ -482,7 +483,7 @@ static BIGNUM* bignum_from_base64(const char* b64) {
if (b64 == nullptr) return nullptr;
std::string string;
if (!absl::WebSafeBase64Unescape(b64, &string)) {
gpr_log(GPR_ERROR, "Invalid base64 for big num.");
LOG(ERROR) << "Invalid base64 for big num.";
return nullptr;
}
return BN_bin2bn(reinterpret_cast<const uint8_t*>(string.data()),
@ -540,27 +541,27 @@ static EVP_PKEY* pkey_from_jwk(const Json& json, const char* kty) {
#if OPENSSL_VERSION_NUMBER < 0x30000000L
rsa = RSA_new();
if (rsa == nullptr) {
gpr_log(GPR_ERROR, "Could not create rsa key.");
LOG(ERROR) << "Could not create rsa key.";
goto end;
}
#endif
it = json.object().find("n");
if (it == json.object().end()) {
gpr_log(GPR_ERROR, "Missing RSA public key field.");
LOG(ERROR) << "Missing RSA public key field.";
goto end;
}
tmp_n = bignum_from_base64(validate_string_field(it->second, "n"));
if (tmp_n == nullptr) goto end;
it = json.object().find("e");
if (it == json.object().end()) {
gpr_log(GPR_ERROR, "Missing RSA public key field.");
LOG(ERROR) << "Missing RSA public key field.";
goto end;
}
tmp_e = bignum_from_base64(validate_string_field(it->second, "e"));
if (tmp_e == nullptr) goto end;
#if OPENSSL_VERSION_NUMBER < 0x30000000L
if (!RSA_set0_key(rsa, tmp_n, tmp_e, nullptr)) {
gpr_log(GPR_ERROR, "Cannot set RSA key from inputs.");
LOG(ERROR) << "Cannot set RSA key from inputs.";
goto end;
}
// RSA_set0_key takes ownership on success.
@ -573,21 +574,21 @@ static EVP_PKEY* pkey_from_jwk(const Json& json, const char* kty) {
if (!OSSL_PARAM_BLD_push_BN(bld, "n", tmp_n) ||
!OSSL_PARAM_BLD_push_BN(bld, "e", tmp_e) ||
(params = OSSL_PARAM_BLD_to_param(bld)) == NULL) {
gpr_log(GPR_ERROR, "Could not create OSSL_PARAM");
LOG(ERROR) << "Could not create OSSL_PARAM";
goto end;
}
ctx = EVP_PKEY_CTX_new_from_name(nullptr, "RSA", nullptr);
if (ctx == nullptr) {
gpr_log(GPR_ERROR, "Could not create rsa key.");
LOG(ERROR) << "Could not create rsa key.";
goto end;
}
if (EVP_PKEY_fromdata_init(ctx) <= 0) {
gpr_log(GPR_ERROR, "Could not create rsa key.");
LOG(ERROR) << "Could not create rsa key.";
goto end;
}
if (EVP_PKEY_fromdata(ctx, &result, EVP_PKEY_KEYPAIR, params) <= 0) {
gpr_log(GPR_ERROR, "Cannot set RSA key from inputs.");
LOG(ERROR) << "Cannot set RSA key from inputs.";
goto end;
}
#endif
@ -618,8 +619,7 @@ static EVP_PKEY* find_verification_key(const Json& json, const char* header_alg,
return extract_pkey_from_x509(cur->string().c_str());
}
if (jwt_keys->type() != Json::Type::kArray) {
gpr_log(GPR_ERROR,
"Unexpected value type of keys property in jwks key set.");
LOG(ERROR) << "Unexpected value type of keys property in jwks key set.";
return nullptr;
}
// Key format is specified in:
@ -661,21 +661,21 @@ static int verify_jwt_signature(EVP_PKEY* key, const char* alg,
CHECK_NE(md, nullptr); // Checked before.
if (md_ctx == nullptr) {
gpr_log(GPR_ERROR, "Could not create EVP_MD_CTX.");
LOG(ERROR) << "Could not create EVP_MD_CTX.";
goto end;
}
if (EVP_DigestVerifyInit(md_ctx, nullptr, md, nullptr, key) != 1) {
gpr_log(GPR_ERROR, "EVP_DigestVerifyInit failed.");
LOG(ERROR) << "EVP_DigestVerifyInit failed.";
goto end;
}
if (EVP_DigestVerifyUpdate(md_ctx, GRPC_SLICE_START_PTR(signed_data),
GRPC_SLICE_LENGTH(signed_data)) != 1) {
gpr_log(GPR_ERROR, "EVP_DigestVerifyUpdate failed.");
LOG(ERROR) << "EVP_DigestVerifyUpdate failed.";
goto end;
}
if (EVP_DigestVerifyFinal(md_ctx, GRPC_SLICE_START_PTR(signature),
GRPC_SLICE_LENGTH(signature)) != 1) {
gpr_log(GPR_ERROR, "JWT signature verification failed.");
LOG(ERROR) << "JWT signature verification failed.";
goto end;
}
@ -742,7 +742,7 @@ static void on_openid_config_retrieved(void* user_data,
if (json.type() == Json::Type::kNull) goto error;
cur = find_property_by_name(json, "jwks_uri");
if (cur == nullptr) {
gpr_log(GPR_ERROR, "Could not find jwks_uri in openid config.");
LOG(ERROR) << "Could not find jwks_uri in openid config.";
goto error;
}
jwks_uri = validate_string_field(*cur, "jwks_uri");
@ -843,11 +843,11 @@ static void retrieve_key_and_verify(verifier_cb_ctx* ctx) {
CHECK(ctx != nullptr && ctx->header != nullptr && ctx->claims != nullptr);
iss = ctx->claims->iss;
if (ctx->header->kid == nullptr) {
gpr_log(GPR_ERROR, "Missing kid in jose header.");
LOG(ERROR) << "Missing kid in jose header.";
goto error;
}
if (iss == nullptr) {
gpr_log(GPR_ERROR, "Missing iss in claims.");
LOG(ERROR) << "Missing iss in claims.";
goto error;
}
@ -862,7 +862,7 @@ static void retrieve_key_and_verify(verifier_cb_ctx* ctx) {
CHECK_NE(ctx->verifier, nullptr);
mapping = verifier_get_mapping(ctx->verifier, email_domain);
if (mapping == nullptr) {
gpr_log(GPR_ERROR, "Missing mapping for issuer email.");
LOG(ERROR) << "Missing mapping for issuer email.";
goto error;
}
host = gpr_strdup(mapping->key_url_prefix);

@ -34,6 +34,7 @@
#include "absl/base/thread_annotations.h"
#include "absl/log/check.h"
#include "absl/log/log.h"
#include "absl/status/status.h"
#include "absl/strings/str_cat.h"
#include "absl/strings/str_format.h"
@ -1138,8 +1139,7 @@ void FilterStackCall::RecvTrailingFilter(grpc_metadata_batch* b,
} else if (!is_client()) {
SetFinalStatus(absl::OkStatus());
} else {
gpr_log(GPR_DEBUG,
"Received trailing metadata with no error and no status");
VLOG(2) << "Received trailing metadata with no error and no status";
SetFinalStatus(grpc_error_set_int(GRPC_ERROR_CREATE("No status received"),
StatusIntProperty::kRpcStatus,
GRPC_STATUS_UNKNOWN));

@ -32,6 +32,7 @@
#include "absl/base/thread_annotations.h"
#include "absl/functional/function_ref.h"
#include "absl/log/check.h"
#include "absl/log/log.h"
#include "absl/status/status.h"
#include "absl/status/statusor.h"
#include "absl/strings/str_cat.h"
@ -530,7 +531,7 @@ XdsOverrideHostLb::Picker::PickOverridenHost(
// a connection attempt and queue the pick until that attempt completes.
if (idle_subchannel != nullptr) {
if (GRPC_TRACE_FLAG_ENABLED(grpc_lb_xds_override_host_trace)) {
gpr_log(GPR_INFO, "Picker override found IDLE subchannel");
LOG(INFO) << "Picker override found IDLE subchannel";
}
// Deletes itself after the connection is requested.
new SubchannelConnectionRequester(std::move(idle_subchannel));
@ -540,7 +541,7 @@ XdsOverrideHostLb::Picker::PickOverridenHost(
// queue the pick and wait for the connection attempt to complete.
if (found_connecting) {
if (GRPC_TRACE_FLAG_ENABLED(grpc_lb_xds_override_host_trace)) {
gpr_log(GPR_INFO, "Picker override found CONNECTING subchannel");
LOG(INFO) << "Picker override found CONNECTING subchannel";
}
return PickResult::Queue();
}
@ -549,7 +550,7 @@ XdsOverrideHostLb::Picker::PickOverridenHost(
// creation of a subchannel for that entry.
if (!address_with_no_subchannel.empty()) {
if (GRPC_TRACE_FLAG_ENABLED(grpc_lb_xds_override_host_trace)) {
gpr_log(GPR_INFO, "Picker override found entry with no subchannel");
LOG(INFO) << "Picker override found entry with no subchannel";
}
if (!IsWorkSerializerDispatchEnabled()) {
new SubchannelCreationRequester(policy_, address_with_no_subchannel);

@ -23,6 +23,7 @@
#include <string.h>
#include "absl/log/check.h"
#include "absl/log/log.h"
#include "upb/mem/arena.hpp"
#include <grpc/credentials.h>
@ -87,7 +88,7 @@ typedef struct alts_tsi_handshaker_result {
static tsi_result handshaker_result_extract_peer(
const tsi_handshaker_result* self, tsi_peer* peer) {
if (self == nullptr || peer == nullptr) {
gpr_log(GPR_ERROR, "Invalid argument to handshaker_result_extract_peer()");
LOG(ERROR) << "Invalid argument to handshaker_result_extract_peer()";
return TSI_INVALID_ARGUMENT;
}
alts_tsi_handshaker_result* result =
@ -97,7 +98,7 @@ static tsi_result handshaker_result_extract_peer(
tsi_result ok = tsi_construct_peer(kTsiAltsNumOfPeerProperties, peer);
int index = 0;
if (ok != TSI_OK) {
gpr_log(GPR_ERROR, "Failed to construct tsi peer");
LOG(ERROR) << "Failed to construct tsi peer";
return ok;
}
CHECK_NE(&peer->properties[index], nullptr);
@ -106,7 +107,7 @@ static tsi_result handshaker_result_extract_peer(
&peer->properties[index]);
if (ok != TSI_OK) {
tsi_peer_destruct(peer);
gpr_log(GPR_ERROR, "Failed to set tsi peer property");
LOG(ERROR) << "Failed to set tsi peer property";
return ok;
}
index++;
@ -116,7 +117,7 @@ static tsi_result handshaker_result_extract_peer(
&peer->properties[index]);
if (ok != TSI_OK) {
tsi_peer_destruct(peer);
gpr_log(GPR_ERROR, "Failed to set tsi peer property");
LOG(ERROR) << "Failed to set tsi peer property";
}
index++;
CHECK_NE(&peer->properties[index], nullptr);
@ -126,7 +127,7 @@ static tsi_result handshaker_result_extract_peer(
GRPC_SLICE_LENGTH(result->rpc_versions), &peer->properties[index]);
if (ok != TSI_OK) {
tsi_peer_destruct(peer);
gpr_log(GPR_ERROR, "Failed to set tsi peer property");
LOG(ERROR) << "Failed to set tsi peer property";
}
index++;
CHECK_NE(&peer->properties[index], nullptr);
@ -136,7 +137,7 @@ static tsi_result handshaker_result_extract_peer(
GRPC_SLICE_LENGTH(result->serialized_context), &peer->properties[index]);
if (ok != TSI_OK) {
tsi_peer_destruct(peer);
gpr_log(GPR_ERROR, "Failed to set tsi peer property");
LOG(ERROR) << "Failed to set tsi peer property";
}
index++;
CHECK_NE(&peer->properties[index], nullptr);
@ -146,7 +147,7 @@ static tsi_result handshaker_result_extract_peer(
&peer->properties[index]);
if (ok != TSI_OK) {
tsi_peer_destruct(peer);
gpr_log(GPR_ERROR, "Failed to set tsi peer property");
LOG(ERROR) << "Failed to set tsi peer property";
}
CHECK(++index == kTsiAltsNumOfPeerProperties);
return ok;
@ -163,8 +164,7 @@ static tsi_result handshaker_result_create_zero_copy_grpc_protector(
const tsi_handshaker_result* self, size_t* max_output_protected_frame_size,
tsi_zero_copy_grpc_protector** protector) {
if (self == nullptr || protector == nullptr) {
gpr_log(GPR_ERROR,
"Invalid arguments to create_zero_copy_grpc_protector()");
LOG(ERROR) << "Invalid arguments to create_zero_copy_grpc_protector()";
return TSI_INVALID_ARGUMENT;
}
alts_tsi_handshaker_result* result =
@ -198,7 +198,7 @@ static tsi_result handshaker_result_create_zero_copy_grpc_protector(
/*is_integrity_only=*/false, /*enable_extra_copy=*/false,
max_output_protected_frame_size, protector);
if (ok != TSI_OK) {
gpr_log(GPR_ERROR, "Failed to create zero-copy grpc protector");
LOG(ERROR) << "Failed to create zero-copy grpc protector";
}
return ok;
}
@ -207,8 +207,8 @@ static tsi_result handshaker_result_create_frame_protector(
const tsi_handshaker_result* self, size_t* max_output_protected_frame_size,
tsi_frame_protector** protector) {
if (self == nullptr || protector == nullptr) {
gpr_log(GPR_ERROR,
"Invalid arguments to handshaker_result_create_frame_protector()");
LOG(ERROR)
<< "Invalid arguments to handshaker_result_create_frame_protector()";
return TSI_INVALID_ARGUMENT;
}
alts_tsi_handshaker_result* result =
@ -219,7 +219,7 @@ static tsi_result handshaker_result_create_frame_protector(
kAltsAes128GcmRekeyKeyLength, result->is_client, /*is_rekey=*/true,
max_output_protected_frame_size, protector);
if (ok != TSI_OK) {
gpr_log(GPR_ERROR, "Failed to create frame protector");
LOG(ERROR) << "Failed to create frame protector";
}
return ok;
}
@ -228,8 +228,7 @@ static tsi_result handshaker_result_get_unused_bytes(
const tsi_handshaker_result* self, const unsigned char** bytes,
size_t* bytes_size) {
if (self == nullptr || bytes == nullptr || bytes_size == nullptr) {
gpr_log(GPR_ERROR,
"Invalid arguments to handshaker_result_get_unused_bytes()");
LOG(ERROR) << "Invalid arguments to handshaker_result_get_unused_bytes()";
return TSI_INVALID_ARGUMENT;
}
alts_tsi_handshaker_result* result =
@ -267,7 +266,7 @@ tsi_result alts_tsi_handshaker_result_create(grpc_gcp_HandshakerResp* resp,
bool is_client,
tsi_handshaker_result** result) {
if (result == nullptr || resp == nullptr) {
gpr_log(GPR_ERROR, "Invalid arguments to create_handshaker_result()");
LOG(ERROR) << "Invalid arguments to create_handshaker_result()";
return TSI_INVALID_ARGUMENT;
}
const grpc_gcp_HandshakerResult* hresult =
@ -275,42 +274,42 @@ tsi_result alts_tsi_handshaker_result_create(grpc_gcp_HandshakerResp* resp,
const grpc_gcp_Identity* identity =
grpc_gcp_HandshakerResult_peer_identity(hresult);
if (identity == nullptr) {
gpr_log(GPR_ERROR, "Invalid identity");
LOG(ERROR) << "Invalid identity";
return TSI_FAILED_PRECONDITION;
}
upb_StringView peer_service_account =
grpc_gcp_Identity_service_account(identity);
if (peer_service_account.size == 0) {
gpr_log(GPR_ERROR, "Invalid peer service account");
LOG(ERROR) << "Invalid peer service account";
return TSI_FAILED_PRECONDITION;
}
upb_StringView key_data = grpc_gcp_HandshakerResult_key_data(hresult);
if (key_data.size < kAltsAes128GcmRekeyKeyLength) {
gpr_log(GPR_ERROR, "Bad key length");
LOG(ERROR) << "Bad key length";
return TSI_FAILED_PRECONDITION;
}
const grpc_gcp_RpcProtocolVersions* peer_rpc_version =
grpc_gcp_HandshakerResult_peer_rpc_versions(hresult);
if (peer_rpc_version == nullptr) {
gpr_log(GPR_ERROR, "Peer does not set RPC protocol versions.");
LOG(ERROR) << "Peer does not set RPC protocol versions.";
return TSI_FAILED_PRECONDITION;
}
upb_StringView application_protocol =
grpc_gcp_HandshakerResult_application_protocol(hresult);
if (application_protocol.size == 0) {
gpr_log(GPR_ERROR, "Invalid application protocol");
LOG(ERROR) << "Invalid application protocol";
return TSI_FAILED_PRECONDITION;
}
upb_StringView record_protocol =
grpc_gcp_HandshakerResult_record_protocol(hresult);
if (record_protocol.size == 0) {
gpr_log(GPR_ERROR, "Invalid record protocol");
LOG(ERROR) << "Invalid record protocol";
return TSI_FAILED_PRECONDITION;
}
const grpc_gcp_Identity* local_identity =
grpc_gcp_HandshakerResult_local_identity(hresult);
if (local_identity == nullptr) {
gpr_log(GPR_ERROR, "Invalid local identity");
LOG(ERROR) << "Invalid local identity";
return TSI_FAILED_PRECONDITION;
}
upb_StringView local_service_account =
@ -331,7 +330,7 @@ tsi_result alts_tsi_handshaker_result_create(grpc_gcp_HandshakerResp* resp,
bool serialized = grpc_gcp_rpc_protocol_versions_encode(
peer_rpc_version, rpc_versions_arena.ptr(), &sresult->rpc_versions);
if (!serialized) {
gpr_log(GPR_ERROR, "Failed to serialize peer's RPC protocol versions.");
LOG(ERROR) << "Failed to serialize peer's RPC protocol versions.";
return TSI_FAILED_PRECONDITION;
}
upb::Arena context_arena;
@ -348,7 +347,7 @@ tsi_result alts_tsi_handshaker_result_create(grpc_gcp_HandshakerResp* resp,
context, const_cast<grpc_gcp_RpcProtocolVersions*>(peer_rpc_version));
grpc_gcp_Identity* peer_identity = const_cast<grpc_gcp_Identity*>(identity);
if (peer_identity == nullptr) {
gpr_log(GPR_ERROR, "Null peer identity in ALTS context.");
LOG(ERROR) << "Null peer identity in ALTS context.";
return TSI_FAILED_PRECONDITION;
}
if (grpc_gcp_Identity_attributes_size(identity) != 0) {
@ -372,7 +371,7 @@ tsi_result alts_tsi_handshaker_result_create(grpc_gcp_HandshakerResp* resp,
char* serialized_ctx = grpc_gcp_AltsContext_serialize(
context, context_arena.ptr(), &serialized_ctx_length);
if (serialized_ctx == nullptr) {
gpr_log(GPR_ERROR, "Failed to serialize peer's ALTS context.");
LOG(ERROR) << "Failed to serialize peer's ALTS context.";
return TSI_FAILED_PRECONDITION;
}
sresult->serialized_context =
@ -388,7 +387,7 @@ static void on_handshaker_service_resp_recv(void* arg,
grpc_error_handle error) {
alts_handshaker_client* client = static_cast<alts_handshaker_client*>(arg);
if (client == nullptr) {
gpr_log(GPR_ERROR, "ALTS handshaker client is nullptr");
LOG(ERROR) << "ALTS handshaker client is nullptr";
return;
}
bool success = true;
@ -440,7 +439,7 @@ static tsi_result alts_tsi_handshaker_continue_handshaker_next(
handshaker->client_vtable_for_testing, handshaker->is_client,
handshaker->max_frame_size, error);
if (client == nullptr) {
gpr_log(GPR_ERROR, "Failed to create ALTS handshaker client");
LOG(ERROR) << "Failed to create ALTS handshaker client";
if (error != nullptr) *error = "Failed to create ALTS handshaker client";
return TSI_FAILED_PRECONDITION;
}
@ -449,7 +448,7 @@ static tsi_result alts_tsi_handshaker_continue_handshaker_next(
CHECK_EQ(handshaker->client, nullptr);
handshaker->client = client;
if (handshaker->shutdown) {
gpr_log(GPR_INFO, "TSI handshake shutdown");
LOG(INFO) << "TSI handshake shutdown";
if (error != nullptr) *error = "TSI handshaker shutdown";
return TSI_HANDSHAKE_SHUTDOWN;
}
@ -529,7 +528,7 @@ static tsi_result handshaker_next(
size_t* /*bytes_to_send_size*/, tsi_handshaker_result** /*result*/,
tsi_handshaker_on_next_done_cb cb, void* user_data, std::string* error) {
if (self == nullptr || cb == nullptr) {
gpr_log(GPR_ERROR, "Invalid arguments to handshaker_next()");
LOG(ERROR) << "Invalid arguments to handshaker_next()";
if (error != nullptr) *error = "invalid argument";
return TSI_INVALID_ARGUMENT;
}
@ -538,7 +537,7 @@ static tsi_result handshaker_next(
{
grpc_core::MutexLock lock(&handshaker->mu);
if (handshaker->shutdown) {
gpr_log(GPR_INFO, "TSI handshake shutdown");
LOG(INFO) << "TSI handshake shutdown";
if (error != nullptr) *error = "handshake shutdown";
return TSI_HANDSHAKE_SHUTDOWN;
}
@ -569,7 +568,7 @@ static tsi_result handshaker_next(
tsi_result ok = alts_tsi_handshaker_continue_handshaker_next(
handshaker, received_bytes, received_bytes_size, cb, user_data, error);
if (ok != TSI_OK) {
gpr_log(GPR_ERROR, "Failed to schedule ALTS handshaker requests");
LOG(ERROR) << "Failed to schedule ALTS handshaker requests";
return ok;
}
}
@ -651,7 +650,7 @@ tsi_result alts_tsi_handshaker_create(
size_t user_specified_max_frame_size) {
if (handshaker_service_url == nullptr || self == nullptr ||
options == nullptr || (is_client && target_name == nullptr)) {
gpr_log(GPR_ERROR, "Invalid arguments to alts_tsi_handshaker_create()");
LOG(ERROR) << "Invalid arguments to alts_tsi_handshaker_create()";
return TSI_INVALID_ARGUMENT;
}
bool use_dedicated_cq = interested_parties == nullptr;

Loading…
Cancel
Save