Android 开机时间慢问题debug

2019-07-14 03:16发布

开机流程

Step 1启动电源以及系统启动

当电源按下,引导芯片代码开始从预定义的地方(固化在ROM)开始执行。加载引导程序到RAM,然后执行。

Step2 : bootloader

引导程序是在Android操作系统开始运行前的一个小程序。引导程序是运行的第一个程序,因此它是针对特定的主板与芯片的。 引导程序分两个阶段执行。第一个阶段,检测外部的RAM以及加载对第二阶段有用的程序;第二阶段,引导程序设置网络、内存等等。这些对于运行内核是必要的,为了达到特殊的目标,引导程序可以根据配置参数或者输入数据设置内核。 Android引导程序可以在bootableootloader



Step3: kernel

内核启动时,设置缓存、被保护存储器、计划列表,加载驱动。当内核完成系统设置,它首先在系统文件中寻找”init”文件,然后启动root进程或者系统的第一个进程。

Step4init

init是第一个进程,我们可以说它是root进程或者说有进程的父进程。init进程有两个责任,一是挂载目录,比如/sys/dev/proc,二是运行init.rc脚本。
  • init进程可以在/system/core/init找到
  • init.rc文件可以在/system/core/rootdir/init.rc 

Step 5 : Native service 启动

在此阶段,会启动android Native service 包括 Zygote,sufaceFlinger,media server,bootanimation 等。

Step 6Javaservice 启动

在此阶段,android 会启动java的service。并进行package的扫描,包括所有的app以及其所有的package,并且会 check所有的app是否进行了oat的优化如果没有则进行oat的优化。

Step 7:启动Home界面

一旦系统服务在内存中跑起来了,Android便启动home界面。Home界面启动完成后,会check wallpaper和 keygurd 是否 draw 完,如果已经draw完,则会设置service.bootanim.exit
为1,然后bootanimation 结束,界面显示完毕。

Debug

从上面的流程知道,开机问题分为kernel
部分和user
space 
部分,下面讨论之。

Kernel

