natas_hw
/
grpc
0
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

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

[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 #36677

COPYBARA_INTEGRATE_REVIEW=https://github.com/grpc/grpc/pull/36677 from tanvi-jagtap:regex_test_end2end dfb803ebff
PiperOrigin-RevId: 635807701
This commit is contained in:
Tanvi Jagtap 2024-05-21 08:01:26 -07:00 committed by Copybara-Service
parent 98752f39fb
commit 4dc1097d04
15 changed files with 116 additions and 121 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

24
test/cpp/end2end/cfstream_test.cc
View File

@ -25,11 +25,11 @@
#include <gtest/gtest.h>
#include "absl/log/check.h"
#include "absl/log/log.h"
#include <grpc/grpc.h>
#include <grpc/support/alloc.h>
#include <grpc/support/atm.h>
#include <grpc/support/log.h>
#include <grpc/support/string_util.h>
#include <grpc/support/time.h>
#include <grpcpp/channel.h>
@ -102,13 +102,13 @@ class CFStreamTest : public ::testing::TestWithParam<TestScenario> {
}
void NetworkUp() {
gpr_log(GPR_DEBUG, "Bringing network up");
VLOG(2) << "Bringing network up";
InterfaceUp();
DNSUp();
}
void NetworkDown() {
gpr_log(GPR_DEBUG, "Bringing network down");
VLOG(2) << "Bringing network down";
InterfaceDown();
DNSDown();
}
@ -156,10 +156,10 @@ class CFStreamTest : public ::testing::TestWithParam<TestScenario> {
ClientContext context;
Status status = stub->Echo(&context, request, response.get());
if (status.ok()) {
gpr_log(GPR_DEBUG, "RPC with succeeded");
VLOG(2) << "RPC with succeeded";
EXPECT_EQ(msg, response->message());
} else {
gpr_log(GPR_DEBUG, "RPC failed: %s", status.error_message().c_str());
VLOG(2) << "RPC failed: " << status.error_message();
}
if (expect_success) {
EXPECT_TRUE(status.ok());
@ -241,7 +241,7 @@ class CFStreamTest : public ::testing::TestWithParam<TestScenario> {
: port_(port), creds_(creds) {}
void Start(const std::string& server_host) {
gpr_log(GPR_INFO, "starting server on port %d", port_);
LOG(INFO) << "starting server on port " << port_;
std::mutex mu;
std::unique_lock<std::mutex> lock(mu);
std::condition_variable cond;
@ -249,7 +249,7 @@ class CFStreamTest : public ::testing::TestWithParam<TestScenario> {
std::bind(&ServerData::Serve, this, server_host, &mu, &cond)));
cond.wait(lock, [this] { return server_ready_; });
server_ready_ = false;
gpr_log(GPR_INFO, "server startup complete");
LOG(INFO) << "server startup complete";
}
void Serve(const std::string& server_host, std::mutex* mu,
@ -380,15 +380,14 @@ TEST_P(CFStreamTest, NetworkFlapRpcsInFlight) {
CHECK(ok);
AsyncClientCall* call = static_cast<AsyncClientCall*>(got_tag);
if (!call->status.ok()) {
gpr_log(GPR_DEBUG, "RPC failed with error: %s",
call->status.error_message().c_str());
VLOG(2) << "RPC failed with error: " << call->status.error_message();
// Bring network up when RPCs start failing
if (network_down) {
NetworkUp();
network_down = false;
}
} else {
gpr_log(GPR_DEBUG, "RPC succeeded");
VLOG(2) << "RPC succeeded";
}
delete call;
}
@ -427,11 +426,10 @@ TEST_P(CFStreamTest, ConcurrentRpc) {
CHECK(ok);
AsyncClientCall* call = static_cast<AsyncClientCall*>(got_tag);
if (!call->status.ok()) {
gpr_log(GPR_DEBUG, "RPC failed with error: %s",
call->status.error_message().c_str());
VLOG(2) << "RPC failed with error: " << call->status.error_message();
// Bring network up when RPCs start failing
} else {
gpr_log(GPR_DEBUG, "RPC succeeded");
VLOG(2) << "RPC succeeded";
}
delete call;
}

10
test/cpp/end2end/client_fork_test.cc
View File

@ -23,11 +23,11 @@ int main(int /* argc */, char** /* argv */) { return 0; }
#include <gtest/gtest.h>
#include "absl/log/log.h"
#include "absl/strings/str_cat.h"
#include <grpc/fork.h>
#include <grpc/grpc.h>
#include <grpc/support/log.h>
#include <grpc/support/time.h>
#include <grpcpp/channel.h>
#include <grpcpp/client_context.h>
@ -53,10 +53,10 @@ class ServiceImpl final : public EchoTestService::Service {
EchoRequest request;
EchoResponse response;
while (stream->Read(&request)) {
gpr_log(GPR_INFO, "recv msg %s", request.message().c_str());
LOG(INFO) << "recv msg " << request.message();
response.set_message(request.message());
stream->Write(response);
gpr_log(GPR_INFO, "wrote msg %s", response.message().c_str());
LOG(INFO) << "wrote msg " << response.message();
}
return Status::OK;
}
@ -114,7 +114,7 @@ TEST(ClientForkTest, ClientCallsBeforeAndAfterForkSucceed) {
GTEST_FAIL() << "fork failed";
case 0: // post-fork child
{
gpr_log(GPR_DEBUG, "In post-fork child");
VLOG(2) << "In post-fork child";
EchoRequest request;
EchoResponse response;
ClientContext context;
@ -131,7 +131,7 @@ TEST(ClientForkTest, ClientCallsBeforeAndAfterForkSucceed) {
}
default: // post-fork parent
{
gpr_log(GPR_DEBUG, "In post-fork parent");
VLOG(2) << "In post-fork parent";
EchoRequest request;
EchoResponse response;
ClientContext context;

19
test/cpp/end2end/connection_attempt_injector.cc
View File

@ -17,6 +17,7 @@
#include <memory>
#include "absl/log/check.h"
#include "absl/log/log.h"
#include "absl/memory/memory.h"
#include "absl/utility/utility.h"
@ -119,14 +120,14 @@ void ConnectionAttemptInjector::HandleConnection(
grpc_pollset_set* interested_parties, const EndpointConfig& config,
const grpc_resolved_address* addr, grpc_core::Timestamp deadline) {
const int port = grpc_sockaddr_get_port(addr);
gpr_log(GPR_INFO, "==> HandleConnection(): port=%d", port);
LOG(INFO) << "==> HandleConnection(): port=" << port;
{
grpc_core::MutexLock lock(&mu_);
// First, check if there's a hold request for this port.
for (auto it = holds_.begin(); it != holds_.end(); ++it) {
Hold* hold = *it;
if (port == hold->port_) {
gpr_log(GPR_INFO, "*** INTERCEPTING CONNECTION ATTEMPT");
LOG(INFO) << "*** INTERCEPTING CONNECTION ATTEMPT";
if (hold->intercept_completion_) {
hold->original_on_complete_ = closure;
closure = GRPC_CLOSURE_INIT(&hold->on_complete_, Hold::OnComplete,
@ -220,16 +221,16 @@ ConnectionAttemptInjector::Hold::Hold(ConnectionAttemptInjector* injector,
intercept_completion_(intercept_completion) {}
void ConnectionAttemptInjector::Hold::Wait() {
gpr_log(GPR_INFO, "=== WAITING FOR CONNECTION ATTEMPT ON PORT %d ===", port_);
LOG(INFO) << "=== WAITING FOR CONNECTION ATTEMPT ON PORT " << port_ << " ===";
grpc_core::MutexLock lock(&injector_->mu_);
while (queued_attempt_ == nullptr) {
start_cv_.Wait(&injector_->mu_);
}
gpr_log(GPR_INFO, "=== CONNECTION ATTEMPT STARTED ON PORT %d ===", port_);
LOG(INFO) << "=== CONNECTION ATTEMPT STARTED ON PORT " << port_ << " ===";
}
void ConnectionAttemptInjector::Hold::Resume() {
gpr_log(GPR_INFO, "=== RESUMING CONNECTION ATTEMPT ON PORT %d ===", port_);
LOG(INFO) << "=== RESUMING CONNECTION ATTEMPT ON PORT " << port_ << " ===";
grpc_core::ExecCtx exec_ctx;
std::unique_ptr<QueuedAttempt> attempt;
{
@ -240,7 +241,7 @@ void ConnectionAttemptInjector::Hold::Resume() {
}
void ConnectionAttemptInjector::Hold::Fail(grpc_error_handle error) {
gpr_log(GPR_INFO, "=== FAILING CONNECTION ATTEMPT ON PORT %d ===", port_);
LOG(INFO) << "=== FAILING CONNECTION ATTEMPT ON PORT " << port_ << " ===";
grpc_core::ExecCtx exec_ctx;
std::unique_ptr<QueuedAttempt> attempt;
{
@ -251,13 +252,13 @@ void ConnectionAttemptInjector::Hold::Fail(grpc_error_handle error) {
}
void ConnectionAttemptInjector::Hold::WaitForCompletion() {
gpr_log(GPR_INFO,
"=== WAITING FOR CONNECTION COMPLETION ON PORT %d ===", port_);
LOG(INFO) << "=== WAITING FOR CONNECTION COMPLETION ON PORT " << port_
<< " ===";
grpc_core::MutexLock lock(&injector_->mu_);
while (original_on_complete_ != nullptr) {
complete_cv_.Wait(&injector_->mu_);
}
gpr_log(GPR_INFO, "=== CONNECTION COMPLETED ON PORT %d ===", port_);
LOG(INFO) << "=== CONNECTION COMPLETED ON PORT " << port_ << " ===";
}
bool ConnectionAttemptInjector::Hold::IsStarted() {

21
test/cpp/end2end/end2end_test.cc
View File

@ -20,6 +20,7 @@
#include <thread>
#include "absl/log/check.h"
#include "absl/log/log.h"
#include "absl/memory/memory.h"
#include "absl/strings/ascii.h"
#include "absl/strings/match.h"
@ -27,7 +28,6 @@
#include <grpc/grpc.h>
#include <grpc/support/alloc.h>
#include <grpc/support/log.h>
#include <grpc/support/time.h>
#include <grpcpp/channel.h>
#include <grpcpp/client_context.h>
@ -538,7 +538,7 @@ class End2endServerTryCancelTest : public End2endTest {
}
num_msgs_sent++;
}
gpr_log(GPR_INFO, "Sent %d messages", num_msgs_sent);
LOG(INFO) << "Sent " << num_msgs_sent << " messages";
stream->WritesDone();
Status s = stream->Finish();
@ -566,8 +566,7 @@ class End2endServerTryCancelTest : public End2endTest {
break;
default:
gpr_log(GPR_ERROR, "Invalid server_try_cancel value: %d",
server_try_cancel);
LOG(ERROR) << "Invalid server_try_cancel value: " << server_try_cancel;
EXPECT_TRUE(server_try_cancel > DO_NOT_CANCEL &&
server_try_cancel <= CANCEL_AFTER_PROCESSING);
break;
@ -618,7 +617,7 @@ class End2endServerTryCancelTest : public End2endTest {
request.message() + std::to_string(num_msgs_read));
num_msgs_read++;
}
gpr_log(GPR_INFO, "Read %d messages", num_msgs_read);
LOG(INFO) << "Read " << num_msgs_read << " messages";
Status s = stream->Finish();
@ -647,8 +646,7 @@ class End2endServerTryCancelTest : public End2endTest {
break;
default: {
gpr_log(GPR_ERROR, "Invalid server_try_cancel value: %d",
server_try_cancel);
LOG(ERROR) << "Invalid server_try_cancel value: " << server_try_cancel;
EXPECT_TRUE(server_try_cancel > DO_NOT_CANCEL &&
server_try_cancel <= CANCEL_AFTER_PROCESSING);
break;
@ -705,8 +703,8 @@ class End2endServerTryCancelTest : public End2endTest {
EXPECT_EQ(response.message(), request.message());
}
gpr_log(GPR_INFO, "Sent %d messages", num_msgs_sent);
gpr_log(GPR_INFO, "Read %d messages", num_msgs_read);
LOG(INFO) << "Sent " << num_msgs_sent << " messages";
LOG(INFO) << "Read " << num_msgs_read << " messages";
stream->WritesDone();
Status s = stream->Finish();
@ -735,8 +733,7 @@ class End2endServerTryCancelTest : public End2endTest {
break;
default:
gpr_log(GPR_ERROR, "Invalid server_try_cancel value: %d",
server_try_cancel);
LOG(ERROR) << "Invalid server_try_cancel value: " << server_try_cancel;
EXPECT_TRUE(server_try_cancel > DO_NOT_CANCEL &&
server_try_cancel <= CANCEL_AFTER_PROCESSING);
break;
@ -1353,7 +1350,7 @@ void ReaderThreadFunc(ClientReaderWriter<EchoRequest, EchoResponse>* stream,
EchoResponse resp;
gpr_event_set(ev, reinterpret_cast<void*>(1));
while (stream->Read(&resp)) {
gpr_log(GPR_INFO, "Read message");
LOG(INFO) << "Read message";
}
}

18
test/cpp/end2end/flaky_network_test.cc
View File

@ -25,12 +25,12 @@
#include <gtest/gtest.h>
#include "absl/log/log.h"
#include "absl/memory/memory.h"
#include <grpc/grpc.h>
#include <grpc/support/alloc.h>
#include <grpc/support/atm.h>
#include <grpc/support/log.h>
#include <grpc/support/port_platform.h>
#include <grpc/support/string_util.h>
#include <grpc/support/time.h>
@ -226,9 +226,9 @@ class FlakyNetworkTest : public ::testing::TestWithParam<TestScenario> {
Status status = stub->Echo(&context, request, response.get());
auto ok = status.ok();
if (ok) {
gpr_log(GPR_DEBUG, "RPC succeeded");
VLOG(2) << "RPC succeeded";
} else {
gpr_log(GPR_DEBUG, "RPC failed: %s", status.error_message().c_str());
VLOG(2) << "RPC failed: " << status.error_message();
}
return ok;
}
@ -245,7 +245,7 @@ class FlakyNetworkTest : public ::testing::TestWithParam<TestScenario> {
: port_(port), creds_(creds) {}
void Start(const std::string& server_host) {
gpr_log(GPR_INFO, "starting server on port %d", port_);
LOG(INFO) << "starting server on port " << port_;
std::mutex mu;
std::unique_lock<std::mutex> lock(mu);
std::condition_variable cond;
@ -253,7 +253,7 @@ class FlakyNetworkTest : public ::testing::TestWithParam<TestScenario> {
std::bind(&ServerData::Serve, this, server_host, &mu, &cond));
cond.wait(lock, [this] { return server_ready_; });
server_ready_ = false;
gpr_log(GPR_INFO, "server startup complete");
LOG(INFO) << "server startup complete";
}
void Serve(const std::string& server_host, std::mutex* mu,
@ -399,7 +399,7 @@ TEST_P(FlakyNetworkTest, ServerUnreachableWithKeepalive) {
// max time between reconnect attempts
args.SetInt(GRPC_ARG_MAX_RECONNECT_BACKOFF_MS, kReconnectBackoffMs);
gpr_log(GPR_DEBUG, "FlakyNetworkTest.ServerUnreachableWithKeepalive start");
VLOG(2) << "FlakyNetworkTest.ServerUnreachableWithKeepalive start";
auto channel = BuildChannel("pick_first", args);
auto stub = BuildStub(channel);
// Channel should be in READY state after we send an RPC
@ -418,18 +418,18 @@ TEST_P(FlakyNetworkTest, ServerUnreachableWithKeepalive) {
});
// break network connectivity
gpr_log(GPR_DEBUG, "Adding iptables rule to drop packets");
VLOG(2) << "Adding iptables rule to drop packets";
DropPackets();
std::this_thread::sleep_for(std::chrono::milliseconds(10000));
EXPECT_TRUE(WaitForChannelNotReady(channel.get()));
// bring network interface back up
RestoreNetwork();
gpr_log(GPR_DEBUG, "Removed iptables rule to drop packets");
VLOG(2) << "Removed iptables rule to drop packets";
EXPECT_TRUE(WaitForChannelReady(channel.get()));
EXPECT_EQ(channel->GetState(false), GRPC_CHANNEL_READY);
shutdown.store(true);
sender.join();
gpr_log(GPR_DEBUG, "FlakyNetworkTest.ServerUnreachableWithKeepalive end");
VLOG(2) << "FlakyNetworkTest.ServerUnreachableWithKeepalive end";
}
//

9
test/cpp/end2end/orca_service_end2end_test.cc
View File

@ -17,6 +17,7 @@
#include <gmock/gmock.h>
#include <gtest/gtest.h>
#include "absl/log/log.h"
#include "absl/strings/str_cat.h"
#include "absl/types/optional.h"
@ -104,7 +105,7 @@ class OrcaServiceEnd2endTest : public ::testing::Test {
builder.AddListeningPort(server_address, grpc::InsecureServerCredentials());
builder.RegisterService(&orca_service_);
server_ = builder.BuildAndStart();
gpr_log(GPR_INFO, "server started on %s", server_address_.c_str());
LOG(INFO) << "server started on " << server_address_;
auto channel = CreateChannel(server_address, InsecureChannelCredentials());
stub_ = OpenRcaService::NewStub(channel);
}
@ -129,13 +130,13 @@ TEST_F(OrcaServiceEnd2endTest, Basic) {
Stream stream1(stub_.get(), grpc_core::Duration::Milliseconds(5000));
Stream stream2(stub_.get(), grpc_core::Duration::Milliseconds(2500));
auto ReadResponses = [&](std::function<void(const OrcaLoadReport&)> checker) {
gpr_log(GPR_INFO, "reading response from stream1");
LOG(INFO) << "reading response from stream1";
OrcaLoadReport response = stream1.ReadResponse();
checker(response);
gpr_log(GPR_INFO, "reading response from stream2");
LOG(INFO) << "reading response from stream2";
response = stream2.ReadResponse();
checker(response);
gpr_log(GPR_INFO, "reading response from stream2");
LOG(INFO) << "reading response from stream2";
response = stream2.ReadResponse();
checker(response);
};

11
test/cpp/end2end/rls_server.cc
View File

@ -18,6 +18,8 @@
#include <gmock/gmock.h>
#include "absl/log/log.h"
#include "src/proto/grpc/lookup/v1/rls.grpc.pb.h"
#include "src/proto/grpc/lookup/v1/rls.pb.h"
#include "test/core/test_util/test_config.h"
@ -31,8 +33,7 @@ namespace testing {
::grpc::Status RlsServiceImpl::RouteLookup(grpc::ServerContext* context,
const RouteLookupRequest* request,
RouteLookupResponse* response) {
gpr_log(GPR_INFO, "RLS: Received request: %s",
request->DebugString().c_str());
LOG(INFO) << "RLS: Received request: " << request->DebugString();
if (context_proc_ != nullptr) {
context_proc_(context);
}
@ -44,7 +45,7 @@ namespace testing {
grpc::internal::MutexLock lock(&mu_);
auto it = responses_.find(*request);
if (it == responses_.end()) {
gpr_log(GPR_INFO, "RLS: no matching request, returning INTERNAL");
LOG(INFO) << "RLS: no matching request, returning INTERNAL";
unmatched_requests_.push_back(*request);
return Status(StatusCode::INTERNAL, "no response entry");
}
@ -57,8 +58,8 @@ namespace testing {
}
IncreaseResponseCount();
*response = res.response;
gpr_log(GPR_INFO, "RLS: returning configured response: %s",
response->DebugString().c_str());
LOG(INFO) << "RLS: returning configured response: "
<< response->DebugString();
return Status::OK;
}

7
test/cpp/end2end/server_load_reporting_end2end_test.cc
View File

@ -21,9 +21,10 @@
#include <gmock/gmock.h>
#include <gtest/gtest.h>
#include "absl/log/log.h"
#include <grpc++/grpc++.h>
#include <grpc/grpc.h>
#include <grpc/support/log.h>
#include <grpc/support/port_platform.h>
#include <grpc/support/string_util.h>
#include <grpcpp/ext/server_load_reporting.h>
@ -138,11 +139,11 @@ TEST_F(ServerLoadReportingEnd2endTest, BasicReport) {
->mutable_load_report_interval()
->set_seconds(5);
stream->Write(request);
gpr_log(GPR_INFO, "Initial request sent.");
LOG(INFO) << "Initial request sent.";
grpc::lb::v1::LoadReportResponse response;
stream->Read(&response);
const std::string& lb_id = response.initial_response().load_balancer_id();
gpr_log(GPR_INFO, "Initial response received (lb_id: %s).", lb_id.c_str());
LOG(INFO) << "Initial response received (lb_id: " << lb_id << ").";
ClientMakeEchoCalls(lb_id, "LB_TAG", kOkMessage, 1);
unsigned load_count = 0;

6
test/cpp/end2end/service_config_end2end_test.cc
View File

@ -28,13 +28,13 @@
#include <gtest/gtest.h>
#include "absl/log/check.h"
#include "absl/log/log.h"
#include "absl/memory/memory.h"
#include "absl/strings/str_cat.h"
#include <grpc/grpc.h>
#include <grpc/support/alloc.h>
#include <grpc/support/atm.h>
#include <grpc/support/log.h>
#include <grpc/support/time.h>
#include <grpcpp/channel.h>
#include <grpcpp/client_context.h>
@ -311,7 +311,7 @@ class ServiceConfigEnd2endTest : public ::testing::Test {
: port_(port > 0 ? port : grpc_pick_unused_port_or_die()) {}
void Start(const std::string& server_host) {
gpr_log(GPR_INFO, "starting server on port %d", port_);
LOG(INFO) << "starting server on port " << port_;
grpc::internal::MutexLock lock(&mu_);
started_ = true;
thread_ = std::make_unique<std::thread>(
@ -320,7 +320,7 @@ class ServiceConfigEnd2endTest : public ::testing::Test {
cond_.Wait(&mu_);
}
server_ready_ = false;
gpr_log(GPR_INFO, "server startup complete");
LOG(INFO) << "server startup complete";
}
void Serve(const std::string& server_host) {

15
test/cpp/end2end/test_service_impl.cc
View File

@ -24,8 +24,8 @@
#include <gtest/gtest.h>
#include "absl/log/check.h"
#include "absl/log/log.h"
#include <grpc/support/log.h>
#include <grpcpp/alarm.h>
#include <grpcpp/security/credentials.h>
#include <grpcpp/server_context.h>
@ -96,7 +96,7 @@ int GetIntValueFromMetadataHelper(
if (metadata.find(key) != metadata.end()) {
std::istringstream iss(ToString(metadata.find(key)->second));
iss >> default_value;
gpr_log(GPR_INFO, "%s : %d", key, default_value);
LOG(INFO) << key << " : " << default_value;
}
return default_value;
@ -112,7 +112,7 @@ int GetIntValueFromMetadata(
void ServerTryCancel(ServerContext* context) {
EXPECT_FALSE(context->IsCancelled());
context->TryCancel();
gpr_log(GPR_INFO, "Server called TryCancel() to cancel the request");
LOG(INFO) << "Server called TryCancel() to cancel the request";
// Now wait until it's really canceled
while (!context->IsCancelled()) {
gpr_sleep_until(gpr_time_add(gpr_now(GPR_CLOCK_REALTIME),
@ -123,8 +123,7 @@ void ServerTryCancel(ServerContext* context) {
void ServerTryCancelNonblocking(CallbackServerContext* context) {
EXPECT_FALSE(context->IsCancelled());
context->TryCancel();
gpr_log(GPR_INFO,
"Server called TryCancelNonblocking() to cancel the request");
LOG(INFO) << "Server called TryCancelNonblocking() to cancel the request";
}
} // namespace internal
@ -211,7 +210,7 @@ ServerUnaryReactor* CallbackTestServiceImpl::Echo(
return;
}
if (req_->has_param() && req_->param().server_die()) {
gpr_log(GPR_ERROR, "The request should not reach application handler.");
LOG(ERROR) << "The request should not reach application handler.";
CHECK(0);
}
if (req_->has_param() && req_->param().has_expected_error()) {
@ -229,7 +228,7 @@ ServerUnaryReactor* CallbackTestServiceImpl::Echo(
// RPC as long as server_try_cancel is not DO_NOT_CANCEL
EXPECT_FALSE(ctx_->IsCancelled());
ctx_->TryCancel();
gpr_log(GPR_INFO, "Server called TryCancel() to cancel the request");
LOG(INFO) << "Server called TryCancel() to cancel the request";
FinishWhenCancelledAsync();
return;
}
@ -398,7 +397,7 @@ ServerReadReactor<EchoRequest>* CallbackTestServiceImpl::RequestStream(
num_msgs_read_++;
StartRead(&request_);
} else {
gpr_log(GPR_INFO, "Read: %d messages", num_msgs_read_);
LOG(INFO) << "Read: " << num_msgs_read_ << " messages";
if (server_try_cancel_ == CANCEL_DURING_PROCESSING) {
// Let OnCancel recover this

27
test/cpp/end2end/test_service_impl.h
View File

@ -28,9 +28,9 @@
#include <gtest/gtest.h>
#include "absl/log/check.h"
#include "absl/log/log.h"
#include <grpc/grpc.h>
#include <grpc/support/log.h>
#include <grpcpp/alarm.h>
#include <grpcpp/security/credentials.h>
#include <grpcpp/server_context.h>
@ -98,35 +98,34 @@ class TestServiceSignaller {
// is whatever the number of RPCs waiting for server notification is
// at that time.
int ClientWaitUntilNRpcsStarted(int desired_rpcs, absl::Duration timeout) {
gpr_log(GPR_DEBUG, "*** enter ClientWaitUntilNRpcsStarted ***");
VLOG(2) << "*** enter ClientWaitUntilNRpcsStarted ***";
absl::Time deadline = absl::Now() + timeout;
std::chrono::system_clock::time_point chrono_deadline =
absl::ToChronoTime(deadline);
std::unique_lock<std::mutex> lock(mu_);
cv_rpc_started_.wait_until(lock, chrono_deadline, [this, desired_rpcs] {
gpr_log(
GPR_DEBUG,
"*** desired_rpcs: %d rpcs_waiting_for_server_to_continue_: %d ***",
desired_rpcs, rpcs_waiting_for_server_to_continue_);
VLOG(2) << "*** desired_rpcs: " << desired_rpcs
<< " rpcs_waiting_for_server_to_continue_: "
<< rpcs_waiting_for_server_to_continue_ << " ***";
return rpcs_waiting_for_server_to_continue_ >= desired_rpcs;
});
gpr_log(GPR_DEBUG, "*** leave ClientWaitUntilNRpcsStarted ***");
VLOG(2) << "*** leave ClientWaitUntilNRpcsStarted ***";
return rpcs_waiting_for_server_to_continue_;
}
void ServerWaitToContinue() {
gpr_log(GPR_DEBUG, "*** enter ServerWaitToContinue ***");
VLOG(2) << "*** enter ServerWaitToContinue ***";
std::unique_lock<std::mutex> lock(mu_);
cv_server_continue_.wait(lock, [this] { return server_should_continue_; });
gpr_log(GPR_DEBUG, "*** leave ServerWaitToContinue ***");
VLOG(2) << "*** leave ServerWaitToContinue ***";
}
void SignalClientThatRpcStarted() {
gpr_log(GPR_DEBUG, "*** SignalClientThatRpcStarted ***");
VLOG(2) << "*** SignalClientThatRpcStarted ***";
std::unique_lock<std::mutex> lock(mu_);
++rpcs_waiting_for_server_to_continue_;
cv_rpc_started_.notify_all();
}
void SignalServerToContinue() {
gpr_log(GPR_DEBUG, "*** SignalServerToContinue ***");
VLOG(2) << "*** SignalServerToContinue ***";
std::unique_lock<std::mutex> lock(mu_);
server_should_continue_ = true;
cv_server_continue_.notify_all();
@ -170,7 +169,7 @@ class TestMultipleServiceImpl : public RpcService {
}
if (request->has_param() && request->param().server_die()) {
gpr_log(GPR_ERROR, "The request should not reach application handler.");
LOG(ERROR) << "The request should not reach application handler.";
CHECK(0);
}
if (request->has_param() && request->param().has_expected_error()) {
@ -330,7 +329,7 @@ class TestMultipleServiceImpl : public RpcService {
while (reader->Read(&request)) {
response->mutable_message()->append(request.message());
}
gpr_log(GPR_INFO, "Read: %d messages", num_msgs_read);
LOG(INFO) << "Read: " << num_msgs_read << " messages";
if (server_try_cancel_thd != nullptr) {
server_try_cancel_thd->join();
@ -441,7 +440,7 @@ class TestMultipleServiceImpl : public RpcService {
int read_counts = 0;
while (stream->Read(&request)) {
read_counts++;
gpr_log(GPR_INFO, "recv msg %s", request.message().c_str());
LOG(INFO) << "recv msg " << request.message();
response.set_message(request.message());
if (read_counts == server_write_last) {
stream->WriteLast(response, WriteOptions());

21
test/cpp/end2end/xds/xds_cluster_end2end_test.cc
View File

@ -20,6 +20,7 @@
#include <gmock/gmock.h>
#include <gtest/gtest.h>
#include "absl/log/log.h"
#include "absl/strings/match.h"
#include "absl/strings/str_cat.h"
@ -898,10 +899,10 @@ TEST_P(EdsTest, LocalityMapUpdateChurn) {
balancer_->ads_service()->SetEdsResource(BuildEdsResource(args));
// Wait for the first 3 backends to be ready.
WaitForAllBackends(DEBUG_LOCATION, 0, 3);
gpr_log(GPR_INFO, "========= BEFORE FIRST BATCH ==========");
LOG(INFO) << "========= BEFORE FIRST BATCH ==========";
// Send kNumRpcs RPCs.
CheckRpcSendOk(DEBUG_LOCATION, kNumRpcs);
gpr_log(GPR_INFO, "========= DONE WITH FIRST BATCH ==========");
LOG(INFO) << "========= DONE WITH FIRST BATCH ==========";
// The picking rates of the first 3 backends should be roughly equal to the
// expectation.
std::vector<double> locality_picked_rates;
@ -931,10 +932,10 @@ TEST_P(EdsTest, LocalityMapUpdateChurn) {
// Wait until the locality update has been processed, as signaled by backend
// 3 receiving a request.
WaitForAllBackends(DEBUG_LOCATION, 3, 4);
gpr_log(GPR_INFO, "========= BEFORE SECOND BATCH ==========");
LOG(INFO) << "========= BEFORE SECOND BATCH ==========";
// Send kNumRpcs RPCs.
CheckRpcSendOk(DEBUG_LOCATION, kNumRpcs);
gpr_log(GPR_INFO, "========= DONE WITH SECOND BATCH ==========");
LOG(INFO) << "========= DONE WITH SECOND BATCH ==========";
// Backend 0 no longer receives any request.
EXPECT_EQ(0U, backends_[0]->backend_service()->request_count());
// The picking rates of the last 3 backends should be roughly equal to the
@ -1091,11 +1092,11 @@ TEST_P(EdsTest, DropConfigUpdate) {
args.drop_categories = {{kLbDropType, kDropPerMillionForLb}};
balancer_->ads_service()->SetEdsResource(BuildEdsResource(args));
// Send kNumRpcsLbOnly RPCs and count the drops.
gpr_log(GPR_INFO, "========= BEFORE FIRST BATCH ==========");
LOG(INFO) << "========= BEFORE FIRST BATCH ==========";
size_t num_drops = SendRpcsAndCountFailuresWithMessage(
DEBUG_LOCATION, kNumRpcsLbOnly, StatusCode::UNAVAILABLE,
kStatusMessageDropPrefix);
gpr_log(GPR_INFO, "========= DONE WITH FIRST BATCH ==========");
LOG(INFO) << "========= DONE WITH FIRST BATCH ==========";
// The drop rate should be roughly equal to the expectation.
double seen_drop_rate = static_cast<double>(num_drops) / kNumRpcsLbOnly;
gpr_log(GPR_INFO, "First batch drop rate %f", seen_drop_rate);
@ -1128,11 +1129,11 @@ TEST_P(EdsTest, DropConfigUpdate) {
},
/*timeout_ms=*/40000);
// Send kNumRpcsBoth RPCs and count the drops.
gpr_log(GPR_INFO, "========= BEFORE SECOND BATCH ==========");
LOG(INFO) << "========= BEFORE SECOND BATCH ==========";
num_drops = SendRpcsAndCountFailuresWithMessage(DEBUG_LOCATION, kNumRpcsBoth,
StatusCode::UNAVAILABLE,
kStatusMessageDropPrefix);
gpr_log(GPR_INFO, "========= DONE WITH SECOND BATCH ==========");
LOG(INFO) << "========= DONE WITH SECOND BATCH ==========";
// The new drop rate should be roughly equal to the expectation.
seen_drop_rate = static_cast<double>(num_drops) / kNumRpcsBoth;
gpr_log(GPR_INFO, "Second batch drop rate %f", seen_drop_rate);
@ -1268,9 +1269,9 @@ TEST_P(FailoverTest, ReportsConnectingDuringFailover) {
// Allow the connection attempt to complete.
hold->Resume();
// Now the RPC should complete successfully.
gpr_log(GPR_INFO, "=== WAITING FOR RPC TO FINISH ===");
LOG(INFO) << "=== WAITING FOR RPC TO FINISH ===";
Status status = rpc.GetStatus();
gpr_log(GPR_INFO, "=== RPC FINISHED ===");
LOG(INFO) << "=== RPC FINISHED ===";
EXPECT_TRUE(status.ok()) << "code=" << status.error_code()
<< " message=" << status.error_message();
}

5
test/cpp/end2end/xds/xds_cluster_type_end2end_test.cc
View File

@ -19,6 +19,7 @@
#include <gtest/gtest.h>
#include "absl/log/check.h"
#include "absl/log/log.h"
#include "absl/status/statusor.h"
#include "absl/strings/str_cat.h"
@ -367,9 +368,9 @@ TEST_P(AggregateClusterTest, FallBackWithConnectivityChurn) {
// Meanwhile, the channel will also start a second attempt for backend
// 0, which we have NOT held, so it will complete normally, and the
// RPC will finish on backend 0.
gpr_log(GPR_INFO, "=== WAITING FOR RPC TO FINISH === ");
LOG(INFO) << "=== WAITING FOR RPC TO FINISH === ";
Status status = rpc.GetStatus();
gpr_log(GPR_INFO, "=== RPC FINISHED === ");
LOG(INFO) << "=== RPC FINISHED === ";
EXPECT_TRUE(status.ok()) << "code=" << status.error_code()
<< " message=" << status.error_message();
EXPECT_EQ(1UL, backends_[0]->backend_service()->request_count());

9
test/cpp/end2end/xds/xds_end2end_test.cc
View File

@ -33,6 +33,7 @@
#include "absl/functional/bind_front.h"
#include "absl/log/check.h"
#include "absl/log/log.h"
#include "absl/memory/memory.h"
#include "absl/strings/match.h"
#include "absl/strings/str_cat.h"
@ -45,7 +46,6 @@
#include <grpc/grpc.h>
#include <grpc/grpc_security.h>
#include <grpc/support/alloc.h>
#include <grpc/support/log.h>
#include <grpc/support/time.h>
#include <grpcpp/channel.h>
#include <grpcpp/client_context.h>
@ -398,8 +398,7 @@ class XdsSecurityTest : public XdsEnd2endTest {
DEBUG_LOCATION,
[&](const RpcResult& result) {
if (result.status.ok()) {
gpr_log(GPR_ERROR,
"RPC succeeded. Failure expected. Trying again.");
LOG(ERROR) << "RPC succeeded. Failure expected. Trying again.";
return true;
}
EXPECT_EQ(result.status.error_code(), StatusCode::UNAVAILABLE);
@ -1051,7 +1050,7 @@ class XdsServerSecurityTest : public XdsEnd2endTest {
std::vector<std::string> expected_client_identity,
bool test_expects_failure = false,
absl::optional<grpc::StatusCode> expected_status = absl::nullopt) {
gpr_log(GPR_INFO, "Sending RPC");
LOG(INFO) << "Sending RPC";
int num_tries = 0;
constexpr int kRetryCount = 100;
auto overall_deadline = absl::Now() + absl::Seconds(5);
@ -1073,7 +1072,7 @@ class XdsServerSecurityTest : public XdsEnd2endTest {
Status status = stub->Echo(&context, request, &response);
if (test_expects_failure) {
if (status.ok()) {
gpr_log(GPR_ERROR, "RPC succeeded. Failure expected. Trying again.");
LOG(ERROR) << "RPC succeeded. Failure expected. Trying again.";
continue;
}
if (expected_status.has_value() &&

35
test/cpp/end2end/xds/xds_server.cc
View File

@ -23,10 +23,9 @@
#include <vector>
#include "absl/log/check.h"
#include "absl/log/log.h"
#include "absl/types/optional.h"
#include <grpc/support/log.h>
#include "src/core/lib/address_utils/parse_address.h"
#include "src/core/lib/gprpp/crash.h"
#include "src/core/lib/gprpp/sync.h"
@ -51,10 +50,9 @@ void AdsServiceImpl::SetResource(google::protobuf::Any resource,
resource_state.resource_type_version =
resource_type_state.resource_type_version;
resource_state.resource = std::move(resource);
gpr_log(GPR_INFO,
"ADS[%s]: Updating %s resource %s; resource_type_version now %u",
debug_label_.c_str(), type_url.c_str(), name.c_str(),
resource_type_state.resource_type_version);
LOG(INFO) << "ADS[" << debug_label_ << "]: Updating " << type_url
<< " resource " << name << "; resource_type_version now "
<< resource_type_state.resource_type_version;
for (SubscriptionState* subscription : resource_state.subscriptions) {
subscription->update_queue->emplace_back(type_url, name);
}
@ -69,10 +67,9 @@ void AdsServiceImpl::UnsetResource(const std::string& type_url,
resource_state.resource_type_version =
resource_type_state.resource_type_version;
resource_state.resource.reset();
gpr_log(GPR_INFO,
"ADS[%s]: Unsetting %s resource %s; resource_type_version now %u",
debug_label_.c_str(), type_url.c_str(), name.c_str(),
resource_type_state.resource_type_version);
LOG(INFO) << "ADS[" << debug_label_ << "]: Unsetting " << type_url
<< " resource " << name << "; resource_type_version now "
<< resource_type_state.resource_type_version;
for (SubscriptionState* subscription : resource_state.subscriptions) {
subscription->update_queue->emplace_back(type_url, name);
}
@ -101,9 +98,9 @@ bool AdsServiceImpl::MaybeSubscribe(const std::string& resource_type,
if (subscription_state->update_queue != nullptr) return false;
subscription_state->update_queue = update_queue;
resource_state->subscriptions.emplace(subscription_state);
gpr_log(GPR_INFO, "ADS[%s]: subscribe to resource type %s name %s state %p",
debug_label_.c_str(), resource_type.c_str(), resource_name.c_str(),
&subscription_state);
LOG(INFO) << "ADS[" << debug_label_ << "]: subscribe to resource type "
<< resource_type << " name " << resource_name << " state "
<< &subscription_state;
return true;
}
@ -123,9 +120,9 @@ void AdsServiceImpl::ProcessUnsubscriptions(
++it;
continue;
}
gpr_log(GPR_INFO, "ADS[%s]: Unsubscribe to type=%s name=%s state=%p",
debug_label_.c_str(), resource_type.c_str(), resource_name.c_str(),
&subscription_state);
LOG(INFO) << "ADS[" << debug_label_
<< "]: Unsubscribe to type=" << resource_type
<< " name=" << resource_name << " state=" << &subscription_state;
auto resource_it = resource_name_map->find(resource_name);
CHECK(resource_it != resource_name_map->end());
auto& resource_state = resource_it->second;
@ -152,7 +149,7 @@ void AdsServiceImpl::Shutdown() {
}
resource_type_response_state_.clear();
}
gpr_log(GPR_INFO, "ADS[%s]: shut down", debug_label_.c_str());
LOG(INFO) << "ADS[" << debug_label_ << "]: shut down";
}
//
@ -233,7 +230,7 @@ void LrsServiceImpl::Shutdown() {
lrs_cv_.SignalAll();
}
}
gpr_log(GPR_INFO, "LRS[%s]: shut down", debug_label_.c_str());
LOG(INFO) << "LRS[" << debug_label_ << "]: shut down";
}
std::vector<LrsServiceImpl::ClientStats> LrsServiceImpl::WaitForLoadReport(
@ -245,7 +242,7 @@ std::vector<LrsServiceImpl::ClientStats> LrsServiceImpl::WaitForLoadReport(
load_report_cond_ = &cv;
while (result_queue_.empty()) {
if (cv.WaitWithTimeout(&load_report_mu_, timeout)) {
gpr_log(GPR_ERROR, "timed out waiting for load report");
LOG(ERROR) << "timed out waiting for load report";
return {};
}
}