[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 executor's thread after the last update.

[mef, 2017/04/28 21:16:54]

Should they be @GuardedBy("mUrlRequestAdapterLock")?

[mgersh, 2017/05/01 15:29:22]

this could clarify which executor

[xunjieli, 2017/05/01 19:17:16]

Done.

[xunjieli, 2017/05/01 19:17:16]

These three are not guarded by the lock because they are read on the executor's
thread without holding the lock. 

+    @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. Use
+                // null to avoid rethrowing in onDestroy().
+                synchronized (mUrlRequestAdapterLock) {

[mef, 2017/04/28 21:16:54]

This whole method is synchronized() at line 191, so I don't think this is needed
here.

[xunjieli, 2017/05/01 19:17:16]

Done.

+                    setIsDoneLocked(null, 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);
+            setIsDoneLocked(null, RequestFinishedInfo.CANCELED);
         }
     }
 
     @Override
     public boolean isDone() {
         synchronized (mUrlRequestAdapterLock) {
             return isDoneLocked();
         }
     }
 
+    /**
+     * Helper method to set final status of CronetUrlRequest and clean up the
+     * native request adapter.
+     */
+    @GuardedBy("mUrlRequestAdapterLock")
+    private void setIsDoneLocked(

[mef, 2017/04/28 21:16:55]

I really think it should still be called destroyRequestAdapterLocked as that's
what it does. 

[xunjieli, 2017/05/01 19:17:16]

Done. Partly yes, but now it also updates |mException| and |mFinishedReason|. I
think it will be a nice counterpart to isDone(). I guess we could discuss that
in a separate CL. I have changed it back.

+            CronetException exception, @RequestFinishedInfoImpl.FinishedReason int finishedReason) {
+        assert mException == null;
+        assert exception == null || finishedReason == RequestFinishedInfo.FAILED;
+        mException = exception;
+        mFinishedReason = finishedReason;
+        if (mUrlRequestAdapter == 0) {
+            return;
+        }
+        mRequestContext.onRequestDestroyed();
+        // Posts a task to destroy the native adapter.
+        nativeDestroy(mUrlRequestAdapter, finishedReason == RequestFinishedInfo.CANCELED);
+        mUrlRequestAdapter = 0;
+    }
+
     @GuardedBy("mUrlRequestAdapterLock")
     private boolean isDoneLocked() {
         return mStarted && mUrlRequestAdapter == 0;
     }
 
     @Override
     public void getStatus(UrlRequest.StatusListener unsafeListener) {
         final VersionSafeCallbacks.UrlRequestStatusListener listener =
                 new VersionSafeCallbacks.UrlRequestStatusListener(unsafeListener);
         synchronized (mUrlRequestAdapterLock) {
             if (mUrlRequestAdapter != 0) {
                 nativeGetStatus(mUrlRequestAdapter, listener);
                 return;
             }
         }
         Runnable task = new Runnable() {
             @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();
-            }
-        }
-    }
-
     /**
      * 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);
+            setIsDoneLocked(exception, RequestFinishedInfo.FAILED);

[mef, 2017/04/28 21:16:54]

Can we set mException = exception; here and just pass RequestFinishedInfo.Reason
to destroyRequestAdapterLocked()?
This way other callers wouldn't need to pass null.

[xunjieli, 2017/05/01 19:17:16]

Done.

         }
-        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);
-        }
+        // Wait until onDestroy() is called to propagate the error to caller to

[mef, 2017/04/28 21:16:54]

I would rephrase this like 'The onFailed callback will be invoked from
onNativeAdapterDestroyed() to ensure metrics collection.

[xunjieli, 2017/05/01 19:17:16]

Done.

+        // gather metrics.
     }
 
     ////////////////////////////////////////////////
     // 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);
+                    setIsDoneLocked(null, RequestFinishedInfo.SUCCEEDED);
                 }
                 try {
                     mCallback.onSucceeded(CronetUrlRequest.this, mResponseInfo);
+                    if (mMetrics != null) {
+                        mRequestContext.reportFinished(
+                                new RequestFinishedInfoImpl(mInitialUrl, mRequestAnnotations,
+                                        mMetrics, mFinishedReason, mResponseInfo, mException));
+                    }
                 } 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);
         }
+        CronetException exception;

[mef, 2017/04/28 21:16:54]

Why do we need local |exception| here?

[xunjieli, 2017/05/01 19:17:16]

Done. Because we can acquire mUrlRequestAdapterLock once for all in
failWithException() ? I got rid of it.

         if (errorCode == NetworkException.ERROR_QUIC_PROTOCOL_FAILED) {
-            failWithException(new QuicExceptionImpl(
-                    "Exception in CronetUrlRequest: " + errorString, nativeError, nativeQuicError));
+            exception = new QuicExceptionImpl(
+                    "Exception in CronetUrlRequest: " + errorString, nativeError, nativeQuicError);
         } else {
             int javaError = mapUrlRequestErrorToApiErrorCode(errorCode);
-            failWithException(new NetworkExceptionImpl(
-                    "Exception in CronetUrlRequest: " + errorString, javaError, nativeError));
+            exception = new NetworkExceptionImpl(
+                    "Exception in CronetUrlRequest: " + errorString, javaError, nativeError);
         }
+        failWithException(exception);
     }
 
     /**
      * 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);
+                    if (mMetrics != null) {

[mef, 2017/04/28 21:16:54]

Does it make sense to extract this into maybeReportFinished or somesuch from
here and in onSucceeded and onDestroyed? 

[xunjieli, 2017/05/01 19:17:16]

Done.

+                        mRequestContext.reportFinished(
+                                new RequestFinishedInfoImpl(mInitialUrl, mRequestAnnotations,
+                                        mMetrics, mFinishedReason, mResponseInfo, mException));
+                    }
                 } 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);
         }

[mef, 2017/04/28 21:16:54]

Maybe add comment that metrics will be reported after final callback?

[xunjieli, 2017/05/01 19:17:16]

Done.

-        mRequestContext.reportFinished(getRequestFinishedInfo());
     }
 
-    private RequestFinishedInfo getRequestFinishedInfo() {
-        return new RequestFinishedInfoImpl(mInitialUrl, mRequestAnnotations, mMetrics,
-                mFinishedReason, mResponseInfo, mException);
+    /**
+     * Called when the native adapter is destroyed.
+     */
+    @SuppressWarnings("unused")
+    @CalledByNative
+    private void onDestroyed() {

[mef, 2017/04/28 21:16:55]

Maybe (not strongly) call it onNativeAdapterDestroyed?

[xunjieli, 2017/05/01 19:17:16]

Done.

+        synchronized (mUrlRequestAdapterLock) {
+            if (mOnDestroyedCallbackForTesting != null) {
+                mOnDestroyedCallbackForTesting.run();
+            }
+            if (mException == null) {

[mef, 2017/04/28 21:16:55]

Need a comment as to why  we check mException and possibly post onFailed from
here.

[xunjieli, 2017/05/01 19:17:16]

Done.

+                return;
+            }
+        }
+        Runnable task = new Runnable() {
+            @Override
+            public void run() {
+                try {
+                    mCallback.onFailed(CronetUrlRequest.this, mResponseInfo, mException);
+                    if (mMetrics != null) {
+                        mRequestContext.reportFinished(
+                                new RequestFinishedInfoImpl(mInitialUrl, mRequestAnnotations,
+                                        mMetrics, mFinishedReason, mResponseInfo, mException));
+                    }
+                } 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 48 matching lines @@
     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);
 }