Video Screencast Help

Vault eject starting, no tapes being moved to mailslots, job runs on.

Created: 09 May 2013 • Updated: 28 Oct 2013 | 8 comments
This issue has been solved. See solution.

Hi,

Our vault jobs are running, saying they are to eject media, but the robot doesn't actually move the media to the mailslots. The job keeps running and doesn't finish. As you can see, the job is still running from yesterday. We have two tape libraries and it's the same on both. 

 

Any ideas?

 

 

08/05/2013 10:38:14 - Info nbjm(pid=5132) starting backup job (jobid=4903088) for client XXXX75, policy Vault_eject-xxxxbkp, schedule Daily  

08/05/2013 10:38:14 - Info nbjm(pid=5132) requesting NO_STORAGE_UNIT resources from RB for backup job (jobid=4903088, request id:{085B6062-F7DB-477B-81E3-CC143621F230})  

08/05/2013 10:38:14 - requesting resource XXXX75.NBVAULT.MAXJOBS

08/05/2013 10:38:14 - requesting resource XXXX75.NBU_POLICY.MAXJOBS.Vault_eject-xxxxbkp

08/05/2013 10:38:14 - granted resource XXXX75.NBVAULT.MAXJOBS

08/05/2013 10:38:14 - granted resource XXXX75.NBU_POLICY.MAXJOBS.Vault_eject-xxxxbkp

08/05/2013 10:38:15 - begin Eject/Report

08/05/2013 10:38:15 - connecting

08/05/2013 10:38:15 - connected; connect time: 00:00:00

08/05/2013 10:38:15 - estimated 0 Kbytes needed

08/05/2013 10:38:15 - begin Parent Job

08/05/2013 10:38:15 - begin Vault, Start Notify Script

08/05/2013 10:38:15 - Info RUNCMD(pid=7216) started            

08/05/2013 10:38:15 - Info RUNCMD(pid=7216) exiting with status: 0         

Status 0

08/05/2013 10:38:15 - end Vault, Start Notify Script; elapsed time: 00:00:00

08/05/2013 10:38:15 - begin Vault, Execute Script

08/05/2013 10:38:15 - started process bpbrm (4728)

08/05/2013 10:38:16 - vault waiting for eject lock

08/05/2013 10:38:16 - requesting resource XXXX75.VAULT_EJECT.LOCK_1

08/05/2013 10:38:16 - granted resource XXXX75.VAULT_EJECT.LOCK_1

08/05/2013 10:38:17 - vault eject lock acquired

08/05/2013 10:38:20 - suspend media for this session: failed to suspend 1 of 43 media at eject time

08/05/2013 10:38:20 - starting eject of 18 media
Operating Systems:

Comments 8 CommentsJump to latest comment

watsons's picture

Check your actual mailslot and make sure they're emptied out if occupied with tapes. It may have ejected some , and is waiting for available mailslot to eject further.

If mailslot has no tape at all, check the session details in \vault\sessions\sid###\logs\detail.log to see what it's waiting for.

MickBoosh's picture

Thanks for the reply but of course I have checked the mailslot!!

 

I've uploaded the latest detail.log (renamed to txt), if anyone would like to take a look.

 

Cheers

AttachmentSize
detail.txt 6.83 MB
mph999's picture

It picks some media for eject ...

 

