[Cronet] Make metrics reporting happen after terminal callbacks.

components/cronet/android/java/src/org/chromium/net/impl/CronetUrlRequest.java

 // Copyright 2014 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 package org.chromium.net.impl;
 
 import org.chromium.base.Log;
 import org.chromium.base.VisibleForTesting;
 import org.chromium.base.annotations.CalledByNative;
 import org.chromium.base.annotations.JNIAdditionalImport;
@@ skipping 33 matching lines @@
 @JNIAdditionalImport(VersionSafeCallbacks.class)
 @VisibleForTesting
 public final class CronetUrlRequest extends UrlRequestBase {
     private final boolean mAllowDirectExecutor;
 
     /* Native adapter object, owned by UrlRequest. */
     @GuardedBy("mUrlRequestAdapterLock")
     private long mUrlRequestAdapter;
 
     @GuardedBy("mUrlRequestAdapterLock")
-    private boolean mStarted = false;
+    private boolean mStarted;
     @GuardedBy("mUrlRequestAdapterLock")
-    private boolean mWaitingOnRedirect = false;
+    private boolean mWaitingOnRedirect;
     @GuardedBy("mUrlRequestAdapterLock")
-    private boolean mWaitingOnRead = false;
-    @GuardedBy("mUrlRequestAdapterLock")
-    private RequestFinishedInfo.Metrics mMetrics;
+    private boolean mWaitingOnRead;
 
     /*
      * Synchronize access to mUrlRequestAdapter, mStarted, mWaitingOnRedirect,
      * and mWaitingOnRead.
      */
     private final Object mUrlRequestAdapterLock = new Object();
     private final CronetUrlRequestContext mRequestContext;
     private final Executor mExecutor;
 
     /*
      * URL chain contains the URL currently being requested, and
      * all URLs previously requested. New URLs are added before
      * mCallback.onRedirectReceived is called.
      */
     private final List<String> mUrlChain = new ArrayList<String>();
     private long mReceivedByteCountFromRedirects;
 
     private final VersionSafeCallbacks.UrlRequestCallback mCallback;
     private final String mInitialUrl;
     private final int mPriority;
     private String mInitialMethod;
     private final HeadersList mRequestHeaders = new HeadersList();
     private final Collection<Object> mRequestAnnotations;
-    @RequestFinishedInfoImpl.FinishedReason
-    private int mFinishedReason;
-    private CronetException mException;
     private final boolean mDisableCache;
     private final boolean mDisableConnectionMigration;
 
     private CronetUploadDataStream mUploadDataStream;
 
     private UrlResponseInfoImpl mResponseInfo;
 
+    // These three should only be updated once with mUrlRequestAdapterLock held. They are read on
+    // URLRequest.Callback executor's and RequestFinishedListener's thread after the last update.

[mgersh, 2017/05/02 18:21:12]

nits: UrlRequest, RequestFinishedInfo.Listener.

These are two different executors, so "thread" should be "threads", or maybe
rephrase to something like "both UrlRequest.Callback and
RequestFinishedInfo.Listener's executors".

[xunjieli, 2017/05/02 23:30:23]

Done.

+    @RequestFinishedInfoImpl.FinishedReason
+    private int mFinishedReason;
+    private CronetException mException;
+    private CronetMetrics mMetrics;
+
     /*
      * Listener callback is repeatedly invoked when each read is completed, so it
      * is cached as a member variable.
      */
     private OnReadCompletedRunnable mOnReadCompletedTask;
 
+    @GuardedBy("mUrlRequestAdapterLock")
     private Runnable mOnDestroyedCallbackForTesting;
 
     private static final class HeadersList extends ArrayList<Map.Entry<String, String>> {}
 
     private final class OnReadCompletedRunnable implements Runnable {
         // Buffer passed back from current invocation of onReadCompleted.
         ByteBuffer mByteBuffer;
 
         @Override
         public void run() {
@@ skipping 117 matching lines @@
                                     return;
                                 }
                                 mUploadDataStream.attachNativeAdapterToRequest(mUrlRequestAdapter);
                                 startInternalLocked();
                             }
                         }
                     });
                     return;
                 }
             } catch (RuntimeException e) {
-                // If there's an exception, cleanup and then throw the
-                // exception to the caller.
-                destroyRequestAdapter(false);
+                // If there's an exception, cleanup and then throw the exception to the caller.
+                // start() is synchronized so we do not acquire mUrlRequestAdapterLock here.
+                destroyRequestAdapterLocked(RequestFinishedInfo.FAILED);
                 throw e;
             }
             mStarted = true;
             startInternalLocked();
         }
     }
 
     /*
      * Starts fully configured request. Could execute on UploadDataProvider executor.
      * Caller is expected to ensure that request isn't canceled and mUrlRequestAdapter is valid.
@@ skipping 41 matching lines @@
             }
         }
     }
 
     @Override
     public void cancel() {
         synchronized (mUrlRequestAdapterLock) {
             if (isDoneLocked() || !mStarted) {
                 return;
             }
-            destroyRequestAdapter(true);
+            destroyRequestAdapterLocked(RequestFinishedInfo.CANCELED);
         }
     }
 
     @Override
     public boolean isDone() {
         synchronized (mUrlRequestAdapterLock) {
             return isDoneLocked();
         }
     }
 
@@ skipping 16 matching lines @@
             @Override
             public void run() {
                 listener.onStatus(UrlRequest.Status.INVALID);
             }
         };
         postTaskToExecutor(task);
     }
 
     @VisibleForTesting
     public void setOnDestroyedCallbackForTesting(Runnable onDestroyedCallbackForTesting) {
-        mOnDestroyedCallbackForTesting = onDestroyedCallbackForTesting;
+        synchronized (mUrlRequestAdapterLock) {
+            mOnDestroyedCallbackForTesting = onDestroyedCallbackForTesting;
+        }
     }
 
     @VisibleForTesting
     public void setOnDestroyedUploadCallbackForTesting(
             Runnable onDestroyedUploadCallbackForTesting) {
         mUploadDataStream.setOnDestroyedCallbackForTesting(onDestroyedUploadCallbackForTesting);
     }
 
     @VisibleForTesting
     public long getUrlRequestAdapterForTesting() {
@@ skipping 54 matching lines @@
     }
 
     private void checkNotStarted() {
         synchronized (mUrlRequestAdapterLock) {
             if (mStarted || isDoneLocked()) {
                 throw new IllegalStateException("Request is already started.");
             }
         }
     }
 
-    private void destroyRequestAdapter(boolean sendOnCanceled) {
-        synchronized (mUrlRequestAdapterLock) {
-            if (mUrlRequestAdapter == 0) {
-                return;
-            }
-            nativeDestroy(mUrlRequestAdapter, sendOnCanceled);
-            mRequestContext.onRequestDestroyed();
-            mUrlRequestAdapter = 0;
-            if (mOnDestroyedCallbackForTesting != null) {
-                mOnDestroyedCallbackForTesting.run();
-            }
-        }
-    }
-
     /**
+     * Helper method to set final status of CronetUrlRequest and clean up the
+     * native request adapter.
+     */
+    @GuardedBy("mUrlRequestAdapterLock")
+    private void destroyRequestAdapterLocked(
+            @RequestFinishedInfoImpl.FinishedReason int finishedReason) {
+        assert mException == null || finishedReason == RequestFinishedInfo.FAILED;
+        mFinishedReason = finishedReason;
+        if (mUrlRequestAdapter == 0) {
+            return;
+        }
+        mRequestContext.onRequestDestroyed();
+        // Posts a task to destroy the native adapter.
+        nativeDestroy(mUrlRequestAdapter, finishedReason == RequestFinishedInfo.CANCELED);
+        mUrlRequestAdapter = 0;
+    }
+
+    /**
      * If callback method throws an exception, request gets canceled
      * and exception is reported via onFailed listener callback.
      * Only called on the Executor.
      */
     private void onCallbackException(Exception e) {
         CallbackException requestError =
                 new CallbackExceptionImpl("Exception received from UrlRequest.Callback", e);
         Log.e(CronetUrlRequestContext.LOG_TAG, "Exception in CalledByNative method", e);
         failWithException(requestError);
     }
 
     /**
      * Called when UploadDataProvider encounters an error.
      */
     void onUploadException(Throwable e) {
         CallbackException uploadError =
                 new CallbackExceptionImpl("Exception received from UploadDataProvider", e);
         Log.e(CronetUrlRequestContext.LOG_TAG, "Exception in upload method", e);
         failWithException(uploadError);
     }
 
     /**
-     * Fails the request with an exception. Can be called on any thread.
+     * Fails the request with an exception on any thread.
      */
     private void failWithException(final CronetException exception) {
-        mException = exception;
         synchronized (mUrlRequestAdapterLock) {
             if (isDoneLocked()) {
                 return;
             }
-            destroyRequestAdapter(false);
+            assert mException == null;
+            mException = exception;
+            destroyRequestAdapterLocked(RequestFinishedInfo.FAILED);
         }
-        Runnable task = new Runnable() {
-            @Override
-            public void run() {
-                try {
-                    mCallback.onFailed(CronetUrlRequest.this, mResponseInfo, exception);
-                } catch (Exception e) {
-                    Log.e(CronetUrlRequestContext.LOG_TAG, "Exception in onFailed method", e);
-                }
-            }
-        };
-        try {
-            mExecutor.execute(task);
-        } catch (RejectedExecutionException e) {
-            Log.e(CronetUrlRequestContext.LOG_TAG, "Exception posting task to executor", e);
-        }
+        // The onFailed callback will be invoked from onNativeAdapterDestroyed() to ensure metrics
+        // collection

[mgersh, 2017/05/02 18:21:13]

nit: missing period at the end

[xunjieli, 2017/05/02 23:30:23]

Done.

     }
 
     ////////////////////////////////////////////////
     // Private methods called by the native code.
     // Always called on network thread.
     ////////////////////////////////////////////////
 
     /**
      * Called before following redirects. The redirect will only be followed if
      * {@link #followRedirect()} is called. If the redirect response has a body, it will be ignored.
@@ skipping 108 matching lines @@
 
     /**
      * Called when request is completed successfully, no callbacks will be
      * called afterwards.
      *
      * @param receivedByteCount number of bytes received.
      */
     @SuppressWarnings("unused")
     @CalledByNative
     private void onSucceeded(long receivedByteCount) {
-        mFinishedReason = RequestFinishedInfo.SUCCEEDED;
         mResponseInfo.setReceivedByteCount(mReceivedByteCountFromRedirects + receivedByteCount);
         Runnable task = new Runnable() {
             @Override
             public void run() {
                 synchronized (mUrlRequestAdapterLock) {
                     if (isDoneLocked()) {
                         return;
                     }
                     // Destroy adapter first, so request context could be shut
                     // down from the listener.
-                    destroyRequestAdapter(false);
+                    destroyRequestAdapterLocked(RequestFinishedInfo.SUCCEEDED);
                 }
                 try {
                     mCallback.onSucceeded(CronetUrlRequest.this, mResponseInfo);
+                    maybeReportMetrics();
                 } catch (Exception e) {
-                    Log.e(CronetUrlRequestContext.LOG_TAG, "Exception in onComplete method", e);
+                    Log.e(CronetUrlRequestContext.LOG_TAG, "Exception in onSucceeded method", e);
                 }
             }
         };
         postTaskToExecutor(task);
     }
 
     /**
      * Called when error has occured, no callbacks will be called afterwards.
      *
      * @param errorCode Error code represented by {@code UrlRequestError} that should be mapped
      *                  to one of {@link NetworkException#ERROR_HOSTNAME_NOT_RESOLVED
      *                  NetworkException.ERROR_*}.
      * @param nativeError native net error code.
      * @param errorString textual representation of the error code.
      * @param receivedByteCount number of bytes received.
      */
     @SuppressWarnings("unused")
     @CalledByNative
     private void onError(int errorCode, int nativeError, int nativeQuicError, String errorString,
             long receivedByteCount) {
-        mFinishedReason = RequestFinishedInfo.FAILED;
         if (mResponseInfo != null) {
             mResponseInfo.setReceivedByteCount(mReceivedByteCountFromRedirects + receivedByteCount);
         }
         if (errorCode == NetworkException.ERROR_QUIC_PROTOCOL_FAILED) {
             failWithException(new QuicExceptionImpl(
                     "Exception in CronetUrlRequest: " + errorString, nativeError, nativeQuicError));
         } else {
             int javaError = mapUrlRequestErrorToApiErrorCode(errorCode);
             failWithException(new NetworkExceptionImpl(
                     "Exception in CronetUrlRequest: " + errorString, javaError, nativeError));
         }
     }
 
     /**
      * Called when request is canceled, no callbacks will be called afterwards.
      */
     @SuppressWarnings("unused")
     @CalledByNative
     private void onCanceled() {
-        mFinishedReason = RequestFinishedInfo.CANCELED;
         Runnable task = new Runnable() {
             @Override
             public void run() {
                 try {
                     mCallback.onCanceled(CronetUrlRequest.this, mResponseInfo);
+                    maybeReportMetrics();
                 } catch (Exception e) {
                     Log.e(CronetUrlRequestContext.LOG_TAG, "Exception in onCanceled method", e);
                 }
             }
         };
         postTaskToExecutor(task);
     }
 
     /**
      * Called by the native code when request status is fetched from the
      * native stack.
      */
     @SuppressWarnings("unused")
     @CalledByNative
     private void onStatus(
             final VersionSafeCallbacks.UrlRequestStatusListener listener, final int loadState) {
         Runnable task = new Runnable() {
             @Override
             public void run() {
                 listener.onStatus(convertLoadState(loadState));
             }
         };
         postTaskToExecutor(task);
     }
 
     /**
-     * Called by the native code to report metrics.
+     * Called by the native code on the network thread to report metrics. Happens before
+     * onSucceeded, onError and onCanceled.
      */
     @SuppressWarnings("unused")
     @CalledByNative
     private void onMetricsCollected(long requestStartMs, long dnsStartMs, long dnsEndMs,
             long connectStartMs, long connectEndMs, long sslStartMs, long sslEndMs,
             long sendingStartMs, long sendingEndMs, long pushStartMs, long pushEndMs,
             long responseStartMs, long requestEndMs, boolean socketReused, long sentByteCount,
             long receivedByteCount) {
         synchronized (mUrlRequestAdapterLock) {
             if (mMetrics != null) {
                 throw new IllegalStateException("Metrics collection should only happen once.");
             }
             mMetrics = new CronetMetrics(requestStartMs, dnsStartMs, dnsEndMs, connectStartMs,
                     connectEndMs, sslStartMs, sslEndMs, sendingStartMs, sendingEndMs, pushStartMs,
                     pushEndMs, responseStartMs, requestEndMs, socketReused, sentByteCount,
                     receivedByteCount);
         }
-        mRequestContext.reportFinished(getRequestFinishedInfo());
+        // Metrics are reported to RequestFinishedListener when the final UrlRequest.Callback has
+        // been invoked.
     }
 
