Send network requests as spans (#776)

EmbraceNetworkLoggingService now records spans when it receives a request.
embrace-io · Apr 19, 2024 · 6c280d2 · 6c280d2
1 parent 7c4f708
commit 6c280d2
Show file tree

Hide file tree

Showing 4 changed files with 23 additions and 86 deletions.
diff --git a/embrace-android-sdk/api/embrace-android-sdk.api b/embrace-android-sdk/api/embrace-android-sdk.api
@@ -209,10 +209,10 @@ public abstract interface class io/embrace/android/embracesdk/internal/EmbraceIn
  public abstract fun logInternalError (Ljava/lang/String;Ljava/lang/String;)V
  public abstract fun logInternalError (Ljava/lang/Throwable;)V
  public abstract fun logWarning (Ljava/lang/String;Ljava/util/Map;Ljava/lang/String;)V
- public abstract fun recordAndDeduplicateNetworkRequest (Ljava/lang/String;Lio/embrace/android/embracesdk/network/EmbraceNetworkRequest;)V
  public abstract fun recordCompletedNetworkRequest (Ljava/lang/String;Ljava/lang/String;JJJJILjava/lang/String;Lio/embrace/android/embracesdk/internal/network/http/NetworkCaptureData;)V
  public abstract fun recordIncompleteNetworkRequest (Ljava/lang/String;Ljava/lang/String;JJLjava/lang/String;Ljava/lang/String;Ljava/lang/String;Lio/embrace/android/embracesdk/internal/network/http/NetworkCaptureData;)V
  public abstract fun recordIncompleteNetworkRequest (Ljava/lang/String;Ljava/lang/String;JJLjava/lang/Throwable;Ljava/lang/String;Lio/embrace/android/embracesdk/internal/network/http/NetworkCaptureData;)V
+ public abstract fun recordNetworkRequest (Lio/embrace/android/embracesdk/network/EmbraceNetworkRequest;)V
  public abstract fun setProcessStartedByNotification ()V
  public abstract fun shouldCaptureNetworkBody (Ljava/lang/String;Ljava/lang/String;)Z
  public abstract fun stopSdk ()V

diff --git a/...c/integrationTest/kotlin/io/embrace/android/embracesdk/testcases/NetworkRequestApiTest.kt b/...c/integrationTest/kotlin/io/embrace/android/embracesdk/testcases/NetworkRequestApiTest.kt
@@ -202,48 +202,6 @@ internal class NetworkRequestApiTest {
  }
  }
 
-// @Ignore() //TODO: Fix this test
-// @Test
-// fun `ensure calls with same callId but different start times are deduped`() {
-// val expectedStartTime = START_TIME + 1
-// with(testRule) {
-// harness.recordSession {
-// harness.overriddenConfigService.updateListeners()
-// harness.overriddenClock.tick(5)
-//
-// val callId = UUID.randomUUID().toString()
-// embrace.internalInterface.recordURLConnectionNetworkRequest(
-// callId,
-// EmbraceNetworkRequest.fromCompletedRequest(
-// "$URL/bad",
-// HttpMethod.GET,
-// START_TIME,
-// END_TIME,
-// BYTES_SENT,
-// BYTES_RECEIVED,
-// 200
-// )
-// )
-// embrace.internalInterface.recordURLConnectionNetworkRequest(
-// callId,
-// EmbraceNetworkRequest.fromCompletedRequest(
-// URL,
-// HttpMethod.GET,
-// expectedStartTime,
-// expectedStartTime + 1,
-// BYTES_SENT,
-// BYTES_RECEIVED,
-// 200
-// )
-// )
-// }
-//
-// val networkSpan = validateAndReturnExpectedNetworkSpan()
-// assertEquals(URL, networkSpan.attributes["url.full"])
-// assertEquals(expectedStartTime, networkSpan.startTimeNanos)
-// }
-// }
-
  /**
  * This reproduces the bug that will be fixed. Uncomment when ready.
  */

diff --git a/...ava/io/embrace/android/embracesdk/internal/network/http/EmbraceUrlConnectionDelegate.java b/...ava/io/embrace/android/embracesdk/internal/network/http/EmbraceUrlConnectionDelegate.java
@@ -21,7 +21,6 @@
 import java.util.HashMap;
 import java.util.List;
 import java.util.Map;
-import java.util.UUID;
 import java.util.concurrent.atomic.AtomicInteger;
 import java.util.concurrent.atomic.AtomicLong;
 import java.util.concurrent.atomic.AtomicReference;
@@ -89,9 +88,6 @@ class EmbraceUrlConnectionDelegate<T extends HttpURLConnection> implements Embra
  */
  private final Embrace embrace;
 
- @NonNull
- private final String callId;
-
  /**
  * A reference to the output stream wrapped in a counter, so we can determine the bytes sent.
  */
@@ -102,11 +98,6 @@ class EmbraceUrlConnectionDelegate<T extends HttpURLConnection> implements Embra
  */
  private volatile boolean didLogNetworkCall = false;
 
- /**
- * The time at which the network call ended.
- */
- private volatile Long endTime;
-
  /**
  * The time at which the network call was initiated.
  */
@@ -157,7 +148,6 @@ public EmbraceUrlConnectionDelegate(@NonNull T connection, boolean enableWrapIoS
  this.enableWrapIoStreams = enableWrapIoStreams;
  this.embrace = embrace;
  this.createdTime = embrace.getInternalInterface().getSdkCurrentTime();
- this.callId = UUID.randomUUID().toString();
  this.isSDKStarted = embrace.isStarted();
  }
 
