Bug 694603 – Insering unmanaged by NM config usb wifi module causes assertion

After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.

Bug 694603 - Insering unmanaged by NM config usb wifi module causes assertion


Summary:	Insering unmanaged by NM config usb wifi module causes assertion


Status:	RESOLVED FIXED

Product:	NetworkManager
Classification:	Platform
Component:	ModemManager
Version:	git master
Hardware:	Other Linux

Importance:	Normal major
Target Milestone:	---
Assigned To:	Aleksander Morgado
QA Contact:	NetworkManager maintainer(s)

URL:
Whiteboard:

Depends on:
Blocks:

Reported:	2013-02-24 17:13 UTC by Oleksii Shevchuk
Modified:	2013-02-25 14:29 UTC

See Also:
GNOME target:	---
GNOME version:	---

Attachments
backtrace (1.45 KB, application/octet-stream) 2013-02-24 17:13 UTC, Oleksii Shevchuk		Details
Workaround (969 bytes, patch) 2013-02-24 17:29 UTC, Oleksii Shevchuk	rejected	Details \| Review
Patch for the issue. (1.27 KB, patch) 2013-02-25 11:09 UTC, Aleksander Morgado	committed	Details \| Review

Description Oleksii Shevchuk 2013-02-24 17:13:33 UTC

Created attachment 237291 [details]
backtrace

NetworkManager[27504]: <info> ModemManager disappeared from bus
systemd[1]: ModemManager1.service: main process exited, code=dumped, status=6/ABRT
dbus-daemon[1660]: dbus[1660]: [system] Activating via systemd: service name='org.freedesktop.ModemManager1' unit='dbus-org.freedesktop.ModemManager1.service'
dbus[1660]: [system] Activating via systemd: service name='org.freedesktop.ModemManager1' unit='dbus-org.freedesk
top.ModemManager1.service'
systemd[1]: Unit ModemManager1.service entered failed state
systemd[1]: Starting Modem Manager...
ModemManager[32728]: ModemManager[32728]: <info>  ModemManager (version 9999) starting...
ModemManager[32728]: <info>  ModemManager (version 9999) starting...
dbus-daemon[1660]: dbus[1660]: [system] Successfully activated service 'org.freedesktop.ModemManager1'
dbus[1660]: [system] Successfully activated service 'org.freedesktop.ModemManager1'
NetworkManager[27504]: <info> ModemManager disappeared from bus
systemd[1]: Started Modem Manager.
NetworkManager[27504]: <info> ModemManager available in the bus
ModemManager[32728]: ModemManager[32728]: <warn>  Couldn't find support for device at '/sys/devices/pci0000:00/0000:00:19.0': not supported by any plugin
BlackICE ModemManager[32728]: ModemManager[32728]: <warn>  Couldn't find support for device at '/sys/devices/pci0000:00/0000:00:1c.1/0000:03:00.0': not supported by any plugin
ModemManager[32728]: **
ModemManager[32728]: ERROR:mm-plugin-manager.c:299:suggest_port_probe_result: assertion failed: (port_probe_ctx->defer_id == 0)
ModemManager[32728]: <warn>  Couldn't find support for device at '/sys/devices/pci0000:00/0000:00:19.0': not supported by any plugin
ModemManager[32728]: <warn>  Couldn't find support for device at '/sys/devices/pci0000:00/0000:00:1c.1/0000:03:00.0': not supported by any plugin
systemd-coredump[32732]: Process 32728 (ModemManager) dumped core.
NetworkManager[27504]: <info> ModemManager disappeared from bus

and so on

Comment 1 Oleksii Shevchuk 2013-02-24 17:16:11 UTC

Ok, I insert module, and hostapd started on it, so it creats wlan2.mon interface. Looks like MM1 doesn't like it:

