From 7cecfa6c48b3f58d0a242b8dfbb671345b95e78f Mon Sep 17 00:00:00 2001
From: Sree Kuchibhotla <sreek@google.com>
Date: Wed, 6 Jan 2016 08:09:02 -0800
Subject: [PATCH] Adjust the log levels in interop tests and stress tests

---
 test/cpp/interop/interop_client.cc        | 96 ++++++++++++-----------
 test/cpp/interop/stress_interop_client.cc |  2 +-
 2 files changed, 51 insertions(+), 47 deletions(-)

diff --git a/test/cpp/interop/interop_client.cc b/test/cpp/interop/interop_client.cc
index 05ef0c8d9d..a758e73def 100644
--- a/test/cpp/interop/interop_client.cc
+++ b/test/cpp/interop/interop_client.cc
@@ -38,19 +38,19 @@
 #include <fstream>
 #include <memory>
 
+#include <grpc++/channel.h>
+#include <grpc++/client_context.h>
+#include <grpc++/security/credentials.h>
 #include <grpc/grpc.h>
 #include <grpc/support/log.h>
 #include <grpc/support/string_util.h>
 #include <grpc/support/useful.h>
-#include <grpc++/channel.h>
-#include <grpc++/client_context.h>
-#include <grpc++/security/credentials.h>
 
 #include "src/core/transport/byte_stream.h"
 #include "test/cpp/interop/client_helper.h"
-#include "test/proto/test.grpc.pb.h"
 #include "test/proto/empty.grpc.pb.h"
 #include "test/proto/messages.grpc.pb.h"