@@ -358,8 +348,7 @@ public long getHeaderFieldLong(@NonNull String name, long defaultValue) {
  @Nullable
  public Map<String, List<String>> getHeaderFields() {
  final long startTime = embrace.getInternalInterface().getSdkCurrentTime();
- cacheNetworkCallData();
- internalLogNetworkCall(startTime);
+ cacheAndLogNetworkCall(startTime);
  return headerFields.get();
  }
 
@@ -377,8 +366,8 @@ private <R> R retrieveHeaderField(@Nullable String name,
  }
 
  R result = action.invoke();
- cacheNetworkCallData();
- internalLogNetworkCall(startTime);
+ cacheAndLogNetworkCall(startTime);
+
  return result;
  }
 
@@ -473,8 +462,7 @@ public String getRequestProperty(@NonNull String key) {
  public int getResponseCode() {
  identifyTraceId();
  long startTime = embrace.getInternalInterface().getSdkCurrentTime();
- cacheNetworkCallData();
- internalLogNetworkCall(startTime);
+ cacheAndLogNetworkCall(startTime);
  return responseCode.get();
  }
 
@@ -484,8 +472,7 @@ public String getResponseMessage() throws IOException {
  identifyTraceId();
  long startTime = embrace.getInternalInterface().getSdkCurrentTime();
  String responseMsg = this.connection.getResponseMessage();
- cacheNetworkCallData();
- internalLogNetworkCall(startTime);
+ cacheAndLogNetworkCall(startTime);
  return responseMsg;
  }
 
@@ -540,30 +527,18 @@ public boolean usingProxy() {
  return this.connection.usingProxy();
  }
 
- /**
- * Given a start time (in milliseconds), logs the network call to Embrace using the current time as the end time.
- * <p>
- * If the network call has already been logged for this HttpURLConnection, this method is a no-op and is effectively
- * ignored.
- */
- synchronized void internalLogNetworkCall(long startTime) {
- if (isSDKStarted) {
- internalLogNetworkCall(startTime, embrace.getInternalInterface().getSdkCurrentTime());
- }
- }
-
  /**
  * Given a start time and end time (in milliseconds), logs the network call to Embrace.
  * <p>
  * If this delegate has already logged the call it represents, this method is a no-op.
  */
- synchronized void internalLogNetworkCall(long startTime, long endTime) {
- if (!this.didLogNetworkCall) {
+ synchronized void internalLogNetworkCall(long startTime) {
+ if (isSDKStarted && !this.didLogNetworkCall) {
  // We are proactive with setting this flag so that we don't get nested calls to log the network call by virtue of
  // extracting the data we need to log the network call.
- this.didLogNetworkCall = true;
+ this.didLogNetworkCall = true; // TODO: Wouldn't this mean that the network call might not be logged
  this.startTime = startTime;
- this.endTime = endTime;
+ long endTime = embrace.getInternalInterface().getSdkCurrentTime();
 
  String url = EmbraceHttpPathOverride.getURLString(new EmbraceHttpUrlConnectionOverride(this.connection));
 
@@ -656,10 +631,8 @@ private CountingInputStreamWithCallback countingInputStream(InputStream inputStr
  inputStream,
  hasNetworkCaptureRules(),
  (responseBody) -> {
- if (startTime != null && endTime != null) {
- cacheNetworkCallData(responseBody);
- internalLogNetworkCall(startTime, endTime);
- }
+ cacheNetworkCallData(responseBody);
+ internalLogNetworkCall(startTime);
  return null;
  });
  }
@@ -695,7 +668,7 @@ private void identifyTraceId() {
  traceId = getRequestProperty(embrace.getTraceIdHeader());
  } catch (Exception e) {
  Embrace.getInstance().getInternalInterface().logWarning(
-  "Failed to retrieve actual trace id header. Current: " + traceId, null, null);
+ "Failed to retrieve actual trace id header. Current: " + traceId, null, null);
  }
  }
  }
@@ -787,7 +760,7 @@ public Principal getPeerPrincipal() throws SSLPeerUnverifiedException {
  @Nullable
  private InputStream getWrappedInputStream(InputStream connectionInputStream) {
  identifyTraceId();
- long startTime = embrace.getInternalInterface().getSdkCurrentTime();
+ startTime = embrace.getInternalInterface().getSdkCurrentTime();
 
  InputStream in = null;
  if (shouldUncompressGzip()) {
@@ -804,11 +777,18 @@ private InputStream getWrappedInputStream(InputStream connectionInputStream) {
  countingInputStream(new BufferedInputStream(connectionInputStream)) : connectionInputStream;
  }
 
- cacheNetworkCallData();
- internalLogNetworkCall(startTime);
+ cacheAndLogNetworkCall(startTime);
+
  return in;
  }
 
+ private void cacheAndLogNetworkCall(long startTime) {
+ if (!enableWrapIoStreams) {
+ cacheNetworkCallData();
+ internalLogNetworkCall(startTime);
+ }
+ }
+
  private boolean hasNetworkCaptureRules() {
  if (!isSDKStarted || this.connection.getURL() == null) {
  return false;

diff --git a/...a/io/embrace/android/embracesdk/internal/network/http/EmbraceUrlConnectionDelegateTest.kt b/...a/io/embrace/android/embracesdk/internal/network/http/EmbraceUrlConnectionDelegateTest.kt
@@ -17,7 +17,6 @@ import io.mockk.verify
 import org.junit.Assert.assertEquals
 import org.junit.Assert.assertNull
 import org.junit.Assert.assertThrows
-import org.junit.Assert.assertTrue
 import org.junit.Before
 import org.junit.Test
 import java.io.ByteArrayInputStream