E3717 EC=ERROR QFA CHUNK OFFSET SURPASSED

[deafasa]

Has Anyone seen this error? We are trying to do a message level restore back to an Exchange 2003 server. Both the Arcserve server and the Exchange premium add on agent are Arcserve 11.1 with SP1 installed.

Here is the exchange log entry.
<12/19/2005-17:24:54 TID:1e70>###################################################################################################
<12/19/2005-17:24:54 TID:1e70># Restore Job Begins JobType:0x0007 JobNumber:0x0026 #
<12/19/2005-17:24:54 TID:1e70>###################################################################################################
<12/19/2005-17:24:54 TID:1e70>[1e70 ExpaAdp INFO]^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Impersonated edc_mass\Administrator ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
<12/19/2005-17:25:01 TID:1e70>[DBAEXSIS INFO] CBrowse::GetExch2000Mailboxes() NulNumberOfItems = 1054
<12/19/2005-17:25:01 TID:1e70>[DBAEXSIS INFO] CBrowse::GetExch2000Mailboxes() GetMailboxLegacyDN().
<12/19/2005-17:35:59 TID:1e70>Error: Could not position tape. Chunk num:8044619, Chunk offset: 7680
<12/19/2005-17:35:59 TID:1e70>Error: performning restore for tape 'W-EDC-SAT-12/03/05'.
(DoRestoreTapeSession) - error code:4
<12/19/2005-17:35:59 TID:1e70>* Session Summary for Microsoft Exchange Server - Document Level <athena> *
<12/19/2005-17:35:59 TID:1e70>Successfully restored: 0 mailboxes, 0 folders, and 0 documents.
<12/19/2005-17:35:59 TID:1e70>Error restoring up node #0.
(DoRestoreNode) - error code:4
<12/19/2005-17:35:59 TID:1e70>This restore job did not complete successfully. (CExpaRestoreJob::Run): error code:4
<12/19/2005-17:35:59 TID:1e70>###################################################################################################
<12/19/2005-17:35:59 TID:1e70># Restore Job Ends JobType:0x0007 JobNumber:0x0026 #
<12/19/2005-17:35:59 TID:1e70>###################################################################################################
<12/19/2005-17:35:59 TID:1e70>[1e70 ExpaAdp INFO]^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Impersonation Ends ^^^^^^^^^^^^^^^^^^^^^^^^^^^^

It almost looks like a Tape Drive Issue. Any thoughts.

 

[davidmichel]

Tape or DB.

Put the Tape Engine in debug mode and try it again. An errors at the tape end will show up there or a lack of could point to a problem with the ARCserve database.

 

[deafasa]

You would think simply setting level to 4 in the registry under tape engine,debug would have it write out to the tape.log file, but it doesn't. I'll have to work on it more in the morning. While it looks like a drive error, I doubt it is, as it is only the exchange agent that is having restore issues.

Jeff

 

[vschumpy]

If you are changing debug levels you need to stop/start the tape engine for it to take effect.

Look for a setting in the ARCserve registry (under task I think) called UseAsyncIO and try changing it to 0, cstop/cstart and try the operation again.

Remember to change it back to 1 again afterwards.

 

[deafasa]

restarting the tape engine did enable logging. Thanks. The UseAsyncIO entry didn't work. Same error. Here is what appears to be the relevant portion of the tape log.

12/21 13:59:46 [0134] SemC Semaphore requesting [ 3d8], Timeout [10000]
12/21 13:59:46 [0134] SemC request Semaphore OK [ 3d8], Timeout [10000]
12/21 13:59:46 [0134] SemC Semaphore Released [ 3d8]
12/21 13:59:46 [0134] =>ABSL:2090 [READ POSITION ] 34 00 00 00 00 00 00 00 00 00 tt[6]
12/21 13:59:46 [0134] DRV:1 Current block #: [002e6e38] [3042872]
12/21 13:59:46 [0134] Mux_ReadDaemon:: ReadDaemon probably suspended -- jID[727], mID[0], jTKN[96183109], jNUM@44@, dcb[1], sNUM[101]
12/21 13:59:46 [0134] Mux_ReadDaemon:: Abnormal Termination. ChunkPos = 695899, posOnTape = 3042872 -- jID[727], mID[0], jTKN[96183109], jNUM@44@, dcb[1], sNUM[101]
12/21 13:59:46 [0134] SemC Semaphore requesting [ 3d4], Timeout [10000]
12/21 13:59:46 [0134] SemC request Semaphore OK [ 3d4], Timeout [10000]
12/21 13:59:46 [0134] SemC Semaphore Released [ 3d4]
12/21 13:59:46 [0134] =>ABSL:2090 ReadDaemon thread suspended. DaemonStatus[0]
12/21 13:59:46 [0588] midl_user_allocate(): size [532]
12/21 13:59:46 [0588] midl_user_allocate(): Got the memory
12/21 13:59:46 [0588] SemC Semaphore requesting [ 3cc], Timeout [10000]
12/21 13:59:46 [0588] SemC request Semaphore OK [ 3cc], Timeout [10000]

