Vault failing Netbackup 7.1

Sorry, a bit more info: Last week I could manually eject the tapes, this week if I try the manual eject of one or two they eject but if i select more all say eject aborted after a couple of minutes on Netbackup but the tape library can see that one or two are in the map. I am inventorying a lot as if the manual eject fails, netbackup doesn't see that the tapes have ejected and the only way to resolve is inventory the robot.

I did see other threads on this but none with a solution

hi,

could you attach the detail.log and summary.log file for the failed vault session

you can find these files in /usr/openv/netbackup/vault/sessions/<profilename>/<sessionid>/

This is the relevant bit from the detail.log, the vault is set to skip the duplication and catalog

16:22:08.478 [7668.6196] <4> vltrun@PickListReports::makeModel()^334: ***Completed Data Collection***
16:22:08.525 [7668.6196] <2> vltrun@PickListReports::makeView()^334: *** Started Data View ***
16:22:08.525 [7668.6196] <2> vltrun@VaultReport::initializeReportFiles^334: Temp RptFile=C:\Program Files\Veritas\NetBackup\Logs\user_ops\vault\vault-07668374851233425196000000000-a06196\picklist_robot.rpt RptID=0
16:22:08.525 [7668.6196] <2> vltrun@VaultReport::openReportFile^334: File=C:\Program Files\Veritas\NetBackup\Logs\user_ops\vault\vault-07668374851233425196000000000-a06196\picklist_robot.rpt for RPT_ID=0 output
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::makeView()^334: Opened report file for RPT_ID=0
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: rendering report RPR_ID=0
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Started Rendering in REGULAR format
16:22:08.541 [7668.6196] <2> vltrun@VaultReport::createGPageHdrs()^334: RPT_ID=0
16:22:08.541 [7668.6196] <2> vltrun@VaultReport::alignReportHeader()^334: Entering alignReportHeader for aligning REPORT_HEADER
16:22:08.541 [7668.6196] <2> vltrun@VaultReport::alignReportHeader()^334: Breaking  (if reqd)
16:22:08.541 [7668.6196] <2> vltrun@VaultReport::alignReportHeader()^334: Broken into 0 parts
16:22:08.541 [7668.6196] <2> vltrun@VaultReport::createCoverHdrs()^334: RPT_ID=0
16:22:08.541 [7668.6196] <2> vltrun@VaultReport::alignReportHeader()^334: Entering alignReportHeader for aligning REPORT_TITLE
16:22:08.541 [7668.6196] <2> vltrun@VaultReport::alignReportHeader()^334: Breaking Picking List for Robot (if reqd)
16:22:08.541 [7668.6196] <2> vltrun@VaultReport::alignReportHeader()^334: Broken into 1 parts
16:22:08.541 [7668.6196] <2> vltrun@VaultReport::writeGPageHdrs^334: Printed Report general page headers
16:22:08.541 [7668.6196] <2> vltrun@VaultReport::writeCoverHdrs^334: Starting CoverPage for report
16:22:08.541 [7668.6196] <2> vltrun@VaultReport::writeCoverHdrs^334: value of m_pageCnt, m_flatFormat, m_rptType are:1 0 1
16:22:08.541 [7668.6196] <2> vltrun@VaultReport::writeCoverHdrs^334: Report Cover Page written out
16:22:08.541 [7668.6196] <2> vltrun@VR::writeColumnHdrs^334: Lines=3
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Completed Header Addition for Reports
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Completed Report Format Determination
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Completed Sorting the Data
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000051
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000051
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000073
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000073
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000092
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000092
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000106
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000106
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000113
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000113
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000184
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000184
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000192
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000192
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000213
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000213
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000215
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000215
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000217
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000217
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000220
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000220
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000221
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000221
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000222
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000222
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000245
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000245
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000256
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000256
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000273
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000273
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000276
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000276
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000281
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000281
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000301
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000301
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000304
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000304
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000320
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000320
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000324
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000324
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000327
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000327
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000355
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000355
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000364
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000364
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000369
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000369
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000370
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000370
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000422
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000422
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000441
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000441
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000454
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000454
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000465
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000465
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000476
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000476
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000509
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000509
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000529
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000529
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000535
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000535
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000539
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000539
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000636
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000636
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000650
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000650
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000655
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000655
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000661
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000661
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000670
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000670
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000672
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000672
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000681
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000681
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000693
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000693
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000696
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000696
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000698
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000698
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000700
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000700
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000701
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000701
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000702
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000702
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000703
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000703
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000704
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000704
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000705
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000705
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000708
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000708
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000710
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000710
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000726
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000726
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000737
16:22:08.541 [7668.6196] <2> vltrun@VaultReport::writeGPageHdrs^334: Printed Report general page headers
16:22:08.541 [7668.6196] <2> vltrun@VR::writeColumnHdrs^334: Lines=3
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000737
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000738
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000738
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000739
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000739
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printing Media details=000740
16:22:08.541 [7668.6196] <2> vltrun@PickListReports::renderReports()^334: Printed Media details=000740
16:22:08.556 [7668.6196] <2> vltrun@PickListReports::makeView()^334: Rendered report for RPT_ID=0
16:22:08.556 [7668.6196] <4> vltrun@PickListReports::makeView()^334: *** Completed Data View ***
16:22:08.556 [7668.6196] <2> vltrun@VaultReport::distribute^334: RptDistribution: RptType=1 Consol=0 Format=0
16:22:08.556 [7668.6196] <2> vltrun@VaultReport::distribute^334: Distributing reports: RPT_ID=0
16:22:08.572 [7668.6196] <2> vltrun@RU::consolidateDistributionValues^334: RPT_ID=0
16:22:08.572 [7668.6196] <2> vltrun@RU::consolidateDistributionValues^334: EM=kbroad@worcestershire.gov.uk;mparker@worcestershire.gov.uk; PR= DIR=D:\VaultReports
16:22:08.572 [7668.6196] <2> vltrun@RU::consolidateDistributionValues^334: EmailList has 3 addresses
16:22:08.572 [7668.6196] <2> vltrun@Distribute::sendToFile()^334: #Folders=1
16:22:08.572 [7668.6196] <2> vltrun@ReportUtil::createReportDirectory()^334: to create (if reqd) RptDir=D:\VaultReports
16:22:08.572 [7668.6196] <2> vltrun@ReportUtil::createReportDirectory()^334: RptDir=D:\VaultReports already exists
16:22:08.572 [7668.6196] <2> vltrun@Distribute::sendToFile()^334: RptSrc=C:\Program Files\Veritas\NetBackup\Logs\user_ops\vault\vault-07668374851233425196000000000-a06196\picklist_robot.rpt RptDest=D:\VaultReports\picklist_robot_sid334_1374851233.rpt
16:22:08.619 [7668.6196] <2> vltrun@Distribute::sendToEmail()^334: #emails=3
16:22:08.619 [7668.6196] <2> vltrun@Distribute::sendToEmail()^334: EmailAdd=,kbroad@worcestershire.gov.uk,mparker@worcestershire.gov.uk Sub=Picking List for Robot [WeeklyEject:Sid 334 ]
16:22:08.744 [7668.6196] <2> vltrun@VaultReport::distribute^334: Completed RPT Dist of RPT_ID=0 with STAT=0
16:22:08.744 [7668.6196] <4> vltrun@VaultReport::distribute^334: Completed Rpt distribution with STAT=0
16:22:08.759 [7668.6196] <2> vltrun@connectToVRTObject^334: Connecting to vccs server appnbu-v
16:22:08.759 [7668.6196] <2> vltrun@connectToVRTObject^334: VaultRuntimePortal init succeeded
16:22:08.759 [7668.6196] <8> vltrun@ReportUtil:isEjectDone()^334: Partial Eject timestamp is not found, so eject is not done
16:22:08.759 [7668.6196] <2> vltrun@ReportsFactory::createReport()^334: ReportCtgy=2
16:22:08.759 [7668.6196] <2> vltrun@RptsFactory::consolidateSubReports^334: RPT_TYPE=2
16:22:08.759 [7668.6196] <2> vltrun@ReportsFactory::getRequestedReports^334: For NORMAL REPORTS=2 #SubReports=2
16:22:08.759 [7668.6196] <2> vltrun@ReportsFactory::getRequestedReports^334: Checking if RPT=4 is enabled
16:22:08.759 [7668.6196] <2> vltrun@ReportsFactory::getRequestedReports^334: RPT=4 ENABLED
16:22:08.759 [7668.6196] <2> vltrun@ReportsFactory::getRequestedReports^334: Checking if RPT=5 is enabled
16:22:08.775 [7668.6196] <2> vltrun@VaultReport::VaultReport()^334: Vault Report with #RptSess=1
16:22:08.775 [7668.6196] <2> vltrun@VaultReport::VaultReport()^334: Rpt for session=WeeklyEject-334
16:22:08.775 [7668.6196] <2> vltrun@VaultReport::VaultReport()^334: Rpt for Containerized Vault?=>0
16:22:08.775 [7668.6196] <2> vltrun@VaultReport::VaultReport()^334: Creating RptDir=C:\Program Files\Veritas\NetBackup\Logs\user_ops\vault\vault-07668374852128775196000000001-a06196 for consol/session rpts
16:22:08.775 [7668.6196] <2> vltrun@VaultReport::initializeReportHeaderNames()^334: L10Ning Report Headers
16:22:08.791 [7668.6196] <2> vltrun@VaultReport::initializeReportHeaderNames()^334: Completed L10Ning Report Headers
16:22:08.791 [7668.6196] <4> vltrun@ReportsFactory::createReport()^334: Returing vreport by creating object of Vault Report Successfully
16:22:08.791 [7668.6196] <2> vltrun@DistListReports::makeModel^334: ***Make Model Starts***
16:22:08.791 [7668.6196] <2> vltrun@cVolInvMgr::LoadInvByPool^334: Host=appnbu-v Npools=1
16:22:08.822 [7668.6196] <4> vltrun@cVolInvMgr::LoadInvByPool^334: V_QUERY_BYPOOL H=appnbu-v Pool=DataStore
16:22:08.916 [7668.6196] <4> vltrun@cVolInvMgr::LoadInvByPool^334: Loaded 695 media records into volInvList
16:22:08.916 [7668.6196] <2> vltrun@cVolInvMgr::LoadInvScratchPools^334: H=appnbu-v
16:22:08.931 [7668.6196] <4> vltrun@cVolInvMgr::LoadInvScratchPools^334: Loaded 0 media from 0 scratch pools SC=0
16:22:08.963 [7668.6196] <4> vltrun@cVolInvMgr::LoadCatalogPools^334: Loaded 2 CtlgPools
16:22:08.963 [7668.6196] <2> vltrun@DistListReports::makeView^334: *** Started Data View ***
16:22:08.963 [7668.6196] <2> vltrun@VaultReport::initializeReportFiles^334: Temp RptFile=C:\Program Files\Veritas\NetBackup\Logs\user_ops\vault\vault-07668374852128775196000000001-a06196\picklist_vault.rpt RptID=4
16:22:08.963 [7668.6196] <2> vltrun@VaultReport::openReportFile^334: File=C:\Program Files\Veritas\NetBackup\Logs\user_ops\vault\vault-07668374852128775196000000001-a06196\picklist_vault.rpt for RPT_ID=4 output
16:22:08.963 [7668.6196] <4> vltrun@DistListReports::renderReports^334: Started Rendering in REGULAR format
16:22:08.963 [7668.6196] <2> vltrun@VaultReport::createGPageHdrs()^334: RPT_ID=4
16:22:08.963 [7668.6196] <2> vltrun@VaultReport::alignReportHeader()^334: Entering alignReportHeader for aligning REPORT_HEADER
16:22:08.963 [7668.6196] <2> vltrun@VaultReport::alignReportHeader()^334: Breaking  (if reqd)
16:22:08.963 [7668.6196] <2> vltrun@VaultReport::alignReportHeader()^334: Broken into 0 parts
16:22:08.963 [7668.6196] <2> vltrun@VaultReport::createCoverHdrs()^334: RPT_ID=4
16:22:08.963 [7668.6196] <2> vltrun@VaultReport::alignReportHeader()^334: Entering alignReportHeader for aligning REPORT_TITLE
16:22:08.963 [7668.6196] <2> vltrun@VaultReport::alignReportHeader()^334: Breaking Picking List for Vault (if reqd)
16:22:08.963 [7668.6196] <2> vltrun@VaultReport::alignReportHeader()^334: Broken into 1 parts
16:22:08.963 [7668.6196] <2> vltrun@VaultReport::writeGPageHdrs^334: Printed Report general page headers
16:22:08.963 [7668.6196] <2> vltrun@VaultReport::writeCoverHdrs^334: Starting CoverPage for report
16:22:08.963 [7668.6196] <2> vltrun@VaultReport::writeCoverHdrs^334: value of m_pageCnt, m_flatFormat, m_rptType are:1 0 2
16:22:08.963 [7668.6196] <2> vltrun@VaultReport::writeCoverHdrs^334: Report Cover Page written out
16:22:08.963 [7668.6196] <2> vltrun@VR::writeColumnHdrs^334: Lines=4
16:22:08.963 [7668.6196] <2> vltrun@DistListReports::makeView^334: *** Completed Data View ***
16:22:08.963 [7668.6196] <2> vltrun@VaultReport::distribute^334: RptDistribution: RptType=2 Consol=0 Format=0
16:22:08.963 [7668.6196] <2> vltrun@VaultReport::distribute^334: Distributing reports: RPT_ID=4
16:22:08.963 [7668.6196] <2> vltrun@RU::consolidateDistributionValues^334: RPT_ID=4
16:22:08.963 [7668.6196] <2> vltrun@RU::consolidateDistributionValues^334: EM=kbroad@worcestershire.gov.uk;mparker@worcestershire.gov.uk; PR= DIR=D:\VaultReports
16:22:08.963 [7668.6196] <2> vltrun@RU::consolidateDistributionValues^334: EmailList has 3 addresses
16:22:08.963 [7668.6196] <2> vltrun@Distribute::sendToFile()^334: #Folders=1
16:22:08.963 [7668.6196] <2> vltrun@ReportUtil::createReportDirectory()^334: to create (if reqd) RptDir=D:\VaultReports
16:22:08.963 [7668.6196] <2> vltrun@ReportUtil::createReportDirectory()^334: RptDir=D:\VaultReports already exists
16:22:08.963 [7668.6196] <2> vltrun@Distribute::sendToFile()^334: RptSrc=C:\Program Files\Veritas\NetBackup\Logs\user_ops\vault\vault-07668374852128775196000000001-a06196\picklist_vault.rpt RptDest=D:\VaultReports\picklist_vault_sid334_1374851233.rpt
16:22:08.978 [7668.6196] <2> vltrun@Distribute::sendToEmail()^334: #emails=3
16:22:08.978 [7668.6196] <2> vltrun@Distribute::sendToEmail()^334: EmailAdd=,kbroad@worcestershire.gov.uk,mparker@worcestershire.gov.uk Sub=Picking List for Vault [WeeklyEject:Sid 334 ]
16:22:09.056 [7668.6196] <2> vltrun@VaultReport::distribute^334: Completed RPT Dist of RPT_ID=4 with STAT=0
16:22:09.056 [7668.6196] <4> vltrun@VaultReport::distribute^334: Completed Rpt distribution with STAT=0
16:22:09.056 [7668.6196] <2> vltrun@connectToVRTObject^334: Connecting to vccs server appnbu-v
16:22:09.056 [7668.6196] <2> vltrun@connectToVRTObject^334: VaultRuntimePortal init succeeded
16:22:09.056 [7668.6196] <8> vltrun@ReportUtil:isEjectDone()^334: Partial Eject timestamp is not found, so eject is not done
16:22:09.056 [7668.6196] <2> vltrun@ReportsFactory::createReport()^334: ReportCtgy=3
16:22:09.056 [7668.6196] <2> vltrun@RptsFactory::consolidateSubReports^334: RPT_TYPE=3
16:22:09.072 [7668.6196] <2> vltrun@connectToVRTObject^334: Connecting to vccs server appnbu-v
16:22:09.072 [7668.6196] <2> vltrun@connectToVRTObject^334: VaultRuntimePortal init succeeded
16:22:09.072 [7668.6196] <8> vltrun@ReportUtil:isEjectDone()^334: Partial Eject timestamp is not found, so eject is not done
16:22:09.072 [7668.6196] <2> vltrun@ReportsFactory::createReport()^334: ReportCtgy=4
16:22:09.072 [7668.6196] <2> vltrun@RptsFactory::consolidateSubReports^334: RPT_TYPE=4
16:22:09.072 [7668.6196] <2> vltrun@connectToVRTObject^334: Connecting to vccs server appnbu-v
16:22:09.072 [7668.6196] <2> vltrun@connectToVRTObject^334: VaultRuntimePortal init succeeded
16:22:09.072 [7668.6196] <8> vltrun@ReportUtil:isEjectDone()^334: Partial Eject timestamp is not found, so eject is not done
16:22:09.072 [7668.6196] <2> vltrun@ReportsFactory::createReport()^334: ReportCtgy=5
16:22:09.072 [7668.6196] <2> vltrun@RptsFactory::consolidateSubReports^334: RPT_TYPE=5
16:22:09.072 [7668.6196] <2> vltrun@ReportsFactory::getRequestedReports^334: For NORMAL REPORTS=5 #SubReports=1
16:22:09.072 [7668.6196] <2> vltrun@ReportsFactory::getRequestedReports^334: Checking if RPT=10 is enabled
16:22:09.072 [7668.6196] <2> vltrun@RptsFactory::consolidateSubReports^334: No sub report enabled, removing session->334
16:22:09.072 [7668.6196] <2> vltrun@connectToVRTObject^334: Connecting to vccs server appnbu-v
16:22:09.072 [7668.6196] <2> vltrun@connectToVRTObject^334: VaultRuntimePortal init succeeded
16:22:09.072 [7668.6196] <8> vltrun@ReportUtil:isEjectDone()^334: Partial Eject timestamp is not found, so eject is not done
16:22:09.072 [7668.6196] <2> vltrun@ReportsFactory::createReport()^334: ReportCtgy=6
16:22:09.072 [7668.6196] <2> vltrun@RptsFactory::consolidateSubReports^334: RPT_TYPE=6
16:22:09.072 [7668.6196] <2> vltrun@vreport^334: Eject Pending. NOT Updating Reports TS V=OnsiteTapes SID=334
16:22:09.072 [7668.6196] <8> vltrun@VaultJobMonitor::IncrementJobProgress^334: BAD Job done PCT 104
16:22:09.072 [7668.6196] <8> vltrun@VltSession::sessionStep()^334: Session STEP COMPLETE
End Time  :2013.07.26 16:22:09 (1374852129)
Elapsed   :14:56
16:22:09.088 [7668.6196] <2> vltrun@VltSession::sessionStep()^334: entering function
16:22:09.088 [7668.6196] <8> vltrun@VltSession::sessionStep()^334: Session STEP Information
RVP   = WeeklyEject
SID   = 334
STEP   = vlt_end_notify
StartTime  = 2013.07.26 16:22:09 (1374852129)
16:22:09.088 [7668.6196] <2> vltrun@VltSession::lock_and_operate^334: OP: vlt_end_notify
16:22:09.088 [7668.6196] <4> vltrun@VltSession::analyzeSessionStatus^334: steps = 4, successful_steps = 3, final_result = 287
16:22:09.088 [7668.6196] <2> vltrun@VOpExecuteScript::doOperation^334: CALLING C:\Program Files\Veritas\NetBackup\bin\vlt_end_notify.cmd script; robot:0, vault:OnsiteTapes, profile:WeeklyEject, and sid:334
16:22:09.088 [7668.6196] <2> vltrun@VOpExecuteScript::doOperation^334: Vault Notify Script=C:\Program Files\Veritas\NetBackup\bin\vlt_end_notify.cmd RV=0
16:22:09.088 [7668.6196] <8> vltrun@VaultJobMonitor::IncrementJobProgress^334: BAD Job done PCT 101
16:22:09.088 [7668.6196] <8> vltrun@VltSession::sessionStep()^334: Session STEP COMPLETE
End Time  :2013.07.26 16:22:09 (1374852129)
Elapsed   :0:0
16:22:09.088 [7668.6196] <2> vltrun@main: Analyzing session status
16:22:09.088 [7668.6196] <4> vltrun@VltSession::analyzeSessionStatus^334: steps = 4, successful_steps = 3, final_result = 287
16:22:09.088 [7668.6196] <8> vltrun@main: vltrun Returning Status:287
16:22:09.088 [7668.6196] <2> vltrun@main^334: End Time:  2013.07.26 16:22:09 (1374852129) Elapsed: 34:05 (2045)

