分析trace中一段sleeping 50ms的问题

130 阅读1分钟

问题:

在抓取设置冷启动的trace时发现在performStart中都有一个50ms的sleeping,并且没有找到唤醒源

image.png

分析:

  1. 知道是performStart里产生的,可以缩小范围在onStart,通过Debug.startMethodTracing和Debug.stopMethodTracing来生成traceview,这样更容易找到问题

在src/com/android/settings/homepage/SettingsHomepageActivity.java的onStart方法中添加Debug.startMethodTracing和Debug.stopMethodTracing

    @Override
    protected void onStart() {
        Debug.startMethodTracing("onStart");
        ((SettingsApplication) getApplication()).setHomeActivity(this);
        super.onStart();
        Debug.stopMethodTracing();
    }
  1. 通过adb pull sdcard/Android/data/com.android.settings/files/onStart.trace获取到traceview文件,点击在Android Studio的Profiler的+,load from file,选择onStart.trace image.png

  2. 选择主线程,搜索关键字"sleep"或"wait",可以看到sleep没有搜索到,但是wait有搜到

image.png

image.png

  1. 定位代码

src/com/android/settings/dashboard/DashboardFragment.java

   private static final long TIMEOUT_MILLIS = 50L;
   private void awaitObserverLatch(CountDownLatch latch) {
        try {
            latch.await(TIMEOUT_MILLIS, TimeUnit.MILLISECONDS);
        } catch (InterruptedException e) {
            // Do nothing
        }
    }
  1. 通过添加trace确认 src/com/android/settings/dashboard/DashboardFragment.java
        if (!pendingObservers.isEmpty()) {
            ....
            android.os.Trace.beginSection("waiting observers");
            awaitObserverLatch(mainLatch);
            android.os.Trace.endSection();
            ....
            pendingObservers.forEach(DynamicDataObserver::updateUi);
        }

image.png

PS:

  • 刚开始以为是SharePreferences的awaitLoadedLocked引起,添加trace

frameworks/base/core/java/android/app/SharedPreferencesImpl.java

    private void awaitLoadedLocked() {
        android.os.Trace.beginSection("SP awaitLoadedLocked");
...
        while (!mLoaded) {
            try {
                mLock.wait();
            } catch (InterruptedException unused) {
            }
        }
...
        android.os.Trace.endSection();
    }

从trace的图可以看出,"SP awaitLoadedLocked"耗时只有6ms,不是问题的发生点

image.png

从下图可以看,这段的sleeping是能找到唤醒源的

image.png

  • 此问题的trace中有时会发现唤醒线程是奇奇怪怪的,但两者是无关的,可能是cpu task轮换的时候刚好上一个是com.google.android.apps.wellbeing的BootImagePollin,但BootImagePollin线程的执行和设置主线程没有关联,即没有唤醒和被唤醒的关系

image.png

image.png