Janky frames 是如何計算出來的

時間 2019-11-24

標籤 janky frames 如何計算出來简体版

原文原文鏈接

想看我更多文章:【張旭童的博客】http://blog.csdn.net/zxt0601 想來gayhub和我gaygayup:【mcxtzhang的Github主頁】https://github.com/mcxtzhanghtml

背景

最近在作一些性能監控的工做，其中線下監控fps這一項，通過調研，最終採用dumpsys gfxinfo的方式。java

在6.0+的手機中執行以下命令，android

adb shell dumpsys gfxinfo 包名 
複製代碼

能夠獲得一些log：c++

Applications Graphics Acceleration Info:
Uptime: 3820706382 Realtime: 3903615964

** Graphics info for pid 427 [包名] **

Stats since: 3820661771494092ns
Total frames rendered: 201
//重點關注對象
Janky frames: 76 (37.81%)
50th percentile: 6ms
90th percentile: 19ms
95th percentile: 61ms
99th percentile: 300ms
Number Missed Vsync: 14
Number High input latency: 0
Number Slow UI thread: 17
Number Slow bitmap uploads: 5
Number Slow issue draw commands: 60
........
//重點關注對象
	ActivityName/android.view.ViewRootImpl@d4c0f16 (visibility=0)
//每一個Activity的每一幀的原始數據，包含每一個階段的時間戳
---PROFILEDATA---
Flags,IntendedVsync,Vsync,OldestInputEvent,NewestInputEvent,HandleInputStart,AnimationStart,PerformTraversalsStart,DrawStart,SyncQueued,SyncStart,IssueDrawCommandsStart,SwapBuffers,FrameCompleted,
0,3820697872348436,3820697872348436,9223372036854775807,0,3820697872662836,3820697872693045,3820697872814399,3820697872932628,3820697873194607,3820697873228461,3820697873328982,3820697873869086,3820697876514920,
0,3820697889204506,3820697889204506,9223372036854775807,0,3820697889517524,3820697889547211,3820697889672211,3820697889801899,3820697890120649,3820697890156586,3820697890267524,3820697890787836,3820697892957628,
0,3820697906060465,3820697906060465,9223372036854775807,0,3820697906622211,3820697906650857,3820697906761795,3820697906888357,3820697907180024,3820697907215961,3820697907325857,3820697907809190,3820697909209190,
0,3820697922916378,3820697922916378,9223372036854775807,0,3820697923237315,3820697923265440,3820697923397732,3820697923533149,3820697923806586,3820697923837315,3820697923936795,3820697924388878,3820697927055024,
0,3820697939772285,3820697939772285,9223372036854775807,0,3820697940389920,3820697940418565,3820697940532628,3820697940652420,3820697940915961,3820697940948774,3820697941046690,3820697941496170,3820697943844086,
0,3820697956628358,3820697956628358,9223372036854775807,0,3820697956922732,3820697956952940,3820697957073774,3820697957197732,3820697957457107,3820697957490961,3820697957583149,3820697958036795,3820697959429503,
............
複製代碼

其中有一項名爲：Janky frames的數據引發了咱們的興趣。git

Janky frames該如何理解呢？參考官方文檔1 的說明，彷佛就是掉幀的數量。github

可若是按照掉幀的數量來理解，這份log顯示的掉幀率高達37.81%，一個app若是近40%的幀都被skip，用戶不可能毫無感知。shell

但在咱們測試時，沒有感受到明顯的卡頓。（且根據原始數據，用另一套計算方式，算出的幀率fps值也與掉幀率的百分比矛盾）bash

但這Janky frames畢竟是官方adb命令給出的值，具備必定的權威性，因而咱們開始自我懷疑，app

是咱們的眼睛沒有看出卡頓?
是咱們計算幀率fps的方式出現了問題？
...

因爲官方在log中並未給出實際fps的值，因而爲了探究問題出在哪裏，也爲了參考官方的計算標準，即如何斷定一幀出現了janky,我便把黑手伸向了無辜的源碼，畢竟源碼之下，了無祕密。ionic

遂，如今的目標是：

找到adb shell dumpsys gfxinfo的源碼
找到源碼裏關於Janky frame的計算方法

找到gfxinfo源碼

通過搜索，在Android dumpsys工具分析文中中得知，當咱們執行adb shell dumpsys後，根據後面不一樣的參數，例如meminfo 、gfxinfo，其實是經過ServiceManager->checkService(services[i])方法，從ServiceManager中取出對應服務的Binder對象，並最終經過service->dump(STDOUT_FILENO, args)調用對應服務Binder對象的dump()方法執行具體命令。

這些系統服務的註冊，是在AMS(ActivityManagerService.java)裏的setSystemProcess()裏完成的，

