Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 9b2cdd9b authored by Fyodor Kupolov's avatar Fyodor Kupolov Committed by Android (Google) Code Review
Browse files

Merge "Additional boot metrics"

parents 6d5723fe 3235e0c2

core/java/android/util/BootTimingsTraceLog.java

0 → 100644
+65 −0
Original line number Original line Diff line number Diff line 
/*

 * Copyright (C) 2016 The Android Open Source Project

 *

 * Licensed under the Apache License, Version 2.0 (the "License");

 * you may not use this file except in compliance with the License.

 * You may obtain a copy of the License at

 *

 *      http://www.apache.org/licenses/LICENSE-2.0

 *

 * Unless required by applicable law or agreed to in writing, software

 * distributed under the License is distributed on an "AS IS" BASIS,

 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.

 * See the License for the specific language governing permissions and

 * limitations under the License

 */



package android.util;



import android.os.Build;

import android.os.SystemClock;

import android.os.Trace;



import java.util.ArrayDeque;

import java.util.Deque;



/**

 * Helper class for reporting boot timing metrics.

 * @hide

 */

public class BootTimingsTraceLog {

    // Debug boot time for every step if it's non-user build.

    private static final boolean DEBUG_BOOT_TIME = !"user".equals(Build.TYPE);

    private final Deque<Pair<String, Long>> mStartTimes

            = DEBUG_BOOT_TIME ? new ArrayDeque<>() : null;

    private final String mTag;

    private long mTraceTag;



    public BootTimingsTraceLog(String tag, long traceTag) {

        mTag = tag;

        mTraceTag = traceTag;

    }



    public void traceBegin(String name) {

        Trace.traceBegin(mTraceTag, name);

        if (DEBUG_BOOT_TIME) {

            mStartTimes.push(Pair.create(name, SystemClock.elapsedRealtime()));

        }

    }



    public void traceEnd() {

        Trace.traceEnd(mTraceTag);

        if (!DEBUG_BOOT_TIME) {

            return;

        }

        // Pop the top element without throwing NoSuchElementException

        Pair<String, Long> event = mStartTimes.pollFirst();

        if (event == null) {

            Slog.w(mTag, "traceEnd called more times than traceBegin");

            return;

        }

        // Log the duration so it can be parsed by external tools for performance reporting

        Slog.d(mTag, event.first + " took to complete: "

                + (SystemClock.elapsedRealtime() - event.second) + "ms");

    }

}

core/java/com/android/internal/os/WrapperInit.java

+4 −1
Original line number Original line Diff line number Diff line
@@ -17,6 +17,8 @@ 
package com.android.internal.os;

package com.android.internal.os;





import android.os.Process;

import android.os.Process;

import android.os.Trace;

import android.util.BootTimingsTraceLog;

import android.util.Slog;

import android.util.Slog;





import dalvik.system.VMRuntime;

import dalvik.system.VMRuntime;
@@ -75,7 +77,8 @@ public class WrapperInit { 
            }

            }





            // Mimic system Zygote preloading.

            // Mimic system Zygote preloading.

            ZygoteInit.preload();

            ZygoteInit.preload(new BootTimingsTraceLog("WrapperInitTiming",

                    Trace.TRACE_TAG_DALVIK));





            // Launch the application.

            // Launch the application.

            String[] runtimeArgs = new String[args.length - 2];

            String[] runtimeArgs = new String[args.length - 2];

core/java/com/android/internal/os/ZygoteInit.java

+24 −15
Original line number Original line Diff line number Diff line
@@ -36,11 +36,13 @@ import android.system.ErrnoException; 
import android.system.Os;

import android.system.Os;

import android.system.OsConstants;

import android.system.OsConstants;

import android.text.Hyphenator;

import android.text.Hyphenator;

import android.util.BootTimingsTraceLog;

import android.util.EventLog;

import android.util.EventLog;

import android.util.Log;

import android.util.Log;

import android.webkit.WebViewFactory;

import android.webkit.WebViewFactory;

import android.widget.TextView;

