Android 성능 최적화 제11편---카드 분석, 정확한 유창도 평가

1. FPS 평가 응용의 유창도가 정확하지 않다.
응용의 유창도에 대해 말하자면 FPS가 떠오른다. 시스템이 FPS를 얻는 원리는 핸드폰 화면에 나타난 내용은 안드로이드 시스템의SurfaceFlinger류를 통해 현재 시스템에서 모든 프로세스가 표시해야 할 정보를 한 프레임으로 합성한 다음에 화면에 제출하여 표시하는 것이다. FPS는 1초 안에SurfaceFlinger가 화면에 제출하는 프레임 수이다.FPS를 사용하여 한 응용 프로그램이 정말 끊기는지 아닌지에 두 가지 문제가 존재한다.FPS가 낮은데 앱이 매끄러워 보일 때가 있다. -APP가 작동을 멈춘 후에도 FPS는 계속 변하고 있는데, 이런 상황이 FPS의 정확도에 영향을 미칠까?FPS가 낮은데 APP가 유창해 보이는 이유는 현재 인터페이스가 1초에 10프레임의 디스플레이 수요만 있으면 끊기지 않기 때문이다. 이때 FPS는 10보다 높으면 된다. 만약에 화면에 그리는 수요가 전혀 없다면 FPS의 값은 0이다.
안드로이드 성능 최적화 제4편 - 안드로이드 렌더링 메커니즘에 따르면 안드로이드 시스템은 16ms마다 VSYNC 신호를 보내고 UI에 대한 렌더링을 터치하며 16ms가 완성되지 않으면 멈춘다고 한다.VSync 메커니즘은 회전 속도가 고정된 엔진(60회전/s)과 같다.모든 이적은 UI와 관련된 일을 하도록 이끌지만, 매 이적마다 할 일이 있는 것은 아니다. (때로는 빈 기어에서, 때로는 D기어에서)때때로 각종 저항 때문에 한 바퀴의 작업량이 16.6ms를 비교적 무겁게 초과하면 이 엔진은 이 초 안에 60회전이 아니다. 물론 다른 요소에 영향을 받을 수도 있다. 예를 들어 기름을 공급하는 것이 부족(주선에서 하는 일이 너무 많다) 등은 회전 속도가 떨어지는 상태가 나타날 수 있다.우리는 이 회전 속도를 유창도라고 부른다.유창도가 작을수록 현재 프로그램이 끊긴다는 것을 설명한다.
2. Choreographer 프레임 확률 측정 원리
우리는 때때로 이런 로그를 볼 수 있는데, 시스템은 우리가 점프 프레임 수를 인쇄하는 것을 도와준다.
02-07 19:47:04.333 17601-17604/zhangwan.wj.com.choreographertest D/dalvikvm: GC_CONCURRENT freed 143K, 3% free 9105K/9384K, paused 2ms+0ms, total 6ms
02-07 19:47:04.337 17601-17601/zhangwan.wj.com.choreographertest I/Choreographer: Skipped 60 frames!  The application may be doing too much work on its main thread.
02-07 19:47:11.685 17601-17601/zhangwan.wj.com.choreographertest I/Choreographer: Skipped 85 frames!  The application may be doing too much work on its main thread.
02-07 19:47:12.545 17601-17601/zhangwan.wj.com.choreographertest I/Choreographer: Skipped 37 frames!  The application may be doing too much work on its main thread.
02-07 19:47:14.893 17601-17601/zhangwan.wj.com.choreographertest I/Choreographer: Skipped 37 frames!  The application may be doing too much work on its main thread.
02-07 19:47:23.049 17601-17601/zhangwan.wj.com.choreographertest I/Choreographer: Skipped 36 frames!  The application may be doing too much work on its main thread.
02-07 19:47:23.929 17601-17601/zhangwan.wj.com.choreographertest I/Choreographer: Skipped 37 frames!  The application may be doing too much work on its main thread.
02-07 19:47:24.961 17601-17601/zhangwan.wj.com.choreographertest I/Choreographer: Skipped 61 frames!  The application may be doing too much work on its main thread.
02-07 19:47:25.817 17601-17601/zhangwan.wj.com.choreographertest I/Choreographer: Skipped 36 frames!  The application may be doing too much work on its main thread.
02-07 19:47:26.433 17601-17601/zhangwan.wj.com.choreographertest I/Choreographer: Skipped 36 frames!  The application may be doing too much work on its main thread.

