Don’t let callbacks cross the bridge

A common theme in talks and blogs about optimising and debugging your Titanium app is The Bridge. The bridge is the Titanium SDK that translates your JavaScript code to native API and UI commands.

The Toll on the Kroll Bridge

Take The Toll on the Kroll Bridge (2012!) by David Bankier for example. He explains why it is better to just pass a model’s ID when you fire an event and then lookup the model itself up again in the listener.

Fighting a random bug

A few weeks ago I was helping out with an app and we lost way too much time fighting what seemed like a random crash on Android. Now when I see something random two options come to my mind:

  1. It happens in a callback or event listener.
  2. It happens on the native side.

The crashlog was different every time, but always looked something like this:

[ERROR] dalvikvm: JNI ERROR (app bug): local reference table overflow (max=512)
[WARN]  dalvikvm: JNI local reference table (0xb815feb0) dump:
[WARN]  dalvikvm:   Last 10 entries (of 512):
[WARN]  dalvikvm:       511: 0xa545ed20 java.util.HashMap
[WARN]  dalvikvm:       510: 0xa545ed08 java.lang.Object[] (1 elements)
[WARN]  dalvikvm:       509: 0xa545ecc8 java.lang.String "items"
[WARN]  dalvikvm:       508: 0xa545ec08 java.util.HashMap
[WARN]  dalvikvm:       507: 0xa545ebc8 java.lang.String "videos"
[WARN]  dalvikvm:       506: 0xa545e9f0 java.util.HashMap
[WARN]  dalvikvm:       505: 0xa545e9a8 java.lang.String "attributes"
[WARN]  dalvikvm:       504: 0xa545e920 java.util.HashMap
[WARN]  dalvikvm:       503: 0xa545e908 java.lang.Object[] (1 elements)
[WARN]  dalvikvm:       502: 0xa545e8c8 java.lang.String "models"
[WARN]  dalvikvm:   Summary:
[WARN]  dalvikvm:         1 of java.lang.Class
[WARN]  dalvikvm:       102 of java.lang.Object[] (1 elements) (102 unique instances)
[WARN]  dalvikvm:       204 of java.lang.String (204 unique instances)
[WARN]  dalvikvm:       204 of java.util.HashMap (204 unique instances)
[WARN]  dalvikvm:         1 of ti.modules.titanium.network.HTTPClientProxy
[ERROR] dalvikvm: Failed adding to JNI local ref table (has 512 entries)
[INFO]  dalvikvm: "KrollRuntimeThread" prio=5 tid=11 RUNNABLE JIT
[INFO]  dalvikvm:   | group="main" sCount=0 dsCount=0 obj=0xa4e8f9d8 self=0xb80c7f08
[INFO]  dalvikvm:   | sysTid=1956 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=-1207083056
[INFO]  dalvikvm:   | state=R schedstat=( 112604939 49257854 256 ) utm=9 stm=1 core=0
[INFO]  dalvikvm:   at org.appcelerator.kroll.runtime.v8.V8Object.nativeCallProperty(Native Method)
[INFO]  dalvikvm:   at org.appcelerator.kroll.runtime.v8.V8Object.callProperty(V8Object.java:69)
[INFO]  dalvikvm:   at org.appcelerator.kroll.KrollProxy.handleMessage(KrollProxy.java:1121)
[INFO]  dalvikvm:   at android.os.Handler.dispatchMessage(Handler.java:95)
[INFO]  dalvikvm:   at android.os.Looper.loop(Looper.java:137)
[INFO]  dalvikvm:   at org.appcelerator.kroll.KrollRuntime$KrollRuntimeThread.run(KrollRuntime.java:112)
[INFO]  dalvikvm:
[ERROR] dalvikvm: VM aborting
[INFO]  libc: Fatal signal 11 (SIGSEGV) at 0xdeadd00d (code=1), thread 1956 (KrollRuntimeThr)

The Last 10 entries (of 512) shown in the log pointed us in the direction of a model or collection somehow polluting a reference table on the native side. So the first thing we did was check if we followed David’s advise everywhere. After fixing one place where we didn’t the crash still happened.