Kernel 又可分为两部分,包括bootloader 部分和driver 加载部分。
  1. bootloader 我们可以从dmesg 中发现bootloderKPI并且计算其时间如:   [   0.416193] KPI: Bootloader start count = 23762   //A LK 开始时间 [   0.416205] KPI: Bootloader end count = 239354   //B LK 结束时间 [   0.416212] KPI: Bootloader display count = 37127 [   0.416219] KPI: Bootloader load kernel count = 2321 [   0.416226] KPI: Kernel XXX timestamp = 260735 // C bootloader 完成时间 [   0.416232] KPI: Kernel XXX Clock frequency = 32768   //D clock   我们可以通过下面的算法来确认相关的时间。如果发现时间太长,请debug 相关部分。 Step1 时间:A/D23762 /32768=0.72s
    LK 时间:(B-A)/D=(23935423762 /327686.57s Bootloader 时间:C/Dkmsg(C)= 260735 /32768-0.416226=7.54s 需要注意的是如果是eng 版本Bootloader的时间会多增加5s
  2. driver 在上面linux启动阶段(step3),linux会加载很多driver,以及console等。加载console是比较耗时的操作(0.5s4s),所以如果没有必要,可以去掉console来优化启动时间。对于其他driver需要注意的是touchdrivercamera sensorLCD driver 我们也可以通过添加打印module initlog,来check每个module初始化时的时间。从而找到花费时间比较多的module
--- a/init/main.c +++ b/init/main.c @@ -785,7 +785,7 @@ int __init_or_module
do_one_initcall(initcall_t fn)
        if (initcall_blacklisted(fn))                 return
-EPERM;
-       if (initcall_debug) +       if (1)                 ret =
do_one_initcall_debug(fn);


static int __init_or_module do_one_initcall_debug(initcall_t fn)
{
 ktime_t calltime, delta, rettime;
 unsigned long long duration;
 int ret;  printk(KERN_DEBUG "calling  %pF @ %i ", fn, task_pid_nr(current));
 calltime = ktime_get();
 ret = fn();
 rettime = ktime_get();
 delta = ktime_sub(rettime, calltime);
 duration = (unsigned long long) ktime_to_ns(delta) >> 10;
 printk(KERN_DEBUG "initcall %pF returned %d after %lld usecs ",
   fn, ret, duration);
 return ret;
}


User Space adb logcat -v threadtime -b events > logcat_envents.txt adb logcat -v threadtime > logcat.txt

Boot Event

我们可以通过查看event来确定是哪部分花时比较多。 // user space 开始时间 07-06 22:18:00.136 I/boot_progress_start(  407): 15528  //systemclock.uptimemillis(),开机到当前时间,毫秒。 //Zygote 进程preload 开始时间 32bit zygote 07-06 22:18:03.846 I/boot_progress_preload_start(  407): 19238 //Zygote 进程preload 开始时间64bit zygote 07-06 22:18:04.551 I/boot_progress_preload_start(  408): 19943 //Zygote 进程preload 结束时间32bit zygot 07-06 22:18:06.313 I/boot_progress_preload_end(  407): 21705 //Zygote 进程preload 结束时间64bit zygote 07-06 22:18:06.356 I/boot_progress_preload_end(  408): 21747 //System server 开始运行时间 07-06 22:18:06.462 I/boot_progress_system_run( 2182): 21853 //Package Scan 开始 07-06 22:18:06.784 I/boot_progress_pms_start( 2182): 22176 //System 目录开始scan 07-06 22:18:06.899 I/boot_progress_pms_system_scan_start(2182): 22290 //data 目录开始scan 07-06 22:18:38.644 I/boot_progress_pms_data_scan_start(2182): 54036 //package scan 结束时间 07-06 22:18:38.660 I/boot_progress_pms_scan_end( 2182):54052 //package manager ready 07-06 22:18:38.882 I/boot_progress_pms_ready( 2182): 54274 //Activity manager ready,这个事件之后便会启动home Activity 07-06 22:21:40.221 I/boot_progress_ams_ready( 2182): 235613 //HomeActivity 启动完毕,系统将检查目前所有的window是否画完,如果所有的window(包括wallpaper Keyguard 等)都已经画好,系统会设置属性service.bootanim.exit值为1.并且trigger下面的event
07-06 22:21:52.740 I/boot_progress_enable_screen( 2182):248132
Code://
void enableScreenAfterBoot() {
        EventLog.writeEvent(EventLogTags.BOOT_PROGRESS_ENABLE_SCREEN,SystemClock.uptimeMillis()); //sent  boot_progress_enable_screen         mWindowManager.enableScreenAfterBoot(); //结束 bootanimation         synchronized (this) {
            updateEventDispatchingLocked();
        }
    }
 public void enableScreenAfterBoot() {
        synchronized(mWindowMap) {
            if (DEBUG_BOOT) {
                RuntimeException here = new RuntimeException("here");
                here.fillInStackTrace();
               ....
            }
            if (mSystemBooted) {
                return;
            }
            
            mH.sendEmptyMessageDelayed(H.BOOT_TIMEOUT, 30*1000);
        }         mPolicy.systemBooted();         performEnableScreen(); //here 设置bootanimation exit 
    }  public void performEnableScreen() {
        synchronized(mWindowMap) {
           ...
            if (mDisplayEnabled) {
                return;
            }
            if (!mSystemBooted && !mShowingBootMessages) {
                return;
            }             // Don't enable the screen until all existing windows have been drawn.
            if (!mForceDisplayEnabled && checkWaitingForWindowsLocked()) {
                return;
            } if (!mBootAnimationStopped) {
                // Do this one time.
                try {
                    IBinder surfaceFlinger = ServiceManager.getService("SurfaceFlinger");
                    if (surfaceFlinger != null) {
                       ...
                        Parcel data = Parcel.obtain();
                        data.writeInterfaceToken("android.ui.ISurfaceComposer");
                        surfaceFlinger.transact(IBinder.FIRST_CALL_TRANSACTION, // BOOT_FINISHED
                                data, null, 0);
                        data.recycle();
                    }
                } catch (RemoteException ex) {
                    Slog.e(TAG, "Boot completed: SurfaceFlinger is dead!");
                }
                mBootAnimationStopped = true;
            }            ....
    }
status_t BnSurfaceComposer::onTransact(
    uint32_t code, const Parcel& data, Parcel* reply, uint32_t flags)
{
    switch(code) {
       .....
        case BOOT_FINISHED: {
            CHECK_INTERFACE(ISurfaceComposer, data, reply);
            bootFinished();
            return NO_ERROR;
        }
void SurfaceFlinger::bootFinished()
{
    const nsecs_t now = systemTime();
    const nsecs_t duration = now - mBootTime;
    ALOGI("Boot is finished (%ld ms)", long(ns2ms(duration)) );
    mBootFinished = true;     // wait patiently for the window manager death
    const String16 name("window");
    sp window(defaultServiceManager()->getService(name));
    if (window != 0) {
        window->linkToDeath(static_cast(this));
    }     // stop boot animation
    // formerly we would just kill the process, but we now ask it to exit so it
    // can choose where to stop the animation.
    property_set("service.bootanim.exit", "1");
}

Bootanimation

在开机启动过程中,bootanimationsurfaceflinger实例化时启动,在其运行过程中会择机检查是否可以退出(service.bootanim.exit1),如果可以退出则会根据bootanimation config退出。有时,当service.bootanim.exit1时,