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.
>
I believe this should now be fixed in the following merge request:
https://gitlab.freedesktop.org/mobile-broadband/ModemManager/merge_requests/248
If you're able to reproduce the problem easily, please give it a try
and let me know if it fixes it or not. I'll backport the relevant
change to 1.12.x once if the change in master looks ok.
--
Aleksander
https://aleksander.es
_______________________________________________
ModemManager-devel mailing list
ModemManager-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/modemmanager-devel
