Pidgin Consistently Crashes

[djha-skin]

Pidgin has consistently crashed for me, but only when this plugin is enabled.

It has done so for like a year. It would crash about once a day. This last month though, it has gotten unusable. Today it crashed four times.

Unfortunately I don't have a copy with debug symbols, but I did get this pidgin --debug log posting debug information right up until it crashed. This time, it took only perhaps 2 minutes to crash.

It's like it does this when it retrieves certain messages or something from the server. It comes and goes, which makes me think it's slack content related.

[djha-skin]

Sorry, I had to remove the gist, it had a ton of sensitive data on second glance.
However, the crash happened immediately after this message:

(11:54:39) slack: api call: https://<REDACTED>.slack.com/api/conversations.info

Which strengthens my argument that it's somehow related to eating a bad character.

[djha-skin]

I just disabled my smileys too, thinking that was somehow related. Nope. Crashed anyways. This time it made it ten minutes.

[dylex]

If you want to send me logs directly I can take a look, or a coredump/traceback would be ideal. I did get a chance to glance at the logs before you removed them and noticed a json memory error right before the crash that looks like it's actually coming from groupme. If you could turn off all other plugins and connections except a single slack that would help track it down.

[djha-skin]

That is interesting, but it doesn't crash when I leave everything else on.

That said, I'll get you that traceback soon. I'll also shut off all other plugins and see if I can still get it to crash.

[djha-skin]

I got it to happen again, this time with the only plugin being on was slack-libpurple.
Gist with anonymized data for the slack-plugin-only run here: https://gist.github.com/djhaskin987/15db6dae6e27c50d9095c1aa99e76247
Here's a gist with the original run here: https://gist.github.com/djhaskin987/5cc40f5305e11666a89fc7b36326b4ee
I'll try to get the traceback soon.

In the first gist, only the slack plugin was on. The second gist represents the content of the log I originally gave you, but with anonymized data.

[djha-skin]

EDIT:

Please disregard the following backtrace, it isn't the right one. I gave the wrong one because apport only keeps one backtrace at a time, and so I thought this one was "the one" caused by the plugin, when it was really caused by my quitting the application before starting up again in order to get the debug symbols. Sorry.

ORIGINAL TEXT:

For what it's worth, I provide the stack trace I was able to pull below. Unfortunately it's not very useful :( since there appears to be a double-error. My theory is that an error occurs, causing an exception, but then there is a (I think?) double-free error which prevents the stack trace from printing the actual error, instead showing us the use-after-free that occurs while pidgin tried to clean up the first error.

Here it is:

(gdb) bt
#0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=139919309240768) at ./nptl/pthread_kill.c:44
#1  __pthread_kill_internal (signo=6, threadid=139919309240768) at ./nptl/pthread_kill.c:78
#2  __GI___pthread_kill (threadid=139919309240768, signo=signo@entry=6) at ./nptl/pthread_kill.c:89
#3  0x00007f4181e42476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
#4  0x00007f4181e287f3 in __GI_abort () at ./stdlib/abort.c:79
#5  0x00007f4181e896f6 in __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0x7f4181fdbb8c "%s\n")
    at ../sysdeps/posix/libc_fatal.c:155
#6  0x00007f4181ea0d7c in malloc_printerr (str=str@entry=0x7f4181fd9764 "free(): invalid pointer") at ./malloc/malloc.c:5664
#7  0x00007f4181ea2ac4 in _int_free (av=<optimized out>, p=<optimized out>, have_lock=0) at ./malloc/malloc.c:4439
#8  0x00007f4181ea54d3 in __GI___libc_free (mem=<optimized out>) at ./malloc/malloc.c:3391
#9  0x00007f4182423439 in g_free (mem=<optimized out>) at ../glib/gmem.c:229
#10 0x00007f418243c6bd in g_slice_free_chain_with_offset (mem_size=24, mem_chain=<optimized out>, next_offset=8)
    at ../glib/gslice.c:372
#11 0x00007f41821bd731 in purple_plugin_destroy () from /lib/x86_64-linux-gnu/libpurple.so.0
#12 0x00007f41821be030 in purple_plugins_destroy_all () from /lib/x86_64-linux-gnu/libpurple.so.0
#13 0x00007f418219d9d5 in purple_core_quit () from /lib/x86_64-linux-gnu/libpurple.so.0
#14 0x00007f418251beff in g_closure_invoke (closure=0x56333f805990, return_value=return_value@entry=0x0, n_param_values=1,
    param_values=param_values@entry=0x7ffe5fb93450, invocation_hint=invocation_hint@entry=0x7ffe5fb933d0) at ../gobject/gclosure.c:832
