commit 78f204cd4841ec65285f1930dec3bb5518de5b08
author Matthias Sohn <matthias.sohn@sap.com> Thu Mar 25 14:02:13 2021 +0100
committer Matthias Sohn <matthias.sohn@sap.com> Fri Apr 09 18:37:31 2021 +0200
tree 579b07828a9047fd9538732939f8faf663b2b2a2
parent 5c48b6695d20c064dd58840332286e1cbb5e3a05

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

Documentation/logs.txt

diff --git a/Documentation/logs.txt b/Documentation/logs.txt
index 1eae8d8..ba370b1 100644
--- a/Documentation/logs.txt
+++ b/Documentation/logs.txt
@@ -54,6 +54,8 @@
 * `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:
 ```

java/com/google/gerrit/httpd/RequestMetricsFilter.java

diff --git a/java/com/google/gerrit/httpd/RequestMetricsFilter.java b/java/com/google/gerrit/httpd/RequestMetricsFilter.java
index 838a3d0..c97b9ad 100644
--- a/java/com/google/gerrit/httpd/RequestMetricsFilter.java
+++ b/java/com/google/gerrit/httpd/RequestMetricsFilter.java
@@ -47,10 +47,12 @@
     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 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;

java/com/google/gerrit/pgm/http/jetty/HttpLog.java

diff --git a/java/com/google/gerrit/pgm/http/jetty/HttpLog.java b/java/com/google/gerrit/pgm/http/jetty/HttpLog.java
index b1c3114..2353116 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 @@
   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 @@
         (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);
   }

java/com/google/gerrit/pgm/http/jetty/HttpLogJsonLayout.java

diff --git a/java/com/google/gerrit/pgm/http/jetty/HttpLogJsonLayout.java b/java/com/google/gerrit/pgm/http/jetty/HttpLogJsonLayout.java
index e4104f7..5f4ec43 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_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 String latency;
     public String cpuTotal;
     public String cpuUser;
+    public String memory;
     public String referer;
     public String userAgent;
 
@@ -68,6 +70,7 @@
       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);
     }

java/com/google/gerrit/pgm/http/jetty/HttpLogLayout.java

diff --git a/java/com/google/gerrit/pgm/http/jetty/HttpLogLayout.java b/java/com/google/gerrit/pgm/http/jetty/HttpLogLayout.java
index 691752d..e9e6866 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 @@
     buf.append(' ');
     opt(buf, event, HttpLog.P_CPU_USER);
 
+    buf.append(' ');
+    opt(buf, event, HttpLog.P_MEMORY);
+
     buf.append('\n');
     return buf.toString();
   }