16:22:09.088 [7668.6196] <2> vltrun@main^334: >>********************************************************************<<
16:22:09.135 [7668.6196] <8> vltrun@VltLogger::mailSummaryLog^334: NotificationEmail ID NOT setup. Returning...
16:22:09.135 [7668.6196] <2> vltrun@main: cleanup vltrun
16:22:09.135 [7668.6196] <2> vltrun@VaultLockProxy::release_all_locks^334: UpdJobd=1
16:22:09.135 [7668.6196] <2> vltrun@VaultLockProxy::release_all_locks^334: Releasing lock Type=NBVAULT.MAXJOBS
16:22:09.135 [7668.6196] <2> vltrun@VaultLockProxy::release_lock^334: Type=NBVAULT.MAXJOBS
16:22:09.135 [7668.6196] <4> vltrun@VaultLockProxy::release_lock^334: released lock. Key=appnbu-v.NBVAULT.MAXJOBS
16:22:09.135 [7668.6196] <2> vltrun@VaultJobMonitor::_send_try_msg^334: At 1374852129 sent TRY_MSG: VAULT_GLOBAL_LOCK_RELEASED 1374852129

16:22:09.135 [7668.6196] <2> vltrun@cancel_keepalive_thread^334: Entered with JOBID=2519403 to cancel ThrGrpId=1
16:22:09.135 [7668.6196] <8> vltrun@cancel_keepalive_thread^334: Notified keepalive thread. Sleeping for a bit (4 secs)
16:22:10.963 [7668.560] <8> vltrun@jobd_pinger: Cancel requested. Leaving...
16:22:13.135 [7668.6196] <4> vltrun@main: Reporting Status=287 (vault eject failed)
16:22:13.135 [7668.6196] <16> vltrun@main Vault Session FAILED [PRFL=0/OnsiteTapes/WeeklyEject SID=334 JID=2519403 EC=287]
16:22:13.135 [7668.6196] <16> vltrun@main FAILed NB_EC=287 NB_MSG=vault eject failed
16:22:13.135 [7668.6196] <2> vltrun@VaultJobMonitor::_send_jobdata^334: SENT JobDataEx_t to JOBD at 1374852133

