NetworkManager and "illegal" SSID chars = crash?
Matthew Miller
mattdm at mattdm.org
Thu Sep 6 02:34:38 UTC 2007
On Wed, Sep 05, 2007 at 01:01:45PM -0400, Dan Williams wrote:
> > Anyone else recognize this behavior?
> RPM versions, kernel version, wpa_supplicant version, and any changes
> you may have made to drivers or whatever could help. Also, was it NM,
> or the applet that died?
Originally NM itself. But see below...
This is rawhide; it's been happening since Fedora 7-era or so, but it just
dawned on me what the cause of the problem is. Or likely is -- I haven't
actually proved it yet. Currently, NetworkManager 0.6.5-9.fc8, kernel
2.6.23-0.164.rc5.fc8, and wpa_supplicant-0.5.7-7. I'm using the stock
orinoco_pci driver.
In the last couple of days (weeks?) NM doesn't completely die, but instead
logs crashy sorts of things while nm-applet vanishes and can't be restarted.
There's backtraces like this in /var/log/messages, but I'm not exactly sure what's
going on when they appear. (Note: see below the log message for more text.)
Sep 3 11:37:16 ylla NetworkManager: <info> nm-netlink-monitor.c - nm_netlink_monitor_event_handler (724) netlink reports device wlan0 link now 0
Sep 3 11:37:17 ylla NetworkManager: <info> nm-netlink-monitor.c - nm_netlink_monitor_event_handler (724) netlink reports device wlan0 link now 1
Sep 3 11:41:26 ylla NetworkManager: <WARN> nm_hal_deinit(): libhal shutdown failed - Connection is closed
Sep 3 11:41:26 ylla NetworkManager: <WARN> nm_signal_handler(): Caught signal 11. Generating backtrace...
Sep 3 11:41:26 ylla NetworkManager: <info> Successfully reconnected to the system bus.
Sep 3 11:41:27 ylla NetworkManager: ******************* START **********************************
Sep 3 11:41:28 ylla NetworkManager: (no debugging symbols found)
Sep 3 11:41:29 ylla NetworkManager: Using host libthread_db library "/lib/libthread_db.so.1".
Sep 3 11:41:29 ylla NetworkManager: (no debugging symbols found)
Sep 3 11:41:29 ylla NetworkManager:last message repeated 12 times
Sep 3 11:41:29 ylla NetworkManager: [Thread debugging using libthread_db enabled]
Sep 3 11:41:29 ylla NetworkManager: [New Thread -1208538624 (LWP 1909)]
Sep 3 11:41:29 ylla NetworkManager: [New Thread -1208542320 (LWP 15022)]
Sep 3 11:41:29 ylla NetworkManager: [New Thread -1219032176 (LWP 15019)]
Sep 3 11:41:29 ylla NetworkManager: [New Thread -1229522032 (LWP 2139)]
Sep 3 11:41:29 ylla NetworkManager: (no debugging symbols found)
Sep 3 11:41:29 ylla NetworkManager:last message repeated 6 times
Sep 3 11:41:29 ylla NetworkManager: 0x0012d402 in __kernel_vsyscall ()
Sep 3 11:41:29 ylla NetworkManager: #0 0x0012d402 in __kernel_vsyscall ()
Sep 3 11:41:29 ylla NetworkManager: #1 0x0035b47b in waitpid () from /lib/libpthread.so.0
Sep 3 11:41:29 ylla NetworkManager: #2 0x0806d3b0 in ?? ()
Sep 3 11:41:29 ylla NetworkManager: #3 0x0806d4a1 in ?? ()
Sep 3 11:41:29 ylla NetworkManager: #4 <signal handler called>
Sep 3 11:41:29 ylla NetworkManager: #5 0x08056147 in nm_get_device_by_iface ()
Sep 3 11:41:29 ylla NetworkManager: #6 0x0807bb9f in nm_dhcp_manager_process_signal ()
Sep 3 11:41:29 ylla NetworkManager: #7 0x0805faed in ?? ()
Sep 3 11:41:29 ylla NetworkManager: #8 0x001bc664 in dbus_connection_dispatch () from /lib/libdbus-1.so.3
Sep 3 11:41:29 ylla NetworkManager: #9 0x00198e7d in ?? () from /usr/lib/libdbus-glib-1.so.2
Sep 3 11:41:29 ylla NetworkManager: #10 0x0025917c in g_main_context_dispatch () from /lib/libglib-2.0.so.0
Sep 3 11:41:29 ylla NetworkManager: #11 0x0025c5bf in ?? () from /lib/libglib-2.0.so.0
Sep 3 11:41:29 ylla NetworkManager: #12 0x0025c969 in g_main_loop_run () from /lib/libglib-2.0.so.0
Sep 3 11:41:29 ylla NetworkManager: #13 0x080693c8 in main ()
Sep 3 11:41:29 ylla NetworkManager:
Sep 3 11:41:29 ylla NetworkManager: Thread 4 (Thread -1229522032 (LWP 2139)):
Sep 3 11:41:29 ylla NetworkManager: #0 0x0012d402 in __kernel_vsyscall ()
Sep 3 11:41:29 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:29 ylla NetworkManager: #1 0x0035a52b in read () from /lib/libpthread.so.0
Sep 3 11:41:29 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:29 ylla NetworkManager: #2 0x0025a11d in ?? () from /lib/libglib-2.0.so.0
Sep 3 11:41:29 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:29 ylla NetworkManager: #3 0x0027c77f in ?? () from /lib/libglib-2.0.so.0
Sep 3 11:41:29 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:29 ylla NetworkManager: #4 0x0035353b in start_thread () from /lib/libpthread.so.0
Sep 3 11:41:29 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:29 ylla NetworkManager: #5 0x004380ee in clone () from /lib/libc.so.6
Sep 3 11:41:29 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:29 ylla NetworkManager:
Sep 3 11:41:29 ylla NetworkManager: Thread 3 (Thread -1219032176 (LWP 15019)):
Sep 3 11:41:29 ylla NetworkManager: #0 0x0012d402 in __kernel_vsyscall ()
Sep 3 11:41:29 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:29 ylla NetworkManager: #1 0x0042e053 in poll () from /lib/libc.so.6
Sep 3 11:41:29 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:29 ylla NetworkManager: #2 0x0025c5f3 in ?? () from /lib/libglib-2.0.so.0
Sep 3 11:41:29 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:29 ylla NetworkManager: #3 0x0025c969 in g_main_loop_run () from /lib/libglib-2.0.so.0
Sep 3 11:41:29 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:29 ylla NetworkManager: #4 0x0805696e in ?? ()
Sep 3 11:41:29 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:29 ylla NetworkManager: #5 0x0027c77f in ?? () from /lib/libglib-2.0.so.0
Sep 3 11:41:29 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:29 ylla NetworkManager: #6 0x0035353b in start_thread () from /lib/libpthread.so.0
Sep 3 11:41:29 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:29 ylla NetworkManager: #7 0x004380ee in clone () from /lib/libc.so.6
Sep 3 11:41:29 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:29 ylla NetworkManager:
Sep 3 11:41:29 ylla NetworkManager: Thread 2 (Thread -1208542320 (LWP 15022)):
Sep 3 11:41:29 ylla NetworkManager: #0 0x0012d402 in __kernel_vsyscall ()
Sep 3 11:41:29 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:29 ylla NetworkManager: #1 0x0042e053 in poll () from /lib/libc.so.6
Sep 3 11:41:29 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:29 ylla NetworkManager: #2 0x0025c5f3 in ?? () from /lib/libglib-2.0.so.0
Sep 3 11:41:29 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:29 ylla NetworkManager: #3 0x0025c969 in g_main_loop_run () from /lib/libglib-2.0.so.0
Sep 3 11:41:29 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:29 ylla NetworkManager: #4 0x0805696e in ?? ()
Sep 3 11:41:30 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:30 ylla NetworkManager: #5 0x0027c77f in ?? () from /lib/libglib-2.0.so.0
Sep 3 11:41:30 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:30 ylla NetworkManager: #6 0x0035353b in start_thread () from /lib/libpthread.so.0
Sep 3 11:41:30 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:30 ylla NetworkManager: #7 0x004380ee in clone () from /lib/libc.so.6
Sep 3 11:41:30 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:30 ylla NetworkManager:
Sep 3 11:41:30 ylla NetworkManager: Thread 1 (Thread -1208538624 (LWP 1909)):
Sep 3 11:41:30 ylla NetworkManager: #0 0x0012d402 in __kernel_vsyscall ()
Sep 3 11:41:30 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:30 ylla NetworkManager: #1 0x0035b47b in waitpid () from /lib/libpthread.so.0
Sep 3 11:41:30 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:30 ylla NetworkManager: #2 0x0806d3b0 in ?? ()
Sep 3 11:41:30 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:30 ylla NetworkManager: #3 0x0806d4a1 in ?? ()
Sep 3 11:41:30 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:30 ylla NetworkManager: #4 <signal handler called>
Sep 3 11:41:30 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:30 ylla NetworkManager: #5 0x08056147 in nm_get_device_by_iface ()
Sep 3 11:41:30 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:30 ylla NetworkManager: #6 0x0807bb9f in nm_dhcp_manager_process_signal ()
Sep 3 11:41:30 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:30 ylla NetworkManager: #7 0x0805faed in ?? ()
Sep 3 11:41:30 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:30 ylla NetworkManager: #8 0x001bc664 in dbus_connection_dispatch () from /lib/libdbus-1.so.3
Sep 3 11:41:30 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:30 ylla NetworkManager: #9 0x00198e7d in ?? () from /usr/lib/libdbus-glib-1.so.2
Sep 3 11:41:30 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:30 ylla NetworkManager: #10 0x0025917c in g_main_context_dispatch () from /lib/libglib-2.0.so.0
Sep 3 11:41:30 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:30 ylla NetworkManager: #11 0x0025c5bf in ?? () from /lib/libglib-2.0.so.0
Sep 3 11:41:30 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:30 ylla NetworkManager: #12 0x0025c969 in g_main_loop_run () from /lib/libglib-2.0.so.0
Sep 3 11:41:30 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:30 ylla NetworkManager: #13 0x080693c8 in main ()
Sep 3 11:41:30 ylla NetworkManager: No symbol table info available.
Sep 3 11:41:30 ylla NetworkManager: #0 0x0012d402 in __kernel_vsyscall ()
Sep 3 11:41:30 ylla NetworkManager: The program is running. Quit anyway (and detach it)? (y or n) [answered Y; input not from terminal]
Sep 3 11:41:30 ylla NetworkManager: ******************* END **********************************
Just now, when I rebooted to try to generate a nice clean log of the problem
under a semi-controlled environment, everything came up apparently fine and
working. (First time ever at my house.) Then I realized that for whatever
reason, iwlist scan wasn't showing the URL SSID. So I moved around the house
until it showed up -- and boom, there goes nm-applet.
When I try to restart nm-applet, I get this error (familiar to me from the
times nm-applet isn't even there at boot time):
process 2230: arguments to dbus_message_new_method_call() were incorrect, assertion "_dbus_check_is_valid_path (path)" failed in file dbus-message.c line 1074.
This is normally a bug in some application using the D-Bus library.
D-Bus not built with -rdynamic so unable to print a backtrace
Aborted
So I then try to restart NetworkManager (sudo service NetworkManager
restart), and then I get this in the logs. (Again, more text below the log.)
Sep 5 21:50:17 ylla NetworkManager: <info> starting...
Sep 5 21:50:18 ylla NetworkManager: <info> New VPN service 'vpnc' (org.freedesktop.NetworkManager.vpnc).
Sep 5 21:50:18 ylla NetworkManager: <info> New VPN service 'openvpn' (org.freedesktop.NetworkManager.openvpn).
Sep 5 21:50:18 ylla NetworkManager: <info> wlan0: Device is fully-supported using driver 'orinoco_pci'.
Sep 5 21:50:18 ylla NetworkManager: <info> nm_device_init(): waiting for device's worker thread to start
Sep 5 21:50:18 ylla NetworkManager: <info> nm_device_init(): device's worker thread started, continuing.
Sep 5 21:50:18 ylla NetworkManager: <info> Now managing wireless (802.11) device 'wlan0'.
Sep 5 21:50:18 ylla NetworkManager: <info> Deactivating device wlan0.
Sep 5 21:50:18 ylla NetworkManager: <info> eth0: Device is fully-supported using driver 'e100'.
Sep 5 21:50:18 ylla NetworkManager: <info> nm_device_init(): waiting for device's worker thread to start
Sep 5 21:50:18 ylla NetworkManager: <info> nm_device_init(): device's worker thread started, continuing.
Sep 5 21:50:18 ylla NetworkManager: <info> Now managing wired Ethernet (802.3) device 'eth0'.
Sep 5 21:50:18 ylla NetworkManager: <info> Deactivating device eth0.
Sep 5 21:50:18 ylla NetworkManager: <info> Found dial up configuration for Verizon via Modem: Verizon
Sep 5 21:50:18 ylla NetworkManager: <info> nm-netlink-monitor.c - nm_netlink_monitor_event_handler (724) netlink reports device eth0 link now 0
Sep 5 21:50:18 ylla NetworkManager: <info> nm-device-802-3-ethernet.c - nm_device_802_3_ethernet_link_deactivated (149) device eth0 scheduled link_deactivated_helper
Sep 5 21:50:18 ylla NetworkManager: <info> nm-netlink-monitor.c - nm_netlink_monitor_event_handler (724) netlink reports device wlan0 link now 0
Sep 5 21:50:18 ylla NetworkManager: <info> nm-netlink-monitor.c - nm_netlink_monitor_event_handler (724) netlink reports device wlan0 link now 0
Sep 5 21:50:18 ylla NetworkManager: <info> nm-netlink-monitor.c - nm_netlink_monitor_event_handler (724) netlink reports device eth0 link now 1
Sep 5 21:50:18 ylla NetworkManager: <info> nm-device-802-3-ethernet.c - link_deactivated_helper (129) device eth0 will set active link to FALSE
Sep 5 21:50:18 ylla NetworkManager: <info> nm-device-802-3-ethernet.c - link_activated_helper (102) device eth0 will set active link to TRUE
Sep 5 21:50:18 ylla NetworkManager: <info> nm-device.c - nm_device_set_active_link (596) device eth0 link state set to 1
Sep 5 21:50:18 ylla NetworkManager: <info> Will activate wired connection 'eth0' because it now has a link.
Sep 5 21:50:18 ylla NetworkManager: <info> nm-device-802-3-ethernet.c - nm_device_802_3_ethernet_link_activated (122) device eth0 scheduled link_activated_helper
Sep 5 21:50:18 ylla NetworkManager: <info> nm-netlink-monitor.c - nm_netlink_monitor_event_handler (724) netlink reports device eth0 link now 0
Sep 5 21:50:18 ylla NetworkManager: <info> nm-device-802-3-ethernet.c - nm_device_802_3_ethernet_link_deactivated (149) device eth0 scheduled link_deactivated_helper
Sep 5 21:50:18 ylla NetworkManager: <info> nm-device-802-3-ethernet.c - link_deactivated_helper (129) device eth0 will set active link to FALSE
Sep 5 21:50:18 ylla NetworkManager: <info> nm-device.c - nm_device_set_active_link (596) device eth0 link state set to 0
Sep 5 21:50:18 ylla NetworkManager: <info> nm-netlink-monitor.c - nm_netlink_monitor_event_handler (724) netlink reports device wlan0 link now 1
Sep 5 21:50:32 ylla NetworkManager: <WARN> request_and_convert_scan_results(): card took too much time scanning. Get a better one.
Sep 5 21:50:55 ylla NetworkManager: <info> Updating allowed wireless network lists.
Sep 5 21:50:55 ylla NetworkManager: <WARN> nm_dbus_get_networks_cb(): error received: org.freedesktop.NetworkManagerInfo.NoNetworks - There are no wireless networks stored..
Sep 5 21:50:55 ylla NetworkManager: <info> Updating VPN Connections...
Sep 5 21:51:02 ylla NetworkManager: <WARN> nm_hal_deinit(): libhal shutdown failed - Connection is closed
Sep 5 21:51:02 ylla NetworkManager: nm_get_device_by_iface: assertion `data != NULL' failed
Sep 5 21:51:02 ylla NetworkManager: <info> Successfully reconnected to the system bus.
Sep 5 21:51:52 ylla NetworkManager: <info> nm-netlink-monitor.c - nm_netlink_monitor_event_handler (724) netlink reports device wlan0 link now 0
Sep 5 21:51:54 ylla NetworkManager: <info> nm-netlink-monitor.c - nm_netlink_monitor_event_handler (724) netlink reports device wlan0 link now 1
Sep 5 21:52:32 ylla NetworkManager: <WARN> nm_hal_deinit(): libhal shutdown failed - Connection is closed
Sep 5 21:52:32 ylla NetworkManager: <info> Successfully reconnected to the system bus.
Sep 5 21:54:42 ylla NetworkManager: <WARN> nm_hal_deinit(): libhal shutdown failed - Connection is closed
Sep 5 21:54:42 ylla NetworkManager: <info> Successfully reconnected to the system bus.
Sep 5 21:55:10 ylla NetworkManager: <info> nm-netlink-monitor.c - nm_netlink_monitor_event_handler (724) netlink reports device wlan0 link now 0
Sep 5 21:55:10 ylla NetworkManager: <info> nm-netlink-monitor.c - nm_netlink_monitor_event_handler (724) netlink reports device wlan0 link now 0
Sep 5 21:55:12 ylla NetworkManager: <info> nm-netlink-monitor.c - nm_netlink_monitor_event_handler (724) netlink reports device wlan0 link now 1
So then I say "screw it", and type "/sbin/ifup wlan0", which just works,
enabling me to scp those logs to you over the network with the URL ssid.
Oh -- hmmm, there's this NetworkManagerDispatcher thing -- sorry, I hadn't
thought to restart that. Well, if I restart NetworkManagerDispatcher *and*
NetworkManager, I can run nm-applet, and it'll be several seconds before
it crashes with the above assertion failure again.
--
Matthew Miller mattdm at mattdm.org <http://mattdm.org/>
Boston University Linux ------> <http://linux.bu.edu/>
More information about the fedora-devel-list
mailing list