detaching thread with interp frames error

[Jin Chiu]

Dalvik VM is giving me this error after calling DetachCurrentThread()
in a native method that was invoked as part of the remote service
call. The basic sequence of invocations is this:
Remote client -> Android remote service function -> Native method ->
AttachCurrentThread() -> DetachCurrentThread()

If I remove the DetachCurrentThread() call, everything works as
expected, but I don't know if this will cause resource leaks.

I'm a bit stumped as to what caused this error and how to debug it.
Could this be because the JNI invocation was done on a background
thread in the Binder threadpool instead of the main thread?


07-11 21:53:51.812: INFO/dalvikvm(778): "Binder Thread #1" prio=5
tid=11 RUNNABLE
07-11 21:53:51.852: INFO/dalvikvm(778): | group="main" sCount=0
dsCount=0 s=N obj=0x43d05a48 self=0x133700
07-11 21:53:51.852: INFO/dalvikvm(778): | sysTid=782 nice=0
sched=0/0 cgrp=default handle=1327928
07-11 21:53:51.852: INFO/dalvikvm(778): at
com.example.android.apis.app.RemoteService.attach(Native Method)
07-11 21:53:51.852: INFO/dalvikvm(778): at
com.example.android.apis.app.RemoteService.access$1(RemoteService.java:
48)
07-11 21:53:51.852: INFO/dalvikvm(778): at
com.example.android.apis.app.RemoteService
$3.registerCallback(RemoteService.java:151)
07-11 21:53:51.852: INFO/dalvikvm(778): at
com.example.android.apis.app.IServiceApi
$Stub.onTransact(IServiceApi.java:54)
07-11 21:53:51.862: INFO/dalvikvm(778): at
android.os.Binder.execTransact(Binder.java:287)
07-11 21:53:51.862: INFO/dalvikvm(778): at
dalvik.system.NativeStart.run(Native Method)
07-11 21:53:51.882: ERROR/dalvikvm(778): VM aborting
07-11 21:53:51.992: INFO/DEBUG(352): *** *** *** *** *** *** *** ***
*** *** *** *** *** *** *** ***
07-11 21:53:51.992: INFO/DEBUG(352): Build fingerprint: 'generic/sdk/
generic/:2.1-update1/ECLAIR/35983:eng/test-keys'
07-11 21:53:52.002: INFO/DEBUG(352): pid: 778, tid: 782 >>>
com.example.android.apis:remote <<<
07-11 21:53:52.002: INFO/DEBUG(352): signal 11 (SIGSEGV), fault addr
deadd00d
07-11 21:53:52.012: INFO/DEBUG(352): r0 00000354 r1 afe1331d r2
0000000c r3 deadd00d
07-11 21:53:52.012: INFO/DEBUG(352): r4 00000026 r5 ad07ff50 r6
fffec3dc r7 fffe57c4
07-11 21:53:52.012: INFO/DEBUG(352): r8 80a0214c r9 426f8ef8 10
426f8ee0 fp 00144308
07-11 21:53:52.022: INFO/DEBUG(352): ip ad080160 sp 44d20ac0 lr
afe142dd pc ad035452 cpsr 20000030
07-11 21:53:52.192: INFO/DEBUG(352): #00 pc 00035452 /
system/lib/libdvm.so
07-11 21:53:52.202: INFO/DEBUG(352): #01 pc 00041314 /
system/lib/libdvm.so
07-11 21:53:52.218: INFO/DEBUG(352): #02 pc 00037e3a /
system/lib/libdvm.so
07-11 21:53:52.222: INFO/DEBUG(352): #03 pc 00027a12 /
system/lib/libdvm.so
07-11 21:53:52.222: INFO/DEBUG(352): #04 pc 00000f72 /data/
data/com.example.android.apis/lib/libacjni.so
07-11 21:53:52.232: INFO/DEBUG(352): #05 pc 00000dc0 /data/
data/com.example.android.apis/lib/libacjni.so
07-11 21:53:52.232: INFO/DEBUG(352): #06 pc 0000f1f4 /
system/lib/libdvm.so
07-11 21:53:52.242: INFO/DEBUG(352): #07 pc 00038018 /
system/lib/libdvm.so
07-11 21:53:52.242: INFO/DEBUG(352): #08 pc 000316a2 /
system/lib/libdvm.so
07-11 21:53:52.252: INFO/DEBUG(352): #09 pc 0003d31c /
system/lib/libdvm.so
07-11 21:53:52.252: INFO/DEBUG(352): #10 pc 00013f58 /
system/lib/libdvm.so
07-11 21:53:52.262: INFO/DEBUG(352): #11 pc 00019888 /
system/lib/libdvm.so
07-11 21:53:52.262: INFO/DEBUG(352): #12 pc 00018d5c /
system/lib/libdvm.so
07-11 21:53:52.272: INFO/DEBUG(352): #13 pc 0004d6d0 /
system/lib/libdvm.so
07-11 21:53:52.272: INFO/DEBUG(352): #14 pc 0003af1e /
system/lib/libdvm.so
07-11 21:53:52.272: INFO/DEBUG(352): #15 pc 00029ec8 /
system/lib/libdvm.so
07-11 21:53:52.282: INFO/DEBUG(352): #16 pc 0003b8be /
system/lib/libandroid_runtime.so
07-11 21:53:52.282: INFO/DEBUG(352): #17 pc 0003bbd0 /
system/lib/libandroid_runtime.so
07-11 21:53:52.292: INFO/DEBUG(352): #18 pc 000154ac /
system/lib/libbinder.so
07-11 21:53:52.292: INFO/DEBUG(352): #19 pc 00018b84 /
system/lib/libbinder.so
07-11 21:53:52.302: INFO/DEBUG(352): #20 pc 00018d52 /
system/lib/libbinder.so
07-11 21:53:52.302: INFO/DEBUG(352): #21 pc 0001f424 /
system/lib/libbinder.so
07-11 21:53:52.302: INFO/DEBUG(352): #22 pc 0001b522 /
system/lib/libutils.so
07-11 21:53:52.312: INFO/DEBUG(352): #23 pc 00026ec6 /
system/lib/libandroid_runtime.so
07-11 21:53:52.312: INFO/DEBUG(352): #24 pc 0001b94a /
system/lib/libutils.so
07-11 21:53:52.322: INFO/DEBUG(352): #25 pc 00010000 /
system/lib/libc.so
07-11 21:53:52.322: INFO/DEBUG(352): #26 pc 0000fad4 /
system/lib/libc.so
07-11 21:53:52.322: INFO/DEBUG(352): code around pc:
07-11 21:53:52.332: INFO/DEBUG(352): ad035440 4808ecb6 6b9b5823
d0002b00 4b064798
07-11 21:53:52.332: INFO/DEBUG(352): ad035450 701c2426 ed28f7d9
0004ab1c fffe57c4
07-11 21:53:52.332: INFO/DEBUG(352): ad035460 fffe8c30 00000354
deadd00d b510b40e
07-11 21:53:52.332: INFO/DEBUG(352): code around lr:
07-11 21:53:52.341: INFO/DEBUG(352): afe142cc 220ce008 2b005eab
1c28d003 47889901
07-11 21:53:52.341: INFO/DEBUG(352): afe142dc 35544306 d5f43f01
2c006824 b003d1ee
07-11 21:53:52.341: INFO/DEBUG(352): afe142ec bdf01c30 00024b44
000000b4 1c0fb5f0
07-11 21:53:52.341: INFO/DEBUG(352): stack:
07-11 21:53:52.351: INFO/DEBUG(352): 44d20a80 00000015
07-11 21:53:52.351: INFO/DEBUG(352): 44d20a84 afe1334d /system/
lib/libc.so
07-11 21:53:52.351: INFO/DEBUG(352): 44d20a88 afe3902c /system/
lib/libc.so
07-11 21:53:52.351: INFO/DEBUG(352): 44d20a8c afe38fd8 /system/
lib/libc.so
07-11 21:53:52.362: INFO/DEBUG(352): 44d20a90 00000000
07-11 21:53:52.362: INFO/DEBUG(352): 44d20a94 afe142dd /system/
lib/libc.so
07-11 21:53:52.362: INFO/DEBUG(352): 44d20a98 00133700 [heap]
07-11 21:53:52.362: INFO/DEBUG(352): 44d20a9c afe1331d /system/
lib/libc.so
07-11 21:53:52.371: INFO/DEBUG(352): 44d20aa0 fffe57c4
07-11 21:53:52.371: INFO/DEBUG(352): 44d20aa4 ad07ff50 /system/
lib/libdvm.so
07-11 21:53:52.371: INFO/DEBUG(352): 44d20aa8 ad07ff50 /system/
lib/libdvm.so
07-11 21:53:52.371: INFO/DEBUG(352): 44d20aac fffec3dc
07-11 21:53:52.371: INFO/DEBUG(352): 44d20ab0 fffe57c4
07-11 21:53:52.381: INFO/DEBUG(352): 44d20ab4 afe1337f /system/
lib/libc.so
07-11 21:53:52.381: INFO/DEBUG(352): 44d20ab8 df002777
07-11 21:53:52.381: INFO/DEBUG(352): 44d20abc e3a070ad
07-11 21:53:52.381: INFO/DEBUG(352): #00 44d20ac0 00133700 [heap]
07-11 21:53:52.381: INFO/DEBUG(352): 44d20ac4 ad041319 /system/
lib/libdvm.so
07-11 21:53:52.381: INFO/DEBUG(352): #01 44d20ac8 0000001b
07-11 21:53:52.381: INFO/DEBUG(352): 44d20acc afbc30b8 /system/
lib/liblog.so
07-11 21:53:52.381: INFO/DEBUG(352): 44d20ad0 44d20f00
07-11 21:53:52.392: INFO/DEBUG(352): 44d20ad4 00133700 [heap]
07-11 21:53:52.392: INFO/DEBUG(352): 44d20ad8 00000001
07-11 21:53:52.392: INFO/DEBUG(352): 44d20adc 00000007
07-11 21:53:52.392: INFO/DEBUG(352): 44d20ae0 0014d470 [heap]
07-11 21:53:52.392: INFO/DEBUG(352): 44d20ae4 ad07ff50 /system/
lib/libdvm.so
07-11 21:53:52.401: INFO/DEBUG(352): 44d20ae8 0000aa48 [heap]
07-11 21:53:52.401: INFO/DEBUG(352): 44d20aec ad037e25 /system/
lib/libdvm.so
07-11 21:53:52.401: INFO/DEBUG(352): 44d20af0 0014d470 [heap]
07-11 21:53:52.401: INFO/DEBUG(352): 44d20af4 ad037e3f /system/
lib/libdvm.so

