Skip to main content
commvault.com commvault.com
Solved

error to restore database

  • September 12, 2023
  • 5 replies
  • 1049 views
M
Byte
Forum|alt.badge.img+1

Hi all!

I have a problem. I can't restore the database after a backup. The backup itself goes through without errors, but when restoring the DB, the task freezes at 5% and after some time error 30:299 appears.
Commvault ver. 11.23.42
SQL server 2019.
Volume DB 1.3 TB.
Log File volume 255 Gb.
What I tried:
Increased time VDI 2700,
I tried to restore it as files,
I tried restoring to different servers.
SQLiDA event id 1 error appears in the events file.
Previously, this database was restored without problems. I do not understand what the problem is. The SQLiDA log file with an error is attached. Can anyone help?

Best answer by Sujay kumar

@MaiklIT SQL Restore job is getting failed due to read error as per below logs lines, there seems to be issue in reading the data from undelying media , you can consult MM support team for any further assistance via incident.
as per your description setup currenlty on  11.23.42 depreacted version , please plan to upgrade to latest suported version as well a general suggestion
 

cvd.log
***************
24984 2b6c  09/13 13:43:14 527433 9-# [DM_READER  ] DataReader::Read: Failed to READ data from ARCHIVE FILE [1371105] COPY [9]. PHYSICAL LEN = [96] LOGICAL LEN =[0]. TAGHEADER = [1]
24984 2b6c  09/13 13:43:14 527433 1751-# [FSRESTHEAD ] Encountered error when reading tagHdr from media
24984 2b6c  09/13 13:43:14 527433 1751-# [FSRESTHEAD ] Encountered error when reading tagHdr from media
24984 2b6c  09/13 13:43:14 527433 1751-# [FSRESTHEAD ] SendDataBuffer: fsRestoreRead reported failure
24984 2b6c  09/13 13:43:14 527433 1751-# [FSRESTHEAD ] SendCtrlBuf: Sending Ctrl Msg 0x87
24984 28e8  09/13 13:43:15 ###### media_fs::GetMountPathInfoFromReg: Error: getMagneticMountPathInfo failed to retrieve mount path information for 43. Error = 0
24984 28e8  09/13 13:43:15 527433 11-# [MEDIAFS    ] media_fs::GetMountPathInfo: Failed to look up mount path info from registry for MPID 43, CCID 2.
24984 28e8  09/13 13:43:15 527433 11-# [DM_BASE    ] GetSfileInfo: Failed to get MP Info for Sfile 1, Chunk [43, 259402, 3748639], CCId=2
24984 28e8  09/13 13:43:15 527433 11-# [DM_BASE    ] AddLinkInfoToSfileMap: GetSfileHandleInfo failed for Sfile 1, Chunk [43, 259402, 3748639], iRet = -1
24984 28e8  09/13 13:43:15 527433 11-# [DM_BASE    ] ReadAheadAllRuns: Ignoring read for Sfile 1 [43, 259402, 3748639] due to Err=7, MMErr=30079
24984 6454  09/13 13:43:16 527433 7-# [DM_BASE    ] SyncWithReadAheadThread: Error found while reading Sfile 1 for Link Chnk [43, 259404, 3748637]. Err=7, MMErr=30079
24984 6454  09/13 13:43:16 527433 7-# [DM_BASE    ] SyncWithReadAheadThread IsMarkChunkBadMMError returned false for Err [30079], Line [0], Path [].
24984 6454  09/13 13:43:16 527433 7-# [DM_BASE    ] ReadTagHeader: Cannot sync up with the read ahead thread. iRet [-1]
24984 6454  09/13 13:43:16 527433 7-# [DM_BASE    ] [ERROR] Invalid Read size - -1
24984 6454  09/13 13:43:16 527433 7-# [DM_READER  ] DataReader::Read: Failed to READ data from ARCHIVE FILE [1371103] COPY [9]. PHYSICAL LEN = [96] LOGICAL LEN =[0]. TAGHEADER = [1]
24984 6454  09/13 13:43:16 527433 1749-# [FSRESTHEAD ] Encountered error when reading tagHdr from media
24984 6454  09/13 13:43:16 527433 1749-# [FSRESTHEAD ] Encountered error when reading tagHdr from media
24984 6454  09/13 13:43:16 527433 1749-# [FSRESTHEAD ] SendDataBuffer: fsRestoreRead reported failure
24984 6454  09/13 13:43:16 527433 1749-# [FSRESTHEAD ] SendCtrlBuf: Sending Ctrl Msg 0x87
24984 645c  09/13 13:43:26 527433 1744-# [FSRESTHEAD ] Waiting for pipeline buf. SndIdx [0/3], RCId [11]
24984 259c  09/13 13:43:29 ###### media_fs::GetMountPathInfoFromReg: Error: getMagneticMountPathInfo failed to retrieve mount path information for 43. Error = 

