Forum Discussion

Wired_IT's avatar
Wired_IT
Level 2
9 years ago

Phase 2 Import fails - status 85 and (191)

I hope someone can please help me with this problem?

 

I have been asked to restore data from another NBU domain, the data is on one tape. I have successfully completed the Phase 1 import, then started the Phase 2 import but it fails with these messages:

12/31/2015 14:56:49 - begin reading
12/31/2015 15:11:50 - Error bptm (pid=1708) cannot read image from media id GAW050, drive index 0, err = 23
12/31/2015 15:11:50 - Info bptm (pid=1708) EXITING with status 85 <----------
12/31/2015 15:11:50 - Error bpimport (pid=4236) Import of policy BDS-ACP-Windows-VMs, schedule Weekly-Full (ACPBDER01_1448737342) failed, media read error.
12/31/2015 15:11:50 - Error bpimport (pid=4236) Status = no images were successfully processed.
12/31/2015 15:11:51 - end Import; elapsed time 0:15:46
no images were successfully processed  (191)

I have checked the block size of the tape and its 262144 - i have then created a SIZE_DATA_BUFFERS file with the value 262144 in  location \Program Files\Veritas\NetBackup\db\config, this hasnt changed the error messages?

I have enabled bptm logging and an extract of the log showing the error is below::

 

