Log memory allocated per command in httpd_log

Add the following field to httpd log records:
- memory allocated during request execution

If this metric is not available in a JVM implementation, the metric is
set to -1.

Change-Id: Ie0ce1382a8515e6dfb7d0d3fe10b3e64c0cf9aee

5 files changed, 19 insertions, 0 deletions

diff --git a/Documentation/logs.txt b/Documentation/logs.txt
index 1eae8d825f..ba370b1563 100644
--- a/Documentation/logs.txt
+++ b/Documentation/logs.txt
@@ -54,6 +54,8 @@ if a log field is not present, a "-" is substituted:
 * `total_cpu`: total CPU time, CPU time in milliseconds to execute command.
 * `user_cpu`: user mode CPU time, CPU time in user mode in milliseconds to execute command.
   CPU time in kernel mode is `total_cpu - user_cpu`.
+* `memory`: memory allocated in bytes to execute command. -1 if the JVM does
+  not support this metric.
 
 Example:
 ```
diff --git a/java/com/google/gerrit/httpd/RequestMetricsFilter.java b/java/com/google/gerrit/httpd/RequestMetricsFilter.java
index 838a3d0f2c..c97b9ad3c0 100644
--- a/java/com/google/gerrit/httpd/RequestMetricsFilter.java
+++ b/java/com/google/gerrit/httpd/RequestMetricsFilter.java
@@ -47,10 +47,12 @@ public class RequestMetricsFilter implements Filter {
     private static final ThreadMXBeanInterface threadMxBean = ThreadMXBeanFactory.create();
     private final long startedTotalCpu;
     private final long startedUserCpu;
+    private final long startedMemory;
 
     Context() {
       startedTotalCpu = threadMxBean.getCurrentThreadCpuTime();
       startedUserCpu = threadMxBean.getCurrentThreadUserTime();
+      startedMemory = threadMxBean.getCurrentThreadAllocatedBytes();
     }
 
     /** @return total CPU time in milliseconds for executing request */
@@ -62,6 +64,13 @@ public class RequestMetricsFilter implements Filter {
     public long getUserCpuTime() {
       return (threadMxBean.getCurrentThreadUserTime() - startedUserCpu) / 1_000_000;
     }
+
+    /** @return memory allocated in bytes for executing request */
+    public long getAllocatedMemory() {
+      return startedMemory == -1
+          ? -1
+          : threadMxBean.getCurrentThreadAllocatedBytes() - startedMemory;
+    }
   }
 
   private final RequestMetrics metrics;
diff --git a/java/com/google/gerrit/pgm/http/jetty/HttpLog.java b/java/com/google/gerrit/pgm/http/jetty/HttpLog.java
index b1c3114308..235311602b 100644
--- a/java/com/google/gerrit/pgm/http/jetty/HttpLog.java
+++ b/java/com/google/gerrit/pgm/http/jetty/HttpLog.java
@@ -54,6 +54,7 @@ class HttpLog extends AbstractLifeCycle implements RequestLog {
   protected static final String P_USER_AGENT = "User-Agent";
   protected static final String P_CPU_TOTAL = "Cpu-Total";
   protected static final String P_CPU_USER = "Cpu-User";
+  protected static final String P_MEMORY = "Memory";
 
   private final AsyncAppender async;
 
@@ -121,6 +122,7 @@ class HttpLog extends AbstractLifeCycle implements RequestLog {
         (RequestMetricsFilter.Context) req.getAttribute(RequestMetricsFilter.METRICS_CONTEXT);
     set(event, P_CPU_TOTAL, ctx.getTotalCpuTime());
     set(event, P_CPU_USER, ctx.getUserCpuTime());
+    set(event, P_MEMORY, ctx.getAllocatedMemory());
 
     async.append(event);
   }
diff --git a/java/com/google/gerrit/pgm/http/jetty/HttpLogJsonLayout.java b/java/com/google/gerrit/pgm/http/jetty/HttpLogJsonLayout.java
index e4104f7c7c..5f4ec43e76 100644
--- a/java/com/google/gerrit/pgm/http/jetty/HttpLogJsonLayout.java
+++ b/java/com/google/gerrit/pgm/http/jetty/HttpLogJsonLayout.java
@@ -19,6 +19,7 @@ import static com.google.gerrit.pgm.http.jetty.HttpLog.P_CPU_TOTAL;
 import static com.google.gerrit.pgm.http.jetty.HttpLog.P_CPU_USER;
 import static com.google.gerrit.pgm.http.jetty.HttpLog.P_HOST;
 import static com.google.gerrit.pgm.http.jetty.HttpLog.P_LATENCY;
+import static com.google.gerrit.pgm.http.jetty.HttpLog.P_MEMORY;
 import static com.google.gerrit.pgm.http.jetty.HttpLog.P_METHOD;
 import static com.google.gerrit.pgm.http.jetty.HttpLog.P_PROTOCOL;
 import static com.google.gerrit.pgm.http.jetty.HttpLog.P_REFERER;
@@ -52,6 +53,7 @@ public class HttpLogJsonLayout extends JsonLayout {
     public String latency;
     public String cpuTotal;
     public String cpuUser;
+    public String memory;
     public String referer;
     public String userAgent;
 
@@ -68,6 +70,7 @@ public class HttpLogJsonLayout extends JsonLayout {
       this.latency = getMdcString(event, P_LATENCY);
       this.cpuTotal = getMdcString(event, P_CPU_TOTAL);
       this.cpuUser = getMdcString(event, P_CPU_USER);
+      this.memory = getMdcString(event, P_MEMORY);
       this.referer = getMdcString(event, P_REFERER);
       this.userAgent = getMdcString(event, P_USER_AGENT);
     }
diff --git a/java/com/google/gerrit/pgm/http/jetty/HttpLogLayout.java b/java/com/google/gerrit/pgm/http/jetty/HttpLogLayout.java
index 691752df6f..e9e6866360 100644
--- a/java/com/google/gerrit/pgm/http/jetty/HttpLogLayout.java
+++ b/java/com/google/gerrit/pgm/http/jetty/HttpLogLayout.java
@@ -77,6 +77,9 @@ public final class HttpLogLayout extends Layout {
     buf.append(' ');
     opt(buf, event, HttpLog.P_CPU_USER);
 
+    buf.append(' ');
+    opt(buf, event, HttpLog.P_MEMORY);
+
     buf.append('\n');
     return buf.toString();
   }