#15 0x00007f418252f9c6 in signal_emit_unlocked_R (node=node@entry=0x56333e64f8d0, detail=detail@entry=0,
    instance=instance@entry=0x56333ec731a0, emission_return=emission_return@entry=0x0,
    instance_and_params=instance_and_params@entry=0x7ffe5fb93450) at ../gobject/gsignal.c:3802
#16 0x00007f4182536511 in g_signal_emit_valist (instance=<optimized out>, signal_id=<optimized out>, detail=<optimized out>,
    var_args=var_args@entry=0x7ffe5fb935d0) at ../gobject/gsignal.c:3555
#17 0x00007f4182536703 in g_signal_emit (instance=instance@entry=0x56333ec731a0, signal_id=<optimized out>, detail=detail@entry=0)
    at ../gobject/gsignal.c:3612
#18 0x00007f4182c6b41c in IA__gtk_widget_activate (widget=0x56333ec731a0) at ../../../../gtk/gtkwidget.c:5048
#19 0x00007f4182b55335 in IA__gtk_menu_shell_activate_item (menu_shell=0x56333eca7c90, menu_item=0x56333ec731a0,
    force_deactivate=<optimized out>) at ../../../../gtk/gtkmenushell.c:1313
#20 0x00007f4182b56ec3 in gtk_menu_shell_button_release (widget=0x56333eca7c90, event=0x56333e6ad260)
    at ../../../../gtk/gtkmenushell.c:738
#21 0x00007f4182b434d7 in _gtk_marshal_BOOLEAN__BOXED (closure=0x56333e28d7e0, return_value=0x7ffe5fb938e0,
    n_param_values=<optimized out>, param_values=0x7ffe5fb93940, invocation_hint=<optimized out>, marshal_data=<optimized out>)
    at /build/gtk+2.0-AJUhhk/gtk+2.0-2.24.33/debian/build/shared/gtk/gtkmarshalers.c:84
#22 0x00007f418251beff in g_closure_invoke (closure=closure@entry=0x56333e28d7e0, return_value=return_value@entry=0x7ffe5fb938e0,
    n_param_values=2, param_values=param_values@entry=0x7ffe5fb93940, invocation_hint=invocation_hint@entry=0x7ffe5fb938c0)
    at ../gobject/gclosure.c:832
#23 0x00007f418252f3b4 in signal_emit_unlocked_R (node=<optimized out>, detail=detail@entry=0,
    instance=instance@entry=0x56333eca7c90, emission_return=emission_return@entry=0x7ffe5fb93a30,
    instance_and_params=instance_and_params@entry=0x7ffe5fb93940) at ../gobject/gsignal.c:3841
#24 0x00007f4182535e97 in g_signal_emit_valist (instance=<optimized out>, signal_id=<optimized out>, detail=<optimized out>,
    var_args=var_args@entry=0x7ffe5fb93ae0) at ../gobject/gsignal.c:3565
#25 0x00007f4182536703 in g_signal_emit (instance=instance@entry=0x56333eca7c90, signal_id=<optimized out>, detail=detail@entry=0)
    at ../gobject/gsignal.c:3612
