Crash on opening 1:1 chat with history when server returns an empty page during RSM

[jacobeva]

Whenever opening a chat window with an existing contact with chat history (be that through them messaging me, or through using the /msg command), profanity crashes within a couple of seconds.

Expected Behavior

Profanity should not crash, and open the chat window with the history.

Current Behavior

Profanity completely crashes.

Possible Solution

No idea.

Crash trace

#1  0x00005555555a1987 in _mam_rsm_id_handler (stanza=<optimized out>, userdata=0x5555561844b0) at src/xmpp/iq.c:2741
        firstid = 0x0
        ctx = <optimized out>
        iq = <optimized out>
        first = <optimized out>
        ndata = <optimized out>
        data = 0x5555561844b0
        window = 0x555555850960
        end_str = 0x0
        is_complete = 0
        start_str = 0x555557b7c250 "2023-07-15T21:27:39.213530+01"
        set = 0x55555584e590
        fin = <optimized out>
        type = <optimized out>
#2  0x00005555555a1d3d in _iq_handler (conn=<optimized out>, userdata=<optimized out>, stanza=0x55555584fe50) at src/xmpp/iq.c:246
        keep = <optimized out>
        handler = <optimized out>
        type = <optimized out>
        discoinfo = <optimized out>
        discoitems = <optimized out>
        lastactivity = <optimized out>
        version = <optimized out>
        ping = <optimized out>
        roster = <optimized out>
        blocking = <optimized out>
        id = 0x555555845f30 "8IeJkcC4jCd573P0963be247217ccfc332164cdf213e1496a3397e6"
        text = 0x5555561b5460 "\225EY\003PU"
        text_size = 304
        cont = <optimized out>
#3  _iq_handler (conn=<optimized out>, stanza=0x55555584fe50, userdata=<optimized out>) at src/xmpp/iq.c:180
        text = 0x5555561b5460 "\225EY\003PU"
        text_size = 304
        cont = <optimized out>
#4  0x00007ffff77e7322 in  () at /usr/lib/libstrophe.so.0
#5  0x00007ffff77ee1df in  () at /usr/lib/libstrophe.so.0
#6  0x00007ffff50fa63f in doContent (parser=parser@entry=0x555555d85a00, startTagLevel=startTagLevel@entry=0, enc=<optimized out>, s=<optimized out>, end=0x55555584b9d5 "essage to='jacob.eva@liberatedsystems.co.uk/profanity.J3pl' from='technology@conference.liberatedsystems.co.uk/jacob.eva' type='groupchat'><subject>For general discussion of (the absolute state of) te"..., nextPtr=0x555555d85a30, haveMore=1 '\001', account=XML_ACCOUNT_DIRECT) at /usr/src/debug/expat-2.5.0/lib/xmlparse.c:3056
        localPart = <optimized out>
        prefix = <optimized out>
        uri = <optimized out>
        len = <optimized out>
        rawName = 0x55555584b9d2 "iq>essage to='jacob.eva@liberatedsystems.co.uk/profanity.J3pl' from='technology@conference.liberatedsystems.co.uk/jacob.eva' type='groupchat'><subject>For general discussion of (the absolute state of)"...
        tag = 0x555555f6f150
        next = 0x55555584b9d5 "essage to='jacob.eva@liberatedsystems.co.uk/profanity.J3pl' from='technology@conference.liberatedsystems.co.uk/jacob.eva' type='groupchat'><subject>For general discussion of (the absolute state of) te"...
        tok = <optimized out>
        accountAfter = <optimized out>
        dtd = 0x555555d85de0
        eventPP = 0x555555d85c20
        eventEndPP = <optimized out>
#7  0x00007ffff50fb43e in contentProcessor (parser=0x555555d85a00, start=<optimized out>, end=<optimized out>, endPtr=<optimized out>) at /usr/src/debug/expat-2.5.0/lib/xmlparse.c:2621
        result = <optimized out>
#8  0x00007ffff50fd8ea in XML_ParseBuffer (parser=0x555555d85a00, len=<optimized out>, isFinal=0) at /usr/src/debug/expat-2.5.0/lib/xmlparse.c:2018
        start = <optimized out>
        result = XML_STATUS_OK
#9  0x00007ffff77e6efe in xmpp_run_once () at /usr/lib/libstrophe.so.0
#10 0x000055555559c9cf in connection_check_events () at src/xmpp/connection.c:160
#11 0x000055555559b9e6 in session_process_events () at src/xmpp/session.c:258
        reconnect_sec = <optimized out>
        conn_status = <optimized out>
#12 0x00005555555955d4 in prof_run (log_level=0x55555562e114 "WARN", account_name=<optimized out>, config_file=0x0, log_file=<optimized out>, theme_name=<optimized out>) at src/profanity.c:132
        cont = 1
        line = 0x0
