Forum Discussion

MickBoosh's avatar
MickBoosh
Level 5
12 years ago

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

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
  • 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

     

8 Replies

  • 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.

  • 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

  • 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

     

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

  • 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

  • It's set to deferred in the vault profile. 

    How can I make it immediate as a one off?

  • 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

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

    Martin