Rolling back

So we digged further. Since the crash didn’t happen in earlier versions we rolled back commits to see when it stopped. And then finally… it worked again! The commit we rolled back was one in which several JavaScript files were replaced by CoffeeScript versions.

Cherry picking

So next step was to roll back file by file and then chunk by chunk. Finally we found the exact line that caused the crash. And guess what? Not only should you not pass large JavaScript objects when calling Titanium proxy methods as David pointed out, but you should also not return them in callbacks set to proxy methods!

Example

Take the following example of a HTTP Client:

var client = Ti.Network.createHTTPClient({
  onload: function(e) {
    var models = JSON.parse(this.responseText);
    processModels(models);
  }
});
client.open('GET', 'https://back.end');
client.sent();

The onload callback will be called by the Titanium HTTPClient when it has received the data. If this were some JSON representing a collection of models you’d want to process these models. Like in our case, which was a CoffeeScript rewrite of the Mads Møller’s Alloy (Backbone) RestApi sync adapter.

Implicit return

Mads’s original script was similar to the example above and worked fine. The CoffeeScript seemed like a 1-1 rewrite. However, CoffeeScript has a behaviour known as Implicit returns. It will add return before the last line of a function block – in the above case return processModels(models);.  This might seem innocent, but it isn’t and a request to remove this behaviour has been debated for 2 years now.

Crossing the bridge

So what did we learn?

Anything a callback or event listener for a Titanium proxy method like that of our example or Ti.*.addEventListener() returns will cross the bridge and be converted to a native object.

When this is a large object it will not only consume memory as David pointed out, but can even crash your app – at least on Android – because it fails converting the JS object to a native one.

JIRA

I plan to create a JIRA ticket for this to be handled better by Titanium. I can’t think of any use-case where the proxy method actually needs to have something returned so the Kroll bridge layer might be adapted not to process what comes back. In the meanwhile, I hope to save you some time if you run in to a similar crash some day and remember this blog.

App imagineer: Imagining, Engineering & Speaking about Native mobile Apps with Appcelerator Titanium & Alloy • Meetup organizer • Certified Expert • Titan


Comments

  • Frank

    Thanks for sharing your experiences in this clear post. It not only potentially saves everybody mass amounts of time, but also helps to understand Titanium and ‘The Bridge’ better.
    I agree in not seeing a good use case in where to return something from an eventlistener, so +1 for opening a Jira ticket for this.
    Thanks again for sharing!

  • Kiley

    Fokke, thank you for this writeup. It was VERY helpful in understanding what is going on!

    That being said, it still has fallen a bit short of helping me resolve my issue, unfortunately.

    Like you showed above, I am getting the “[ERROR] dalvikvm: JNI ERROR (app bug): local reference table overflow (max=512)” issue when simply calling Ti.Contacts.getAllPeople(). Literally, that ONE line of code is causing the error. I have 2900 contacts (and I know plenty of people with more), so I am not an abnormal use case. I know it is this one line because I have removed any other code around it (after the permissions of course), and the call works on Android 6.0+, but does not work on versions prior to Android 6.0. Do you have any advice for this? I am wondering if I need to dive into the SDK and force it to release some of the used memory, but this is a very widely-used call, so why am I the only one seeming having an issue with it running properly?

    It works perfectly fine when I run it against an emulator with 0 contacts, or even 5 contacts, so it is clearly not releasing the memory when it iterates over the contacts that it is retrieving.

    Please help! Thanks!

  • fokkezb

    Hi Kiley, I recently heard something who ran into the exact same thing! I thought he reported it, but I can’t find it: https://jira.appcelerator.org/issues/?jql=text%20~%20%22getAllPeople%22%20ORDER%20BY%20updated%20DESC. Could you create a ticket with reproducible sample code, environment info and steps? We’ll be on it asap.

  • Kiley

    Sure thing, I’ll do that this evening! Thanks a ton!

  • Kiley

    Hi Fokke! Sorry for the slow movement on this, but I filed it. Please let me know if you need more information to be added to it.

    You can find the bug filed at: https://jira.appcelerator.org/browse/TC-5841