#13 0x0000555555590b8d in main (argc=<optimized out>, argv=<optimized out>) at src/main.c:185
        entries = {{long_name = 0x55555562f2f9 "version", short_name = 118 'v', flags = 0, arg = G_OPTION_ARG_NONE, arg_data = 0x5555556e0fa8 <version>, description = 0x55555565de4f "Show version information", arg_description = 0x0}, {long_name = 0x55555563ffe1 "account", short_name = 97 'a', flags = 0, arg = G_OPTION_ARG_STRING, arg_data = 0x5555556e0f90 <account_name>, description = 0x55555565e0b8 "Auto connect to an account on startup", arg_description = 0x0}, {long_name = 0x55555565d0f4 "log", short_name = 108 'l', flags = 0, arg = G_OPTION_ARG_STRING, arg_data = 0x5555556e0fa0 <log>, description = 0x55555565e0e0 "Set logging levels, DEBUG, INFO, WARN (default), ERROR", arg_description = 0x55555565de68 "LEVEL"}, {long_name = 0x5555556553dd "config", short_name = 99 'c', flags = 0, arg = G_OPTION_ARG_STRING, arg_data = 0x5555556e0f88 <config_file>, description = 0x55555565e118 "Use an alternative configuration file", arg_description = 0x0}, {long_name = 0x55555565de6e "logfile", short_name = 102 'f', flags = 0, arg = G_OPTION_ARG_STRING, arg_data = 0x5555556e0f98 <log_file>, description = 0x55555565de76 "Specify log file", arg_description = 0x0}, {long_name = 0x555555640388 "theme", short_name = 116 't', flags = 0, arg = G_OPTION_ARG_STRING, arg_data = 0x5555556e0f80 <theme_name>, description = 0x55555565de87 "Specify theme name", arg_description = 0x0}, {long_name = 0x0, short_name = 0 '\000', flags = 0, arg = G_OPTION_ARG_NONE, arg_data = 0x0, description = 0x0, arg_description = 0x0}}
        error = 0x0
        context = 0x555555700a10

Context

I am trying to contact people in a 1:1 chat who I have previous chat history with.

Environment

Profanity, version 0.13.1dev.master.48148877
Copyright (C) 2012 - 2019 James Booth boothj5web@gmail.com.
Copyright (C) 2019 - 2023 Michael Vetter jubalh@iodoru.org.
License GPLv3+: GNU GPL version 3 or later https://www.gnu.org/licenses/gpl.html
Build information:
XMPP library: libstrophe
Desktop notification support: Enabled
OTR support: Enabled (libotr 4.1.1)
PGP support: Enabled (libgpgme 1.21.0)
OMEMO support: Enabled
C plugins: Enabled
Python plugins: Enabled (3.11.3)
GTK icons/clipboard: Enabled
GDK Pixbuf: Enabled

[jacobeva]

Interestingly enough, this only occurs with my account on the liberatedsystems.co.uk domain, maybe that's something to do with it? I did notice that the technology MUC was in the stack trace too...

[jacobeva]

My terminal is really messed up after as well, scrolling just goes through my command history, using cat on text yields strangely formatted text with % symbols at the end of the file... (maybe control signals are being sent before the crash?)

[jubalh]

It seems like we don't get a first stanza when doing RSM.
Let's guard against that.
Can you build from #1869 and test if it fixes the problem for you?

liberatedsystems.co.uk seems to use ejabberd 23.04, which is latest.

[jacobeva]

Excellent, this stops the crash, but now the history never loads unfortunately. Do you think this is an issue with the server?

[jubalh]

Excellent, this stops the crash, but now the history never loads unfortunately.

I expected that. Give me a minute to try to find out more. We don't get the first item in the result set. So that's why we can't display anything. We need to find out why is that.

[jubalh]

@jacobeva and you are sure you have a history which we could get from the server?

[jacobeva]

Okay, so it looks like that for whatever reason MAM isn't working well on my server, let me investigate.

[jacobeva]

Boom, got it!

Okay, really weird issue. Basically, my ejabberd server was configured to use SQL as the backend database, but was still storing stuff in mnesia for some reason. So when it came to requesting archives, it would try to retrieve them from the SQL database, see nothing and then return nothing. Hence my server sending no history. To fix it, I just imported the SQL schema, exported my ejabberd server's DB using ejabberdctl export2sql and then imported it again, and it works!

[jacobeva]

That PR will still be useful of course, since it does fix a crash, even if my server was misconfigured ;)

[jubalh]

Okay, really weird issue. Basically, my ejabberd server was configured to use SQL as the backend database, but was still storing stuff in mnesia for some reason. So when it came to requesting archives, it would try to retrieve them from the SQL database, see nothing and then return nothing. Hence my server sending no history. To fix it, I just imported the SQL schema, exported my ejabberd server's DB using ejabberdctl export2sql and then imported it again, and it works!

Great to know the reason!

That PR will still be useful of course, since it does fix a crash

Of course :) We shouldn't crash in such cases.