Log the result of git-upload-pack command in httpd_log

When executing a git-upload-pack over HTTP the http_log will log a
200 OK as long as the transfer to the client has started successfully.

This information however is incomplete, since there is no trace in the
http_log of the final result of the command itself.

The transfer might be abruptly interrupted by the client or by the
server and ultimately the git-upload-pack command might fail.

This behaviour is already reflected in the sshd_log, however the
httpd_log is just not reporting this information at all, making it
virtually impossible to understand whether a git-upload-pack ultimately
succeeded or failed.

Extend the httpd_log layout by adding an additional 'commandStatus'
field to report the ultimate status of the git-upload-pack command.

0  indicates success
-1 indicates failure

Bug: Issue 14930
Change-Id: Ic6520c1fc44ef51de8bb5d33e307e60ece630163

5 files changed, 71 insertions, 0 deletions

diff --git a/Documentation/logs.txt b/Documentation/logs.txt
index 43a8e62dd7..a95956c86e 100644
--- a/Documentation/logs.txt
+++ b/Documentation/logs.txt
@@ -48,6 +48,11 @@ if a log field is not present, a "-" is substituted:
 * `referer`: the `Referer` HTTP request header. This gives the site that
   the client reports having been referred from.
 * `client agent`: the client agent which sent the request.