ModemManager[27806]: <debug> [1361726096.461813] [mm-iface-modem-messaging.c:1113] load_supported_storages_ready(): Supported storages loaded:
ModemManager[27806]: <debug> [1361726096.461878] [mm-iface-modem-messaging.c:1114] load_supported_storages_ready():   mem1 (list/read/delete) storages: 'me, sm'
ModemManager[27806]: <debug> [1361726096.461918] [mm-iface-modem-messaging.c:1115] load_supported_storages_ready():   mem2 (write/send) storages:       'me, sm'
ModemManager[27806]: <debug> [1361726096.461955] [mm-iface-modem-messaging.c:1116] load_supported_storages_ready():   mem3 (reception) storages:        'me, sm'
ModemManager[27806]: <debug> [1361726096.462155] [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM1) device open count is 1 (close)
ModemManager[27806]: <debug> [1361726096.462470] [mm-broadband-modem.c:8545] iface_modem_time_initialize_ready(): Couldn't initialize interface: 'Time not supported'
ModemManager[27806]: <debug> [1361726096.462728] [mm-broadband-modem.c:8546] iface_modem_firmware_initialize_ready(): Couldn't initialize interface: 'Firmware not supported'
ModemManager[27806]: <info>  [1361726096.463018] [mm-iface-modem.c:1201] __iface_modem_update_state_internal(): Modem: state changed (unknown -> disabled)
ModemManager[27806]: <debug> [1361726096.463218] [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM1) device open count is 0 (close)
ModemManager[27806]: <debug> [1361726096.463343] [mm-serial-port.c:1019] mm_serial_port_close(): (ttyACM1) closing serial port...
ModemManager[27806]: <debug> [1361726096.468048] [mm-serial-port.c:1050] mm_serial_port_close(): (ttyACM1) serial port closed
ModemManager[27806]: <debug> [1361726096.468145] [mm-base-modem.c:808] initialize_ready(): modem properly initialized
ModemManager[27806]: <debug> [1361726096.469906] [mm-device.c:397] export_modem(): Exported modem '/sys/devices/pci0000:00/0000:00:1d.7/usb8/8-4' at path '/org/freedesktop/ModemManager1/Modem/0'
ModemManager[27806]: <debug> [1361726096.470266] [mm-device.c:405] export_modem(): (/org/freedesktop/ModemManager1/Modem/0): 'Ericsson MBM' modem, VID 0x0BDB PID 0x1900 (usb)
ModemManager[27806]: <debug> [1361726100.611486] [mm-plugin-manager.c:617] mm_plugin_manager_find_device_support(): (Plugin Manager) [/sys/devices/pci0000:00/0000:00:1d.7/usb8/8-2] Checking device support...
ModemManager[27806]: <debug> [1361726100.611829] [mm-plugin.c:207] apply_pre_probing_filters(): (X22X) [wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726100.611912] [mm-plugin.c:207] apply_pre_probing_filters(): (Novatel) [wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726100.611960] [mm-plugin.c:316] apply_pre_probing_filters(): (AnyDATA) [wlan2] filtered by vendor/product IDs
ModemManager[27806]: <debug> [1361726100.612007] [mm-plugin.c:207] apply_pre_probing_filters(): (Wavecom) [wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726100.612051] [mm-plugin.c:248] apply_pre_probing_filters(): (Option High-Speed) [wlan2] filtered by drivers
ModemManager[27806]: <debug> [1361726100.612097] [mm-plugin.c:248] apply_pre_probing_filters(): (Sierra) [wlan2] filtered by drivers
ModemManager[27806]: <debug> [1361726100.612140] [mm-plugin.c:316] apply_pre_probing_filters(): (Huawei) [wlan2] filtered by vendor/product IDs
ModemManager[27806]: <debug> [1361726100.612186] [mm-plugin.c:316] apply_pre_probing_filters(): (Nokia (Icera)) [wlan2] filtered by vendor/product IDs
ModemManager[27806]: <debug> [1361726100.612271] [mm-plugin.c:316] apply_pre_probing_filters(): (Samsung) [wlan2] filtered by vendor/product IDs
ModemManager[27806]: <debug> [1361726100.612316] [mm-plugin.c:316] apply_pre_probing_filters(): (Novatel LTE) [wlan2] filtered by vendor/product IDs
ModemManager[27806]: <debug> [1361726100.659308] [mm-plugin.c:207] apply_pre_probing_filters(): (Motorola) [wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726100.659413] [mm-plugin.c:207] apply_pre_probing_filters(): (Linktop) [wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726100.661341] [mm-plugin.c:316] apply_pre_probing_filters(): (ZTE) [wlan2] filtered by vendor/product IDs
ModemManager[27806]: <debug> [1361726100.661419] [mm-plugin.c:207] apply_pre_probing_filters(): (Iridium) [wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726100.667447] [mm-plugin.c:370] apply_pre_probing_filters(): (Ericsson MBM) [wlan2] filtered by udev tags
ModemManager[27806]: <debug> [1361726100.671018] [mm-plugin.c:207] apply_pre_probing_filters(): (Cinterion) [wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726100.672485] [mm-plugin.c:207] apply_pre_probing_filters(): (Longcheer) [wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726100.677632] [mm-plugin.c:207] apply_pre_probing_filters(): (Via CBP7) [wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726100.686739] [mm-plugin.c:316] apply_pre_probing_filters(): (Pantech) [wlan2] filtered by vendor/product IDs
ModemManager[27806]: <debug> [1361726100.688370] [mm-plugin.c:207] apply_pre_probing_filters(): (Option) [wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726100.689127] [mm-plugin.c:207] apply_pre_probing_filters(): (Nokia) [wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726100.690998] [mm-plugin.c:248] apply_pre_probing_filters(): (Gobi) [wlan2] filtered by drivers
ModemManager[27806]: <debug> [1361726100.692550] [mm-plugin.c:207] apply_pre_probing_filters(): (SimTech) [wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726100.696638] [mm-plugin-manager.c:518] build_plugins_list(): (Plugin Manager) [wlan2] Found '1' plugins to try...
ModemManager[27806]: <debug> [1361726100.698312] [mm-plugin-manager.c:522] build_plugins_list(): (Plugin Manager) [wlan2]   Will try with plugin 'Generic'
ModemManager[27806]: <debug> [1361726100.699804] [mm-plugin.c:679] mm_plugin_supports_port(): (Generic) [wlan2] probing deferred until result suggested
ModemManager[27806]: <debug> [1361726100.701529] [mm-plugin-manager.c:447] plugin_supports_port_ready(): (Plugin Manager) [wlan2] deferring support check until result suggested
ModemManager[27806]: <debug> [1361726101.552891] [mm-plugin.c:207] apply_pre_probing_filters(): (X22X) [mon.wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726101.553116] [mm-plugin.c:207] apply_pre_probing_filters(): (Novatel) [mon.wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726101.553171] [mm-plugin.c:316] apply_pre_probing_filters(): (AnyDATA) [mon.wlan2] filtered by vendor/product IDs
ModemManager[27806]: <debug> [1361726101.553218] [mm-plugin.c:207] apply_pre_probing_filters(): (Wavecom) [mon.wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726101.560039] [mm-plugin.c:248] apply_pre_probing_filters(): (Option High-Speed) [mon.wlan2] filtered by drivers
ModemManager[27806]: <debug> [1361726101.561328] [mm-plugin.c:248] apply_pre_probing_filters(): (Sierra) [mon.wlan2] filtered by drivers
ModemManager[27806]: <debug> [1361726101.562430] [mm-plugin.c:316] apply_pre_probing_filters(): (Huawei) [mon.wlan2] filtered by vendor/product IDs
ModemManager[27806]: <debug> [1361726101.563494] [mm-plugin.c:316] apply_pre_probing_filters(): (Nokia (Icera)) [mon.wlan2] filtered by vendor/product IDs
ModemManager[27806]: <debug> [1361726101.564571] [mm-plugin.c:316] apply_pre_probing_filters(): (Samsung) [mon.wlan2] filtered by vendor/product IDs
ModemManager[27806]: <debug> [1361726101.564637] [mm-plugin.c:316] apply_pre_probing_filters(): (Novatel LTE) [mon.wlan2] filtered by vendor/product IDs
ModemManager[27806]: <debug> [1361726101.564683] [mm-plugin.c:207] apply_pre_probing_filters(): (Motorola) [mon.wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726101.567508] [mm-plugin.c:207] apply_pre_probing_filters(): (Linktop) [mon.wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726101.567785] [mm-plugin.c:316] apply_pre_probing_filters(): (ZTE) [mon.wlan2] filtered by vendor/product IDs
ModemManager[27806]: <debug> [1361726101.567841] [mm-plugin.c:207] apply_pre_probing_filters(): (Iridium) [mon.wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726101.567988] [mm-plugin.c:370] apply_pre_probing_filters(): (Ericsson MBM) [mon.wlan2] filtered by udev tags
ModemManager[27806]: <debug> [1361726101.568036] [mm-plugin.c:207] apply_pre_probing_filters(): (Cinterion) [mon.wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726101.568077] [mm-plugin.c:207] apply_pre_probing_filters(): (Longcheer) [mon.wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726101.568117] [mm-plugin.c:207] apply_pre_probing_filters(): (Via CBP7) [mon.wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726101.568158] [mm-plugin.c:316] apply_pre_probing_filters(): (Pantech) [mon.wlan2] filtered by vendor/product IDs
ModemManager[27806]: <debug> [1361726101.568201] [mm-plugin.c:207] apply_pre_probing_filters(): (Option) [mon.wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726101.568280] [mm-plugin.c:207] apply_pre_probing_filters(): (Nokia) [mon.wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726101.568326] [mm-plugin.c:248] apply_pre_probing_filters(): (Gobi) [mon.wlan2] filtered by drivers
ModemManager[27806]: <debug> [1361726101.578834] [mm-plugin.c:207] apply_pre_probing_filters(): (SimTech) [mon.wlan2] filtered by subsystem
ModemManager[27806]: <debug> [1361726101.579092] [mm-plugin-manager.c:518] build_plugins_list(): (Plugin Manager) [mon.wlan2] Found '1' plugins to try...
ModemManager[27806]: <debug> [1361726101.579332] [mm-plugin-manager.c:522] build_plugins_list(): (Plugin Manager) [mon.wlan2]   Will try with plugin 'Generic'
ModemManager[27806]: <debug> [1361726101.579399] [mm-plugin.c:679] mm_plugin_supports_port(): (Generic) [mon.wlan2] probing deferred until result suggested
ModemManager[27806]: <debug> [1361726101.579679] [mm-plugin-manager.c:447] plugin_supports_port_ready(): (Plugin Manager) [mon.wlan2] deferring support check until result suggested
ModemManager[27806]: <debug> [1361726103.297790] [mm-plugin-manager.c:588] min_probing_timeout_cb(): (Plugin Manager) [/sys/devices/pci0000:00/0000:00:1d.7/usb8/8-2] Minimum probing time consumed
ModemManager[27806]: <debug> [1361726103.299282] [mm-plugin-manager.c:297] suggest_port_probe_result(): (Plugin Manager) [mon.wlan2] deferred task cancelled, no suggested plugin
ModemManager[27806]: <debug> [1361726103.300318] [mm-plugin-manager.c:297] suggest_port_probe_result(): (Plugin Manager) [wlan2] deferred task cancelled, no suggested plugin
ModemManager[27806]: <debug> [1361726103.300501] [mm-plugin-manager.c:155] port_probe_context_finished(): (Plugin Manager) [mon.wlan2] not supported by any plugin
ModemManager[27806]: <debug> [1361726103.300630] [mm-device.c:320] mm_device_ignore_port(): Fully ignoring port 'net/mon.wlan2' from now on
ModemManager[27806]: <debug> [1361726103.300746] [mm-plugin-manager.c:297] suggest_port_probe_result(): (Plugin Manager) [wlan2] deferred task cancelled, no suggested plugin
ERROR: port_probe_ctx->defer_id: 570

