[android-porting] Re: Debugging Dalvik start-up / JarVerifier problem on x86-64 Linux build

2011-07-12 Thread Stephen Kell
> The debugger support in the VM will wait a second or two for the
> debugger to "settle" before continuing if you use
> android.os.Debug.waitForDebugger().  That's not enough to enter
> breakpoints by hand, but if you use a more sophisticated program like
> Eclipse it gives the debugger enough time to set breakpoints before
> resuming.

Ah, cool -- sounds useful. That was the reminder I needed to move
to the Eclipse front-end anyhow, and has helped -- thanks!

> That does look peculiar.  I would guess the JNIEnv is bogus, and
> you're looking at a bunch of memory that isn't actually holding a JNI
> function table.

Indeed, silly me -- the stack seems to be corrupt. I have now
sidestepped this whole problem by commenting out the jar verification
process (the initial exceptions were complaining about failing to find
public keys, before being turned into other exceptions with a less
helpful message -- I guess I need to install Android public keys
locally
for the Jars to verify? not sure why they're not in the distribution,
but no matter).

The fun's not over yet -- getting even stranger segfaults (without
non-stop gdb) in some native calls originating in SystemServer
(calling
sqlite stuff). I might post back about those once I've investigated.

-- 
unsubscribe: android-porting+unsubscr...@googlegroups.com
website: http://groups.google.com/group/android-porting


[android-porting] Re: Debugging Dalvik start-up / JarVerifier problem on x86-64 Linux build

2011-07-08 Thread fadden
On Jul 7, 10:50 am, Stephen Kell  wrote:
> #0  0x00ad97fb in dvmChangeStatus (self=0xf0d057d8,
> newStatus=THREAD_RUNNING)
>     at dalvik/vm/Thread.c:3160
> #1  0x00ab0bb5 in dvmDbgThreadContinuing (status=1) at dalvik/vm/
> Debugger.c:502
> #2  0x00afb823 in dvmJdwpPostThreadChange (state=0x805dbe8,
>     threadId=, start=true)
>     at dalvik/vm/jdwp/JdwpEvent.c:992
> #3  0x00ab3958 in dvmDbgPostThreadStart (thread=0xf0d057d8)
>     at dalvik/vm/Debugger.c:2605

Interesting -- looks like a bad state change during debugger setup.
Should be okay to ignore.

> So I can now attach jdb okay, I have a different problem. To make jdb
> finish attaching (and give me a prompt) I have to resume the process
> in
> gdb. If I resume all threads, then I don't have time to intervene
> (since
> jdb doesn't suspend execution when it attaches) before the failure
> happens. If I try running the VM in gdb's "non-stop" mode, it
> segfaults.

The debugger support in the VM will wait a second or two for the
debugger to "settle" before continuing if you use
android.os.Debug.waitForDebugger().  That's not enough to enter
breakpoints by hand, but if you use a more sophisticated program like
Eclipse it gives the debugger enough time to set breakpoints before
resuming.

The delay is defined in Debug.java:

/*
 * How long to wait for the debugger to finish sending requests.
I've
 * seen this hit 800msec on the device while waiting for a
response
 * to travel over USB and get processed, so we take that and add
 * half a second.
 */
private static final int MIN_DEBUGGER_IDLE = 1300;  // msec

> It
> looks like the JNI dispatch table has been trashed---some of the
> entries
> are plausible, but others are clearly bogus.

That does look peculiar.  I would guess the JNIEnv is bogus, and
you're looking at a bunch of memory that isn't actually holding a JNI
function table.

-- 
unsubscribe: android-porting+unsubscr...@googlegroups.com
website: http://groups.google.com/group/android-porting


[android-porting] Re: Debugging Dalvik start-up / JarVerifier problem on x86-64 Linux build

2011-07-07 Thread Stephen Kell
> You may be able to just remove the assertion for your purposes.
>
> For some reason a thread in the "running" state is trying to change to
> "running", i.e. it's a do-nothing operation that just wastes time.  It
> also represents a potential problem in that a bit of code that was
> assuming it was in some other state has made incorrect assumptions,
> which could lead to a hang or correctness problems (e.g. it thought it
> was in "vmwait" so blocking synchronization ops are okay).  The gdb
> backtrace at the point of failure might be interesting, to see which
> bit of code is doing the redundant update.

Cool -- thanks for this (and sorry for the delay).  Here's the
backtrace:

0x00ad97fb in dvmChangeStatus (self=0xf0d057d8,
newStatus=THREAD_RUNNING)
at dalvik/vm/Thread.c:3160
3160assert(oldStatus != THREAD_RUNNING);
(gdb) bt
#0  0x00ad97fb in dvmChangeStatus (self=0xf0d057d8,
newStatus=THREAD_RUNNING)
at dalvik/vm/Thread.c:3160
#1  0x00ab0bb5 in dvmDbgThreadContinuing (status=1) at dalvik/vm/
Debugger.c:502
#2  0x00afb823 in dvmJdwpPostThreadChange (state=0x805dbe8,
threadId=, start=true)
at dalvik/vm/jdwp/JdwpEvent.c:992
#3  0x00ab3958 in dvmDbgPostThreadStart (thread=0xf0d057d8)
at dalvik/vm/Debugger.c:2605
#4  0x00ada882 in interpThreadStart (arg=0xf0d057d8) at dalvik/vm/
Thread.c:1687
#5  0x0045f919 in start_thread () from /lib/libpthread.so.0
#6  0x0080bd4e in clone () from /lib/libc.so.6