Any ideas??
Jeff

 

[vschumpy]

what make/model of tape drive are you using, and are you using multiplexing?

 

[deafasa]

Quantum Superloader SDLT 320
Yes, we are using multiplexing.

Thanks,
Jeff

 

[davidmichel]

install
QO74248 10.6 MB 11/14/05 NT -DEVICE SUPPORT UPDATE 6

Make sure the tape drive and library are disabled from within the OS device manager.

 

[deafasa]

Device update 6 has been installed. The tape drive and library are disabled within Windows 2000.
Same error.

It is only restores to the exchange agent that have problems. All other restores work fine.

Jeff

 

[vschumpy]

I would suggest contacting CA for further assistance - they may have a testfix for this problem.

 

[deafasa]

CA has a testfix, it has been installed and the tape library is cataloging the slots. We shall see if the fix works.

Jeff

 

[deafasa]

Testfix failed. I'll keep this thread updated on the progress with CA support in case anyone else has this issue.

Jeff

 

[myauto]

Hello deafasa, we had the same issue as you, could you please send me the testfix to me? fortgao@hotmail.com

Thanks very much!!!

 

[Barkey]

Have seen this error code when restoring data onto a file server.

Solution was as follows:

Change registry setting to resolve:

HKEY_LOCAL_MACHINE\SOFTWARE\ComputerAssociates\BrightStor ARCserve Backup\Base\Task\Restore.

Set "UseAsyncIO" value to 0 instead of 1.

Hope that helps.

 

[vschumpy]

UseAsyncIO was suggested earlier in this thread and it did not resolve the issue in this case.

 

[deafasa]

USEAsyncIO did not fix the problem.
myauto, the testfix did not work for us. In fact, my tape engine now stops at the most inappropriate time, (as in 2am in the middle of the backup job.) Are you sure you want it?

Jeff

 

[davidmichel]

Ok so updates installed, drivers not loaded, only happens with Exchange backups.

Error: Could not position tape. Chunk num:8044619, Chunk offset: 7680

2/21 13:59:46 [0134] =>ABSL:2090 [READ POSITION ] 34 00 00 00 00 00 00 00 00 00 tt[6]
12/21 13:59:46 [0134] DRV:1 Current block #: [002e6e38] [3042872]
12/21 13:59:46 [0134] Mux_ReadDaemon:: ReadDaemon probably suspended -- jID[727], mID[0], jTKN[96183109], jNUM@44@, dcb[1], sNUM[101]

It can not position tape, but yet the tape log does not show any errors. Instead it points to the process either being hung or stopped. Possibly database corruption, I've seen it cause a restore problem with specific data, but in this case it seems unlikely.

We have Exchange and multiplex. The failure point seems to be with the multiplex read daemon, but it still could be an Exchange only problem. Another question - Is the problem with the backup or restore? You see if the problem is with the backup then no matter what we do now the restore will fail until the backup problem is resolved. Tape Engine debug level 4 might help but I'm not so sure.

Right now I see the bigest problem as we don't know where the problem is. backup, restore, Tape Engine, Exchange Agent, Database, Task or a combination.

I say put the Tape Engine in debug level 4 as you originally suggested, and the Job as well as the Database Engines in debug, and also the Exchange Agent in debug (see faq if you don't know how). With everything in debug hopefully we will be able to find out were the error is.

 

[deafasa]

The problem appears to be with the restore. If I had to venture a guess, the issue is with the exchange agent.

CA Techsupport current attempt is to change USEAsyncIO=0 and retry the restore. They also deleted all the r* files.
Of course, it failed. The current tech had us reboot the server. We will see what else they try. I will continue to update this thread.

Jeff

 

[vschumpy]

Hey Jeff,

Curious as to whether the information you're trying to get from tape is in a session which starts out on one tape sequence and spans to another.

Not saying I can give any advice based on it if this is the case, but I would make sure that CA understands and documents this as part of their investigation.

Also if you did a test backup right now and tried a restore (without spanning a tape sequence) would you receive the same error. I know the practicalities of actually doing this may be difficult and time consuming, but it may help narrow down the problem area further.

 

[deafasa]

The session is streamed. It appears to span 3 tapes, but I don't know of anyway to verify this. The restore job goes through 3 tapes before it fails (There is a fourth tape in the backup set.) CA is aware of this. If I simply backup my mailbox, and restore part of it, it works fine.
CA is still reviewing the log files.
Jeff