Description of problem: I have Fedora 16 (Vortexbox 2.0) installed and use an external USB disk attached permanently. The drive (/dev/sdb) is mounted on /storagen(by using UUID in fstab). I noticed that after suspend the drive no longer mounted on /dev/sdb but on /dev/sdc. However the mount /dev/sdb on /storage stills exists but is not accessable. I now have to reboot the server to get access to my data on /storage. Version-Release number of selected component (if applicable): Fedora 16 How reproducible: It is hard to reproduce. I think it happens once in 3-4 days. In that time the server suspends about 20 times. attach usb device (/dev/sdb) mount usb device using UUID to /storage Steps to Reproduce: 1. echo 0 > /sys/class/rtc/rtc0/wakealarm 2. echo `date '+%s' -d '+ 5 minutes'` > /sys/class/rtc/rtc0/wakealarm 3. /usr/sbin/pm-suspend Actual results: device sdb no longer available (/dev/sdb does not exist) /dev/sdb still mounted on /storage Expected results: if device sdb no longer exists (replaced by /dev/sdc) then the mount /dev/sdb should be deleted and a remount of the UUID should take place. That leads to /dev/sdc being mounted on /storage Additional info: Here are some listings: #/etc/fstab UUID=27a71999-3d79-4a94-8c69-5ab22423db74 /storage ext4 noatime,barrier=0,rw 0 0 #output from mount /dev/sdb on /storage type ext4 (rw,noatime,user_xattr,acl,barrier=0,data=ordered) #udev/rules.d/80-usbmount.rules ACTION=="add", BUS=="usb", KERNEL=="sd*", RUN+="/opt/vortexbox/usbaction add %k %n" ACTION=="remove", BUS=="usb", KERNEL=="sd*", RUN+="/opt/vortexbox/usbaction remove %k %n" # output of /opt/vortexbox/usbaction 11/22/2011 00:30:13 - USB disk /dev/sdb removed 11/22/2011 00:30:32 - USB disk added [Disk /dev/sdc: 2000.4 GB, 2000398934016 bytes] 11/22/2011 01:56:30 - USB disk /dev/sdc removed 11/22/2011 01:56:31 - USB disk added [Disk /dev/sdc: 2000.4 GB, 2000398934016 bytes]
This morning the problems occurred again. Looks like the hibernate is causing the problem. The server is hibernated every night at 0:30. This morning it was hibernated at 0:50. Looks like the storage.mount exited with an error. If this process wants to umount /storage then it will fail because squeezeboxserver is still running. Listings: # ls -d /dev/sd* /dev/sda /dev/sda1 /dev/sda2 /dev/sda3 /dev/sdc # mount | grep storage /dev/sdb on /storage type ext4 (rw,noatime,user_xattr,acl,barrier=0,data=ordered) # tail /var/log/usbbackup.log 11/24/2011 00:50:20 - USB disk /dev/sdb removed 11/24/2011 00:50:39 - USB disk added [Disk /dev/sdc: 2000.4 GB, 2000398934016 bytes] # grep "Nov 24 00:50" /var/log/messages Nov 24 00:50:19 vortexbox kernel: [92329.036380] scsi: killing requests for dead queue Nov 24 00:50:20 vortexbox kernel: [92329.139121] usb 3-2: new full speed USB device number 2 using uhci_hcd Nov 24 00:50:20 vortexbox kernel: [92329.267053] usb 3-2: not running at top speed; connect to a high speed hub Nov 24 00:50:20 vortexbox kernel: [92329.295055] usb 3-2: New USB device found, idVendor=1058, idProduct=1003 Nov 24 00:50:20 vortexbox kernel: [92329.295059] usb 3-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Nov 24 00:50:20 vortexbox kernel: [92329.295062] usb 3-2: Product: External HDD Nov 24 00:50:20 vortexbox kernel: [92329.295064] usb 3-2: Manufacturer: Western Digital Nov 24 00:50:20 vortexbox kernel: [92329.295067] usb 3-2: SerialNumber: 57442D574341565932343033323336 Nov 24 00:50:20 vortexbox dbus[806]: [system] Activating service name='org.freedesktop.PackageKit' (using servicehelper) Nov 24 00:50:20 vortexbox dbus-daemon[806]: dbus[806]: [system] Activating service name='org.freedesktop.PackageKit' (using s ervicehelper) Nov 24 00:50:20 vortexbox kernel: [92329.298187] scsi7 : usb-storage 3-2:1.0 Nov 24 00:50:20 vortexbox systemd[1]: storage.mount mount process exited, code=exited status=1 Nov 24 00:50:20 vortexbox dbus[806]: [system] Successfully activated service 'org.freedesktop.PackageKit' Nov 24 00:50:20 vortexbox dbus-daemon[806]: dbus[806]: [system] Successfully activated service 'org.freedesktop.PackageKit' Nov 24 00:50:21 vortexbox kernel: [92330.302093] scsi 7:0:0:0: Direct-Access WD 20EADS External 1.75 PQ: 0 ANSI: 4 Nov 24 00:50:21 vortexbox kernel: [92330.302149] scsi: killing requests for dead queue Nov 24 00:50:21 vortexbox kernel: [92330.302217] scsi: killing requests for dead queue Nov 24 00:50:21 vortexbox kernel: [92330.302277] scsi: killing requests for dead queue Nov 24 00:50:21 vortexbox kernel: [92330.302337] scsi: killing requests for dead queue Nov 24 00:50:21 vortexbox kernel: [92330.302396] scsi: killing requests for dead queue Nov 24 00:50:21 vortexbox kernel: [92330.302455] scsi: killing requests for dead queue Nov 24 00:50:21 vortexbox kernel: [92330.302515] scsi: killing requests for dead queue Nov 24 00:50:21 vortexbox kernel: [92330.302573] scsi: killing requests for dead queue Nov 24 00:50:21 vortexbox kernel: [92330.302802] sd 7:0:0:0: Attached scsi generic sg2 type 0 Nov 24 00:50:21 vortexbox kernel: [92330.308077] sd 7:0:0:0: [sdc] 3907029168 512-byte logical blocks: (2.00 TB/1.81 TiB) Nov 24 00:50:21 vortexbox kernel: [92330.311075] sd 7:0:0:0: [sdc] Write Protect is off Nov 24 00:50:21 vortexbox kernel: [92330.314075] sd 7:0:0:0: [sdc] No Caching mode page present Nov 24 00:50:21 vortexbox kernel: [92330.314127] sd 7:0:0:0: [sdc] Assuming drive cache: write through Nov 24 00:50:21 vortexbox kernel: [92330.325075] sd 7:0:0:0: [sdc] No Caching mode page present Nov 24 00:50:21 vortexbox kernel: [92330.325121] sd 7:0:0:0: [sdc] Assuming drive cache: write through Nov 24 00:50:21 vortexbox kernel: [92330.469889] e1000e: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx Nov 24 00:50:21 vortexbox NetworkManager[782]: <info> (eth0): carrier now ON (device state 100) Nov 24 00:50:21 vortexbox NetworkManager[782]: NetworkManager[782]: <info> (eth0): carrier now ON (device state 100) Nov 24 00:50:31 vortexbox kernel: [92340.565204] sdc: unknown partition table Nov 24 00:50:31 vortexbox kernel: [92340.578194] sd 7:0:0:0: [sdc] No Caching mode page present Nov 24 00:50:31 vortexbox kernel: [92340.578247] sd 7:0:0:0: [sdc] Assuming drive cache: write through Nov 24 00:50:31 vortexbox kernel: [92340.578289] sd 7:0:0:0: [sdc] Attached SCSI disk Nov 24 00:50:39 vortexbox kernel: [92348.119027] usb 3-2: reset full speed USB device number 2 using uhci_hcd
Looking closer to the messages log file I noticed Nov 24 00:50:19 vortexbox kernel: [92328.913492] PM: Not enough free swap Adding enough space to the swap solved the problem. Steps to Reproduce the error: 1. swap partition smaller then amount of memory used 2. attach usb device (/dev/sdb) 3. mount usb device using UUID to /storage 4. echo 0 > /sys/class/rtc/rtc0/wakealarm 5. echo `date '+%s' -d '+ 5 minutes'` > /sys/class/rtc/rtc0/wakealarm 6. /usr/sbin/pm-hibernate
This seems like it was due to not enough swap space for hibernation, which was causing the bus probe again after a failure. Thanks for letting us know you solved it.