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(a)mattdm.org <
http://mattdm.org/>
Boston University Linux ------> <
http://linux.bu.edu/>