diff --git a/ReactAndroid/src/main/java/com/facebook/react/bridge/PerformanceCounter.java b/ReactAndroid/src/main/java/com/facebook/react/bridge/PerformanceCounter.java index c956810e4..87a2e4b08 100644 --- a/ReactAndroid/src/main/java/com/facebook/react/bridge/PerformanceCounter.java +++ b/ReactAndroid/src/main/java/com/facebook/react/bridge/PerformanceCounter.java @@ -11,5 +11,5 @@ package com.facebook.react.bridge; import java.util.Map; public interface PerformanceCounter { - public Map getPerformanceCounters(); + public Map getPerformanceCounters(); } diff --git a/ReactAndroid/src/main/java/com/facebook/react/uimanager/UIImplementation.java b/ReactAndroid/src/main/java/com/facebook/react/uimanager/UIImplementation.java index 58d83f594..bdeadcdf4 100644 --- a/ReactAndroid/src/main/java/com/facebook/react/uimanager/UIImplementation.java +++ b/ReactAndroid/src/main/java/com/facebook/react/uimanager/UIImplementation.java @@ -8,6 +8,7 @@ */ package com.facebook.react.uimanager; +import android.os.SystemClock; import com.facebook.common.logging.FLog; import com.facebook.infer.annotation.Assertions; import com.facebook.react.animation.Animation; @@ -27,6 +28,7 @@ import com.facebook.systrace.SystraceMessage; import com.facebook.yoga.YogaDirection; import java.util.Arrays; import java.util.List; +import java.util.Map; import javax.annotation.Nullable; /** @@ -43,8 +45,7 @@ public class UIImplementation { private final ReactApplicationContext mReactContext; protected final EventDispatcher mEventDispatcher; - private double mLayoutCount = 0.0; - private double mLayoutTimer = 0.0; + private long mLastCalculateLayoutTime = 0; public UIImplementation( ReactApplicationContext reactContext, @@ -168,12 +169,12 @@ public class UIImplementation { } } - public double getLayoutCount() { - return mLayoutCount; + public void profileNextBatch() { + mOperationsQueue.profileNextBatch(); } - public double getLayoutTimer() { - return mLayoutTimer; + public Map getProfiledBatchPerfCounters() { + return mOperationsQueue.getProfiledBatchPerfCounters(); } /** @@ -555,10 +556,11 @@ public class UIImplementation { "UIImplementation.dispatchViewUpdates") .arg("batchId", batchId) .flush(); + final long commitStartTime = SystemClock.uptimeMillis(); try { updateViewHierarchy(); mNativeViewHierarchyOptimizer.onBatchComplete(); - mOperationsQueue.dispatchViewUpdates(batchId); + mOperationsQueue.dispatchViewUpdates(batchId, commitStartTime, mLastCalculateLayoutTime); } finally { Systrace.endSection(Systrace.TRACE_TAG_REACT_JAVA_BRIDGE); } @@ -824,13 +826,12 @@ public class UIImplementation { SystraceMessage.beginSection(Systrace.TRACE_TAG_REACT_JAVA_BRIDGE, "cssRoot.calculateLayout") .arg("rootTag", cssRoot.getReactTag()) .flush(); - double startTime = (double) System.nanoTime(); + long startTime = SystemClock.uptimeMillis(); try { cssRoot.calculateLayout(); } finally { Systrace.endSection(Systrace.TRACE_TAG_REACT_JAVA_BRIDGE); - mLayoutTimer = mLayoutTimer + ((double)System.nanoTime() - startTime) / 1000000.0; - mLayoutCount = mLayoutCount + 1; + mLastCalculateLayoutTime = SystemClock.uptimeMillis() - startTime; } } diff --git a/ReactAndroid/src/main/java/com/facebook/react/uimanager/UIManagerModule.java b/ReactAndroid/src/main/java/com/facebook/react/uimanager/UIManagerModule.java index 6e13dddf4..a8ed244b2 100644 --- a/ReactAndroid/src/main/java/com/facebook/react/uimanager/UIManagerModule.java +++ b/ReactAndroid/src/main/java/com/facebook/react/uimanager/UIManagerModule.java @@ -33,7 +33,6 @@ import com.facebook.react.uimanager.debug.NotThreadSafeViewHierarchyUpdateDebugL import com.facebook.react.uimanager.events.EventDispatcher; import com.facebook.systrace.Systrace; import com.facebook.systrace.SystraceMessage; -import java.util.HashMap; import java.util.List; import java.util.Map; import javax.annotation.Nullable; @@ -160,11 +159,9 @@ public class UIManagerModule extends ReactContextBaseJavaModule implements } } - public Map getPerformanceCounters() { - Map perfMap = new HashMap<>(); - perfMap.put("LayoutCount", mUIImplementation.getLayoutCount()); - perfMap.put("LayoutTimer", mUIImplementation.getLayoutTimer()); - return perfMap; + @Override + public Map getPerformanceCounters() { + return mUIImplementation.getProfiledBatchPerfCounters(); } /** diff --git a/ReactAndroid/src/main/java/com/facebook/react/uimanager/UIViewOperationQueue.java b/ReactAndroid/src/main/java/com/facebook/react/uimanager/UIViewOperationQueue.java index 49ef580de..462557813 100644 --- a/ReactAndroid/src/main/java/com/facebook/react/uimanager/UIViewOperationQueue.java +++ b/ReactAndroid/src/main/java/com/facebook/react/uimanager/UIViewOperationQueue.java @@ -9,12 +9,7 @@ package com.facebook.react.uimanager; -import javax.annotation.Nullable; -import javax.annotation.concurrent.GuardedBy; - -import java.util.ArrayDeque; -import java.util.ArrayList; - +import android.os.SystemClock; import com.facebook.common.logging.FLog; import com.facebook.react.animation.Animation; import com.facebook.react.animation.AnimationRegistry; @@ -31,6 +26,12 @@ import com.facebook.react.modules.core.ReactChoreographer; import com.facebook.react.uimanager.debug.NotThreadSafeViewHierarchyUpdateDebugListener; import com.facebook.systrace.Systrace; import com.facebook.systrace.SystraceMessage; +import java.util.ArrayDeque; +import java.util.ArrayList; +import java.util.HashMap; +import java.util.Map; +import javax.annotation.Nullable; +import javax.annotation.concurrent.GuardedBy; /** * This class acts as a buffer for command executed on {@link NativeViewHierarchyManager} or on @@ -542,6 +543,14 @@ public class UIViewOperationQueue { private @Nullable NotThreadSafeViewHierarchyUpdateDebugListener mViewHierarchyUpdateDebugListener; private boolean mIsDispatchUIFrameCallbackEnqueued = false; private boolean mIsInIllegalUIState = false; + private boolean mIsProfilingNextBatch = false; + private long mNonBatchedExecutionTotalTime; + private long mProfiledBatchCommitStartTime; + private long mProfiledBatchLayoutTime; + private long mProfiledBatchDispatchViewUpdatesTime; + private long mProfiledBatchRunStartTime; + private long mProfiledBatchBatchedExecutionTime; + private long mProfiledBatchNonBatchedExecutionTime; public UIViewOperationQueue( ReactApplicationContext reactContext, @@ -561,6 +570,22 @@ public class UIViewOperationQueue { mViewHierarchyUpdateDebugListener = listener; } + public void profileNextBatch() { + mIsProfilingNextBatch = true; + mProfiledBatchCommitStartTime = 0; + } + + public Map getProfiledBatchPerfCounters() { + Map perfMap = new HashMap<>(); + perfMap.put("CommitStartTime", mProfiledBatchCommitStartTime); + perfMap.put("LayoutTime", mProfiledBatchLayoutTime); + perfMap.put("DispatchViewUpdatesTime", mProfiledBatchDispatchViewUpdatesTime); + perfMap.put("RunStartTime", mProfiledBatchRunStartTime); + perfMap.put("BatchedExecutionTime", mProfiledBatchBatchedExecutionTime); + perfMap.put("NonBatchedExecutionTime", mProfiledBatchNonBatchedExecutionTime); + return perfMap; + } + public boolean isEmpty() { return mOperations.isEmpty(); } @@ -725,13 +750,16 @@ public class UIViewOperationQueue { mOperations.add(new UIBlockOperation(block)); } - /* package */ void dispatchViewUpdates(final int batchId) { + /* package */ void dispatchViewUpdates( + final int batchId, final long commitStartTime, final long layoutTime) { SystraceMessage.beginSection( Systrace.TRACE_TAG_REACT_JAVA_BRIDGE, "UIViewOperationQueue.dispatchViewUpdates") .arg("batchId", batchId) .flush(); try { + final long dispatchViewUpdatesTime = SystemClock.uptimeMillis(); + // Store the current operation queues to dispatch and create new empty ones to continue // receiving new operations final ArrayList batchedOperations; @@ -756,41 +784,72 @@ public class UIViewOperationQueue { mViewHierarchyUpdateDebugListener.onViewHierarchyUpdateEnqueued(); } - Runnable runOperations = new Runnable() { - @Override - public void run() { - SystraceMessage.beginSection(Systrace.TRACE_TAG_REACT_JAVA_BRIDGE, "DispatchUI") - .arg("BatchId", batchId) - .flush(); - try { - // All nonBatchedOperations should be executed before regular operations as - // regular operations may depend on them - if (nonBatchedOperations != null) { - for (UIOperation op : nonBatchedOperations) { - op.execute(); + Runnable runOperations = + new Runnable() { + @Override + public void run() { + SystraceMessage.beginSection(Systrace.TRACE_TAG_REACT_JAVA_BRIDGE, "DispatchUI") + .arg("BatchId", batchId) + .flush(); + try { + long runStartTime = SystemClock.uptimeMillis(); + + // All nonBatchedOperations should be executed before regular operations as + // regular operations may depend on them + if (nonBatchedOperations != null) { + for (UIOperation op : nonBatchedOperations) { + op.execute(); + } + } + + if (batchedOperations != null) { + for (UIOperation op : batchedOperations) { + op.execute(); + } + } + + if (mIsProfilingNextBatch && mProfiledBatchCommitStartTime == 0) { + mProfiledBatchCommitStartTime = commitStartTime; + mProfiledBatchLayoutTime = layoutTime; + mProfiledBatchDispatchViewUpdatesTime = dispatchViewUpdatesTime; + mProfiledBatchRunStartTime = runStartTime; + + Systrace.beginAsyncSection( + Systrace.TRACE_TAG_REACT_JAVA_BRIDGE, + "delayBeforeDispatchViewUpdates", + 0, + mProfiledBatchCommitStartTime * 1000000); + Systrace.endAsyncSection( + Systrace.TRACE_TAG_REACT_JAVA_BRIDGE, + "delayBeforeDispatchViewUpdates", + 0, + mProfiledBatchDispatchViewUpdatesTime * 1000000); + Systrace.beginAsyncSection( + Systrace.TRACE_TAG_REACT_JAVA_BRIDGE, + "delayBeforeBatchRunStart", + 0, + mProfiledBatchDispatchViewUpdatesTime * 1000000); + Systrace.endAsyncSection( + Systrace.TRACE_TAG_REACT_JAVA_BRIDGE, + "delayBeforeBatchRunStart", + 0, + mProfiledBatchRunStartTime * 1000000); + } + + // Clear layout animation, as animation only apply to current UI operations batch. + mNativeViewHierarchyManager.clearLayoutAnimation(); + + if (mViewHierarchyUpdateDebugListener != null) { + mViewHierarchyUpdateDebugListener.onViewHierarchyUpdateFinished(); + } + } catch (Exception e) { + mIsInIllegalUIState = true; + throw e; + } finally { + Systrace.endSection(Systrace.TRACE_TAG_REACT_JAVA_BRIDGE); } } - - if (batchedOperations != null) { - for (UIOperation op : batchedOperations) { - op.execute(); - } - } - - // Clear layout animation, as animation only apply to current UI operations batch. - mNativeViewHierarchyManager.clearLayoutAnimation(); - - if (mViewHierarchyUpdateDebugListener != null) { - mViewHierarchyUpdateDebugListener.onViewHierarchyUpdateFinished(); - } - } catch (Exception e) { - mIsInIllegalUIState = true; - throw e; - } finally { - Systrace.endSection(Systrace.TRACE_TAG_REACT_JAVA_BRIDGE); - } - } - }; + }; SystraceMessage.beginSection( Systrace.TRACE_TAG_REACT_JAVA_BRIDGE, @@ -832,12 +891,12 @@ public class UIViewOperationQueue { flushPendingBatches(); } - private void flushPendingBatches() { + private boolean flushPendingBatches() { if (mIsInIllegalUIState) { FLog.w( ReactConstants.TAG, "Not flushing pending UI operations because of previously thrown Exception"); - return; + return false; } final ArrayList runnables; @@ -850,11 +909,14 @@ public class UIViewOperationQueue { } } - if (runnables != null) { - for (Runnable runnable : runnables) { - runnable.run(); - } + if (runnables == null) { + return false; } + + for (Runnable runnable : runnables) { + runnable.run(); + } + return true; } /** @@ -897,7 +959,23 @@ public class UIViewOperationQueue { Systrace.endSection(Systrace.TRACE_TAG_REACT_JAVA_BRIDGE); } - flushPendingBatches(); + final long flushPendingBatchesStartTime = SystemClock.uptimeMillis(); + if (flushPendingBatches()) { + if (mIsProfilingNextBatch) { + mProfiledBatchBatchedExecutionTime = + SystemClock.uptimeMillis() - flushPendingBatchesStartTime; + mProfiledBatchNonBatchedExecutionTime = mNonBatchedExecutionTotalTime; + mIsProfilingNextBatch = false; + + Systrace.beginAsyncSection( + Systrace.TRACE_TAG_REACT_JAVA_BRIDGE, + "batchedExecutionTime", + 0, + flushPendingBatchesStartTime * 1000000); + Systrace.endAsyncSection(Systrace.TRACE_TAG_REACT_JAVA_BRIDGE, "batchedExecutionTime", 0); + } + mNonBatchedExecutionTotalTime = 0; + } ReactChoreographer.getInstance().postFrameCallback( ReactChoreographer.CallbackType.DISPATCH_UI, this); @@ -920,7 +998,10 @@ public class UIViewOperationQueue { } try { + long nonBatchedExecutionStartTime = SystemClock.uptimeMillis(); nextOperation.execute(); + mNonBatchedExecutionTotalTime += + SystemClock.uptimeMillis() - nonBatchedExecutionStartTime; } catch (Exception e) { mIsInIllegalUIState = true; throw e; diff --git a/ReactAndroid/src/main/java/com/facebook/systrace/Systrace.java b/ReactAndroid/src/main/java/com/facebook/systrace/Systrace.java index 343f44c45..85690d23b 100644 --- a/ReactAndroid/src/main/java/com/facebook/systrace/Systrace.java +++ b/ReactAndroid/src/main/java/com/facebook/systrace/Systrace.java @@ -74,12 +74,18 @@ public class Systrace { final int cookie) { } + public static void beginAsyncSection( + long tag, final String sectionName, final int cookie, final long startNanos) {} + public static void endAsyncSection( long tag, final String sectionName, final int cookie) { } + public static void endAsyncSection( + long tag, final String sectionName, final int cookie, final long endNanos) {} + public static void traceCounter( long tag, final String counterName,