[Android] Experimental sync barrier detection for tracing

base/android/java/src/org/chromium/base/SystemMessageHandler.java

 // Copyright 2012 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.base;
 
 import android.os.Handler;
 import android.os.Message;
+import android.os.MessageQueue;
+import android.util.Log;
+
+import java.lang.reflect.Field;
+import java.lang.reflect.InvocationTargetException;
+import java.lang.reflect.Method;
 
 class SystemMessageHandler extends Handler {
 
+    private static final String TAG = "SystemMessageHandler";
+
     private static final int SCHEDULED_WORK = 1;
     private static final int DELAYED_SCHEDULED_WORK = 2;
 
     // Native class pointer set by the constructor of the SharedClient native class.
     private long mMessagePumpDelegateNative = 0;
     private long mDelayedScheduledTimeTicks = 0;
 
+    // The following members are used to detect and trace the presence of sync
+    // barriers in Android's MessageQueue. Note that this detection is
+    // experimental, temporary and intended only for diagnostic purposes.
+    private MessageQueue mMessageQueue;
+    private Field mMessageQueueMessageField;
+    private Field mMessageTargetField;
+    private boolean mQueueHasSyncBarrier;
+    private long mSyncBarrierTraceId;
+
     private SystemMessageHandler(long messagePumpDelegateNative) {
         mMessagePumpDelegateNative = messagePumpDelegateNative;
-    }
+        tryEnableSyncBarrierDetection();
+     }
 
     @Override
     public void handleMessage(Message msg) {
+        updateWhetherQueueHasBlockingSyncBarrier();
         if (msg.what == DELAYED_SCHEDULED_WORK) {
             mDelayedScheduledTimeTicks = 0;
         }
         nativeDoRunLoopOnce(mMessagePumpDelegateNative, mDelayedScheduledTimeTicks);
     }
 
     @SuppressWarnings("unused")
     @CalledByNative
     private void scheduleWork() {
+        updateWhetherQueueHasBlockingSyncBarrier();
+        if (mQueueHasSyncBarrier) TraceEvent.instant("SystemMessageHandler:immediateWorkBlocked");
         sendEmptyMessage(SCHEDULED_WORK);
     }
 
     @SuppressWarnings("unused")
     @CalledByNative
     private void scheduleDelayedWork(long delayedTimeTicks, long millis) {
         if (mDelayedScheduledTimeTicks != 0) {
             removeMessages(DELAYED_SCHEDULED_WORK);
         }
         mDelayedScheduledTimeTicks = delayedTimeTicks;
+        updateWhetherQueueHasBlockingSyncBarrier();
+        if (mQueueHasSyncBarrier) TraceEvent.instant("SystemMessageHandler:delayedWorkBlocked");
         sendEmptyMessageDelayed(DELAYED_SCHEDULED_WORK, millis);
     }
 
     @SuppressWarnings("unused")
     @CalledByNative
     private void removeAllPendingMessages() {
+        updateWhetherQueueHasBlockingSyncBarrier();
         removeMessages(SCHEDULED_WORK);
         removeMessages(DELAYED_SCHEDULED_WORK);
     }
 