Summary.log is

Robot:                TLD(0)
Vault:                OnsiteTapes
Profile:              WeeklyEject
Session ID:           0
Job_Id:               2519403
====================================

Session STEP Information
RVP   = WeeklyEject
SID   = 334
STEP   = start_notify
StartTime  = 2013.07.26 15:48:04 (1374850084)
Session STEP COMPLETE
End Time  :2013.07.26 15:48:04 (1374850084)
Elapsed   :0:0
Session STEP Information
RVP   = WeeklyEject
SID   = 334
STEP   = changegroup_torobot
StartTime  = 2013.07.26 15:48:04 (1374850084)
Session STEP COMPLETE
End Time  :2013.07.26 15:49:01 (1374850141)
Elapsed   :0:57
Session STEP Information
RVP   = WeeklyEject
SID   = 334
STEP   = select
StartTime  = 2013.07.26 15:49:01 (1374850141)
Session STEP COMPLETE
End Time  :2013.07.26 15:59:32 (1374850772)
Elapsed   :10:31
Session STEP Information
RVP   = WeeklyEject
SID   = 334
STEP   = suspend_media
StartTime  = 2013.07.26 15:59:32 (1374850772)
Session STEP COMPLETE
End Time  :2013.07.26 15:59:32 (1374850772)
Elapsed   :0:0
Session STEP Information
RVP   = WeeklyEject
SID   = 334
STEP   = vlt_ejectlist_notify
StartTime  = 2013.07.26 15:59:32 (1374850772)
Session STEP COMPLETE
End Time  :2013.07.26 15:59:32 (1374850772)
Elapsed   :0:0
Session STEP Information
RVP   = WeeklyEject
SID   = 334
STEP   = collect_eject_media
StartTime  = 2013.07.26 15:59:32 (1374850772)
Session STEP COMPLETE
End Time  :2013.07.26 15:59:32 (1374850772)
Elapsed   :0:0
Session STEP Information
RVP   = WeeklyEject
SID   = 334
STEP   = assignslot_media
StartTime  = 2013.07.26 15:59:32 (1374850772)
Session STEP COMPLETE
End Time  :2013.07.26 15:59:38 (1374850778)
Elapsed   :0:6
Session STEP Information
RVP   = WeeklyEject
SID   = 334
STEP   = assignslot_media
StartTime  = 2013.07.26 15:59:38 (1374850778)
Session STEP COMPLETE
End Time  :2013.07.26 15:59:49 (1374850789)
Elapsed   :0:11
Session STEP Information
RVP   = WeeklyEject
SID   = 334
STEP   = genejectlist
StartTime  = 2013.07.26 15:59:49 (1374850789)
Generated eject list containing 59 media Id(s)
Session STEP COMPLETE
End Time  :2013.07.26 15:59:49 (1374850789)
Elapsed   :0:0
Session STEP Information
RVP   = WeeklyEject
SID   = 334
STEP   = recall_media
StartTime  = 2013.07.26 15:59:49 (1374850789)
Session STEP COMPLETE
End Time  :2013.07.26 15:59:50 (1374850790)
Elapsed   :0:1
Session STEP Information
RVP   = WeeklyEject
SID   = 334
STEP   = gen_session_debug_files
StartTime  = 2013.07.26 15:59:50 (1374850790)
Session STEP COMPLETE
End Time  :2013.07.26 15:59:50 (1374850790)
Elapsed   :0:0
Session STEP Information
RVP   = WeeklyEject
SID   = 334
STEP   = eject_media
StartTime  = 2013.07.26 15:59:50 (1374850790)
NetBackup Media Manager Error: [2013:07:26::16:02:57] the media is allocated for use (199)
NetBackup Error: [2013:07:26::16:02:57] requested media id is in use, cannot process request (97)
NetBackup Error: [2013:07:26::16:02:57] failure occurred while suspending media for eject (335)
NetBackup Error: [2013:07:26::16:07:13] vault eject failed (287)
Session STEP COMPLETE
End Time  :2013.07.26 16:07:13 (1374851233)
Elapsed   :7:23
Session STEP Information
RVP   = WeeklyEject
SID   = 334
STEP   = report
StartTime  = 2013.07.26 16:07:13 (1374851233)
Session STEP COMPLETE
End Time  :2013.07.26 16:22:09 (1374852129)
Elapsed   :14:56
Session STEP Information
RVP   = WeeklyEject
SID   = 334
STEP   = vlt_end_notify
StartTime  = 2013.07.26 16:22:09 (1374852129)
Session STEP COMPLETE
End Time  :2013.07.26 16:22:09 (1374852129)
Elapsed   :0:0