+* `command status`: the overall result of the git command over HTTP. Currently
+   populated only for the transfer phase of `git-upload-pack` commands.
+   Possible values:
+** `-1`: The `git-upload-pack` transfer was ultimately not successful
+** `0`: The `git-upload-pack` transfer was ultimately successful
 
 Example:
 ```
diff --git a/java/com/google/gerrit/httpd/GitOverHttpServlet.java b/java/com/google/gerrit/httpd/GitOverHttpServlet.java
index 6e22704534..3e2d3efb07 100644
--- a/java/com/google/gerrit/httpd/GitOverHttpServlet.java
+++ b/java/com/google/gerrit/httpd/GitOverHttpServlet.java
@@ -14,11 +14,15 @@
 
 package com.google.gerrit.httpd;
 
+import static javax.servlet.http.HttpServletResponse.SC_INTERNAL_SERVER_ERROR;
+import static org.eclipse.jgit.http.server.GitSmartHttpTools.sendError;
+
 import com.google.common.annotations.VisibleForTesting;
 import com.google.common.cache.Cache;
 import com.google.common.collect.ImmutableListMultimap;
 import com.google.common.collect.ListMultimap;
 import com.google.common.collect.Lists;
+import com.google.common.flogger.FluentLogger;
 import com.google.gerrit.common.data.Capable;
 import com.google.gerrit.entities.Project;
 import com.google.gerrit.extensions.registration.DynamicSet;
@@ -54,6 +58,7 @@ import com.google.inject.Singleton;
 import com.google.inject.TypeLiteral;
 import com.google.inject.name.Named;
 import java.io.IOException;
+import java.text.MessageFormat;
 import java.time.Duration;
 import java.util.Arrays;
 import java.util.Collections;
@@ -70,10 +75,13 @@ import javax.servlet.ServletResponse;
 import javax.servlet.http.HttpServletRequest;
 import javax.servlet.http.HttpServletResponse;
 import javax.servlet.http.HttpServletResponseWrapper;
+import org.eclipse.jgit.errors.PackProtocolException;
 import org.eclipse.jgit.errors.RepositoryNotFoundException;
 import org.eclipse.jgit.http.server.GitServlet;
 import org.eclipse.jgit.http.server.GitSmartHttpTools;
+import org.eclipse.jgit.http.server.HttpServerText;
 import org.eclipse.jgit.http.server.ServletUtils;
+import org.eclipse.jgit.http.server.UploadPackErrorHandler;
 import org.eclipse.jgit.http.server.resolver.AsIsFileService;
 import org.eclipse.jgit.lib.ObjectId;
 import org.eclipse.jgit.lib.Repository;
@@ -100,6 +108,23 @@ public class GitOverHttpServlet extends GitServlet {
   private static final String ID_CACHE = "adv_bases";
 
   public static final String URL_REGEX;
+  public static final String GIT_COMMAND_STATUS_HEADER = "X-git-command-status";
+
+  private enum GIT_COMMAND_STATUS {
+    OK(0),
+    FAIL(-1);
+
+    private final int exitStatus;
+
+    GIT_COMMAND_STATUS(int exitStatus) {
+      this.exitStatus = exitStatus;
+    }
+
+    @Override
+    public String toString() {
+      return Integer.toString(exitStatus);
+    }
+  }
 
   static {
     StringBuilder url = new StringBuilder();
@@ -212,12 +237,14 @@ public class GitOverHttpServlet extends GitServlet {
       Resolver resolver,
       UploadFactory upload,
       UploadFilter uploadFilter,
+      GerritUploadPackErrorHandler uploadPackErrorHandler,
       ReceivePackFactory<HttpServletRequest> receive,
       ReceiveFilter receiveFilter) {
     setRepositoryResolver(resolver);
     setAsIsFileService(AsIsFileService.DISABLED);
 
     setUploadPackFactory(upload);
+    setUploadPackErrorHandler(uploadPackErrorHandler);
     addUploadPackFilter(uploadFilter);
 
     setReceivePackFactory(receive);
@@ -456,6 +483,35 @@ public class GitOverHttpServlet extends GitServlet {
     public void destroy() {}
   }
 
+  static class GerritUploadPackErrorHandler implements UploadPackErrorHandler {
+    private static final FluentLogger logger = FluentLogger.forEnclosingClass();
+
+    @Override
+    public void upload(HttpServletRequest req, HttpServletResponse rsp, UploadPackRunnable r)
+        throws IOException {
+      rsp.setHeader(GIT_COMMAND_STATUS_HEADER, GIT_COMMAND_STATUS.FAIL.toString());
+      try {
+        r.upload();
+        rsp.setHeader(GIT_COMMAND_STATUS_HEADER, GIT_COMMAND_STATUS.OK.toString());
+      } catch (ServiceMayNotContinueException e) {
+        if (!e.isOutput() && !rsp.isCommitted()) {
+          rsp.reset();
+          sendError(req, rsp, e.getStatusCode(), e.getMessage());
+        }
+      } catch (Throwable e) {
+        logger.atSevere().withCause(e).log(
+            MessageFormat.format(
+                HttpServerText.get().internalErrorDuringUploadPack,
+                ServletUtils.getRepository(req)));
+        if (!rsp.isCommitted()) {
+          rsp.reset();
+          String msg = e instanceof PackProtocolException ? e.getMessage() : null;
+          sendError(req, rsp, SC_INTERNAL_SERVER_ERROR, msg);
+        }
+      }
+    }
+  }
+
   static class ReceiveFactory implements ReceivePackFactory<HttpServletRequest> {
     private final AsyncReceiveCommits.Factory factory;
     private final Provider<CurrentUser> userProvider;
diff --git a/java/com/google/gerrit/pgm/http/jetty/HttpLog.java b/java/com/google/gerrit/pgm/http/jetty/HttpLog.java
index 4e4c93b57b..27a53c2052 100644
--- a/java/com/google/gerrit/pgm/http/jetty/HttpLog.java
+++ b/java/com/google/gerrit/pgm/http/jetty/HttpLog.java
@@ -14,6 +14,8 @@
 
 package com.google.gerrit.pgm.http.jetty;
 
+import static com.google.gerrit.httpd.GitOverHttpServlet.GIT_COMMAND_STATUS_HEADER;
+
 import com.google.common.base.Strings;
 import com.google.gerrit.httpd.GetUserFilter;
 import com.google.gerrit.httpd.restapi.LogRedactUtil;
@@ -51,6 +53,7 @@ class HttpLog extends AbstractLifeCycle implements RequestLog {
   protected static final String P_LATENCY = "Latency";
   protected static final String P_REFERER = "Referer";
   protected static final String P_USER_AGENT = "User-Agent";
+  protected static final String P_COMMAND_STATUS = "Command-Status";
 
   private final AsyncAppender async;
 
@@ -113,6 +116,7 @@ class HttpLog extends AbstractLifeCycle implements RequestLog {
     set(event, P_LATENCY, System.currentTimeMillis() - req.getTimeStamp());
     set(event, P_REFERER, req.getHeader("Referer"));
     set(event, P_USER_AGENT, req.getHeader("User-Agent"));
+    set(event, P_COMMAND_STATUS, rsp.getHeader(GIT_COMMAND_STATUS_HEADER));
 
     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 95a5b07689..807b311745 100644
--- a/java/com/google/gerrit/pgm/http/jetty/HttpLogJsonLayout.java
+++ b/java/com/google/gerrit/pgm/http/jetty/HttpLogJsonLayout.java
@@ -14,6 +14,7 @@
 
 package com.google.gerrit.pgm.http.jetty;
 
+import static com.google.gerrit.pgm.http.jetty.HttpLog.P_COMMAND_STATUS;
 import static com.google.gerrit.pgm.http.jetty.HttpLog.P_CONTENT_LENGTH;
 import static com.google.gerrit.pgm.http.jetty.HttpLog.P_HOST;
 import static com.google.gerrit.pgm.http.jetty.HttpLog.P_LATENCY;
@@ -50,6 +51,7 @@ public class HttpLogJsonLayout extends JsonLayout {
     public String latency;
     public String referer;
     public String userAgent;
+    public String commandStatus;
 
     public HttpJsonLogEntry(LoggingEvent event) {
       this.host = getMdcString(event, P_HOST);
@@ -64,6 +66,7 @@ public class HttpLogJsonLayout extends JsonLayout {
       this.latency = getMdcString(event, P_LATENCY);
       this.referer = getMdcString(event, P_REFERER);
       this.userAgent = getMdcString(event, P_USER_AGENT);
+      this.commandStatus = getMdcString(event, P_COMMAND_STATUS);
     }
   }
 }
diff --git a/java/com/google/gerrit/pgm/http/jetty/HttpLogLayout.java b/java/com/google/gerrit/pgm/http/jetty/HttpLogLayout.java
index 268f59fdbe..b83fcc55b0 100644
--- a/java/com/google/gerrit/pgm/http/jetty/HttpLogLayout.java
+++ b/java/com/google/gerrit/pgm/http/jetty/HttpLogLayout.java
@@ -71,6 +71,9 @@ public final class HttpLogLayout extends Layout {
     buf.append(' ');
     dq_opt(buf, event, HttpLog.P_USER_AGENT);
 
+    buf.append(' ');
+    dq_opt(buf, event, HttpLog.P_COMMAND_STATUS);
+
     buf.append('\n');
     return buf.toString();
   }