#621 - add the logging of requestId (port to 2.35.*)

daniel-rusnak · daniel-rusnak · commit 9705937292f1 · 2021-06-20T22:56:10.000+02:00
Added 'RequestIdInterceptor' on the apache http client to generate 'requestId' for the client requests. It wasn't added to Spring 'RestTemplate' because the Sardine client doesn't use it.

Added 'ResponseMissingRequestIdInterceptor' on the apache http client to add missing 'X-GDC-REQUEST' header in responses coming from WebDav server.

Added the 'requestId' information to exceptions to easier tracking the problem.
diff --git a/src/main/java/com/gooddata/GoodData.java b/src/main/java/com/gooddata/GoodData.java
@@ -288,6 +288,8 @@ private HttpClientBuilder createHttpClientBuilder(final GoodDataSettings setting
 
         return HttpClientBuilder.create()
                 .setUserAgent(StringUtils.isNotBlank(settings.getUserAgent()) ? String.format("%s %s", settings.getUserAgent(), getUserAgent()) : getUserAgent())
+                .addInterceptorFirst(new RequestIdInterceptor())
+                .addInterceptorFirst(new ResponseMissingRequestIdInterceptor())
                 .setConnectionManager(connectionManager)
                 .setDefaultRequestConfig(requestConfig.build());
     }
diff --git a/src/main/java/com/gooddata/RequestIdInterceptor.java b/src/main/java/com/gooddata/RequestIdInterceptor.java
@@ -0,0 +1,39 @@
+/*
+ * Copyright (C) 2004-2021, GoodData(R) Corporation. All rights reserved.
+ * This source code is licensed under the BSD-style license found in the
+ * LICENSE.txt file in the root directory of this source tree.
+ */
+package com.gooddata;
+
+import org.apache.commons.lang3.RandomStringUtils;
+import org.apache.http.Header;
+import org.apache.http.HttpException;
+import org.apache.http.HttpRequest;
+import org.apache.http.HttpRequestInterceptor;
+import org.apache.http.annotation.Contract;
+import org.apache.http.annotation.ThreadingBehavior;
+import org.apache.http.protocol.HttpContext;
+
+import java.io.IOException;
+
+import static com.gooddata.gdc.Header.GDC_REQUEST_ID;
+
+/**
+ * Intercepts the client-side requests on low-level in order to be able to catch requests also from the Sardine,
+ * that is working independently from Spring {@link org.springframework.web.client.RestTemplate} to set
+ * the X-GDC-REQUEST header to them.
+ */
+@Contract(threading = ThreadingBehavior.IMMUTABLE)
+public class RequestIdInterceptor implements HttpRequestInterceptor {
+
+    @Override
+    public void process(final HttpRequest request, final HttpContext context) throws HttpException, IOException {
+        final StringBuilder requestIdBuilder = new StringBuilder();
+        final Header requestIdHeader = request.getFirstHeader(GDC_REQUEST_ID);
+        if (requestIdHeader != null) {
+            requestIdBuilder.append(requestIdHeader.getValue()).append(":");
+        }
+        final String requestId = requestIdBuilder.append(RandomStringUtils.randomAlphanumeric(16)).toString();
+        request.setHeader(GDC_REQUEST_ID, requestId);
+    }
+}
diff --git a/src/main/java/com/gooddata/ResponseMissingRequestIdInterceptor.java b/src/main/java/com/gooddata/ResponseMissingRequestIdInterceptor.java
@@ -0,0 +1,38 @@
+/*
+ * Copyright (C) 2004-2021, GoodData(R) Corporation. All rights reserved.
+ * This source code is licensed under the BSD-style license found in the
+ * LICENSE.txt file in the root directory of this source tree.
+ */
+package com.gooddata;
+
+import org.apache.http.Header;
+import org.apache.http.HttpException;
+import org.apache.http.HttpResponse;
+import org.apache.http.HttpResponseInterceptor;
+import org.apache.http.annotation.Contract;
+import org.apache.http.annotation.ThreadingBehavior;
+import org.apache.http.protocol.HttpContext;
+import org.apache.http.protocol.HttpCoreContext;
+
+import java.io.IOException;
+
+import static com.gooddata.gdc.Header.GDC_REQUEST_ID;
+
+
+/**
+ * Intercepts responses to check if they have set the X-GDC-REQUEST header for easier debugging.
+ * If not, it takes this header from the request sent.
+ */
+@Contract(threading = ThreadingBehavior.IMMUTABLE)
+public class ResponseMissingRequestIdInterceptor implements HttpResponseInterceptor {
+
+    @Override
+    public void process(final HttpResponse response, final HttpContext context) throws HttpException, IOException {
+
+        if (response.getFirstHeader(GDC_REQUEST_ID) == null) {
+            final HttpCoreContext coreContext = HttpCoreContext.adapt(context);
+            final Header requestIdHeader = coreContext.getRequest().getFirstHeader(GDC_REQUEST_ID);
+            response.setHeader(GDC_REQUEST_ID, requestIdHeader.getValue());
+        }
+    }
+}
diff --git a/src/main/java/com/gooddata/gdc/DataStoreService.java b/src/main/java/com/gooddata/gdc/DataStoreService.java
@@ -5,8 +5,8 @@
  */
 package com.gooddata.gdc;
 
