Updates from C thread leads to Choreographer skipping frames

Question

I have a C thread that is making requests and receiving updates from a server. The updates are sent to Java through JNI calls. My problem happens when I'm receiving a player's inventory which can contain up to 100 items (100 responses from the server, I cannot modify this part). Sometimes the problem happens, sometimes not but the bigger the inventory is, the more often I have this issue.

I don't get any exception in the logcat except the following message :

06-10 10:09:46.085: I/Choreographer(23815): Skipped 87 frames!  The application may be doing too much work on its main thread.

And then my app closes. I also need to say that even when I comment the lines where I update the UI with runOnUiThread the app crash.

I tried to check if I'm on the UI Thread when I return to Java with JNI but Looper.myLooper() == Looper.getMainLooper() return false.

Anyone experienced the same problem ? Are the C threads related to the main thread somehow ? Thanks

EDIT

When I receive an update from the server the following calls are made :

From a Java Thread (not the UI thread) : call a C function named notifyAll

From notifyAll call a C function named update which will call its equivalent in Java (see code below)

void UpdateListenerWrapper::update(Update& u) {
    // Retrieve the current JNIEnv* with the cached JVM
    int status;
    JNIEnv* env;
    bool isAttached = false;

    status = gCachedJVM->GetEnv((void **) &env, JNI_VERSION_1_2);
    if(status < 0) {
        __android_log_print(ANDROID_LOG_ERROR, "UpdateListenerWrapper", "Failed to get JNI environment");
        status = gCachedJVM->AttachCurrentThread(&env, NULL);
        if(status < 0) {
            __android_log_print(ANDROID_LOG_ERROR, "UpdateListenerWrapper", "Failed to attach current thread");
            return;
        }
        isAttached = true;
    }

    jmethodID update = env->GetMethodID(gClazzUpdateListenerWrapper, "update", "(J)V"); // J stands for Java long type

    // Call Java method update from jUpdateListener object
    env->CallVoidMethod(jUpdateListener, update, (jlong)(intptr_t)&u); // Pointer as agument, we'll build the Update object in Java

    if (isAttached) {
        gCachedJVM->DetachCurrentThread();
    }
}

I think the problem is at this line gCachedJVM->GetEnv((void **) &env, JNI_VERSION_1_2); and maybe GetEnv return a pointer for the UI thread. Could that be the problem ? How can I fix this ?

fadden · Answer 1 · 2013-06-12T14:46:35.480

The app crash is unrelated to the Choreographer complaints. Those are just a warning that indicates the animation is being starved.

You really want to be viewing the logcat output in a mode that shows thread IDs. I recommend adb logcat -v threadtime from the command line. If you put a log message at the start of your server interaction you can easily see if it's running on the UI thread (thread ID and process ID are the same -- not guaranteed by the system, but reliably true in apps).

Never do network or database I/O on the main thread. If it takes too long, the system gets bored and decides that your app is not responding.

Calling into native code through JNI does not switch you to a different thread. There are not C threads and Java threads, just threads, which can call in and out of code written in C and Java.

Re: question updates...

GetEnv always returns a pointer to data for the current thread. Also, CallVoidMethod always happens in the current thread; even if you passed in the wrong JNIEnv it wouldn't "jump" threads.

The GetMethodID call can be expensive in a class with a lot of methods, so you should try to cache that at the same point where gClassUpdateListenerWrapper is set up. Attaching and detaching the thread from the VM can also be expensive and is something best avoided -- and if you're calling here from a Java method, then by definition it's attached already. I would guess that isAttached is never being set.

That doesn't really explain why the Choreographer is starving though. I think you still need to add a log message to C update() and use logcat -v threadtime to get a sense for what is happening on which threads, and use traceview to see where the time is going.

Thanks for your answer. Actually I think I found where my problem comes from but I have no idea on how to solve that. See my updates — Fr4nz, Jun 12 '13 at 11:52
So I first tried to cache the method ID but I had the same result as before. I then tried to use `logcat -v threadtime` and I get this log `06-13 17:25:38.505 6252 6762 E UpdateListenerWrapper: ::update1` which seems fine because it's not running on the main thread. After that I tried to use traceview (http://stackoverflow.com/a/14872118/1304830) but my app started to crash instantly when I was requesting an update and recording at the same time. — Fr4nz, Jun 13 '13 at 15:55
Your comments would maybe help someone else, you deserve an up vote — Fr4nz, Jun 18 '13 at 15:47

score 0 · Accepted Answer · answered Jun 18 '13 at 15:45

I found the solution to my problem but it's kind of specific to my app. In the update function (Java side), I had a case which had no break and each updates were triggering new network calls (not in the UI thread). Nasty to find but thanks for your time and your answers, you helped me to solve this :)

Updates from C thread leads to Choreographer skipping frames

2 Answers2