15:10:26.068 [964.4824] <2> report_drives: FILE = D:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_IBM.ULT3580-HH5.000
15:10:26.068 [964.4824] <2> main: Sending [EXIT STATUS 0] to NBJM
15:10:26.068 [964.4824] <2> bptm: EXITING with status 0 <----------
15:11:50.324 [1708.2660] <2> openTpreqFile: tpreq_file: D:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_IBM.ULT3580-HH5.000, serial_num: 1068010079
15:11:50.324 [1708.2660] <2> get_drive_path: SCSI coordinates {5,0,0,0}, dos_path \\.\Tape0, pnp_path \\?\scsi#sequential&ven_ibm&prod_ult3580-hh5#5&1a5f4c65&0&000000#{53f5630b-b6bf-11d0-94f2-00a0c91efb8b}
15:11:50.324 [1708.2660] <2> check_serial_num: serial number match for drive with SCSI coordinates {5,0,0,0}, dos_path \\.\Tape0, drive serial number 1068010079, expected serial number 1068010079
15:11:50.387 [1708.2660] <2> init_tape: \\.\Tape0 (SCSI coordinates {5,0,0,0}) configured with blocksize 0
15:11:50.402 [1708.2660] <2> init_tape: \\.\Tape0 (SCSI coordinates {5,0,0,0}) has compression enabled
15:11:50.402 [1708.2660] <2> io_open: SCSI RESERVE (D:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_IBM.ULT3580-HH5.000)
15:11:50.402 [1708.2660] <2> openTpreqFile: tpreq_file: D:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_IBM.ULT3580-HH5.000, serial_num: 1068010079
15:11:50.402 [1708.2660] <2> get_drive_path: SCSI coordinates {5,0,0,0}, dos_path \\.\Tape0, pnp_path \\?\scsi#sequential&ven_ibm&prod_ult3580-hh5#5&1a5f4c65&0&000000#{53f5630b-b6bf-11d0-94f2-00a0c91efb8b}
15:11:50.402 [1708.2660] <2> check_serial_num: serial number match for drive with SCSI coordinates {5,0,0,0}, dos_path \\.\Tape0, drive serial number 1068010079, expected serial number 1068010079
15:11:50.433 [1708.2660] <2> init_tape: \\.\Tape0 (SCSI coordinates {5,0,0,0}) configured with blocksize 0
15:11:50.433 [1708.2660] <2> io_open: file D:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_IBM.ULT3580-HH5.000 successfully opened (mode 0)
15:11:50.433 [1708.2660] <2> tape_error_rec: locating to absolute block number 3 for error recovery
15:11:50.433 [1708.2660] <2> tape_error_rec: absolute block position after read position is 3
15:11:50.449 [1708.2660] <2> read_data: ReadFile returned FALSE, Data error (cyclic redundancy check). (23);bytes = 0
15:11:50.449 [1708.2660] <2> read_data: attempting read error recovery, err = 23
15:11:50.449 [1708.2660] <2> tape_error_rec: error recovery to block 3 requested
15:11:50.449 [1708.2660] <16> read_data: cannot read image from media id GAW050, drive index 0, err = 23
15:11:50.449 [1708.2660] <2> send_MDS_msg: DEVICE_STATUS 1 28 netbackup GAW050 4000022 IBM.ULT3580-HH5.000 2000002 READ_ERROR 0 0
15:11:50.511 [1708.2660] <2> log_media_error: successfully wrote to error file - 12/31/15 15:11:50 GAW050 0 READ_ERROR IBM.ULT3580-HH5.000
15:11:50.511 [1708.2660] <2> notify: executing - D:\Program Files\Veritas\NetBackup\bin\restore_notify.cmd bptm ACPBDER01_1448737342 import
15:11:50.808 [1708.2660] <2> check_error_history: just tpunmount: called from bptm line 13238, EXIT_Status = 85
15:11:50.808 [1708.2660] <2> io_close: closing D:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_IBM.ULT3580-HH5.000, from bptm.c.16674
15:11:50.808 [1708.2660] <2> openTpreqFile: tpreq_file: D:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_IBM.ULT3580-HH5.000, serial_num: 1068010079
15:11:50.808 [1708.2660] <2> get_drive_path: SCSI coordinates {5,0,0,0}, dos_path \\.\Tape0, pnp_path \\?\scsi#sequential&ven_ibm&prod_ult3580-hh5#5&1a5f4c65&0&000000#{53f5630b-b6bf-11d0-94f2-00a0c91efb8b}
15:11:50.808 [1708.2660] <2> check_serial_num: serial number match for drive with SCSI coordinates {5,0,0,0}, dos_path \\.\Tape0, drive serial number 1068010079, expected serial number 1068010079
15:11:50.823 [1708.2660] <2> init_tape: \\.\Tape0 (SCSI coordinates {5,0,0,0}) configured with blocksize 0
15:11:50.839 [1708.2660] <2> init_tape: \\.\Tape0 (SCSI coordinates {5,0,0,0}) has compression enabled
15:11:50.839 [1708.2660] <2> io_open: SCSI RESERVE
15:11:50.839 [1708.2660] <2> io_open: file D:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_IBM.ULT3580-HH5.000 successfully opened (mode 2)
15:11:50.839 [1708.2660] <2> process_tapealert: TapeAlert returned 0x00000000 0x00000000 (from tpunmount)
15:11:50.839 [1708.2660] <2> io_close: closing D:\Program Files\Veritas\NetBackup\db\media\tpreq\drive_IBM.ULT3580-HH5.000, from bptm.c.16710
15:11:50.839 [1708.2660] <2> drivename_write: Called with mode 1
15:11:50.839 [1708.2660] <2> drivename_unlock: unlocked
15:11:50.839 [1708.2660] <2> drivename_checklock: Called
15:11:50.839 [1708.2660] <2> drivename_lock: lock established
15:11:50.839 [1708.2660] <2> drivename_unlock: unlocked
15:11:50.839 [1708.2660] <2> drivename_close: Called for file IBM.ULT3580-HH5.000
15:11:50.839 [1708.2660] <2> tpunmount: NOP: MEDIA_DONE 0 11 0 GAW050 4000022 180 {F97B6505-0125-4B0A-9BCF-51A0F2120651}
15:11:50.839 [1708.2660] <2> bptm: Calling tpunmount for media GAW050
15:11:50.839 [1708.2660] <2> send_MDS_msg: MEDIA_DONE 0 11 0 GAW050 4000022 180 {F97B6505-0125-4B0A-9BCF-51A0F2120651}
15:11:50.839 [1708.2660] <2> packageBptmResourceDoneMsg: msg (MEDIA_DONE 0 11 0 GAW050 4000022 180 {F97B6505-0125-4B0A-9BCF-51A0F2120651})
15:11:50.839 [1708.2660] <2> packageBptmResourceDoneMsg: keyword MEDIA_DONE version 0 jobid 11 copyNum 0 mediaId GAW050 mediaKey 4000022 unloadDelay 180 allocId {F97B6505-0125-4B0A-9BCF-51A0F2120651}
15:11:50.839 [1708.2660] <2> packageBptmResourceDoneMsg: returns 0
15:11:50.839 [1708.2660] <2> JobInst::sendIrmMsg: returning
15:11:50.839 [1708.2660] <2> bptm: EXITING with status 85 <----------