이 로그는 Choreographer에서 나온 거예요.ˌkɒrɪ’ɒɡrəfə(r)] 아름다움[ˌkɒrɪ’ɒɡrəfə(r)]).
void doFrame(long frameTimeNanos, int frame) {
        final long startNanos;
        synchronized (mLock) {
            if (!mFrameScheduled) {
                return; // no work to do
            }

            if (DEBUG_JANK && mDebugPrintNextFrameTimeDelta) {
                mDebugPrintNextFrameTimeDelta = false;
                Log.d(TAG, "Frame time delta: "
                        + ((frameTimeNanos - mLastFrameTimeNanos) * 0.000001f) + " ms");
            }

            long intendedFrameTimeNanos = frameTimeNanos;
            startNanos = System.nanoTime();
            final long jitterNanos = startNanos - frameTimeNanos;
            if (jitterNanos >= mFrameIntervalNanos) {
                final long skippedFrames = jitterNanos / mFrameIntervalNanos;
                if (skippedFrames >= SKIPPED_FRAME_WARNING_LIMIT) {
                    Log.i(TAG, "Skipped " + skippedFrames + " frames!  "
                            + "The application may be doing too much work on its main thread.");
                }
                final long lastFrameOffset = jitterNanos % mFrameIntervalNanos;
                if (DEBUG_JANK) {
                    Log.d(TAG, "Missed vsync by " + (jitterNanos * 0.000001f) + " ms "
                            + "which is more than the frame interval of "
                            + (mFrameIntervalNanos * 0.000001f) + " ms!  "
                            + "Skipping " + skippedFrames + " frames and setting frame "
                            + "time to " + (lastFrameOffset * 0.000001f) + " ms in the past.");
                }
                frameTimeNanos = startNanos - lastFrameOffset;
            }
        }

    }

여기서 SKIPPEDFRAME_WARNING_LIMIT는 Choreographer의 구성원 변수입니다.
  // Set a limit to warn about skipped frames.
  // Skipped frames imply jank.
  private static final int SKIPPED_FRAME_WARNING_LIMIT =SystemProperties.getInt( "debug.choreographer.skipwarning", 30);

즉, 점프 프레임 수가 설정된 SKIPPED보다 클 때FRAME_WARNING_LIMIT 값은 현재 세션에서 이 log를 출력합니다.SKIPPED로 인해FRAME_WARNING_LIMIT의 값은 기본적으로 30이기 때문에 위의 로그는 자주 보지 않습니다. 만약에 우리가 반사하는 방법으로 SKIPPED 를FRAME_WARNING_LIMIT의 값을 1로 설정하면 프레임을 잃어버리면 위의 로그가 지는 것을 보장할 수 있습니다.
static {
        try {
            Field field = Choreographer.class.getDeclaredField("SKIPPED_FRAME_WARNING_LIMIT");
            field.setAccessible(true);
            field.set(Choreographer.class,1);
        } catch (Throwable e) {
            e.printStackTrace();
        }
    }

이 시나리오는 API 16 이상이어야 지원됩니다.Choreographer는 메시지 프로세서로 vsync 신호에 따라 프레임을 계산하고 프레임을 계산하는 방식은 이벤트 리셋, 애니메이션 리셋, 그리기 리셋을 포함한 세 가지 리셋을 처리하는 것이다.이 세 가지 이벤트는 메시지 입력, 애니메이션 추가, 그림 그리기layout 준비 등 동작을 할 때 모두 Choreographer에 보냅니다.한마디로, 우리는 이 로그를 포획해서skippedFrames를 추출하면 인터페이스가 끊기는지 알 수 있다.
3. 어떻게 검측하는가
위의 방식을 사용하면 앱 내부에서 현재 앱의 유창도를 관측할 수 있다.또한 프레임을 잃어버린 곳에서 인쇄하면 프레임을 잃어버린 대략적인 원인, 대략적인 위치, 포지셔닝 코드 문제를 알 수 있다.
Choreographer에 리셋 인터페이스, FrameCallback이 있습니다.
public interface FrameCallback {  
  //              。  
   public void doFrame(long frameTimeNanos);
}

위 코드에 따라 Do Frame 방법을 다시 쓰기 때문에 조롱박에 따라 바가지를 그리고 Frame Callback을 사용자 정의합니다.우리는 각 프레임이 렌더링될 때 렌더링을 시작하는 시간을 기록할 수 있으며, 다음 프레임이 처리될 때 이전 프레임이 렌더링 과정에서 프레임이 떨어졌는지 판단할 수 있다.
public class SMFrameCallback implements Choreographer.FrameCallback {

    public static  SMFrameCallback sInstance;

    private String TAG="SMFrameCallback";

    public static final float deviceRefreshRateMs=16.6f;

    public static  long lastFrameTimeNanos=0;//     

    public static  long currentFrameTimeNanos=0;

    public void start() {
        Choreographer.getInstance().postFrameCallback(SMFrameCallback.getInstance());
    }

    public static SMFrameCallback getInstance() {
        if (sInstance == null) {
            sInstance = new SMFrameCallback();
        }
        return sInstance;
    }

