3.0.0 crashes on sending message

[InI4]

Description

My app is somewhat similar to the demo and I did the minimal changes to run on 3.0.0 instead of 2.0.8. However sending a message always crashes. Might be a duplicate of #42 .

Steps to Reproduce

1. Send a message
2. crash

Code (optional)

Can deliver some Java if this helps.

Expected Behavior

No crash

Actual Behavior

crash

Reproduces how Often

100%

Logs

On one emulator

04-25 20:46:43.296 21453-22862/de.spieleck.app.badgers.debug E/jni_mate: #
    # Fatal error in /var/lib/jenkins/jobs/chat-sdk-android/workspace/configuration/Release/label/master/sdk/build/prebuilt/jni-mate/include/ListenerWrapper.h, line 40
    # Check failed: statusListener_ && (onSuccess_ || onSuccessBackup_)
    # Invariant violated
    #

On a different emulator

    ### ### ### ### ### ### ### ### ### ### ### ### ###
04-25 20:54:44.653 23085-25050/de.spieleck.app.badgers.debug A/libc: Fatal signal 6 (SIGABRT), code -6 in tid 25050 (- 23661 - 23683)
04-25 20:54:44.728 25052-25052/? A/DEBUG: *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
    Build fingerprint: 'Android/sdk_google_phone_x86_64/generic_x86_64:7.1.1/NYC/4660551:userdebug/test-keys'
    Revision: '0'
    ABI: 'x86_64'
    pid: 23085, tid: 25050, name: - 23661 - 23683  >>> de.spieleck.app.badgers.debug <<<
    signal 6 (SIGABRT), code -6 (SI_TKILL), fault addr --------
04-25 20:54:44.729 25052-25052/? A/DEBUG: Abort message: '   129922686096464 | 04/25/20:54:24.328 | FATAL    | 12     | TNNotificationClient | Fatal error while registering twilsock connection: 9: Message type list is empty, public error code: 0'
        rax 0000000000000000  rbx 00007629f3afa4f8  rcx ffffffffffffffff  rdx 0000000000000006
        rsi 00000000000061da  rdi 0000000000005a2d
        r8  00000000000061da  r9  00007629f3afa450  r10 0000000000000008  r11 0000000000000206
        r12 00000000000061da  r13 0000000000000006  r14 000000000000000a  r15 0000000000000000
        cs  0000000000000033  ss  000000000000002b
        rip 0000762a28aaebe7  rbp 0000000000000000  rsp 00007629f3af9d88  eflags 0000000000000206
04-25 20:54:44.744 25052-25052/? A/DEBUG: backtrace:
        #00 pc 000000000008dbe7  /system/lib64/libc.so (tgkill+7)
        #01 pc 000000000008a681  /system/lib64/libc.so (pthread_kill+65)
        #02 pc 00000000000302c1  /system/lib64/libc.so (raise+17)
        #03 pc 00000000000287fd  /system/lib64/libc.so (abort+77)
        #04 pc 0000000000733ac5  /data/app/de.spieleck.app.badgers.debug-1/lib/x86_64/libtwilio-rtd-native.so (_ZN8jni_mate12FatalMessageD1Ev+325)
        #05 pc 00000000003d6523  /data/app/de.spieleck.app.badgers.debug-1/lib/x86_64/libtwilio-rtd-native.so (_ZZ20resultListenerLambdaIJxEENSt3__18functionIFvNS0_10shared_ptrIN3rtd9ITMResultEEEDpT_EEE19ChatListenerWrapperPKcSC_ENKUlS5_xE_clES5_x+803)
        #06 pc 00000000003d6787  /data/app/de.spieleck.app.badgers.debug-1/lib/x86_64/libtwilio-rtd-native.so (_ZNSt3__110__function6__funcIZ20resultListenerLambdaIJxEENS_8functionIFvNS_10shared_ptrIN3rtd9ITMResultEEEDpT_EEE19ChatListenerWrapperPKcSE_EUlS7_xE_NS_9allocatorISF_EEFvS7_xEEclEOS7_Ox+55)
        #07 pc 00000000003d1ada  /data/app/de.spieleck.app.badgers.debug-1/lib/x86_64/libtwilio-rtd-native.so (_ZNSt3__110__function6__funcINS_8functionIFvNS_10shared_ptrIN3rtd9ITMResultEEExEEENS_9allocatorIS8_EEFvS6_iEEclEOS6_Oi+74)
        #08 pc 000000000040c28b  /data/app/de.spieleck.app.badgers.debug-1/lib/x86_64/libtwilio-rtd-native.so (_ZNSt3__120__packaged_task_funcINS_6__bindIRKNS_8functionIFvNS_10shared_ptrIN3rtd9ITMResultEEEiEEEJNS3_INS4_8TMResultEEERiEEENS_9allocatorISE_EEFvvEEclEv+115)
        #09 pc 0000000000409e08  /data/app/de.spieleck.app.badgers.debug-1/lib/x86_64/libtwilio-rtd-native.so (_ZNSt3__113packaged_taskIFvvEEclEv+166)
        #10 pc 0000000000409ec8  /data/app/de.spieleck.app.badgers.debug-1/lib/x86_64/libtwilio-rtd-native.so (_ZNSt3__114__thread_proxyINS_5tupleIJNS_13packaged_taskIFvvEEEEEEEEPvS6_+89)
        #11 pc 00000000000897f1  /system/lib64/libc.so (_ZL15__pthread_startPv+177)
        #12 pc 0000000000029a6b  /system/lib64/libc.so (__start_thread+11)
        #13 pc 000000000001cae5  /system/lib64/libc.so (__bionic_clone+53)

