Created attachment 2877 [details]
resume failure log from serial

The key point here is:

rmmod: gspi8xxx: Resource temporarily unavailable
rmmod: gspi: Resource temporarily unavailable

The wlan module was never removed before the system suspended. Using the serial port can you try this and see if you get the same error:
    /etc/init.d/wlan stop

If so then does running 'rmmod gspi8xxxx gspi' from the command line work? What about trying to add a 5 second delay before the rmmod in that script.

Seems to work OK:

--
# /etc/init.d/wlan stop
Stopping wlan
killall: cannot kill pid 814: No such process
# eth0      no private ioctls.

eth0      no private ioctls.

ifconfig
lo        Link encap:Local Loopback
          inet addr:127.0.0.1  Mask:255.0.0.0
          UP LOOPBACK RUNNING  MTU:16436  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)

# eth0      no private ioctls.

lsmod
Module                  Size  Used by    Tainted: P

eth0      no private ioctls.

# /etc/init.d/wlan start
Starting wlan
mapped channel 3 to 1
DMA TX on 1, RX on 1
Data transfer modes: RX=DMA, TX=DMA
FIQ: setting TX/RX mode
Setting ethaddr: 00:04:20:1A:00:52
Setting region: 16
ioctl[SIOCSIWPMKSA]: Invalid argument
Selected interface 'eth0'
--

The "eth0 no private ioctls" message appears about every 5 seconds until I restart wlan.

Andy, more things to try:

lsmod at the start of the wlan stop script.
lsmod at before the rmmod in the wlan stop script.
ifconfig at before the rmmod in the wlan stop script.

Ben Dooks asks if we can strace the rmmod process.

Fix in r1963. Leaving this bug open as Dean and Steinar Bjaerum have reports where dhcp is not started on resume.

Additional fix in r1968. Jive will disconnect from SC/SN before entering suspend mode. This is better practice then letting the tcp connections timeout, and also fixes a problem noticed by Steinar where the show briefly popups don't always work on resume.

The remaining issue I think has been reported by Dean and Steinar, that dhcp does not always start on resume. I have tested again this morning, and I can't recreate this. Checkin r1969 contains some additional debugging in the network scripts.

To progress this someone who can recreate the problem needs to capture the syslog on an SD card and have access to the serial port. After resume, when the spinny is still visible please check the following:
- ps (is the udhcpcd process running?)
- cat /var/run/udhcpc.eth0.pid (does this file exist, what's the pid?)
- cat /etc/network/interfaces (i need the contents of this file)
- contents of /var/log/messages

In case someone feels like doing some additional debugging to help, this is the order things should happen:
- wpa_supplicant connects to wlan and notifies listening processes
- wpa_cli calls /etc/init.d/wpa_action (now log in syslog)
- wpa_action calls ifup to bring the interface up
- ifup check /etc/network/interfaces. it should see to configure the interface using dhcp
- ifup starts udhcpcd
- udhcpcd negotiates the lease and calls /etc/init.d/udhcpc_action to configure the interface

One possible race here is that wpa_supplicant connects to the network before wpa_cli runs. Hmm, your all on WEP right? That will reconnect quicker than WPA - let me test that case and see if I can recreate.

Additional debug in r1970. I can't recreate this on WPA or WEP, with a 10 minute DHCP timeout.

Steinar and Ben can't recreate this now either. Please reopen if you see this problem again.

This bug has recently been fixed in the latest release of SqueezeCenter 7.0.1

Please try that version, if you still see the error, then reopen this bug.

To download this version, please navigate to: http://www.slimdevices.com/su_downloads.html