[Tim Mensch]

Jin Chiu wrote:
> Dalvik VM is giving me this error after calling DetachCurrentThread()
> in a native method that was invoked as part of the remote service
> call. The basic sequence of invocations is this:
> Remote client -> Android remote service function -> Native method ->
> AttachCurrentThread() -> DetachCurrentThread()
>

I'm no expert, but there's a JavaVM->GetEnv() call that I've been using
(and that's recommended on this page: http://bit.ly/6kcz5) to check if
the thread already has an allocated Java thread. In that case, I don't
call Attach or, possibly more importantly, Detach.

The docs seem to imply that Attach does nothing if the thread is already
attached, so it may simply not be safe to call Detach if you weren't the
one to actually Attach the thread.

Tim

__________ Information from ESET NOD32 Antivirus, version of virus signature database 5270 (20100711) __________

The message was checked by ESET NOD32 Antivirus.

http://www.eset.com

[andrej sarkic]

I'm no expert either, but it seems that it's not safe to call
DetachCurrentThread unless if the interpreted call stack is not empty.
In other words, it should really only be called just before the thread
exists. There are some comments in the dalvik source code in vm/
Thread.c about this.

[Tim Mensch]

Good point (assuming you mean when the thread "exits"--looks like a
typo). That is in fact how I use Attach/Detach: I spawn a thread with
pthreads, call Attach, run the process until I'm ready to quit, then
detach and exit. That seems solid for me. Now if I can only get GDB to
actually break in that thread. :(

Though, if I'm interpreting his question (and your comment) correctly,
the only way the call stack could not be empty is if his code is in a
thread that already had a VM. In which case GetEnv() will get the
reference, and simply never calling Detach would fix his issue (which
I'm guessing is the case).

Tim

[Lee Leclair]

Ah okay, I had no idea what DetachCurrentThread() did behind the
scenes or its proper usage patterns. I thought Attach() and Detach()
can be invoked from any native thread any time when it needs to make a
Java callback but doesn't have a JEnv handle. So it looks like instead
of doing potentially multiple Attach/Detach calls throughout the
lifetime of a thread, I should be only doing an Attach() when the
thread is created and Detach() before the thread exits.

[andrej sarkic]

Yes, that was a typo - I meant to write "exits". Thanks.

[fadden]

On Jul 11, 3:07 pm, Jin Chiu <live2drea...@gmail.com> wrote:
> I'm a bit stumped as to what caused this error and how to debug it.
> Could this be because the JNI invocation was done on a background
> thread in the Binder threadpool instead of the main thread?

...

> 07-11 21:53:51.812: INFO/dalvikvm(778): "Binder Thread #1" prio=5
> tid=11 RUNNABLE
> 07-11 21:53:51.852: INFO/dalvikvm(778):   | group="main" sCount=0
> dsCount=0 s=N obj=0x43d05a48 self=0x133700
> 07-11 21:53:51.852: INFO/dalvikvm(778):   | sysTid=782 nice=0
> sched=0/0 cgrp=default handle=1327928

I think the other posts here have likely figured the problem out
(Attach and Detach do not stack).

For future reference, the specific complaint from the VM should be
just above the part where you started pasting. Also, you don't need
to include the "code around pc" and "stack" parts; they're really only
useful when the crash is "weird". 0xdeadd00d indicates a deliberate
VM abort, and it's generally pretty specific about letting you know
why.