Queued jobs in the activity monitor with no detail - Netbackup 5.1 MP6

[a5972s]

Hi there,

I have an issue with a number of queued jobs appearing in the activity monitor with no detail other than the owner and the start time.

I've attached extracts of both the SQL Server Log and dbclient log from the server.

SQL Server Log
2008-10-22 02:27:00.11 logon     Login succeeded for user 'NT AUTHORITY\SYSTEM'. Connection: Trusted.
2008-10-22 02:28:11.81 logon     Login succeeded for user 'Runtime'. Connection: Non-Trusted.
2008-10-22 02:28:33.34 logon     Login succeeded for user 'Runtime'. Connection: Non-Trusted.
2008-10-22 02:28:35.98 logon     Login succeeded for user 'Runtime'. Connection: Non-Trusted.
2008-10-22 02:28:38.84 logon     Login succeeded for user 'Runtime'. Connection: Non-Trusted.
2008-10-22 02:28:45.17 logon     Login succeeded for user 'Runtime'. Connection: Non-Trusted.
2008-10-22 02:30:01.94 logon     Login succeeded for user 'Runtime'. Connection: Non-Trusted.
2008-10-22 02:30:34.68 logon     Login succeeded for user 'Runtime'. Connection: Non-Trusted.
2008-10-22 02:30:37.32 logon     Login succeeded for user 'Runtime'. Connection: Non-Trusted.
2008-10-22 02:32:03.24 logon     Login succeeded for user 'Runtime'. Connection: Non-Trusted.
2008-10-22 02:32:38.69 logon     Login succeeded for user 'Runtime'. Connection: Non-Trusted.
2008-10-22 02:34:04.48 logon     Login succeeded for user 'Runtime'. Connection: Non-Trusted.
2008-10-22 02:34:31.82 logon     Login succeeded for user 'Runtime'. Connection: Non-Trusted.
2008-10-22 02:34:39.84 logon     Login succeeded for user 'Runtime'. Connection: Non-Trusted.
2008-10-22 02:34:58.87 logon     Login succeeded for user 'Runtime'. Connection: Non-Trusted.
2008-10-22 02:35:03.24 logon     Login succeeded for user 'Runtime'. Connection: Non-Trusted.
2008-10-22 02:35:36.52 spid86    BackupMedium::ReportIoError: write failure on backup device 'VNBU0-7136-6580'. Operating system error 995(error not found).
2008-10-22 02:35:36.52 backup    BACKUP failed to complete the command backup database "bp-archive-data-o1" to VIRTUAL_DEVICE='VNBU0-7136-6580' with blocksize = 65536, maxtransfersize = 65536, buffercount = 1
2008-10-22 02:35:36.52 spid86    Internal I/O request 0x3D811C30: Op: Write, pBuffer: 0x049B0000, Size: 65536, Position: 0, UMS: Internal: 0x0, InternalHigh: 0x0, Offset: 0x0, OffsetHigh: 0x0, m_buf: 0x00000000, m_len: 0, m_actualBytes: 0, m_errcode: 995, BackupFile: VNBU0-7136-6580
2008-10-22 02:35:36.54 spid86    BackupVirtualDeviceFile::RequestDurableMedia: Flush failure on backup device 'VNBU0-7136-6580'. Operating system error 995(error not found).