sqlida.log
****************************
2704  fa8   09/13 13:43:15 527433 SqlDataReader::readPipelineData(700): -Debug-: Received PL_DATA for file [NPF_OPS_CO], Processing...
2704  1c78  09/13 13:43:17 527433 SqlDataReader::readPipelineData(700): -Debug-: Received PL_DATA for file [NPF_OPS_CO], Processing...
2704  23cc  09/13 13:43:27 527433 SqlDataReader::readPipelineData(700): -Debug-: Received PL_DATA for file [NPF_OPS_CO], Processing...
2704  1bdc  09/13 13:43:28 527433 SqlDataReader::readPipelineData(700): -Debug-: Received PL_DATA for file [NPF_OPS_CO], Processing...
2704  2a64  09/13 13:43:28 527433 SqlDataReader::readPipelineData(626): -Debug-: Received PL_FS_READ_ERR from pipeline read
2704  28bc  09/13 13:43:28 527433 CCvSQLVDI::GetBytesForRestore(564): -Debug-: GetCommand returned  [0x80770004].
2704  28bc  09/13 13:43:28 527433 SqlDataReader::readDBData() - Failed to get backup data. GetBytesForRestore failed.
2704  2688  09/13 13:43:28 527433 CCvSQLVDI::GetBytesForRestore(564): -Debug-: GetCommand returned  [0x80770004].
2704  2688  09/13 13:43:28 527433 SqlDataReader::readDBData() - Failed to get backup data. GetBytesForRestore failed.
2704  1a68  09/13 13:43:28 527433 CCvSQLVDI::GetBytesForRestore(564): -Debug-: GetCommand returned  [0x80770004].
2704  1a68  09/13 13:43:28 527433 SqlDataReader::readDBData() - Failed to get backup data. GetBytesForRestore failed.
2704  12bc  09/13 13:43:28 527433 CCvSQLVDI::GetBytesForRestore(564): -Debug-: GetCommand returned  [0x80770004].
2704  288c  09/13 13:43:28 527433 SqlDataReader::readDBData() - Failed to write the data to the sql server.
2704  2054  09/13 13:43:28 527433 CCvSQLVDI::GetBytesForRestore(564): -Debug-: GetCommand returned  [0x80770004].
2704  23cc  09/13 13:43:28 527433 CCvSQLVDI::GetBytesForRestore(564): -Debug-: GetCommand returned  [0x80770004].
2704  23cc  09/13 13:43:28 527433 SqlDataReader::readDBData() - Failed to get backup data. GetBytesForRestore failed.
2704  12bc  09/13 13:43:28 527433 SqlDataReader::readDBData() - Failed to get backup data. GetBytesForRestore failed.
2704  2054  09/13 13:43:28 527433 SqlDataReader::readDBData() - Failed to get backup data. GetBytesForRestore failed.
2704  fa8   09/13 13:43:28 527433 CCvSQLVDI::GetBytesForRestore(564): -Debug-: GetCommand returned  [0x80770004].
2704  fa8   09/13 13:43:28 527433 SqlDataReader::readDBData() - Failed to get backup data. GetBytesForRestore failed.
2704  9ec   09/13 13:43:28 527433 CCvSQLVDIBase::RunQuery() - Error: Microsoft.SqlServer.Management.Common.ExecutionFailureException:RESTORE DATABASE is terminating abnormally.
An exception occurred while executing a Transact-SQL statement or batch..
2704  1bdc  09/13 13:43:29 527433 SqlDataReader::readDBData() - Failed to write the data to the sql server.
2704  2078  09/13 13:43:35 527433 SqlDataReader::readDBData() - Failed to write the data to the sql server.
2704  1c78  09/13 13:43:36 527433 SqlDataReader::readDBData() - Failed to write the data to the sql server.
2704  21c4  09/13 13:43:36 527433 SqlDataTransferHandler::startTransfer(308): -Debug-: Restore has failed. Closing archive files.

Best Regards
Sujay kumar