Can anyone suggest why i cant read this tape?

Thanks

 

7.7
Backup and Recovery
NetBackup
Windows Server (2003-2008)
  • Wired_IT's avatar
    Wired_IT
    9 years ago

    Thanks for all the input, the Data was actually encrypted on the source domain using netbackup encryption …. this was identified by a clue in the logs

     

    When I look in the log I saw this:

    [5904.1296] <2> manage_drive_attributes: MediaPool [ENCR_BrewinDolphin], MediaLabel [MEDIA=GAW050;]

     

    The ENCR_ prefix is a requirement for NBU KMS encrytpion option!!

     

    and if you try to read a tape thats KMS encrypted this way it allows you to read the image list (phase 1 import) but fails on phase 2 import when it tries to read the data/file list

     

    So i had to contact the data owner for the key/passphrase etc and i now have to setup KMS and retry the restore.....

  • areznik's avatar
    areznik
    Level 5
    9 years ago

    Is this the only tape that has the problem? Is this the only drive? 

    Try to run some tests using defferent tapes and drives to isolate the error. If you find that you can import another tape using the same drive, chances are - you have a bad tape. 

  • Marianne's avatar
    Marianne
    Level 6
    9 years ago
    " cyclic redundancy check" normally means that the tape is bad. Sorry.
  • Marianne's avatar
    Marianne
    Level 6
    9 years ago
    This TN is for Backup Exec, but the error and possible reasons are the same: https://www.veritas.com/support/en_US/article.TECH5433.html
  • mph999's avatar
    mph999
    Level 6
    9 years ago

    Agree with Marianne ...

    15:11:50.449 [1708.2660] <2> read_data: ReadFile returned FALSE, Data error (cyclic redundancy check). (23);bytes = 0


    That is either a faulty drive or media.

    Persoanlly, in 12 odd years of being involved with backups, every singlr CRC error I have see has been faulty hardware, but it can be caused by the media, I've just never seen it myself.

    Changing the blocksize makes no fdifference to imports / restores, the blocksize used is the blocksize that the tape was writtem with, it cannot be changed.

    However, the fact you created the SIZE_DATA_BUFFERS file shows that previously you were using the default which I think is 634K which with LTO drives will probably be giving terrible performance.262144 (256k) shold be good, though you may want to create the file NUMBER_DATA_BUFFERS in the same directy and try a value or 128 or 256 to see if that improves things further. (Try a backup and see how fast it goes).

  • Wired_IT's avatar
    Wired_IT
    Level 2
    9 years ago

    Thanks for all the input, the Data was actually encrypted on the source domain using netbackup encryption …. this was identified by a clue in the logs

     

    When I look in the log I saw this:

    [5904.1296] <2> manage_drive_attributes: MediaPool [ENCR_BrewinDolphin], MediaLabel [MEDIA=GAW050;]

     

    The ENCR_ prefix is a requirement for NBU KMS encrytpion option!!

     

    and if you try to read a tape thats KMS encrypted this way it allows you to read the image list (phase 1 import) but fails on phase 2 import when it tries to read the data/file list

     

    So i had to contact the data owner for the key/passphrase etc and i now have to setup KMS and retry the restore.....