프로파일링 도입 이유 - UI 속도 문제를 해결하고자 함

최초 로그인을 할 때

1단계. 로그인버튼을 누른다
2단계. 소셜로그인을 한다
3단계. 메인 홈으로 들어간다

밑의 파란색으로 잡은 부분이 위의 1,2,3단계를 거치는 시간인데, 이상하리만치 시간이 오래 걸리는 것을 확인했다.
특히 밑의 캡처화면에서 빨간색 네모박스로 표시한 부분은 '소셜로그인 후 메인 홈 진입' 단계인데, 이 부분에서 로딩시간으로 5초 정도 소요되는 문제가 있다. 신규 개발 단계에서는 구현만하고 지나쳤는데 앱을 만들다보니 점점 더 느려진 감이 있다. 최적화를 할 필요성을 가장 먼저 느낀 부분이었다.

'로그인 버튼 클릭 후 소셜로그인', '소셜로그인 후 메인 홈 진입' 이렇게 타임라인을 나눠서 프로파일링 하기로 했다.
로그인하고 메인 홈 가는데 5.7초면 진짜 따귀맞아야됨

'로그인 버튼 클릭 후 소셜로그인' <- 0.7초 걸림(양호)
'소셜로그인 후 메인 홈 진입' <- 5초 걸리는 금쪽이

후자를 고쳐야하는 상황이라 프로파일링을 시작했는데 이것저것 펼치다보면 되게 볼게 많아서 어질어질하다.
우선 이 포스팅에서는 프로파일링과 친해지기 위해서 연습삼아 '로그인버튼 클릭 후 소셜로그인' 부분을 분석해보았다.

첫 시도 - '로그인버튼 클릭 후 소셜로그인' 프로파일링하기

아래는 1단계, 2단계 범위의 분석 요약이다. 아래와 같이 Interaction의 User 타임라인에 빨갛게 자국이 남은게 버튼을 누른 것이다.
버튼을 누른후 소셜로그인을 하는 kakao.sdk.AuthCodeHandlerActivity가 create되고 stop하기까지의 시간이 약 0.7초가 걸렸다.

'로그인버튼 클릭 후 소셜로그인' 프로파일링 분석 결과1

프로파일링 기능에 아직 익숙하지가 않아서 CPU 성능 레코딩을 여러번 시도하게 되었다. 그래서 프로파일링 화면이 일관되지 않은점...양해부탁드립니다😓

다시 프로파일링 해봐도 비슷하게 0.7초가 걸린다.

com.hmoa.app을 보면 알록달록하게 작업 이벤트들이 있는데 아래와 같이 요약데이터를 캡처했다.

위에 activity관련 이벤트들이 보이는데, 이 중 activityDestroy라고 써있는 건 앱의 MainActivity가 아니고 카카오 소셜로그인용 AuthCodeHandlerActivity이다. 소셜로그인 인텐트로 로그인을 마치면, 다시 MainActivity로 돌아와야 하기 때문에 activityDestroy가 발생한 걸로 보인다.다른 작업들보다 월등하게 CPU Self Time, Wall Self Time이 커서 눈에 띈다. 근데 제3자가 만든 Activity라...뭥미하고 넘어간다 어차피 미미하다

states

이 부분은 분석자료를 보고 gpt가 생성한 설명이다.

Sleeping: 스레드가 541.86ms 동안 슬립 상태에 있었습니다. 전체 시간 중 73.73%를 차지하고 있습니다.
Running: 180.45ms 동안 실행 상태에 있었으며, 24.55%를 차지합니다.
Waiting: 9.82ms 동안 대기 상태에 있었고, 1.34%를 차지합니다.
Runnable: 2.53ms 동안 실행 준비 상태에 있었으며, 이는 0.34%에 해당합니다.
Unknown: 224μs로 매우 짧은 시간을 알 수 없는 상태에 있었습니다. 0.03%입니다.

그러니까 실제 실행시간은 짧은데 스레드가 대부분의 시간을 슬립 상태로 보낸다고 해석할 수 있다. 슬립상태가 많은 것이 꼭 성능 문제를 유발하지는 않는다고 한다. 불필요하게 CPU자원을 소모하지 않도록 효율적으로 처리하고 있다는 신호일 수 있기 때문이다. 하지만 슬립과 실행상태의 전환이 자주 발생하거나, 대기시간이 너무 길다면 성능문제의 원인이 될 수 있다. 위의 결과를 보면 대기시간은 1.34%에 불과하므로, 거의 대기없이 잠자다가 실행한 거니까 딱히 문제삼을 부분은 없기 때문에 0.7초 안에 작업이 끝난 것 아닐까 싶다.

Longest running events(가장 긴 실행 이벤트)

오래걸리는 작업 10개가 있었는데, 다 비슷하고, 특별한 건 아래의 Choreographer, traversal 작업이다.이 2개가 오래걸리는 작업으로 확인되었다.

Wall Duration과 CPU Self Time 관점

Choreographer#doFrame과 traversal이 가장 오래 걸리는 작업들로, Choreographer#doFrame 이벤트는 Wall Duration이 40.29ms로, 하나의 프레임을 처리하는 데 꽤 시간이 걸린다. 하지만 Wall Self Time을 보면 58μs로, 실제로 이 작업을 수행한 시간은 매우 짧다. 즉, CPU가 처리하는데 시간이 많이 걸린 것이 아니라 주로 다른 요인(예: I/O 작업 대기나 시스템 간 대기)으로 인해 경과 시간이 길어진 것이다.

최적화와 밀접한 개념들

프레임 시간 기준 = 60fps

모바일 애플리케이션, 특히 안드로이드와 iOS의 UI에서 60fps는 일반적으로 기본 목표이다. 화면이 빠르고 부드럽게 렌더링되어야 사용자 경험이 향상되기 때문이다. 안드로이드 UI에서 60fps를 유지하려면 1프레임당 약 16ms 이내에 작업이 완료되어야 한다.

Choreographer#doFrame 작업

Choreopgrapher는 안드로이드드이 UI 프레임워크에서 애니메이션과 화면 갱신을 조율하는 중요한 역할을 하기 때문에 각 프레임을 그리는 작업과 밀접하게 연관된 메소드이다. 앞으로 프로파일링을 하면서 많이 보게 될 거 같다.

Wall Duration

실제 경과된 시간이다. I/O 작업(네트워크, 디스크, 스레드 대기 등)으로 인해 CPU가 비활성 상태일 때도 포함하는 시간이다.

Wall Self Time

특정 함수가 자체적으로 실행된 시간이다. 해당 함수자체에서 경과된 시간을 나타내며, 이 시간에는 해당 함수가 실행되는 동안 호출한 하위 함수들이 실행된 시간은 제외된다.

CPU Duration

해당 작업이 실제로 CPU를 사용한 시간이다. 작업이 시스템의 CPU에서 얼마나 오래 실행되었는지를 나타낸다.

CPU Self Time

해당 함수 자체에서만 CPU를 사용한 시간을 의미한다. 자신의 코드 내부에서 얼마나 많은 CPU자원을 소모했는지 알 수 있다.