#26 0x00007f4182c6f024 in gtk_widget_event_internal (widget=0x56333eca7c90, event=0x56333e6ad260) at ../../../../gtk/gtkwidget.c:5017
#27 0x00007f4182b41094 in IA__gtk_propagate_event (widget=0x56333eca7c90, event=0x56333e6ad260) at ../../../../gtk/gtkmain.c:2522
#28 0x00007f4182b426db in IA__gtk_main_do_event (event=0x56333e6ad260) at ../../../../gtk/gtkmain.c:1712
#29 IA__gtk_main_do_event (event=<optimized out>) at ../../../../gtk/gtkmain.c:1517
#30 0x00007f41829a616b in gdk_event_dispatch (source=<optimized out>, callback=<optimized out>, user_data=<optimized out>)
    at x11/../../../../../gdk/x11/gdkevents-x11.c:2425
#31 0x00007f418241c67b in g_main_dispatch (context=0x56333e231c00) at ../glib/gmain.c:3454
#32 g_main_context_dispatch (context=0x56333e231c00) at ../glib/gmain.c:4172
#33 0x00007f418241c928 in g_main_context_iterate (context=0x56333e231c00, block=block@entry=1, dispatch=dispatch@entry=1,
    self=<optimized out>) at ../glib/gmain.c:4248
#34 0x00007f418241cc33 in g_main_loop_run (loop=loop@entry=0x56333e8b3c80) at ../glib/gmain.c:4448
--Type <RET> for more, q to quit, c to continue without paging--c
#35 0x00007f4182b402d2 in IA__gtk_main () at ../../../../gtk/gtkmain.c:1284
#36 0x000056333d02022d in main (argc=<optimized out>, argv=<optimized out>) at ././pidgin/gtkmain.c:946

[djha-skin]

I apologize, that's not the right backtrace at all. It was a mix-up. I'll get you the right one.

[djha-skin]

Got the correct backtrace. Here it is:

  0 43:07      ~/C/t/p/pidgincrash $ gdb /usr/bin/pidgin CoreDump
GNU gdb (Ubuntu 12.1-0ubuntu1~22.04) 12.1
Copyright (C) 2022 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<https://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/bin/pidgin...
Reading symbols from /usr/lib/debug/.build-id/ee/e12c6129ace726dca0de28803a03788fe7351f.debug...

warning: Can't open file /run/user/1000/orcexec.WNqF0u (deleted) during file-backed mapping note processing

warning: Can't open file /SYSV00000000 (deleted) during file-backed mapping note processing