Comment 2 Oleksii Shevchuk 2013-02-24 17:24:56 UTC

Ok, I add some debug messages where defer_id setted up:

ModemManager[28412]: <debug> [1361726635.623776] [mm-plugin-manager.c:311] suggest_port_probe_result(): SETTING UP HERE: 117
ModemManager[28412]: <debug> [1361726635.625157] [mm-plugin-manager.c:258] deferred_support_check_idle(): SETTING UP port_probe_ctx->defer_id: 0
ModemManager[28412]: <debug> [1361726637.304834] [mm-plugin-manager.c:311] suggest_port_probe_result(): SETTING UP HERE: 143
ModemManager[28412]: <debug> [1361726637.305043] [mm-plugin-manager.c:311] suggest_port_probe_result(): SETTING UP HERE: 144
ModemManager[28412]: <debug> [1361726637.305210] [mm-plugin-manager.c:311] suggest_port_probe_result(): SETTING UP HERE: 145
ModemManager[28412]: <debug> [1361726637.305377] [mm-plugin-manager.c:311] suggest_port_probe_result(): SETTING UP HERE: 146
ModemManager[28412]: <debug> [1361726637.306900] [mm-plugin-manager.c:258] deferred_support_check_idle(): SETTING UP port_probe_ctx->defer_id: 0
ModemManager[28412]: <debug> [1361726637.307323] [mm-plugin-manager.c:258] deferred_support_check_idle(): SETTING UP port_probe_ctx->defer_id: 0
ModemManager[28412]: <debug> [1361726637.307648] [mm-plugin-manager.c:258] deferred_support_check_idle(): SETTING UP port_probe_ctx->defer_id: 0
SETTING ERROR: port_probe_ctx->defer_id: 146

