Bug 1266003

Summary: NetworkManager segfault on_bss_proxy_acquired
Product: [Fedora] Fedora Reporter: Hein-Pieter van Braam <hp>
Component: NetworkManagerAssignee: Lubomir Rintel <lkundrak>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 22CC: ben.r.xiao, dcbw, eminguez, fadnix, fedora, jklimes, lkundrak, psimerda
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: NetworkManager-1.0.6-7.fc22 NetworkManager-1.0.6-7.fc23 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 1267462 (view as bug list) Environment:
Last Closed: 2015-10-28 16:23:46 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1267462    
Attachments:
Description Flags
lshw output of affected system (in case that matters) none

Description Hein-Pieter van Braam 2015-09-24 09:41:00 UTC
Description of problem:

As of NetworkManager-1.0.6-5.fc22.x86_64 / Linux 4.1.7-200.fc22.x86_64 NetworkManager continuously crashes when I'm at my workplace with WiFi enabled. It does not happen at home. I believe this has something to do with the security enabled on some of the networks here.

Version-Release number of selected component (if applicable):

1.0.6-5.fc22.x86_64
4.1.7-200.fc22.x86_64

How reproducible:

Just leave NetworkManager on with WiFi enabled in the face of WPA2 networks with enterprise authentication schemes. (I think)


Actual results:

Crash

Expected results:

Not a crash

Additional info:

Backtrace of NetworkManager during the crash