====================================

SUMMARY REPORT
================
Master Server:        appnbu-v
Started:              2013.07.26 15:48:04
Stopped:              2013.07.26 16:22:09
Exit Status:          vault eject failed (287)

For detailed information, please refer to:
    G:\NetBackup\vault\sessions\OnsiteTapes\sid334\logs\detail.log.

====================================

NetBackup Error: [2013:07:26::16:22:13] vault eject failed (287)

i would appreciate if you can provide the total log G:\NetBackup\vault\sessions\OnsiteTapes\sid334\logs\detail.log. as an attachment.

Hi Nagalla,

This website is a public one so I am unable to upload the whole detail.log file unedited, and due to the issues that the failing vault process is causing I don't have time to abridge the whole file and replace all the server names etc. Can you be a bit more specific about what you expect or don't expect to see in the log so I can work on getting you that part?

Katie

Katie,

If I PM you my address you can send it direct to me - I'll take a look when I can.

Martin

Thanks Martin, I have sent that to you now

Katie

You didn't mention how many MAPs on the library, but with your testing of ejecting 1 or 2 it will work, I'd assume there are 2 MAPs available.

26/07/2013 13:36:18 - suspend media for this session: failed to suspend 1 of 52 media at eject time
==> This will not be major issue as it can't suspend only 1 media 

