blob: 95ef6a7e03c6941c9e480fe83b17507e4873d9ed [file] [log] [blame]
David Warren1b4feb42009-04-30 17:16:25 -07001page.title=Debugging Native Code
2pdk.version=1.0
3@jd:body
4
5
6<a name="toc"/>
7<div style="padding:10px">
8 <a href="#Capturing_logs">Capturing logs</a><br/>
9 <a href="#Debug_Scenarios">Debug Scenarios</a><br/>
10 <div style="padding-left:40px">
11 <a href="#Crash_but_no_exit_stuck">Crash but no exit...stuck</a><br/>
12 <a href="#Blocked_in_a_syscall">Blocked in a syscall</a><br/>
13 <a href="#Crash_in_C_C_code">Crash in C / C++ code</a>
14 </div>
15</div>
16
17
18<a name="Capturing_logs"></a><h2>Capturing logs</h2>
19
20<p>To capture log output:</p>
21<ol>
22<li> Produce a process list with <code>ps</code> (<code>ps -t</code> if you want verbose thread feedback).</li>
23<li> Dump kernel messages with <code>dmesg</code>.</li>
24<li> Get verbose log messages with <code>logcat '*:v' &amp;</code> (running in bg with &amp; is important).</li>
25
26</ol>
27
28<a name="Debug_Scenarios"></a><h2>Debug Scenarios</h2>
29<pre class="prettify">
30 # command to device shell (via adb)
31 % command to host pc shell
32</pre>
33<p>
34</p>
35
36<a name="Crash_but_no_exit_stuck"></a><h3>Crash but no exit...stuck</h3>
37<pre class="prettify">
38&gt;&gt;&gt; gtalk app crashed but did not actually exit or seems stuck
39&gt;&gt;&gt; let's check the debug logs and see if there's anything to see:
40
41# logcat &amp;
42
43...
44E/WindowManager( 182): Window client android.util.BinderProxy@4089f948 has died!! Removing window.
45W/WindowManager( 182): **** WINDOW CLIENT android.view.WindowProxy@40882248 DIED!
46W/ActivityManager( 182): **** APPLICATION com.google.android.gtalk DIED!
47I/ServiceManager( 257): Executing: /android/bin/app_process (link=/tmp/android-servicemanager/com.google.android.gtalk, wrapper=/tmp/android-servi
48cemanager/com.google.android.gtalk)
49I/appproc ( 257): App process is starting with pid=257, class=android/activity/ActivityThread.
50I/ ( 257): java.io.FileDescriptor: class initialization
51I/SurfaceFlinger.HW( 182): About to give-up screen
52I/SurfaceFlinger.HW( 182): screen given-up
53I/SurfaceFlinger.HW( 182): Screen about to return
54I/SurfaceFlinger.HW( 182): screen returned
55I/SurfaceFlinger.HW( 182): About to give-up screen
56I/SurfaceFlinger.HW( 182): screen given-up
57I/SurfaceFlinger.HW( 182): Screen about to return
58...
59
60&gt;&gt;&gt; looks like the system launched a replacement gtalk process
61&gt;&gt;&gt; but it is stuck somehow
62
63# ps
64PID PPID VSIZE RSS WCHAN PC NAME
65257 181 45780 5292 ffffffff 53030cb4 S com.google.andr
66
67&gt;&gt;&gt; gtalk's PC is at 53030cb4
68&gt;&gt;&gt; look at the memory map to find out what lib is 0x53......
69
70# cat /proc/257/maps
71...
7251000000-5107c000 rwxp 00000000 1f:03 619 /android/lib/libutils.so
7352000000-52013000 rwxp 00000000 1f:03 639 /android/lib/libz.so
7453000000-53039000 rwxp 00000000 1f:03 668 /android/lib/libc.so
7553039000-53042000 rw-p 53039000 00:00 0
7654000000-54002000 rwxp 00000000 1f:03 658 /android/lib/libstdc++.so
77...
78
79&gt;&gt;&gt; let's disassemble libc and find out where we are?!
80
81% prebuilt/Linux/toolchain-eabi-4.2.1/bin/arm-elf-objdump -d out/target/product/sooner/symbols/android/lib/libc.so
82
8300030ca4 &lt;__futex_wait&gt;:
84 30ca4: e1a03002 mov r3, r2
85 30ca8: e1a02001 mov r2, r1
86 30cac: e3a01000 mov r1, #0 ; 0x0
87 30cb0: ef9000f0 swi 0x009000f0
88 30cb4: e12fff1e bx lr
89</pre>
90
91<a name="Blocked_in_a_syscall"></a><h4>Blocked in a syscall</h4>
92
93<pre class="prettify">
94&gt;&gt;&gt; we're blocked in a syscall, let's see what gdb can show us
95&gt;&gt;&gt; (we could have done this first if we wanted to)
96
97&gt;&gt;&gt; tell adb to forward the GDB port
98% adb forward tcp:5039 tcp:5039
99
100&gt;&gt;&gt; start gdb server and attach to process 257 (from example above)
101# gdbserver :5039 --attach 257 &amp;
102Attached; pid = 257
103Listening on port 5039
104
105% prebuilt/Linux/toolchain-eabi-4.2.1/bin/arm-elf-gdb out/target/product/sooner/system/bin/app_process
106(gdb) set solib-absolute-prefix /work/android/device/out/target/product/sooner/symbols
107(gdb) set solib-search-path /work/android/device/out/target/product/sooner/symbols/android/lib
108(gdb) target remote :5039
109Remote debugging using :5039
1100x53030cb4 in ?? ()
111Current language: auto; currently asm
112
113&gt;&gt;&gt; Don't let other threads get scheduled while we're debugging.
114&gt;&gt;&gt; You should "set scheduler-locking off" before issuing a "continue",
115&gt;&gt;&gt; or else your thread may get stuck on a futex or other
116&gt;&gt;&gt; spinlock because no other thread can release it.
117(gdb) set scheduler-locking on
118
119&gt;&gt;&gt; Ignore SIGUSR1 if you're using JamVM. Shouldn't hurt if you're not.
120(gdb) handle SIGUSR1 noprint
121
122(gdb) where
123#0 __futex_wait () at system/klibc/android/atomics_arm.S:88
124#1 0x53010eb8 in pthread_cond_timedwait (cond=0x12081c, mutex=0x120818, abstime=0xffffffff)
125 at system/klibc/android/pthread.c:490
126#2 0x6b01c848 in monitorWait (mon=0x120818, self=0x6b039ba4, ms=0, ns=0) at extlibs/jamvm-1.4.1/src/lock.c:194
127#3 0x6b01d1d8 in objectWait (obj=0x408091c0, ms=0, ns=0) at extlibs/jamvm-1.4.1/src/lock.c:420
128#4 0x6b01d4c8 in jamWait (clazz=0xfffffffc, mb=0x0, ostack=0x2e188) at extlibs/jamvm-1.4.1/src/natives.c:91
129#5 0x6b013b2c in resolveNativeWrapper (clazz=0x408001d0, mb=0x41798, ostack=0x2e188) at extlibs/jamvm-1.4.1/src/dll.c:236
130#6 0x6b015c04 in executeJava () at extlibs/jamvm-1.4.1/src/interp.c:2614
131#7 0x6b01471c in executeMethodVaList (ob=0x0, clazz=0x40808f20, mb=0x12563c, jargs=0xbe9229f4)
132 at extlibs/jamvm-1.4.1/src/execute.c:91
133#8 0x6b01bcd0 in Jam_CallStaticVoidMethod (env=0xfffffffc, klass=0x0, methodID=0x12563c)
134 at extlibs/jamvm-1.4.1/src/jni.c:1063
135#9 0x58025b2c in android::AndroidRuntime::callStatic (this=0xfffffffc,
136 className=0xbe922f0a "android/activity/ActivityThread", methodName=0x57000b7c "main")
137 at libs/android_runtime/AndroidRuntime.cpp:215
138#10 0x57000504 in android::app_init (className=0xbe922f0a "android/activity/ActivityThread")
139 at servers/app/library/app_init.cpp:20
140#11 0x000089b0 in android::sp&lt;android::ProcessState&gt;::~sp ()
141#12 0x000089b0 in android::sp&lt;android::ProcessState&gt;::~sp ()
142Previous frame identical to this frame (corrupt stack?)
143
144(gdb) info threads
145 7 thread 263 __ioctl () at system/klibc/syscalls/__ioctl.S:12
146 6 thread 262 accept () at system/klibc/syscalls/accept.S:12
147 5 thread 261 __futex_wait () at system/klibc/android/atomics_arm.S:88
148 4 thread 260 __futex_wait () at system/klibc/android/atomics_arm.S:88
149 3 thread 259 __futex_wait () at system/klibc/android/atomics_arm.S:88
150 2 thread 258 __sigsuspend () at system/klibc/syscalls/__sigsuspend.S:12
151 1 thread 257 __futex_wait () at system/klibc/android/atomics_arm.S:88
152
153
154(gdb) thread 7
155[Switching to thread 7 (thread 263)]#0 __ioctl () at system/klibc/syscalls/__ioctl.S:12
15612 movs r0, r0
157(gdb) bt
158#0 __ioctl () at system/klibc/syscalls/__ioctl.S:12
159#1 0x53010704 in ioctl (fd=-512, request=-1072143871) at system/klibc/android/ioctl.c:22
160#2 0x51040ac0 in android::IPCThreadState::talkWithDriver (this=0x1207b8, doReceive=true) at RefBase.h:83
161#3 0x510418a0 in android::IPCThreadState::joinThreadPool (this=0x1207b8, isMain=false)
162 at libs/utils/IPCThreadState.cpp:343
163#4 0x51046004 in android::PoolThread::threadLoop (this=0xfffffe00) at libs/utils/ProcessState.cpp:52
164#5 0x51036428 in android::Thread::_threadLoop (user=0xfffffe00) at libs/utils/Threads.cpp:1100
165#6 0x58025c68 in android::AndroidRuntime::javaThreadShell (args=0x105ffe28) at libs/android_runtime/AndroidRuntime.cpp:540
166
167(gdb) thread 6
168[Switching to thread 6 (thread 262)]#0 accept () at system/klibc/syscalls/accept.S:12
16912 movs r0, r0
170(gdb) bt
171#0 accept () at system/klibc/syscalls/accept.S:12
172#1 0x6b0334e4 in jdwpAcceptConnection (state=0xfffffe00) at extlibs/jamvm-1.4.1/jdwp/JdwpNet.c:213
173#2 0x6b032660 in jdwpThreadEntry (self=0x4d020) at extlibs/jamvm-1.4.1/jdwp/JdwpMain.c:37
174#3 0x6b022c2c in shell (args=0x4d960) at extlibs/jamvm-1.4.1/src/thread.c:629
175
176(gdb) thread 5
177[Switching to thread 5 (thread 261)]#0 __futex_wait () at system/klibc/android/atomics_arm.S:88
17888 bx lr
179(gdb) bt
180#0 __futex_wait () at system/klibc/android/atomics_arm.S:88
181#1 0x53010f48 in pthread_cond_timeout (cond=0x6b039b64, mutex=0x6b039b60, msecs=0) at system/klibc/android/pthread.c:513
182#2 0x6b01c8d0 in monitorWait (mon=0x6b039b60, self=0x4d400, ms=1000, ns=272629312) at extlibs/jamvm-1.4.1/src/lock.c:183
183#3 0x6b022084 in threadSleep (thread=0x4d400, ms=1000, ns=272629312) at extlibs/jamvm-1.4.1/src/thread.c:215
184#4 0x6b00d4fc in asyncGCThreadLoop (self=0x4d400) at extlibs/jamvm-1.4.1/src/alloc.c:1179
185#5 0x6b022c2c in shell (args=0x4d480) at extlibs/jamvm-1.4.1/src/thread.c:629
186
187(gdb) thread 4
188[Switching to thread 4 (thread 260)]#0 __futex_wait () at system/klibc/android/atomics_arm.S:88
18988 bx lr
190(gdb) bt
191#0 __futex_wait () at system/klibc/android/atomics_arm.S:88
192#1 0x53010eb8 in pthread_cond_timedwait (cond=0x6b039934, mutex=0x6b039930, abstime=0x0)
193 at system/klibc/android/pthread.c:490
194#2 0x6b00b3ec in referenceHandlerThreadLoop (self=0x4d360) at extlibs/jamvm-1.4.1/src/alloc.c:1247
195#3 0x6b022c2c in shell (args=0x4d960) at extlibs/jamvm-1.4.1/src/thread.c:629
196
197(gdb) thread 3
198[Switching to thread 3 (thread 259)]#0 __futex_wait () at system/klibc/android/atomics_arm.S:88
19988 bx lr
200(gdb) bt
201#0 __futex_wait () at system/klibc/android/atomics_arm.S:88
202#1 0x53010eb8 in pthread_cond_timedwait (cond=0x6b03992c, mutex=0x6b039928, abstime=0x0)
203 at system/klibc/android/pthread.c:490
204#2 0x6b00b1dc in finalizerThreadLoop (self=0x4d8e0) at extlibs/jamvm-1.4.1/src/alloc.c:1238
205#3 0x6b022c2c in shell (args=0x4d960) at extlibs/jamvm-1.4.1/src/thread.c:629
206
207(gdb) thread 2
208[Switching to thread 2 (thread 258)]#0 __sigsuspend () at system/klibc/syscalls/__sigsuspend.S:12
20912 movs r0, r0
210(gdb) bt
211#0 __sigsuspend () at system/klibc/syscalls/__sigsuspend.S:12
212#1 0x6b023814 in dumpThreadsLoop (self=0x51b98) at extlibs/jamvm-1.4.1/src/thread.c:1107
213#2 0x6b022c2c in shell (args=0x51b58) at extlibs/jamvm-1.4.1/src/thread.c:629
214</pre>
215
216<a name="Crash_in_C_C_code"></a><h3>Crash in C / C++ code</h3>
217<p>If it crashes, connect with <code>aproto</code> and run <code>logcat</code> on the device. You should see output like this:</p>
218
219<pre class="prettify">
220I/ActivityManager( 188): Starting activity: Intent { component=com.android.calendar.MonthScreen }
221I/ActivityManager( 188): Starting application com.android.calendar to host activity com.android.calendar.MonthScree
222n
223I/ServiceManager( 417): Executing: /android/bin/app_process (link=/android/bin/app_process, wrapper=/android/bin/app_process)
224I/DEBUG: -- observer of pid 417 starting --
225I/appproc ( 417): App process is starting with pid=417, class=android/activity/ActivityThread.
226I/DEBUG: -- observer of pid 417 exiting --
227I/DEBUG: -- observer of pid 420 starting --
228I/DEBUG: *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
229I/DEBUG: pid: 373, tid: 401 &gt;&gt;&gt; android.content.providers.pim &lt;&lt;&lt;
230I/DEBUG: signal 11 (SIGSEGV), fault addr 00000000
231I/DEBUG: r0 ffffffff r1 00000000 r2 00000454 r3 002136d4
232I/DEBUG: r4 002136c0 r5 40804810 r6 0022dc70 r7 00000010
233I/DEBUG: r8 0020a258 r9 00000014 10 6b039074 fp 109ffcf8
234I/DEBUG: ip 6b039e90 sp 109ffc0c lr 580239f0 pc 6b0156a0
235I/DEBUG: #01 pc 6b0156a0 /android/lib/libjamvm.so
236I/DEBUG: #01 lr 580239f0 /android/lib/libandroid_runtime.so
237I/DEBUG: #02 pc 6b01481c /android/lib/libjamvm.so
238I/DEBUG: #03 pc 6b0148a4 /android/lib/libjamvm.so
239I/DEBUG: #04 pc 6b00ebc0 /android/lib/libjamvm.so
240I/DEBUG: #05 pc 6b02166c /android/lib/libjamvm.so
241I/DEBUG: #06 pc 6b01657c /android/lib/libjamvm.so
242I/DEBUG: #07 pc 6b01481c /android/lib/libjamvm.so
243I/DEBUG: #08 pc 6b0148a4 /android/lib/libjamvm.so
244I/DEBUG: #09 pc 6b0235c0 /android/lib/libjamvm.so
245I/DEBUG: #10 pc 5300fac4 /android/lib/libc.so
246I/DEBUG: #11 pc 5300fc5c /android/lib/libc.so
247I/DEBUG: -- observer of pid 373 exiting --
248I/DEBUG: -- observer of pid 423 starting --
249</pre>
250
251<p>If debugging output indicates an error in C or C++ code, the addresses aren't particularly useful, but the debugging symbols aren't present on the device. Use the "stack" tool to convert these addresses to files and line numbers, for example:</p>
252
253<pre class="prettify">
254pid: 373, tid: 401 &gt;&gt;&gt; android.content.providers.pim &lt;&lt;&lt;
255
256 signal 11 (SIGSEGV), fault addr 00000000
257 r0 ffffffff r1 00000000 r2 00000454 r3 002136d4
258 r4 002136c0 r5 40804810 r6 0022dc70 r7 00000010
259 r8 0020a258 r9 00000014 10 6b039074 fp 109ffcf8
260 r8 0020a258 r9 00000014 10 6b039074 fp 109ffcf8
261
262 ADDR FUNCTION FILE:LINE
263 6b0156a0 executeJava extlibs/jamvm-1.4.1/src/interp.c:2674
264 580239f0 android_util_Parcel_freeBuffer libs/android_runtime/android_util_Binder.cpp:765
265 6b01481c executeMethodVaList extlibs/jamvm- 1.4.1/src/execute.c:91
266 6b0148a4 executeMethodArgs extlibs/jamvm-1.4.1/src/execute.c:67
267 6b00ebc0 initClass extlibs/jamvm-1.4.1/src/class.c:1124
268 6b02166c resolveMethod extlibs/jamvm- 1.4.1/src/resolve.c:197
269 6b01657c executeJava extlibs/jamvm-1.4.1/src/interp.c:2237
270 6b01481c executeMethodVaList extlibs/jamvm-1.4.1/src/execute.c:91
271 6b0148a4 executeMethodArgs extlibs/jamvm- 1.4.1/src/execute.c:67
272 6b0235c0 threadStart extlibs/jamvm-1.4.1/src/thread.c:355
273 5300fac4 __thread_entry system/klibc/android/pthread.c:59
274 5300fc5c pthread_create system/klibc/android/pthread.c:182
275</pre>
276
277<p>If you save the debug spew into a file called <code>out.txt</code>, you can pass that to the tool, like this:
278</p>
279
280<pre class="prettify">
281./tools/stack out.txt
282</pre>
283
284<p>Or you can run <code>logcat</code> without any parameters and it will read from <code>stdin</code>. You can then paste output into the terminal or pipe it. Run <code>logcat</code> from the top of the tree in the environment in which you do builds so that the application can determine relative paths to the toolchain to use to decode the object files.
285</body>
286</html>