Topic: Waking up RDX backup drive - backupwk fail

[gbentley]

Cron <root@server> /sbin/e-smith/do_backupwk
Error while mounting /dev/sdc1 /media/nolabel :
mount: you must specify the filesystem type
Backup terminated: backup failed - status: 7424

Logging in with ssh I notice that ;

[root@server ~]# mount /media/nolabel
mount: wrong fs type, bad option, bad superblock on /dev/sdc1,
       missing codepage or other error
       In some cases useful info is found in syslog - try
       dmesg | tail  or so

[root@server ~]# mount /media/nolabel
[root@server ~]# ls /media/nolabel
[root@server ~]# touch /media/nolabel/test
[root@server ~]# ls /media/nolabel
test
[root@server ~]#

From /var/log/messages

Jun 16 23:15:01 server /sbin/e-smith/do_backupwk[4234]: /home/e-smith/db/backups: OLD 1339884901=(undefined)
Jun 16 23:15:01 server /sbin/e-smith/do_backupwk[4234]: /home/e-smith/db/backups: NEW 1339884901=backup_record
Jun 16 23:15:01 server /sbin/e-smith/do_backupwk[4234]: /home/e-smith/db/backups: OLD 1339884901=backup_record
Jun 16 23:15:01 server /sbin/e-smith/do_backupwk[4234]: /home/e-smith/db/backups: NEW 1339884901=backup_record|StartEpochTime|1339884901
Jun 16 23:15:01 server /sbin/e-smith/do_backupwk[4234]: /home/e-smith/db/backups: OLD 1339884901=backup_record|StartEpochTime|1339884901
Jun 16 23:15:01 server /sbin/e-smith/do_backupwk[4234]: /home/e-smith/db/backups: NEW 1339884901=backup_record|BackupType|workstation|StartEpochTime|1339884901
Jun 16 23:15:01 server esmith::event[4235]: Processing event: pre-backup 
Jun 16 23:15:01 server esmith::event[4235]: Running event handler: /etc/e-smith/events/actions/generic_template_expand
Jun 16 23:15:02 server esmith::event[4235]: expanding /etc/dar/DailyBackup.dcf 
Jun 16 23:15:02 server esmith::event[4235]: generic_template_expand=action|Event|pre-backup|Action|generic_template_expand|Start|1339884901 961037|End|1339884902 521918|Elapsed|0.560881
Jun 16 23:15:02 server esmith::event[4235]: Running event handler: /etc/e-smith/events/pre-backup/S10mysql-delete-dumped-tables
Jun 16 23:15:02 server esmith::event[4235]: S10mysql-delete-dumped-tables=action|Event|pre-backup|Action|S10mysql-delete-dumped-tables|Start|1339884902 522284|End|1339884902 524934|Elapsed|0.00265
Jun 16 23:15:02 server esmith::event[4235]: Running event handler: /etc/e-smith/events/pre-backup/S20mysql-dump-tables
Jun 16 23:15:03 server esmith::event[4235]: S20mysql-dump-tables=action|Event|pre-backup|Action|S20mysql-dump-tables|Start|1339884902 525238|End|1339884903 244111|Elapsed|0.718873
Jun 16 23:15:03 server esmith::event[4235]: Running event handler: /etc/e-smith/events/pre-backup/S30ldap-dump
Jun 16 23:15:03 server esmith::event[4235]: S30ldap-dump=action|Event|pre-backup|Action|S30ldap-dump|Start|1339884903 244510|End|1339884903 834336|Elapsed|0.589826
Jun 16 23:15:03 server esmith::event[4235]: Running event handler: /etc/e-smith/events/pre-backup/S50rewind-tape
Jun 16 23:15:03 server esmith::event[4235]: S50rewind-tape=action|Event|pre-backup|Action|S50rewind-tape|Start|1339884903 834730|End|1339884903 888099|Elapsed|0.053369
Jun 16 23:15:05 server kernel: sdc: Current: sense key: No Sense
Jun 16 23:15:05 server kernel:     Add. Sense: No additional sense information
Jun 16 23:15:05 server kernel:
Jun 16 23:15:05 server kernel: sd 5:0:0:0: Device not ready
Jun 16 23:15:05 server kernel: sd 5:0:0:0: SCSI error: return code = 0x08000002
Jun 16 23:15:05 server kernel: Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE,SUGGEST_OK
Jun 16 23:15:05 server kernel: sdc: Current: sense key: Not Ready
Jun 16 23:15:05 server kernel:     Add. Sense: Logical unit not ready, cause not reportable
Jun 16 23:15:05 server kernel:
Jun 16 23:15:05 server kernel: Buffer I/O error on device sdc1, logical block 0
Jun 16 23:15:05 server kernel: Buffer I/O error on device sdc1, logical block 1
Jun 16 23:15:05 server kernel: Buffer I/O error on device sdc1, logical block 2
Jun 16 23:15:05 server kernel: Buffer I/O error on device sdc1, logical block 3
Jun 16 23:15:05 server kernel: Buffer I/O error on device sdc1, logical block 4
Jun 16 23:15:05 server kernel: Buffer I/O error on device sdc1, logical block 5
Jun 16 23:15:05 server kernel: Buffer I/O error on device sdc1, logical block 6
Jun 16 23:15:05 server kernel: Buffer I/O error on device sdc1, logical block 7
Jun 16 23:15:05 server kernel: Buffer I/O error on device sdc1, logical block 8
Jun 16 23:15:05 server kernel: Buffer I/O error on device sdc1, logical block 9
Jun 16 23:15:05 server kernel: sd 5:0:0:0: Device not ready
Jun 16 23:15:05 server kernel: sd 5:0:0:0: SCSI error: return code = 0x08000002
Jun 16 23:15:05 server kernel: Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE,SUGGEST_OK
Jun 16 23:15:05 server kernel: sdc: Current: sense key: Not Ready
Jun 16 23:15:05 server kernel:     Add. Sense: Logical unit not ready, cause not reportable
Jun 16 23:15:05 server kernel:
Jun 16 23:15:05 server kernel: sd 5:0:0:0: Device not ready
Jun 16 23:15:05 server kernel: sd 5:0:0:0: SCSI error: return code = 0x08000002
Jun 16 23:15:05 server kernel: Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE,SUGGEST_OK
Jun 16 23:15:05 server kernel: sdc: Current: sense key: Not Ready
Jun 16 23:15:05 server kernel:     Add. Sense: Logical unit not ready, cause not reportable
Jun 16 23:15:05 server kernel:
Jun 16 23:15:05 server kernel: sd 5:0:0:0: Device not ready
Jun 16 23:15:05 server kernel: sd 5:0:0:0: SCSI error: return code = 0x08000002
Jun 16 23:15:05 server kernel: Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE,SUGGEST_OK
Jun 16 23:15:05 server kernel: sdc: Current: sense key: Not Ready
Jun 16 23:15:05 server kernel:     Add. Sense: Logical unit not ready, cause not reportable
Jun 16 23:15:05 server kernel:
Jun 16 23:15:05 server kernel: sdc: Spinning up disk...<6>sd 5:0:0:0: Device not ready
Jun 16 23:15:05 server kernel: sd 5:0:0:0: SCSI error: return code = 0x08000002
Jun 16 23:15:05 server kernel: Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE,SUGGEST_OK
Jun 16 23:15:05 server kernel: sdc: Current: sense key: Not Ready
Jun 16 23:15:05 server kernel:     Add. Sense: Logical unit not ready, cause not reportable
Jun 16 23:15:05 server kernel:
Jun 16 23:15:10 server kernel: .....ready
Jun 16 23:15:10 server kernel: SCSI device sdc: 312573616 512-byte hdwr sectors (160038 MB)
Jun 16 23:15:10 server kernel: sdc: Write Protect is off
Jun 16 23:15:10 server kernel: sdc: Mode Sense: 00 56 00 00
Jun 16 23:15:10 server kernel: SCSI device sdc: drive cache: write back
Jun 16 23:15:10 server kernel: SCSI device sdc: 312573616 512-byte hdwr sectors (160038 MB)
Jun 16 23:15:10 server kernel: sdc: Write Protect is off
Jun 16 23:15:10 server kernel: sdc: Mode Sense: 00 56 00 00
Jun 16 23:15:10 server kernel: SCSI device sdc: drive cache: write back
Jun 16 23:15:11 server kernel:  sdc: sdc1
Jun 16 23:15:11 server kernel: hfs: unable to find HFS+ superblock
Jun 16 23:15:11 server /sbin/e-smith/do_backupwk[4234]: /home/e-smith/db/backups: OLD 1339884901=backup_record|BackupType|workstation|StartEpochTime|1339884901
Jun 16 23:15:11 server /sbin/e-smith/do_backupwk[4234]: /home/e-smith/db/backups: NEW 1339884901=backup_record|BackupType|workstation|EndEpochTime|1339884911|StartEpochTime|1339884901
Jun 16 23:15:11 server /sbin/e-smith/do_backupwk[4234]: /home/e-smith/db/backups: OLD 1339884901=backup_record|BackupType|workstation|EndEpochTime|1339884911|StartEpochTime|1339884901
Jun 16 23:15:11 server /sbin/e-smith/do_backupwk[4234]: /home/e-smith/db/backups: NEW 1339884901=backup_record|BackupType|workstation|EndEpochTime|1339884911|Result|backup:7424|StartEpochTime|1339884901