26/07/2013 13:36:18 - starting eject of 52 media
26/07/2013 13:40:34 - eject complete with status 287.  0 of 52 media ejected

NetBackup Media Manager Error: [2013:07:26::16:02:57] the media is allocated for use (199)
NetBackup Error: [2013:07:26::16:02:57] requested media id is in use, cannot process request (97)
NetBackup Error: [2013:07:26::16:02:57] failure occurred while suspending media for eject (335)

==> Just pick a few of those media chosen to be ejected, are they in use during the eject process? Make sure they're not. Suspended media will not be used for backup anymore, but restore job may still pick them up.

A look in the /usr/openv/netbackup/logs/vault/* will also help.

Are you thinking that all 52 tapes are in use, or reserved for use? I have checked and there are no restores pending or tried today, and I have tried again to eject tapes using the vault. 2 have ended up in the map but Netbackup advised that the job failed with 0 of 44 ejected.

As far as I can tell they are not in use at the time of the eject. These are tapes which are full, but the primary copy of the data will still be on disk storage, so if someone were to request a restore it would come off a copy on disk.

There are 2 physical I/O drawers, one has 12 slots available and a library expansion added another 6 about 2 years ago.

I have logged a call with the tape library support although they are likely to point to the software as causing the issues (the tape library is not giving any alerts about load or eject failures), does everyone think this is some sort of hardware issue?

My Netbackup servers are windows boxes so I think the file path is the one earlier in the thread

I am also getting an error when trying to load tapes using Netbackup, which is why I am thinking it could be a hardware issue "Inventory failed: cannot move media from access port to slot (218)". I restarted all the boxes and the library last week when this all started happening, so the robot should have re-calibrated itself.

Katie