+    private void updateWhetherQueueHasBlockingSyncBarrier() {
+        if (mMessageQueue == null) return;
+        // As barrier detection is only used for tracing, early out when tracing
+        // is disabled to avoid any potential performance penalties.
+        if (!TraceEvent.enabled()) {
+            mQueueHasSyncBarrier = false;
+            return;
+        }
+        final Message queueHead = (Message)getField(mMessageQueue, mMessageQueueMessageField);

[nyquist, 2014/09/23 00:08:39]

These final qualifiers are unnecessary I believe.

[jdduke (slow), 2014/09/23 16:20:46]

Done.

+        final boolean queueHasSyncbarrier = isSyncBarrierMessage(queueHead);

[nyquist, 2014/09/23 00:08:38]

queueHasSyncBarrier

[jdduke (slow), 2014/09/23 16:20:46]

Done.

+        setQueueHasSyncBarrier(queueHasSyncbarrier);
+    }
+
+    private boolean isSyncBarrierMessage(Message message) {
+        if (message == null) return false;
+        // Sync barrier messages have null targets.
+        return getField(message, mMessageTargetField) == null;
+    }
+
+    private void tryEnableSyncBarrierDetection() {
+        assert mMessageQueue == null;
+
+        boolean success = false;
+        try {
+            Class<?> looperClass = Class.forName("android.os.Looper");
+            Method getQueueMethod = looperClass.getMethod("getQueue", new Class[]{});
+            mMessageQueue = (MessageQueue)(getQueueMethod.invoke(getLooper()));

[nyquist, 2014/09/23 00:08:38]

Just (MessageQueue) getQueueMethod.invoke(getLooper()) ?

[jdduke (slow), 2014/09/23 16:20:46]

Done.

+
+            mMessageQueueMessageField = mMessageQueue.getClass().getDeclaredField("mMessages");
+            mMessageQueueMessageField.setAccessible(true);
+
+            mMessageTargetField = new Message().getClass().getDeclaredField("target");

[nyquist, 2014/09/23 00:08:38]

Could this just be Message.class.getDeclaredField("target")?

[jdduke (slow), 2014/09/23 16:20:46]

Done.

+            mMessageTargetField.setAccessible(true);
+
+            mSyncBarrierTraceId = hashCode();
+
+            success = true;
+        } catch (ClassNotFoundException e) {
+            Log.e(TAG, "Failed to find class: " + e);
+        } catch (NoSuchMethodException e) {
+            Log.e(TAG, "Failed to load method: " + e);
+        } catch (NoSuchFieldException e) {
+            Log.e(TAG, "Failed to load field: " + e);
+        } catch (InvocationTargetException e) {
+            Log.e(TAG, "Failed invocation: " + e);
+        } catch (IllegalAccessException e) {
+            Log.e(TAG, "Illegal access to reflected invocation: " + e);
+        } catch (RuntimeException e) {

[nyquist, 2014/09/23 00:08:39]

This is masking IllegalArgumentException thrown by invoke. Add both separately?
It's OK as is as well since it's just a RuntimeException, but I wasn't sure it
was intentional.

[jdduke (slow), 2014/09/23 16:20:46]

Not intentional, good catch.

+            Log.e(TAG, e.toString());
+        } finally {
+            if (!success) disableSyncBarrierDetection();
+        }
+    }
+
+    private void disableSyncBarrierDetection() {
+        Log.e(TAG, "Unexpected error with sync barrier detection, disabling.");
+        mMessageQueue = null;
+        mMessageQueueMessageField = null;
+        mMessageTargetField = null;
+        setQueueHasSyncBarrier(false);
+    }
+
+    private void setQueueHasSyncBarrier(boolean queueHasSyncbarrier) {

[nyquist, 2014/09/23 00:08:39]

queueHasSyncBarrier

[jdduke (slow), 2014/09/23 16:20:46]

Done.

+        if (queueHasSyncbarrier == mQueueHasSyncBarrier) return;
+        mQueueHasSyncBarrier = queueHasSyncbarrier;
+        if (mQueueHasSyncBarrier) {
+            TraceEvent.startAsync("SyncBarrier", mSyncBarrierTraceId);
+        } else {
+            TraceEvent.finishAsync("SyncBarrier", mSyncBarrierTraceId);
+        }
+    }
+
+    private Object getField(Object object, Field field) {
+        try {
+            return field.get(object);
+        } catch (IllegalAccessException e) {
+            Log.e(TAG, "Failed field access: " + e);
+            disableSyncBarrierDetection();
+        }
+        return null;
+     }
+
     @CalledByNative
     private static SystemMessageHandler create(long messagePumpDelegateNative) {
         return new SystemMessageHandler(messagePumpDelegateNative);
     }
 
     private native void nativeDoRunLoopOnce(
             long messagePumpDelegateNative, long delayedScheduledTimeTicks);
 }