-    private RequestFinishedInfo getRequestFinishedInfo() {
-        return new RequestFinishedInfoImpl(mInitialUrl, mRequestAnnotations, mMetrics,
-                mFinishedReason, mResponseInfo, mException);
+    /**
+     * Called when the native adapter is destroyed.
+     */
+    @SuppressWarnings("unused")
+    @CalledByNative
+    private void onNativeAdapterDestroyed() {
+        synchronized (mUrlRequestAdapterLock) {
+            if (mOnDestroyedCallbackForTesting != null) {
+                mOnDestroyedCallbackForTesting.run();
+            }
+            // mException is set when an error is encountered (in native code via onError or in
+            // Java code). If mException is not null, notify the mCallback and report metrics.
+            if (mException == null) {
+                return;
+            }
+        }
+        Runnable task = new Runnable() {
+            @Override
+            public void run() {
+                try {
+                    mCallback.onFailed(CronetUrlRequest.this, mResponseInfo, mException);
+                    maybeReportMetrics();
+                } catch (Exception e) {
+                    Log.e(CronetUrlRequestContext.LOG_TAG, "Exception in onFailed method", e);
+                }
+            }
+        };
+        try {
+            mExecutor.execute(task);
+        } catch (RejectedExecutionException e) {
+            Log.e(CronetUrlRequestContext.LOG_TAG, "Exception posting task to executor", e);
+        }
     }
 
     /** Enforces prohibition of direct execution. */
     void checkCallingThread() {
         if (!mAllowDirectExecutor && mRequestContext.isNetworkThread(Thread.currentThread())) {
             throw new InlineExecutionProhibitedException();
         }
     }
 
     private int mapUrlRequestErrorToApiErrorCode(int errorCode) {
@@ skipping 19 matching lines @@
             case UrlRequestError.QUIC_PROTOCOL_FAILED:
                 return NetworkException.ERROR_QUIC_PROTOCOL_FAILED;
             case UrlRequestError.OTHER:
                 return NetworkException.ERROR_OTHER;
             default:
                 Log.e(CronetUrlRequestContext.LOG_TAG, "Unknown error code: " + errorCode);
                 return errorCode;
         }
     }
 
