Hey,
> While testing a mechanism to trigger a modem restart based on port timeout
> (and disposing of modem object in MM) I managed to segfault ModemManager.
> I'm using vanilla MM 1.12.4 built for armhf target.
>
> What I've found, is that a race condition is possible on
> serial_port_timed_out_cb, which is called one more time than it should,
> causing a use-after-free.
> I've found out that by the fact I used default value of max_timeouts (10) and
> the method got called with n_consecutive_timeouts = 11, but according to the
> condition there, the cancellable was triggered on previous call with
> n_consecutive_timeouts = 10.
>
> The crash happened when calling g_dbus_object_get_object_path (G_DBUS_OBJECT
> (self) when evaluating arguments for the error log in
> serial_port_timed_out_cb :
>
> Stack trace:
> #0 g_dbus_object_get_object_path (object=0x68f1c0) at
> /usr/src/debug/glib-2.0/1_2.48.2-r0/glib-2.48.2/gio/gdbusobject.c:110
> #1 0x0005844c in serial_port_timed_out_cb (port=<optimized out>,
> n_consecutive_timeouts=11, self=0x68f1c0)
> at
> /usr/src/debug/modemmanager/1.12+gitrAUTOINC+cef03ce291-r6/git/src/mm-base-modem.c:130
> #2 0x7699ce48 in g_cclosure_marshal_VOID__FLAGSv (closure=<optimized out>,
> return_value=<optimized out>, instance=<optimized out>, args=...,
> marshal_data=0x0, n_params=1,
> param_types=0x670fa0) at
> /usr/src/debug/glib-2.0/1_2.48.2-r0/glib-2.48.2/gobject/gmarshal.c:1570
> #3 0x7699aaec in _g_closure_invoke_va (closure=closure@entry=0x66e548,
> return_value=return_value@entry=0x0, instance=0x60ea18,
> instance@entry=0x6ac628, args=args@entry=..., n_params=1,
> param_types=0x670fa0) at
> /usr/src/debug/glib-2.0/1_2.48.2-r0/glib-2.48.2/gobject/gclosure.c:867
> #4 0x769b5f44 in g_signal_emit_valist (instance=instance@entry=0x6ac628,
> signal_id=<optimized out>, detail=detail@entry=0, var_args=...,
> var_args@entry=...)
> at /usr/src/debug/glib-2.0/1_2.48.2-r0/glib-2.48.2/gobject/gsignal.c:3294
> #5 0x769b6580 in g_signal_emit (instance=instance@entry=0x6ac628,
> signal_id=<optimized out>, detail=0) at
> /usr/src/debug/glib-2.0/1_2.48.2-r0/glib-2.48.2/gobject/gsignal.c:3441
> #6 0x000d225c in port_serial_timed_out (data=<optimized out>) at
> /usr/src/debug/modemmanager/1.12+gitrAUTOINC+cef03ce291-r6/git/src/mm-port-serial.c:797
> #7 0x768d4758 in g_timeout_dispatch (source=0x682280, callback=0xd21d8
> <port_serial_timed_out>, user_data=<optimized out>)
> at /usr/src/debug/glib-2.0/1_2.48.2-r0/glib-2.48.2/glib/gmain.c:4577
> #8 0x768d3b1c in g_main_dispatch (context=0x614bf8) at
> /usr/src/debug/glib-2.0/1_2.48.2-r0/glib-2.48.2/glib/gmain.c:3154
> #9 g_main_context_dispatch (context=context@entry=0x614bf8) at
> /usr/src/debug/glib-2.0/1_2.48.2-r0/glib-2.48.2/glib/gmain.c:3769
> #10 0x768d3eb4 in g_main_context_iterate (context=0x614bf8,
> block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>)
> at /usr/src/debug/glib-2.0/1_2.48.2-r0/glib-2.48.2/glib/gmain.c:3840
> #11 0x768d4210 in g_main_loop_run (loop=0x61ef10) at
> /usr/src/debug/glib-2.0/1_2.48.2-r0/glib-2.48.2/glib/gmain.c:4034
> #12 0x00044714 in main (argc=<optimized out>, argv=<optimized out>) at
> /usr/src/debug/modemmanager/1.12+gitrAUTOINC+cef03ce291-r6/git/src/main.c:206
>
> Frame #1:
> (gdb) info frame
> Stack level 0, frame at 0x7e9fca90:
> pc = 0x76ae816c in g_dbus_object_get_object_path
> (/usr/src/debug/glib-2.0/1_2.48.2-r0/glib-2.48.2/gio/gdbusobject.c:110);
> saved pc = 0x5844c
> called by frame at 0x7e9fcac0
> source language c.
> Arglist at 0x7e9fca88, args: object=0x68f1c0
> Locals at 0x7e9fca88, Previous frame's sp is 0x7e9fca90
> Saved registers:
> r4 at 0x7e9fca88, lr at 0x7e9fca8c
> object = 0x68f1c0
>
> (gdb) info args
> port = <optimized out>
> n_consecutive_timeouts = 11
>
> (gdb) print *self
> $2 = {parent = {parent_instance = {parent_instance = {g_type_instance =
> {g_class = 0x0}, ref_count = 0, qdata = 0x0}, priv = 0x68f1b0}, priv = 0x0},
> priv = 0x68f148}
> (gdb) print *self->priv
> $4 = {connection = 0x0, cancellable = 0x0, invalid_if_cancelled = 61, device
> = 0x6b22f0 "XEb", drivers = 0x6abda0, plugin = 0x653fc0 "\230\275j",
> vendor_id = 7111, product_id = 33,
> hotplugged = 0, valid = 0, reprobe = 0, max_timeouts = 10, authp = 0x0,
> authp_cancellable = 0x0, ports = 0x0, primary = 0x0, secondary = 0x0, qcdm =
> 0x0, data = 0x0, gps_control = 0x0,
> gps = 0x0, audio = 0x0, enable_tasks = 0x0, disable_tasks = 0x0, qmi = 0x0,
> mbim = 0x0}
>
> I have a full session log and a core dump, so pretty much anything could be
> extracted if needed. So far it only reproduced once. I'm also analyzing
> myself how to fix it, but I'd be glad if you could take a look at this.
>
The error makes sense; the port object is living for longer than the
modem object, and so by the time the timed-out signal is emitted, the
modem object is already unrefed. The fix for this issue is to keep
track of all signal ids returned by g_signal_connect(port,
"timed-out",...) and make sure they are disconnected when the modem
object is unref-ed. Let me try to patch that.
--
Aleksander
https://aleksander.es
_______________________________________________
ModemManager-devel mailing list
ModemManager-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/modemmanager-devel
