anr 로그 /data/anr/traces.txt

ANR 로그 파일 보는 법 알고 싶다... 안드로이드 실전

2011/04/21 22:42

http://blog.naver.com/regako/130107257328

이번 포스팅은 일반 앱개발자들은 저~언혀 상관없는 내용이다.

그러나 폰 제조사의 개발자들에게는 너무나도 소중한 정보가 될 수도 있을 수도 있을 것만 같은..(?)

그러므로 이미지따윈 없이 텍스트로만 구성한다. 왜냐면 이 포스팅의 목적은 나중에 내가 까먹으면

다시 보기 위함이니까 ㅋㅋㅋ

 

안드로이드 스맛폰을 사용하다 보면 가끔(혹은 수시로) 보게 되는 ANR 팝업. 일반적인 Sorry 팝업과는 다르다.

 

일반적인 Sorry 팝업은 흔히 프로그램에서 Exception이 발생해 프로세스가 사망하면서 뜨는 팝업이다.

대충 이런 내용이 뜬다.

"XXXX 프로세스가 예기치 못한 오류로 중단되었습니다 - 버튼 : 닫기 하나만 존재"

이건 명백히 프로그램의 오류이고, 바로 ddms에 물려보면 exception 로그도 나오기 때문에 쉽게

원인을 파악해 해결할 수 있다.

 

BUT!!!!!

 

개발자 최대의 적 ANR...(다른 적도 무쟈게 많지만 일단 지금은 이게 제일 강적이다)

대충 이런 내용이 뜬다.

"XXX프로세스가 응답을 받지 않아 대기중입니다 - 버튼 : 강제 종료 or 대기"(맞나? 전혀 다른가? 암튼 저런 뜻이다. 응답과 대기)

ANR은 말그대로 Android Not Response, 즉 응답이 없다는 것이다.

 

왜냐?

우리는 스마트폰이 기존의 피쳐폰의 개념보다 "컴퓨터"의 개념에 가깝다는 걸 알아야 한다.

컴퓨터 공학을 배울 때 데드락(Deadlock)이라는 것이 있다. 즉 A와 B가 서로 같은 걸 요구하면서 그게 올때까지 무한 대기...

아 설명 하기 힘드네..산업공학과 출신이라 자세히 배운적이 없으니 원...

 

뭐 이런거 아닐까

A : 야 B, 지금 못 박아야 되니까 그 망치 내놔.

B : 나도 박아야 돼. 니 못부터 먼저 주면 망치 줄게.

A : 나부터 박을라니까 망치부터 내놔 얼른!

B : 즐!

 

적절한 사례를 찾기 힘들겠다. 데드락이 궁금하면 인터넷 검색으로 알아보기로 하고...

아무튼 저런 식으로 서로 리소스를 요구하는데 하필 그 중간에 waiting이 걸려서 양쪽에서 무한 대기를

하는 경우가 있고, 아니면 하나의 프로세스가 리소스를 가져가서 죽어라 자기만 사용하는 경우도 있다.

 

ANR은 흔히 이 데드락에 의해 프로세스간 대기가 무한정 길어지면 안되니까 특정 시간이 지나도록

요청한 자원을 얻을 수 없으면 경고 팝업을 띄워 주는 역할을 한다.

특정 시간은 framework쪽에서 따로 지정해 줄 수 있지만 보통 안드로이드 기본은 5초이다.

 

좌우간,

 

ANR에 대한 설명만 쓸데 없이 길게 했군...

 

그러므로 정작 중요한 본문 내용은 짧게 마무리 하기로 하겠다 ㅋㅋㅋㅋ

 

ANR이 발생하면 안드로이드 파일 시스템에

data/anr/ 위치에 traces.txt라는 ANR발생 시점의 프로세스 상태에 관한 로그가 기록된다.

이건 모든 안드로이드 폰 공통이지만 안타깝게도 루트권한에서만 접근이 되기 때문에 일반 사용자는

볼 수가 없다.(루팅하면 가능하다....ㅡ.ㅡ)

 

하지만 볼 수 있다고 해서 얼씨구나 하고 열어보면 또 앞이 깜깜해진다.

프로세스가 나열되어 있지만 대체 어디가 문제인지 어떻게 보는지 도무지 알 수 없기때문....

 

나도 아직 저 로그로 ANR의 원인을 다 잡을 수는 없지만 최소한 한가지 경우는 알아냈다.

 

중요한 키워드는 "waiting to lock 어쩌구저쩌구(호출 자바 파일) threadid = X"

즉 자바파일에서 호출했는데, 그 부분을 Thread ID가 X인 곳에서 안놔주고 있다는 것이다.

그러므로 그 프로세스 안에서 thread ID X인 쓰레드를 찾아가보면 역시 거기서 어느 지점에 멈춰있는지

명확히 나와있다.

그러면 소스로 직접 그 부분을 찾아가면 뭐때문에 자원을 안 놔주고 있는지 쉽게 알 수 있다는 얘기.

 

보통은 synchronized가 걸려서 독접하고 있거나 혹은 생각없이 sleep을 줘서 안놔주고 있는 경우가 많다.

 

이렇게...

traces.txt에 held by라는 단어가 나오면 참 좋은데, 정말 좋은데, 쉽게 잡는데 어떻게 표현할 방법이 없는데...

문제는 저런 힌트가 없는 로그가 많다는 것이다.

분명 뒤져보면 그냥 wait걸린 부분은 꽤 되는데 중요한 held by가 없다...휴....

 

아직 이런 로그에 대한 분석과 원인 파악은 무리로 보여진다. 저런 건 그냥 시간 지나면 정상동작합니다~

라고 생각하는 수밖에...ㅡㅜ

 

흠... held by tid 는 보이는데 요 tid 녀석이 pool-1-thread-1 로 되있고 call stack 도 그냥 Thread.run 부터 시작하네요 ~_~ 당췌 어디서 호출하는건지 -_-;