+    // Maybe report metrics. This method should only be called on Callback's executor thread and
+    // after Callback's onSucceeded, onFailed and onCanceled.
+    private void maybeReportMetrics() {
+        if (mMetrics != null) {
+            mRequestContext.reportFinished(new RequestFinishedInfoImpl(mInitialUrl,
+                    mRequestAnnotations, mMetrics, mFinishedReason, mResponseInfo, mException));
+        }
+    }
+
     // Native methods are implemented in cronet_url_request_adapter.cc.
 
     private native long nativeCreateRequestAdapter(long urlRequestContextAdapter, String url,
             int priority, boolean disableCache, boolean disableConnectionMigration,
             boolean enableMetrics);
 
     @NativeClassQualifiedName("CronetURLRequestAdapter")
     private native boolean nativeSetHttpMethod(long nativePtr, String method);
 
     @NativeClassQualifiedName("CronetURLRequestAdapter")
     private native boolean nativeAddRequestHeader(long nativePtr, String name, String value);
 
     @NativeClassQualifiedName("CronetURLRequestAdapter")
     private native void nativeStart(long nativePtr);
 
     @NativeClassQualifiedName("CronetURLRequestAdapter")
     private native void nativeFollowDeferredRedirect(long nativePtr);
 
     @NativeClassQualifiedName("CronetURLRequestAdapter")
     private native boolean nativeReadData(
             long nativePtr, ByteBuffer byteBuffer, int position, int capacity);
 
     @NativeClassQualifiedName("CronetURLRequestAdapter")
     private native void nativeDestroy(long nativePtr, boolean sendOnCanceled);
 
     @NativeClassQualifiedName("CronetURLRequestAdapter")
     private native void nativeGetStatus(
             long nativePtr, VersionSafeCallbacks.UrlRequestStatusListener listener);
 }