Versions

Chat Android SDK

3.0.0

Android API & Android Device

8.1 & Pixel XL Emulator
7.1.1 & Nexus X Emulator

[berkus]

Can you show what kind of listener you use when sending?

[InI4]

Here is some code from my MessageActivity, as said I was just in the state of "try to get it compile und run with 3.0.0".

    private void sendMessage(final String text)
    {
        final Messages messagesObject = this.channel.getMessages();
        // XXX 2.0 API change and weird
        Message.Options options = Message.options().withBody(text);
                messagesObject.sendMessage(options, new CallbackListener<Message>() {
            @Override
            public void onSuccess(Message message) {
                Log.d(TAG, "message send success. "+Thread.currentThread());
                inputText.setText("");
                inputText.invalidate();
                onMessageAdded(message); // XXX this is a weird way to add it.
            }

            @Override
            public void onError(ErrorInfo errorInfo) {
                TwilioApplication.get().showError(getString(R.string.twilio_could_not_send_message), errorInfo);
            }
        });
    }

    private void sendMessage()
    {
        inputText = (EditText)findViewById(R.id.messageInput);
        String input = inputText.getText().toString();
        Log.d(TAG, "send <"+input+">");
        if (!input.equals("")) {
            sendMessage(input);
        }
        inputText.clearFocus();
    }

[InI4]

This problem is still there with 3.0.1

[berkus]

I haven't digged into this yet. I'm going to release one more update 3.0.2 soon and after that I will get to this issue.

[berkus]

Could you please collect logs as described in this manual, I am unable to reproduce this problem.

[InI4]

Ah, nothing happening here. My fault. Summary: It still crashes relyably with v3.1.1 on all tested devices. Makes 3.X.Y completely useless here. Attached find the requested logs.

my_error.log.gz

[berkus]

10-01 07:01:50.898  1255  7827 I ActivityManager: Process com.android.chrome:sandboxed_process0 (pid 28080) has died: cch+1CACC
10-01 07:01:50.899  1255  7827 W ActivityManager: Scheduling restart of crashed service de.spieleck.app.badgers.debug/org.chromium.content.app.SandboxedProcessService0 in 1000ms
10-01 07:01:57.463  1255  1270 D RestartProcessManager: updateSelf :  de.spieleck.app.badgers.debug, size : 30
10-01 07:01:58.757  1255  7827 I ActivityManager: START u0 {cmp=de.spieleck.app.badgers.debug/de.spieleck.app.badgers.chat.twilio.MessageActivity (has extras)} from uid 10386 pid 27628

Am I correct in understanding that some (web) frontend is crashing and then the ChatClient crashes because it couldn't send notification to no-more-existing listener? Or am I completely off-base here?

Sorry that I have to guess, the logs are missing some critical parts.

[berkus]

Hi, please try 4.0.0-rc11 and send your feedback.

[InI4]

@berkus what parts are missing? I followed your procedure. Note, that I cannot capture via AS3.2 either, as I have not figured out, how to avoid the crash flushing the logcat stuff. There is no Webserver involved, apart from a slightly different UI the embedding is still fairly close to your (Java) sample code. It is also that my app does not contain any code to restart itself, when an Activity crashes main thread, so I thought that'd be a Twilio Chat feature?

I'll try to do some experiments with 4.0.0-rc11 later. Good to hear, things are proceeding, it was getting a little quiet down here..

[berkus]

The crash in ChatClient is very clear that it was expecting to see a CallbackListener but did not find one.

Solution would be to find WHY this CallbackListener disappears and make it not disappear, then everything would work.

If the code is indeed like shown here then between the moment of sendMessage() and the moment CallbackListener's onSuccess method is called, the reference to CallbackListener has gone away. This is possible but highly unlikely, because CallbackListener's wrapper holds a strong reference to it internally until the moment its callback is actually fired.

The log from here however shows a completely different scenario - crash in Messages.advanceLastConsumedMessageIndexWithResult. Yes, it's the same callback thingie, but in a different place and perhaps different access pattern - you did not post any code for this part, so it's only guesses.

Could you check the logs before the crash for patterns like