Netbackup Log
02:28:05.551 [7136.6044] <16> readCommFile: ERR - timed out after 4500 seconds while reading from C:\Program Files\VERITAS\NetBackup\Logs\user_ops\mssql\logs\1022108011252-7136-6552-000-000-prg
02:28:05.551 [7136.6044] <32> serverResponse: ERR - could not read from comm file <C:\Program Files\VERITAS\NetBackup\Logs\user_ops\mssql\logs\1022108011252-7136-6552-000-000-prg>
02:28:05.551 [7136.6044] <16> CreateNewImage: ERR - serverResponse() failed
02:28:05.551 [7136.6044] <16> VxBSACreateObject: ERR - Could not create new image with file /svr-qat-pdb02.MSSQL7.SVR-QAT-PDB-B.db.bp-archive-data-o1.~.7.001of001.20081022011300..C.
02:28:05.551 [7136.6044] <4> getServerName: Read server name from nb_master_config: master-server
02:28:05.551 [7136.6044] <2> logconnections: bprd CONNECT FROM 172.30.252.173.3550 TO 192.168.51.3.13720
02:28:05.551 [7136.6044] <2> logconnections: BPRD CONNECT FROM 172.30.252.173.3550 TO 192.168.51.3.13720
02:28:06.098 [7136.6044] <4> getServerName: Read server name from nb_master_config: master-server
02:28:06.098 [7136.6044] <2> logconnections: bprd CONNECT FROM 172.30.252.173.3551 TO 192.168.51.3.13720
02:28:06.098 [7136.6044] <2> logconnections: BPRD CONNECT FROM 172.30.252.173.3551 TO 192.168.51.3.13720
02:35:36.513 [7136.6044] <32> DBthreads::dbclient: ERR - <VxBSACreateObject> failed with error <3>. The text follows:
02:35:36.513 [7136.6044] <1> DBthreads::dbclient:     CONTINUATION: - System detected error, operation aborted.
02:35:36.513 [7136.6044] <8> close_image: Session being terminated abnormally, cleaning up
02:35:36.513 [7136.6044] <4> close_image: INF - backup FAILED
02:35:36.513 [7136.6044] <4> close_image: INF ---- end of Backup ---

