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

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

COPYBARA_INTEGRATE_REVIEW=https://github.com/grpc/grpc/pull/36608 from tanvi-jagtap:regex_test_core_misc e6b9481dac
PiperOrigin-RevId: 634246311
pull/36617/head
Tanvi Jagtap 8 months ago committed by Copybara-Service
parent 3ca738907c
commit ed5893120e
  1. 21
      test/core/event_engine/test_suite/posix/oracle_event_engine_posix.cc
  2. 9
      test/core/event_engine/windows/iocp_test.cc
  3. 12
      test/core/gprpp/mpscq_test.cc
  4. 3
      test/core/gprpp/single_set_ptr_test.cc
  5. 20
      test/core/handshake/client_ssl.cc
  6. 12
      test/core/handshake/server_ssl_common.cc
  7. 4
      test/core/handshake/verify_peer_options.cc
  8. 8
      test/core/http/httpcli_test_util.cc
  9. 98
      test/core/load_balancing/lb_policy_test_lib.h
  10. 38
      test/core/load_balancing/outlier_detection_test.cc
  11. 26
      test/core/load_balancing/weighted_round_robin_test.cc
  12. 29
      test/core/load_balancing/xds_override_host_test.cc
  13. 76
      test/core/network_benchmarks/low_level_ping_pong.cc
  14. 7
      test/core/promise/party_test.cc
  15. 5
      test/core/slice/slice_test.cc
  16. 6
      test/core/surface/completion_queue_test.cc
  17. 42
      test/core/surface/completion_queue_threading_test.cc
  18. 8
      test/core/surface/concurrent_connectivity_test.cc
  19. 4
      test/core/test_util/cmdline.h
  20. 17
      test/core/test_util/reconnect_server.cc
  21. 17
      test/core/test_util/test_config.cc
  22. 10
      test/core/tsi/alts/fake_handshaker/fake_handshaker_server.cc
  23. 34
      test/core/tsi/alts/handshaker/alts_concurrent_connectivity_test.cc
  24. 9
      test/core/tsi/alts/handshaker/alts_handshaker_service_api_test_lib.cc
  25. 69
      test/core/tsi/ssl_transport_security_test.cc
  26. 70
      test/core/xds/xds_client_fuzzer.cc

@ -24,6 +24,7 @@
#include <memory>
#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"
@ -32,7 +33,6 @@
#include <grpc/event_engine/event_engine.h>
#include <grpc/support/alloc.h>
#include <grpc/support/log.h>
#include "src/core/lib/address_utils/sockaddr_utils.h"
#include "src/core/lib/gprpp/crash.h"
@ -255,7 +255,7 @@ bool PosixOracleEndpoint::Write(
}
void PosixOracleEndpoint::ProcessReadOperations() {
gpr_log(GPR_INFO, "Starting thread to process read ops ...");
LOG(INFO) << "Starting thread to process read ops ...";
while (true) {
read_op_signal_->WaitForNotification();
read_op_signal_ = std::make_unique<grpc_core::Notification>();
@ -273,11 +273,11 @@ void PosixOracleEndpoint::ProcessReadOperations() {
grpc_core::StrError(saved_errno)))
: absl::OkStatus());
}
gpr_log(GPR_INFO, "Shutting down read ops thread ...");
LOG(INFO) << "Shutting down read ops thread ...";
}
void PosixOracleEndpoint::ProcessWriteOperations() {
gpr_log(GPR_INFO, "Starting thread to process write ops ...");
LOG(INFO) << "Starting thread to process write ops ...";
while (true) {
write_op_signal_->WaitForNotification();
write_op_signal_ = std::make_unique<grpc_core::Notification>();
@ -293,7 +293,7 @@ void PosixOracleEndpoint::ProcessWriteOperations() {
grpc_core::StrError(saved_errno)))
: absl::OkStatus());
}
gpr_log(GPR_INFO, "Shutting down write ops thread ...");
LOG(INFO) << "Shutting down write ops thread ...";
}
PosixOracleListener::PosixOracleListener(
@ -341,7 +341,7 @@ PosixOracleListener::~PosixOracleListener() {
}
void PosixOracleListener::HandleIncomingConnections() {
gpr_log(GPR_INFO, "Starting accept thread ...");
LOG(INFO) << "Starting accept thread ...";
CHECK(!listener_fds_.empty());
int nfds = listener_fds_.size();
// Add one extra file descriptor to poll the pipe fd.
@ -371,17 +371,16 @@ void PosixOracleListener::HandleIncomingConnections() {
// pfds[i].fd has a readable event.
int client_sock_fd = accept(pfds[i].fd, nullptr, nullptr);
if (client_sock_fd < 0) {
gpr_log(GPR_ERROR,
"Error accepting new connection: %s. Ignoring connection "
"attempt ...",
grpc_core::StrError(errno).c_str());
LOG(ERROR) << "Error accepting new connection: "
<< grpc_core::StrError(errno)
<< ". Ignoring connection attempt ...";
continue;
}
on_accept_(PosixOracleEndpoint::Create(client_sock_fd),
memory_allocator_factory_->CreateMemoryAllocator("test"));
}
}
gpr_log(GPR_INFO, "Shutting down accept thread ...");
LOG(INFO) << "Shutting down accept thread ...";
gpr_free(pfds);
}