ListenerWrapper default onSuccessany letters not found
or
ListenerWrapper backup onSuccessany letters not found
or
ListenerWrapper: Failed to find listener onSuccess method

If these are not anywhere in the logs (they are at Log.WARNING level) then the original CallbackListener was found correctly but then it was gone while command was executing. We can dig more from there.

[InI4]

I am a bit in a hurry right now, I am afraid I did not understand, what you wrote. Will try later, when I have more time.

However building is fast. With v4.0.0-rc12 my app now crashes before even displaying the message thread, i.e. before I could even post something to crash things. Again with this crude autorestart feature which kills the logs in the AS3.2 view.

I am sorry, when I have got the objects wrong, thanks for your help!

[berkus]

You can disable log cleanup in AS, then you will see everything. In your app run configuration uncheck this box:

[InI4]

Well, I have this settings already, no clue, why the interesting lines are still flushed so fast.

Anyway, I tried to get rc12 running on emulators and actually fail: App doesn't even start up (and it does when I revert to twilio2).

I know, I am a bit messy here right now, but maybe, maybe, this message is interesting for you:

2018-10-03 09:41:58.812 de.spieleck.app.badgers.debug E/linker: "/data/app/de.spieleck.app.badgers.debug-PB4dopG-HviGQ3mYo-Bc4w==/lib/x86/libtwilio-rtd-native.so" has text relocations (https://android.googlesource.com/platform/bionic/+/master/android-changes-for-ndk-developers.md#Text-Relocations-Enforced-for-API-level-23)
2018-10-03 09:41:58.973 de.spieleck.app.badgers.debug E/linker: "/data/data/de.spieleck.app.badgers.debug/app_lib/libtwilio-rtd-native.so" has text relocations (https://android.googlesource.com/platform/bionic/+/master/android-changes-for-ndk-developers.md#Text-Relocations-Enforced-for-API-level-23)
2018-10-03 09:41:59.002 de.spieleck.app.badgers.debug E/AndroidRuntime: FATAL EXCEPTION: AsyncTask #2
Process: de.spieleck.app.badgers.debug, PID: 3638
java.lang.RuntimeException: An error occurred while executing doInBackground()
at android.os.AsyncTask$3.done(AsyncTask.java:353)
at java.util.concurrent.FutureTask.finishCompletion(FutureTask.java:383)
at java.util.concurrent.FutureTask.setException(FutureTask.java:252)
at java.util.concurrent.FutureTask.run(FutureTask.java:271)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
at java.lang.Thread.run(Thread.java:764)
Caused by: java.lang.UnsatisfiedLinkError: dlopen failed: "/data/data/de.spieleck.app.badgers.debug/app_lib/libtwilio-rtd-native.so" has text relocations (https://android.googlesource.com/platform/bionic/+/master/android-changes-for-ndk-developers.md#Text-Relocations-Enforced-for-API-level-23)
at java.lang.Runtime.load0(Runtime.java:928)
at java.lang.System.load(System.java:1621)
at com.twilio.chat.internal.ReLinker.loadLibrary(ReLinker.java:74)
at com.twilio.chat.ChatClient.loadNativeLibraries(ChatClient.java:187)
at com.twilio.chat.ChatClient.(ChatClient.java:376)
at com.twilio.chat.ChatClient.create(ChatClient.java:287)
at de.spieleck.app.badgers.chat.twilio.BasicChatClient.createClient(BasicChatClient.java:212)
at de.spieleck.app.badgers.chat.twilio.BasicChatClient.access$300(BasicChatClient.java:32)
at de.spieleck.app.badgers.chat.twilio.BasicChatClient$4.run(BasicChatClient.java:170)
at de.spieleck.app.badgers.util.AsyncPooledRunner$1.doInBackground(AsyncPooledRunner.java:29)
at de.spieleck.app.badgers.util.AsyncPooledRunner$1.doInBackground(AsyncPooledRunner.java:26)
at android.os.AsyncTask$2.call(AsyncTask.java:333)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162) 
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636) 
at java.lang.Thread.run(Thread.java:764) 

[berkus]

Thanks, this looks interesting, will check.

[InI4]

Turns out, I had "Clear log before launch" disabled, it was the filter on current process which interrrupted my logging. I am afraid the attached log is the same like in #58 . I have made many of my CallbackListener final members of the Activity and still it crashes. I mean, how permanent does it need to be? From the native code, can you give me a hint, what (generic) type of CallbackListener<???> I need to search for, maybe I missed one.

twilio400rc12.log

[InI4]

OK, got it, I found something like

Messages messages
messages.advanceLastConsumedMessageIndexWithResult(long, null);

Was due to the fast testing upgrades from Twilio 2 over 3 and so on.
It would be nice, if the 2nd argument had a NotNull annotation or so.

[berkus]

Aye, added annotations, will be in the next 4.0.0 release. Cheers!