SQL Agent backup jobs end with Status 6 or 150

Question

Hi guys,
I have a problem backing up one particular database on an SQL 2005 server using the Netbackup SQL agent. There are about 8 or 10 databases on this server and all backup OK except one, which generally fails with status 6 or status 150. The database is 400GB in size, so is quite large, and used to backup without any issues.
I have looked through the SQL server's event logs and NBU logs - some extracts below. I did find an SQL 995 Operating System error, and wondered if this is an SQL bug? But as mentioned all other databases for this server backup fine.
Any help anyone can provide would be appreciated. Colin.
Event Type:&nbsp;Error
	Event Source:&nbsp;MSSQLSERVER
	Event Category:&nbsp;(6)
	Event ID:&nbsp;17055
	Date:&nbsp;&nbsp;19/04/2012
	Time:&nbsp;&nbsp;07:00:09
	User:&nbsp;&nbsp;NT AUTHORITY\SYSTEM
	Computer:&nbsp;server-name
	Description:
	3041 :
	BACKUP failed to complete the command backup database "database-name" to VIRTUAL_DEVICE='VNBU0-5188-2076-1334779681' with blocksize = 65536, maxtransfersize = 65536, buffercount = 1

For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp.
	Data:
	0000: e1 0b 00 00 10 00 00 00&nbsp;&nbsp; á.......
	0008: 0f 00 00 00 47 00 42 00&nbsp;&nbsp; ....G.B.
	0010: 45 00 44 00 43 00 2d 00&nbsp;&nbsp; E.D.C.-.
	0018: 53 00 51 00 4c 00 53 00&nbsp;&nbsp; S.Q.L.S.
	0020: 43 00 50 00 30 00 32 00&nbsp;&nbsp; C.P.0.2.
	0028: 00 00 00 00 00 00&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; ......
Event Type:&nbsp;Error
	Event Source:&nbsp;MSSQLSERVER
	Event Category:&nbsp;(2)
	Event ID:&nbsp;17055
	Date:&nbsp;&nbsp;19/04/2012
	Time:&nbsp;&nbsp;07:00:09
	User:&nbsp;&nbsp;NT AUTHORITY\SYSTEM
	Computer:&nbsp;server-name
	Description:
	18210 :
	BackupMedium::ReportIoError: write failure on backup device 'VNBU0-5188-2076-1334779681'. Operating system error 995(error not found).

For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp.
	Data:
	0000: 22 47 00 00 10 00 00 00&nbsp;&nbsp; "G......
	0008: 0f 00 00 00 47 00 42 00&nbsp;&nbsp; ....G.B.
	0010: 45 00 44 00 43 00 2d 00&nbsp;&nbsp; E.D.C.-.
	0018: 53 00 51 00 4c 00 53 00&nbsp;&nbsp; S.Q.L.S.
	0020: 43 00 50 00 30 00 32 00&nbsp;&nbsp; C.P.0.2.
	0028: 00 00 00 00 00 00&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; ......&nbsp;
Event Type:&nbsp;Error
	Event Source:&nbsp;MSSQLSERVER
	Event Category:&nbsp;(2)
	Event ID:&nbsp;17055
	Date:&nbsp;&nbsp;19/04/2012
	Time:&nbsp;&nbsp;07:00:09
	User:&nbsp;&nbsp;NT AUTHORITY\SYSTEM
	Computer:&nbsp;server-name
	Description:
	18210 :
	BackupVirtualDeviceFile::RequestDurableMedia: Flush failure on backup device 'VNBU0-5188-2076-1334779681'. Operating system error 995(error not found).

For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp.
	Data:
	0000: 22 47 00 00 10 00 00 00&nbsp;&nbsp; "G......
	0008: 0f 00 00 00 47 00 42 00&nbsp;&nbsp; ....G.B.
	0010: 45 00 44 00 43 00 2d 00&nbsp;&nbsp; E.D.C.-.
	0018: 53 00 51 00 4c 00 53 00&nbsp;&nbsp; S.Q.L.S.
	0020: 43 00 50 00 30 00 32 00&nbsp;&nbsp; C.P.0.2.
	0028: 00 00 00 00 00 00&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; ......&nbsp;
