HDDS-9718. Add performance audit logging for S3G

hadoop-hdds/framework/src/main/java/org/apache/hadoop/ozone/audit/AuditLogger.java

@@ -30,6 +30,7 @@
 import java.util.HashSet;
 import java.util.Locale;
 import java.util.Set;
+import java.util.concurrent.TimeUnit;
 import java.util.concurrent.atomic.AtomicReference;
 import java.util.stream.Collectors;
 
@@ -132,4 +133,75 @@ private boolean shouldLogAtDebug(AuditMessage auditMessage) {
     return debugCmdSetRef.get()
         .contains(auditMessage.getOp().toLowerCase(Locale.ROOT));
   }
+
+  /**
+   * Utility class for building performance log strings.
+   */
+  public static class PerformanceStringBuilder {
+    private final StringBuilder builder = new StringBuilder(128).append('{');
+    /**
+     * Appends metadata operation latency in milliseconds.
+     * @param nanos Latency in nanoseconds.
+     */
+    public void appendMetaLatencyNanos(long nanos) {
+      append("metaLatencyMs", TimeUnit.NANOSECONDS.toMillis(nanos));
+    }
+
+    /**
+     * Appends whole operation latency in milliseconds.
+     * @param nanos Latency in nanoseconds.
+     */
+    public void appendOpLatencyNanos(long nanos) {
+      append("opLatencyMs", TimeUnit.NANOSECONDS.toMillis(nanos));
+    }
+
+    /**
+     * Appends the size in bytes.
+     * @param bytes Size in bytes.
+     */
+    public void appendSizeBytes(long bytes) {
+      append("sizeByte", bytes);
+    }
+
+    /**
+     * Appends the count.
+     * @param count The count value to be appended.
+     */
+    public void appendCount(long count) {
+      append("count", count);
+    }
+
+    /**
+     * Appends a stream mode flag.
+     */
+    public void appendStreamMode() {
+      append("streamMode", "true");
+    }
+
+    private void append(String name, long value) {
+      append(name, String.valueOf(value));
+    }
+
+    /**
+     * Appends a name-value pair to the log string.
+     * @param name Name of the metric.
+     * @param value Value of the metric.
+     */
+    private void append(String name, String value) {
+      builder.append(name)
+          .append('=')
+          .append(value)
+          .append(", ");
+    }
+
+    public String build() {
+      final int length = builder.length();
+      if (length < 2) {
+        return "{}";
+      }
+      builder.setCharAt(length - 2, '}');
+      builder.setLength(length - 1);
+      return builder.toString();
+    }
+  }
 }

hadoop-hdds/framework/src/main/java/org/apache/hadoop/ozone/audit/AuditMessage.java

@@ -34,13 +34,14 @@ public final class AuditMessage implements Message {
   private final Throwable throwable;
 
   private AuditMessage(String user, String ip, String op,
-      Map<String, String> params, String ret, Throwable throwable) {
+      Map<String, String> params, String ret, Throwable throwable,
+      String performance) {
     this.user = user;
     this.ip = ip;
     this.op = op;
     this.params = params;
     this.ret = ret;
-    this.message = formMessage(user, ip, op, params, ret);
+    this.message = formMessage(user, ip, op, params, ret, performance);
     this.throwable = throwable;
   }
 
@@ -78,6 +79,7 @@ public static class Builder {
     private String op;
     private Map<String, String> params;
     private String ret;
+    private String performance;
 
     public Builder setUser(String usr) {
       this.user = usr;
@@ -109,15 +111,23 @@ public Builder withException(Throwable ex) {
       return this;
     }
 
+    public Builder setPerformance(String perf) {
+      this.performance = perf;
+      return this;
+    }
+
     public AuditMessage build() {
-      return new AuditMessage(user, ip, op, params, ret, throwable);
+      return new AuditMessage(user, ip, op, params, ret, throwable,
+          performance);
     }
   }
 
   private String formMessage(String userStr, String ipStr, String opStr,
-      Map<String, String> paramsMap, String retStr) {
+      Map<String, String> paramsMap, String retStr,
+      String performanceMap) {
+    String perf = performanceMap != null && !performanceMap.isEmpty()
+        ? " | perf=" + performanceMap : "";
     return "user=" + userStr + " | ip=" + ipStr + " | " + "op=" + opStr
-        + " " + paramsMap + " | " + "ret=" + retStr;
-
+        + " " + paramsMap + " | ret=" + retStr + perf;
   }
 }

hadoop-ozone/s3gateway/src/main/java/org/apache/hadoop/ozone/audit/S3GAction.java

@@ -36,6 +36,7 @@ public enum S3GAction implements AuditAction {
 
   //ObjectEndpoint
   CREATE_MULTIPART_KEY,
+  CREATE_MULTIPART_KEY_BY_COPY,
   COPY_OBJECT,
   CREATE_KEY,
   LIST_PARTS,

hadoop-ozone/s3gateway/src/main/java/org/apache/hadoop/ozone/s3/endpoint/BucketEndpoint.java

@@ -69,6 +69,7 @@
 import java.util.List;
 import java.util.Set;
 
+import static org.apache.hadoop.ozone.audit.AuditLogger.PerformanceStringBuilder;
 import static org.apache.hadoop.ozone.OzoneAcl.AclScope.ACCESS;
 import static org.apache.hadoop.ozone.OzoneConsts.OZONE_URI_DELIMITER;
 import static org.apache.hadoop.ozone.s3.S3GatewayConfigKeys.OZONE_S3G_LIST_KEYS_SHALLOW_ENABLED;
@@ -113,6 +114,8 @@ public Response get(
       @Context HttpHeaders hh) throws OS3Exception, IOException {
     long startNanos = Time.monotonicNowNanos();
     S3GAction s3GAction = S3GAction.GET_BUCKET;
+    PerformanceStringBuilder perf = new PerformanceStringBuilder();
+
     Iterator<? extends OzoneKey> ozoneKeyIterator;
     ContinueToken decodedToken =
         ContinueToken.decodeFromString(continueToken);
@@ -264,12 +267,15 @@ public Response get(
       response.setTruncated(false);
     }
 
-    AUDIT.logReadSuccess(buildAuditMessageForSuccess(s3GAction,
-        getAuditParameters()));
     int keyCount =
         response.getCommonPrefixes().size() + response.getContents().size();
-    getMetrics().updateGetBucketSuccessStats(startNanos);
+    long opLatencyNs =
+        getMetrics().updateGetBucketSuccessStats(startNanos);
     getMetrics().incListKeyCount(keyCount);
+    perf.appendCount(keyCount);
+    perf.appendOpLatencyNanos(opLatencyNs);
+    AUDIT.logReadSuccess(buildAuditMessageForSuccess(s3GAction,
+        getAuditParameters(), perf.build()));
     response.setKeyCount(keyCount);
     return Response.ok(response).build();
   }

hadoop-ozone/s3gateway/src/main/java/org/apache/hadoop/ozone/s3/endpoint/EndpointBase.java

@@ -353,6 +353,14 @@ public AuditMessage buildAuditMessageForSuccess(AuditAction op,
     return builder.build();
   }
 
+  public AuditMessage buildAuditMessageForSuccess(AuditAction op,
+      Map<String, String> auditMap, String performance) {
+    AuditMessage.Builder builder = auditMessageBaseBuilder(op, auditMap)
+        .withResult(AuditEventStatus.SUCCESS);
+    builder.setPerformance(performance);
+    return builder.build();
+  }
+
   @Override
   public AuditMessage buildAuditMessageForFailure(AuditAction op,
       Map<String, String> auditMap, Throwable throwable) {