warning: Can't open file /memfd:pulseaudio (deleted) during file-backed mapping note processing
[New LWP 16493]
[New LWP 16494]
[New LWP 16496]
[New LWP 16499]
[New LWP 16502]
[New LWP 16500]
[New LWP 16498]
[New LWP 16495]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `pidgin'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x00007fb47e298e36 in g_hash_table_lookup_node (hash_return=<synthetic pointer>, key=0x5644a2e59490, hash_table=0x2f0)
    at ../glib/ghash.c:474
474       hash_value = hash_table->hash_func (key);
[Current thread is 1 (Thread 0x7fb47ca229c0 (LWP 16493))]
(gdb) bt
#0  0x00007fb47e298e36 in g_hash_table_lookup_node (hash_return=<synthetic pointer>, key=0x5644a2e59490, hash_table=0x2f0)
    at ../glib/ghash.c:474
#1  g_hash_table_lookup (hash_table=0x2f0, key=0x5644a2e59490) at ../glib/ghash.c:1541
#2  0x00007fb478141794 in slack_unset_typing_cb (chatbuddy=0x5644a4c69810,
    chatbuddy@entry=<error reading variable: value has been optimized out>) at slack-message.c:576
#3  0x00007fb47e2ae12f in g_timeout_dispatch (user_data=<optimized out>, callback=<optimized out>, source=0x5644a4be2810)
    at ../glib/gmain.c:5017
#4  g_timeout_dispatch (source=0x5644a4be2810, callback=<optimized out>, user_data=<optimized out>) at ../glib/gmain.c:4995
#5  0x00007fb47e2ad584 in g_main_dispatch (context=0x5644a2827c00) at ../glib/gmain.c:3454
#6  g_main_context_dispatch (context=0x5644a2827c00) at ../glib/gmain.c:4172
#7  0x00007fb47e2ad928 in g_main_context_iterate (context=0x5644a2827c00, block=block@entry=1, dispatch=dispatch@entry=1,
    self=<optimized out>) at ../glib/gmain.c:4248
#8  0x00007fb47e2adc33 in g_main_loop_run (loop=loop@entry=0x5644a2ff0370) at ../glib/gmain.c:4448
#9  0x00007fb47e9402d2 in IA__gtk_main () at ../../../../gtk/gtkmain.c:1284
#10 0x00005644a1b8222d in main (argc=<optimized out>, argv=<optimized out>) at ././pidgin/gtkmain.c:946
(gdb)

[dylex]

Ah, this looks potentially straight-forward -- there's a 4 second callback to clear chat typing flags, but if the chat conversation was closed during these 4 seconds, I could certainly see this happening. This code actually came from @EionRobb who knows more about this than me. Should we register a handler for deleting-conversation or slack_chat_leave to clear the timeout, or is there another way to register this reference?

[djha-skin]

I'm using the following diff to try to fix the issue. I don't know what I'm doing, but basically I'm storing the channel and account in SlackChatBuddy, rather than the chat. Then I'm looking up the chat again after four seconds using the account and channel. I have no idea if those pointers are still valid, but I guessed they would be. Also I think I found a memory leak bug: the SlackBuddyChat struct was not being freed after use. I'll let you know if I have any more crashes :)

diff --git a/slack-message.c b/slack-message.c
index c06f7ae..3cf810a 100644
--- a/slack-message.c
+++ b/slack-message.c
@@ -88,7 +88,7 @@ void slack_message_to_html(GString *html, SlackAccount *sa, gchar *s, PurpleMess
 		char c = *s++;
 		if (c == '\n') {
 			g_string_append(html, "<BR>");
-			
+
 			// This is here for attachments.  If this message is part of an attachment,
 			// we must add the preprend string after every newline.
 			if (prepend_newline_str) {
@@ -227,13 +227,13 @@ static void slack_attachment_to_html(GString *html, SlackAccount *sa, json_value
 	char *service_link = json_get_prop_strptr(attachment, "service_link");
 	char *author_name = json_get_prop_strptr(attachment, "author_name");
 	char *author_subname = json_get_prop_strptr(attachment, "author_subname");
-	
+
 	char *author_link = json_get_prop_strptr(attachment, "author_link");
 	char *text = json_get_prop_strptr(attachment, "text");
 
 	//char *fallback = json_get_prop_strptr(attachment, "fallback");
 	char *pretext = json_get_prop_strptr(attachment, "pretext");
-	
+
 	char *title = json_get_prop_strptr(attachment, "title");
 	char *title_link = json_get_prop_strptr(attachment, "title_link");
 	char *footer = json_get_prop_strptr(attachment, "footer");
@@ -359,7 +359,7 @@ static void slack_file_to_html(GString *html, SlackAccount *sa, json_value *file
 void slack_json_to_html(GString *html, SlackAccount *sa, json_value *message, PurpleMessageFlags *flags) {
 	const char *subtype = json_get_prop_strptr(message, "subtype");
 	int i;
-	
+
 	if (flags && json_get_prop_boolean(message, "hidden", FALSE))
 		*flags |= PURPLE_MESSAGE_INVISIBLE;
 
@@ -428,7 +428,7 @@ void slack_handle_message(SlackAccount *sa, SlackObject *obj, json_value *json,
 		return;
 	}
 
-	json_value *message     = json;
+	json_value *message = json;
 	json_value *ts = json_get_prop(message, "ts");
 	const char *tss = json_get_strptr(ts);
 	const char *subtype = json_get_prop_strptr(message, "subtype");
@@ -529,7 +529,7 @@ void slack_handle_message(SlackAccount *sa, SlackObject *obj, json_value *json,
 					!strcmp(subtype, "group_topic"))
 				purple_conv_chat_set_topic(chat, user ? user->object.name : user_id, json_get_prop_strptr(json, "topic"));
 		}
-		
+
 		serv_got_chat_in(sa->gc, chan->cid, user ? user->object.name : user_id ?: username ?: "", flags, html->str, mt);
 	} else if (SLACK_IS_USER(obj)) {
 		SlackUser *im = (SlackUser*)obj;
@@ -568,23 +568,29 @@ gboolean slack_message(SlackAccount *sa, json_value *json) {
 }
 
 typedef struct {
-	PurpleConvChat *chat;
+	SlackAccount *sa;
+	SlackChannel *chan;
 	gchar *name;
 } SlackChatBuddy;
 
 static gboolean slack_unset_typing_cb(SlackChatBuddy *chatbuddy) {
-	PurpleConvChatBuddy *cb = purple_conv_chat_cb_find(chatbuddy->chat, chatbuddy->name);
+	PurpleConvChat *chat = slack_channel_get_conversation(chatbuddy->sa, chatbuddy->chan);
+	PurpleConvChatBuddy *cb = chat ? purple_conv_chat_cb_find(chat, chatbuddy->name) : NULL;
 	if (cb) {
 		purple_conv_chat_user_set_flags(chatbuddy->chat, chatbuddy->name, cb->flags & ~PURPLE_CBFLAGS_TYPING);
 	}
-	
 	g_free(chatbuddy->name);
 	chatbuddy->name = NULL;
+	chatbuddy->sa = NULL;
+	chatbuddy->chan = NULL;
+	// Memory leak? We allocated this, probs should deallocate it.
+	g_free(chatbuddy);
+
 	return FALSE;
 }
 
 void slack_user_typing(SlackAccount *sa, json_value *json) {
-	const char *user_id    = json_get_prop_strptr(json, "user");
+	const char *user_id = json_get_prop_strptr(json, "user");
 	const char *channel_id = json_get_prop_strptr(json, "channel");
 
 	SlackUser *user = (SlackUser*)slack_object_hash_table_lookup(sa->users, user_id);
@@ -598,7 +604,7 @@ void slack_user_typing(SlackAccount *sa, json_value *json) {
 		PurpleConvChatBuddy *cb = chat ? purple_conv_chat_cb_find(chat, user->object.name) : NULL;
 		if (cb) {
 			purple_conv_chat_user_set_flags(chat, user->object.name, cb->flags | PURPLE_CBFLAGS_TYPING);
-			
+
 			guint timeout = GPOINTER_TO_UINT(g_dataset_get_data(user, "typing_timeout"));
 			SlackChatBuddy *chatbuddy = g_dataset_get_data(user, "chatbuddy");
 			if (timeout) {
@@ -609,10 +615,11 @@ void slack_user_typing(SlackAccount *sa, json_value *json) {
 				}
 			}
 			chatbuddy = g_new0(SlackChatBuddy, 1);
-			chatbuddy->chat = chat;
+			chatbuddy->sa = sa;
+			chatbuddy->chan = chan;
 			chatbuddy->name = g_strdup(user->object.name);
 			timeout = purple_timeout_add_seconds(4, (GSourceFunc)slack_unset_typing_cb, chatbuddy);
-			
+
 			g_dataset_set_data(user, "typing_timeout", GUINT_TO_POINTER(timeout));
 			g_dataset_set_data(user, "chatbuddy", chatbuddy);
 		}

[djha-skin]

That extra g_free I added was problematic. Caused a double-free, oopz. I'm still testing :)

[djha-skin]

If you want to follow along at home with my tests, they are here: https://github.com/djhaskin987/slack-libpurple/tree/bugfix/crashing-and-memory
That branch contains my fixes but also it contains the find-user hack so I could get it to log in.

[djha-skin]

Tests went well. I submitted a PR with my changes in #179 :)