Skip to content

Commit

Permalink
Only log network request when getWrappedStream is called (#787)
Browse files Browse the repository at this point in the history
## Goal

We were prematurely trying to log a span for a request sent using HttpUrlConnection - we used to overwrite this but since we don't do that anymore, it got used.

Instead of relying on that, we streamline the logging - putting in the "cacheNetworkCall" to force request invocation down the path of calling getResponseCode(). This took care of some edge cases that we previously didn't cover.

If we are not wrapping the stream, we log the call after the request is executed. If we are wrapping the stream, we do the logging when the stream is read and the bytes are counted. If there's an error during the execution or if the request wasn't executed at all because of the lack of a network connection, the logging happens at disconnect.

HttpUrlConnection - you got me again!

## Testing

Existing unit tests pass.
  • Loading branch information
bidetofevil authored Apr 20, 2024
2 parents c8c4d2b + 12e0eb2 commit a6fe62a
Showing 1 changed file with 28 additions and 27 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -174,7 +174,8 @@ public void connect() throws IOException {
@Override
public void disconnect() {
// The network call must be logged before we close the transport
internalLogNetworkCall(createdTime);
setStartTime(createdTime);
internalLogNetworkCall();
this.connection.disconnect();
}

Expand Down Expand Up @@ -347,8 +348,7 @@ public long getHeaderFieldLong(@NonNull String name, long defaultValue) {
@Override
@Nullable
public Map<String, List<String>> getHeaderFields() {
final long startTime = embrace.getInternalInterface().getSdkCurrentTime();
cacheAndLogNetworkCall(startTime);
cacheNetworkCallData();
return headerFields.get();
}

Expand All @@ -359,14 +359,13 @@ private <R> R retrieveHeaderField(@Nullable String name,
if (name == null) {
return null;
}
long startTime = embrace.getInternalInterface().getSdkCurrentTime();
if (shouldInterceptHeaderRetrieval(name)) {
// Strip the content encoding and length headers, as we transparently ungzip the content
return defaultValue;
}

R result = action.invoke();
cacheAndLogNetworkCall(startTime);
cacheNetworkCallData();

return result;
}
Expand Down Expand Up @@ -461,19 +460,16 @@ public String getRequestProperty(@NonNull String key) {
@Override
public int getResponseCode() {
identifyTraceId();
long startTime = embrace.getInternalInterface().getSdkCurrentTime();
cacheAndLogNetworkCall(startTime);
cacheNetworkCallData();
return responseCode.get();
}

@Override
@Nullable
public String getResponseMessage() throws IOException {
identifyTraceId();
long startTime = embrace.getInternalInterface().getSdkCurrentTime();
String responseMsg = this.connection.getResponseMessage();
cacheAndLogNetworkCall(startTime);
return responseMsg;
cacheNetworkCallData();
return this.connection.getResponseMessage();
}

@Override
Expand Down Expand Up @@ -532,12 +528,11 @@ public boolean usingProxy() {
* <p>
* If this delegate has already logged the call it represents, this method is a no-op.
*/
synchronized void internalLogNetworkCall(long startTime) {
synchronized void internalLogNetworkCall() {
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; // TODO: Wouldn't this mean that the network call might not be logged
this.startTime = startTime;
long endTime = embrace.getInternalInterface().getSdkCurrentTime();

String url = EmbraceHttpPathOverride.getURLString(new EmbraceHttpUrlConnectionOverride(this.connection));
Expand Down Expand Up @@ -632,7 +627,7 @@ private CountingInputStreamWithCallback countingInputStream(InputStream inputStr
hasNetworkCaptureRules(),
(responseBody) -> {
cacheNetworkCallData(responseBody);
internalLogNetworkCall(startTime);
internalLogNetworkCall();
return null;
});
}
Expand Down Expand Up @@ -760,8 +755,7 @@ public Principal getPeerPrincipal() throws SSLPeerUnverifiedException {
@Nullable
private InputStream getWrappedInputStream(InputStream connectionInputStream) {
identifyTraceId();
startTime = embrace.getInternalInterface().getSdkCurrentTime();

setStartTime(embrace.getInternalInterface().getSdkCurrentTime());
InputStream in = null;
if (shouldUncompressGzip()) {
try {
Expand All @@ -777,18 +771,11 @@ private InputStream getWrappedInputStream(InputStream connectionInputStream) {
countingInputStream(new BufferedInputStream(connectionInputStream)) : connectionInputStream;
}

cacheAndLogNetworkCall(startTime);
cacheNetworkCallData();

return in;
}

private void cacheAndLogNetworkCall(long startTime) {
if (!enableWrapIoStreams) {
cacheNetworkCallData();
internalLogNetworkCall(startTime);
}
}

private boolean hasNetworkCaptureRules() {
if (!isSDKStarted || this.connection.getURL() == null) {
return false;
Expand All @@ -800,16 +787,20 @@ private boolean hasNetworkCaptureRules() {
}

private void cacheNetworkCallData() {
if (isSDKStarted) {
cacheNetworkCallData(null);
}
cacheNetworkCallData(null);
}

/**
* Cache values from response at the first point of availability so that we won't try to retrieve these values when the response
* is not available.
*/
private void cacheNetworkCallData(@Nullable byte[] responseBody) {
if (!isSDKStarted) {
return;
}

setStartTime(embrace.getInternalInterface().getSdkCurrentTime());

if (headerFields.get() == null) {
synchronized (headerFields) {
if (headerFields.get() == null) {
Expand Down Expand Up @@ -856,6 +847,10 @@ private void cacheNetworkCallData(@Nullable byte[] responseBody) {
}
}

if (!enableWrapIoStreams) {
internalLogNetworkCall();
}

if (shouldCaptureNetworkData()) {
// If we don't have network capture rules, it's unnecessary to save these values
synchronized (networkCaptureData) {
Expand Down Expand Up @@ -905,6 +900,12 @@ private boolean shouldCaptureNetworkData() {
(networkCaptureData.get() == null || networkCaptureData.get().getCapturedResponseBody() == null);
}

private void setStartTime(@NonNull Long startTimeMs) {
if (startTime == null) {
startTime = startTimeMs;
}
}

private void logError(@NonNull Throwable t) {
Embrace.getInstance().getInternalInterface().logInternalError(t);
}
Expand Down

0 comments on commit a6fe62a

Please sign in to comment.