02:35:36.513 [7136.6044] <4> KillAllThreads: INF - entering KillAllThreads <1>
02:35:36.513 [7136.6044] <4> KillAllThreads: INF - Killing group #0
02:35:36.513 [7136.6044] <4> KillAllThreads: INF - Issuing SignalAbort to MS SQL Server VDI
02:35:36.513 [7136.2824] <4> KillAllThreads: INF - entering KillAllThreads <1>
02:35:36.513 [7136.2824] <4> KillAllThreads: INF - Killing group #0
02:35:36.529 [7136.6700] <4> KillAllThreads: INF - entering KillAllThreads <1>
02:35:36.529 [7136.6700] <4> KillAllThreads: INF - Killing group #0
02:35:37.529 [7136.6580] <4> DBDisconnect: INF - Logging out of SQL Server with handle <0x008d1a20>
02:35:37.544 [7136.6580] <32> CDBbackrec::FreeDeviceSet(): ERR - Error in VDS->Close: 0x80770004. The text follows:
02:35:37.544 [7136.6580] <1> CDBbackrec::FreeDeviceSet():     CONTINUATION: - An abort request is preventing anything except termination actions.
02:35:37.544 [7136.6580] <4> Dbbackrec::Perform: INF - OPERATION #1 of batch NBU_Full.bch FAILED with status 1. Elapsed time = 4957(4957) seconds.
02:35:39.544 [7136.6552] <4> DBConnect: INF - Logging into SQL Server with DSN <NBMSSQL_7136_6552>, SQL userid <SYSTEM> handle <0x008d3c10>.
02:35:39.654 [7136.6552] <4> CGlobalInformation::CreateDSN: INF - A successful connection to SQL Server <SVR-QAT-PDB-B\> has been made using trusted security with DSN <NBMSSQL_7136_6552>
02:35:39.654 [7136.6552] <4> DBDisconnect: INF - Logging out of SQL Server with handle <0x008d3c10>
02:35:39.654 [7136.6552] <4> DBConnect: INF - Logging into SQL Server with DSN <NBMSSQL_7136_6552>, SQL userid <sa> handle <0x008d3c10>.
02:35:39.654 [7136.6552] <4> DBDisconnect: INF - Logging out of SQL Server with handle <0x008d3c10>
02:35:39.654 [7136.6552] <4> DBConnect: INF - Logging into SQL Server with DSN <NBMSSQL_7136_6552>, SQL userid <sa> handle <0x008d3c10>.
02:35:39.654 [7136.6552] <4> DBDisconnect: INF - Logging out of SQL Server with handle <0x008d3c10>
02:35:39.654 [7136.6552] <4> CDBbackcat::GetVirtualServer: INF - Accessing database instance <SVR-QAT-PDB-B> on virtual server <SVR-QAT-PDB-B>.
02:35:39.669 [7136.6552] <2> logconnections: bprd CONNECT FROM 172.30.252.173.3621 TO 192.168.51.3.13720
02:35:39.669 [7136.6552] <2> logconnections: BPRD CONNECT FROM 172.30.252.173.3621 TO 192.168.51.3.13720
02:35:39.904 [7136.6552] <4> CDBbackrec::CDBbackrec: INF - Use standard backup method with policy <POLICY_SQL_Daily2>.
02:35:39.904 [7136.7648] <4> DBConnect: INF - Logging into SQL Server with DSN <NBMSSQL_7136_6552>, SQL userid <sa> handle <0x008d3c10>.
02:35:39.904 [7136.7648] <4> DBDisconnect: INF - Logging out of SQL Server with handle <0x008d3c10>
02:35:39.904 [7136.7648] <4> Dbbackrec::PerformNBOperation: INF - DUMP STARTED USING
Microsoft SQL Server  2000 - 8.00.2039 (Intel X86) 
May  3 2005 23:18:38 
Copyright (c) 1988-2003 Microsoft Corporation
Enterprise Edition on Windows NT 5.2 (Build 3790: Service Pack 2) 
Batch = NBU_Full.bch, Op# = 2.
02:35:39.904 [7136.7648] <4> InitPipeInfo: INF - Using backup image 'svr-qat-pdb02.MSSQL7.SVR-QAT-PDB-B.db.bp-case-data-o1.~.7.001of001.20081022023539..C'.
02:35:39.904 [7136.7648] <4> Dbbackrec::CreateSQLcmdSyntax: INF - backup database "bp-case-data-o1" to VIRTUAL_DEVICE='VNBU0-7136-7648' with blocksize = 65536, maxtransfersize = 65536, buffercount = 1
02:35:39.904 [7136.7648] <4> Dbbackrec::CreateSQLcmdSyntax: INF - #Stripes: 1, #Bufs per stripe 1, To: NetBackup on MASTER-SERVER
02:35:39.904 [7136.7648] <4> DBConnect: INF - Logging into SQL Server with DSN <NBMSSQL_7136_6552>, SQL userid <sa> handle <0x008d3c10>.
02:35:39.904 [7136.7116] <2> logconnections: bprd CONNECT FROM 172.30.252.173.3624 TO 192.168.51.3.13720
02:35:39.904 [7136.7116] <2> logconnections: BPRD CONNECT FROM 172.30.252.173.3624 TO 192.168.51.3.13720
02:35:39.904 [7136.7648] <4> CDBbackrec::InitDeviceSet(): INF - Created VDI object for SQL Server instance <*DEFAULT*>. Connection timeout is <300> seconds.
02:35:40.232 [7136.7116] <2> logconnections: bprd CONNECT FROM 172.30.252.173.3625 TO 192.168.51.3.13720
02:35:40.232 [7136.7116] <2> logconnections: BPRD CONNECT FROM 172.30.252.173.3625 TO 192.168.51.3.13720

What I don't understand is what is creating these jobs in the first place.  Can anyone see or explain the root cause?

[Patrick_Whelan_]

Have you checked "Scheduled Tasks" to be sure there is nothing that could call bpbackup?

[a5972s]

Absolutely no scheduled tasks set up.

[Omar_Villa]

check this looks pretty similar to the log that you show

http://seer.entsupport.symantec.com/docs/280108.htm

also I place a search on the knowledge base for: "ERR - Error in VDS- Close" a lot of issues came up, dig a bit on them and probably you will find what you need.

regards