import android.widget.TextView;





import com.android.internal.logging.MetricsLogger;

import com.android.internal.os.InstallerConnection.InstallerException;

import com.android.internal.os.InstallerConnection.InstallerException;





import dalvik.system.DexFile;

import dalvik.system.DexFile;
@@ -106,20 +108,20 @@ public class ZygoteInit { 
    private static final int ROOT_UID = 0;

    private static final int ROOT_UID = 0;

    private static final int ROOT_GID = 0;

    private static final int ROOT_GID = 0;





    static void preload() {

    static void preload(BootTimingsTraceLog bootTimingsTraceLog) {

        Log.d(TAG, "begin preload");

        Log.d(TAG, "begin preload");

        Trace.traceBegin(Trace.TRACE_TAG_DALVIK, "BeginIcuCachePinning");

        bootTimingsTraceLog.traceBegin("BeginIcuCachePinning");

        beginIcuCachePinning();

        beginIcuCachePinning();

        Trace.traceEnd(Trace.TRACE_TAG_DALVIK);

        bootTimingsTraceLog.traceEnd(); // BeginIcuCachePinning

        Trace.traceBegin(Trace.TRACE_TAG_DALVIK, "PreloadClasses");

        bootTimingsTraceLog.traceBegin("PreloadClasses");

        preloadClasses();

        preloadClasses();

        Trace.traceEnd(Trace.TRACE_TAG_DALVIK);

        bootTimingsTraceLog.traceEnd(); // PreloadClasses

        Trace.traceBegin(Trace.TRACE_TAG_DALVIK, "PreloadResources");

        bootTimingsTraceLog.traceBegin("PreloadResources");

        preloadResources();

        preloadResources();

        Trace.traceEnd(Trace.TRACE_TAG_DALVIK);

        bootTimingsTraceLog.traceEnd(); // PreloadResources

        Trace.traceBegin(Trace.TRACE_TAG_DALVIK, "PreloadOpenGL");

        bootTimingsTraceLog.traceBegin("PreloadOpenGL");

        preloadOpenGL();

        preloadOpenGL();

        Trace.traceEnd(Trace.TRACE_TAG_DALVIK);

        bootTimingsTraceLog.traceEnd(); // PreloadOpenGL

        preloadSharedLibraries();

        preloadSharedLibraries();

        preloadTextResources();

        preloadTextResources();

        // Ask the WebViewFactory to do any initialization that must run in the zygote process,

        // Ask the WebViewFactory to do any initialization that must run in the zygote process,
@@ -639,7 +641,13 @@ public class ZygoteInit { 
        }

        }





        try {

        try {

            Trace.traceBegin(Trace.TRACE_TAG_DALVIK, "ZygoteInit");

            // Report Zygote start time to tron

            MetricsLogger.histogram(null, "boot_zygote_init", (int) SystemClock.uptimeMillis());



            String bootTimeTag = Process.is64Bit() ? "Zygote64Timing" : "Zygote32Timing";

            BootTimingsTraceLog bootTimingsTraceLog = new BootTimingsTraceLog(bootTimeTag,

                    Trace.TRACE_TAG_DALVIK);

            bootTimingsTraceLog.traceBegin("ZygoteInit");

            RuntimeInit.enableDdms();

            RuntimeInit.enableDdms();

            // Start profiling the zygote initialization.

            // Start profiling the zygote initialization.

            SamplingProfilerIntegration.start();

            SamplingProfilerIntegration.start();
@@ -664,22 +672,23 @@ public class ZygoteInit { 
            }

            }





            zygoteServer.registerServerSocket(socketName);

            zygoteServer.registerServerSocket(socketName);

            Trace.traceBegin(Trace.TRACE_TAG_DALVIK, "ZygotePreload");

            bootTimingsTraceLog.traceBegin("ZygotePreload");

            EventLog.writeEvent(LOG_BOOT_PROGRESS_PRELOAD_START,

            EventLog.writeEvent(LOG_BOOT_PROGRESS_PRELOAD_START,

                SystemClock.uptimeMillis());

                SystemClock.uptimeMillis());

            preload();

            preload(bootTimingsTraceLog);

            EventLog.writeEvent(LOG_BOOT_PROGRESS_PRELOAD_END,

            EventLog.writeEvent(LOG_BOOT_PROGRESS_PRELOAD_END,

                SystemClock.uptimeMillis());

                SystemClock.uptimeMillis());

            Trace.traceEnd(Trace.TRACE_TAG_DALVIK);

            bootTimingsTraceLog.traceEnd(); // ZygotePreload





            // Finish profiling the zygote initialization.

            // Finish profiling the zygote initialization.

            SamplingProfilerIntegration.writeZygoteSnapshot();

            SamplingProfilerIntegration.writeZygoteSnapshot();





            // Do an initial gc to clean up after startup

            // Do an initial gc to clean up after startup

            Trace.traceBegin(Trace.TRACE_TAG_DALVIK, "PostZygoteInitGC");

            bootTimingsTraceLog.traceBegin("PostZygoteInitGC");

            gcAndFinalize();

            gcAndFinalize();

            Trace.traceEnd(Trace.TRACE_TAG_DALVIK);

            bootTimingsTraceLog.traceEnd(); // PostZygoteInitGC





            bootTimingsTraceLog.traceEnd(); // ZygoteInit

            // Disable tracing so that forked processes do not inherit stale tracing tags from

            // Disable tracing so that forked processes do not inherit stale tracing tags from

            // Zygote.

            // Zygote.

            Trace.setTracingEnabled(false);

            Trace.setTracingEnabled(false);

services/java/com/android/server/SystemServer.java

+11 −27
Original line number Original line Diff line number Diff line
@@ -41,12 +41,10 @@ import android.os.SystemClock; 
import android.os.SystemProperties;

import android.os.SystemProperties;

import android.os.Trace;

import android.os.Trace;

import android.os.UserHandle;

import android.os.UserHandle;

import android.os.UserManager;

import android.os.storage.IStorageManager;

import android.os.storage.IStorageManager;

import android.provider.Settings;

import android.util.BootTimingsTraceLog;

import android.util.DisplayMetrics;

import android.util.DisplayMetrics;

import android.util.EventLog;

import android.util.EventLog;

import android.util.Pair;

import android.util.Slog;

import android.util.Slog;

import android.view.WindowManager;

import android.view.WindowManager;
@@ -55,7 +53,6 @@ import com.android.internal.app.NightDisplayController; 
import com.android.internal.logging.MetricsLogger;

import com.android.internal.logging.MetricsLogger;

import com.android.internal.os.BinderInternal;

import com.android.internal.os.BinderInternal;

import com.android.internal.os.SamplingProfilerIntegration;

import com.android.internal.os.SamplingProfilerIntegration;

import com.android.internal.os.ZygoteInit;

import com.android.internal.policy.EmergencyAffordanceManager;

import com.android.internal.policy.EmergencyAffordanceManager;

import com.android.internal.widget.ILockSettings;

import com.android.internal.widget.ILockSettings;

import com.android.server.accessibility.AccessibilityManagerService;

import com.android.server.accessibility.AccessibilityManagerService;
@@ -102,8 +99,8 @@ import com.android.server.statusbar.StatusBarManagerService; 
import com.android.server.storage.DeviceStorageMonitorService;

import com.android.server.storage.DeviceStorageMonitorService;

import com.android.server.telecom.TelecomLoaderService;

import com.android.server.telecom.TelecomLoaderService;

import com.android.server.trust.TrustManagerService;

import com.android.server.trust.TrustManagerService;

import com.android.server.tv.TvRemoteService;

import com.android.server.tv.TvInputManagerService;

import com.android.server.tv.TvInputManagerService;

import com.android.server.tv.TvRemoteService;

import com.android.server.twilight.TwilightService;

import com.android.server.twilight.TwilightService;

import com.android.server.usage.UsageStatsService;

import com.android.server.usage.UsageStatsService;

import com.android.server.vr.VrManagerService;

import com.android.server.vr.VrManagerService;
@@ -112,8 +109,6 @@ import com.android.server.wm.WindowManagerService; 




import dalvik.system.VMRuntime;

import dalvik.system.VMRuntime;





import java.util.ArrayDeque;

import java.util.Deque;

import java.io.File;

import java.io.File;

import java.io.IOException;

import java.io.IOException;

import java.util.Locale;

import java.util.Locale;
@@ -125,11 +120,8 @@ import static android.view.Display.DEFAULT_DISPLAY; 
public final class SystemServer {

public final class SystemServer {

    private static final String TAG = "SystemServer";

    private static final String TAG = "SystemServer";





    private static final boolean LOG_BOOT_TIME = true;

    private static final BootTimingsTraceLog BOOT_TIMINGS_TRACE_LOG

    // Debug boot time for every step if it's non-user build.

            = new BootTimingsTraceLog("SystemServerTiming", Trace.TRACE_TAG_SYSTEM_SERVER);

    private static final boolean DEBUG_BOOT_TIME = LOG_BOOT_TIME && !"user".equals(Build.TYPE);

    private static final String TAG_BOOT_TIME = "SystemServerTiming";

    private static final Deque<Pair<String, Long>> START_TIMES = new ArrayDeque<>();





    private static final String ENCRYPTING_STATE = "trigger_restart_min_framework";

    private static final String ENCRYPTING_STATE = "trigger_restart_min_framework";

    private static final String ENCRYPTED_STATE = "1";

    private static final String ENCRYPTED_STATE = "1";
@@ -279,6 +271,11 @@ public final class SystemServer { 
            int uptimeMillis = (int) SystemClock.uptimeMillis();

            int uptimeMillis = (int) SystemClock.uptimeMillis();

            EventLog.writeEvent(EventLogTags.BOOT_PROGRESS_SYSTEM_RUN, uptimeMillis);

            EventLog.writeEvent(EventLogTags.BOOT_PROGRESS_SYSTEM_RUN, uptimeMillis);

            MetricsLogger.histogram(null, "boot_system_server_init", uptimeMillis);

            MetricsLogger.histogram(null, "boot_system_server_init", uptimeMillis);

            // Also report when first stage of init has started

            long initStartNs = SystemProperties.getLong("init.start", -1);

            if (initStartNs >= 0) {

                MetricsLogger.histogram(null, "boot_android_init", (int)(initStartNs / 1000000));

            }





            // In case the runtime switched since last boot (such as when

            // In case the runtime switched since last boot (such as when

            // the old runtime was removed in an OTA), set the system

            // the old runtime was removed in an OTA), set the system
@@ -1643,24 +1640,11 @@ public final class SystemServer { 
    }

    }





    private static void traceBeginAndSlog(String name) {

    private static void traceBeginAndSlog(String name) {

        Trace.traceBegin(Trace.TRACE_TAG_SYSTEM_SERVER, name);

        Slog.i(TAG, name);

        Slog.i(TAG, name);

        if (DEBUG_BOOT_TIME) {

        BOOT_TIMINGS_TRACE_LOG.traceBegin(name);

            START_TIMES.push(Pair.create(name, Long.valueOf(SystemClock.elapsedRealtime())));

        }

    }

    }





    private static void traceEnd() {

    private static void traceEnd() {

        Trace.traceEnd(Trace.TRACE_TAG_SYSTEM_SERVER);

        BOOT_TIMINGS_TRACE_LOG.traceEnd();

        if (!DEBUG_BOOT_TIME) {

            return;

        }

        Pair<String, Long> event = START_TIMES.pollFirst();

        if (event == null) {

            Slog.w(TAG, "traceEnd called more times than traceBeginAndSlog");

            return;

        }

        Slog.d(TAG_BOOT_TIME, event.first + " took to complete: "

                + (SystemClock.elapsedRealtime() - event.second) + "ms");

    }

    }

}
 
}