-import com.github.sardine.Sardine;
 import com.github.sardine.impl.SardineException;
+import com.gooddata.GoodDataRestException;
 import com.gooddata.UriPrefixer;
 import org.apache.http.Header;
 import org.apache.http.HeaderIterator;
@@ -24,19 +24,23 @@
 import org.apache.http.client.methods.CloseableHttpResponse;
 import org.apache.http.client.methods.HttpUriRequest;
 import org.apache.http.conn.ClientConnectionManager;
+import org.apache.http.entity.InputStreamEntity;
 import org.apache.http.impl.client.CloseableHttpClient;
 import org.apache.http.impl.client.HttpClientBuilder;
+import org.apache.http.message.BasicHeader;
 import org.apache.http.params.HttpParams;
+import org.apache.http.protocol.HTTP;
 import org.apache.http.protocol.HttpContext;
 import org.springframework.http.HttpMethod;
 import org.springframework.http.HttpStatus;
 import org.springframework.http.ResponseEntity;
-import org.springframework.web.client.RestClientException;
 import org.springframework.web.client.RestTemplate;
 
 import java.io.IOException;
 import java.io.InputStream;
 import java.net.URI;
+import java.util.Collections;
+import java.util.List;
 import java.util.Locale;
 
 import static com.gooddata.util.Validate.notEmpty;
