Refactor logging of Fabric commit statistics

Summary:
This is a refactor of the logging of Fabric commit statistics to simplify the way we track performance points.

we'll later refactor and iterate on the API to integrate fabric perf point into developer tools

changelog: [internal] internal

Reviewed By: ShikaSD

Differential Revision: D34006700

fbshipit-source-id: 93a01accd90dfacc8b44edd158033b442a843284
This commit is contained in:
David Vacca
2022-02-16 00:23:59 -08:00
committed by Facebook GitHub Bot
parent 6ab5bb6869
commit 8dddff5547
2 changed files with 138 additions and 17 deletions
@@ -0,0 +1,129 @@
/*
* Copyright (c) Meta Platforms, Inc. and affiliates.
*
* This source code is licensed under the MIT license found in the
* LICENSE file in the root directory of this source tree.
*/
package com.facebook.react.fabric;
import static com.facebook.react.bridge.ReactMarkerConstants.*;
import androidx.annotation.Nullable;
import com.facebook.common.logging.FLog;
import com.facebook.react.bridge.ReactMarker;
import com.facebook.react.bridge.ReactMarkerConstants;
import java.util.HashMap;
import java.util.Map;
public class ConsoleReactFabricPerfLogger implements ReactMarker.FabricMarkerListener {
private final Map<Integer, FabricCommitPoint> mFabricCommitMarkers = new HashMap<>();
private static class FabricCommitPoint {
public long commitStart;
public long commitEnd;
public long finishTransactionStart;
public long finishTransactionEnd;
public long diffStart;
public long diffEnd;
public long updateUIMainThreadEnd;
public long layoutStart;
public long layoutEnd;
public long batchExecutionStart;
public long batchExecutionEnd;
public long updateUIMainThreadStart;
}
@Override
public void logFabricMarker(
ReactMarkerConstants name, @Nullable String tag, int instanceKey, long timestamp) {
if (isFabricCommitMarker(name)) {
FabricCommitPoint commitPoint = mFabricCommitMarkers.get(instanceKey);
if (commitPoint == null) {
commitPoint = new FabricCommitPoint();
mFabricCommitMarkers.put(instanceKey, commitPoint);
}
updateFabricCommitPoint(name, commitPoint, timestamp);
if (name == ReactMarkerConstants.FABRIC_BATCH_EXECUTION_END) {
FLog.i(
FabricUIManager.TAG,
"Statistic of Fabric commit #: "
+ instanceKey
+ "\n - Total commit time: "
+ (commitPoint.finishTransactionEnd - commitPoint.commitStart)
+ " ms.\n - Layout: "
+ (commitPoint.layoutEnd - commitPoint.layoutStart)
+ " ms.\n - Diffing: "
+ (commitPoint.diffEnd - commitPoint.diffStart)
+ " ms.\n"
+ " - FinishTransaction (Diffing + Processing + Serialization of MutationInstructions): "
+ (commitPoint.finishTransactionEnd - commitPoint.finishTransactionStart)
+ " ms.\n"
+ " - Mounting: "
+ (commitPoint.batchExecutionEnd - commitPoint.batchExecutionStart)
+ " ms.");
mFabricCommitMarkers.remove(instanceKey);
}
}
}
private static boolean isFabricCommitMarker(ReactMarkerConstants name) {
return name == FABRIC_COMMIT_START
|| name == FABRIC_COMMIT_END
|| name == FABRIC_FINISH_TRANSACTION_START
|| name == FABRIC_FINISH_TRANSACTION_END
|| name == FABRIC_DIFF_START
|| name == FABRIC_DIFF_END
|| name == FABRIC_LAYOUT_START
|| name == FABRIC_LAYOUT_END
|| name == FABRIC_BATCH_EXECUTION_START
|| name == FABRIC_BATCH_EXECUTION_END
|| name == FABRIC_UPDATE_UI_MAIN_THREAD_START
|| name == FABRIC_UPDATE_UI_MAIN_THREAD_END;
}
private static void updateFabricCommitPoint(
ReactMarkerConstants name, FabricCommitPoint commitPoint, long timestamp) {
switch (name) {
case FABRIC_COMMIT_START:
commitPoint.commitStart = timestamp;
break;
case FABRIC_COMMIT_END:
commitPoint.commitEnd = timestamp;
break;
case FABRIC_FINISH_TRANSACTION_START:
commitPoint.finishTransactionStart = timestamp;
break;
case FABRIC_FINISH_TRANSACTION_END:
commitPoint.finishTransactionEnd = timestamp;
break;
case FABRIC_DIFF_START:
commitPoint.diffStart = timestamp;
break;
case FABRIC_DIFF_END:
commitPoint.diffEnd = timestamp;
break;
case FABRIC_LAYOUT_START:
commitPoint.layoutStart = timestamp;
break;
case FABRIC_LAYOUT_END:
commitPoint.layoutEnd = timestamp;
break;
case FABRIC_BATCH_EXECUTION_START:
commitPoint.batchExecutionStart = timestamp;
break;
case FABRIC_BATCH_EXECUTION_END:
commitPoint.batchExecutionEnd = timestamp;
break;
case FABRIC_UPDATE_UI_MAIN_THREAD_START:
commitPoint.updateUIMainThreadStart = timestamp;
break;
case FABRIC_UPDATE_UI_MAIN_THREAD_END:
commitPoint.updateUIMainThreadEnd = timestamp;
break;
}
}
}
@@ -105,6 +105,7 @@ public class FabricUIManager implements UIManager, LifecycleEventListener {
ReactFeatureFlags.enableFabricLogs
|| PrinterHolder.getPrinter()
.shouldDisplayLogMessage(ReactDebugOverlayTags.FABRIC_UI_MANAGER);
public ConsoleReactFabricPerfLogger mConsoleReactFabricPerfLogger;
static {
FabricSoLoader.staticInit();
@@ -364,6 +365,10 @@ public class FabricUIManager implements UIManager, LifecycleEventListener {
public void initialize() {
mEventDispatcher.registerEventEmitter(FABRIC, new FabricEventEmitter(this));
mEventDispatcher.addBatchEventDispatchedListener(mEventBeatManager);
if (ENABLE_FABRIC_LOGS) {
mConsoleReactFabricPerfLogger = new ConsoleReactFabricPerfLogger();
ReactMarker.addFabricListener(mConsoleReactFabricPerfLogger);
}
}
// This is called on the JS thread (see CatalystInstanceImpl).
@@ -373,6 +378,10 @@ public class FabricUIManager implements UIManager, LifecycleEventListener {
public void onCatalystInstanceDestroy() {
FLog.i(TAG, "FabricUIManager.onCatalystInstanceDestroy");
if (mConsoleReactFabricPerfLogger != null) {
ReactMarker.removeFabricListener(mConsoleReactFabricPerfLogger);
}
if (mDestroyed) {
ReactSoftExceptionLogger.logSoftException(
FabricUIManager.TAG, new IllegalStateException("Cannot double-destroy FabricUIManager"));
@@ -767,23 +776,6 @@ public class FabricUIManager implements UIManager, LifecycleEventListener {
ReactMarker.logFabricMarker(
ReactMarkerConstants.FABRIC_LAYOUT_END, null, commitNumber, layoutEndTime);
ReactMarker.logFabricMarker(ReactMarkerConstants.FABRIC_COMMIT_END, null, commitNumber);
if (ENABLE_FABRIC_LOGS) {
FLog.i(
TAG,
"Statistic of Fabric commit #: "
+ commitNumber
+ "\n - Total commit time: "
+ (finishTransactionEndTime - commitStartTime)
+ " ms.\n - Layout: "
+ mLayoutTime
+ " ms.\n - Diffing: "
+ (diffEndTime - diffStartTime)
+ " ms.\n"
+ " - FinishTransaction (Diffing + Processing + Serialization of MountingInstructions): "
+ mFinishTransactionCPPTime
+ " ms.");
}
}
}