+#include "test/proto/test.grpc.pb.h"
 
 namespace grpc {
 namespace testing {
@@ -145,13 +145,13 @@ void InteropClient::AssertOkOrPrintErrorStatus(const Status& s) {
   if (s.ok()) {
     return;
   }
-  gpr_log(GPR_INFO, "Error status code: %d, message: %s", s.error_code(),
+  gpr_log(GPR_ERROR, "Error status code: %d, message: %s", s.error_code(),
           s.error_message().c_str());
   GPR_ASSERT(0);
 }
 
 void InteropClient::DoEmpty() {
-  gpr_log(GPR_INFO, "Sending an empty rpc...");
+  gpr_log(GPR_DEBUG, "Sending an empty rpc...");
 
   Empty request = Empty::default_instance();
   Empty response = Empty::default_instance();
@@ -160,7 +160,7 @@ void InteropClient::DoEmpty() {
   Status s = serviceStub_.Get()->EmptyCall(&context, request, &response);
   AssertOkOrPrintErrorStatus(s);
 
-  gpr_log(GPR_INFO, "Empty rpc done.");
+  gpr_log(GPR_DEBUG, "Empty rpc done.");
 }
 
 void InteropClient::PerformLargeUnary(SimpleRequest* request,
@@ -208,7 +208,7 @@ void InteropClient::PerformLargeUnary(SimpleRequest* request,
 void InteropClient::DoComputeEngineCreds(
     const grpc::string& default_service_account,
     const grpc::string& oauth_scope) {
-  gpr_log(GPR_INFO,
+  gpr_log(GPR_DEBUG,
           "Sending a large unary rpc with compute engine credentials ...");
   SimpleRequest request;
   SimpleResponse response;
@@ -216,19 +216,19 @@ void InteropClient::DoComputeEngineCreds(
   request.set_fill_oauth_scope(true);
   request.set_response_type(PayloadType::COMPRESSABLE);
   PerformLargeUnary(&request, &response);
-  gpr_log(GPR_INFO, "Got username %s", response.username().c_str());
-  gpr_log(GPR_INFO, "Got oauth_scope %s", response.oauth_scope().c_str());
+  gpr_log(GPR_DEBUG, "Got username %s", response.username().c_str());
+  gpr_log(GPR_DEBUG, "Got oauth_scope %s", response.oauth_scope().c_str());
   GPR_ASSERT(!response.username().empty());
   GPR_ASSERT(response.username().c_str() == default_service_account);
   GPR_ASSERT(!response.oauth_scope().empty());
   const char* oauth_scope_str = response.oauth_scope().c_str();
   GPR_ASSERT(oauth_scope.find(oauth_scope_str) != grpc::string::npos);
-  gpr_log(GPR_INFO, "Large unary with compute engine creds done.");
+  gpr_log(GPR_DEBUG, "Large unary with compute engine creds done.");
 }
 
 void InteropClient::DoOauth2AuthToken(const grpc::string& username,
                                       const grpc::string& oauth_scope) {
-  gpr_log(GPR_INFO,
+  gpr_log(GPR_DEBUG,
           "Sending a unary rpc with raw oauth2 access token credentials ...");
   SimpleRequest request;
   SimpleResponse response;
@@ -245,11 +245,11 @@ void InteropClient::DoOauth2AuthToken(const grpc::string& username,
   GPR_ASSERT(username == response.username());
   const char* oauth_scope_str = response.oauth_scope().c_str();
   GPR_ASSERT(oauth_scope.find(oauth_scope_str) != grpc::string::npos);
-  gpr_log(GPR_INFO, "Unary with oauth2 access token credentials done.");
+  gpr_log(GPR_DEBUG, "Unary with oauth2 access token credentials done.");
 }
 
 void InteropClient::DoPerRpcCreds(const grpc::string& json_key) {
-  gpr_log(GPR_INFO, "Sending a unary rpc with per-rpc JWT access token ...");
+  gpr_log(GPR_DEBUG, "Sending a unary rpc with per-rpc JWT access token ...");
   SimpleRequest request;
   SimpleResponse response;
   request.set_fill_username(true);
@@ -266,11 +266,12 @@ void InteropClient::DoPerRpcCreds(const grpc::string& json_key) {
   AssertOkOrPrintErrorStatus(s);
   GPR_ASSERT(!response.username().empty());
   GPR_ASSERT(json_key.find(response.username()) != grpc::string::npos);
-  gpr_log(GPR_INFO, "Unary with per-rpc JWT access token done.");
+  gpr_log(GPR_DEBUG, "Unary with per-rpc JWT access token done.");
 }
 
 void InteropClient::DoJwtTokenCreds(const grpc::string& username) {
-  gpr_log(GPR_INFO, "Sending a large unary rpc with JWT token credentials ...");
+  gpr_log(GPR_DEBUG,
+          "Sending a large unary rpc with JWT token credentials ...");
   SimpleRequest request;
   SimpleResponse response;
   request.set_fill_username(true);
@@ -278,16 +279,16 @@ void InteropClient::DoJwtTokenCreds(const grpc::string& username) {
   PerformLargeUnary(&request, &response);
   GPR_ASSERT(!response.username().empty());
   GPR_ASSERT(username.find(response.username()) != grpc::string::npos);
-  gpr_log(GPR_INFO, "Large unary with JWT token creds done.");
+  gpr_log(GPR_DEBUG, "Large unary with JWT token creds done.");
 }
 
 void InteropClient::DoLargeUnary() {
-  gpr_log(GPR_INFO, "Sending a large unary rpc...");
+  gpr_log(GPR_DEBUG, "Sending a large unary rpc...");
   SimpleRequest request;
   SimpleResponse response;
   request.set_response_type(PayloadType::COMPRESSABLE);
   PerformLargeUnary(&request, &response);
-  gpr_log(GPR_INFO, "Large unary done.");
+  gpr_log(GPR_DEBUG, "Large unary done.");
 }
 
 void InteropClient::DoLargeCompressedUnary() {
@@ -300,20 +301,21 @@ void InteropClient::DoLargeCompressedUnary() {
                    CompressionType_Name(compression_types[j]).c_str(),
                    PayloadType_Name(payload_types[i]).c_str());
 
-      gpr_log(GPR_INFO, "Sending a large compressed unary rpc %s.", log_suffix);
+      gpr_log(GPR_DEBUG, "Sending a large compressed unary rpc %s.",
+              log_suffix);
       SimpleRequest request;
       SimpleResponse response;
       request.set_response_type(payload_types[i]);
       request.set_response_compression(compression_types[j]);
       PerformLargeUnary(&request, &response, CompressionChecks);
-      gpr_log(GPR_INFO, "Large compressed unary done %s.", log_suffix);
+      gpr_log(GPR_DEBUG, "Large compressed unary done %s.", log_suffix);
       gpr_free(log_suffix);
     }
   }
 }
 
 void InteropClient::DoRequestStreaming() {
-  gpr_log(GPR_INFO, "Sending request steaming rpc ...");
+  gpr_log(GPR_DEBUG, "Sending request steaming rpc ...");
 
   ClientContext context;
   StreamingInputCallRequest request;
@@ -334,11 +336,11 @@ void InteropClient::DoRequestStreaming() {
 
   GPR_ASSERT(response.aggregated_payload_size() == aggregated_payload_size);
   AssertOkOrPrintErrorStatus(s);
-  gpr_log(GPR_INFO, "Request streaming done.");
+  gpr_log(GPR_DEBUG, "Request streaming done.");
 }
 
 void InteropClient::DoResponseStreaming() {
-  gpr_log(GPR_INFO, "Receiving response steaming rpc ...");
+  gpr_log(GPR_DEBUG, "Receiving response steaming rpc ...");
 
   ClientContext context;
   StreamingOutputCallRequest request;
@@ -359,7 +361,7 @@ void InteropClient::DoResponseStreaming() {
   GPR_ASSERT(response_stream_sizes.size() == i);
   Status s = stream->Finish();
   AssertOkOrPrintErrorStatus(s);
-  gpr_log(GPR_INFO, "Response streaming done.");
+  gpr_log(GPR_DEBUG, "Response streaming done.");
 }
 
 void InteropClient::DoResponseCompressedStreaming() {
@@ -376,7 +378,7 @@ void InteropClient::DoResponseCompressedStreaming() {
                    CompressionType_Name(compression_types[j]).c_str(),
                    PayloadType_Name(payload_types[i]).c_str());
 
-      gpr_log(GPR_INFO, "Receiving response steaming rpc %s.", log_suffix);
+      gpr_log(GPR_DEBUG, "Receiving response steaming rpc %s.", log_suffix);
 
       request.set_response_type(payload_types[i]);
       request.set_response_compression(compression_types[j]);
@@ -434,14 +436,14 @@ void InteropClient::DoResponseCompressedStreaming() {
       Status s = stream->Finish();
 
       AssertOkOrPrintErrorStatus(s);
-      gpr_log(GPR_INFO, "Response streaming done %s.", log_suffix);
+      gpr_log(GPR_DEBUG, "Response streaming done %s.", log_suffix);
       gpr_free(log_suffix);
     }
   }
 }
 
 void InteropClient::DoResponseStreamingWithSlowConsumer() {
-  gpr_log(GPR_INFO, "Receiving response steaming rpc with slow consumer ...");
+  gpr_log(GPR_DEBUG, "Receiving response steaming rpc with slow consumer ...");
 
   ClientContext context;
   StreamingOutputCallRequest request;
@@ -458,7 +460,7 @@ void InteropClient::DoResponseStreamingWithSlowConsumer() {
   while (stream->Read(&response)) {
     GPR_ASSERT(response.payload().body() ==
                grpc::string(kResponseMessageSize, '\0'));
-    gpr_log(GPR_INFO, "received message %d", i);
+    gpr_log(GPR_DEBUG, "received message %d", i);
     usleep(kReceiveDelayMilliSeconds * 1000);
     ++i;
   }
@@ -466,11 +468,11 @@ void InteropClient::DoResponseStreamingWithSlowConsumer() {
   Status s = stream->Finish();
 
   AssertOkOrPrintErrorStatus(s);
-  gpr_log(GPR_INFO, "Response streaming done.");
+  gpr_log(GPR_DEBUG, "Response streaming done.");
 }
 
 void InteropClient::DoHalfDuplex() {
-  gpr_log(GPR_INFO, "Sending half-duplex streaming rpc ...");
+  gpr_log(GPR_DEBUG, "Sending half-duplex streaming rpc ...");
 
   ClientContext context;
   std::unique_ptr<ClientReaderWriter<StreamingOutputCallRequest,
@@ -495,11 +497,11 @@ void InteropClient::DoHalfDuplex() {
   GPR_ASSERT(response_stream_sizes.size() == i);
   Status s = stream->Finish();
   AssertOkOrPrintErrorStatus(s);
-  gpr_log(GPR_INFO, "Half-duplex streaming rpc done.");
+  gpr_log(GPR_DEBUG, "Half-duplex streaming rpc done.");
 }
 
 void InteropClient::DoPingPong() {
-  gpr_log(GPR_INFO, "Sending Ping Pong streaming rpc ...");
+  gpr_log(GPR_DEBUG, "Sending Ping Pong streaming rpc ...");
 
   ClientContext context;
   std::unique_ptr<ClientReaderWriter<StreamingOutputCallRequest,
@@ -524,11 +526,11 @@ void InteropClient::DoPingPong() {
   GPR_ASSERT(!stream->Read(&response));
   Status s = stream->Finish();
   AssertOkOrPrintErrorStatus(s);
-  gpr_log(GPR_INFO, "Ping pong streaming done.");
+  gpr_log(GPR_DEBUG, "Ping pong streaming done.");
 }
 
 void InteropClient::DoCancelAfterBegin() {
-  gpr_log(GPR_INFO, "Sending request steaming rpc ...");
+  gpr_log(GPR_DEBUG, "Sending request steaming rpc ...");
 
   ClientContext context;
   StreamingInputCallRequest request;
@@ -537,15 +539,15 @@ void InteropClient::DoCancelAfterBegin() {
   std::unique_ptr<ClientWriter<StreamingInputCallRequest>> stream(
       serviceStub_.Get()->StreamingInputCall(&context, &response));
 
-  gpr_log(GPR_INFO, "Trying to cancel...");
+  gpr_log(GPR_DEBUG, "Trying to cancel...");
   context.TryCancel();
   Status s = stream->Finish();
   GPR_ASSERT(s.error_code() == StatusCode::CANCELLED);
-  gpr_log(GPR_INFO, "Canceling streaming done.");
+  gpr_log(GPR_DEBUG, "Canceling streaming done.");
 }
 
 void InteropClient::DoCancelAfterFirstResponse() {
-  gpr_log(GPR_INFO, "Sending Ping Pong streaming rpc ...");
+  gpr_log(GPR_DEBUG, "Sending Ping Pong streaming rpc ...");
 
   ClientContext context;
   std::unique_ptr<ClientReaderWriter<StreamingOutputCallRequest,
@@ -561,15 +563,16 @@ void InteropClient::DoCancelAfterFirstResponse() {
   GPR_ASSERT(stream->Write(request));
   GPR_ASSERT(stream->Read(&response));
   GPR_ASSERT(response.payload().body() == grpc::string(31415, '\0'));
-  gpr_log(GPR_INFO, "Trying to cancel...");
+  gpr_log(GPR_DEBUG, "Trying to cancel...");
   context.TryCancel();
 
   Status s = stream->Finish();
-  gpr_log(GPR_INFO, "Canceling pingpong streaming done.");
+  gpr_log(GPR_DEBUG, "Canceling pingpong streaming done.");
 }
 
 void InteropClient::DoTimeoutOnSleepingServer() {
-  gpr_log(GPR_INFO, "Sending Ping Pong streaming rpc with a short deadline...");
+  gpr_log(GPR_DEBUG,
+          "Sending Ping Pong streaming rpc with a short deadline...");
 
   ClientContext context;
   std::chrono::system_clock::time_point deadline =
@@ -585,11 +588,11 @@ void InteropClient::DoTimeoutOnSleepingServer() {
 
   Status s = stream->Finish();
   GPR_ASSERT(s.error_code() == StatusCode::DEADLINE_EXCEEDED);
-  gpr_log(GPR_INFO, "Pingpong streaming timeout done.");
+  gpr_log(GPR_DEBUG, "Pingpong streaming timeout done.");
 }
 
 void InteropClient::DoEmptyStream() {
-  gpr_log(GPR_INFO, "Starting empty_stream.");
+  gpr_log(GPR_DEBUG, "Starting empty_stream.");
 
   ClientContext context;
   std::unique_ptr<ClientReaderWriter<StreamingOutputCallRequest,
@@ -600,11 +603,12 @@ void InteropClient::DoEmptyStream() {
   GPR_ASSERT(stream->Read(&response) == false);
   Status s = stream->Finish();
   AssertOkOrPrintErrorStatus(s);
-  gpr_log(GPR_INFO, "empty_stream done.");
+  gpr_log(GPR_DEBUG, "empty_stream done.");
 }
 
 void InteropClient::DoStatusWithMessage() {
-  gpr_log(GPR_INFO, "Sending RPC with a request for status code 2 and message");
+  gpr_log(GPR_DEBUG,
+          "Sending RPC with a request for status code 2 and message");
 
   ClientContext context;
   SimpleRequest request;
@@ -618,7 +622,7 @@ void InteropClient::DoStatusWithMessage() {
 
   GPR_ASSERT(s.error_code() == grpc::StatusCode::UNKNOWN);
   GPR_ASSERT(s.error_message() == test_msg);
-  gpr_log(GPR_INFO, "Done testing Status and Message");
+  gpr_log(GPR_DEBUG, "Done testing Status and Message");
 }
 
 }  // namespace testing
diff --git a/test/cpp/interop/stress_interop_client.cc b/test/cpp/interop/stress_interop_client.cc
index 5d2951e3ed..04671fb935 100644
--- a/test/cpp/interop/stress_interop_client.cc
+++ b/test/cpp/interop/stress_interop_client.cc
@@ -112,7 +112,7 @@ void StressTestInteropClient::MainLoop(std::shared_ptr<Gauge> qps_gauge) {
          gpr_time_cmp(gpr_now(GPR_CLOCK_REALTIME), test_end_time) < 0) {
     // Select the test case to execute based on the weights and execute it
     TestCaseType test_case = test_selector_.GetNextTest();
-    gpr_log(GPR_INFO, "%d - Executing the test case %d", test_id_, test_case);
+    gpr_log(GPR_DEBUG, "%d - Executing the test case %d", test_id_, test_case);
     RunTest(test_case);
 
     num_calls_per_interval++;
-- 
GitLab