View original
1 Attachments
    Did this answer your question?

    5 replies

    Rajiv
    Vaulter
    Forum|alt.badge.img+12
    • RajivVaulter
    • Vaulter
    • 323 replies
    • September 13, 2023

    Hello @MaiklIT Does it restore anything or there is no throughput at all? Can you try to double the VDI timeout for the destination client eg. 7200 and observe you are not facing any resources (RAM/CPU) issues on the destination client?

    Best,

    Rajiv Singal

    M
    Byte
    Forum|alt.badge.img+1
    • MaiklIT
    • Author
    • Byte
    • 3 replies
    • September 13, 2023

    Hello @Rajiv Thanks for your reply! 


    I see that the client is writing to disk at about 800MB/sec. But there is no network traffic.
    Server configuration: CPU 4 RAM 48 GB and don’t have problem.
    I increased vdi to 7200 but it didn't help. I collected a new log and post it here.

     

    1 Attachments
    Rajiv
    Vaulter
    Forum|alt.badge.img+12
    • RajivVaulter
    • Vaulter
    • 323 replies
    • September 13, 2023

    Hello @MaiklIT You are attempting the restore to a disk, correct? Also, can you please try to use a different MA after selecting browse and restore and see if that helps?

    Best,

    Rajiv Singal

    S
    Vaulter
    Forum|alt.badge.img+7
    • Sujay kumarVaulter
    • Vaulter
    • 70 replies
    • Answer
    • September 13, 2023

    @MaiklIT SQL Restore job is getting failed due to read error as per below logs lines, there seems to be issue in reading the data from undelying media , you can consult MM support team for any further assistance via incident.
    as per your description setup currenlty on  11.23.42 depreacted version , please plan to upgrade to latest suported version as well a general suggestion
     

    cvd.log
    ***************
    24984 2b6c  09/13 13:43:14 527433 9-# [DM_READER  ] DataReader::Read: Failed to READ data from ARCHIVE FILE [1371105] COPY [9]. PHYSICAL LEN = [96] LOGICAL LEN =[0]. TAGHEADER = [1]
    24984 2b6c  09/13 13:43:14 527433 1751-# [FSRESTHEAD ] Encountered error when reading tagHdr from media
    24984 2b6c  09/13 13:43:14 527433 1751-# [FSRESTHEAD ] Encountered error when reading tagHdr from media
    24984 2b6c  09/13 13:43:14 527433 1751-# [FSRESTHEAD ] SendDataBuffer: fsRestoreRead reported failure
    24984 2b6c  09/13 13:43:14 527433 1751-# [FSRESTHEAD ] SendCtrlBuf: Sending Ctrl Msg 0x87
    24984 28e8  09/13 13:43:15 ###### media_fs::GetMountPathInfoFromReg: Error: getMagneticMountPathInfo failed to retrieve mount path information for 43. Error = 0
    24984 28e8  09/13 13:43:15 527433 11-# [MEDIAFS    ] media_fs::GetMountPathInfo: Failed to look up mount path info from registry for MPID 43, CCID 2.
    24984 28e8  09/13 13:43:15 527433 11-# [DM_BASE    ] GetSfileInfo: Failed to get MP Info for Sfile 1, Chunk [43, 259402, 3748639], CCId=2
    24984 28e8  09/13 13:43:15 527433 11-# [DM_BASE    ] AddLinkInfoToSfileMap: GetSfileHandleInfo failed for Sfile 1, Chunk [43, 259402, 3748639], iRet = -1
    24984 28e8  09/13 13:43:15 527433 11-# [DM_BASE    ] ReadAheadAllRuns: Ignoring read for Sfile 1 [43, 259402, 3748639] due to Err=7, MMErr=30079
    24984 6454  09/13 13:43:16 527433 7-# [DM_BASE    ] SyncWithReadAheadThread: Error found while reading Sfile 1 for Link Chnk [43, 259404, 3748637]. Err=7, MMErr=30079
    24984 6454  09/13 13:43:16 527433 7-# [DM_BASE    ] SyncWithReadAheadThread IsMarkChunkBadMMError returned false for Err [30079], Line [0], Path [].
    24984 6454  09/13 13:43:16 527433 7-# [DM_BASE    ] ReadTagHeader: Cannot sync up with the read ahead thread. iRet [-1]
    24984 6454  09/13 13:43:16 527433 7-# [DM_BASE    ] [ERROR] Invalid Read size - -1
    24984 6454  09/13 13:43:16 527433 7-# [DM_READER  ] DataReader::Read: Failed to READ data from ARCHIVE FILE [1371103] COPY [9]. PHYSICAL LEN = [96] LOGICAL LEN =[0]. TAGHEADER = [1]
    24984 6454  09/13 13:43:16 527433 1749-# [FSRESTHEAD ] Encountered error when reading tagHdr from media
    24984 6454  09/13 13:43:16 527433 1749-# [FSRESTHEAD ] Encountered error when reading tagHdr from media
    24984 6454  09/13 13:43:16 527433 1749-# [FSRESTHEAD ] SendDataBuffer: fsRestoreRead reported failure
    24984 6454  09/13 13:43:16 527433 1749-# [FSRESTHEAD ] SendCtrlBuf: Sending Ctrl Msg 0x87
    24984 645c  09/13 13:43:26 527433 1744-# [FSRESTHEAD ] Waiting for pipeline buf. SndIdx [0/3], RCId [11]
    24984 259c  09/13 13:43:29 ###### media_fs::GetMountPathInfoFromReg: Error: getMagneticMountPathInfo failed to retrieve mount path information for 43. Error = 

    sqlida.log
    ****************************
    2704  fa8   09/13 13:43:15 527433 SqlDataReader::readPipelineData(700): -Debug-: Received PL_DATA for file [NPF_OPS_CO], Processing...
    2704  1c78  09/13 13:43:17 527433 SqlDataReader::readPipelineData(700): -Debug-: Received PL_DATA for file [NPF_OPS_CO], Processing...
    2704  23cc  09/13 13:43:27 527433 SqlDataReader::readPipelineData(700): -Debug-: Received PL_DATA for file [NPF_OPS_CO], Processing...
    2704  1bdc  09/13 13:43:28 527433 SqlDataReader::readPipelineData(700): -Debug-: Received PL_DATA for file [NPF_OPS_CO], Processing...
    2704  2a64  09/13 13:43:28 527433 SqlDataReader::readPipelineData(626): -Debug-: Received PL_FS_READ_ERR from pipeline read
    2704  28bc  09/13 13:43:28 527433 CCvSQLVDI::GetBytesForRestore(564): -Debug-: GetCommand returned  [0x80770004].
    2704  28bc  09/13 13:43:28 527433 SqlDataReader::readDBData() - Failed to get backup data. GetBytesForRestore failed.
    2704  2688  09/13 13:43:28 527433 CCvSQLVDI::GetBytesForRestore(564): -Debug-: GetCommand returned  [0x80770004].
    2704  2688  09/13 13:43:28 527433 SqlDataReader::readDBData() - Failed to get backup data. GetBytesForRestore failed.
    2704  1a68  09/13 13:43:28 527433 CCvSQLVDI::GetBytesForRestore(564): -Debug-: GetCommand returned  [0x80770004].
    2704  1a68  09/13 13:43:28 527433 SqlDataReader::readDBData() - Failed to get backup data. GetBytesForRestore failed.
    2704  12bc  09/13 13:43:28 527433 CCvSQLVDI::GetBytesForRestore(564): -Debug-: GetCommand returned  [0x80770004].
    2704  288c  09/13 13:43:28 527433 SqlDataReader::readDBData() - Failed to write the data to the sql server.
    2704  2054  09/13 13:43:28 527433 CCvSQLVDI::GetBytesForRestore(564): -Debug-: GetCommand returned  [0x80770004].
    2704  23cc  09/13 13:43:28 527433 CCvSQLVDI::GetBytesForRestore(564): -Debug-: GetCommand returned  [0x80770004].
    2704  23cc  09/13 13:43:28 527433 SqlDataReader::readDBData() - Failed to get backup data. GetBytesForRestore failed.
    2704  12bc  09/13 13:43:28 527433 SqlDataReader::readDBData() - Failed to get backup data. GetBytesForRestore failed.
    2704  2054  09/13 13:43:28 527433 SqlDataReader::readDBData() - Failed to get backup data. GetBytesForRestore failed.
    2704  fa8   09/13 13:43:28 527433 CCvSQLVDI::GetBytesForRestore(564): -Debug-: GetCommand returned  [0x80770004].
    2704  fa8   09/13 13:43:28 527433 SqlDataReader::readDBData() - Failed to get backup data. GetBytesForRestore failed.
    2704  9ec   09/13 13:43:28 527433 CCvSQLVDIBase::RunQuery() - Error: Microsoft.SqlServer.Management.Common.ExecutionFailureException:RESTORE DATABASE is terminating abnormally.
    An exception occurred while executing a Transact-SQL statement or batch..
    2704  1bdc  09/13 13:43:29 527433 SqlDataReader::readDBData() - Failed to write the data to the sql server.
    2704  2078  09/13 13:43:35 527433 SqlDataReader::readDBData() - Failed to write the data to the sql server.
    2704  1c78  09/13 13:43:36 527433 SqlDataReader::readDBData() - Failed to write the data to the sql server.
    2704  21c4  09/13 13:43:36 527433 SqlDataTransferHandler::startTransfer(308): -Debug-: Restore has failed. Closing archive files.

    Best Regards
    Sujay kumar

    M
    1 person likes this
    • M
      MaiklIT
    M
    Byte
    Forum|alt.badge.img+1
    • MaiklIT
    • Author
    • Byte
    • 3 replies
    • September 13, 2023

    @Rajiv 

    I checked the disk library and noticed that the share mount path option was disabled on one of the disks. This disk was the problem disk that was causing a data error. After connecting the disk to the media agent, database recovery started.

    Many thanks for the help!
    Best Regards

    MaiklIT

    S
    1 person likes this
    • S
      Sujay kumar

    Reply


    Most helpful members this week

    Terms & ConditionsCookie settings

    Cookie policy

    We use cookies to enhance and personalize your experience. If you accept you agree to our full cookie policy. Learn more about our cookies.

     
    Cookie settings