07:00:04.451 [5188.5652] &lt;16&gt; writeToServer: ERR - send() to server on socket failed: An existing connection was forcibly closed by the remote host.
	07:00:04.451 [5188.5652] &lt;16&gt; dbc_put: ERR - writeToServer() failed when sending keepalive
	07:00:04.451 [5188.5652] &lt;16&gt; writeToServer: ERR - send() to server on socket failed: An existing connection was forcibly closed by the remote host.
	07:00:04.451 [5188.5652] &lt;16&gt; closeApi: ERR - could not write client EXIT STATUS message to the NAME socket
	07:00:04.451 [5188.5652] &lt;16&gt; VxBSASendData: ERR - Could not do a bsa_put().
	07:00:04.451 [5188.5652] &lt;4&gt; getServerName: Read server name from nb_master_config: master-server
	07:00:04.482 [5188.5652] &lt;2&gt; vnet_vnetd_service_socket: ..\libvlibs\vnet_vnetd.c.2034: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
	07:00:04.482 [5188.5652] &lt;2&gt; vnet_vnetd_service_socket: ..\libvlibs\vnet_vnetd.c.2048: service: bprd
	07:00:04.701 [5188.5652] &lt;2&gt; logconnections: BPRD CONNECT FROM client-ip.4610 TO master-ip.13724
	07:00:04.982 [5188.5652] &lt;4&gt; getServerName: Read server name from nb_master_config: master-server
	07:00:04.998 [5188.5652] &lt;2&gt; vnet_vnetd_service_socket: ..\libvlibs\vnet_vnetd.c.2034: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
	07:00:04.998 [5188.5652] &lt;2&gt; vnet_vnetd_service_socket: ..\libvlibs\vnet_vnetd.c.2048: service: bprd
	07:00:05.217 [5188.5652] &lt;2&gt; logconnections: BPRD CONNECT FROM client-ip.4611 TO master-ip.13724
	07:00:09.279 [5188.5652] &lt;16&gt; DBthreads::dbclient: ERR - Error in VxBSASendData: 1.
	07:00:09.279 [5188.5652] &lt;1&gt; DBthreads::dbclient:&nbsp;&nbsp;&nbsp;&nbsp; CONTINUATION: - All backup jobs have completed.
	07:00:09.279 [5188.5652] &lt;8&gt; close_image: Session being terminated abnormally, cleaning up
	07:00:09.279 [5188.5652] &lt;4&gt; close_image: INF - backup FAILED
	07:00:09.279 [5188.5652] &lt;4&gt; close_image: INF ---- end of Backup ---
