Removed failed execution timer, log request before execution, and changed execution time at table level.

Author: soumitra-st

pinot-common/src/main/java/org/apache/pinot/common/metrics/ServerTimer.java

@@ -53,8 +53,7 @@ public enum ServerTimer implements AbstractMetrics.Timer {
       "Total time taken to preload a table partition of an upsert table with upsert snapshot"),
   UPSERT_REMOVE_EXPIRED_PRIMARY_KEYS_TIME_MS("milliseconds", false,
       "Total time taken to delete expired primary keys based on metadataTTL or deletedKeysTTL"),
-  GRPC_QUERY_EXECUTION_MS("milliseconds", true, "Total execution time of a successful query over gRPC"),
-  GRPC_FAILED_QUERY_EXECUTION_MS("milliseconds", true, "Total execution time of a failing query over gRPC"),
+  GRPC_QUERY_EXECUTION_MS("milliseconds", false, "Total execution time of a successful query over gRPC"),
   UPSERT_SNAPSHOT_TIME_MS("milliseconds", false, "Total time taken to take upsert table snapshot");
 
   private final String _timerName;

pinot-core/src/main/java/org/apache/pinot/core/transport/grpc/GrpcQueryServer.java

@@ -172,8 +172,6 @@ public void submit(ServerRequest request, StreamObserver<ServerResponse> respons
       LOGGER.error("Caught exception while deserializing the request: {}", request, e);
       _serverMetrics.addMeteredGlobalValue(ServerMeter.REQUEST_DESERIALIZATION_EXCEPTIONS, 1);
       responseObserver.onError(Status.INVALID_ARGUMENT.withDescription("Bad request").withCause(e).asException());
-      _serverMetrics.addTimedValue(ServerTimer.GRPC_FAILED_QUERY_EXECUTION_MS, System.nanoTime() - startTime,
-          TimeUnit.NANOSECONDS);
       return;
     }
 
@@ -189,23 +187,21 @@ public void submit(ServerRequest request, StreamObserver<ServerResponse> respons
       _serverMetrics.addMeteredGlobalValue(ServerMeter.NO_TABLE_ACCESS, 1);
       responseObserver.onError(
           Status.NOT_FOUND.withDescription(exceptionMsg).withCause(unsupportedOperationException).asException());
-      _serverMetrics.addTimedValue(ServerTimer.GRPC_FAILED_QUERY_EXECUTION_MS, System.nanoTime() - startTime,
-          TimeUnit.NANOSECONDS);
       return;
     }
 
     // Process the query
     InstanceResponseBlock instanceResponse;
     try {
+      LOGGER.info("Executing gRPC query request {}: {} received from broker: {}", queryRequest.getRequestId(),
+          queryRequest.getQueryContext(), queryRequest.getBrokerId());
       instanceResponse = _queryExecutor.execute(queryRequest, _executorService,
           new GrpcResultsBlockStreamer(responseObserver, _serverMetrics));
     } catch (Exception e) {
       LOGGER.error("Caught exception while processing request {}: {} from broker: {}", queryRequest.getRequestId(),
           queryRequest.getQueryContext(), queryRequest.getBrokerId(), e);
       _serverMetrics.addMeteredGlobalValue(ServerMeter.UNCAUGHT_EXCEPTIONS, 1);
       responseObserver.onError(Status.INTERNAL.withCause(e).asException());
-      _serverMetrics.addTimedValue(ServerTimer.GRPC_FAILED_QUERY_EXECUTION_MS, System.nanoTime() - startTime,
-          TimeUnit.NANOSECONDS);
       return;
     }
 
@@ -219,15 +215,13 @@ public void submit(ServerRequest request, StreamObserver<ServerResponse> respons
           queryRequest.getRequestId(), queryRequest.getQueryContext(), queryRequest.getBrokerId(), e);
       _serverMetrics.addMeteredGlobalValue(ServerMeter.RESPONSE_SERIALIZATION_EXCEPTIONS, 1);
       responseObserver.onError(Status.INTERNAL.withCause(e).asException());
-      _serverMetrics.addTimedValue(ServerTimer.GRPC_FAILED_QUERY_EXECUTION_MS, System.nanoTime() - startTime,
-          TimeUnit.NANOSECONDS);
       return;
     }
     responseObserver.onNext(serverResponse);
     _serverMetrics.addMeteredGlobalValue(ServerMeter.GRPC_BYTES_SENT, serverResponse.getSerializedSize());
     responseObserver.onCompleted();
-    _serverMetrics.addTimedValue(ServerTimer.GRPC_QUERY_EXECUTION_MS, System.nanoTime() - startTime,
-        TimeUnit.NANOSECONDS);
+    _serverMetrics.addTimedTableValue(queryRequest.getTableNameWithType(), ServerTimer.GRPC_QUERY_EXECUTION_MS,
+        System.nanoTime() - startTime, TimeUnit.NANOSECONDS);
 
     // Log the query
     if (_queryLogger != null) {