Comment 3 Oleksii Shevchuk 2013-02-24 17:29:19 UTC

Created attachment 237292 [details] [review]
Workaround

Comment 4 Aleksander Morgado 2013-02-25 11:07:15 UTC

Review of attachment 237292 [details] [review]:

Think I have a better solution, see next patch.

Comment 5 Aleksander Morgado 2013-02-25 11:09:33 UTC

Created attachment 237347 [details] [review]
Patch for the issue.

So, instead of keeping the deferred-until-suggested flag set, we should unset it as soon as we know the probing task is cancelled. This should avoid re-suggesting plugin results and therefore it should skip the defer_id reset.

Oleksii, can you test the patch?

Comment 6 Oleksii Shevchuk 2013-02-25 13:34:22 UTC

Looks like it works

ModemManager[7830]: <debug> [1361799193.845538] [mm-plugin-manager.c:514] build_plugins_list(): (Plugin Manager) [wlan1mon] Found '1' plugins to try...
ModemManager[7830]: <debug> [1361799193.845773] [mm-plugin-manager.c:518] build_plugins_list(): (Plugin Manager) [wlan1mon]   Will try with plugin 'Generic'
ModemManager[7830]: <debug> [1361799193.846087] [mm-plugin.c:679] mm_plugin_supports_port(): (Generic) [wlan1mon] probing deferred until result suggested
ModemManager[7830]: <debug> [1361799193.846412] [mm-plugin-manager.c:443] plugin_supports_port_ready(): (Plugin Manager) [wlan1mon] deferring support check until result suggested
ModemManager[7830]: <debug> [1361799195.325243] [mm-plugin-manager.c:584] min_probing_timeout_cb(): (Plugin Manager) [/sys/devices/pci0000:00/0000:00:1d.7/usb8/8-2] Minimum probing time consumed
ModemManager[7830]: <debug> [1361799195.326540] [mm-plugin-manager.c:297] suggest_port_probe_result(): (Plugin Manager) [wlan1mon] deferred task cancelled, no suggested plugin
ModemManager[7830]: <debug> [1361799195.327019] [mm-plugin-manager.c:297] suggest_port_probe_result(): (Plugin Manager) [wlan1] deferred task cancelled, no suggested plugin
ModemManager[7830]: <debug> [1361799195.327237] [mm-plugin-manager.c:151] port_probe_context_finished(): (Plugin Manager) [wlan1mon] not supported by any plugin
ModemManager[7830]: <debug> [1361799195.327389] [mm-device.c:320] mm_device_ignore_port(): Fully ignoring port 'net/wlan1mon' from now on
ModemManager[7830]: <debug> [1361799195.328245] [mm-plugin-manager.c:230] port_probe_context_finished(): (Plugin Manager) 'wlan1mon' port probe finished, still 1 running probes in this device (wlan1)
ModemManager[7830]: <debug> [1361799195.328410] [mm-plugin-manager.c:151] port_probe_context_finished(): (Plugin Manager) [wlan1] not supported by any plugin
ModemManager[7830]: <debug> [1361799195.328560] [mm-device.c:320] mm_device_ignore_port(): Fully ignoring port 'net/wlan1' from now on
ModemManager[7830]: <debug> [1361799195.328702] [mm-plugin-manager.c:241] port_probe_context_finished(): (Plugin Manager) 'wlan1' port probe finished, last one in device
ModemManager[7830]: <debug> [1361799195.328850] [mm-plugin-manager.c:107] find_device_support_context_complete_and_free(): (Plugin Manager) [/sys/devices/pci0000:00/0000:00:1d.7/usb8/8-2] device support check finished in '1.816534' seconds
ModemManager[7830]: <warn>  [1361799195.329004] [mm-manager.c:140] find_device_support_ready(): Couldn't find support for device at '/sys/devices/pci0000:00/0000:00:1d.7/usb8/8-2': not supported by any plugin