Koozali.org: home of the SME Server

Obsolete Releases => SME Server 7.x => Topic started by: stian on March 07, 2006, 05:57:00 PM

Title: Tape restore error
Post by: stian on March 07, 2006, 05:57:00 PM
Using an Adaptec kontroller (AHA 29320U-R) and a VXA-2 68pins LVDSCSI.

flexbackup version 1.2.1 (http://flexbackup.sourceforge.net)
/etc/flexbackup.conf syntax OK

 $keyfile not found in config: default=00-index-key
 $buffer_fill_pct not found in config: default=75
 $buffer_pause_usec not found in config: default=100
|------------------------------------------------------------
| Checking 'buffer' on this machine... Ok
| Checking /bin/sh on this machine... bash1
|------------------------------------------------------------
| Doing level 0 backup of set all using tar
| All sets = full (1 tapes)
| Rewinding & erasing tape...
| Creating index key 200603071610
| Backup set "full" (/)
| Tape #0
|------------------------------------------------------------
SCSI 2 tape drive:
File number=0, block number=0, partition=0.
Tape block size 1024 bytes. Density code 0x81 (DLT 15GB compressed).
Soft error count since last status=0
General status bits on (41010000):
 BOT ONLINE IM_REP_EN
|------------------------------------------------------------
| File number 1, tape index 200603071610
| Backup of: /
| Date of this level 0 backup: Tue Mar 07 16:11:30 2006
| Date of last level 0 backup: the epoch
|------------------------------------------------------------
| cd "/" && /tmp/collectexit.3454.sh find . -depth -xdev ! -type s ! -regex \
|   "news/articles" ! -regex ".*~"$ -print0 | /tmp/collectexit.3454.sh tar \
|   --create --null --files-from=- --ignore-failed-read --same-permissions \
|   --no-recursion --totals --label "level 0 / Tue Mar 07 16:11:30 2006 \
|   tar+gzip from sme" --sparse --atime-preserve -b 64 --file - | \
|   /tmp/collectexit.3454.sh gzip -4 | /tmp/collectexit.3454.sh buffer -m \
|   20m -p 75 -s 32k -t -u 100 -B -o "/dev/nst0"
| [ ! -e /tmp/exitstatus.3454 ]
|------------------------------------------------------------
buffer (writer): write of data failed: Input/output error
bytes to write=32768, bytes written=-1, total written          0K

ERROR: non-zero exit from:
buffer -m 20m -p 75 -s 32k -t -u 100 -B -o /dev/nst0
gzip -4
tar --create --null --files-from=- --ignore-failed-read --same-permissions --no-recursion --totals --label level 0 / Tue Mar 07 16:11:30 2006 tar+gzip from sme --sparse --atime-preserve -b 64 --file -
find . -depth -xdev ! -type s ! -regex news/articles ! -regex .*~$ -print0


ERROR: exiting
|------------------------------------------------------------
| Backup start: Tue Mar 07 16:11:30 2006
| Backup end:   Tue Mar 07 16:12:51 2006
|------------------------------------------------------------
SCSI 2 tape drive:
File number=0, block number=-1, partition=0.
Tape block size 1024 bytes. Density code 0x81 (DLT 15GB compressed).
Soft error count since last status=0
General status bits on (1010000):
 ONLINE IM_REP_EN
|------------------------------------------------------------
| Rewinding...
Title: Tape restore error
Post by: cljunkie on March 11, 2006, 01:47:07 AM
I'm getting the same error message about input/output. I've had problem s with DLT AIT and SME 6 and 7prev's. I had luck with a 8 mm during 6.x days, but now it too has the same errors under 7. I'm restoring to going to harddrive backup via rsync due to the included program's 4GB limit which I haven't gotten my head around yet. Kinda sucks to do a rsync and then delete enough to do a backup to desktop safely.
Title: Backup ok but not restore!
Post by: stian on March 15, 2006, 05:57:08 PM
I got the backup to work by connecting the scsi-cable to another port on the adapter-card. I looks ok in the log under here. Then I tried to restore, with no success. The log around the restore-process is also pasted under here. Anyone sees whats wrong?


BACKUP:
flexbackup version 1.2.1 (http://flexbackup.sourceforge.net)
/etc/flexbackup.conf syntax OK

 $keyfile not found in config: default=00-index-key
 $buffer_fill_pct not found in config: default=75
 $buffer_pause_usec not found in config: default=100
|------------------------------------------------------------
| Checking 'buffer' on this machine... Ok
| Checking /bin/sh on this machine... bash1
|------------------------------------------------------------
| Doing level 0 backup of set all using tar
| All sets = full (1 tapes)
| Rewinding & erasing tape...
| Found index key 200603151705, next file is 2
| Deleting record for 200603151705 file 0
| Deleting record for 200603151705 file 1
|------------------------------------------------------------
| Creating index key 200603151715
| Backup set "full" (/)
| Tape #0
|------------------------------------------------------------
SCSI 2 tape drive:
File number=1, block number=0, partition=0.
Tape block size 0 bytes. Density code 0x81 (DLT 15GB compressed).
Soft error count since last status=0
General status bits on (81010000):
 EOF ONLINE IM_REP_EN
|------------------------------------------------------------
| File number 1, tape index 200603151715
| Backup of: /
| Date of this level 0 backup: Wed Mar 15 17:15:23 2006
| Date of last level 0 backup: the epoch
|------------------------------------------------------------
| cd "/" && /tmp/collectexit.3663.sh find . -depth -xdev ! -type s ! -regex \
|   "news/articles" ! -regex ".*~"$ -print0 | /tmp/collectexit.3663.sh tar \
|   --create --null --files-from=- --ignore-failed-read --same-permissions \
|   --no-recursion --totals --label "level 0 / Wed Mar 15 17:15:23 2006 \
|   tar+gzip from sme70" --sparse --atime-preserve -b 64 --file - | \
|   /tmp/collectexit.3663.sh gzip -4 | /tmp/collectexit.3663.sh buffer -m \
|   20m -p 75 -s 32k -t -u 100 -B -o "/dev/nst0"
| [ ! -e /tmp/exitstatus.3663 ]
|------------------------------------------------------------
Total bytes written: 869957632 (830MiB, 7.2MiB/s)
Kilobytes Out 314048
|------------------------------------------------------------
| Backup start: Wed Mar 15 17:15:23 2006
| Backup end:   Wed Mar 15 17:17:22 2006
|------------------------------------------------------------
SCSI 2 tape drive:
File number=2, block number=0, partition=0.
Tape block size 0 bytes. Density code 0x81 (DLT 15GB compressed).
Soft error count since last status=0
General status bits on (81010000):
 EOF ONLINE IM_REP_EN
|------------------------------------------------------------
| Rewinding...
| Removing old level 0 log of all (dated 200603151705)
| Compressing log (all.0.200603151715.gz)
| Linking all.latest.gz -> all.0.200603151715.gz
|------------------------------------------------------------

File  Contents    (tape index 200603151715)
---------------------------------------------
0    <tape index key>
1    level 0 / Wed Mar 15 17:15:23 2006 tar+gzip from sme70






RESTORE:
Mar 15 17:15:01 sme70 crond(pam_unix)[3656]: session opened for user root by (uid=0)
Mar 15 17:15:01 sme70 /sbin/e-smith/do_backup[3657]: /home/e-smith/db/backups: OLD 1142439301=(undefined)
Mar 15 17:15:01 sme70 /sbin/e-smith/do_backup[3657]: /home/e-smith/db/backups: NEW 1142439301=backup_record
Mar 15 17:15:01 sme70 /sbin/e-smith/do_backup[3657]: /home/e-smith/db/backups: OLD 1142439301=backup_record
Mar 15 17:15:01 sme70 /sbin/e-smith/do_backup[3657]: /home/e-smith/db/backups: NEW 1142439301=backup_record|StartEpochTime|1142439301
Mar 15 17:15:01 sme70 /sbin/e-smith/do_backup[3657]: /home/e-smith/db/backups: OLD 1142439301=backup_record|StartEpochTime|1142439301
Mar 15 17:15:01 sme70 /sbin/e-smith/do_backup[3657]: /home/e-smith/db/backups: NEW 1142439301=backup_record|BackupType|tape|StartEpochTime|1142439301
Mar 15 17:15:01 sme70 esmith::event[3658]: Processing event: pre-backup tape
Mar 15 17:15:01 sme70 esmith::event[3658]: Running event handler: /etc/e-smith/events/pre-backup/S10mysql-delete-dumped-tables
Mar 15 17:15:01 sme70 esmith::event[3658]: S10mysql-delete-dumped-tables=action|Event|pre-backup|Action|S10mysql-delete-dumped-tables|Start|1142439301 615192|End|1142439301 618657|Elapsed|0.003465
Mar 15 17:15:01 sme70 esmith::event[3658]: Running event handler: /etc/e-smith/events/pre-backup/S20mysql-dump-tables
Mar 15 17:15:01 sme70 esmith::event[3658]: S20mysql-dump-tables=action|Event|pre-backup|Action|S20mysql-dump-tables|Start|1142439301 619102|End|1142439301 719939|Elapsed|0.100837
Mar 15 17:15:01 sme70 esmith::event[3658]: Running event handler: /etc/e-smith/events/pre-backup/S50rewind-tape
Mar 15 17:15:01 sme70 esmith::event[3658]: S50rewind-tape=action|Event|pre-backup|Action|S50rewind-tape|Start|1142439301 720403|End|1142439301 838354|Elapsed|0.117951
Mar 15 17:18:21 sme70 esmith::event[3711]: Processing event: post-backup tape
Mar 15 17:18:21 sme70 esmith::event[3711]: Running event handler: /etc/e-smith/events/post-backup/S10mysql-delete-dumped-tables
Mar 15 17:18:21 sme70 esmith::event[3711]: S10mysql-delete-dumped-tables=action|Event|post-backup|Action|S10mysql-delete-dumped-tables|Start|1142439501 137383|End|1142439501 161698|Elapsed|0.024315
Mar 15 17:18:21 sme70 esmith::event[3711]: Running event handler: /etc/e-smith/events/post-backup/S50rewind-tape
Mar 15 17:18:21 sme70 esmith::event[3711]: S50rewind-tape=action|Event|post-backup|Action|S50rewind-tape|Start|1142439501 162168|End|1142439501 313641|Elapsed|0.151473
Mar 15 17:18:21 sme70 /sbin/e-smith/do_backup[3657]: /home/e-smith/db/backups: OLD 1142439301=backup_record|BackupType|tape|StartEpochTime|1142439301
Mar 15 17:18:21 sme70 /sbin/e-smith/do_backup[3657]: /home/e-smith/db/backups: NEW 1142439301=backup_record|BackupType|tape|EndEpochTime|1142439501|StartEpochTime|1142439301
Mar 15 17:18:21 sme70 /sbin/e-smith/do_backup[3657]: /home/e-smith/db/backups: OLD 1142439301=backup_record|BackupType|tape|EndEpochTime|1142439501|StartEpochTime|1142439301
Mar 15 17:18:21 sme70 /sbin/e-smith/do_backup[3657]: /home/e-smith/db/backups: NEW 1142439301=backup_record|BackupType|tape|EndEpochTime|1142439501|Result|0|StartEpochTime|1142439301
Mar 15 17:18:21 sme70 crond(pam_unix)[3656]: session closed for user root
Mar 15 17:20:14 sme70 /etc/e-smith/web/panels/manager/cgi-bin/backup[3734]: /etc/e-smith/restore: OLD restore=status|finish|0|start|0|state|idle
Mar 15 17:20:14 sme70 /etc/e-smith/web/panels/manager/cgi-bin/backup[3734]: /etc/e-smith/restore: NEW restore=status|finish|0|start|0|state|running
Mar 15 17:20:14 sme70 /etc/e-smith/web/panels/manager/cgi-bin/backup[3734]: /etc/e-smith/restore: OLD restore=status|finish|0|start|0|state|running
Mar 15 17:20:14 sme70 /etc/e-smith/web/panels/manager/cgi-bin/backup[3734]: /etc/e-smith/restore: NEW restore=status|finish|0|start|1142439614|state|running
Mar 15 17:20:14 sme70 esmith::event[3736]: Processing event: pre-restore  
Mar 15 17:20:14 sme70 esmith::event[3736]: Running event handler: /etc/e-smith/events/pre-restore/S10save-system-files
Mar 15 17:20:14 sme70 esmith::event[3736]: S10save-system-files=action|Event|pre-restore|Action|S10save-system-files|Start|1142439614 769883|End|1142439614 855335|Elapsed|0.085452
Mar 15 17:20:14 sme70 esmith::event[3736]: Running event handler: /etc/e-smith/events/pre-restore/S25ldap-delete-dumps
Mar 15 17:20:15 sme70 slapd[3007]: slapd shutdown: waiting for 0 threads to terminate
Mar 15 17:20:15 sme70 slapd[3007]: slapd stopped.
Mar 15 17:20:15 sme70 slapcat: bdb_initialize: Sleepycat Software: Berkeley DB 4.2.52: (December  3, 2003)
Mar 15 17:20:15 sme70 slapcat: bdb_initialize: Sleepycat Software: Berkeley DB 4.2.52: (December  3, 2003)
Mar 15 17:20:15 sme70 slapcat: /etc/openldap/slapd.conf: line 18: schema checking disabled! your mileage may vary!
Mar 15 17:20:16 sme70 ldap: Stopping ldap succeeded
Mar 15 17:20:16 sme70 esmith::event[3736]: Stopping ldap:[  OK  ]
 
Mar 15 17:20:16 sme70 esmith::event[3736]: S25ldap-delete-dumps=action|Event|pre-restore|Action|S25ldap-delete-dumps|Start|1142439614 855795|End|1142439616 209973|Elapsed|1.354178
Mar 15 17:20:16 sme70 esmith::event[3736]: Running event handler: /etc/e-smith/events/actions/adjust-services
Mar 15 17:20:16 sme70 esmith::event[3736]: adjusting supervised mysqld (stop)  
Mar 15 17:20:16 sme70 esmith::event[3736]: adjust-services=action|Event|pre-restore|Action|adjust-services|Start|1142439616 210280|End|1142439616 411730|Elapsed|0.20145
Mar 15 17:20:16 sme70 esmith::event[3736]: Running event handler: /etc/e-smith/events/pre-restore/S99mysql-delete-db-files
Mar 15 17:20:16 sme70 esmith::event[3736]: S99mysql-delete-db-files=action|Event|pre-restore|Action|S99mysql-delete-db-files|Start|1142439616 412130|End|1142439616 428894|Elapsed|0.016764
Mar 15 17:20:16 sme70 esmith::event[3763]: Processing event: restore-tape  
Mar 15 17:20:16 sme70 esmith::event[3763]: Running event handler: /etc/e-smith/events/restore-tape/S10tape-restore-flexbackup
Mar 15 17:20:16 sme70 esmith::event[3763]: Name "cfg::set" used only once: possible typo at /etc/e-smith/events/restore-tape/S10tape-restore-flexbackup line 55.  
Mar 15 17:20:33 sme70 esmith::event[3763]: dd: reading /dev/nst0': Invalid argument  
Mar 15 17:20:33 sme70 esmith::event[3763]: 0+0 records in  
Mar 15 17:20:33 sme70 esmith::event[3763]: 0+0 records out  
Mar 15 17:20:44 sme70 esmith::event[3763]:  
Mar 15 17:20:44 sme70 esmith::event[3763]: flexbackup version 1.2.1 (http://flexbackup.sourceforge.net)  
Mar 15 17:20:44 sme70 esmith::event[3763]: /etc/flexbackup.conf syntax OK  
Mar 15 17:20:44 sme70 esmith::event[3763]: (override) blksize = 0  
Mar 15 17:20:44 sme70 esmith::event[3763]:  
Mar 15 17:20:44 sme70 esmith::event[3763]:  $keyfile not found in config: default=00-index-key  
Mar 15 17:20:44 sme70 esmith::event[3763]:  $buffer_fill_pct not found in config: default=75  
Mar 15 17:20:44 sme70 esmith::event[3763]:  $buffer_pause_usec not found in config: default=100  
Mar 15 17:20:44 sme70 esmith::event[3763]: |------------------------------------------------------------  
Mar 15 17:20:44 sme70 esmith::event[3763]: | Checking 'buffer' on this machine... Ok  
Mar 15 17:20:44 sme70 esmith::event[3763]: | Checking /bin/sh on this machine... bash1  
Mar 15 17:20:44 sme70 esmith::event[3763]: |------------------------------------------------------------  
Mar 15 17:20:44 sme70 esmith::event[3763]: | Logging output to "flexbackup.extract.200603151720.log"  
Mar 15 17:20:44 sme70 esmith::event[3763]: | Reading from CURRENT TAPE POSITION  
Mar 15 17:20:44 sme70 esmith::event[3763]: |------------------------------------------------------------  
Mar 15 17:20:44 sme70 esmith::event[3763]: SCSI 2 tape drive:  
Mar 15 17:20:44 sme70 esmith::event[3763]: File number=1, block number=0, partition=0.  
Mar 15 17:20:44 sme70 esmith::event[3763]: Tape block size 0 bytes. Density code 0x81 (DLT 15GB compressed).  
Mar 15 17:20:44 sme70 esmith::event[3763]: Soft error count since last status=0  
Mar 15 17:20:44 sme70 esmith::event[3763]: General status bits on (81010000):  
Mar 15 17:20:44 sme70 esmith::event[3763]:  EOF ONLINE IM_REP_EN  
Mar 15 17:20:44 sme70 esmith::event[3763]: |------------------------------------------------------------  
Mar 15 17:20:44 sme70 esmith::event[3763]: | Extracting files listed in /tmp/restore.3767  
Mar 15 17:20:44 sme70 esmith::event[3763]: | buffer -m 20m -p 75 -t -u 100 -i "/dev/nst0" | gzip -dq | tar --extract \  
Mar 15 17:20:44 sme70 esmith::event[3763]: |   --files-from /tmp/extract.3780 --totals --same-permissions   --sparse   \  
Mar 15 17:20:44 sme70 esmith::event[3763]: |   -B --file -  
Mar 15 17:20:44 sme70 esmith::event[3763]: |------------------------------------------------------------  
Mar 15 17:20:48 sme70 kernel: st0: Failed to read 32768 byte block with 10240 byte transfer.
Mar 15 17:20:48 sme70 esmith::event[3763]: buffer (reader): failed to read input: Cannot allocate memory  
Mar 15 17:20:48 sme70 esmith::event[3763]:  
Mar 15 17:20:48 sme70 esmith::event[3763]: gzip: stdin: unexpected end of file  
Mar 15 17:20:48 sme70 esmith::event[3763]: tar: ./home/e-smith: Not found in archive  
Mar 15 17:20:48 sme70 esmith::event[3763]: tar: ./etc/e-smith/templates-custom: Not found in archive  
Mar 15 17:20:48 sme70 esmith::event[3763]: tar: ./etc/e-smith/templates-user-custom: Not found in archive  
Mar 15 17:20:48 sme70 esmith::event[3763]: tar: ./etc/ssh: Not found in archive  
Mar 15 17:20:48 sme70 esmith::event[3763]: tar: ./root: Not found in archive  
Mar 15 17:20:48 sme70 esmith::event[3763]: tar: ./etc/sudoers: Not found in archive  
Mar 15 17:20:48 sme70 esmith::event[3763]: tar: ./etc/passwd: Not found in archive  
Mar 15 17:20:48 sme70 esmith::event[3763]: tar: ./etc/shadow: Not found in archive  
Mar 15 17:20:48 sme70 esmith::event[3763]: tar: ./etc/group: Not found in archive  
Mar 15 17:20:48 sme70 esmith::event[3763]: tar: ./etc/gshadow: Not found in archive  
Mar 15 17:20:48 sme70 esmith::event[3763]: tar: ./etc/samba/secrets.tdb: Not found in archive  
Mar 15 17:20:48 sme70 esmith::event[3763]: tar: ./etc/samba/smbpasswd: Not found in archive  
Mar 15 17:20:48 sme70 esmith::event[3763]: tar: ./etc/smbpasswd: Not found in archive  
Mar 15 17:20:48 sme70 esmith::event[3763]: tar: Error exit delayed from previous errors  
Mar 15 17:20:48 sme70 esmith::event[3763]: |------------------------------------------------------------  
Mar 15 17:20:48 sme70 esmith::event[3763]: SCSI 2 tape drive:  
Mar 15 17:20:48 sme70 esmith::event[3763]: File number=1, block number=1, partition=0.  
Mar 15 17:20:48 sme70 esmith::event[3763]: Tape block size 0 bytes. Density code 0x81 (DLT 15GB compressed).  
Mar 15 17:20:48 sme70 esmith::event[3763]: Soft error count since last status=0  
Mar 15 17:20:48 sme70 esmith::event[3763]: General status bits on (1010000):  
Mar 15 17:20:48 sme70 esmith::event[3763]:  ONLINE IM_REP_EN  
Mar 15 17:20:48 sme70 esmith::event[3763]: |------------------------------------------------------------  
Mar 15 17:20:48 sme70 esmith::event[3763]: S10tape-restore-flexbackup=action|Event|restore-tape|Action|S10tape-restore-flexbackup|Start|1142439616 603191|End|1142439648 370487|Elapsed|31.767296
Mar 15 17:20:48 sme70 esmith::event[3763]: Running event handler: /etc/e-smith/events/restore-tape/S40restore-from-disk
Mar 15 17:20:48 sme70 esmith::event[3763]: S40restore-from-disk=action|Event|restore-tape|Action|S40restore-from-disk|Start|1142439648 370785|End|1142439648 519260|Elapsed|0.148475
Mar 15 17:20:48 sme70 esmith::event[3763]: Running event handler: /etc/e-smith/events/restore-tape/S50rewind-tape
Mar 15 17:20:48 sme70 esmith::event[3763]: S50rewind-tape=action|Event|restore-tape|Action|S50rewind-tape|Start|1142439648 519717|End|1142439648 627175|Elapsed|0.107458
Mar 15 17:20:48 sme70 esmith::event[3814]: Processing event: post-upgrade  
Mar 15 17:20:48 sme70 esmith::event[3814]: Running event handler: /etc/e-smith/events/post-upgrade/S00initialize-default-databases
Mar 15 17:20:49 sme70 esmith::event[3814]: Migrating existing database yum_available  
Mar 15 17:20:49 sme70 esmith::event[3814]: Migrating existing database networks  
Mar 15 17:20:49 sme70 esmith::event[3814]: Migrating existing database accounts  
Mar 15 17:20:49 sme70 esmith::event[3814]: Migrating existing database configuration  
Mar 15 17:20:50 sme70 esmith::event[3814]: Migrating existing database domains  
Mar 15 17:20:50 sme70 esmith::event[3814]: Migrating existing database yum_repositories  
Mar 15 17:20:50 sme70 esmith::event[3814]: Migrating existing database yum_updates  
Mar 15 17:20:50 sme70 esmith::event[3814]: Migrating existing database yum_installed  
Mar 15 17:20:50 sme70 esmith::event[3814]: Migrating existing database mailpatterns  
Mar 15 17:20:50 sme70 esmith::event[3814]: Migrating existing database spamassassin  
Mar 15 17:20:50 sme70 esmith::event[3814]: Migrating existing database hosts  
Mar 15 17:20:50 sme70 esmith::event[3814]: Migrating existing database backups  
Mar 15 17:20:50 sme70 esmith::event[3814]: S00initialize-default-databases=action|Event|post-upgrade|Action|S00initialize-default-databases|Start|1142439648 843705|End|1142439650 482901|Elapsed|1.639196
Mar 15 17:20:50 sme70 esmith::event[3814]: Running event handler: /etc/e-smith/events/post-upgrade/S00merge-system-files
Mar 15 17:20:50 sme70 esmith::event[3814]: Preserving etc/sudoers as etc/sudoers.1142439650  
Mar 15 17:20:50 sme70 esmith::event[3814]: Preserving etc/passwd as etc/passwd.1142439650  
Mar 15 17:20:50 sme70 esmith::event[3814]: Preserving etc/shadow as etc/shadow.1142439650  
Mar 15 17:20:50 sme70 esmith::event[3814]: Preserving etc/group as etc/group.1142439650  
Mar 15 17:20:50 sme70 esmith::event[3814]: Preserving etc/gshadow as etc/gshadow.1142439650  
Mar 15 17:20:50 sme70 esmith::event[3814]: Preserving etc/samba/secrets.tdb as etc/samba/secrets.tdb.1142439650  
Mar 15 17:20:50 sme70 esmith::event[3814]: Preserving etc/samba/smbpasswd as etc/samba/smbpasswd.1142439650  
Mar 15 17:20:50 sme70 esmith::event[3814]: Preserving etc/smbpasswd as etc/smbpasswd.1142439650  
Mar 15 17:20:50 sme70 esmith::event[3814]: S00merge-system-files=action|Event|post-upgrade|Action|S00merge-system-files|Start|1142439650 483312|End|1142439650 568803|Elapsed|0.085491
Mar 15 17:20:50 sme70 esmith::event[3814]: Running event handler: /etc/e-smith/events/actions/generic_template_expand
Mar 15 17:20:50 sme70 esmith::event[3814]: expanding /boot/grub/grub.conf  
Mar 15 17:20:50 sme70 esmith::event[3814]: expanding /var/qmail/control/me  
Mar 15 17:20:50 sme70 esmith::event[3814]: expanding /var/qmail/control/doublebounceto  
Mar 15 17:20:50 sme70 esmith::event[3814]: expanding /var/qmail/control/smtproutes  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /var/qmail/control/rcpthosts  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /var/qmail/control/helohost  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /var/qmail/control/concurrencylocal  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /var/qmail/control/databytes  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /var/qmail/control/defaultdomain  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /var/qmail/control/envnoathost  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /var/qmail/control/concurrencyremote  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /var/qmail/control/plusdomain  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /var/qmail/control/bouncehost  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /var/qmail/control/locals  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /var/qmail/control/defaulthost  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /var/qmail/control/bouncefrom  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /var/qmail/control/virtualdomains  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /var/qmail/alias/.qmail-default  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /var/qmail/alias/.qmail-localdelivery-default  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /etc/startmail  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /etc/issue.net  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /etc/fetchmail  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /etc/motd  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /etc/ulogd.conf  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /etc/issue  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /etc/fstab  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /etc/syslog.conf  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /etc/crontab  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /etc/modprobe.conf  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /etc/redhat-release  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /etc/inittab  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /etc/mime.types  
Mar 15 17:20:51 sme70 esmith::event[3814]: expanding /etc/sysconfig/syslog  
Mar 15 17:20:52 sme70 esmith::event[3814]: expanding /etc/sysconfig/ups  
Mar 15 17:20:52 sme70 esmith::event[3814]: expanding /etc/sysconfig/i18n  
Mar 15 17:20:52 sme70 esmith::event[3814]: expanding /etc/ups/upsd.users  
Mar 15 17:20:52 sme70 esmith::event[3814]: expanding /etc/ups/upsd.conf  
Mar 15 17:20:52 sme70 esmith::event[3814]: expanding /etc/ups/upssched.conf  
Mar 15 17:20:52 sme70 esmith::event[3814]: expanding /etc/ups/upsmon.conf  
Mar 15 17:20:52 sme70 esmith::event[3814]: expanding /etc/ups/ups.conf  
Mar 15 17:20:52 sme70 esmith::event[3814]: expanding /etc/logrotate.d/syslog  
Mar 15 17:20:52 sme70 esmith::event[3814]: expanding /etc/samba/smbusers  
Mar 15 17:20:52 sme70 esmith::event[3814]: expanding /etc/samba/smb.conf  
Mar 15 17:20:52 sme70 esmith::event[3814]: expanding /etc/e-smith/sql/init/50turba_upgrade  
Mar 15 17:20:52 sme70 esmith::event[3814]: expanding /etc/e-smith/sql/init/21horde.mysql_set_password  
Mar 15 17:20:52 sme70 esmith::event[3814]: expanding /etc/e-smith/sql/init/20mysql_migrate_horde  
Mar 15 17:20:52 sme70 esmith::event[3814]: expanding /etc/e-smith/sql/init/40mysql_create_indexes  
Mar 15 17:20:52 sme70 esmith::event[3814]: expanding /etc/e-smith/sql/init/30mysql_create_tables  
Mar 15 17:20:52 sme70 esmith::event[3814]: expanding /etc/e-smith/sql/init/60migrate-imp-to-turba  
Mar 15 17:20:52 sme70 esmith::event[3814]: expanding /etc/e-smith/sql/init/40mysql.create.turba  
Mar 15 17:20:52 sme70 esmith::event[3814]: expanding /etc/e-smith/sql/init/75horde-2.2_to_3.0  
Mar 15 17:20:52 sme70 esmith::event[3814]: expanding /home/httpd/html/horde/scripts/db/mysql_set_password.sql  
Mar 15 17:20:52 sme70 esmith::event[3814]: generic_template_expand=action|Event|post-upgrade|Action|generic_template_expand|Start|1142439650 569201|End|1142439652 864892|Elapsed|2.295691
Mar 15 17:20:52 sme70 esmith::event[3814]: Running event handler: /etc/e-smith/events/post-upgrade/S05imap-relocate-maildirs
Mar 15 17:20:53 sme70 esmith::event[3814]: S05imap-relocate-maildirs=action|Event|post-upgrade|Action|S05imap-relocate-maildirs|Start|1142439652 865183|End|1142439653 25061|Elapsed|0.159878
Mar 15 17:20:53 sme70 esmith::event[3814]: Running event handler: /etc/e-smith/events/post-upgrade/S05init-accounts
Mar 15 17:20:53 sme70 esmith::event[3814]: S05init-accounts=action|Event|post-upgrade|Action|S05init-accounts|Start|1142439653 25428|End|1142439653 233564|Elapsed|0.208136
Mar 15 17:20:53 sme70 esmith::event[3814]: Running event handler: /etc/e-smith/events/post-upgrade/S10conf-startup
Mar 15 17:20:53 sme70 /sbin/e-smith/db[3834]: /home/e-smith/db/configuration: OLD bootstrap-console=service|ForceSave|no|Run|no|status|enabled
Mar 15 17:20:53 sme70 /sbin/e-smith/db[3834]: /home/e-smith/db/configuration: NEW bootstrap-console=service|ForceSave|yes|Run|no|status|enabled
Mar 15 17:20:53 sme70 /sbin/e-smith/db[3834]: /home/e-smith/db/configuration: OLD bootstrap-console=service|ForceSave|yes|Run|no|status|enabled
Mar 15 17:20:53 sme70 /sbin/e-smith/db[3834]: /home/e-smith/db/configuration: NEW bootstrap-console=service|ForceSave|yes|Run|yes|status|enabled
Mar 15 17:20:53 sme70 esmith::event[3814]: S10conf-startup=action|Event|post-upgrade|Action|S10conf-startup|Start|1142439653 233927|End|1142439653 309493|Elapsed|0.075566
Mar 15 17:20:53 sme70 esmith::event[3814]: Running event handler: /etc/e-smith/events/post-upgrade/S15group-modify-unix
Mar 15 17:20:53 sme70 esmith::event[3814]: S15group-modify-unix=action|Event|post-upgrade|Action|S15group-modify-unix|Start|1142439653 309939|End|1142439653 430009|Elapsed|0.12007
Mar 15 17:20:53 sme70 esmith::event[3814]: Running event handler: /etc/e-smith/events/post-upgrade/S15init-ibays
Mar 15 17:20:53 sme70 esmith::event[3814]: S15init-ibays=action|Event|post-upgrade|Action|S15init-ibays|Start|1142439653 430371|End|1142439653 571957|Elapsed|0.141586
Mar 15 17:20:53 sme70 esmith::event[3814]: Running event handler: /etc/e-smith/events/post-upgrade/S15user-modify-unix
Mar 15 17:20:53 sme70 esmith::event[3814]: S15user-modify-unix=action|Event|post-upgrade|Action|S15user-modify-unix|Start|1142439653 572323|End|1142439653 697727|Elapsed|0.125404
Mar 15 17:20:53 sme70 esmith::event[3814]: Running event handler: /etc/e-smith/events/post-upgrade/S20update-passwd
Mar 15 17:20:53 sme70 esmith::event[3814]: S20update-passwd=action|Event|post-upgrade|Action|S20update-passwd|Start|1142439653 698090|End|1142439653 820434|Elapsed|0.122344
Mar 15 17:20:53 sme70 esmith::event[3814]: Running event handler: /etc/e-smith/events/post-upgrade/S20user-create-profiledir
Mar 15 17:20:53 sme70 esmith::event[3814]: S20user-create-profiledir=action|Event|post-upgrade|Action|S20user-create-profiledir|Start|1142439653 820881|End|1142439653 986709|Elapsed|0.165828
Mar 15 17:20:53 sme70 esmith::event[3814]: Running event handler: /etc/e-smith/events/post-upgrade/S25count-active-user-accounts
Mar 15 17:20:54 sme70 esmith::event[3814]: S25count-active-user-accounts=action|Event|post-upgrade|Action|S25count-active-user-accounts|Start|1142439653 987072|End|1142439654 114749|Elapsed|0.127677
Mar 15 17:20:54 sme70 esmith::event[3814]: Running event handler: /etc/e-smith/events/post-upgrade/S30conf-modules
Mar 15 17:20:57 sme70 esmith::event[3814]: S30conf-modules=action|Event|post-upgrade|Action|S30conf-modules|Start|1142439654 115113|End|1142439657 197612|Elapsed|3.082499
Mar 15 17:20:57 sme70 esmith::event[3814]: Running event handler: /etc/e-smith/events/post-upgrade/S50create-mnt-floppy
Mar 15 17:20:57 sme70 esmith::event[3814]: S50create-mnt-floppy=action|Event|post-upgrade|Action|S50create-mnt-floppy|Start|1142439657 197993|End|1142439657 241858|Elapsed|0.043865
Mar 15 17:20:57 sme70 esmith::event[3814]: Running event handler: /etc/e-smith/events/post-upgrade/S90grub-install-raid
Mar 15 17:20:57 sme70 esmith::event[3814]: Forcing grub to rescan devices  
Mar 15 17:20:57 sme70 esmith::event[3814]: Probing devices to guess BIOS drives. This may take a long time.  
Mar 15 17:20:57 sme70 kernel: cdrom: open failed.
Mar 15 17:20:57 sme70 esmith::event[3814]: /dev/md1 does not have any corresponding BIOS drive.  
Mar 15 17:20:57 sme70 esmith::event[3814]: Calling grub-install on /dev/hda  
Mar 15 17:20:57 sme70 esmith::event[3814]: Probing devices to guess BIOS drives. This may take a long time.  
Mar 15 17:20:57 sme70 esmith::event[3814]:  
Mar 15 17:20:57 sme70 esmith::event[3814]:  
Mar 15 17:20:57 sme70 esmith::event[3814]:     GNU GRUB  version 0.95  (640K lower / 3072K upper memory)  
Mar 15 17:20:57 sme70 esmith::event[3814]:  
Mar 15 17:20:57 sme70 esmith::event[3814]:  [ Minimal BASH-like line editing is supported.  For the first word, TAB  
Mar 15 17:20:57 sme70 esmith::event[3814]:    lists possible command completions.  Anywhere else TAB lists the possible  
Mar 15 17:20:57 sme70 esmith::event[3814]:    completions of a device/filename.]  
Mar 15 17:20:57 sme70 esmith::event[3814]: grub> device (hd0) /dev/hda  
Mar 15 17:20:57 sme70 esmith::event[3814]: grub> root (hd0,0)  
Mar 15 17:20:57 sme70 esmith::event[3814]:  Filesystem type is ext2fs, partition type 0xfd  
Mar 15 17:20:57 sme70 esmith::event[3814]: grub> setup (hd0)  
Mar 15 17:20:57 sme70 esmith::event[3814]:  Checking if "/boot/grub/stage1" exists... no  
Mar 15 17:20:57 sme70 esmith::event[3814]:  Checking if "/grub/stage1" exists... yes  
Mar 15 17:20:57 sme70 esmith::event[3814]:  Checking if "/grub/stage2" exists... yes  
Mar 15 17:20:57 sme70 esmith::event[3814]:  Checking if "/grub/e2fs_stage1_5" exists... yes  
Mar 15 17:20:57 sme70 esmith::event[3814]:  Running "embed /grub/e2fs_stage1_5 (hd0)"...  16 sectors are embedded.  
Mar 15 17:20:57 sme70 esmith::event[3814]: succeeded  
Mar 15 17:20:57 sme70 esmith::event[3814]:  Running "install /grub/stage1 (hd0) (hd0)1+16 p (hd0,0)/grub/stage2 /grub/grub.conf"... succeeded  
Mar 15 17:20:57 sme70 esmith::event[3814]: Done.  
Mar 15 17:20:57 sme70 esmith::event[3814]: grub> Skipping grub-install on hd1  
Mar 15 17:20:57 sme70 esmith::event[3814]: S90grub-install-raid=action|Event|post-upgrade|Action|S90grub-install-raid|Start|1142439657 242220|End|1142439657 814416|Elapsed|0.572196
Mar 15 17:20:57 sme70 esmith::event[3814]: Running event handler: /etc/e-smith/events/post-upgrade/S90testing-conf
Mar 15 17:20:57 sme70 esmith::event[3814]: S90testing-conf=action|Event|post-upgrade|Action|S90testing-conf|Start|1142439657 814654|End|1142439657 945840|Elapsed|0.131186
Mar 15 17:20:57 sme70 /etc/e-smith/web/panels/manager/cgi-bin/backup[3735]: /etc/e-smith/restore: OLD restore=status|finish|0|start|1142439614|state|running
Mar 15 17:20:57 sme70 /etc/e-smith/web/panels/manager/cgi-bin/backup[3735]: /etc/e-smith/restore: NEW restore=status|finish|0|start|1142439614|state|complete
Mar 15 17:20:57 sme70 /etc/e-smith/web/panels/manager/cgi-bin/backup[3735]: /etc/e-smith/restore: OLD restore=status|finish|0|start|1142439614|state|complete
Mar 15 17:20:57 sme70 /etc/e-smith/web/panels/manager/cgi-bin/backup[3735]: /etc/e-smith/restore: NEW restore=status|finish|1142439657|start|1142439614|state|complete
Mar 15 17:21:22 sme70 esmith::event[3935]: Processing event: reboot  
Mar 15 17:21:22 sme70 esmith::event[3935]: Running event handler: /etc/e-smith/events/actions/adjust-services
Mar 15 17:21:23 sme70 esmith::event[3935]: adjusting supervised pppoe (down)  
Mar 15 17:21:23 sme70 esmith::event[3935]: adjusting supervised pppoe (stop)  
Mar 15 17:21:23 sme70 esmith::event[3935]: adjusting supervised dhcpcd (down)  
Mar 15 17:21:23 sme70 esmith::event[3935]: adjusting supervised dhcpcd (stop)  
Mar 15 17:21:23 sme70 esmith::event[3935]: adjust-services=action|Event|reboot|Action|adjust-services|Start|1142439682 997698|End|1142439683 149967|Elapsed|0.152269
Mar 15 17:21:23 sme70 esmith::event[3935]: Running event handler: /etc/e-smith/events/reboot/S99reboot
Mar 15 17:21:23 sme70 shutdown: shutting down for system reboot
Mar 15 17:21:23 sme70 init: Switching to runlevel: 6
Mar 15 17:21:23 sme70 esmith::event[3935]: S99reboot=action|Event|reboot|Action|S99reboot|Start|1142439683 150355|End|1142439683 301090|Elapsed|0.150735
Mar 15 17:21:24 sme70 haldaemon: haldaemon -TERM succeeded
Mar 15 17:21:24 sme70 messagebus: messagebus -TERM succeeded
Mar 15 17:21:24 sme70 atalk: papd shutdown succeeded
Mar 15 17:21:24 sme70 atalk:   Unregistering sme70:Workstation: succeeded
Mar 15 17:21:24 sme70 atalk:   Unregistering sme70:netatalk: succeeded
Mar 15 17:21:24 sme70 atalkd[3259]: done
Mar 15 17:21:24 sme70 atalk: atalkd shutdown succeeded
Mar 15 17:21:24 sme70 afpd[3471]: shutting down on signal 15
Mar 15 17:21:24 sme70 atalk: afpd shutdown succeeded
Mar 15 17:21:25 sme70 atalk: cnid_metad shutdown succeeded
Mar 15 17:21:25 sme70 acpid: acpid shutdown succeeded
Mar 15 17:21:25 sme70 crond: crond shutdown succeeded
Mar 15 17:20:57 sme70 kernel: cdrom: open failed.
Mar 15 17:21:25 sme70 kernel: Kernel logging (proc) stopped.
Mar 15 17:21:25 sme70 kernel: Kernel log daemon terminating.
Mar 15 17:21:26 sme70 syslog: klogd shutdown succeeded
Mar 15 17:21:26 sme70 exiting on signal 15
Title: Tape restore error
Post by: stian on March 21, 2006, 08:30:05 AM
Does everyone have tape backup working? I cant figure out the problem... Could anyone point me to where I find the driver that is beeing loaded for the AHA 29320U-R in 7.0, so I can copy it to a 6.0.1 distro. The driver doesnt load in older versions of sme... Also where should I put it in the older versions?
Title: Sony AIT Ide Tape drive problems
Post by: compsos on March 22, 2006, 12:31:13 PM
Hi

We have encounted the following using a Sony AIT IDE interface drive
OS SMEServer 7pre4 & RC1
command flexbackup -test-tape-drive

Writing test file #1
buffer (writer): write of data failed: Invalid argument
bytes to write=32768, bytes written=-1, total written          0K
SCSI 2 tape drive:
File number=0, block number=0, partition=0.
Tape block size 0 bytes. Density code 0x30 (AIT-1 or MLR3).
Soft error count since last status=0
General status bits on (41010000):
 BOT ONLINE IM_REP_EN

Have tried different settings but no change. I think the issue is in the buffer rather than the hardware.

Anyone have any solutions or test procedure?