Manually trying to mount disc here ...

Jun 17 08:05:15 server kernel: sdc: Current: sense key: No Sense
Jun 17 08:05:15 server kernel:     Add. Sense: No additional sense information
Jun 17 08:05:15 server kernel:
Jun 17 08:05:15 server kernel: sd 5:0:0:0: Device not ready
Jun 17 08:05:15 server kernel: sd 5:0:0:0: SCSI error: return code = 0x08000002
Jun 17 08:05:15 server kernel: Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE,SUGGEST_OK
Jun 17 08:05:15 server kernel: sdc: Current: sense key: Not Ready
Jun 17 08:05:15 server kernel:     Add. Sense: Logical unit not ready, cause not reportable
Jun 17 08:05:15 server kernel:
Jun 17 08:05:15 server kernel: EXT3-fs: unable to read superblock
Jun 17 08:05:20 server kernel: sdc: Spinning up disk........ready
Jun 17 08:05:20 server kernel: SCSI device sdc: 312573616 512-byte hdwr sectors (160038 MB)
Jun 17 08:05:20 server kernel: sdc: Write Protect is off
Jun 17 08:05:20 server kernel: sdc: Mode Sense: 00 56 00 00
Jun 17 08:05:20 server kernel: SCSI device sdc: drive cache: write back
Jun 17 08:05:20 server kernel: SCSI device sdc: 312573616 512-byte hdwr sectors (160038 MB)
Jun 17 08:05:20 server kernel: sdc: Write Protect is off
Jun 17 08:05:20 server kernel: sdc: Mode Sense: 00 56 00 00
Jun 17 08:05:20 server kernel: SCSI device sdc: drive cache: write back
Jun 17 08:05:20 server kernel:  sdc: sdc1
Jun 17 08:05:55 server kernel: kjournald starting.  Commit interval 5 seconds
Jun 17 08:05:55 server kernel: EXT3-fs warning: maximal mount count reached, running e2fsck is recommended
Jun 17 08:05:55 server kernel: EXT3 FS on sdc1, internal journal
Jun 17 08:05:55 server kernel: EXT3-fs: mounted filesystem with ordered data mode.

Seems like disc is timing out and going into sleep mode or some such ...

Have tried adding to /etc/cron.d 'touchdisk' in hope of keeping it awake

*/5 * * * * root /bin/touch /dev/sdc &>/dev/null

but this doesnt seme to work!

Once disc is awake [manually trying to mount it twice usually does it - the backup works fine!

Any suggestions on above would be greatfully received - thanks!

[janet]

gbentley

There was a bug report back a year or two ago regarding waking up some Western Digital USB drives, that may assist you.
Maybe it was Graeme Robinson who posted the bug or the answer, so start searching.

[gbentley]

http://bugs.contribs.org/bugs/buglist.cgi?query_format=specific&order=relevance%20desc&bug_status=__open__&content=Graeme%20Robinson%20USB&list_id=9712

Came up with some intersting stuff ... and this handy little script for forcing drive spin up

---
until [ -d /media/nolabel/tmp_dir ]; do
/bin/mount -t ext3 /dev/sdc1 /media/nolabel
done
/bin/umount /media/nolabel
---

Now part for my 'cleardisk' script described here

http://wiki.contribs.org/Backup_with_dar#Backup_disk_size_limits_workaround

[I am swapping out carts daily for off site bu and want to overwrite / complete backup each night]