    @Override
    public void doFrame(long frameTimeNanos) {
        if(lastFrameTimeNanos==0){
            lastFrameTimeNanos=frameTimeNanos;
            Choreographer.getInstance().postFrameCallback(this);
            return;
        }
        currentFrameTimeNanos=frameTimeNanos;
        float value=(currentFrameTimeNanos-lastFrameTimeNanos)/1000000.0f;

        final int skipFrameCount = skipFrameCount(lastFrameTimeNanos, currentFrameTimeNanos, deviceRefreshRateMs);
        Log.e(TAG,"        value="+value+"  frameTimeNanos="+frameTimeNanos+"  currentFrameTimeNanos="+currentFrameTimeNanos+"  skipFrameCount="+skipFrameCount+"");
        lastFrameTimeNanos=currentFrameTimeNanos;
        Choreographer.getInstance().postFrameCallback(this);
    }


    /**
     *
     *       
     * @param start
     * @param end
     * @param devicefreshRate
     * @return
     */
    private  int skipFrameCount(long start,long end,float devicefreshRate){
        int count =0;
        long diffNs=end-start;
        long diffMs = Math.round(diffNs / 1000000.0f);
        long dev=Math.round(devicefreshRate);
        if(diffMs>dev){
            long skipCount=diffMs/dev;
            count=(int)skipCount;
        }
        return  count;
    }
}

테스트가 필요한 Activity에서 SMFrameCallback을 호출합니다.getInstance().start ()만 있으면 됩니다.일반적으로BaseActivity에서 호출하거나Activitylifecyclecallbacks에서 호출할 수 있도록 최적화합니다.일반적으로 출력되는 로그는 다음과 같습니다.
02-07 20:18:52.605 6683-6683/zhangwan.wj.com.choreographertest E/SMFrameCallback:         value=16.666666  frameTimeNanos=6996166386820  currentFrameTimeNanos=6996166386820  skipFrameCount=0
02-07 20:18:52.621 6683-6683/zhangwan.wj.com.choreographertest E/SMFrameCallback:         value=16.666666  frameTimeNanos=6996183053486  currentFrameTimeNanos=6996183053486  skipFrameCount=0
02-07 20:18:52.637 6683-6683/zhangwan.wj.com.choreographertest E/SMFrameCallback:         value=16.666666  frameTimeNanos=6996199720152  currentFrameTimeNanos=6996199720152  skipFrameCount=0
02-07 20:18:52.657 6683-6683/zhangwan.wj.com.choreographertest E/SMFrameCallback:         value=16.666666  frameTimeNanos=6996216386818  currentFrameTimeNanos=6996216386818  skipFrameCount=0
02-07 20:18:52.673 6683-6683/zhangwan.wj.com.choreographertest E/SMFrameCallback:         value=16.666666  frameTimeNanos=6996233053484  currentFrameTimeNanos=6996233053484  skipFrameCount=0
02-07 20:18:52.689 6683-6683/zhangwan.wj.com.choreographertest E/SMFrameCallback:         value=16.666666  frameTimeNanos=6996249720150  currentFrameTimeNanos=6996249720150  skipFrameCount=0

점프가 있을 때 출력하는 로그는
02-07 20:21:53.909 9530-9530/zhangwan.wj.com.choreographertest E/SMFrameCallback:         value=16.666666  frameTimeNanos=7177466379568  currentFrameTimeNanos=7177466379568  skipFrameCount=0
02-07 20:21:53.925 9530-9530/zhangwan.wj.com.choreographertest E/SMFrameCallback:         value=16.666666  frameTimeNanos=7177483046234  currentFrameTimeNanos=7177483046234  skipFrameCount=0
02-07 20:21:54.133 9530-9530/zhangwan.wj.com.choreographertest E/SMFrameCallback:         value=200.0  frameTimeNanos=7177683046226  currentFrameTimeNanos=7177683046226  skipFrameCount=11
02-07 20:21:54.745 9530-9530/zhangwan.wj.com.choreographertest E/SMFrameCallback:         value=616.6666  frameTimeNanos=7178299712868  currentFrameTimeNanos=7178299712868  skipFrameCount=36
02-07 20:21:54.757 9530-9530/zhangwan.wj.com.choreographertest E/SMFrameCallback:         value=16.666666  frameTimeNanos=7178316379534  currentFrameTimeNanos=7178316379534  skipFrameCount=0
02-07 20:21:54.773 9530-9530/zhangwan.wj.com.choreographertest E/SMFrameCallback:         value=16.666666  frameTimeNanos=7178333046200  currentFrameTimeNanos=7178333046200  skipFrameCount=0
02-07 20:21:54.789 9530-9530/zhangwan.wj.com.choreographertest E/SMFrameCallback:         value=16.666666  frameTimeNanos=7178349712866  currentFrameTimeNanos=7178349712866  skipFrameCount=0

두 번 그린 시간 간격이 616.666밀리초로 36 프레임을 뛰어넘는 것을 보았는데 이 카드 사용자는 뚜렷하게 감지할 수 있다.
Please accept mybest wishes for your happiness and success !

좋은 웹페이지 즐겨찾기