@@ -47,7 +51,7 @@
  */
 public class DataStoreService {
 
-    private final Sardine sardine;
+    private final GdcSardine sardine;
     private final GdcService gdcService;
     private final URI gdcUri;
     private final RestTemplate restTemplate;
@@ -102,7 +106,10 @@ public void upload(String path, InputStream stream) {
 
     private void upload(URI url, InputStream stream) {
         try {
-            sardine.put(url.toString(), stream);
+            // We need to use it this way, if we want to track request_id in the stacktrace.
+            InputStreamEntity entity = new InputStreamEntity(stream);
+            List<Header> headers = Collections.singletonList(new BasicHeader(HTTP.EXPECT_DIRECTIVE, HTTP.EXPECT_CONTINUE));
+            sardine.put(url.toString(), entity, headers, new GdcSardineResponseHandler());
         } catch (SardineException e) {
             if (HttpStatus.INTERNAL_SERVER_ERROR.value() == e.getStatusCode()) {
                 // this error may occur when user issues request to WebDAV before SST and TT were obtained
@@ -144,7 +151,7 @@ public InputStream download(String path) {
         notEmpty(path, "path");
         final URI uri = getUri(path);
         try {
-            return sardine.get(uri.toString());
+            return sardine.get(uri.toString(), Collections.emptyList(), new GdcSardineResponseHandler());
         } catch (IOException e) {
             throw new DataStoreException("Unable to download from " + uri, e);
         }
@@ -165,7 +172,7 @@ public void delete(String path) {
             if (HttpStatus.MOVED_PERMANENTLY.equals(result.getStatusCode())) {
                 restTemplate.exchange(result.getHeaders().getLocation(), HttpMethod.DELETE, org.springframework.http.HttpEntity.EMPTY, Void.class);
             }
-        } catch (RestClientException e) {
+        } catch (GoodDataRestException e) {
             throw new DataStoreException("Unable to delete " + uri, e);
         }
     }
diff --git a/src/main/java/com/gooddata/gdc/GdcSardine.java b/src/main/java/com/gooddata/gdc/GdcSardine.java
@@ -8,11 +8,18 @@
 import static com.gooddata.util.Validate.notNull;
 
 import com.github.sardine.impl.SardineImpl;
+import com.github.sardine.impl.io.ContentLengthInputStream;
+import com.github.sardine.impl.io.HttpMethodReleaseInputStream;
+import org.apache.http.Header;
+import org.apache.http.HttpResponse;
 import org.apache.http.client.ResponseHandler;
+import org.apache.http.client.methods.HttpGet;
 import org.apache.http.client.methods.HttpRequestBase;
 import org.apache.http.impl.client.HttpClientBuilder;
 
 import java.io.IOException;
+import java.util.List;
+import java.util.Map;
 
 /**
  * This class extends SardineImpl, connections were not correctly closed by parent
@@ -28,11 +35,41 @@ public GdcSardine(HttpClientBuilder builder) {
      */
     @Override
     protected <T> T execute(HttpRequestBase request, ResponseHandler<T> responseHandler) throws IOException {
-        notNull(request,"request");
+        notNull(request, "request");
         try {
             return super.execute(request, responseHandler);
         } finally {
             request.releaseConnection();
         }
     }
+
+    /**
+     * The method body is retrieved from {@link SardineImpl#get(String, Map)} and extended about the response handler
+     * to be able to handle responses arbitrarily.
+     *
+     * @param url             Path to the resource including protocol and hostname
+     * @param headers         Additional HTTP headers to add to the request
+     * @param responseHandler Arbitrary response handler to manipulate with responses
+     * @return Data stream to read from
+     * @throws IOException I/O error or HTTP response validation failure
+     */
+    public <T> ContentLengthInputStream get(final String url, final List<Header> headers, final
+    ResponseHandler<T> responseHandler) throws IOException {
+
+        final HttpGet get = new HttpGet(url);
+        for (Header header : headers) {
+            get.addHeader(header);
+        }
+        // Must use #execute without handler, otherwise the entity is consumed
+        // already after the handler exits.
+        final HttpResponse response = this.execute(get);
+        try {
+            responseHandler.handleResponse(response);
+            // Will abort the read when closed before EOF.
+            return new ContentLengthInputStream(new HttpMethodReleaseInputStream(response), response.getEntity().getContentLength());
+        } catch (IOException ex) {
+            get.abort();
+            throw ex;
+        }
+    }
 }
diff --git a/src/main/java/com/gooddata/gdc/GdcSardineException.java b/src/main/java/com/gooddata/gdc/GdcSardineException.java
@@ -0,0 +1,33 @@
+/*
+ * Copyright (C) 2007-2021, GoodData(R) Corporation. All rights reserved.
+ */
+package com.gooddata.gdc;
+
+import com.github.sardine.impl.SardineException;
+
+/**
+ * Extended Sardine exception about X-GDC-REQUEST header value.
+ */
+public class GdcSardineException extends SardineException {
+
+    private final String requestId;
+
+    /**
+     * @param msg            Custom description of failure
+     * @param statusCode     Error code returned by server
+     * @param responsePhrase Response phrase following the error code
+     * @param requestId      The X-GDC-REQUEST identifier.
+     */
+    public GdcSardineException(String requestId, String msg, int statusCode, String responsePhrase) {
+        super(msg, statusCode, responsePhrase);
+        this.requestId = requestId;
+    }
+
+    @Override
+    public String getMessage() {
+        return String.format("[request_id=%s]: %s (%d %s)", this.requestId, super.getMessage(), this.getStatusCode(),
+                this.getResponsePhrase()
+        );
+    }
+
+}
diff --git a/src/main/java/com/gooddata/gdc/GdcSardineResponseHandler.java b/src/main/java/com/gooddata/gdc/GdcSardineResponseHandler.java
@@ -0,0 +1,42 @@
+/*
+ * Copyright (C) 2004-2021, GoodData(R) Corporation. All rights reserved.
+ * This source code is licensed under the BSD-style license found in the
+ * LICENSE.txt file in the root directory of this source tree.
+ */
+package com.gooddata.gdc;
+
+import com.github.sardine.impl.SardineException;
+import org.apache.http.Header;
+import org.apache.http.HttpResponse;
+import org.apache.http.HttpStatus;
+import org.apache.http.StatusLine;
+import org.apache.http.client.ResponseHandler;
+
+import java.io.IOException;
+
+import static com.gooddata.gdc.Header.GDC_REQUEST_ID;
+
+
+/**
+ * A basic validation response handler that extends the functionality of {@link com.github.sardine.impl.handler.ValidatingResponseHandler}
+ * about the addition of X-GDC-REQUEST header to exception.
+ */
+class GdcSardineResponseHandler implements ResponseHandler<Void> {
+
+    @Override
+    public Void handleResponse(final HttpResponse response) throws IOException {
+        final StatusLine statusLine = response.getStatusLine();
+        final int statusCode = statusLine.getStatusCode();
+        if (statusCode >= HttpStatus.SC_OK && statusCode < HttpStatus.SC_MULTIPLE_CHOICES) {
+            return null;
+        }
+        final Header requestIdHeader = response.getFirstHeader(GDC_REQUEST_ID);
+        if (requestIdHeader != null) {
+            throw new GdcSardineException(requestIdHeader.getValue(), "Unexpected response", statusLine.getStatusCode(),
+                    statusLine.getReasonPhrase()
+            );
+        } else {
+            throw new SardineException("Unexpected response", statusLine.getStatusCode(), statusLine.getReasonPhrase());
+        }
+    }
+}
diff --git a/src/test/java/com/gooddata/gdc/DatastoreServiceAT.java b/src/test/java/com/gooddata/gdc/DatastoreServiceAT.java
@@ -18,10 +18,11 @@
 import java.util.UUID;
 
 import static com.gooddata.util.ResourceUtils.readFromResource;
-import static org.hamcrest.CoreMatchers.equalTo;
+import static org.hamcrest.CoreMatchers.containsString;
+import static org.hamcrest.CoreMatchers.instanceOf;
 import static org.hamcrest.CoreMatchers.is;
+import static org.hamcrest.CoreMatchers.equalTo;
 import static org.hamcrest.MatcherAssert.assertThat;
-import static org.testng.Assert.assertEquals;
 import static org.testng.Assert.fail;
 
 /**
@@ -60,6 +61,17 @@ public void datastoreDownload() throws Exception {
     }
 
     @Test(groups = "datastore", dependsOnMethods = "datastoreDownload")
+    public void verifyRequestIdInException() throws Exception {
+        DataStoreService dataStoreService = AbstractGoodDataAT.gd.getDataStoreService();
+
+        try (InputStream ignored = dataStoreService.download(this.directory + "/none.txt")) {
+            fail("The exception should contain the request_id in its stacktrace.");
+        } catch (Exception e){
+            assertThat(e.getCause().toString(), containsString("request_id"));
+        }
+    }
+
+    @Test(groups = "datastore", dependsOnMethods = "verifyRequestIdInException")
     public void datastoreDelete() throws Exception {
         DataStoreService dataStoreService = gd.getDataStoreService();
         dataStoreService.delete(this.file);
@@ -68,8 +80,10 @@ public void datastoreDelete() throws Exception {
         try {
             dataStoreService.delete(this.directory);
             fail("Exception was expected, as there is nothing to delete");
-        } catch (GoodDataRestException e) {
-            assertEquals(404, e.getStatusCode());
+        } catch (DataStoreException e) {
+            assertThat(e.getCause().toString(), containsString("request_id"));
+            assertThat(e.getCause().toString(), containsString("404"));
+            assertThat(e.getCause(), instanceOf(GoodDataRestException.class));
         }
     }
 

Original file line number	Diff line number	Diff line change
`@@ -288,6 +288,8 @@ private HttpClientBuilder createHttpClientBuilder(final GoodDataSettings setting`
`288`	`288`
`289`	`289`	`return HttpClientBuilder.create()`
`290`	`290`	`.setUserAgent(StringUtils.isNotBlank(settings.getUserAgent()) ? String.format("%s %s", settings.getUserAgent(), getUserAgent()) : getUserAgent())`
	`291`	`+ .addInterceptorFirst(new RequestIdInterceptor())`
	`292`	`+ .addInterceptorFirst(new ResponseMissingRequestIdInterceptor())`
`291`	`293`	`.setConnectionManager(connectionManager)`
`292`	`294`	`.setDefaultRequestConfig(requestConfig.build());`
`293`	`295`	`}`