public void setSystemProcess() {
        try {
            //在ServiceManager中註冊服務
            //"activity";
            ServiceManager.addService(Context.ACTIVITY_SERVICE, this, true);
            ServiceManager.addService(ProcessStats.SERVICE_NAME, mProcessStats);
            ServiceManager.addService("meminfo", new MemBinder(this));
            ServiceManager.addService("gfxinfo", new GraphicsBinder(this));
            ServiceManager.addService("dbinfo", new DbBinder(this));
            ...
        } catch (PackageManager.NameNotFoundException e) {
            throw new RuntimeException(
                    "Unable to find android system package", e);
        }
    }
複製代碼

能夠看到，咱們熟悉的 "activity"、"meminfo"以及本文的主角"gfxinfo"都在其中註冊。

java層源碼

順藤摸瓜，咱們看看GraphicsBinder這個類以及它的dump()方法:

static class GraphicsBinder extends Binder {
        ActivityManagerService mActivityManagerService;
        GraphicsBinder(ActivityManagerService activityManagerService) {
            mActivityManagerService = activityManagerService;
        }

        @Override
        protected void dump(FileDescriptor fd, PrintWriter pw, String[] args) {
            if (!DumpUtils.checkDumpAndUsageStatsPermission(mActivityManagerService.mContext,
                    "gfxinfo", pw)) return;
            //調用ams的dumpGraphicsHardwareUsage()方法
            mActivityManagerService.dumpGraphicsHardwareUsage(fd, pw, args);
        }
    }
複製代碼

dump()方法很簡單，僅僅驗證權限後調用ams的dumpGraphicsHardwareUsage()方法,繼續跟進：

final void dumpGraphicsHardwareUsage(FileDescriptor fd,
            PrintWriter pw, String[] args) {
        //根據args參數，參數裏包含進程名 或者進程id，獲得指定進程。 若是args參數裏不包含進程名，則獲得全部進程
        ArrayList<ProcessRecord> procs = collectProcesses(pw, 0, false, args);
        //沒有符合條件的進程時的輸出
        if (procs == null) {
            pw.println("No process found for: " + args[0]);
            return;
        }
        //執行命令時的時間
        long uptime = SystemClock.uptimeMillis();
        long realtime = SystemClock.elapsedRealtime();
        pw.println("Applications Graphics Acceleration Info:");
        pw.println("Uptime: " + uptime + " Realtime: " + realtime);
        //循環進程列表
        for (int i = procs.size() - 1 ; i >= 0 ; i--) {
            ProcessRecord r = procs.get(i);
            if (r.thread != null) {
                pw.println("\n** Graphics info for pid " + r.pid + " [" + r.processName + "] **");
                pw.flush();
                try {
                    TransferPipe tp = new TransferPipe();
                    try {
                        //重點，執行每一個進程的ApplicationThread的dumpGfxInfo()方法
                        r.thread.dumpGfxInfo(tp.getWriteFd(), args);
                        tp.go(fd);
                    } finally {
                        tp.kill();
                    }
                } catch (IOException e) {
                    pw.println("Failure while dumping the app: " + r);
                    pw.flush();
                } catch (RemoteException e) {
                    pw.println("Got a RemoteException while dumping the app " + r);
                    pw.flush();
                }
            }
        }
    }
複製代碼

能夠看到，咱們關心的核心輸出(Janky frames部分)以進程區分，並在ApplicationThread.dumpGfxInfo()方法中輸出。 ApplicationThread在ActivityThread.java中，繼續跟進：

@Override
        public void dumpGfxInfo(ParcelFileDescriptor pfd, String[] args) {
            //jni  ，janky frames輸出就在其中
            dumpGraphicsInfo(pfd.getFileDescriptor());
            // java方法，輸出 Profile data in ms: 後面的部分
            WindowManagerGlobal.getInstance().dumpGfxInfo(pfd.getFileDescriptor(), args);
            IoUtils.closeQuietly(pfd);
        }
        
    // ------------------ Regular JNI ------------------------
    private native void dumpGraphicsInfo(FileDescriptor fd);
複製代碼

查看WindowManagerGlobal.dumpGfxInfo()方法：

