Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Android: Log basic initialization performance numbers. #25559

Closed
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
15 changes: 15 additions & 0 deletions ReactAndroid/src/main/java/com/facebook/react/ReactNativeHost.java
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,7 @@ public abstract class ReactNativeHost {

private final Application mApplication;
private @Nullable ReactInstanceManager mReactInstanceManager;
private @Nullable ReactPerformanceLogger mReactPerformanceLogger;

protected ReactNativeHost(Application application) {
mApplication = application;
Expand All @@ -34,13 +35,23 @@ protected ReactNativeHost(Application application) {
/** Get the current {@link ReactInstanceManager} instance, or create one. */
public ReactInstanceManager getReactInstanceManager() {
if (mReactInstanceManager == null) {
// Ensure {@link ReactPerformanceLogger} exists before we create {@link ReactInstanceManager}.
getReactPerformanceLogger();
ReactMarker.logMarker(ReactMarkerConstants.GET_REACT_INSTANCE_MANAGER_START);
mReactInstanceManager = createReactInstanceManager();
ReactMarker.logMarker(ReactMarkerConstants.GET_REACT_INSTANCE_MANAGER_END);
}
return mReactInstanceManager;
}

/** Get the current {@link ReactPerformanceLogger} instance, or create one. */
public ReactPerformanceLogger getReactPerformanceLogger() {
if (mReactPerformanceLogger == null) {
mReactPerformanceLogger = new ReactPerformanceLogger();
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why can't this be a singleton ? I am not sure if we are using this instance variable anywhere else.

}
return mReactPerformanceLogger;
}

/**
* Get whether this holder contains a {@link ReactInstanceManager} instance, or not. I.e. if
* {@link #getReactInstanceManager()} has been called at least once since this object was created
Expand All @@ -58,6 +69,10 @@ public void clear() {
mReactInstanceManager.destroy();
mReactInstanceManager = null;
}
if (mReactPerformanceLogger != null) {
mReactPerformanceLogger.release();
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What happens when app is reloaded in DEV mode ? Will the markers continue to aggregate ?

mReactPerformanceLogger = null;
}
}

protected ReactInstanceManager createReactInstanceManager() {
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,93 @@
/**
* Copyright (c) Facebook, Inc. and its affiliates.
*
* <p>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;

import android.util.Log;

import com.facebook.react.bridge.ReactMarker;
import com.facebook.react.bridge.ReactMarkerConstants;
import com.facebook.react.common.annotations.VisibleForTesting;

import javax.annotation.Nullable;

import static com.facebook.react.bridge.ReactMarkerConstants.RUN_JS_BUNDLE_END;

public class ReactPerformanceLogger implements ReactMarker.MarkerListener {

public enum Tag {
BRIDGE_STARTUP,
SCRIPT_EXECUTION,
}

private static final String TAG = ReactPerformanceLogger.class.getSimpleName();

private long[][] mData = new long[Tag.values().length][2];
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

How is mData exposed to the apps ? Whats the API to consume this ?


public ReactPerformanceLogger() {
ReactMarker.addListener(this);
}

public long getDuration(Tag tag) {
return mData[tag.ordinal()][1] - mData[tag.ordinal()][0];
}

public void release() {
ReactMarker.removeListener(this);
}

@Override
public void logMarker(ReactMarkerConstants name, @Nullable String tag, int instanceKey) {
switch (name) {
case GET_REACT_INSTANCE_MANAGER_START:
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why are we only marking these ? Why not just pick up all markers that RN gives ?

markStart(Tag.BRIDGE_STARTUP);
break;

case RUN_JS_BUNDLE_END:
markStop(Tag.SCRIPT_EXECUTION);
break;

case CHANGE_THREAD_PRIORITY:
// Due to a bug, RUN_JS_BUNDLE_END may not be triggered:
// https://github.com/facebook/react-native/issues/23771
if (getDuration(Tag.SCRIPT_EXECUTION) < 0) {
logMarker(RUN_JS_BUNDLE_END, tag, instanceKey);
}
markStop(Tag.BRIDGE_STARTUP);
break;

case PRE_RUN_JS_BUNDLE_START:
markStart(Tag.SCRIPT_EXECUTION);
break;

default:
break;
}
}

private void markStart(Tag tag) {
markStart(tag, System.currentTimeMillis());
}

private void markStop(Tag tag) {
markStop(tag, System.currentTimeMillis());
}

@VisibleForTesting
public void markStart(Tag tag, long timestamp) {
mData[tag.ordinal()][0] = timestamp;
mData[tag.ordinal()][1] = 0;
}

@VisibleForTesting
public void markStop(Tag tag, long timestamp) {
if (mData[tag.ordinal()][0] == 0 || mData[tag.ordinal()][1] != 0) {
Log.i(TAG, "Unbalanced start/end calls for tag " + tag.name());
} else {
mData[tag.ordinal()][1] = timestamp;
}
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,109 @@
package com.facebook.react;

import android.util.Log;

import org.junit.Test;
import org.junit.runner.RunWith;
import org.robolectric.RobolectricTestRunner;
import org.robolectric.annotation.Config;
import org.robolectric.annotation.Implements;

import static com.facebook.react.bridge.ReactMarkerConstants.CHANGE_THREAD_PRIORITY;
import static com.facebook.react.bridge.ReactMarkerConstants.GET_REACT_INSTANCE_MANAGER_START;
import static com.facebook.react.bridge.ReactMarkerConstants.PRE_RUN_JS_BUNDLE_START;
import static com.facebook.react.bridge.ReactMarkerConstants.RUN_JS_BUNDLE_END;
import static org.fest.assertions.api.Assertions.assertThat;

/** Test case for {@link ReactPerformanceLogger}. */
@RunWith(RobolectricTestRunner.class)
@Config(manifest=Config.NONE, shadows={ReactPerformanceLoggerTest.ShadowLog.class})
public final class ReactPerformanceLoggerTest {

@Test
public void logsDuration() {
ReactPerformanceLogger logger = new ReactPerformanceLogger();
assertThat(logger.getDuration(ReactPerformanceLogger.Tag.BRIDGE_STARTUP)).isEqualTo(0);

logger.markStop(ReactPerformanceLogger.Tag.BRIDGE_STARTUP, 1);
assertThat(logger.getDuration(ReactPerformanceLogger.Tag.BRIDGE_STARTUP)).isEqualTo(0);

logger.markStart(ReactPerformanceLogger.Tag.BRIDGE_STARTUP, 1000);
assertThat(logger.getDuration(ReactPerformanceLogger.Tag.BRIDGE_STARTUP)).isLessThan(0);

logger.markStop(ReactPerformanceLogger.Tag.BRIDGE_STARTUP, 2500);
assertThat(logger.getDuration(ReactPerformanceLogger.Tag.BRIDGE_STARTUP)).isEqualTo(1500);

logger.markStart(ReactPerformanceLogger.Tag.BRIDGE_STARTUP, 3000);
assertThat(logger.getDuration(ReactPerformanceLogger.Tag.BRIDGE_STARTUP)).isLessThan(0);

logger.markStart(ReactPerformanceLogger.Tag.BRIDGE_STARTUP, 3500);
assertThat(logger.getDuration(ReactPerformanceLogger.Tag.BRIDGE_STARTUP)).isLessThan(0);

logger.markStop(ReactPerformanceLogger.Tag.BRIDGE_STARTUP, 4500);
assertThat(logger.getDuration(ReactPerformanceLogger.Tag.BRIDGE_STARTUP)).isEqualTo(1000);

logger.markStop(ReactPerformanceLogger.Tag.BRIDGE_STARTUP, 9000);
assertThat(logger.getDuration(ReactPerformanceLogger.Tag.BRIDGE_STARTUP)).isEqualTo(1000);
}

@Test
public void handlesUnbalancedCalls() {
ReactPerformanceLogger logger = new ReactPerformanceLogger();
assertThat(logger.getDuration(ReactPerformanceLogger.Tag.SCRIPT_EXECUTION)).isEqualTo(0);

logger.logMarker(RUN_JS_BUNDLE_END, null, 0);
assertThat(logger.getDuration(ReactPerformanceLogger.Tag.SCRIPT_EXECUTION)).isEqualTo(0);

logger.logMarker(PRE_RUN_JS_BUNDLE_START, null, 0);
assertThat(logger.getDuration(ReactPerformanceLogger.Tag.SCRIPT_EXECUTION)).isLessThan(0);

logger.logMarker(PRE_RUN_JS_BUNDLE_START, null, 0);
assertThat(logger.getDuration(ReactPerformanceLogger.Tag.SCRIPT_EXECUTION)).isLessThan(0);

logger.logMarker(RUN_JS_BUNDLE_END, null, 0);
final long duration = logger.getDuration(ReactPerformanceLogger.Tag.SCRIPT_EXECUTION);
assertThat(duration).isGreaterThanOrEqualTo(0);

logger.logMarker(RUN_JS_BUNDLE_END, null, 0);
assertThat(logger.getDuration(ReactPerformanceLogger.Tag.SCRIPT_EXECUTION)).isEqualTo(duration);

logger.logMarker(PRE_RUN_JS_BUNDLE_START, null, 0);
assertThat(logger.getDuration(ReactPerformanceLogger.Tag.SCRIPT_EXECUTION)).isLessThan(0);
}

@Test
public void logsBridgeStartupDuration() {
ReactPerformanceLogger logger = new ReactPerformanceLogger();
assertThat(logger.getDuration(ReactPerformanceLogger.Tag.BRIDGE_STARTUP)).isEqualTo(0);

logger.logMarker(GET_REACT_INSTANCE_MANAGER_START, null, 0);
assertThat(logger.getDuration(ReactPerformanceLogger.Tag.BRIDGE_STARTUP)).isLessThan(0);

logger.logMarker(CHANGE_THREAD_PRIORITY, null, 0);
assertThat(logger.getDuration(ReactPerformanceLogger.Tag.BRIDGE_STARTUP)).isGreaterThanOrEqualTo(0);
}

@Test
public void logsScriptExecutionDuration() {
ReactPerformanceLogger logger = new ReactPerformanceLogger();
assertThat(logger.getDuration(ReactPerformanceLogger.Tag.SCRIPT_EXECUTION)).isEqualTo(0);

logger.logMarker(PRE_RUN_JS_BUNDLE_START, null, 0);
assertThat(logger.getDuration(ReactPerformanceLogger.Tag.SCRIPT_EXECUTION)).isLessThan(0);

logger.logMarker(RUN_JS_BUNDLE_END, null, 0);
assertThat(logger.getDuration(ReactPerformanceLogger.Tag.SCRIPT_EXECUTION)).isGreaterThanOrEqualTo(0);
}

@SuppressWarnings("unused")
@Implements(Log.class)
public static class ShadowLog {
public static int d(String tag, String msg) {
return 0;
}

public static int i(String tag, String msg) {
return 0;
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -11,9 +11,11 @@
import static org.mockito.Mockito.doAnswer;
import static org.mockito.Mockito.mock;

import android.annotation.TargetApi;
import android.graphics.Color;
import android.graphics.Typeface;
import android.graphics.drawable.Drawable;
import android.os.Build;
import android.text.Layout;
import android.text.Spanned;
import android.text.TextUtils;
Expand Down