Skip to content

Commit

Permalink
Adjust the log levels in interop tests and stress tests
Browse files Browse the repository at this point in the history
  • Loading branch information
@sreecha
sreecha committed Jan 6, 2016
1 parent 0fa95ea commit 7cecfa6
Show file tree
Hide file tree
Showing 2 changed files with 51 additions and 47 deletions.
96 changes: 50 additions & 46 deletions test/cpp/interop/interop_client.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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 {
Expand Down Expand Up @@ -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();
Expand All @@ -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,
Expand Down Expand Up @@ -208,27 +208,27 @@ 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;
request.set_fill_username(true);
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;
Expand All @@ -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);
Expand All @@ -266,28 +266,29 @@ 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);
request.set_response_type(PayloadType::COMPRESSABLE);
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() {
Expand All @@ -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;
Expand All @@ -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;
Expand All @@ -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() {
Expand All @@ -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]);
Expand Down Expand Up @@ -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;
Expand All @@ -458,19 +460,19 @@ 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;
}
GPR_ASSERT(kNumResponseMessages == i);
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,
Expand All @@ -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,
Expand All @@ -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;
Expand All @@ -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,
Expand All @@ -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 =
Expand All @@ -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,
Expand All @@ -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;
Expand All @@ -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
Expand Down
2 changes: 1 addition & 1 deletion test/cpp/interop/stress_interop_client.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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++;
Expand Down

0 comments on commit 7cecfa6

Please sign in to comment.