Ubuntu
network-manager package

NetworkManager breaks suspend, stops working

Bug #151405 reported by Marius Gedminas on 2007-10-10

Affects		Status	Importance	Assigned to	Milestone
	network-manager (Ubuntu)	Fix Released	Medium	Unassigned

Bug Description

Binary package hint: network-manager

I run the latest Gutsy on a T61 laptop with ipw3945 wireless.

Suspend usually works, but every now and then the system gets stuck in the dark-screen-blinking-moon-LED state and aborts the suspend leaving me the screensaver's unlock dialog. dmesg shows at this point:

[27494.464000] PM: Preparing system for mem sleep
[27494.464000] Stopping tasks ...
[27514.468000] Stopping user space processes timed out after 20 seconds (1 tasks refusing to freeze):
[27514.468000] NetworkManager
[27514.468000] Restarting tasks ... done.

I can unlock the screensaver and ask the system to suspend again, which works fine. After a resume network manager is oblivious: doesn't perform network scanning, shows an outdated list of wireless networks, ignores my attempts to disable/reenable it. Restarting NM with

sudo /etc/dbus-1/event.d/25NetworkManager restart
sudo /etc/dbus-1/event.d/26NetworkManagerDispatcher restart

helps. But this is a minor irritation; the major thing is that NetworkManager sporadically prevents the first attempt to suspend.

I'm used to press Fn-F5, close the lid, wait a couple of seconds to give the system the chance to sleep, then stash my laptop in my backpack. Three or four times already I discovered my laptop running hot in the backpack unsuspended, but only just now I discovered the reason.

Revision history for this message

Alexander Sack (asac) wrote on 2007-10-10:

please reproduce this bug and attach the /var/log/syslog right after you reproduced it.

Changed in network-manager:
importance:	Undecided → Medium
status:	New → Incomplete

Revision history for this message

Alexander Sack (asac) wrote on 2007-10-11:

please test the network-manager packages available in my ppa ( http://ppa.launchpad.net/asac/ubuntu/pool/main/n/network-manager/) ... the version to test is 0.6.5-0ubuntu16~ppa1

Thanks,
- Alexander

Revision history for this message

Marius Gedminas (mgedmin) wrote on 2007-10-11:

syslog showing the network manager crash Edit (26.4 KiB, application/octet-stream)

Attaching yesterday's syslog (biggish, 188KB uncompressed) starting from boot. It has several successful suspends plus the network manager error. One thing I didn't notice before: network manager segfaulted on Oct 10 21:38:36, during the previous resume, which was 50 minutes before my failed suspend attempt:

Oct 10 21:38:36 platonas NetworkManager: <WARN> nm_signal_handler(): Caught signal 11. Generating backtrace...

I also see a /var/crash/_usr_sbin_NetworkManager.0.crash file, but it has date Oct 4 10:12:32, so it's from an older crash. Interested?

I don't know how to reliably trigger the crash. It seems to happen about once a week. I'll try the 0.6.5-0ubuntu16~ppa1 and see if the crash happens again. Any chance for a network-manager-dbgsym package for this version?

Revision history for this message

Alexander Sack (asac) wrote on 2007-10-19:

please test the latest test package mentioned in summary of bug 145683

Thanks,
- Alexander

Revision history for this message

Marius Gedminas (mgedmin) wrote on 2007-10-19:

Download full text (4.4 KiB)

You mean 0.6.5-0ubuntu16~ppa3? I had that installed between 2007-10-12 and 2007-10-16 according to dpkg.log, then apt-get decided that 0.6.5-0ubuntu16 was newer and upgraded to that one without telling me.

I've seen no suspend timeouts since 2007-10-10. I had network-manager eat 100% CPU for a few minutes after a resume once or twice, until I got bored, killed (with sigterm, not sigkill) and restarted it. I think that was the non-ppa ubuntu16 version.

*checks syslog*

Oh, hey, it was today:

syslog.0:Oct 19 13:28:05 platonas NetworkManager: <info> eth1: Device is fully-supported using driver 'ipw3945'.
syslog.0:Oct 19 13:28:05 platonas NetworkManager: <info> nm_device_init(): waiting for device's worker thread to start
syslog.0:Oct 19 13:28:05 platonas NetworkManager: <info> nm_device_init(): device's worker thread started, continuing.
syslog.0:Oct 19 13:28:05 platonas NetworkManager: <info> Now managing wireless (802.11) device 'eth1'.
syslog.0:Oct 19 13:28:05 platonas NetworkManager: <info> Deactivating device eth1.
syslog.0:Oct 19 13:28:07 platonas NetworkManager: <debug> [1192789687.532850] nm_hal_device_removed(): Device removed (hal udi is '/org/freedesktop/Hal/devices/computer_logicaldev_input_3')
syslog.0:Oct 19 13:28:15 platonas NetworkManager: <WARN> nm_signal_handler(): Caught signal 11. Generating backtrace...
syslog.0:Oct 19 13:28:15 platonas NetworkManager: ******************* START **********************************
syslog.0:Oct 19 13:28:16 platonas NetworkManager: (no debugging symbols found)
syslog.0:Oct 19 13:28:16 platonas NetworkManager: Using host libthread_db library "/lib/tls/i686/cmov/libthread_db.so.1".
syslog.0:Oct 19 13:28:16 platonas NetworkManager: (no debugging symbols found)
syslog.0:Oct 19 13:28:16 platonas NetworkManager: [Thread debugging using libthread_db enabled]
syslog.0:Oct 19 13:28:16 platonas NetworkManager: [New Thread -1212565840 (LWP 6315)]
syslog.0:Oct 19 13:28:16 platonas NetworkManager: [New Thread -1220961392 (LWP 18914)]
syslog.0:Oct 19 13:28:16 platonas NetworkManager: [New Thread -1212568688 (LWP 18911)]
syslog.0:Oct 19 13:28:16 platonas NetworkManager: [New Thread -1231029360 (LWP 7976)]
syslog.0:Oct 19 13:28:16 platonas NetworkManager: (no debugging symbols found)
syslog.0:Oct 19 13:28:16 platonas NetworkManager: 0xffffe410 in __kernel_vsyscall ()
syslog.0:Oct 19 13:28:16 platonas NetworkManager: ******************* END **********************************
syslog.0:Oct 19 13:29:46 platonas NetworkManager: <info> starting...
syslog.0:Oct 19 13:29:46 platonas NetworkManager: <info> eth1: Device is fully-supported using driver 'ipw3945'.

and yesterday too:

You mean 0.6.5-0ubuntu16~ppa3?  I had that installed between 2007-10-12 and 2007-10-16 according to dpkg.log, then apt-get decided that 0.6.5-0ubuntu16 was newer and upgraded to that one without telling me.

I've seen no suspend timeouts since 2007-10-10.  I had network-manager eat 100% CPU for a few minutes after a resume once or twice, until I got bored, killed (with sigterm, not sigkill) and restarted it.  I think that was the non-ppa ubuntu16 version.

*checks syslog*

Oh, hey, it was today:

syslog.0:Oct 19 13:28:05 platonas NetworkManager: <info>  eth1: Device is fully-supported using driver 'ipw3945'. 
syslog.0:Oct 19 13:28:05 platonas NetworkManager: <info>  nm_device_init(): waiting for device's worker thread to start 
syslog.0:Oct 19 13:28:05 platonas NetworkManager: <info>  nm_device_init(): device's worker thread started, continuing. 
syslog.0:Oct 19 13:28:05 platonas NetworkManager: <info>  Now managing wireless (802.11) device 'eth1'. 
syslog.0:Oct 19 13:28:05 platonas NetworkManager: <info>  Deactivating device eth1. 
syslog.0:Oct 19 13:28:07 platonas NetworkManager: <debug> [1192789687.532850] nm_hal_device_removed(): Device removed (hal udi is '/org/freedesktop/Hal/devices/computer_logicaldev_input_3')
syslog.0:Oct 19 13:28:15 platonas NetworkManager: <WARN>  nm_signal_handler(): Caught signal 11.  Generating backtrace... 
syslog.0:Oct 19 13:28:15 platonas NetworkManager: ******************* START **********************************
syslog.0:Oct 19 13:28:16 platonas NetworkManager: (no debugging symbols found)
syslog.0:Oct 19 13:28:16 platonas NetworkManager: Using host libthread_db library "/lib/tls/i686/cmov/libthread_db.so.1".
syslog.0:Oct 19 13:28:16 platonas NetworkManager: (no debugging symbols found)
syslog.0:Oct 19 13:28:16 platonas NetworkManager: [Thread debugging using libthread_db enabled]
syslog.0:Oct 19 13:28:16 platonas NetworkManager: [New Thread -1212565840 (LWP 6315)]
syslog.0:Oct 19 13:28:16 platonas NetworkManager: [New Thread -1220961392 (LWP 18914)]
syslog.0:Oct 19 13:28:16 platonas NetworkManager: [New Thread -1212568688 (LWP 18911)]
syslog.0:Oct 19 13:28:16 platonas NetworkManager: [New Thread -1231029360 (LWP 7976)]
syslog.0:Oct 19 13:28:16 platonas NetworkManager: (no debugging symbols found)
syslog.0:Oct 19 13:28:16 platonas NetworkManager: 0xffffe410 in __kernel_vsyscall ()
syslog.0:Oct 19 13:28:16 platonas NetworkManager: ******************* END **********************************
syslog.0:Oct 19 13:29:46 platonas NetworkManager: <info>  starting... 
syslog.0:Oct 19 13:29:46 platonas NetworkManager: <info>  eth1: Device is fully-supported using driver 'ipw3945'.

and yesterday too:

Oct 18 00:35:29 platonas NetworkManager: <info>  SUP: response was 'TIMEOUT[CLI]' 
Oct 18 00:35:29 platonas NetworkManager: <WARN>  nm_utils_supplicant_request_with_check(): supplicant_cleanup: supplicant error for 'TERMINATE'.  Response: 'TIMEOUT[CLI]' 
Oct 18 00:35:29 platonas NetworkManager: <WARN>  supplicant_cleanup(): supplicant_cleanup - couldn't terminate wpasupplicant cleanly. 
Oct 18 00:35:29 platonas NetworkManager: <WARN>  nm_signal_handler(): Caught signal 11.  Generating backtrace... 
Oct 18 00:35:29 platonas NetworkManager: ******************* START **********************************
Oct 18 00:35:30 platonas NetworkManager: (no debugging symbols found)
Oct 18 00:35:30 platonas NetworkManager: Using host libthread_db library "/lib/tls/i686/cmov/libthread_db.so.1".
Oct 18 00:35:30 platonas NetworkManager: (no debugging symbols found)
Oct 18 00:35:30 platonas last message repeated 13 times
Oct 18 00:35:30 platonas NetworkManager: [Thread debugging using libthread_db enabled]
Oct 18 00:35:30 platonas NetworkManager: [New Thread -1212344656 (LWP 6192)]
Oct 18 00:35:30 platonas NetworkManager: [New Thread -1229132912 (LWP 7781)]
Oct 18 00:35:30 platonas NetworkManager: (no debugging symbols found)
Oct 18 00:35:30 platonas last message repeated 9 times
Oct 18 00:35:30 platonas NetworkManager: 0xffffe410 in __kernel_vsyscall ()
Oct 18 00:35:30 platonas NetworkManager: ******************* END **********************************
Oct 18 00:36:21 platonas kernel: [20601.780000] input: Virtual ThinkFinger Keyboard as /class/input/input13
Oct 18 00:37:24 platonas NetworkManager: <info>  starting...

Two crashes in four days with 0.6.5-0ubuntu16, no crashes in four days with 0.6.5-0ubuntu16~ppa3.  I'll tell apt to "downgrade" to the ppa3 version and see what happens in a week.

Revision history for this message

Fredrik Wendt (fredrik-wendt) wrote on 2007-10-20:

My laptop is a Thinkpad Z61t which also uses ipw3945. Until Gutsy NetworkManager worked flawlessy, I really had no issues at all.
With Gutsy running now, I can't get it to connect to WPA networks after suspend (I only use suspend to ram) and resume - it only connects to unencrypted open APs. From what I've seen it looks like the dhcp-client never starts/runs when the computer and AP is associated.
Might this be related or should I file a separate bug?

Revision history for this message

Alexander Sack (asac) wrote on 2007-11-05:

network-manager (0.6.5-0ubuntu17) hardy; urgency=low

* upload 0.6.5-0ubuntu17 to hardy

network-manager (0.6.5-0ubuntu16.7.10.0) gutsy-proposed; urgency=low

  Release changes from test package previously known as 0.6.5-0ubuntu16~ppa3:
  * drop gracefull supplicant shutdown feature and its followup patches,
    because they cause crashes and a real fix would need more intrusive code
    rewrites: (LP: #145683, LP: #83623, LP: #152098, LP: #151405)
    - debian/patches/41n_graceful_supplicant_shutdown.patch,
      debian/patches/41q_retry_supplicant_cleanup_startup_if_ctrl_interface_connect_failes.patch,
      debian/patches/41v_lp141233-fix-supplicant-cleanup-crashes.patch,
      debian/patches/41w_lp145683_cancel_scan_in_supplicant_cleanup.patch: drop
        patches that belong to the "graveful supplicant feature".
    - debian/patches/41u_custom_timeout_for_some_wpa_ctrl_operations.patch: update
      interleaving patch
    - debian/patches/series: update quilt series accordingly.
  * debian/patches/24pp_svn2604_Add-HAL-based-rfkill-support.patch: use
    gint32 instead of guint32 for getting the killswitch power argument
    (LP: #138794).

-- Alexander Sack <email address hidden> Mon, 05 Nov 2007 19:14:43 +0100

Changed in network-manager:
status:	Incomplete → Fix Released

Revision history for this message

Romano Giannetti (romano-giannetti) wrote on 2007-11-26:

Alexander,

I tried the gutsy-proposed pacage. It seems to me that the bugs happens less frequently, but still happens. The only nice things is that it seems that now, if you kill the rogue NetworkManager, then the system did suspend and resume ok.

I've seen a lot of related bugs (at least #85113, #145683, #139387). I do not know exactly where to report this...

Revision history for this message

Marius Gedminas (mgedmin) wrote on 2007-12-07:

I can confirm that this sometimes happens with n-m 0.6.5-0ubuntu16.7.10.0.

syslog:

Dec 2 04:05:07 platonas gnome-power-manager: (mg) Užmigdomas kompiuterį nes paspaustas užmigdymo mygtukas
Dec 2 04:05:09 platonas dhcdbd: Unrequested down ?:3
Dec 2 04:05:09 platonas NetworkManager: <info> DHCP daemon state is now 14 (normal exit) for interface eth1
Dec 2 04:05:09 platonas avahi-daemon[7769]: Interface eth1.IPv4 no longer relevant for mDNS.
Dec 2 04:05:09 platonas avahi-daemon[7769]: Leaving mDNS multicast group on interface eth1.IPv4 with address 192.168.0.32.
Dec 2 04:05:09 platonas avahi-daemon[7769]: Withdrawing address record for fe80::21b:77ff:fe41:4781 on eth1.
Dec 2 04:05:09 platonas avahi-daemon[7769]: Withdrawing address record for 192.168.0.32 on eth1.
Dec 2 04:05:09 platonas postfix/master[7569]: reload configuration /etc/postfix
Dec 2 04:05:10 platonas NetworkManager: <debug> [1196561110.040443] nm_hal_device_removed(): Device removed (hal udi is '/org/freedesktop/Hal/devices/net_
Dec 2 04:05:10 platonas NetworkManager: <info> Deactivating device eth0.
Dec 2 04:05:10 platonas kernel: [49581.048000] ACPI: PCI interrupt for device 0000:00:19.0 disabled
Dec 2 04:05:10 platonas kernel: [49581.224000] ACPI: PCI interrupt for device 0000:03:00.0 disabled
Dec 2 04:05:10 platonas kernel: [49581.228000] ieee80211_crypt: unregistered algorithm 'NULL'
Dec 2 04:05:10 platonas NetworkManager: <debug> [1196561110.294213] nm_hal_device_removed(): Device removed (hal udi is '/org/freedesktop/Hal/devices/net_
Dec 2 04:05:10 platonas NetworkManager: <info> Deactivating device eth1.
Dec 2 04:05:10 platonas NetworkManager: <WARN> nm_device_802_11_wireless_get_mode(): error getting card mode on eth1: No such device
Dec 2 04:05:33 platonas kernel: [49584.020000] PM: Preparing system for mem sleep
Dec 2 04:05:33 platonas kernel: [49584.020000] Stopping tasks ...
Dec 2 04:05:33 platonas kernel: [49604.024000] Stopping user space processes timed out after 20 seconds (1 tasks refusing to freeze):
Dec 2 04:05:33 platonas kernel: [49604.024000] NetworkManager
Dec 2 04:05:33 platonas kernel: [49604.024000] Restarting tasks ... done.

I can confirm that this sometimes happens with n-m 0.6.5-0ubuntu16.7.10.0.

syslog:

Dec  2 04:05:07 platonas gnome-power-manager: (mg) Užmigdomas kompiuterį nes paspaustas užmigdymo mygtukas
Dec  2 04:05:09 platonas dhcdbd: Unrequested down ?:3
Dec  2 04:05:09 platonas NetworkManager: <info>  DHCP daemon state is now 14 (normal exit) for interface eth1 
Dec  2 04:05:09 platonas avahi-daemon[7769]: Interface eth1.IPv4 no longer relevant for mDNS.
Dec  2 04:05:09 platonas avahi-daemon[7769]: Leaving mDNS multicast group on interface eth1.IPv4 with address 192.168.0.32.
Dec  2 04:05:09 platonas avahi-daemon[7769]: Withdrawing address record for fe80::21b:77ff:fe41:4781 on eth1.
Dec  2 04:05:09 platonas avahi-daemon[7769]: Withdrawing address record for 192.168.0.32 on eth1.
Dec  2 04:05:09 platonas postfix/master[7569]: reload configuration /etc/postfix
Dec  2 04:05:10 platonas NetworkManager: <debug> [1196561110.040443] nm_hal_device_removed(): Device removed (hal udi is '/org/freedesktop/Hal/devices/net_
Dec  2 04:05:10 platonas NetworkManager: <info>  Deactivating device eth0. 
Dec  2 04:05:10 platonas kernel: [49581.048000] ACPI: PCI interrupt for device 0000:00:19.0 disabled
Dec  2 04:05:10 platonas kernel: [49581.224000] ACPI: PCI interrupt for device 0000:03:00.0 disabled
Dec  2 04:05:10 platonas kernel: [49581.228000] ieee80211_crypt: unregistered algorithm 'NULL'
Dec  2 04:05:10 platonas NetworkManager: <debug> [1196561110.294213] nm_hal_device_removed(): Device removed (hal udi is '/org/freedesktop/Hal/devices/net_
Dec  2 04:05:10 platonas NetworkManager: <info>  Deactivating device eth1. 
Dec  2 04:05:10 platonas NetworkManager: <WARN>  nm_device_802_11_wireless_get_mode(): error getting card mode on eth1: No such device 
Dec  2 04:05:33 platonas kernel: [49584.020000] PM: Preparing system for mem sleep
Dec  2 04:05:33 platonas kernel: [49584.020000] Stopping tasks ... 
Dec  2 04:05:33 platonas kernel: [49604.024000] Stopping user space processes timed out after 20 seconds (1 tasks refusing to freeze):
Dec  2 04:05:33 platonas kernel: [49604.024000]  NetworkManager
Dec  2 04:05:33 platonas kernel: [49604.024000] Restarting tasks ... done.

Revision history for this message

Mike Baranczak (mbaranczak-gmail) wrote on 2007-12-16:

#10

This sounds similar to the problems I've been having with NetworkManager. I'm running 7.10 on a Thinkpad T43. I found this workaround, which stops NetworkManager on suspend and restarts it on resume:

https://help.ubuntu.com/community/WifiDocs/NetworkManager#head-5c71df23d1410c1c5c1c0bcd216353a41e6f935c

Hope this helps.

Revision history for this message

Michael Gratton (mjog) wrote on 2008-01-11:

#11

This still happens occasionally on my Thinkpad X61s with a iwl4965 - maybe 1 in 20 suspends. Most of my wireless usage is on networks with WPA-2 encryption (enterprise and personal).

I've just added the acpi scripts as suggested in the comment above, which I assume will work around the problem, but I think it should be noted that the problem still exists.

Given the common Thinkpad/iwlxxxx theme, maybe it is related to Intel's drivers more than NM?

Revision history for this message

Romano Giannetti (romano-giannetti) wrote on 2008-01-11:

#12

No, I do not think it's related to the driver. It happens to me with ndiswrapper/atheros too, although I have to say that it's much more rare now after the upgrade of NM.