Permalink
Browse files

Add more perf counters

Reviewed By: AaaChiuuu

Differential Revision: D5624307

fbshipit-source-id: a7fd744b7a1989f35efe99d7471337a411870934
  • Loading branch information...
alexeylang authored and facebook-github-bot committed Aug 17, 2017
1 parent 3c12faf commit caaf7fd417e974d32bfaf8a8bd35e7a6e5b99f3d
@@ -11,5 +11,5 @@
import java.util.Map;
public interface PerformanceCounter {
public Map<String,Double> getPerformanceCounters();
public Map<String, Long> getPerformanceCounters();
}
@@ -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.yoga.YogaDirection;
import java.util.Arrays;
import java.util.List;
import java.util.Map;
import javax.annotation.Nullable;
/**
@@ -43,8 +45,7 @@
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 void updateNodeSize(
}
}
public double getLayoutCount() {
return mLayoutCount;
public void profileNextBatch() {
mOperationsQueue.profileNextBatch();
}
public double getLayoutTimer() {
return mLayoutTimer;
public Map<String, Long> getProfiledBatchPerfCounters() {
return mOperationsQueue.getProfiledBatchPerfCounters();
}
/**
@@ -555,10 +556,11 @@ public void dispatchViewUpdates(int batchId) {
"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 @@ protected void calculateRootLayout(ReactShadowNode cssRoot) {
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;
}
}
@@ -33,7 +33,6 @@
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 void onCatalystInstanceDestroy() {
}
}
public Map<String,Double> getPerformanceCounters() {
Map<String,Double> perfMap = new HashMap<>();
perfMap.put("LayoutCount", mUIImplementation.getLayoutCount());
perfMap.put("LayoutTimer", mUIImplementation.getLayoutTimer());
return perfMap;
@Override
public Map<String, Long> getPerformanceCounters() {
return mUIImplementation.getProfiledBatchPerfCounters();
}
/**
@@ -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.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 void execute() {
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 void setViewHierarchyUpdateDebugListener(
mViewHierarchyUpdateDebugListener = listener;
}
public void profileNextBatch() {
mIsProfilingNextBatch = true;
mProfiledBatchCommitStartTime = 0;
}
public Map<String, Long> getProfiledBatchPerfCounters() {
Map<String, Long> 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 void enqueueUIBlock(UIBlock block) {
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<UIOperation> batchedOperations;
@@ -756,41 +784,72 @@ public void enqueueUIBlock(UIBlock block) {
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();
}
}
if (batchedOperations != null) {
for (UIOperation op : batchedOperations) {
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);
}
}
// 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 void runGuarded() {
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<Runnable> runnables;
@@ -850,11 +909,14 @@ private void flushPendingBatches() {
}
}
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 void doFrameGuarded(long frameTimeNanos) {
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 @@ private void dispatchPendingNonBatchedOperations(long frameTimeNanos) {
}
try {
long nonBatchedExecutionStartTime = SystemClock.uptimeMillis();
nextOperation.execute();
mNonBatchedExecutionTotalTime +=
SystemClock.uptimeMillis() - nonBatchedExecutionStartTime;
} catch (Exception e) {
mIsInIllegalUIState = true;
throw e;
@@ -74,12 +74,18 @@ public static void beginAsyncSection(
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,

0 comments on commit caaf7fd

Please sign in to comment.