@ -19,6 +19,7 @@
#include <gmock/gmock.h>
#include <gtest/gtest.h>
#include "absl/log/log.h"
#include "absl/status/status.h"
#include "absl/time/time.h"
#include "absl/types/variant.h"
@ -49,7 +50,7 @@ using ::grpc_event_engine::experimental::WinSocket;
// `ASSERT_OK(...) << GetErrorMessage(error, context);`
void LogErrorMessage(int messageid, absl::string_view context) {
char* utf8_message = gpr_format_message(messageid);
gpr_log(GPR_ERROR, "Error in %s: %s", context, utf8_message);
LOG(ERROR) << "Error in " << context << ": " << utf8_message;
gpr_free(utf8_message);
}
} // namespace
@ -77,7 +78,7 @@ TEST_F(IOCPTest, ClientReceivesNotificationOfServerSend) {
DWORD bytes_rcvd;
on_read = new AnyInvocableClosure([win_socket = wrapped_client_socket.get(),
&read_called, &read_wsabuf]() {
gpr_log(GPR_DEBUG, "Notified on read");
VLOG(2) << "Notified on read";
EXPECT_GE(win_socket->read_info()->result().bytes_transferred, 10u);
EXPECT_STREQ(read_wsabuf.buf, "hello!");
read_called.Notify();
@ -96,7 +97,7 @@ TEST_F(IOCPTest, ClientReceivesNotificationOfServerSend) {
}
{
on_write = new AnyInvocableClosure([&write_called] {
gpr_log(GPR_DEBUG, "Notified on write");
VLOG(2) << "Notified on write";
write_called.Notify();
});
wrapped_server_socket->NotifyOnWrite(on_write);
@ -153,7 +154,7 @@ TEST_F(IOCPTest, IocpWorkTimeoutDueToNoNotificationRegistered) {
wrapped_client_socket->NotifyOnRead(
SelfDeletingClosure::Create([win_socket = wrapped_client_socket.get(),
&read_called, &read_wsabuf]() {
gpr_log(GPR_DEBUG, "Notified on read");
VLOG(2) << "Notified on read";
EXPECT_GE(win_socket->read_info()->result().bytes_transferred, 10u);
EXPECT_STREQ(read_wsabuf.buf, "hello!");
read_called.Notify();

@ -23,9 +23,9 @@
#include <memory>
#include "absl/log/log.h"
#include "gtest/gtest.h"
#include <grpc/support/log.h>
#include <grpc/support/sync.h>
#include <grpc/support/time.h>
@ -49,7 +49,7 @@ static test_node* new_node(size_t i, size_t* ctr) {
}
TEST(MpscqTest, Serial) {
gpr_log(GPR_DEBUG, "test_serial");
VLOG(2) << "test_serial";
MultiProducerSingleConsumerQueue q;
for (size_t i = 0; i < 10000000; i++) {
q.Push(&new_node(i, nullptr)->node);
@ -79,7 +79,7 @@ static void test_thread(void* args) {
}
TEST(MpscqTest, Mt) {
gpr_log(GPR_DEBUG, "test_mt");
VLOG(2) << "test_mt";
gpr_event start;
gpr_event_init(&start);
grpc_core::Thread thds[100];
@ -106,7 +106,7 @@ TEST(MpscqTest, Mt) {
if (tn->i == THREAD_ITERATIONS) num_done++;
delete tn;
}
gpr_log(GPR_DEBUG, "spins: %" PRIdPTR, spins);
VLOG(2) << "spins: " << spins;
for (auto& th : thds) {
th.Join();
}
@ -146,7 +146,7 @@ static void pull_thread(void* arg) {
}
TEST(MpscqTest, MtMultipop) {
gpr_log(GPR_DEBUG, "test_mt_multipop");
VLOG(2) << "test_mt_multipop";
gpr_event start;
gpr_event_init(&start);
grpc_core::Thread thds[50];
@ -176,7 +176,7 @@ TEST(MpscqTest, MtMultipop) {
for (auto& pth : pull_thds) {
pth.Join();
}
gpr_log(GPR_DEBUG, "spins: %" PRIdPTR, pa.spins);
VLOG(2) << "spins: " << pa.spins;
for (auto& th : thds) {
th.Join();
}

@ -18,6 +18,7 @@
#include <thread>
#include <vector>
#include "absl/log/log.h"
#include "gtest/gtest.h"
namespace grpc_core {
@ -28,7 +29,7 @@ TEST(SingleSetPtrTest, NoOp) { SingleSetPtr<int>(); }
TEST(SingleSetPtrTest, CanSet) {
SingleSetPtr<int> p;
EXPECT_FALSE(p.is_set());
EXPECT_DEATH_IF_SUPPORTED(gpr_log(GPR_ERROR, "%d", *p), "");
EXPECT_DEATH_IF_SUPPORTED({ LOG(ERROR) << *p; }, "");
p.Set(new int(42));
EXPECT_EQ(*p, 42);
}

@ -24,6 +24,7 @@
#include <openssl/evp.h>
#include "absl/base/thread_annotations.h"
#include "absl/strings/str_format.h"
#include "gtest/gtest.h"
#include <grpc/impl/channel_arg_names.h>
@ -49,12 +50,12 @@
#include <openssl/err.h>
#include <openssl/ssl.h>
#include "absl/log/log.h"
#include "absl/strings/str_cat.h"
#include <grpc/credentials.h>
#include <grpc/grpc.h>
#include <grpc/grpc_security.h>
#include <grpc/support/log.h>
#include "src/core/lib/debug/trace.h"
#include "src/core/lib/gprpp/crash.h"
@ -119,7 +120,7 @@ static int create_socket(int* out_port) {
if (bind(s, reinterpret_cast<struct sockaddr*>(&addr), sizeof(addr)) < 0) {
perror("Unable to bind");
gpr_log(GPR_ERROR, "%s", "Unable to bind to any port");
LOG(ERROR) << "Unable to bind to any port";
close(s);
return -1;
}
@ -135,7 +136,7 @@ static int create_socket(int* out_port) {
0 ||
addr_len > sizeof(addr)) {
perror("getsockname");
gpr_log(GPR_ERROR, "%s", "Unable to get socket local address");
LOG(ERROR) << "Unable to get socket local address";
close(s);
return -1;
}
@ -176,14 +177,15 @@ static void ssl_log_where_info(const SSL* ssl, int where, int flag,
const char* msg) {
if ((where & flag) &&
GRPC_TRACE_FLAG_ENABLED(client_ssl_tsi_tracing_enabled)) {
gpr_log(GPR_INFO, "%20.20s - %30.30s - %5.10s", msg,
SSL_state_string_long(ssl), SSL_state_string(ssl));
LOG(INFO) << absl::StrFormat("%20.20s - %30.30s - %5.10s", msg,
SSL_state_string_long(ssl),
SSL_state_string(ssl));
}
}
static void ssl_server_info_callback(const SSL* ssl, int where, int ret) {
if (ret == 0) {
gpr_log(GPR_ERROR, "ssl_server_info_callback: error occurred.\n");
LOG(ERROR) << "ssl_server_info_callback: error occurred.\n";
return;
}
@ -251,7 +253,7 @@ static void server_thread(void* arg) {
// bind/listen/accept at TCP layer.
const int sock = args->socket;
gpr_log(GPR_INFO, "Server listening");
LOG(INFO) << "Server listening";
struct sockaddr_in addr;
socklen_t len = sizeof(addr);
const int client =
@ -268,9 +270,9 @@ static void server_thread(void* arg) {
SSL_set_fd(ssl, client);
if (SSL_accept(ssl) <= 0) {
ERR_print_errors_fp(stderr);
gpr_log(GPR_ERROR, "Handshake failed.");
LOG(ERROR) << "Handshake failed.";
} else {
gpr_log(GPR_INFO, "Handshake successful.");
LOG(INFO) << "Handshake successful.";
}
// Send out the settings frame.

@ -35,6 +35,7 @@
#include "absl/base/thread_annotations.h"
#include "absl/log/check.h"
#include "absl/log/log.h"
#include "absl/strings/str_cat.h"
#include <grpc/credentials.h>
@ -42,7 +43,6 @@
#include <grpc/grpc_security.h>
#include <grpc/slice.h>
#include <grpc/support/alloc.h>
#include <grpc/support/log.h>
#include <grpc/support/sync.h>
#include <grpc/support/time.h>
@ -152,7 +152,7 @@ void server_thread(void* arg) {
CHECK(ev.type == GRPC_QUEUE_TIMEOUT);
}
gpr_log(GPR_INFO, "Shutting down server");
LOG(INFO) << "Shutting down server";
grpc_server_shutdown_and_notify(server, cq, nullptr);
grpc_completion_queue_shutdown(cq);
@ -246,7 +246,7 @@ bool server_ssl_test(const char* alpn_list[], unsigned int alpn_list_len,
}
}
CHECK_GT(sock, 0);
gpr_log(GPR_INFO, "Connected to server on port %d", s.port());
LOG(INFO) << "Connected to server on port " << s.port();
// Establish a SSL* and connect at SSL layer.
SSL* ssl = SSL_new(ctx);
@ -254,10 +254,10 @@ bool server_ssl_test(const char* alpn_list[], unsigned int alpn_list_len,
SSL_set_fd(ssl, sock);
if (SSL_connect(ssl) <= 0) {
ERR_print_errors_fp(stderr);
gpr_log(GPR_ERROR, "Handshake failed.");
LOG(ERROR) << "Handshake failed.";
success = false;
} else {
gpr_log(GPR_INFO, "Handshake successful.");
LOG(INFO) << "Handshake successful.";
// Validate ALPN preferred by server matches alpn_expected.
const unsigned char* alpn_selected;
unsigned int alpn_selected_len;
@ -265,7 +265,7 @@ bool server_ssl_test(const char* alpn_list[], unsigned int alpn_list_len,
if (strlen(alpn_expected) != alpn_selected_len ||
strncmp(reinterpret_cast<const char*>(alpn_selected), alpn_expected,
alpn_selected_len) != 0) {
gpr_log(GPR_ERROR, "Unexpected ALPN protocol preference");
LOG(ERROR) << "Unexpected ALPN protocol preference";
success = false;
}
}

@ -33,13 +33,13 @@
#include <openssl/ssl.h>
#include "absl/log/check.h"
#include "absl/log/log.h"
#include "absl/strings/str_cat.h"
#include <grpc/credentials.h>
#include <grpc/grpc.h>
#include <grpc/grpc_security.h>
#include <grpc/support/alloc.h>
#include <grpc/support/log.h>
#include "src/core/lib/gprpp/crash.h"
#include "src/core/lib/gprpp/thd.h"
@ -89,7 +89,7 @@ static void server_thread(void* arg) {
CHECK(ev.type == GRPC_QUEUE_TIMEOUT);
}
gpr_log(GPR_INFO, "Shutting down server");
LOG(INFO) << "Shutting down server";
grpc_server_shutdown_and_notify(server, cq, nullptr);
grpc_server_cancel_all_calls(server);
grpc_completion_queue_shutdown(cq);

@ -23,11 +23,11 @@
#include <vector>
#include "absl/log/check.h"
#include "absl/log/log.h"
#include "absl/strings/str_cat.h"
#include "absl/types/optional.h"
#include <grpc/support/alloc.h>
#include <grpc/support/log.h>
#include <grpc/support/port_platform.h>
#include <grpc/support/string_util.h>
#include <grpc/support/time.h>
@ -86,10 +86,10 @@ HttpRequestTestServer StartHttpRequestTestServer(int argc, char** argv,
absl::StrCat(root, "/src/core/tsi/test_creds/ca.pem");
ConfigVars::SetOverrides(overrides);
}
gpr_log(GPR_INFO, "starting HttpRequest test server subprocess:");
LOG(INFO) << "starting HttpRequest test server subprocess:";
for (size_t i = 0; i < args.size(); i++) {
gpr_log(GPR_INFO, " HttpRequest test server subprocess argv[%ld]: %s", i,
args[i]);
LOG(INFO) << " HttpRequest test server subprocess argv[" << i
<< "]: " << args[i];
}
gpr_subprocess* server =
gpr_subprocess_create(args.size(), const_cast<const char**>(args.data()));

@ -36,6 +36,7 @@
#include "absl/base/thread_annotations.h"
#include "absl/functional/any_invocable.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_format.h"
@ -51,7 +52,6 @@
#include <grpc/event_engine/event_engine.h>
#include <grpc/grpc.h>
#include <grpc/support/alloc.h>
#include <grpc/support/log.h>
#include <grpc/support/port_platform.h>
#include "src/core/client_channel/client_channel_internal.h"
@ -152,8 +152,8 @@ class LoadBalancingPolicyTest : public ::testing::Test {
void OnConnectivityStateChange(grpc_connectivity_state new_state,
const absl::Status& status) override {
gpr_log(GPR_INFO, "notifying watcher: state=%s status=%s",
ConnectivityStateName(new_state), status.ToString().c_str());
LOG(INFO) << "notifying watcher: state="
<< ConnectivityStateName(new_state) << " status=" << status;
watcher_->OnConnectivityStateChange(new_state, status);
}
@ -212,11 +212,10 @@ class LoadBalancingPolicyTest : public ::testing::Test {
health_watcher_wrapper_ = watcher_wrapper.get();
state_->state_tracker_.AddWatcher(GRPC_CHANNEL_SHUTDOWN,
std::move(watcher_wrapper));
gpr_log(GPR_INFO,
"AddDataWatcher(): added HealthWatch=%p "
"connectivity_watcher=%p watcher_wrapper=%p",
health_watcher_.get(), connectivity_watcher_ptr,
health_watcher_wrapper_);
LOG(INFO) << "AddDataWatcher(): added HealthWatch="
<< health_watcher_.get()
<< " connectivity_watcher=" << connectivity_watcher_ptr
<< " watcher_wrapper=" << health_watcher_wrapper_;
}
}
@ -232,10 +231,9 @@ class LoadBalancingPolicyTest : public ::testing::Test {
if (health_watcher_.get() != static_cast<HealthWatcher*>(watcher)) {
return;
}
gpr_log(GPR_INFO,
"CancelDataWatcher(): cancelling HealthWatch=%p "
"watcher_wrapper=%p",
health_watcher_.get(), health_watcher_wrapper_);
LOG(INFO) << "CancelDataWatcher(): cancelling HealthWatch="
<< health_watcher_.get()
<< " watcher_wrapper=" << health_watcher_wrapper_;
state_->state_tracker_.RemoveWatcher(health_watcher_wrapper_);
health_watcher_wrapper_ = nullptr;
health_watcher_.reset();
@ -327,18 +325,16 @@ class LoadBalancingPolicyTest : public ::testing::Test {
AssertValidConnectivityStateTransition(state_tracker_.state(),
state, location);
}
gpr_log(GPR_INFO, "Setting state on tracker");
LOG(INFO) << "Setting state on tracker";
state_tracker_.SetState(state, status, "set from test");
// SetState() enqueued the connectivity state notifications for
// the subchannel, so we add another callback to the queue to be
// executed after that state notifications has been delivered.
gpr_log(GPR_INFO,
"Waiting for state notifications to be delivered");
LOG(INFO) << "Waiting for state notifications to be delivered";
test_->work_serializer_->Run(
[&]() {
gpr_log(GPR_INFO,
"State notifications delivered, waiting for health "
"notifications");
LOG(INFO) << "State notifications delivered, waiting for "
"health notifications";
// Now the connectivity state notifications has been
// delivered. If the state reported was READY, then the
// pick_first leaf policy will have started a health watch, so
@ -351,7 +347,7 @@ class LoadBalancingPolicyTest : public ::testing::Test {
},
DEBUG_LOCATION);
notification.WaitForNotification();
gpr_log(GPR_INFO, "Health notifications delivered");
LOG(INFO) << "Health notifications delivered";
}
// Indicates if any of the associated SubchannelInterface objects
@ -472,8 +468,7 @@ class LoadBalancingPolicyTest : public ::testing::Test {
<< location.file() << ":" << location.line();
if (update == nullptr) return absl::nullopt;
StateUpdate result = std::move(*update);
gpr_log(GPR_INFO, "dequeued next state update: %s",
result.ToString().c_str());
LOG(INFO) << "dequeued next state update: " << result.ToString();
queue_.pop_front();
return std::move(result);
}
@ -506,8 +501,8 @@ class LoadBalancingPolicyTest : public ::testing::Test {
PickerWrapper(LoadBalancingPolicyTest* test,
RefCountedPtr<LoadBalancingPolicy::SubchannelPicker> picker)
: test_(test), picker_(std::move(picker)) {
gpr_log(GPR_INFO, "creating wrapper %p for picker %p", this,
picker_.get());
LOG(INFO) << "creating wrapper " << this << " for picker "
<< picker_.get();
}
void Orphaned() override {
@ -579,8 +574,8 @@ class LoadBalancingPolicyTest : public ::testing::Test {
StateUpdate update{
state, status,
MakeRefCounted<PickerWrapper>(test_, std::move(picker))};
gpr_log(GPR_INFO, "enqueuing state update from LB policy: %s",
update.ToString().c_str());
LOG(INFO) << "enqueuing state update from LB policy: "
<< update.ToString();
queue_.push_back(std::move(update));
}
@ -847,14 +842,12 @@ class LoadBalancingPolicyTest : public ::testing::Test {
// notifications for the subchannels, so we add another
// callback to the queue to be executed after those initial
// state notifications have been delivered.
gpr_log(GPR_INFO,
"Applied update, waiting for initial connectivity state "
"notifications");
LOG(INFO) << "Applied update, waiting for initial connectivity state "
"notifications";
work_serializer_->Run(
[&]() {
gpr_log(GPR_INFO,
"Initial connectivity state notifications delivered; "
"waiting for health notifications");
LOG(INFO) << "Initial connectivity state notifications "
"delivered; waiting for health notifications";
// Now that the initial state notifications have been
// delivered, the queue will contain the health watch
// notifications for any subchannels in state READY,
@ -868,7 +861,7 @@ class LoadBalancingPolicyTest : public ::testing::Test {
},
DEBUG_LOCATION);
notification.WaitForNotification();
gpr_log(GPR_INFO, "health notifications delivered");
LOG(INFO) << "health notifications delivered";
return status;
}
@ -900,15 +893,15 @@ class LoadBalancingPolicyTest : public ::testing::Test {
bool WaitForStateUpdate(
std::function<bool(FakeHelper::StateUpdate update)> continue_predicate,
SourceLocation location = SourceLocation()) {
gpr_log(GPR_INFO, "==> WaitForStateUpdate()");
LOG(INFO) << "==> WaitForStateUpdate()";
while (true) {
auto update = helper_->GetNextStateUpdate(location);
if (!update.has_value()) {
gpr_log(GPR_INFO, "WaitForStateUpdate() returning false");
LOG(INFO) << "WaitForStateUpdate() returning false";
return false;
}
if (!continue_predicate(std::move(*update))) {
gpr_log(GPR_INFO, "WaitForStateUpdate() returning true");
LOG(INFO) << "WaitForStateUpdate() returning true";
return true;
}
}
@ -945,7 +938,7 @@ class LoadBalancingPolicyTest : public ::testing::Test {
// update for state READY, whose picker is returned.
RefCountedPtr<LoadBalancingPolicy::SubchannelPicker> WaitForConnected(
SourceLocation location = SourceLocation()) {
gpr_log(GPR_INFO, "==> WaitForConnected()");
LOG(INFO) << "==> WaitForConnected()";
RefCountedPtr<LoadBalancingPolicy::SubchannelPicker> final_picker;
WaitForStateUpdate(
[&](FakeHelper::StateUpdate update) {
@ -1022,7 +1015,7 @@ class LoadBalancingPolicyTest : public ::testing::Test {
const CallAttributes& call_attributes = {},
size_t num_iterations = 3,
SourceLocation location = SourceLocation()) {
gpr_log(GPR_INFO, "Waiting for expected RR addresses...");
LOG(INFO) << "Waiting for expected RR addresses...";
RefCountedPtr<LoadBalancingPolicy::SubchannelPicker> retval;
size_t num_picks =
std::max(new_addresses.size(), old_addresses.size()) * num_iterations;
@ -1038,7 +1031,7 @@ class LoadBalancingPolicyTest : public ::testing::Test {
EXPECT_TRUE(picks.has_value())
<< location.file() << ":" << location.line();
if (!picks.has_value()) return false;
gpr_log(GPR_INFO, "PICKS: %s", absl::StrJoin(*picks, " ").c_str());
LOG(INFO) << "PICKS: " << absl::StrJoin(*picks, " ");
// If the picks still match the old list, then keep going.
if (PicksAreRoundRobin(old_addresses, *picks)) return true;
// Otherwise, the picks should match the new list.
@ -1053,7 +1046,7 @@ class LoadBalancingPolicyTest : public ::testing::Test {
return false; // Stop.
},
location);
gpr_log(GPR_INFO, "done waiting for expected RR addresses");
LOG(INFO) << "done waiting for expected RR addresses";
return retval;
}
@ -1307,7 +1300,7 @@ class LoadBalancingPolicyTest : public ::testing::Test {
RefCountedPtr<LoadBalancingPolicy::SubchannelPicker>
DrainRoundRobinPickerUpdates(absl::Span<const absl::string_view> addresses,
SourceLocation location = SourceLocation()) {
gpr_log(GPR_INFO, "Draining RR picker updates...");
LOG(INFO) << "Draining RR picker updates...";
RefCountedPtr<LoadBalancingPolicy::SubchannelPicker> picker;
while (!helper_->QueueEmpty()) {
auto update = helper_->GetNextStateUpdate(location);
@ -1322,17 +1315,17 @@ class LoadBalancingPolicyTest : public ::testing::Test {
location);
picker = std::move(update->picker);
}
gpr_log(GPR_INFO, "Done draining RR picker updates");
LOG(INFO) << "Done draining RR picker updates";
return picker;
}
// Expects zero or more CONNECTING updates.
void DrainConnectingUpdates(SourceLocation location = SourceLocation()) {
gpr_log(GPR_INFO, "Draining CONNECTING updates...");
LOG(INFO) << "Draining CONNECTING updates...";
while (!helper_->QueueEmpty()) {
ASSERT_TRUE(ExpectConnectingUpdate(location));
}
gpr_log(GPR_INFO, "Done draining CONNECTING updates");
LOG(INFO) << "Done draining CONNECTING updates";
}
// Triggers a connection failure for the current address for an
@ -1341,10 +1334,10 @@ class LoadBalancingPolicyTest : public ::testing::Test {
absl::Span<const absl::string_view> addresses, size_t current_index,
size_t new_index, absl::AnyInvocable<void()> expect_after_disconnect,
SourceLocation location = SourceLocation()) {
gpr_log(GPR_INFO,
"Expecting endpoint address change: addresses={%s}, "
"current_index=%" PRIuPTR ", new_index=%" PRIuPTR,
absl::StrJoin(addresses, ", ").c_str(), current_index, new_index);
LOG(INFO) << "Expecting endpoint address change: addresses={"
<< absl::StrJoin(addresses, ", ")
<< "}, current_index=" << current_index
<< ", new_index=" << new_index;
ASSERT_LT(current_index, addresses.size());
ASSERT_LT(new_index, addresses.size());
// Find all subchannels.
@ -1385,7 +1378,7 @@ class LoadBalancingPolicyTest : public ::testing::Test {
// interacts with it again.
subchannel->SetConnectivityState(GRPC_CHANNEL_IDLE);
}
gpr_log(GPR_INFO, "Done with endpoint address change");
LOG(INFO) << "Done with endpoint address change";
}
// Requests a picker on picker and expects a Fail result.
@ -1451,19 +1444,18 @@ class LoadBalancingPolicyTest : public ::testing::Test {
void WaitForWorkSerializerToFlush() {
ExecCtx exec_ctx;
gpr_log(GPR_INFO, "waiting for WorkSerializer to flush...");
LOG(INFO) << "waiting for WorkSerializer to flush...";
absl::Notification notification;
work_serializer_->Run([&]() { notification.Notify(); }, DEBUG_LOCATION);
notification.WaitForNotification();
gpr_log(GPR_INFO, "WorkSerializer flush complete");
LOG(INFO) << "WorkSerializer flush complete";
}
void IncrementTimeBy(Duration duration) {
ExecCtx exec_ctx;
gpr_log(GPR_INFO, "Incrementing time by %s...",
duration.ToString().c_str());
LOG(INFO) << "Incrementing time by " << duration;
fuzzing_ee_->TickForDuration(duration);
gpr_log(GPR_INFO, "Done incrementing time");
LOG(INFO) << "Done incrementing time";
// Flush WorkSerializer, in case the timer callback enqueued anything.
WaitForWorkSerializerToFlush();
}

@ -25,6 +25,7 @@
#include <utility>
#include <vector>
#include "absl/log/log.h"
#include "absl/status/status.h"
#include "absl/strings/string_view.h"
#include "absl/types/optional.h"
@ -33,7 +34,6 @@
#include <grpc/grpc.h>
#include <grpc/support/json.h>
#include <grpc/support/log.h>
#include "src/core/lib/gprpp/orphanable.h"
#include "src/core/lib/gprpp/ref_counted_ptr.h"
@ -215,14 +215,14 @@ TEST_F(OutlierDetectionTest, FailurePercentage) {
// Expect normal startup.
auto picker = ExpectRoundRobinStartup(kAddresses);
ASSERT_NE(picker, nullptr);
gpr_log(GPR_INFO, "### RR startup complete");
LOG(INFO) << "### RR startup complete";
// Do a pick and report a failed call.
auto address = DoPickWithFailedCall(picker.get());
ASSERT_TRUE(address.has_value());
gpr_log(GPR_INFO, "### failed RPC on %s", address->c_str());
LOG(INFO) << "### failed RPC on " << *address;
// Advance time and run the timer callback to trigger ejection.
IncrementTimeBy(Duration::Seconds(10));
gpr_log(GPR_INFO, "### ejection complete");
LOG(INFO) << "### ejection complete";
// Expect a picker update.
std::vector<absl::string_view> remaining_addresses;
for (const auto& addr : kAddresses) {
@ -231,7 +231,7 @@ TEST_F(OutlierDetectionTest, FailurePercentage) {
WaitForRoundRobinListChange(kAddresses, remaining_addresses);
// Advance time and run the timer callback to trigger un-ejection.
IncrementTimeBy(Duration::Seconds(10));
gpr_log(GPR_INFO, "### un-ejection complete");
LOG(INFO) << "### un-ejection complete";
// Expect a picker update.
WaitForRoundRobinListChange(remaining_addresses, kAddresses);
}
@ -265,11 +265,11 @@ TEST_F(OutlierDetectionTest, MultipleAddressesPerEndpoint) {
// Expect normal startup.
auto picker = ExpectRoundRobinStartup(kEndpoints);
ASSERT_NE(picker, nullptr);
gpr_log(GPR_INFO, "### RR startup complete");
LOG(INFO) << "### RR startup complete";
// Do a pick and report a failed call.
auto address = DoPickWithFailedCall(picker.get());
ASSERT_TRUE(address.has_value());
gpr_log(GPR_INFO, "### failed RPC on %s", address->c_str());
LOG(INFO) << "### failed RPC on " << *address;
// Based on the address that the failed call went to, we determine
// which addresses to use in the subsequent steps.
absl::Span<const absl::string_view> ejected_endpoint_addresses;
@ -297,12 +297,12 @@ TEST_F(OutlierDetectionTest, MultipleAddressesPerEndpoint) {
}
// Advance time and run the timer callback to trigger ejection.
IncrementTimeBy(Duration::Seconds(10));
gpr_log(GPR_INFO, "### ejection complete");
LOG(INFO) << "### ejection complete";
// Expect a picker that removes the ejected address.
WaitForRoundRobinListChange(
{kEndpoint1Addresses[0], kEndpoint2Addresses[0], kEndpoint3Addresses[0]},
{sentinel_endpoint_addresses[0], unmodified_endpoint_address});
gpr_log(GPR_INFO, "### ejected endpoint removed");
LOG(INFO) << "### ejected endpoint removed";
// Cause the connection to the ejected endpoint to fail, and then
// have it reconnect to a different address. The endpoint is still
// ejected, so the new address should not be used.
@ -312,7 +312,7 @@ TEST_F(OutlierDetectionTest, MultipleAddressesPerEndpoint) {
// re-resolution request in the queue.
DrainRoundRobinPickerUpdates(
{sentinel_endpoint_addresses[0], unmodified_endpoint_address});
gpr_log(GPR_INFO, "### done changing address of ejected endpoint");
LOG(INFO) << "### done changing address of ejected endpoint";
// Do the same thing for the sentinel endpoint, so that we
// know that the LB policy has seen the address change for the ejected
// endpoint.
@ -324,10 +324,10 @@ TEST_F(OutlierDetectionTest, MultipleAddressesPerEndpoint) {
WaitForRoundRobinListChange(
{unmodified_endpoint_address},
{sentinel_endpoint_addresses[1], unmodified_endpoint_address});
gpr_log(GPR_INFO, "### done changing address of ejected endpoint");
LOG(INFO) << "### done changing address of ejected endpoint";
// Advance time and run the timer callback to trigger un-ejection.
IncrementTimeBy(Duration::Seconds(10));
gpr_log(GPR_INFO, "### un-ejection complete");
LOG(INFO) << "### un-ejection complete";
// The ejected endpoint should come back using the new address.
WaitForRoundRobinListChange(
{sentinel_endpoint_addresses[1], unmodified_endpoint_address},
@ -363,11 +363,11 @@ TEST_F(OutlierDetectionTest, EjectionStateResetsWhenEndpointAddressesChange) {
// Expect normal startup.
auto picker = ExpectRoundRobinStartup(kEndpoints);
ASSERT_NE(picker, nullptr);
gpr_log(GPR_INFO, "### RR startup complete");
LOG(INFO) << "### RR startup complete";
// Do a pick and report a failed call.
auto ejected_address = DoPickWithFailedCall(picker.get());
ASSERT_TRUE(ejected_address.has_value());
gpr_log(GPR_INFO, "### failed RPC on %s", ejected_address->c_str());
LOG(INFO) << "### failed RPC on " << *ejected_address;
// Based on the address that the failed call went to, we determine
// which addresses to use in the subsequent steps.
std::vector<absl::string_view> expected_round_robin_while_ejected;
@ -393,12 +393,12 @@ TEST_F(OutlierDetectionTest, EjectionStateResetsWhenEndpointAddressesChange) {
}
// Advance time and run the timer callback to trigger ejection.
IncrementTimeBy(Duration::Seconds(10));
gpr_log(GPR_INFO, "### ejection complete");
LOG(INFO) << "### ejection complete";
// Expect a picker that removes the ejected address.
WaitForRoundRobinListChange(
{kEndpoint1Addresses[0], kEndpoint2Addresses[0], kEndpoint3Addresses[0]},
expected_round_robin_while_ejected);
gpr_log(GPR_INFO, "### ejected endpoint removed");
LOG(INFO) << "### ejected endpoint removed";
// Send an update that removes the other address from the ejected endpoint.
status = ApplyUpdate(BuildUpdate(new_endpoints, kConfig), lb_policy_.get());
EXPECT_TRUE(status.ok()) << status;
@ -447,14 +447,14 @@ TEST_F(OutlierDetectionTest, DoesNotWorkWithPickFirst) {
for (size_t i = 0; i < 3; ++i) {
EXPECT_EQ(ExpectPickComplete(picker.get()), kAddresses[0]);
}
gpr_log(GPR_INFO, "### PF startup complete");
LOG(INFO) << "### PF startup complete";
// Now have an RPC to that subchannel fail.
auto address = DoPickWithFailedCall(picker.get());
ASSERT_TRUE(address.has_value());
gpr_log(GPR_INFO, "### failed RPC on %s", address->c_str());
LOG(INFO) << "### failed RPC on " << *address;
// Advance time and run the timer callback to trigger ejection.
IncrementTimeBy(Duration::Seconds(10));
gpr_log(GPR_INFO, "### ejection timer pass complete");
LOG(INFO) << "### ejection timer pass complete";
// Subchannel should not be ejected.
ExpectQueueEmpty();
// Subchannel should not see a reconnection request.

@ -27,6 +27,7 @@
#include <utility>
#include <vector>
#include "absl/log/log.h"
#include "absl/status/status.h"
#include "absl/strings/str_join.h"
#include "absl/strings/string_view.h"
@ -38,7 +39,6 @@
#include <grpc/grpc.h>
#include <grpc/support/json.h>
#include <grpc/support/log.h>
#include "src/core/lib/gprpp/debug_location.h"
#include "src/core/lib/gprpp/orphanable.h"
@ -98,7 +98,7 @@ class WeightedRoundRobinTest : public LoadBalancingPolicyTest {
RefCountedPtr<LoadBalancingPolicy::Config> Build() {
Json config = Json::FromArray({Json::FromObject(
{{"weighted_round_robin", Json::FromObject(json_)}})});
gpr_log(GPR_INFO, "CONFIG: %s", JsonDump(config).c_str());
LOG(INFO) << "CONFIG: " << JsonDump(config);
return MakeConfig(config);
}
@ -247,10 +247,10 @@ class WeightedRoundRobinTest : public LoadBalancingPolicyTest {
auto picks = GetCompletePicks(picker, NumPicksNeeded(expected), {},
&subchannel_call_trackers, location);
ASSERT_TRUE(picks.has_value()) << location.file() << ":" << location.line();
gpr_log(GPR_INFO, "PICKS: %s", absl::StrJoin(*picks, " ").c_str());
LOG(INFO) << "PICKS: " << absl::StrJoin(*picks, " ");
ReportBackendMetrics(*picks, subchannel_call_trackers, backend_metrics);
auto actual = MakePickMap(*picks);
gpr_log(GPR_INFO, "Pick map: %s", PickMapString(actual).c_str());
LOG(INFO) << "Pick map: " << PickMapString(actual);
EXPECT_EQ(expected, actual)
<< "Expected: " << PickMapString(expected)
<< "\nActual: " << PickMapString(actual) << "\nat " << location.file()
@ -265,17 +265,17 @@ class WeightedRoundRobinTest : public LoadBalancingPolicyTest {
absl::Duration timeout = absl::Seconds(5),
bool run_timer_callbacks = true,
SourceLocation location = SourceLocation()) {
gpr_log(GPR_INFO, "==> WaitForWeightedRoundRobinPicks(): Expecting %s",
PickMapString(expected).c_str());
LOG(INFO) << "==> WaitForWeightedRoundRobinPicks(): Expecting "
<< PickMapString(expected);
size_t num_picks = NumPicksNeeded(expected);
absl::Time deadline = absl::Now() + timeout;
while (true) {
gpr_log(GPR_INFO, "TOP OF LOOP");
LOG(INFO) << "TOP OF LOOP";
// We need to see the expected weights for 3 consecutive passes, just
// to make sure we're consistently returning the right weights.
size_t num_passes = 0;
for (; num_passes < 3; ++num_passes) {
gpr_log(GPR_INFO, "PASS %" PRIuPTR ": DOING PICKS", num_passes);
LOG(INFO) << "PASS " << num_passes << ": DOING PICKS";
std::vector<std::unique_ptr<
LoadBalancingPolicy::SubchannelCallTrackerInterface>>
subchannel_call_trackers;
@ -284,13 +284,13 @@ class WeightedRoundRobinTest : public LoadBalancingPolicyTest {
EXPECT_TRUE(picks.has_value())
<< location.file() << ":" << location.line();
if (!picks.has_value()) return false;
gpr_log(GPR_INFO, "PICKS: %s", absl::StrJoin(*picks, " ").c_str());
LOG(INFO) << "PICKS: " << absl::StrJoin(*picks, " ");
// Report backend metrics to the LB policy.
ReportBackendMetrics(*picks, subchannel_call_trackers, backend_metrics);
// Check the observed weights.
auto actual = MakePickMap(*picks);
gpr_log(GPR_INFO, "Pick map:\nExpected: %s\n Actual: %s",
PickMapString(expected).c_str(), PickMapString(actual).c_str());
LOG(INFO) << "Pick map:\nExpected: " << PickMapString(expected)
<< "\n Actual: " << PickMapString(actual);
if (expected != actual) {
// Make sure each address is one of the expected addresses,
// even if the weights aren't as expected.
@ -321,7 +321,7 @@ class WeightedRoundRobinTest : public LoadBalancingPolicyTest {
<< location.file() << ":" << location.line();
if (*picker == nullptr) return false;
} else if (run_timer_callbacks) {
gpr_log(GPR_INFO, "running timer callback...");
LOG(INFO) << "running timer callback...";
// Increment time and run any timer callbacks.
IncrementTimeBy(Duration::Seconds(1));
}
@ -1150,7 +1150,7 @@ TEST_F(WeightedRoundRobinTest, MetricValues) {
::testing::Optional(0));
// Advance time to make weights stale and trigger the timer callback
// to recompute weights.
gpr_log(GPR_INFO, "advancing time to trigger staleness...");
LOG(INFO) << "advancing time to trigger staleness...";
IncrementTimeBy(Duration::Seconds(2));
// Picker should now be falling back to round-robin.
ExpectWeightedRoundRobinPicks(

@ -23,6 +23,7 @@
#include <utility>
#include <vector>
#include "absl/log/log.h"
#include "absl/status/status.h"
#include "absl/status/statusor.h"
#include "absl/strings/str_join.h"
@ -35,7 +36,6 @@
#include <grpc/grpc.h>
#include <grpc/support/json.h>
#include <grpc/support/log.h>
#include "src/core/ext/filters/stateful_session/stateful_session_filter.h"
#include "src/core/lib/channel/channel_args.h"
@ -295,21 +295,20 @@ TEST_F(XdsOverrideHostTest,
auto* address1_attribute = MakeOverrideHostAttribute(kAddresses[1]);
ExpectOverridePicks(picker.get(), address1_attribute, kAddresses[1]);
// Subchannel for address 1 becomes disconnected.
gpr_log(GPR_INFO, "### subchannel 1 reporting IDLE");
LOG(INFO) << "### subchannel 1 reporting IDLE";
auto subchannel = FindSubchannel(kAddresses[1]);
ASSERT_NE(subchannel, nullptr);
subchannel->SetConnectivityState(GRPC_CHANNEL_IDLE);
EXPECT_TRUE(subchannel->ConnectionRequested());
gpr_log(GPR_INFO, "### expecting re-resolution request");
LOG(INFO) << "### expecting re-resolution request";
ExpectReresolutionRequest();
gpr_log(GPR_INFO,
"### expecting RR picks to exclude the disconnected subchannel");
LOG(INFO) << "### expecting RR picks to exclude the disconnected subchannel";
picker =
WaitForRoundRobinListChange(kAddresses, {kAddresses[0], kAddresses[2]});
// Picks with the override will be queued.
ExpectPickQueued(picker.get(), {address1_attribute});
// The subchannel starts trying to reconnect.
gpr_log(GPR_INFO, "### subchannel 1 reporting CONNECTING");
LOG(INFO) << "### subchannel 1 reporting CONNECTING";
subchannel->SetConnectivityState(GRPC_CHANNEL_CONNECTING);
picker = ExpectState(GRPC_CHANNEL_READY);
ASSERT_NE(picker, nullptr);
@ -317,15 +316,15 @@ TEST_F(XdsOverrideHostTest,
// Picks with the override will still be queued.
ExpectPickQueued(picker.get(), {address1_attribute});
// The connection attempt fails.
gpr_log(GPR_INFO, "### subchannel 1 reporting TRANSIENT_FAILURE");
LOG(INFO) << "### subchannel 1 reporting TRANSIENT_FAILURE";
subchannel->SetConnectivityState(GRPC_CHANNEL_TRANSIENT_FAILURE,
absl::ResourceExhaustedError("Hmmmm"));
gpr_log(GPR_INFO, "### expecting re-resolution request");
LOG(INFO) << "### expecting re-resolution request";
ExpectReresolutionRequest();
picker = ExpectState(GRPC_CHANNEL_READY);
ExpectRoundRobinPicks(picker.get(), {kAddresses[0], kAddresses[2]});
// The host override is not used.
gpr_log(GPR_INFO, "### checking that host override is not used");
LOG(INFO) << "### checking that host override is not used";
ExpectRoundRobinPicksWithAttribute(picker.get(), address1_attribute,
{kAddresses[0], kAddresses[2]});
}
@ -376,7 +375,7 @@ TEST_F(XdsOverrideHostTest, DrainingSubchannelIsConnecting) {
// The picker should use the DRAINING host when a call's override
// points to that hose, but the host should not be used if there is no
// override pointing to it.
gpr_log(GPR_INFO, "### sending update with DRAINING host");
LOG(INFO) << "### sending update with DRAINING host";
ApplyUpdateWithHealthStatuses({{kAddresses[0], XdsHealthStatus::kUnknown},
{kAddresses[1], XdsHealthStatus::kDraining},
{kAddresses[2], XdsHealthStatus::kHealthy}},
@ -391,7 +390,7 @@ TEST_F(XdsOverrideHostTest, DrainingSubchannelIsConnecting) {
// Now the connection to the draining host gets dropped.
// The picker should queue picks where the override host is IDLE.
// All picks without an override host should not use this host.
gpr_log(GPR_INFO, "### closing connection to DRAINING host");
LOG(INFO) << "### closing connection to DRAINING host";
subchannel->SetConnectivityState(GRPC_CHANNEL_IDLE);
picker = ExpectState(GRPC_CHANNEL_READY);
ExpectPickQueued(picker.get(), {address1_attribute});
@ -401,7 +400,7 @@ TEST_F(XdsOverrideHostTest, DrainingSubchannelIsConnecting) {
// The pick behavior is the same as above: The picker should queue
// picks where the override host is CONNECTING. All picks without an
// override host should not use this host.
gpr_log(GPR_INFO, "### subchannel starts reconnecting");
LOG(INFO) << "### subchannel starts reconnecting";
WaitForWorkSerializerToFlush();
EXPECT_TRUE(subchannel->ConnectionRequested());
ExpectQueueEmpty();
@ -412,7 +411,7 @@ TEST_F(XdsOverrideHostTest, DrainingSubchannelIsConnecting) {
// The subchannel now becomes connected again.
// Now picks with this override host can be completed again.
// Picks without an override host still don't use the draining host.
gpr_log(GPR_INFO, "### subchannel becomes reconnected");
LOG(INFO) << "### subchannel becomes reconnected";
subchannel->SetConnectivityState(GRPC_CHANNEL_READY);
picker = ExpectState(GRPC_CHANNEL_READY);
ExpectOverridePicks(picker.get(), address1_attribute, kAddresses[1]);
@ -644,7 +643,7 @@ TEST_F(XdsOverrideHostTest, IdleTimer) {
});
const std::array<absl::string_view, 3> kAddresses = {
"ipv4:127.0.0.1:441", "ipv4:127.0.0.1:442", "ipv4:127.0.0.1:443"};
gpr_log(GPR_INFO, "### sending initial update");
LOG(INFO) << "### sending initial update";
EXPECT_EQ(UpdateXdsOverrideHostPolicy(kAddresses, {"UNKNOWN", "HEALTHY"},
Duration::Minutes(1)),
absl::OkStatus());
@ -663,7 +662,7 @@ TEST_F(XdsOverrideHostTest, IdleTimer) {
ExpectOverridePicks(picker.get(), address2_attribute, kAddresses[2]);
// Increment time by 5 seconds and send an update that moves endpoints 1
// and 2 to state DRAINING.
gpr_log(GPR_INFO, "### moving endpoints 1 and 2 to state DRAINING");
LOG(INFO) << "### moving endpoints 1 and 2 to state DRAINING";
IncrementTimeBy(Duration::Seconds(5));
ApplyUpdateWithHealthStatuses({{kAddresses[0], XdsHealthStatus::kUnknown},
{kAddresses[1], XdsHealthStatus::kDraining},

@ -36,9 +36,9 @@
#include <sys/socket.h>
#include "absl/log/check.h"
#include "absl/log/log.h"
#include <grpc/support/alloc.h>
#include <grpc/support/log.h>
#include <grpc/support/time.h>
#include "src/core/lib/gprpp/strerror.h"
@ -84,8 +84,7 @@ static int read_bytes(int fd, char* buf, size_t read_size, int spin) {
if (errno == EAGAIN && spin == 1) {
continue;
}
gpr_log(GPR_ERROR, "Read failed: %s",
grpc_core::StrError(errno).c_str());
LOG(ERROR) << "Read failed: " << grpc_core::StrError(errno);
return -1;
}
} else {
@ -118,8 +117,7 @@ static int poll_read_bytes(int fd, char* buf, size_t read_size, int spin) {
if (errno == EINTR) {
continue;
} else {
gpr_log(GPR_ERROR, "Poll failed: %s",
grpc_core::StrError(errno).c_str());
LOG(ERROR) << "Poll failed: " << grpc_core::StrError(errno);
return -1;
}
}
@ -130,7 +128,7 @@ static int poll_read_bytes(int fd, char* buf, size_t read_size, int spin) {
err2 = read(fd, buf + bytes_read, read_size - bytes_read);
} while (err2 < 0 && errno == EINTR);
if (err2 < 0 && errno != EAGAIN) {
gpr_log(GPR_ERROR, "Read failed: %s", grpc_core::StrError(errno).c_str());
LOG(ERROR) << "Read failed: " << grpc_core::StrError(errno);
return -1;
}
bytes_read += static_cast<size_t>(err2);
@ -159,8 +157,7 @@ static int epoll_read_bytes(struct thread_args* args, char* buf, int spin) {
err = epoll_wait(args->epoll_fd, &ev, 1, spin ? 0 : -1);
if (err < 0) {
if (errno == EINTR) continue;
gpr_log(GPR_ERROR, "epoll_wait failed: %s",
grpc_core::StrError(errno).c_str());
LOG(ERROR) << "epoll_wait failed: " << grpc_core::StrError(errno);
return -1;
}
if (err == 0 && spin) continue;
@ -206,8 +203,7 @@ static int blocking_write_bytes(struct thread_args* args, char* buf) {
if (errno == EINTR) {
continue;
} else {
gpr_log(GPR_ERROR, "Read failed: %s",
grpc_core::StrError(errno).c_str());
LOG(ERROR) << "Read failed: " << grpc_core::StrError(errno);
return -1;
}
} else {
@ -245,7 +241,7 @@ static int epoll_setup(thread_args* args) {
set_socket_nonblocking(args);
epoll_fd = epoll_create(1);
if (epoll_fd < 0) {
gpr_log(GPR_ERROR, "epoll_create: %s", grpc_core::StrError(errno).c_str());
LOG(ERROR) << "epoll_create: " << grpc_core::StrError(errno);
return -1;
}
@ -254,7 +250,7 @@ static int epoll_setup(thread_args* args) {
ev.events = EPOLLIN | EPOLLET;
ev.data.fd = args->fds.read_fd;
if (epoll_ctl(epoll_fd, EPOLL_CTL_ADD, args->fds.read_fd, &ev) < 0) {
gpr_log(GPR_ERROR, "epoll_ctl: %s", grpc_core::StrError(errno).c_str());
LOG(ERROR) << "epoll_ctl: " << grpc_core::StrError(errno);
}
return 0;
}
@ -263,16 +259,16 @@ static int epoll_setup(thread_args* args) {
static void server_thread(thread_args* args) {
char* buf = static_cast<char*>(gpr_malloc(args->msg_size));
if (args->setup(args) < 0) {
gpr_log(GPR_ERROR, "Setup failed");
LOG(ERROR) << "Setup failed";
}
for (;;) {
if (args->read_bytes(args, buf) < 0) {
gpr_log(GPR_ERROR, "Server read failed");
LOG(ERROR) << "Server read failed";
gpr_free(buf);
return;
}
if (args->write_bytes(args, buf) < 0) {
gpr_log(GPR_ERROR, "Server write failed");
LOG(ERROR) << "Server write failed";
gpr_free(buf);
return;
}
@ -287,11 +283,11 @@ static void server_thread_wrap(void* arg) {
static void print_histogram(grpc_histogram* histogram) {
// TODO(klempner): Print more detailed information, such as detailed histogram
// buckets
gpr_log(GPR_INFO, "latency (50/95/99/99.9): %f/%f/%f/%f",
grpc_histogram_percentile(histogram, 50),
grpc_histogram_percentile(histogram, 95),
grpc_histogram_percentile(histogram, 99),
grpc_histogram_percentile(histogram, 99.9));
LOG(INFO) << "latency (50/95/99/99.9): "
<< grpc_histogram_percentile(histogram, 50) << "/"
<< grpc_histogram_percentile(histogram, 95) << "/"
<< grpc_histogram_percentile(histogram, 99) << "/"
<< grpc_histogram_percentile(histogram, 99.9);
}
static double now(void) {
@ -310,16 +306,16 @@ static void client_thread(thread_args* args) {
int i;
if (args->setup(args) < 0) {
gpr_log(GPR_ERROR, "Setup failed");
LOG(ERROR) << "Setup failed";
}
for (i = 0; i < kNumIters; ++i) {
start_time = now();
if (args->write_bytes(args, buf) < 0) {
gpr_log(GPR_ERROR, "Client write failed");
LOG(ERROR) << "Client write failed";
goto error;
}
if (args->read_bytes(args, buf) < 0) {
gpr_log(GPR_ERROR, "Client read failed");
LOG(ERROR) << "Client read failed";
goto error;
}
end_time = now();
@ -338,8 +334,7 @@ error:
static int create_listening_socket(struct sockaddr* port, socklen_t len) {
int fd = socket(port->sa_family, SOCK_STREAM, 0);
if (fd < 0) {
gpr_log(GPR_ERROR, "Unable to create socket: %s",
grpc_core::StrError(errno).c_str());
LOG(ERROR) << "Unable to create socket: " << grpc_core::StrError(errno);
goto error;
}
@ -357,17 +352,17 @@ static int create_listening_socket(struct sockaddr* port, socklen_t len) {
}
if (bind(fd, port, len) < 0) {
gpr_log(GPR_ERROR, "bind: %s", grpc_core::StrError(errno).c_str());
LOG(ERROR) << "bind: " << grpc_core::StrError(errno);
goto error;
}
if (listen(fd, 1) < 0) {
gpr_log(GPR_ERROR, "listen: %s", grpc_core::StrError(errno).c_str());
LOG(ERROR) << "listen: " << grpc_core::StrError(errno);
goto error;
}
if (getsockname(fd, port, &len) < 0) {
gpr_log(GPR_ERROR, "getsockname: %s", grpc_core::StrError(errno).c_str());
LOG(ERROR) << "getsockname: " << grpc_core::StrError(errno);
goto error;
}
@ -384,8 +379,7 @@ static int connect_client(struct sockaddr* addr, socklen_t len) {
int fd = socket(addr->sa_family, SOCK_STREAM, 0);
int err;
if (fd < 0) {
gpr_log(GPR_ERROR, "Unable to create socket: %s",
grpc_core::StrError(errno).c_str());
LOG(ERROR) << "Unable to create socket: " << grpc_core::StrError(errno);
goto error;
}
@ -403,7 +397,7 @@ static int connect_client(struct sockaddr* addr, socklen_t len) {
} while (err < 0 && errno == EINTR);
if (err < 0) {
gpr_log(GPR_ERROR, "connect error: %s", grpc_core::StrError(errno).c_str());
LOG(ERROR) << "connect error: " << grpc_core::StrError(errno);
goto error;
}
return fd;
@ -418,7 +412,7 @@ error:
static int accept_server(int listen_fd) {
int fd = accept(listen_fd, nullptr, nullptr);
if (fd < 0) {
gpr_log(GPR_ERROR, "Accept failed: %s", grpc_core::StrError(errno).c_str());
LOG(ERROR) << "Accept failed: " << grpc_core::StrError(errno);
return -1;
}
return fd;
@ -438,19 +432,19 @@ static int create_sockets_tcp(fd_pair* client_fds, fd_pair* server_fds) {
listen_fd = create_listening_socket(sa_port, sizeof(port));
if (listen_fd == -1) {
gpr_log(GPR_ERROR, "Listen failed");
LOG(ERROR) << "Listen failed";
goto error;
}
client_fd = connect_client(sa_port, sizeof(port));
if (client_fd == -1) {
gpr_log(GPR_ERROR, "Connect failed");
LOG(ERROR) << "Connect failed";
goto error;
}
server_fd = accept_server(listen_fd);
if (server_fd == -1) {
gpr_log(GPR_ERROR, "Accept failed");
LOG(ERROR) << "Accept failed";
goto error;
}
@ -477,7 +471,7 @@ error:
static int create_sockets_socketpair(fd_pair* client_fds, fd_pair* server_fds) {
int fds[2];
if (socketpair(AF_UNIX, SOCK_STREAM, 0, fds) < 0) {
gpr_log(GPR_ERROR, "socketpair: %s", grpc_core::StrError(errno).c_str());
LOG(ERROR) << "socketpair: " << grpc_core::StrError(errno);
return -1;
}
@ -492,12 +486,12 @@ static int create_sockets_pipe(fd_pair* client_fds, fd_pair* server_fds) {
int cfds[2];
int sfds[2];
if (pipe(cfds) < 0) {
gpr_log(GPR_ERROR, "pipe: %s", grpc_core::StrError(errno).c_str());
LOG(ERROR) << "pipe: " << grpc_core::StrError(errno);
return -1;
}
if (pipe(sfds) < 0) {
gpr_log(GPR_ERROR, "pipe: %s", grpc_core::StrError(errno).c_str());
LOG(ERROR) << "pipe: " << grpc_core::StrError(errno);
return -1;
}
@ -592,8 +586,8 @@ static int run_benchmark(const char* socket_type, thread_args* client_args,
return rv;
}
gpr_log(GPR_INFO, "Starting test %s %s %zu", client_args->strategy_name,
socket_type, client_args->msg_size);
LOG(INFO) << "Starting test " << client_args->strategy_name << " "
<< socket_type << " " << client_args->msg_size;
grpc_core::Thread server("server_thread", server_thread_wrap, server_args);
server.Start();
@ -663,7 +657,7 @@ int main(int argc, char** argv) {
}
if (read_strategy == nullptr) {
gpr_log(GPR_INFO, "No strategy specified, running all benchmarks");
LOG(INFO) << "No strategy specified, running all benchmarks";
return run_all_benchmarks(static_cast<size_t>(msg_size));
}

@ -23,6 +23,7 @@
#include <vector>
#include "absl/base/thread_annotations.h"
#include "absl/log/log.h"
#include "gtest/gtest.h"
#include <grpc/event_engine/event_engine.h>
@ -114,8 +115,7 @@ TYPED_TEST(PartySyncTest, AddAndRemoveParticipant) {
participants[slot].exchange(nullptr, std::memory_order_acquire);
if (participant == done.get()) run_me = true;
if (participant == nullptr) {
gpr_log(GPR_ERROR,
"Participant was null (spurious wakeup observed)");
LOG(ERROR) << "Participant was null (spurious wakeup observed)";
return false;
}
participant->store(true, std::memory_order_release);
@ -165,8 +165,7 @@ TYPED_TEST(PartySyncTest, AddAndRemoveTwoParticipants) {
participants[slot].exchange(nullptr, std::memory_order_acquire);
if (participant == done.get()) run_me++;
if (participant == nullptr) {
gpr_log(GPR_ERROR,
"Participant was null (spurious wakeup observed)");
LOG(ERROR) << "Participant was null (spurious wakeup observed)";
return false;
}
participant->fetch_sub(1, std::memory_order_release);

@ -28,6 +28,7 @@
#include <string>
#include <vector>
#include "absl/log/log.h"
#include "absl/strings/string_view.h"
#include "gtest/gtest.h"
@ -182,7 +183,7 @@ TEST_P(GrpcSliceSizedTest, SliceSplitHeadWorks) {
grpc_slice head, tail;
size_t i;
gpr_log(GPR_INFO, "length=%" PRIuPTR, length);
LOG(INFO) << "length=" << length;
// Create a slice in which each byte is equal to the distance from it to the
// beginning of the slice.
@ -211,7 +212,7 @@ TEST_P(GrpcSliceSizedTest, SliceSplitTailWorks) {
grpc_slice head, tail;
size_t i;
gpr_log(GPR_INFO, "length=%" PRIuPTR, length);
LOG(INFO) << "length=" << length;
// Create a slice in which each byte is equal to the distance from it to the
// beginning of the slice.

@ -22,11 +22,11 @@
#include <memory>
#include "absl/log/log.h"
#include "absl/status/status.h"
#include "gtest/gtest.h"
#include <grpc/grpc.h>
#include <grpc/support/log.h>
#include <grpc/support/sync.h>
#include <grpc/support/time.h>
@ -34,7 +34,7 @@
#include "src/core/util/useful.h"
#include "test/core/test_util/test_config.h"
#define LOG_TEST(x) gpr_log(GPR_INFO, "%s", x)
#define LOG_TEST(x) LOG(INFO) << x
static void* create_test_tag(void) {
static intptr_t i = 0;
@ -65,7 +65,7 @@ static void shutdown_and_destroy(grpc_completion_queue* cc) {
break;
}
default: {
gpr_log(GPR_ERROR, "Unknown completion type");
LOG(ERROR) << "Unknown completion type";
break;
}
}

@ -21,12 +21,12 @@
#include <memory>
#include "absl/log/log.h"
#include "absl/status/status.h"
#include "gtest/gtest.h"
#include <grpc/grpc.h>
#include <grpc/support/alloc.h>
#include <grpc/support/log.h>
#include <grpc/support/sync.h>
#include <grpc/support/time.h>
@ -37,7 +37,7 @@
#include "src/core/util/useful.h"
#include "test/core/test_util/test_config.h"
#define LOG_TEST(x) gpr_log(GPR_INFO, "%s", x)
#define LOG_TEST(x) LOG(INFO) << x
static void* create_test_tag(void) {
static intptr_t i = 0;
@ -61,7 +61,7 @@ static void shutdown_and_destroy(grpc_completion_queue* cc) {
break;
}
default: {
gpr_log(GPR_ERROR, "Unknown completion type");
LOG(ERROR) << "Unknown completion type";
break;
}
}
@ -155,20 +155,20 @@ static void producer_thread(void* arg) {
test_thread_options* opt = static_cast<test_thread_options*>(arg);
int i;
gpr_log(GPR_INFO, "producer %d started", opt->id);
LOG(INFO) << "producer " << opt->id << " started";
gpr_event_set(&opt->on_started, reinterpret_cast<void*>(1));
ASSERT_TRUE(gpr_event_wait(opt->phase1, ten_seconds_time()));
gpr_log(GPR_INFO, "producer %d phase 1", opt->id);
LOG(INFO) << "producer " << opt->id << " phase 1";
for (i = 0; i < TEST_THREAD_EVENTS; i++) {
ASSERT_TRUE(grpc_cq_begin_op(opt->cc, (void*)(intptr_t)1));
}
gpr_log(GPR_INFO, "producer %d phase 1 done", opt->id);
LOG(INFO) << "producer " << opt->id << " phase 1 done";
gpr_event_set(&opt->on_phase1_done, reinterpret_cast<void*>(1));
ASSERT_TRUE(gpr_event_wait(opt->phase2, ten_seconds_time()));
gpr_log(GPR_INFO, "producer %d phase 2", opt->id);
LOG(INFO) << "producer " << opt->id << " phase 2";
for (i = 0; i < TEST_THREAD_EVENTS; i++) {
grpc_core::ExecCtx exec_ctx;
grpc_cq_end_op(opt->cc, reinterpret_cast<void*>(1), absl::OkStatus(),
@ -178,7 +178,7 @@ static void producer_thread(void* arg) {
opt->events_triggered++;
}
gpr_log(GPR_INFO, "producer %d phase 2 done", opt->id);
LOG(INFO) << "producer " << opt->id << " phase 2 done";
gpr_event_set(&opt->on_finished, reinterpret_cast<void*>(1));
}
@ -186,17 +186,17 @@ static void consumer_thread(void* arg) {
test_thread_options* opt = static_cast<test_thread_options*>(arg);
grpc_event ev;
gpr_log(GPR_INFO, "consumer %d started", opt->id);
LOG(INFO) << "consumer " << opt->id << " started";
gpr_event_set(&opt->on_started, reinterpret_cast<void*>(1));
ASSERT_TRUE(gpr_event_wait(opt->phase1, ten_seconds_time()));
gpr_log(GPR_INFO, "consumer %d phase 1", opt->id);
LOG(INFO) << "consumer " << opt->id << " phase 1";
gpr_log(GPR_INFO, "consumer %d phase 1 done", opt->id);
LOG(INFO) << "consumer " << opt->id << " phase 1 done";
gpr_event_set(&opt->on_phase1_done, reinterpret_cast<void*>(1));
ASSERT_TRUE(gpr_event_wait(opt->phase2, ten_seconds_time()));
gpr_log(GPR_INFO, "consumer %d phase 2", opt->id);
LOG(INFO) << "consumer " << opt->id << " phase 2";
for (;;) {
ev = grpc_completion_queue_next(
opt->cc, gpr_inf_future(GPR_CLOCK_MONOTONIC), nullptr);
@ -206,7 +206,7 @@ static void consumer_thread(void* arg) {
opt->events_triggered++;
break;
case GRPC_QUEUE_SHUTDOWN:
gpr_log(GPR_INFO, "consumer %d phase 2 done", opt->id);
LOG(INFO) << "consumer " << opt->id << " phase 2 done";
gpr_event_set(&opt->on_finished, reinterpret_cast<void*>(1));
return;
case GRPC_QUEUE_TIMEOUT:
@ -225,8 +225,8 @@ static void test_threading(size_t producers, size_t consumers) {
size_t total_consumed = 0;
static int optid = 101;
gpr_log(GPR_INFO, "%s: %" PRIuPTR " producers, %" PRIuPTR " consumers",
"test_threading", producers, consumers);
LOG(INFO) << "test_threading: " << producers << " producers, " << consumers
<< " consumers";
// start all threads: they will wait for phase1
grpc_core::Thread* threads = static_cast<grpc_core::Thread*>(
@ -252,17 +252,17 @@ static void test_threading(size_t producers, size_t consumers) {
// start phase1: producers will pre-declare all operations they will
// complete
gpr_log(GPR_INFO, "start phase 1");
LOG(INFO) << "start phase 1";
gpr_event_set(&phase1, reinterpret_cast<void*>(1));
gpr_log(GPR_INFO, "wait phase 1");
LOG(INFO) << "wait phase 1";
for (i = 0; i < producers + consumers; i++) {
ASSERT_TRUE(gpr_event_wait(&options[i].on_phase1_done, ten_seconds_time()));
}
gpr_log(GPR_INFO, "done phase 1");
LOG(INFO) << "done phase 1";
// start phase2: operations will complete, and consumers will consume them
gpr_log(GPR_INFO, "start phase 2");
LOG(INFO) << "start phase 2";
gpr_event_set(&phase2, reinterpret_cast<void*>(1));
// in parallel, we shutdown the completion channel - all events should still
@ -270,11 +270,11 @@ static void test_threading(size_t producers, size_t consumers) {
grpc_completion_queue_shutdown(cc);
// join all threads
gpr_log(GPR_INFO, "wait phase 2");
LOG(INFO) << "wait phase 2";
for (i = 0; i < producers + consumers; i++) {
ASSERT_TRUE(gpr_event_wait(&options[i].on_finished, ten_seconds_time()));
}
gpr_log(GPR_INFO, "done phase 2");
LOG(INFO) << "done phase 2";
// destroy the completion channel
grpc_completion_queue_destroy(cc);

@ -23,6 +23,7 @@
#include <string>
#include <vector>
#include "absl/log/log.h"
#include "absl/strings/str_cat.h"
#include "gtest/gtest.h"
@ -30,7 +31,6 @@
#include <grpc/grpc.h>
#include <grpc/grpc_security.h>
#include <grpc/support/alloc.h>
#include <grpc/support/log.h>
#include <grpc/support/sync.h>
#include <grpc/support/time.h>
@ -192,7 +192,7 @@ TEST(ConcurrentConnectivityTest, RunConcurrentConnectivityTest) {
// First round, no server
{
gpr_log(GPR_DEBUG, "Wave 1");
VLOG(2) << "Wave 1";
grpc_core::Thread threads[NUM_THREADS];
args.addr = "localhost:54321";
for (auto& th : threads) {
@ -207,7 +207,7 @@ TEST(ConcurrentConnectivityTest, RunConcurrentConnectivityTest) {
// Second round, actual grpc server
{
gpr_log(GPR_DEBUG, "Wave 2");
VLOG(2) << "Wave 2";
int port = grpc_pick_unused_port_or_die();
args.addr = absl::StrCat("localhost:", port);
args.server = grpc_server_create(nullptr, nullptr);
@ -239,7 +239,7 @@ TEST(ConcurrentConnectivityTest, RunConcurrentConnectivityTest) {
// Third round, bogus tcp server
{
gpr_log(GPR_DEBUG, "Wave 3");
VLOG(2) << "Wave 3";
auto* pollset = static_cast<grpc_pollset*>(gpr_zalloc(grpc_pollset_size()));
grpc_pollset_init(pollset, &args.mu);
args.pollset.push_back(pollset);

@ -21,6 +21,8 @@
#include <string>
#include "absl/log/log.h"
#include <grpc/support/port_platform.h>
/// Simple command line parser.
@ -43,7 +45,7 @@
/// gpr_cmdline_destroy(cl);
/// if (verbose) {
/// gpr_log(GPR_INFO, "Goodbye cruel world!");
/// LOG(INFO) << "Goodbye cruel world!";
/// }
/// return 0;

@ -20,10 +20,10 @@
#include <string.h>
#include "absl/log/log.h"
#include "absl/strings/string_view.h"
#include <grpc/support/alloc.h>
#include <grpc/support/log.h>
#include <grpc/support/time.h>
#include "src/core/lib/iomgr/endpoint.h"
@ -37,14 +37,14 @@ static void pretty_print_backoffs(reconnect_server* server) {
int i = 1;
double expected_backoff = 1000.0, backoff;
timestamp_list* head = server->head;
gpr_log(GPR_INFO, "reconnect server: new connection");
LOG(INFO) << "reconnect server: new connection";
for (head = server->head; head && head->next; head = head->next, i++) {
diff = gpr_time_sub(head->next->timestamp, head->timestamp);
backoff = gpr_time_to_millis(diff);
gpr_log(GPR_INFO,
"retry %2d:backoff %6.2fs,expected backoff %6.2fs, jitter %4.2f%%",
i, backoff / 1000.0, expected_backoff / 1000.0,
(backoff - expected_backoff) * 100.0 / expected_backoff);
LOG(INFO) << absl::StrFormat(
"retry %2d:backoff %6.2fs,expected backoff %6.2fs, jitter %4.2f%%", i,
backoff / 1000.0, expected_backoff / 1000.0,
(backoff - expected_backoff) * 100.0 / expected_backoff);
expected_backoff *= 1.6;
int max_reconnect_backoff_ms = 120 * 1000;
if (server->max_reconnect_backoff_ms > 0) {
@ -73,11 +73,10 @@ static void on_connect(void* arg, grpc_endpoint* tcp,
server->peer = new std::string(peer);
} else {
if (last_colon == std::string::npos) {
gpr_log(GPR_ERROR, "peer does not contain a ':'");
LOG(ERROR) << "peer does not contain a ':'";
} else if (peer.compare(0, static_cast<size_t>(last_colon),
*server->peer) != 0) {
gpr_log(GPR_ERROR, "mismatched peer! %s vs %s", server->peer->c_str(),
std::string(peer).c_str());
LOG(ERROR) << "mismatched peer! " << *server->peer << " vs " << peer;
}
}
new_tail = static_cast<timestamp_list*>(gpr_malloc(sizeof(timestamp_list)));

@ -22,6 +22,7 @@
#include <stdlib.h>
#include "absl/debugging/failure_signal_handler.h"
#include "absl/log/log.h"
#include "absl/status/status.h"
#include "absl/strings/match.h"
#include "absl/strings/str_format.h"
@ -126,11 +127,11 @@ void grpc_test_init(int* argc, char** argv) {
grpc_core::testing::InitializeStackTracer(argv[0]);
absl::FailureSignalHandlerOptions options;
absl::InstallFailureSignalHandler(options);
gpr_log(GPR_DEBUG,
"test slowdown factor: sanitizer=%" PRId64 ", fixture=%" PRId64
", poller=%" PRId64 ", total=%" PRId64,
grpc_test_sanitizer_slowdown_factor(), g_fixture_slowdown_factor,
g_poller_slowdown_factor, grpc_test_slowdown_factor());
VLOG(2) << "test slowdown factor: sanitizer="
<< grpc_test_sanitizer_slowdown_factor()
<< ", fixture=" << g_fixture_slowdown_factor
<< ", poller=" << g_poller_slowdown_factor
<< ", total=" << grpc_test_slowdown_factor();
// seed rng with pid, so we don't end up with the same random numbers as a
// concurrently running test binary
srand(seed());
@ -160,7 +161,7 @@ TestEnvironment::~TestEnvironment() {
// This will wait until gRPC shutdown has actually happened to make sure
// no gRPC resources (such as thread) are active. (timeout = 10s)
if (!grpc_wait_until_shutdown(10)) {
gpr_log(GPR_ERROR, "Timeout in waiting for gRPC shutdown");
LOG(ERROR) << "Timeout in waiting for gRPC shutdown";
}
if (BuiltUnderMsan()) {
// This is a workaround for MSAN. MSAN doesn't like having shutdown thread
@ -171,7 +172,7 @@ TestEnvironment::~TestEnvironment() {
gpr_sleep_until(gpr_time_add(gpr_now(GPR_CLOCK_REALTIME),
gpr_time_from_millis(500, GPR_TIMESPAN)));
}
gpr_log(GPR_INFO, "TestEnvironment ends");
LOG(INFO) << "TestEnvironment ends";
}
TestGrpcScope::TestGrpcScope() { grpc_init(); }
@ -179,7 +180,7 @@ TestGrpcScope::TestGrpcScope() { grpc_init(); }
TestGrpcScope::~TestGrpcScope() {
grpc_shutdown();
if (!grpc_wait_until_shutdown(10)) {
gpr_log(GPR_ERROR, "Timeout in waiting for gRPC shutdown");
LOG(ERROR) << "Timeout in waiting for gRPC shutdown";
}
}

@ -22,10 +22,10 @@
#include <string>
#include "absl/log/check.h"
#include "absl/log/log.h"
#include "absl/strings/str_format.h"
#include <grpc/grpc.h>
#include <grpc/support/log.h>
#include <grpcpp/impl/sync.h>
#include <grpcpp/security/server_credentials.h>
#include <grpcpp/server.h>
@ -69,7 +69,7 @@ class FakeHandshakerService : public HandshakerService::Service {
HandshakerContext context;
HandshakerReq request;
HandshakerResp response;
gpr_log(GPR_DEBUG, "Start a new handshake.");
VLOG(2) << "Start a new handshake.";
while (stream->Read(&request)) {
status = ProcessRequest(&context, request, &response);
if (!status.ok()) return WriteErrorResponse(stream, status);
@ -101,13 +101,13 @@ class FakeHandshakerService : public HandshakerService::Service {
CHECK_NE(response, nullptr);
response->Clear();
if (request.has_client_start()) {
gpr_log(GPR_DEBUG, "Process client start request.");
VLOG(2) << "Process client start request.";
return ProcessClientStart(context, request.client_start(), response);
} else if (request.has_server_start()) {
gpr_log(GPR_DEBUG, "Process server start request.");
VLOG(2) << "Process server start request.";
return ProcessServerStart(context, request.server_start(), response);
} else if (request.has_next()) {
gpr_log(GPR_DEBUG, "Process next request.");
VLOG(2) << "Process next request.";
return ProcessNext(context, request.next(), response);
}
return Status(StatusCode::INVALID_ARGUMENT, "Request is empty.");

@ -32,6 +32,7 @@
#include <gmock/gmock.h>
#include "absl/log/check.h"
#include "absl/log/log.h"
#include "absl/memory/memory.h"
#include "absl/strings/str_cat.h"
@ -40,7 +41,6 @@
#include <grpc/grpc_security.h>
#include <grpc/slice.h>
#include <grpc/support/alloc.h>
#include <grpc/support/log.h>
#include <grpc/support/port_platform.h>
#include <grpc/support/string_util.h>
#include <grpc/support/time.h>
@ -113,8 +113,7 @@ class FakeHandshakeServer {
// TODO(apolcyn): when removing the global concurrent handshake limiting
// queue, set MAX_CONCURRENT_STREAMS on this server.
server_ = builder.BuildAndStart();
gpr_log(GPR_INFO, "Fake handshaker server listening on %s",
address_.c_str());
LOG(INFO) << "Fake handshaker server listening on " << address_;
}
~FakeHandshakeServer() {
@ -148,13 +147,12 @@ class TestServer {
server_creds));
grpc_server_credentials_release(server_creds);
grpc_server_start(server_);
gpr_log(GPR_DEBUG, "Start TestServer %p. listen on %s", this,
server_addr_.c_str());
VLOG(2) << "Start TestServer " << this << ". listen on " << server_addr_;
server_thd_ = std::make_unique<std::thread>(PollUntilShutdown, this);
}
~TestServer() {
gpr_log(GPR_DEBUG, "Begin dtor of TestServer %p", this);
VLOG(2) << "Begin dtor of TestServer " << this;
grpc_server_shutdown_and_notify(server_, server_cq_, this);
server_thd_->join();
grpc_server_destroy(server_);
@ -170,7 +168,7 @@ class TestServer {
self->server_cq_, gpr_inf_future(GPR_CLOCK_REALTIME), nullptr);
CHECK(ev.type == GRPC_OP_COMPLETE);
CHECK(ev.tag == self);
gpr_log(GPR_DEBUG, "TestServer %p stop polling", self);
VLOG(2) << "TestServer " << self << " stop polling";
}
private:
@ -210,7 +208,7 @@ class ConnectLoopRunner {
static void ConnectLoop(const ConnectLoopRunner* self) {
for (size_t i = 0; i < self->loops_; i++) {
gpr_log(GPR_DEBUG, "runner:%p connect_loop begin loop %ld", self, i);
VLOG(2) << "runner:" << self << " connect_loop begin loop " << i;
grpc_completion_queue* cq =
grpc_completion_queue_create_for_next(nullptr);
grpc_channel* channel = create_secure_channel_for_test(
@ -259,7 +257,7 @@ class ConnectLoopRunner {
grpc_completion_queue_shutdown(cq);
drain_cq(cq);
grpc_completion_queue_destroy(cq);
gpr_log(GPR_DEBUG, "runner:%p connect_loop finished loop %ld", self, i);
VLOG(2) << "runner:" << self << " connect_loop finished loop " << i;
}
}
@ -296,8 +294,7 @@ TEST(AltsConcurrentConnectivityTest, TestConcurrentClientServerHandshakes) {
TestServer test_server;
size_t num_concurrent_connects = 50;
std::vector<std::unique_ptr<ConnectLoopRunner>> connect_loop_runners;
gpr_log(GPR_DEBUG,
"start performing concurrent expected-to-succeed connects");
VLOG(2) << "start performing concurrent expected-to-succeed connects";
for (size_t i = 0; i < num_concurrent_connects; i++) {
connect_loop_runners.push_back(std::make_unique<ConnectLoopRunner>(
test_server.address(), fake_handshake_server.address(),
@ -306,8 +303,7 @@ TEST(AltsConcurrentConnectivityTest, TestConcurrentClientServerHandshakes) {
0 /* reconnect_backoff_ms unset */));
}
connect_loop_runners.clear();
gpr_log(GPR_DEBUG,
"done performing concurrent expected-to-succeed connects");
VLOG(2) << "done performing concurrent expected-to-succeed connects";
}
}
@ -336,7 +332,7 @@ TEST(AltsConcurrentConnectivityTest,
{
std::vector<std::unique_ptr<ConnectLoopRunner>> connect_loop_runners;
size_t num_concurrent_connects = 100;
gpr_log(GPR_DEBUG, "start performing concurrent expected-to-fail connects");
VLOG(2) << "start performing concurrent expected-to-fail connects";
for (size_t i = 0; i < num_concurrent_connects; i++) {
connect_loop_runners.push_back(std::make_unique<ConnectLoopRunner>(
fake_backend_server.address(), fake_handshake_server.address(),
@ -345,7 +341,7 @@ TEST(AltsConcurrentConnectivityTest,
0 /* reconnect_backoff_ms unset */));
}
connect_loop_runners.clear();
gpr_log(GPR_DEBUG, "done performing concurrent expected-to-fail connects");
VLOG(2) << "done performing concurrent expected-to-fail connects";
}
}
@ -368,7 +364,7 @@ TEST(AltsConcurrentConnectivityTest,
{
std::vector<std::unique_ptr<ConnectLoopRunner>> connect_loop_runners;
size_t num_concurrent_connects = 100;
gpr_log(GPR_DEBUG, "start performing concurrent expected-to-fail connects");
VLOG(2) << "start performing concurrent expected-to-fail connects";
for (size_t i = 0; i < num_concurrent_connects; i++) {
connect_loop_runners.push_back(std::make_unique<ConnectLoopRunner>(
fake_backend_server.address(), fake_handshake_server.address(),
@ -377,7 +373,7 @@ TEST(AltsConcurrentConnectivityTest,
0 /* reconnect_backoff_ms unset */));
}
connect_loop_runners.clear();
gpr_log(GPR_DEBUG, "done performing concurrent expected-to-fail connects");
VLOG(2) << "done performing concurrent expected-to-fail connects";
}
}
@ -400,7 +396,7 @@ TEST(AltsConcurrentConnectivityTest,
{
std::vector<std::unique_ptr<ConnectLoopRunner>> connect_loop_runners;
size_t num_concurrent_connects = 100;
gpr_log(GPR_DEBUG, "start performing concurrent expected-to-fail connects");
VLOG(2) << "start performing concurrent expected-to-fail connects";
for (size_t i = 0; i < num_concurrent_connects; i++) {
connect_loop_runners.push_back(std::make_unique<ConnectLoopRunner>(
fake_backend_server.address(), fake_handshake_server.address(),
@ -409,7 +405,7 @@ TEST(AltsConcurrentConnectivityTest,
100 /* reconnect_backoff_ms */));
}
connect_loop_runners.clear();
gpr_log(GPR_DEBUG, "done performing concurrent expected-to-fail connects");
VLOG(2) << "done performing concurrent expected-to-fail connects";
}
}

@ -18,13 +18,14 @@
#include "test/core/tsi/alts/handshaker/alts_handshaker_service_api_test_lib.h"
#include "absl/log/log.h"
bool grpc_gcp_handshaker_resp_set_peer_rpc_versions(
grpc_gcp_HandshakerResp* resp, upb_Arena* arena, uint32_t max_major,
uint32_t max_minor, uint32_t min_major, uint32_t min_minor) {
if (resp == nullptr) {
gpr_log(GPR_ERROR,
"Invalid nullptr argument to "
"grpc_gcp_handshaker_resp_set_peer_rpc_versions().");
LOG(ERROR) << "Invalid nullptr argument to "
"grpc_gcp_handshaker_resp_set_peer_rpc_versions().";
return false;
}
grpc_gcp_rpc_protocol_versions versions;
@ -50,7 +51,7 @@ grpc_gcp_HandshakerReq* grpc_gcp_handshaker_req_decode(grpc_slice slice,
grpc_gcp_HandshakerReq* resp = grpc_gcp_HandshakerReq_parse(
reinterpret_cast<char*>(buf), buf_size, arena);
if (!resp) {
gpr_log(GPR_ERROR, "grpc_gcp_HandshakerReq decode error");
LOG(ERROR) << "grpc_gcp_HandshakerReq decode error";
return nullptr;
}
return resp;

@ -27,11 +27,11 @@
#include <openssl/err.h>
#include <openssl/pem.h>
#include "absl/log/log.h"
#include "absl/strings/str_cat.h"
#include <grpc/grpc.h>
#include <grpc/support/alloc.h>
#include <grpc/support/log.h>
#include <grpc/support/string_util.h>
#include "src/core/lib/gprpp/memory.h"
@ -710,7 +710,7 @@ INSTANTIATE_TEST_SUITE_P(
});
TEST_P(SslTransportSecurityTest, DoHandshakeTinyHandshakeBuffer) {
gpr_log(GPR_INFO, "ssl_tsi_test_do_handshake_tiny_handshake_buffer");
LOG(INFO) << "ssl_tsi_test_do_handshake_tiny_handshake_buffer";
SetUpSslFixture(/*tls_version=*/std::get<0>(GetParam()),
/*send_client_ca_list=*/std::get<1>(GetParam()));
ssl_tsi_test_fixture_->handshake_buffer_size =
@ -722,7 +722,7 @@ TEST_P(SslTransportSecurityTest, DoHandshakeTinyHandshakeBuffer) {
}
TEST_P(SslTransportSecurityTest, DoHandshakeSmallHandshakeBuffer) {
gpr_log(GPR_INFO, "ssl_tsi_test_do_handshake_small_handshake_buffer");
LOG(INFO) << "ssl_tsi_test_do_handshake_small_handshake_buffer";
SetUpSslFixture(/*tls_version=*/std::get<0>(GetParam()),
/*send_client_ca_list=*/std::get<1>(GetParam()));
ssl_tsi_test_fixture_->handshake_buffer_size =
@ -731,14 +731,14 @@ TEST_P(SslTransportSecurityTest, DoHandshakeSmallHandshakeBuffer) {
}
TEST_P(SslTransportSecurityTest, DoHandshake) {
gpr_log(GPR_INFO, "ssl_tsi_test_do_handshake");
LOG(INFO) << "ssl_tsi_test_do_handshake";
SetUpSslFixture(/*tls_version=*/std::get<0>(GetParam()),
/*send_client_ca_list=*/std::get<1>(GetParam()));
DoHandshake();
}
TEST_P(SslTransportSecurityTest, DoHandshakeWithRootStore) {
gpr_log(GPR_INFO, "ssl_tsi_test_do_handshake_with_root_store");
LOG(INFO) << "ssl_tsi_test_do_handshake_with_root_store";
SetUpSslFixture(/*tls_version=*/std::get<0>(GetParam()),
/*send_client_ca_list=*/std::get<1>(GetParam()));
ssl_fixture_->MutableKeyCertLib()->use_root_store = true;
@ -749,8 +749,8 @@ TEST_P(SslTransportSecurityTest, DoHandshakeWithRootStore) {
#if OPENSSL_VERSION_NUMBER >= 0x10100000
TEST_P(SslTransportSecurityTest,
DoHandshakeSkippingServerCertificateVerification) {
gpr_log(GPR_INFO,
"ssl_tsi_test_do_handshake_skipping_server_certificate_verification");
LOG(INFO)
<< "ssl_tsi_test_do_handshake_skipping_server_certificate_verification";
SetUpSslFixture(/*tls_version=*/std::get<0>(GetParam()),
/*send_client_ca_list=*/std::get<1>(GetParam()));
ssl_fixture_->SetVerifyRootCertSubject(false);
@ -763,8 +763,7 @@ TEST_P(SslTransportSecurityTest,
#endif
TEST_P(SslTransportSecurityTest, DoHandshakeWithLargeServerHandshakeMessages) {
gpr_log(GPR_INFO,
"ssl_tsi_test_do_handshake_with_large_server_handshake_messages");
LOG(INFO) << "ssl_tsi_test_do_handshake_with_large_server_handshake_messages";
std::string trust_bundle = GenerateTrustBundle();
SetUpSslFixture(/*tls_version=*/std::get<0>(GetParam()),
/*send_client_ca_list=*/std::get<1>(GetParam()));
@ -792,7 +791,7 @@ TEST_P(SslTransportSecurityTest, DoHandshakeWithLargeServerHandshakeMessages) {
}
TEST_P(SslTransportSecurityTest, DoHandshakeWithClientAuthentication) {
gpr_log(GPR_INFO, "ssl_tsi_test_do_handshake_with_client_authentication");
LOG(INFO) << "ssl_tsi_test_do_handshake_with_client_authentication";
SetUpSslFixture(/*tls_version=*/std::get<0>(GetParam()),
/*send_client_ca_list=*/std::get<1>(GetParam()));
ssl_fixture_->SetForceClientAuth(true);
@ -801,9 +800,8 @@ TEST_P(SslTransportSecurityTest, DoHandshakeWithClientAuthentication) {
TEST_P(SslTransportSecurityTest,
DoHandshakeWithClientAuthenticationAndRootStore) {
gpr_log(
GPR_INFO,
"ssl_tsi_test_do_handshake_with_client_authentication_and_root_store");
LOG(INFO)
<< "ssl_tsi_test_do_handshake_with_client_authentication_and_root_store";
SetUpSslFixture(/*tls_version=*/std::get<0>(GetParam()),
/*send_client_ca_list=*/std::get<1>(GetParam()));
ssl_fixture_->SetForceClientAuth(true);
@ -813,8 +811,8 @@ TEST_P(SslTransportSecurityTest,
TEST_P(SslTransportSecurityTest,
DoHandshakeWithServerNameIndicationExactDomain) {
gpr_log(GPR_INFO,
"ssl_tsi_test_do_handshake_with_server_name_indication_exact_domain");
LOG(INFO)
<< "ssl_tsi_test_do_handshake_with_server_name_indication_exact_domain";
SetUpSslFixture(/*tls_version=*/std::get<0>(GetParam()),
/*send_client_ca_list=*/std::get<1>(GetParam()));
// server1 cert contains "waterzooi.test.google.be" in SAN.
@ -825,9 +823,8 @@ TEST_P(SslTransportSecurityTest,
TEST_P(SslTransportSecurityTest,
DoHandshakeWithServerNameIndicationWildStarDomain) {
gpr_log(
GPR_INFO,
"ssl_tsi_test_do_handshake_with_server_name_indication_wild_star_domain");
LOG(INFO) << "ssl_tsi_test_do_handshake_with_server_name_indication_wild_"
"star_domain";
SetUpSslFixture(/*tls_version=*/std::get<0>(GetParam()),
/*send_client_ca_list=*/std::get<1>(GetParam()));
// server1 cert contains "*.test.google.fr" in SAN.
@ -837,8 +834,7 @@ TEST_P(SslTransportSecurityTest,
}
TEST_P(SslTransportSecurityTest, DoHandshakeWithWrongServerNameIndication) {
gpr_log(GPR_INFO,
"ssl_tsi_test_do_handshake_with_wrong_server_name_indication");
LOG(INFO) << "ssl_tsi_test_do_handshake_with_wrong_server_name_indication";
SetUpSslFixture(/*tls_version=*/std::get<0>(GetParam()),
/*send_client_ca_list=*/std::get<1>(GetParam()));
// server certs do not contain "test.google.cn".
@ -849,9 +845,8 @@ TEST_P(SslTransportSecurityTest, DoHandshakeWithWrongServerNameIndication) {
TEST_P(SslTransportSecurityTest,
DoHandshakeWithInvalidAndIgnoredServerNameIndication) {
gpr_log(GPR_INFO,
"ssl_tsi_test_do_handshake_with_invalid_and_ignored_server_name_"
"indication");
LOG(INFO) << "ssl_tsi_test_do_handshake_with_invalid_and_ignored_server_name_"
"indication";
SetUpSslFixture(/*tls_version=*/std::get<0>(GetParam()),
/*send_client_ca_list=*/std::get<1>(GetParam()));
// SNI that's an IP address will be ignored.
@ -861,7 +856,7 @@ TEST_P(SslTransportSecurityTest,
}
TEST_P(SslTransportSecurityTest, DoHandshakeWithBadServerCert) {
gpr_log(GPR_INFO, "ssl_tsi_test_do_handshake_with_bad_server_cert");
LOG(INFO) << "ssl_tsi_test_do_handshake_with_bad_server_cert";
SetUpSslFixture(/*tls_version=*/std::get<0>(GetParam()),
/*send_client_ca_list=*/std::get<1>(GetParam()));
ssl_fixture_->MutableKeyCertLib()->use_bad_server_cert = true;
@ -869,7 +864,7 @@ TEST_P(SslTransportSecurityTest, DoHandshakeWithBadServerCert) {
}
TEST_P(SslTransportSecurityTest, DoHandshakeWithBadClientCert) {
gpr_log(GPR_INFO, "ssl_tsi_test_do_handshake_with_bad_client_cert");
LOG(INFO) << "ssl_tsi_test_do_handshake_with_bad_client_cert";
SetUpSslFixture(/*tls_version=*/std::get<0>(GetParam()),
/*send_client_ca_list=*/std::get<1>(GetParam()));
ssl_fixture_->MutableKeyCertLib()->use_bad_client_cert = true;
@ -880,7 +875,7 @@ TEST_P(SslTransportSecurityTest, DoHandshakeWithBadClientCert) {
#ifdef OPENSSL_IS_BORINGSSL
// BoringSSL and OpenSSL have different behaviors on mismatched ALPN.
TEST_P(SslTransportSecurityTest, DoHandshakeAlpnClientNoServer) {
gpr_log(GPR_INFO, "ssl_tsi_test_do_handshake_alpn_client_no_server");
LOG(INFO) << "ssl_tsi_test_do_handshake_alpn_client_no_server";
SetUpSslFixture(/*tls_version=*/std::get<0>(GetParam()),
/*send_client_ca_list=*/std::get<1>(GetParam()));
ssl_fixture_->SetAlpnMode(ALPN_CLIENT_NO_SERVER);
@ -888,7 +883,7 @@ TEST_P(SslTransportSecurityTest, DoHandshakeAlpnClientNoServer) {
}
TEST_P(SslTransportSecurityTest, DoHandshakeAlpnClientServerMismatch) {
gpr_log(GPR_INFO, "ssl_tsi_test_do_handshake_alpn_client_server_mismatch");
LOG(INFO) << "ssl_tsi_test_do_handshake_alpn_client_server_mismatch";
SetUpSslFixture(/*tls_version=*/std::get<0>(GetParam()),
/*send_client_ca_list=*/std::get<1>(GetParam()));
ssl_fixture_->SetAlpnMode(ALPN_CLIENT_SERVER_MISMATCH);
@ -896,7 +891,7 @@ TEST_P(SslTransportSecurityTest, DoHandshakeAlpnClientServerMismatch) {
}
TEST_P(SslTransportSecurityTest, DoRoundTripForAllConfigs) {
gpr_log(GPR_INFO, "ssl_tsi_test_do_round_trip_for_all_configs");
LOG(INFO) << "ssl_tsi_test_do_round_trip_for_all_configs";
unsigned int* bit_array = static_cast<unsigned int*>(
gpr_zalloc(sizeof(unsigned int) * TSI_TEST_NUM_OF_ARGUMENTS));
const unsigned int mask = 1U << (TSI_TEST_NUM_OF_ARGUMENTS - 1);
@ -919,7 +914,7 @@ TEST_P(SslTransportSecurityTest, DoRoundTripForAllConfigs) {
}
TEST_P(SslTransportSecurityTest, DoRoundTripWithErrorOnStack) {
gpr_log(GPR_INFO, "ssl_tsi_test_do_round_trip_with_error_on_stack");
LOG(INFO) << "ssl_tsi_test_do_round_trip_with_error_on_stack";
// Invoke an SSL function that causes an error, and ensure the error
// makes it to the stack.
ASSERT_FALSE(EC_KEY_new_by_curve_name(NID_rsa));
@ -930,7 +925,7 @@ TEST_P(SslTransportSecurityTest, DoRoundTripWithErrorOnStack) {
}
TEST_P(SslTransportSecurityTest, DoRoundTripOddBufferSize) {
gpr_log(GPR_INFO, "ssl_tsi_test_do_round_trip_odd_buffer_size");
LOG(INFO) << "ssl_tsi_test_do_round_trip_odd_buffer_size";
const size_t odd_sizes[] = {1025, 2051, 4103, 8207, 16409};
size_t size = sizeof(odd_sizes) / sizeof(size_t);
// 1. This test is extremely slow under MSAN and TSAN.
@ -962,7 +957,7 @@ TEST_P(SslTransportSecurityTest, DoRoundTripOddBufferSize) {
}
TEST_P(SslTransportSecurityTest, DoHandshakeSessionCache) {
gpr_log(GPR_INFO, "ssl_tsi_test_do_handshake_session_cache");
LOG(INFO) << "ssl_tsi_test_do_handshake_session_cache";
tsi_ssl_session_cache* session_cache = tsi_ssl_session_cache_create_lru(16);
char session_ticket_key[kSessionTicketEncryptionKeySize];
auto do_handshake = [this, &session_ticket_key,
@ -995,7 +990,7 @@ TEST_P(SslTransportSecurityTest, DoHandshakeSessionCache) {
#endif // OPENSSL_IS_BORINGSSL
TEST_P(SslTransportSecurityTest, DoHandshakeAlpnServerNoClient) {
gpr_log(GPR_INFO, "ssl_tsi_test_do_handshake_alpn_server_no_client");
LOG(INFO) << "ssl_tsi_test_do_handshake_alpn_server_no_client";
SetUpSslFixture(/*tls_version=*/std::get<0>(GetParam()),
/*send_client_ca_list=*/std::get<1>(GetParam()));
ssl_fixture_->SetAlpnMode(ALPN_SERVER_NO_CLIENT);
@ -1003,7 +998,7 @@ TEST_P(SslTransportSecurityTest, DoHandshakeAlpnServerNoClient) {
}
TEST_P(SslTransportSecurityTest, DoHandshakeAlpnClientServerOk) {
gpr_log(GPR_INFO, "ssl_tsi_test_do_handshake_alpn_client_server_ok");
LOG(INFO) << "ssl_tsi_test_do_handshake_alpn_client_server_ok";
SetUpSslFixture(/*tls_version=*/std::get<0>(GetParam()),
/*send_client_ca_list=*/std::get<1>(GetParam()));
ssl_fixture_->SetAlpnMode(ALPN_CLIENT_SERVER_OK);
@ -1011,7 +1006,7 @@ TEST_P(SslTransportSecurityTest, DoHandshakeAlpnClientServerOk) {
}
TEST_P(SslTransportSecurityTest, DoHandshakeWithCustomBioPair) {
gpr_log(GPR_INFO, "ssl_tsi_test_do_handshake_with_custom_bio_pair");
LOG(INFO) << "ssl_tsi_test_do_handshake_with_custom_bio_pair";
SetUpSslFixture(/*tls_version=*/std::get<0>(GetParam()),
/*send_client_ca_list=*/std::get<1>(GetParam()));
#if OPENSSL_VERSION_NUMBER >= 0x10100000
@ -1143,7 +1138,7 @@ TEST(SslTransportSecurityTest, TestClientHandshakerFactoryBadParams) {
}
TEST(SslTransportSecurityTest, DuplicateRootCertificates) {
gpr_log(GPR_INFO, "ssl_tsi_test_duplicate_root_certificates");
LOG(INFO) << "ssl_tsi_test_duplicate_root_certificates";
char* root_cert = load_file(SSL_TSI_TEST_CREDENTIALS_DIR "ca.pem");
char* dup_root_cert = static_cast<char*>(
gpr_zalloc(sizeof(char) * (strlen(root_cert) * 2 + 1)));
@ -1159,7 +1154,7 @@ TEST(SslTransportSecurityTest, DuplicateRootCertificates) {
}
TEST(SslTransportSecurityTest, ExtractX509SubjectNames) {
gpr_log(GPR_INFO, "ssl_tsi_test_extract_x509_subject_names");
LOG(INFO) << "ssl_tsi_test_extract_x509_subject_names";
char* cert = load_file(SSL_TSI_TEST_CREDENTIALS_DIR "multi-domain.pem");
tsi_peer peer;
ASSERT_EQ(tsi_ssl_extract_x509_subject_names_from_pem_cert(cert, &peer),
@ -1263,7 +1258,7 @@ TEST(SslTransportSecurityTest, ExtractX509SubjectNames) {
}
TEST(SslTransportSecurityTest, ExtractCertChain) {
gpr_log(GPR_INFO, "ssl_tsi_test_extract_cert_chain");
LOG(INFO) << "ssl_tsi_test_extract_cert_chain";
char* cert = load_file(SSL_TSI_TEST_CREDENTIALS_DIR "server1.pem");
char* ca = load_file(SSL_TSI_TEST_CREDENTIALS_DIR "ca.pem");
char* chain = static_cast<char*>(

@ -20,6 +20,7 @@
#include <string>
#include <utility>
#include "absl/log/log.h"
#include "absl/status/status.h"
#include "absl/status/statusor.h"
#include "absl/strings/str_cat.h"
@ -28,7 +29,6 @@
#include "absl/types/optional.h"
#include <grpc/grpc.h>
#include <grpc/support/log.h>
#include "src/core/lib/event_engine/default_event_engine.h"
#include "src/core/lib/gprpp/orphanable.h"
@ -53,8 +53,7 @@ class Fuzzer {
explicit Fuzzer(absl::string_view bootstrap_json) {
auto bootstrap = GrpcXdsBootstrap::Create(bootstrap_json);
if (!bootstrap.ok()) {
gpr_log(GPR_ERROR, "error creating bootstrap: %s",
bootstrap.status().ToString().c_str());
LOG(ERROR) << "error creating bootstrap: " << bootstrap.status();
// Leave xds_client_ unset, so Act() will be a no-op.
return;
}
@ -122,20 +121,18 @@ class Fuzzer {
[](const testing::XdsClientTestPeer::ResourceCountLabels&
labels,
uint64_t count) {
gpr_log(GPR_INFO,
"xds_authority=\"%s\", resource_type=\"%s\", "
"cache_state=\"%s\" count=%" PRIu64,
std::string(labels.xds_authority).c_str(),
std::string(labels.resource_type).c_str(),
std::string(labels.cache_state).c_str(), count);
LOG(INFO) << "xds_authority=\"" << labels.xds_authority
<< "\", resource_type=\"" << labels.resource_type
<< "\", cache_state=\"" << labels.cache_state
<< "\" count=" << count;
});
break;
case xds_client_fuzzer::Action::kReportServerConnections:
testing::XdsClientTestPeer(xds_client_.get())
.TestReportServerConnections(
[](absl::string_view xds_server, bool connected) {
gpr_log(GPR_INFO, "xds_server=\"%s\" connected=%d",
std::string(xds_server).c_str(), connected);
LOG(INFO) << "xds_server=\"" << xds_server
<< "\" connected=" << connected;
});
break;
case xds_client_fuzzer::Action::kTriggerConnectionFailure:
@ -174,26 +171,24 @@ class Fuzzer {
std::shared_ptr<const typename ResourceType::ResourceType> resource,
RefCountedPtr<XdsClient::ReadDelayHandle> /* read_delay_handle */)
override {
gpr_log(GPR_INFO, "==> OnResourceChanged(%s %s): %s",
std::string(ResourceType::Get()->type_url()).c_str(),
resource_name_.c_str(), resource->ToString().c_str());
LOG(INFO) << "==> OnResourceChanged(" << ResourceType::Get()->type_url()
<< " " << resource_name_ << "): " << resource->ToString();
}
void OnError(
absl::Status status,
RefCountedPtr<XdsClient::ReadDelayHandle> /* read_delay_handle */)
override {
gpr_log(GPR_INFO, "==> OnError(%s %s): %s",
std::string(ResourceType::Get()->type_url()).c_str(),
resource_name_.c_str(), status.ToString().c_str());
LOG(INFO) << "==> OnError(" << ResourceType::Get()->type_url() << " "
<< resource_name_ << "): " << status;
}
void OnResourceDoesNotExist(
RefCountedPtr<XdsClient::ReadDelayHandle> /* read_delay_handle */)
override {
gpr_log(GPR_INFO, "==> OnResourceDoesNotExist(%s %s)",
std::string(ResourceType::Get()->type_url()).c_str(),
resource_name_.c_str());
LOG(INFO) << "==> OnResourceDoesNotExist("
<< ResourceType::Get()->type_url() << " " << resource_name_
<< ")";
}
private:
@ -208,9 +203,9 @@ class Fuzzer {
template <typename WatcherType>
void StartWatch(std::map<std::string, std::set<WatcherType*>>* watchers,
std::string resource_name) {
gpr_log(GPR_INFO, "### StartWatch(%s %s)",
std::string(WatcherType::ResourceType::Get()->type_url()).c_str(),
resource_name.c_str());
LOG(INFO) << "### StartWatch("
<< WatcherType::ResourceType::Get()->type_url() << " "
<< resource_name << ")";
auto watcher = MakeRefCounted<WatcherType>(resource_name);
(*watchers)[resource_name].insert(watcher.get());
WatcherType::ResourceType::Get()->StartWatch(
@ -220,9 +215,9 @@ class Fuzzer {
template <typename WatcherType>
void StopWatch(std::map<std::string, std::set<WatcherType*>>* watchers,
std::string resource_name) {
gpr_log(GPR_INFO, "### StopWatch(%s %s)",
std::string(WatcherType::ResourceType::Get()->type_url()).c_str(),
resource_name.c_str());
LOG(INFO) << "### StopWatch("
<< WatcherType::ResourceType::Get()->type_url() << " "
<< resource_name << ")";
auto& watchers_set = (*watchers)[resource_name];
auto it = watchers_set.begin();
if (it == watchers_set.end()) return;
@ -252,8 +247,8 @@ class Fuzzer {
void TriggerConnectionFailure(const std::string& authority,
absl::Status status) {
gpr_log(GPR_INFO, "### TriggerConnectionFailure(%s): %s", authority.c_str(),
status.ToString().c_str());
LOG(INFO) << "### TriggerConnectionFailure(" << authority
<< "): " << status;
const auto* xds_server = GetServer(authority);
if (xds_server == nullptr) return;
transport_factory_->TriggerConnectionFailure(*xds_server,
@ -290,14 +285,14 @@ class Fuzzer {
void ReadMessageFromClient(const xds_client_fuzzer::StreamId& stream_id,
bool ok) {
gpr_log(GPR_INFO, "### ReadMessageFromClient(%s): %s",
StreamIdString(stream_id).c_str(), ok ? "true" : "false");
LOG(INFO) << "### ReadMessageFromClient(" << StreamIdString(stream_id)
<< "): " << (ok ? "true" : "false");
auto stream = GetStream(stream_id);
if (stream == nullptr) return;
gpr_log(GPR_INFO, " stream=%p", stream.get());
LOG(INFO) << " stream=" << stream.get();
auto message = stream->WaitForMessageFromClient(absl::ZeroDuration());
if (message.has_value()) {
gpr_log(GPR_INFO, " completing send_message");
LOG(INFO) << " completing send_message";
stream->CompleteSendMessageFromClient(ok);
}
}
@ -305,21 +300,20 @@ class Fuzzer {
void SendMessageToClient(
const xds_client_fuzzer::StreamId& stream_id,
const envoy::service::discovery::v3::DiscoveryResponse& response) {
gpr_log(GPR_INFO, "### SendMessageToClient(%s)",
StreamIdString(stream_id).c_str());
LOG(INFO) << "### SendMessageToClient(" << StreamIdString(stream_id) << ")";
auto stream = GetStream(stream_id);
if (stream == nullptr) return;
gpr_log(GPR_INFO, " stream=%p", stream.get());
LOG(INFO) << " stream=" << stream.get();
stream->SendMessageToClient(response.SerializeAsString());
}
void SendStatusToClient(const xds_client_fuzzer::StreamId& stream_id,
absl::Status status) {
gpr_log(GPR_INFO, "### SendStatusToClient(%s): %s",
StreamIdString(stream_id).c_str(), status.ToString().c_str());
LOG(INFO) << "### SendStatusToClient(" << StreamIdString(stream_id)
<< "): " << status;
auto stream = GetStream(stream_id);
if (stream == nullptr) return;
gpr_log(GPR_INFO, " stream=%p", stream.get());
LOG(INFO) << " stream=" << stream.get();
stream->MaybeSendStatusToClient(std::move(status));
}

Loading…
Cancel
Save