feat(logging): unified request logging (graphql, openapi, restli) (#1…

…0802)

metadata-operation-context/build.gradle

@@ -7,6 +7,8 @@ dependencies {
   api project(':metadata-auth:auth-api')
 
   implementation externalDependency.slf4jApi
+  implementation externalDependency.servletApi
+  implementation spec.product.pegasus.restliServer
   compileOnly externalDependency.lombok
 
   annotationProcessor externalDependency.lombok

metadata-operation-context/src/main/java/io/datahubproject/metadata/context/RequestContext.java

@@ -1,5 +1,8 @@
 package io.datahubproject.metadata.context;
 
+import com.google.common.net.HttpHeaders;
+import com.linkedin.restli.server.ResourceContext;
+import jakarta.servlet.http.HttpServletRequest;
 import java.util.Arrays;
 import java.util.Collection;
 import java.util.List;
@@ -11,14 +14,18 @@
 import javax.annotation.Nullable;
 import lombok.Builder;
 import lombok.Getter;
+import lombok.extern.slf4j.Slf4j;
 
+@Slf4j
 @Getter
 @Builder
 public class RequestContext implements ContextInterface {
   @Nonnull
   public static final RequestContext TEST =
       RequestContext.builder().requestID("test").requestAPI(RequestAPI.TEST).build();
 
+  @Nonnull private final String actorUrn;
+  @Nonnull private final String sourceIP;
   @Nonnull private final RequestAPI requestAPI;
 
   /**
@@ -27,46 +34,100 @@ public class RequestContext implements ContextInterface {
    */
   @Nonnull private final String requestID;
 
+  @Nonnull private final String userAgent;
+
+  public RequestContext(
+      @Nonnull String actorUrn,
+      @Nonnull String sourceIP,
+      @Nonnull RequestAPI requestAPI,
+      @Nonnull String requestID,
+      @Nonnull String userAgent) {
+    this.actorUrn = actorUrn;
+    this.sourceIP = sourceIP;
+    this.requestAPI = requestAPI;
+    this.requestID = requestID;
+    this.userAgent = userAgent;
+    // Uniform common logging of requests across APIs
+    log.info(toString());
+  }
+
   @Override
   public Optional<Integer> getCacheKeyComponent() {
     return Optional.empty();
   }
 
   public static class RequestContextBuilder {
     private RequestContext build() {
-      return new RequestContext(this.requestAPI, this.requestID);
+      return new RequestContext(
+          this.actorUrn, this.sourceIP, this.requestAPI, this.requestID, this.userAgent);
     }
 
-    public RequestContext buildGraphql(@Nonnull String queryName, Map<String, Object> variables) {
+    public RequestContext buildGraphql(
+        @Nonnull String actorUrn,
+        @Nonnull HttpServletRequest request,
+        @Nonnull String queryName,
+        Map<String, Object> variables) {
+      actorUrn(actorUrn);
+      sourceIP(extractSourceIP(request));
       requestAPI(RequestAPI.GRAPHQL);
       requestID(buildRequestId(queryName, Set.of()));
+      userAgent(extractUserAgent(request));
       return build();
     }
 
-    public RequestContext buildRestli(String action, @Nullable String entityName) {
-      return buildRestli(action, entityName == null ? null : List.of(entityName));
+    public RequestContext buildRestli(
+        @Nonnull String actorUrn,
+        @Nullable ResourceContext resourceContext,
+        String action,
+        @Nullable String entityName) {
+      return buildRestli(
+          actorUrn, resourceContext, action, entityName == null ? null : List.of(entityName));
     }
 
-    public RequestContext buildRestli(@Nonnull String action, @Nullable String[] entityNames) {
+    public RequestContext buildRestli(
+        @Nonnull String actorUrn,
+        @Nullable ResourceContext resourceContext,
+        @Nonnull String action,
+        @Nullable String[] entityNames) {
       return buildRestli(
+          actorUrn,
+          resourceContext,
           action,
           entityNames == null ? null : Arrays.stream(entityNames).collect(Collectors.toList()));
     }
 
-    public RequestContext buildRestli(String action, @Nullable Collection<String> entityNames) {
+    public RequestContext buildRestli(
+        @Nonnull String actorUrn,
+        @Nullable ResourceContext resourceContext,
+        String action,
+        @Nullable Collection<String> entityNames) {
+      actorUrn(actorUrn);
+      sourceIP(resourceContext == null ? "" : extractSourceIP(resourceContext));
       requestAPI(RequestAPI.RESTLI);
       requestID(buildRequestId(action, entityNames));
+      userAgent(resourceContext == null ? "" : extractUserAgent(resourceContext));
       return build();
     }
 
-    public RequestContext buildOpenapi(@Nonnull String action, @Nullable String entityName) {
-      return buildOpenapi(action, entityName == null ? null : List.of(entityName));
+    public RequestContext buildOpenapi(
+        @Nonnull String actorUrn,
+        @Nonnull HttpServletRequest request,
+        @Nonnull String action,
+        @Nullable String entityName) {
+      return buildOpenapi(
+          actorUrn, request, action, entityName == null ? null : List.of(entityName));
     }
 
     public RequestContext buildOpenapi(
-        @Nonnull String action, @Nullable Collection<String> entityNames) {
+        @Nonnull String actorUrn,
+        @Nullable HttpServletRequest request,
+        @Nonnull String action,
+        @Nullable Collection<String> entityNames) {
+      actorUrn(actorUrn);
+      sourceIP(request == null ? "" : extractSourceIP(request));
       requestAPI(RequestAPI.OPENAPI);
       requestID(buildRequestId(action, entityNames));
+      userAgent(request == null ? "" : extractUserAgent(request));
       return build();
     }
 
@@ -77,6 +138,46 @@ private static String buildRequestId(
           : String.format(
               "%s(%s)", action, entityNames.stream().distinct().collect(Collectors.toList()));
     }
+
+    private static String extractUserAgent(@Nonnull HttpServletRequest request) {
+      return Optional.ofNullable(request.getHeader(HttpHeaders.USER_AGENT)).orElse("");
+    }
+
+    private static String extractUserAgent(@Nonnull ResourceContext resourceContext) {
+      return Optional.ofNullable(resourceContext.getRequestHeaders().get(HttpHeaders.USER_AGENT))
+          .orElse("");
+    }
+
+    private static String extractSourceIP(@Nonnull HttpServletRequest request) {
+      return Optional.ofNullable(request.getHeader(HttpHeaders.X_FORWARDED_FOR))
+          .orElse(request.getRemoteAddr());
+    }
+
+    private static String extractSourceIP(@Nonnull ResourceContext resourceContext) {
+      return Optional.ofNullable(
+              resourceContext.getRequestHeaders().get(HttpHeaders.X_FORWARDED_FOR))
+          .orElse(resourceContext.getRawRequestContext().getLocalAttr("REMOTE_ADDR").toString());
+    }
+  }
+
+  @Override
+  public String toString() {
+    return "RequestContext{"
+        + "actorUrn='"
+        + actorUrn
+        + '\''
+        + ", sourceIP='"
+        + sourceIP
+        + '\''
+        + ", requestAPI="
+        + requestAPI
+        + ", requestID='"
+        + requestID
+        + '\''
+        + ", userAgent='"
+        + userAgent
+        + '\''
+        + '}';
   }
 
   public enum RequestAPI {

metadata-service/graphql-servlet-impl/src/main/java/com/datahub/graphql/GraphQLController.java

@@ -59,7 +59,8 @@ public GraphQLController() {
   private static final int MAX_LOG_WIDTH = 512;
 
   @PostMapping(value = "/graphql", produces = "application/json;charset=utf-8")
-  CompletableFuture<ResponseEntity<String>> postGraphQL(HttpEntity<String> httpEntity) {
+  CompletableFuture<ResponseEntity<String>> postGraphQL(
+      HttpServletRequest request, HttpEntity<String> httpEntity) {
 
     String jsonStr = httpEntity.getBody();
     ObjectMapper mapper = new ObjectMapper();
@@ -117,13 +118,18 @@ CompletableFuture<ResponseEntity<String>> postGraphQL(HttpEntity<String> httpEnt
 
     SpringQueryContext context =
         new SpringQueryContext(
-            true, authentication, _authorizerChain, systemOperationContext, query, variables);
+            true,
+            authentication,
+            _authorizerChain,
+            systemOperationContext,
+            request,
+            operationName,
+            query,
+            variables);
     Span.current().setAttribute("actor.urn", context.getActorUrn());
 
-    // operationName is an optional field only required if multiple operations are present
-    final String queryName = operationName != null ? operationName : context.getQueryName();
     final String threadName = Thread.currentThread().getName();
-    log.info("Processing request, operation: {}, actor urn: {}", queryName, context.getActorUrn());
+    final String queryName = context.getQueryName();
     log.debug("Query: {}, variables: {}", query, variables);
 
     return GraphQLConcurrencyUtils.supplyAsync(

metadata-service/graphql-servlet-impl/src/main/java/com/datahub/graphql/SpringQueryContext.java

@@ -7,8 +7,10 @@
 import graphql.parser.Parser;
 import io.datahubproject.metadata.context.OperationContext;
 import io.datahubproject.metadata.context.RequestContext;
+import jakarta.servlet.http.HttpServletRequest;
 import java.util.Map;
 import javax.annotation.Nonnull;
+import javax.annotation.Nullable;
 import lombok.Getter;
 
 @Getter
@@ -25,26 +27,33 @@ public SpringQueryContext(
       final Authentication authentication,
       final Authorizer authorizer,
       @Nonnull final OperationContext systemOperationContext,
+      @Nonnull final HttpServletRequest request,
+      @Nullable final String operationName,
       String jsonQuery,
       Map<String, Object> variables) {
     this.isAuthenticated = isAuthenticated;
     this.authentication = authentication;
     this.authorizer = authorizer;
 
+    // operationName is an optional field only required if multiple operations are present
     this.queryName =
-        new Parser()
-            .parseDocument(jsonQuery).getDefinitions().stream()
-                .filter(def -> def instanceof OperationDefinition)
-                .map(def -> (OperationDefinition) def)
-                .filter(opDef -> opDef.getOperation().equals(OperationDefinition.Operation.QUERY))
-                .findFirst()
-                .map(OperationDefinition::getName)
-                .orElse("graphql");
+        operationName != null
+            ? operationName
+            : new Parser()
+                .parseDocument(jsonQuery).getDefinitions().stream()
+                    .filter(def -> def instanceof OperationDefinition)
+                    .map(def -> (OperationDefinition) def)
+                    .filter(
+                        opDef -> opDef.getOperation().equals(OperationDefinition.Operation.QUERY))
+                    .findFirst()
+                    .map(OperationDefinition::getName)
+                    .orElse("graphql");
 
     this.operationContext =
         OperationContext.asSession(
             systemOperationContext,
-            RequestContext.builder().buildGraphql(queryName, variables),
+            RequestContext.builder()
+                .buildGraphql(authentication.getActor().toUrnStr(), request, queryName, variables),
             authorizer,
             authentication,
             true);

metadata-service/openapi-analytics-servlet/build.gradle

@@ -19,7 +19,7 @@ dependencies {
     implementation externalDependency.springWebMVC
     implementation externalDependency.springBeans
     implementation externalDependency.springContext
-
+    implementation externalDependency.servletApi
     implementation externalDependency.reflections
     implementation externalDependency.slf4jApi
     compileOnly externalDependency.lombok

metadata-service/openapi-analytics-servlet/src/main/java/io/datahubproject/openapi/delegates/DatahubUsageEventsImpl.java

@@ -12,6 +12,7 @@
 import io.datahubproject.metadata.context.RequestContext;
 import io.datahubproject.openapi.exception.UnauthorizedException;
 import io.datahubproject.openapi.v2.generated.controller.DatahubUsageEventsApiDelegate;
+import jakarta.servlet.http.HttpServletRequest;
 import java.util.List;
 import java.util.Objects;
 import org.springframework.beans.factory.annotation.Autowired;
@@ -27,6 +28,8 @@ public class DatahubUsageEventsImpl implements DatahubUsageEventsApiDelegate {
   @Qualifier("systemOperationContext")
   OperationContext systemOperationContext;
 
+  @Autowired private HttpServletRequest request;
+
   public static final String DATAHUB_USAGE_INDEX = "datahub_usage_event";
 
   @Override
@@ -36,7 +39,8 @@ public ResponseEntity<String> raw(String body) {
     OperationContext opContext =
         OperationContext.asSession(
             systemOperationContext,
-            RequestContext.builder().buildOpenapi("raw", List.of()),
+            RequestContext.builder()
+                .buildOpenapi(authentication.getActor().toUrnStr(), request, "raw", List.of()),
             _authorizationChain,
             authentication,
             true);