It doesn't look too informative to me. But I can confirm that
taking out the assertion doesn't obviously break anything.

So I can now attach jdb okay, I have a different problem. To make jdb
finish attaching (and give me a prompt) I have to resume the process
in
gdb. If I resume all threads, then I don't have time to intervene
(since
jdb doesn't suspend execution when it attaches) before the failure
happens. If I try running the VM in gdb's "non-stop" mode, it
segfaults.

I'm going to try hacking in a pause just before the problem Java code,
so
that I can suspend from within jdb. But any clues on this segfault?
It
looks like the JNI dispatch table has been trashed---some of the
entries
are plausible, but others are clearly bogus.

(gdb) set non-stop
(gdb) break main
Breakpoint 1 at 0x804f7f2: file frameworks/base/cmds/runtime/
main_runtime.cpp, line 343.
(gdb) run
Starting program: /home/scratch/skell/android-platform-built-gcc/out/
host/linux-x86/pr/sim/system/bin/runtime
ERROR: ld.so: object '/home/scratch/skell/android-platform-built-gcc/
out/host/linux-x86/pr/sim/system/lib/libwrapsim.so' from LD_PRELOAD
cannot be preloaded: ignored.
[Thread debugging using libthread_db enabled]

Breakpoint 1, main (argc=1, argv=0xc144)
at frameworks/base/cmds/runtime/main_runtime.cpp:343
343 {
Missing separate debuginfos, use: debuginfo-install alsa-
lib-1.0.23-1.fc13.i686 glibc-2.12.2-1.i686 libgcc-4.4.4-10.fc13.i686
libstdc++-4.4.4-10.fc13.i686
(gdb) break AndroidRuntime.cpp:974
Breakpoint 2 at 0x1f73be: file frameworks/base/core/jni/
AndroidRuntime.cpp, line 974.
(gdb) cont
Continuing.
I/runtime (30688): commandline args:
I/runtime (30688):0: '/home/scratch/skell/android-platform-built-
gcc/out/host/linux-x86/pr/sim/system/bin/runtime'
I/runtime (30688): Startup: sys='/home/scratch/skell/android-platform-
built-gcc/out/host/linux-x86/pr/sim/system' asset='/home/scratch/skell/
android-platform-built-gcc/out/host/linux-x86/pr/sim/system/app'
data='/home/scratch/skell/android-platform-built-gcc/out/host/linux-
x86/pr/sim/data'
W/ProcessState(30688): Opening '/dev/binder' failed: No such file or
directory
I/runtime (30688): Entered boot_init()!
I/runtime (30688): Binder driver not found.  Processes not supported.
I/AndroidRuntime(30688): Using TCP socket for JDWP
I/AndroidRuntime(30688): Assertions enabled: '-ea'
[New Thread 0x1edeb70 (LWP 30923)]
[New Thread 0x28dfb70 (LWP 30924)]
[New Thread 0x32e0b70 (LWP 30925)]
[New Thread 0x3ce1b70 (LWP 30926)]

Breakpoint 2, android::AndroidRuntime::start (this=0x8055fa8,
className=0x80507b0 "com/android/server/SystemServer",
startSystemServer=false) at frameworks/base/core/jni/
AndroidRuntime.cpp:974
974 env->CallStaticVoidMethod(startClass, startMeth,
strArray);
(gdb) step
_JNIEnv::CallStaticVoidMethod (this=0xf6fe1090, clazz=0xf6acce14,
methodID=0xf6fe0f58)
at dalvik/libnativehelper/include/nativehelper/jni.h:789
789 void CallStaticVoidMethod(jclass clazz, jmethodID
methodID, ...)
(gdb) step
792 va_start(args, methodID);
(gdb) step
793 functions->CallStaticVoidMethodV(this, clazz,
methodID, args);
(gdb) step

Program received signal SIGSEGV, Segmentation fault.
0x in ?? ()
(gdb) bt
#0  0x in ?? ()
#1  0x001f790a in _JNIEnv::CallStaticVoidMethod (this=0xf6fe1090,
clazz=0xf6acce14, methodID=0xf6fe0f58)
at dalvik/libnativehelper/include/nativehelper/jni.h:793
#2  0x080548c8 in ?? ()
Backtrace stopped: previous frame inner to this frame (corrupt stack?)

[android-porting] Re: Debugging Dalvik start-up / JarVerifier problem on x86-64 Linux build

2011-07-06 Thread fadden
On Jul 5, 4:53 am, Stephen Kell  wrote:
> If I break the dalvikvm in gdb before it does
> Check_CallStaticVoidMethodV,
> then attach jdb and resume both, I get the following.
>
> E/dalvikvm(26824): ASSERT FAILED (dalvik/vm/Thread.c:3160): oldStatus !
> = THREAD_RUNNING

You may be able to just remove the assertion for your purposes.

For some reason a thread in the "running" state is trying to change to
"running", i.e. it's a do-nothing operation that just wastes time.  It
also represents a potential problem in that a bit of code that was
assuming it was in some other state has made incorrect assumptions,
which could lead to a hang or correctness problems (e.g. it thought it
was in "vmwait" so blocking synchronization ops are okay).  The gdb
backtrace at the point of failure might be interesting, to see which
bit of code is doing the redundant update.

-- 
unsubscribe: android-porting+unsubscr...@googlegroups.com
website: http://groups.google.com/group/android-porting