Segfault in MM 1.12.4 in port timeout detection logic

[Lech Perczak]

Hi Aleksander,

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 at entry=0x66e548, return_value=return_value at entry=0x0, instance=0x60ea18, instance at entry=0x6ac628, args=args at 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 at entry=0x6ac628, signal_id=<optimized out>, detail=detail at entry=0, var_args=..., var_args at 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 at 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 at 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 at entry=1, dispatch=dispatch at 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.

-- 
Pozdrawiam/With kind regards,
Lech Perczak

Sr. Software Engineer
Camlin Technologies Poland Limited Sp. z o.o.