STEP = genejectlist
StartTime = 2013.05.08 16:03:59 (1368025439)
16:03:59.308 [10412.7840] <2> vltrun@VltSession::lock_and_operate^1315: OP: genejectlist
16:03:59.308 [10412.7840] <2> vltrun@GenMediaEjectList^1315: entering function
16:03:59.308 [10412.7840] <2> vltrun@connectToVRTObject^1315: Connecting to vccs server xxxx75
16:03:59.324 [10412.7840] <2> vltrun@connectToVRTObject^1315: VaultRuntimePortal init succeeded
16:03:59.339 [10412.7840] <4> vltrun@GenMediaEjectList^1315: Appending session to vlteject.mstr returned=0
16:03:59.355 [10412.7840] <2> vltrun@GenMediaEjectList^1315: Suspend Mode = LATER
16:03:59.355 [10412.7840] <2> vltrun@GenMediaEjectList^1315: ADDing media=0073L4 SUSPEND host=xxxxbkp for Eject
16:03:59.355 [10412.7840] <2> vltrun@GenMediaEjectList^1315: ADDing media=0076L4 SUSPEND host=xxxxbkp for Eject
16:03:59.355 [10412.7840] <2> vltrun@GenMediaEjectList^1315: ADDing media=0081L4 SUSPEND host=xxxxbkp for Eject
16:03:59.355 [10412.7840] <2> vltrun@GenMediaEjectList^1315: ADDing media=0082L4 SUSPEND host=xxxxbkp for Eject
16:03:59.355 [10412.7840] <2> vltrun@GenMediaEjectList^1315: ADDing media=0084L4 SUSPEND host=xxxxbkp for Eject
16:03:59.355 [10412.7840] <2> vltrun@GenMediaEjectList^1315: ADDing media=0098L4 SUSPEND host=xxxxbkp for Eject
16:03:59.355 [10412.7840] <2> vltrun@GenMediaEjectList^1315: ADDing media=0101L4 SUSPEND host=xxxxbkp for Eject
16:03:59.355 [10412.7840] <2> vltrun@GenMediaEjectList^1315: ADDing media=0111L4 SUSPEND host=xxxxbkp for Eject
16:03:59.355 [10412.7840] <2> vltrun@GenMediaEjectList^1315: ADDing media=0113L4 SUSPEND host=xxxxbkp for Eject
16:03:59.355 [10412.7840] <2> vltrun@GenMediaEjectList^1315: ADDing media=0114L4 SUSPEND host=xxxxbkp for Eject
16:03:59.355 [10412.7840] <2> vltrun@GenMediaEjectList^1315: ADDing media=0116L4 SUSPEND host=xxxxbkp for Eject
16:03:59.355 [10412.7840] <2> vltrun@GenMediaEjectList^1315: ADDing media=0117L4 SUSPEND host=xxxxbkp for Eject
16:03:59.355 [10412.7840] <2> vltrun@GenMediaEjectList^1315: ADDing media=0174L4 SUSPEND host=xxxxbkp for Eject
16:03:59.355 [10412.7840] <2> vltrun@GenMediaEjectList^1315: ADDing media=0177L4 SUSPEND host=xxxxbkp for Eject
16:03:59.355 [10412.7840] <2> vltrun@GenMediaEjectList^1315: ADDing media=0180L4 SUSPEND host=xxxxbkp for Eject
16:03:59.355 [10412.7840] <2> vltrun@GenMediaEjectList^1315: ADDing media=0181L4 SUSPEND host=xxxxbkp for Eject
16:03:59.355 [10412.7840] <2> vltrun@GenMediaEjectList^1315: ADDing media=0190L4 SUSPEND host=xxxxbkp for Eject
16:03:59.355 [10412.7840] <4> vltrun@GenMediaEjectList^1315: Generated eject list containing 17 media Id(s)
 
Then we see the actual eject is set to deferred :
 
16:03:59.621 [10412.7840] <2> vltrun@VltSession::lock_and_operate^1315: OP: eject_media
16:03:59.621 [10412.7840] <2> vltrun@VaultJobMonitor::_send_try_msg^1315: At 1368025439 sent TRY_MSG: VAULT_EJECT_DEFERRED 1368025439
 
16:03:59.621 [10412.7840] <2> vltrun@VaultJobMonitor::_send_jobrundata^1315: SENT JobRunDataEx_t to JOBD at 1368025439
16:03:59.621 [10412.7840] <2> vltrun@VaultJobMonitor::IncrementJobProgress^1315: SENT completion pct=80 to JOBD
16:03:59.621 [10412.7840] <8> vltrun@VltSession::sessionStep()^1315: Session STEP COMPLETE
 
So it will not actually eject anything, until the 'deferred' eject is run as a separate step.
 
It is working as designed.
 
If you wish to eject the media, either deselect the 'deferred' eject option in the vault config, or run the deferred eject as a separate step.
 
Martin

 

 

Regards,  Martin
 
Setting Logs in NetBackup:
http://www.symantec.com/docs/TECH75805
 
SOLUTION
MickBoosh's picture

Thanks Martin. We haven't changed the configuration and this was working ok until this week. Why would you use deffered instead of immediate?

mph999's picture

Simply to prevent the tapes ejecting at the time th evault runs.  Somepeople like to control this as a separate step.

Perhaps you could check the vault profile (under the eject tab) to see if deferred eject really is set, there is always a possibility I have mis-understood the log.

Though I have to say it seems quite clear in this case:

16:03:59.621 [10412.7840] <2> vltrun@VaultJobMonitor::_send_try_msg^1315: At 1368025439 sent TRY_MSG: VAULT_EJECT_DEFERRED 1368025439

 

Martin

 

Regards,  Martin
 
Setting Logs in NetBackup:
http://www.symantec.com/docs/TECH75805
 
MickBoosh's picture

It's set to deferred in the vault profile. 

How can I make it immediate as a one off?

Will Restore's picture

Try running this command  vlteject -eject

 

 

from the Vault Admin Guide:

Ejecting media

If you configure a profile to defer ejection, you must perform or schedule another

action to eject media.

You can use one of the following actions to eject media that was not ejected by a

profile that selected or duplicated images:

■ Manually by using the Vault Management node in the NetBackup

Administration Console

■ Manually by using the Vault Operator Menu

■ Manually by using the vlteject command

■ Automatically by creating and scheduling a Vault policy and entering the

appropriate vlteject command and options in the file list

Will Restore -- where there is a Will there is a way

mph999's picture

Unfortunately, you cannot set this as a one-off - it is either set as deferred or not.

Martin

 

Regards,  Martin
 
Setting Logs in NetBackup:
http://www.symantec.com/docs/TECH75805