07:00:09.279 [5188.5652] &lt;4&gt; KillAllThreads: INF - Killing group #0
	07:00:09.279 [5188.5652] &lt;4&gt; KillAllThreads: INF - Issuing SignalAbort to MS SQL Server VDI
	07:00:09.279 [5188.2040] &lt;4&gt; KillAllThreads: INF - Killing group #0
	07:00:09.279 [5188.2228] &lt;4&gt; KillAllThreads: INF - Killing group #0
	07:00:09.435 [5188.5652] &lt;16&gt; CDBbackrec::ProcessVxBSAerror: ERR - Error in DBthreads::dbclient: 6.
	07:00:09.435 [5188.5652] &lt;1&gt; CDBbackrec::ProcessVxBSAerror:&nbsp;&nbsp;&nbsp;&nbsp; CONTINUATION: - The system cannot find the file specified.
	07:00:09.435 [5188.5652] &lt;16&gt; DBthreads::dbclient: ERR - Error in VxBSAEndData: 6.
	07:00:09.435 [5188.5652] &lt;1&gt; DBthreads::dbclient:&nbsp;&nbsp;&nbsp;&nbsp; CONTINUATION: - The handle used to associate this call with a previous VxBSAInit() call is invalid.
	07:00:12.279 [5188.2076] &lt;4&gt; DBDisconnect: INF - Logging out of SQL Server with handle &lt;0x00b21a20&gt;
	07:00:12.279 [5188.2076] &lt;4&gt; getServerName: Read server name from nb_master_config: master-server
	07:00:12.295 [5188.2076] &lt;2&gt; vnet_vnetd_service_socket: ..\libvlibs\vnet_vnetd.c.2034: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
	07:00:12.295 [5188.2076] &lt;2&gt; vnet_vnetd_service_socket: ..\libvlibs\vnet_vnetd.c.2048: service: bprd
	07:00:12.514 [5188.2076] &lt;2&gt; logconnections: BPRD CONNECT FROM client-ip.4618 TO master-ip.13724
	07:00:16.608 [5188.2076] &lt;16&gt; CDBbackrec::FreeDeviceSet(): ERR - Error in VDS-&gt;Close: 0x80770004.
	07:00:16.608 [5188.2076] &lt;1&gt; CDBbackrec::FreeDeviceSet():&nbsp;&nbsp;&nbsp;&nbsp; CONTINUATION: - An abort request is preventing anything except termination actions.
	07:00:16.608 [5188.2076] &lt;4&gt; Dbbackrec::Perform: INF - OPERATION #7 of batch C:\Program Files\VERITAS\NetBackup\DbExt\MsSql\sqlfull.bch FAILED with STATUS 1 (0 is normal). Elapsed time = 31935(0) seconds.
	07:00:18.623 [5188.4596] &lt;4&gt; CDBbackmain::dbbackup: INF - Results of executing &lt;C:\Program Files\VERITAS\NetBackup\DbExt\MsSql\sqlfull.bch&gt;:
&lt;6&gt; operations succeeded. &lt;1&gt; operations failed.
INFO Server Status:&nbsp; Communication with the server has not been iniatated or the server status has not been retrieved from the server.
	INFO Error in VxBSASendData: 1.
	INFO All backup jobs have completed.
	INFO Error in DBthreads::dbclient: 6.
	INFO The system cannot find the file specified.
	INFO Error in VxBSAEndData: 6.
	INFO The handle used to associate this call with a previous VxBSAInit() call is invalid.
	ENDOPER TRUE
	&nbsp;

aalmroth · Answer

You say it generally fails now; does it mean it works sometimes?
From the log it would seem that the media server has diconnected the session, hence the write error to the BSA object. If this is an incremental backup, it could be due to client read timeout setting, as incremental backups sometimes does not write data for an extended period, thus the media server disconnects.
You could check on the media server's bpbrm/bptm log files if this is the case. If so, adjust the client read timeout for the DB server in media server settings.
/A
&nbsp;

marianne · Answer

Wee need to see full dbclient log to see what happened prior to this:

07:00:04.451 [5188.5652] &lt;16&gt; writeToServer: ERR - send() to server on socket failed: An existing connection was forcibly closed by the remote host.

You will also need bpbrm and bptm logs on the media server.
The above error indicates a possible timeout on the media server, but we do not have sufficient info to say for sure.
We often see large database backups fail due to timeout.
	For this reason we increase 'Client Connect Timeout' and 'Client Read Timeout' to 1800 (as a start) on the media server(s).
&nbsp;

colin_north · Answer

Thanks for the replies - I have adjusted the client read timeout value from 300 to 1800, I had thought that this could be a cause.
I'll run the backup job again this evening, will post if there's any further issues.
Colin.

colin_north · Answer

Looked like a timeout issue, so adjusting the client read timeout settings helped. I did open a call with Symantec, but that wasn't much help.

marianne · Answer

We would love to assist, but without the logs that I mentioned above we are merely guessing.

Forum Discussion

SQL Agent backup jobs end with Status 6 or 150

6 Replies

Related Content

VM backup failing with status 23 and status 6

exit status 140

Status Code:8500 Error when trying to install agent on new server

Vmware Backup Status code 50

BAckup fails with status 24