Program received signal SIGSEGV, Segmentation fault.
on_bss_proxy_acquired (proxy=0x7f05dc003b80 [GDBusProxy], result=<optimized out>, user_data=<optimized out>) at supplicant-manager/nm-supplicant-interface.c:157
157		while (*iter) {
(gdb) bt
#0  0x000055d77ff2048b in on_bss_proxy_acquired (proxy=0x7f05dc003b80 [GDBusProxy], result=<optimized out>, user_data=<optimized out>) at supplicant-manager/nm-supplicant-interface.c:157
#1  0x00007f05f26c7ba7 in g_simple_async_result_complete (simple=0x55d781af7980 [GSimpleAsyncResult]) at gsimpleasyncresult.c:763
#2  0x00007f05f26c7c09 in complete_in_idle_cb (data=<optimized out>) at gsimpleasyncresult.c:775
#3  0x00007f05f2110a8a in g_main_context_dispatch (context=0x55d781931400) at gmain.c:3122
#4  0x00007f05f2110a8a in g_main_context_dispatch (context=context@entry=0x55d781931400) at gmain.c:3737
#5  0x00007f05f2110e20 in g_main_context_iterate (context=0x55d781931400, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at gmain.c:3808
#6  0x00007f05f2111142 in g_main_loop_run (loop=0x55d7819314c0) at gmain.c:4002
#7  0x000055d77feb9ca2 in main (argc=1, argv=0x7ffea5fb5a68) at main.c:512

# journalctl -fu NetworkManager 

Sep 24 11:28:36 lola NetworkManager[11626]: <info>  WiFi now enabled by radio killswitch
Sep 24 11:28:36 lola NetworkManager[11626]: <info>  (wlp3s0) supports 5 scan SSIDs
Sep 24 11:28:36 lola NetworkManager[11626]: <info>  (wlp3s0): supplicant interface state: starting -> ready
Sep 24 11:28:36 lola NetworkManager[11626]: <info>  (wlp3s0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
Sep 24 11:28:39 lola NetworkManager[11626]: <info>  (wlp3s0): supplicant interface state: ready -> inactive
Sep 24 11:31:12 lola systemd[1]: NetworkManager.service: main process exited, code=dumped, status=11/SEGV
Sep 24 11:31:12 lola systemd[1]: Unit NetworkManager.service entered failed state.
Sep 24 11:31:12 lola systemd[1]: NetworkManager.service failed.
Sep 24 11:31:13 lola systemd[1]: NetworkManager.service holdoff time over, scheduling restart.
Sep 24 11:31:13 lola systemd[1]: Starting Network Manager...

Another oddity:

# iwlist scanning
virbr1-nic  Interface doesn't support scanning.

enp0s25   Interface doesn't support scanning.

lo        Interface doesn't support scanning.

virbr1    Interface doesn't support scanning.

print_scanning_info: Allocation failed


this last message makes me thing that perhaps this is a kernel/driver issue but I have not been able to confirm this yet.

Comment 1 Hein-Pieter van Braam 2015-09-24 09:45:25 UTC
Created attachment 1076420 [details]
lshw output of affected system (in case that matters)

Comment 2 Jirka Klimes 2015-09-29 10:58:34 UTC
The bug has been fixed [1] in upstream master for some time, but nm-1-0 branch (used for NM 1.0.6) have missed the fix. Adding it now [2].

[1] http://cgit.freedesktop.org/NetworkManager/NetworkManager/commit/?id=33527341b1e35034a4f1736df4bc98f8ac8418ab
[2] http://cgit.freedesktop.org/NetworkManager/NetworkManager/commit/?h=nm-1-0&id=9736327b2616861dfec181e88f908a18b22d781c

Comment 3 Hein-Pieter van Braam 2015-09-29 11:03:01 UTC
Awesome, thank you. Would it help if I tested this or are you satisfied that this fixes this issue?

Comment 4 Jirka Klimes 2015-09-30 06:36:28 UTC
(In reply to Hein-Pieter van Braam from comment #3)
> Awesome, thank you. Would it help if I tested this or are you satisfied that
> this fixes this issue?

I could make a test build if you want. But it is not necessary, I am quite confident of the fix. Thanks.

Comment 5 Eduardo Minguez 2015-10-08 10:48:08 UTC
It happens to me too. Journalctl says:

...
oct 08 12:39:22 nostromo.minwi.lan NetworkManager[1166]: <info>  connectivity: check for uri 'http://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': No address associated with hostname'
oct 08 12:39:23 nostromo.minwi.lan NetworkManager[1166]: <info>  (virbr0): device state change: secondaries -> activated (reason 'none') [90 100 0]
oct 08 12:39:23 nostromo.minwi.lan NetworkManager[1166]: <info>  (virbr0): Activation: successful, device activated.
oct 08 12:39:23 nostromo.minwi.lan NetworkManager[1166]: <info>  (virbr1): device state change: secondaries -> activated (reason 'none') [90 100 0]
oct 08 12:39:23 nostromo.minwi.lan NetworkManager[1166]: <info>  (virbr1): Activation: successful, device activated.
oct 08 12:39:23 nostromo.minwi.lan NetworkManager[1166]: <info>  (virbr2): device state change: secondaries -> activated (reason 'none') [90 100 0]
oct 08 12:39:23 nostromo.minwi.lan NetworkManager[1166]: <info>  (virbr2): Activation: successful, device activated.
oct 08 12:39:23 nostromo.minwi.lan NetworkManager[1166]: <info>  (docker0): device state change: secondaries -> activated (reason 'none') [90 100 0]
oct 08 12:39:23 nostromo.minwi.lan NetworkManager[1166]: <info>  (docker0): Activation: successful, device activated.
oct 08 12:39:24 nostromo.minwi.lan NetworkManager[1166]: (NetworkManager:1166): libnm-CRITICAL **: nm_utils_hwaddr_matches: assertion 'hwaddr1 != NULL' failed
oct 08 12:39:24 nostromo.minwi.lan NetworkManager[1166]: (NetworkManager:1166): libnm-CRITICAL **: nm_utils_hwaddr_matches: assertion 'hwaddr1 != NULL' failed
oct 08 12:39:24 nostromo.minwi.lan NetworkManager[1166]: **
oct 08 12:39:24 nostromo.minwi.lan NetworkManager[1166]: NetworkManager-wifi:ERROR:nm-device-wifi.c:1653:try_fill_ssid_for_hidden_ap: assertion failed: (bssid)
oct 08 12:39:29 nostromo.minwi.lan systemd-coredump[1761]: Process 1166 (NetworkManager) of user 0 dumped core.
                                                           
                                                           Stack trace of thread 1166:
                                                           #0  0x00007ff80a3139c8 raise (libc.so.6)
                                                           #1  0x00007ff80a31565a abort (libc.so.6)
                                                           #2  0x00007ff80a9262a5 g_assertion_message (libglib-2.0.so.0)
                                                           #3  0x00007ff80a92633a g_assertion_message_expr (libglib-2.0.so.0)
                                                           #4  0x00007ff7fb1de40e supplicant_iface_new_bss_cb (libnm-device-plugin-wifi.so)
                                                           #5  0x00007ff8086e0db0 ffi_call_unix64 (libffi.so.6)
                                                           #6  0x00007ff8086e0818 ffi_call (libffi.so.6)
                                                           #7  0x00007ff80ac00a25 g_cclosure_marshal_generic_va (libgobject-2.0.so.0)
                                                           #8  0x00007ff80abfff04 _g_closure_invoke_va (libgobject-2.0.so.0)
                                                           #9  0x00007ff80ac19c7d g_signal_emit_valist (libgobject-2.0.so.0)
                                                           #10 0x00007ff80ac1a29f g_signal_emit (libgobject-2.0.so.0)
                                                           #11 0x000055962602e4d5 on_bss_proxy_acquired (NetworkManager)
                                                           #12 0x00007ff80aeb6ba7 g_simple_async_result_complete (libgio-2.0.so.0)
                                                           #13 0x00007ff80aeb6c09 complete_in_idle_cb (libgio-2.0.so.0)
                                                           #14 0x00007ff80a8ffa8a g_main_context_dispatch (libglib-2.0.so.0)
                                                           #15 0x00007ff80a8ffe20 g_main_context_iterate.isra.29 (libglib-2.0.so.0)
                                                           #16 0x00007ff80a900142 g_main_loop_run (libglib-2.0.so.0)
                                                           #17 0x0000559625fc7ca2 main (NetworkManager)
                                                           #18 0x00007ff80a2ff700 __libc_start_main (libc.so.6)
                                                           #19 0x0000559625fc9bf9 _start (NetworkManager)
                                                           
                                                           Stack trace of thread 1168:
                                                           #0  0x00007ff80a3dbeb9 syscall (libc.so.6)
                                                           #1  0x00007ff80a94514a g_cond_wait_until (libglib-2.0.so.0)
                                                           #2  0x00007ff80a8d4a29 g_async_queue_pop_intern_unlocked (libglib-2.0.so.0)
                                                           #3  0x00007ff80a927a16 g_thread_pool_thread_proxy (libglib-2.0.so.0)
                                                           #4  0x00007ff80a9270a5 g_thread_proxy (libglib-2.0.so.0)
                                                           #5  0x00007ff80c8b3555 start_thread (libpthread.so.0)
                                                           #6  0x00007ff80a3e1b9d __clone (libc.so.6)
                                                           
                                                           Stack trace of thread 1653:
                                                           #0  0x00007ff80a3dbeb9 syscall (libc.so.6)
                                                           #1  0x00007ff80a94514a g_cond_wait_until (libglib-2.0.so.0)
                                                           #2  0x00007ff80a8d4a29 g_async_queue_pop_intern_unlocked (libglib-2.0.so.0)
                                                           #3  0x00007ff80a927a16 g_thread_pool_thread_proxy (libglib-2.0.so.0)
                                                           #4  0x00007ff80a9270a5 g_thread_proxy (libglib-2.0.so.0)
                                                           #5  0x00007ff80c8b3555 start_thread (libpthread.so.0)
                                                           #6  0x00007ff80a3e1b9d __clone (libc.so.6)
                                                           
                                                           Stack trace of thread 1655:
                                                           #0  0x00007ff80a3dbeb9 syscall (libc.so.6)
                                                           #1  0x00007ff80a94514a g_cond_wait_until (libglib-2.0.so.0)
                                                           #2  0x00007ff80a8d4a29 g_async_queue_pop_intern_unlocked (libglib-2.0.so.0)
                                                           #3  0x00007ff80a927a16 g_thread_pool_thread_proxy (libglib-2.0.so.0)
                                                           #4  0x00007ff80a9270a5 g_thread_proxy (libglib-2.0.so.0)
                                                           #5  0x00007ff80c8b3555 start_thread (libpthread.so.0)
                                                           #6  0x00007ff80a3e1b9d __clone (libc.so.6)
                                                           
                                                           Stack trace of thread 1699:
                                                           #0  0x00007ff80a3dbeb9 syscall (libc.so.6)
                                                           #1  0x00007ff80a94514a g_cond_wait_until (libglib-2.0.so.0)
                                                           #2  0x00007ff80a8d4a29 g_async_queue_pop_intern_unlocked (libglib-2.0.so.0)
                                                           #3  0x00007ff80a927a16 g_thread_pool_thread_proxy (libglib-2.0.so.0)
                                                           #4  0x00007ff80a9270a5 g_thread_proxy (libglib-2.0.so.0)
                                                           #5  0x00007ff80c8b3555 start_thread (libpthread.so.0)
                                                           #6  0x00007ff80a3e1b9d __clone (libc.so.6)
                                                           
                                                           Stack trace of thread 1700:
                                                           #0  0x00007ff80a3dbeb9 syscall (libc.so.6)
                                                           #1  0x00007ff80a94514a g_cond_wait_until (libglib-2.0.so.0)
                                                           #2  0x00007ff80a8d4a29 g_async_queue_pop_intern_unlocked (libglib-2.0.so.0)
                                                           #3  0x00007ff80a927a16 g_thread_pool_thread_proxy (libglib-2.0.so.0)
                                                           #4  0x00007ff80a9270a5 g_thread_proxy (libglib-2.0.so.0)
                                                           #5  0x00007ff80c8b3555 start_thread (libpthread.so.0)
                                                           #6  0x00007ff80a3e1b9d __clone (libc.so.6)
                                                           
                                                           Stack trace of thread 1701:
                                                           #0  0x00007ff80a3dbeb9 syscall (libc.so.6)
                                                           #1  0x00007ff80a94514a g_cond_wait_until (libglib-2.0.so.0)
                                                           #2  0x00007ff80a8d4a29 g_async_queue_pop_intern_unlocked (libglib-2.0.so.0)
                                                           #3  0x00007ff80a927a16 g_thread_pool_thread_proxy (libglib-2.0.so.0)
                                                           #4  0x00007ff80a9270a5 g_thread_proxy (libglib-2.0.so.0)
                                                           #5  0x00007ff80c8b3555 start_thread (libpthread.so.0)
                                                           #6  0x00007ff80a3e1b9d __clone (libc.so.6)
                                                           
                                                           Stack trace of thread 1702:
                                                           #0  0x00007ff80a3dbeb9 syscall (libc.so.6)
                                                           #1  0x00007ff80a94514a g_cond_wait_until (libglib-2.0.so.0)
                                                           #2  0x00007ff80a8d4a29 g_async_queue_pop_intern_unlocked (libglib-2.0.so.0)
                                                           #3  0x00007ff80a927a16 g_thread_pool_thread_proxy (libglib-2.0.so.0)
                                                           #4  0x00007ff80a9270a5 g_thread_proxy (libglib-2.0.so.0)
                                                           #5  0x00007ff80c8b3555 start_thread (libpthread.so.0)
                                                           #6  0x00007ff80a3e1b9d __clone (libc.so.6)
                                                           
                                                           Stack trace of thread 1167:
                                                           #0  0x00007ff80a3d62fd poll (libc.so.6)
                                                           #1  0x00007ff80a8ffdbc g_main_context_iterate.isra.29 (libglib-2.0.so.0)
                                                           #2  0x00007ff80a8ffecc g_main_context_iteration (libglib-2.0.so.0)
                                                           #3  0x00007ff80a8fff09 glib_worker_main (libglib-2.0.so.0)
                                                           #4  0x00007ff80a9270a5 g_thread_proxy (libglib-2.0.so.0)
                                                           #5  0x00007ff80c8b3555 start_thread (libpthread.so.0)
                                                           #6  0x00007ff80a3e1b9d __clone (libc.so.6)
                                                           
                                                           Stack trace of thread 1169:
                                                           #0  0x00007ff80a3836db __strncpy_sse2_unaligned (libc.so.6)
                                                           #1  0x00007ff80a91e939 g_strndup (libglib-2.0.so.0)
                                                           #2  0x00007ff80a9424d8 g_variant_type_info_get (libglib-2.0.so.0)
                                                           #3  0x00007ff80a93b289 g_variant_new_from_children (libglib-2.0.so.0)
                                                           #4  0x00007ff80a937fac g_variant_builder_end (libglib-2.0.so.0)
                                                           #5  0x00007ff80af17336 parse_value_from_blob (libgio-2.0.so.0)
                                                           #6  0x00007ff80af1937c g_dbus_message_new_from_blob (libgio-2.0.so.0)
                                                           #7  0x00007ff80af236ad _g_dbus_worker_do_read_cb (libgio-2.0.so.0)
                                                           #8  0x00007ff80aeb6ba7 g_simple_async_result_complete (libgio-2.0.so.0)
                                                           #9  0x00007ff80aeb6c09 complete_in_idle_cb (libgio-2.0.so.0)
                                                           #10 0x00007ff80a8ffa8a g_main_context_dispatch (libglib-2.0.so.0)
                                                           #11 0x00007ff80a8ffe20 g_main_context_iterate.isra.29 (libglib-2.0.so.0)
                                                           #12 0x00007ff80a900142 g_main_loop_run (libglib-2.0.so.0)
                                                           #13 0x00007ff80af21696 gdbus_shared_thread_func (libgio-2.0.so.0)
                                                           #14 0x00007ff80a9270a5 g_thread_proxy (libglib-2.0.so.0)
                                                           #15 0x00007ff80c8b3555 start_thread (libpthread.so.0)
                                                           #16 0x00007ff80a3e1b9d __clone (libc.so.6)
oct 08 12:39:29 nostromo.minwi.lan systemd[1]: NetworkManager.service: main process exited, code=dumped, status=6/ABRT
oct 08 12:39:29 nostromo.minwi.lan systemd[1]: Unit NetworkManager.service entered failed state.
oct 08 12:39:29 nostromo.minwi.lan systemd[1]: NetworkManager.service failed.
...

Comment 6 Fedora Update System 2015-10-19 13:10:37 UTC
NetworkManager-1.0.6-7.fc23 has been submitted as an update to Fedora 23. https://bodhi.fedoraproject.org/updates/FEDORA-2015-85c8578fc7

Comment 7 Fedora Update System 2015-10-19 16:23:55 UTC
NetworkManager-1.0.6-7.fc23 has been pushed to the Fedora 23 testing repository. If problems still persist, please make note of it in this bug report.
If you want to test the update, you can install it with
$ su -c 'dnf --enablerepo=updates-testing update NetworkManager'
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2015-85c8578fc7

Comment 8 Fedora Update System 2015-10-20 04:22:49 UTC
NetworkManager-1.0.6-7.fc22 has been pushed to the Fedora 22 testing repository. If problems still persist, please make note of it in this bug report.
If you want to test the update, you can install it with
$ su -c 'dnf --enablerepo=updates-testing update NetworkManager'
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2015-6c051fe008

Comment 10 Jirka Klimes 2015-10-22 08:52:59 UTC
*** Bug 1273939 has been marked as a duplicate of this bug. ***

Comment 11 Hein-Pieter van Braam 2015-10-22 09:50:38 UTC
I'm still seeing a crash in the exact same configuration, but the error message seems to have changed. Should I file a new bug? This is the journal output:

Oct 22 09:54:36 lola NetworkManager[591]: (NetworkManager:591): libnm-CRITICAL **: nm_utils_hwaddr_matches: assertion 'hwaddr1 != NULL' failed
Oct 22 09:54:36 lola NetworkManager[591]: (NetworkManager:591): libnm-CRITICAL **: nm_utils_hwaddr_matches: assertion 'hwaddr1 != NULL' failed
Oct 22 09:54:36 lola NetworkManager[591]: **
Oct 22 09:54:36 lola NetworkManager[591]: NetworkManager-wifi:ERROR:nm-device-wifi.c:1653:try_fill_ssid_for_hidden_ap: assertion failed: (bssid)
Oct 22 09:54:36 lola systemd[1]: NetworkManager.service: main process exited, code=dumped, status=6/ABRT
Oct 22 09:54:36 lola systemd[1]: Unit NetworkManager.service entered failed state.
Oct 22 09:54:36 lola systemd[1]: NetworkManager.service failed.
Oct 22 09:54:36 lola systemd[1]: NetworkManager.service holdoff time over, scheduling restart.
Oct 22 09:54:36 lola systemd[1]: Starting Network Manager...

It seems that rather than a crash I'm hitting an assertion now.

Comment 12 Jirka Klimes 2015-10-23 12:04:50 UTC
(In reply to Hein-Pieter van Braam from comment #11)
> I'm still seeing a crash in the exact same configuration, but the error
> message seems to have changed. Should I file a new bug? This is the journal
> output:
> 
> Oct 22 09:54:36 lola NetworkManager[591]: (NetworkManager:591):
> libnm-CRITICAL **: nm_utils_hwaddr_matches: assertion 'hwaddr1 != NULL'
> failed
> Oct 22 09:54:36 lola NetworkManager[591]: (NetworkManager:591):
> libnm-CRITICAL **: nm_utils_hwaddr_matches: assertion 'hwaddr1 != NULL'
> failed
> Oct 22 09:54:36 lola NetworkManager[591]: **
> Oct 22 09:54:36 lola NetworkManager[591]:
> NetworkManager-wifi:ERROR:nm-device-wifi.c:1653:try_fill_ssid_for_hidden_ap:
> assertion failed: (bssid)
> Oct 22 09:54:36 lola systemd[1]: NetworkManager.service: main process
> exited, code=dumped, status=6/ABRT
> Oct 22 09:54:36 lola systemd[1]: Unit NetworkManager.service entered failed
> state.
> Oct 22 09:54:36 lola systemd[1]: NetworkManager.service failed.
> Oct 22 09:54:36 lola systemd[1]: NetworkManager.service holdoff time over,
> scheduling restart.
> Oct 22 09:54:36 lola systemd[1]: Starting Network Manager...
> 
> It seems that rather than a crash I'm hitting an assertion now.

That is something else. Fixed upstream by 
http://cgit.freedesktop.org/NetworkManager/NetworkManager/commit/?h=nm-1-0&id=e0e043ef3918de54f8d19a3af07d3367962970e5

Comment 13 Hein-Pieter van Braam 2015-10-23 12:43:23 UTC
(In reply to Jirka Klimes from comment #12)
> (In reply to Hein-Pieter van Braam from comment #11)
on now.
> 
> That is something else. Fixed upstream by 
> http://cgit.freedesktop.org/NetworkManager/NetworkManager/commit/?h=nm-1-
> 0&id=e0e043ef3918de54f8d19a3af07d3367962970e5

That seems correct. Should I file another bug with Fedora to get this backported also?

Comment 14 Fedora Update System 2015-10-28 16:23:34 UTC
NetworkManager-1.0.6-7.fc22 has been pushed to the Fedora 22 stable repository. If problems still persist, please make note of it in this bug report.

Comment 15 Fedora Update System 2015-11-01 02:33:17 UTC
NetworkManager-1.0.6-7.fc23 has been pushed to the Fedora 23 stable repository. If problems still persist, please make note of it in this bug report.

Comment 16 Benjamin Xiao 2015-11-03 20:37:49 UTC
@Hein-Pieter van Braam

I am having the same crash issue as you. NetworkManager-1.0.6-7.fc23 does not solve this.