public void dumpGfxInfo(FileDescriptor fd, String[] args) {
        FileOutputStream fout = new FileOutputStream(fd);
        PrintWriter pw = new FastPrintWriter(fout);
        try {
            synchronized (mLock) {
                final int count = mViews.size();

                pw.println("Profile data in ms:");

                for (int i = 0; i < count; i++) {
                    ViewRootImpl root = mRoots.get(i);
                    String name = getWindowName(root);
                    pw.printf("\n\t%s (visibility=%d)", name, root.getHostVisibility());

                    ThreadedRenderer renderer =
                            root.getView().mAttachInfo.mThreadedRenderer;
                    if (renderer != null) {
                        renderer.dumpGfxInfo(pw, fd, args);
                    }
                }

                pw.println("\nView hierarchy:\n");

                int viewsCount = 0;
                int displayListsSize = 0;
                int[] info = new int[2];

                for (int i = 0; i < count; i++) {
                    ViewRootImpl root = mRoots.get(i);
                    root.dumpGfxInfo(info);

                    String name = getWindowName(root);
                    pw.printf(" %s\n %d views, %.2f kB of display lists",
                            name, info[0], info[1] / 1024.0f);
                    pw.printf("\n\n");

                    viewsCount += info[0];
                    displayListsSize += info[1];
                }

                pw.printf("\nTotal ViewRootImpl: %d\n", count);
                pw.printf("Total Views: %d\n", viewsCount);
                pw.printf("Total DisplayList: %.2f kB\n\n", displayListsSize / 1024.0f);
            }
        } finally {
            pw.flush();
        }
    }
複製代碼

可知，其中輸出的是"Profile data in ms:"後面部分的log，因此，咱們關心的部分就在JNI裏了。

C層源碼

看到JNI我是抗拒的，本科時學的那些C、C++早已記不太清，一想到要看C層的源碼，就以爲頭大。本來想溜，可是轉念一想，我只須要關注它對於"Janky frame"的計算方式，無外乎那些數學運算。只要重點關注函數調用處，搜索關鍵字，說不定能夠找到答案。因而，繼續跟進。

因爲涉及C層的源碼在AndroidStudio中查看不了，下面的分析使用查看framework源碼網站進行。我全局搜索了關鍵字dumpGraphicsInfo,找到函數定義處：

進入 android_view_DisplayListCanvas.cpp查看()：

搜索 dumpGraphicsMemory：

進入 RenderProxy.cpp後，

因爲對c++不是很懂，這一塊的代碼不是很懂，可是從全局搜索只有三處調用，並且從jankTracker的字樣上能夠看出（這一步有一些連蒙帶猜）,這裏應該是正確的方向，繼續跟進：在 JankTracker.h文件中：

因而咱們進入 JankTracker.cpp中查看 dumpData（）方法的具體實現：

看到這裏我是既興奮又痛苦。興奮的是我找到了最終log對應的輸出之處，痛苦的是，這裏僅僅是將 ProfileData->jankFrameCount字段輸出，看來革命之路還長，還要找到賦值的地方。

jankFrameCount 賦值之處

全局搜索->jankFrameCount調用之處，：

發現僅在 JankTracker.cpp中使用到,在 addFrame（）函數中會遞增:

能夠看出，若是一幀的時間若是小於 mFrameInterval，則return,那麼 jankFrameCount不會遞增， 即每一幀的時間大於等於mFrameInterval，就是Janky frame

看來咱們離答案已經很接近了，那麼mFrameInterval是多少呢？搜索mFrameInterval是在setFrameInterval()中賦值的：

setFrameInterval()在JankTracker初始化時調用:

根據官方文檔1以及官方視頻 why60fps,刷新頻率fps是60。因此可得 frameIntervalNanos約等於16.67ms.

結論

至此咱們能夠得出結論，官方衡量Janky frames的標準：一幀的時間超過16.67ms。

想法

注：如下想法目前尚未源碼撐腰，並不必定正確，若有錯誤以及知情大佬，煩請指正，謝謝

有上述結論能夠看出 Janky frames確實表明了這一幀的完整繪製時間過久，出現了問題，

那麼回到咱們文首的問題，某些頁面的Janky frames高達近37.81%，爲什麼咱們沒有感到卡頓？以及爲什麼算出來的fps並無低於37.2= 60*（1-0.38）?

關於這個問題，通過討論，有如下暫時的想法：

Android 5.0之後，加入了RenderThread，用於分擔UI Thread的部分繪製工做。即一幀的完整繪製時間 是由UIThread和RenderThread上的耗時相加獲得的。
UI Thread在處理完input animation以及部分draw的工做後，將剩餘繪製工做交於RenderThread，UI Thread此時能夠繼續處理下一個VSYNC到來時的工做。
RenderThread 以及三緩衝機制

能夠看出B先致使了一次視覺上的jank，C理論上也是jank的（相加時間超過了16.67ms），可是因爲此時屏幕上顯示的是B，C雖然delay了一幀，可是因爲C以前的B已經delay了一幀，因此C看起來仍然是緊跟着B顯示在屏幕上，並且A順利的在16.67ms完成了任務，緊跟着C繼續繪製了，則用戶在視覺上只少看到了一幀。

因此咱們的想法是：

在Android5.0+,Janky frames 並不表明用戶視覺上的，顯示在屏幕上的丟幀率，可是它能夠表明有問題的幀率，

即這些幀有問題，但最終因爲三緩衝機制的背鍋，部分幀沒有最終影響到用戶，

因此實際上的fps值會高於 60*（1-掉幀率）.

這個問題後面也會繼續跟進，作到理據服。