cancel
Showing results for 
Search instead for 
Did you mean: 

ERR - exit status: <2> <41>

svasilev
Level 3

AUTOMATIC_DATABASE_BACKUP

Apr 2, 2019 1:56:30 PM - Info nbjm (pid=6452) starting backup job (jobid=7972396) for client ************, policy Prophix-DBs, schedule Hourly
Apr 2, 2019 1:56:30 PM - Info nbjm (pid=6452) requesting MEDIA_SERVER_ONLY resources from RB for backup job (jobid=7972396, request id:{15A07788-7AD1-4032-A3EB-329244BF4990})
Apr 2, 2019 1:56:30 PM - requesting resource  M**T-SQL
Apr 2, 2019 1:56:30 PM - estimated 0 kbytes needed
Apr 2, 2019 1:56:30 PM - Info nbjm (pid=6452) started backup (backupid=************_1554202590) job for client ************, policy Prophix-DBs, schedule Hourly on storage unit 
Apr 2, 2019 1:56:32 PM - started process bpbrm (pid=8832)
Apr 2, 2019 1:56:33 PM - Info bpbrm (pid=8832) ************ is the host to backup data from
Apr 2, 2019 1:56:33 PM - Info bpbrm (pid=8832) reading file list for client
Apr 2, 2019 1:56:34 PM - connecting
Apr 2, 2019 1:56:35 PM - Info bpbrm (pid=8832) starting bphdb on client
Apr 2, 2019 1:56:35 PM - Info bphdb (pid=12072) Backup started
Apr 2, 2019 1:56:35 PM - connected; connect time: 0:00:00
Apr 2, 2019 1:56:36 PM - Info dbclient (pid=5164) INF - Intelligent policy initiated by server <srv-snbu01.M**T.ru>
Apr 2, 2019 1:56:37 PM - Info dbclient (pid=5164) INF - Intelligent policy <Prophix-DBs> is valid. The input file <C:\Program Files\Veritas\NetBackup\dbext\mssql\input.12072.0.0402119.135635> has been parsed successfully
Apr 2, 2019 1:56:38 PM - Info dbclient (pid=5164) INF - Instance server name resolved to: <PROPHIX-APP>
Apr 2, 2019 1:56:40 PM - Info dbclient (pid=5164) INF - Intelligent policy <Prophix-DBs> has resulted in <1> batch operation(s).
Apr 2, 2019 1:56:41 PM - Info dbclient (pid=5164) INF - Intelligent policy <Prophix-DBs>: <1> operation(s) will protect the database transaction logs.
Apr 2, 2019 1:56:42 PM - Info dbclient (pid=5164) INF - Intelligent policy preprocessing has finished, created temporary batch file <__13_56_39_925_00.bch>, and submitted it to the backend agent for processing
Apr 2, 2019 1:56:43 PM - Info dbclient (pid=5164) INF - Querying master.sys.database_recovery_status to determine last_log_backup_lsn for database Dev_PROPHIX_FactDb
Apr 2, 2019 1:56:44 PM - Info dbclient (pid=5164) INF - A full backup has already been performed on this database.
Apr 2, 2019 1:56:45 PM - Info dbclient (pid=5164) INF - No conversion required for transaction log backup.
Apr 2, 2019 1:56:47 PM - Info dbclient (pid=5164) INF - BACKUP STARTED USING
Apr 2, 2019 1:56:47 PM - Info dbclient (pid=5164) Microsoft SQL Server 2016 (SP1-CU11) (KB4459676) - 13.0.4528.0 (X64) 
Apr 2, 2019 1:56:47 PM - Info dbclient (pid=5164) Aug 30 2018 21:57:02 
Apr 2, 2019 1:56:47 PM - Info dbclient (pid=5164) Copyright (c) Microsoft Corporation
Apr 2, 2019 1:56:47 PM - Info dbclient (pid=5164) Enterprise Edition: Core-based Licensing (64-bit) on Windows Server 2016 Standard 10.0 <X64> (Build 14393: ) (Hypervisor) 
Apr 2, 2019 1:56:47 PM - Info dbclient (pid=5164) Batch = __13_56_39_925_00.bch, Op# = 1
Apr 2, 2019 1:56:49 PM - Info dbclient (pid=5164) INF - Using backup image PROPHIX-APP.MSSQL7.PROPHIX-APP.trx.Dev_PROPHIX_FactDb.~.7.001of001.20190402135646..C
Apr 2, 2019 1:56:50 PM - Info dbclient (pid=5164) INF - backup log "Dev_PROPHIX_FactDb" to VIRTUAL_DEVICE='VNBU0-5164-7736-1554202609' with  compression,  stats = 10, checksum, stop_on_error, blocksize = 65536, maxtransfersize = 4194304, buffercount = 2
Apr 2, 2019 1:56:51 PM - Info dbclient (pid=5164) INF - Number of stripes: 1, Number of buffers per stripe 2.
Apr 2, 2019 1:56:52 PM - Info dbclient (pid=5164) INF - Setting backup catalog name to: ************
Apr 2, 2019 1:56:52 PM - Info dbclient (pid=5164) INF - Created VDI object for SQL Server instance <PROPHIX-APP>. Connection timeout is <300> seconds.
Apr 2, 2019 3:36:21 PM - Info dbclient (pid=5164) ERR - Error in VxBSACreateObject: 3.
Apr 2, 2019 3:36:23 PM - Info dbclient (pid=5164)     CONTINUATION: - System detected error, operation aborted.
Apr 2, 2019 3:36:25 PM - Info dbclient (pid=5164) ERR - Error in GetCommand: 0x80770004.
Apr 2, 2019 3:36:26 PM - Info dbclient (pid=5164) INF - OPERATION #1 of batch __13_56_39_925_00.bch FAILED with STATUS 1 (0 is normal). Elapsed time = 5980(5980) seconds.
Apr 2, 2019 3:36:27 PM - Info dbclient (pid=5164)     CONTINUATION: - An abort request is preventing anything except termination actions.
Apr 2, 2019 3:36:29 PM - Info dbclient (pid=5164) INF - Results of executing <__13_56_39_925_00.bch>: 
Apr 2, 2019 3:36:29 PM - Info dbclient (pid=5164) <0> operations succeeded. <1> operations failed.
Apr 2, 2019 3:36:30 PM - Info dbclient (pid=5164) INF - The following object(s) were not backed up successfully.
Apr 2, 2019 3:36:32 PM - Info dbclient (pid=5164) INF - Dev_PROPHIX_FactDb
Apr 2, 2019 3:36:32 PM - Error bpbrm (pid=8832) from client ************: ERR - exit status: <2>
Apr 2, 2019 3:36:33 PM - Error bpbrm (pid=8832) from client ************: ERR - bphdb exit status = 2: none of the requested files were backed up
Apr 2, 2019 3:36:33 PM - Info bphdb (pid=12072) done. status: 2: none of the requested files were backed up
Apr 2, 2019 3:36:33 PM - end writing
none of the requested files were backed up  (2)

AND

Apr 2, 2019 1:56:55 PM - Info nbjm (pid=6452) starting backup job (jobid=7972398) for client ************, policy Prophix-DBs, schedule Hourly
Apr 2, 2019 1:56:55 PM - Info nbjm (pid=6452) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=7972398, request id:{4BE15C6D-B68B-4B9C-9EF5-A90C8B765BB2})
Apr 2, 2019 1:56:55 PM - requesting resource  MONT-SQL
Apr 2, 2019 1:56:55 PM - requesting resource  MASTER.NBU_CLIENT.MAXJOBS.************
Apr 2, 2019 1:56:55 PM - awaiting resource MONT-SQL. Maximum job count has been reached for the storage unit.
Apr 2, 2019 1:58:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:00:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:02:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:04:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:06:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:08:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:10:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:12:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:14:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:16:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:18:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:20:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:22:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:24:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:26:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:28:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:30:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:32:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:34:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:36:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:38:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:40:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:42:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:44:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:46:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:48:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:50:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:52:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:54:55 PM - Info nbjm (pid=6452) Waiting in NetBackup scheduler work queue on server MASTER
Apr 2, 2019 2:55:39 PM - granted resource  MASTER.NBU_CLIENT.MAXJOBS.************
Apr 2, 2019 2:55:39 PM - granted resource  MediaID=@aaaa6;DiskVolume=PureDiskVolume;DiskPool=DDUPool-01;Path=PureDiskVolume;StorageServer=srv-snbu08.mont.ru;MediaServer=srv-snbu03.mont.ru
Apr 2, 2019 2:55:39 PM - granted resource  DiskStorage-1
Apr 2, 2019 2:55:39 PM - estimated 2857766 kbytes needed
Apr 2, 2019 2:55:39 PM - Info nbjm (pid=6452) started backup (backupid=************_1554206139) job for client ************, policy Prophix-DBs, schedule Hourly on storage unit DiskStorage-1
Apr 2, 2019 2:55:41 PM - started process bpbrm (pid=12200)
Apr 2, 2019 2:55:41 PM - Info bpbrm (pid=12200) ************ is the host to backup data from
Apr 2, 2019 2:55:42 PM - connecting
Apr 2, 2019 2:55:42 PM - Info bpbrm (pid=12200) reading file list for client
Apr 2, 2019 2:55:43 PM - Info bpbrm (pid=12200) listening for client connection
Apr 2, 2019 2:55:44 PM - Info bpbrm (pid=12200) INF - Client read timeout = 900
Apr 2, 2019 2:55:44 PM - Info bpbrm (pid=12200) accepted connection from client
Apr 2, 2019 2:55:44 PM - Info dbclient (pid=5164) Backup started
Apr 2, 2019 2:55:44 PM - Info bptm (pid=11352) start
Apr 2, 2019 2:55:45 PM - connected; connect time: 0:00:00
Apr 2, 2019 2:55:45 PM - Info bptm (pid=11352) using 262144 data buffer size
Apr 2, 2019 2:55:45 PM - Info bptm (pid=11352) setting receive network buffer to 1049600 bytes
Apr 2, 2019 2:55:45 PM - Info bptm (pid=11352) using 30 data buffers
Apr 2, 2019 2:55:47 PM - Info bptm (pid=11352) start backup
Apr 2, 2019 3:19:03 PM - Info bptm (pid=11352) backup child process is pid 10980.10236
Apr 2, 2019 3:19:03 PM - begin writing
Apr 2, 2019 3:19:03 PM - Info bptm (pid=10980) start
Apr 2, 2019 3:39:06 PM - Info dbclient (pid=5164) done. status: 41: network connection timed out
Apr 2, 2019 3:39:06 PM - end writing; write time: 0:20:03
network connection timed out  (41)
5 REPLIES 5

svasilev
Level 3

What is the problem?
Backup runs on schedule

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

Please share dbclient log on the SQL client. Logging level 3 should be sufficient.
If dbclient log folder does not exist, please create it under ...netbackup\logs and set logging level to 3 for this client in Host Properties.

Please copy log file to dbclient.txt and upload as attachment. 

dbclient.txt in attachment

help us please

Hello
We have a new error - 2 (job 1) > 2 (job 2) > 41  (job 3)

Full backup - job 1:

Apr 8, 2019 4:43:19 PM - Info nbjm (pid=6452) starting backup job (jobid=8013185) for client srv-snbu01.dom.ru, policy NIKTA-DBs, schedule Weekly
Apr 8, 2019 4:43:19 PM - Info nbjm (pid=6452) requesting MEDIA_SERVER_ONLY resources from RB for backup job (jobid=8013185, request id:{71499A86-9497-488D-9764-C80504CFE895})
Apr 8, 2019 4:43:19 PM - requesting resource  DiskStorage-1
Apr 8, 2019 4:43:19 PM - requesting resource  srv-snbu01.dom.ru.NBU_CLIENT.MAXJOBS.srv-snbu01.dom.ru
Apr 8, 2019 4:43:19 PM - granted resource  srv-snbu01.dom.ru.NBU_CLIENT.MAXJOBS.srv-snbu01.dom.ru
Apr 8, 2019 4:43:20 PM - estimated 0 kbytes needed
Apr 8, 2019 4:43:20 PM - begin Parent Job
Apr 8, 2019 4:43:20 PM - begin Application Resolver: Start Notify Script
Apr 8, 2019 4:43:20 PM - Info RUNCMD (pid=8492) started
Apr 8, 2019 4:43:20 PM - Info RUNCMD (pid=8492) exiting with status: 0
Operation Status: 0
Apr 8, 2019 4:43:20 PM - end Application Resolver: Start Notify Script; elapsed time 0:00:00
Apr 8, 2019 4:43:20 PM - begin Application Resolver: Step By Condition
Operation Status: 0
Apr 8, 2019 4:43:20 PM - end Application Resolver: Step By Condition; elapsed time 0:00:00
Apr 8, 2019 4:43:20 PM - begin Application Resolver: Resolver Discovery
Operation Status: 0
Apr 8, 2019 4:43:21 PM - end Application Resolver: Resolver Discovery; elapsed time 0:00:01
Apr 8, 2019 4:43:21 PM - begin Application Resolver: Policy Execution Manager Preprocessed
Operation Status: 2
Apr 9, 2019 12:59:47 AM - end Application Resolver: Policy Execution Manager Preprocessed; elapsed time 8:16:26
Apr 9, 2019 12:59:47 AM - begin Application Resolver: Stop On Error
Operation Status: 0
Apr 9, 2019 12:59:47 AM - end Application Resolver: Stop On Error; elapsed time 0:00:00
Apr 9, 2019 12:59:47 AM - begin Application Resolver: End Notify Script
Apr 9, 2019 12:59:48 AM - Info RUNCMD (pid=1520) started
Apr 9, 2019 12:59:48 AM - Info RUNCMD (pid=1520) exiting with status: 0
Operation Status: 0
Apr 9, 2019 12:59:48 AM - end Application Resolver: End Notify Script; elapsed time 0:00:01
Operation Status: 2
Apr 9, 2019 12:59:48 AM - end Parent Job; elapsed time 8:16:28
none of the requested files were backed up  (2)

Job 2:

Apr 8, 2019 4:43:21 PM - Info nbjm (pid=6452) starting backup job (jobid=8013186) for client nikta-sql.dom.ru, policy NIKTA-DBs, schedule Weekly
Apr 8, 2019 4:43:21 PM - Info nbjm (pid=6452) requesting MEDIA_SERVER_ONLY resources from RB for backup job (jobid=8013186, request id:{8CAD7B27-479F-467A-AE9D-10C1B5174C4F})
Apr 8, 2019 4:43:21 PM - requesting resource  DiskStorage-1
Apr 8, 2019 4:43:22 PM - estimated 0 kbytes needed
Apr 8, 2019 4:43:22 PM - Info nbjm (pid=6452) started backup (backupid=nikta-sql.dom.ru_1554731001) job for client nikta-sql.dom.ru, policy NIKTA-DBs, schedule Weekly on storage unit 
Apr 8, 2019 4:43:23 PM - started process bpbrm (pid=4992)
Apr 8, 2019 4:43:24 PM - connecting
Apr 8, 2019 4:43:24 PM - Info bpbrm (pid=4992) nikta-sql.dom.ru is the host to backup data from
Apr 8, 2019 4:43:24 PM - Info bpbrm (pid=4992) reading file list for client
Apr 8, 2019 4:43:25 PM - Info bpbrm (pid=4992) starting bphdb on client
Apr 8, 2019 4:43:25 PM - Info bphdb (pid=11096) Backup started
Apr 8, 2019 4:43:25 PM - connected; connect time: 0:00:00
Apr 8, 2019 4:43:26 PM - Info dbclient (pid=5324) INF - Intelligent policy initiated by server <srv-snbu01.dom.ru>
Apr 8, 2019 4:43:27 PM - Info dbclient (pid=5324) INF - Intelligent policy <NIKTA-DBs> is valid. The input file <C:\Program Files\Veritas\NetBackup\dbext\mssql\input.11096.0.0408119.164325> has been parsed successfully
Apr 8, 2019 4:43:30 PM - Info dbclient (pid=5324) INF - Instance server name resolved to: <NIKTA-SQL-N2>
Apr 8, 2019 4:43:31 PM - Info dbclient (pid=5324) INF - Intelligent policy <NIKTA-DBs> has resulted in <1> batch operation(s).
Apr 8, 2019 4:43:34 PM - Info dbclient (pid=5324) INF - Intelligent policy <NIKTA-DBs>: <1> operation(s) will protect full databases.
Apr 8, 2019 4:43:36 PM - Info dbclient (pid=5324) INF - Intelligent policy preprocessing has finished, created temporary batch file <__16_43_31_830_00.bch>, and submitted it to the backend agent for processing
Apr 8, 2019 4:43:41 PM - Info dbclient (pid=5324) INF - BACKUP STARTED USING
Apr 8, 2019 4:43:41 PM - Info dbclient (pid=5324) Microsoft SQL Server 2016 (SP2-CU1) (KB4135048) - 13.0.5149.0 (X64) 
Apr 8, 2019 4:43:41 PM - Info dbclient (pid=5324) May 19 2018 09:41:57 
Apr 8, 2019 4:43:41 PM - Info dbclient (pid=5324) Copyright (c) Microsoft Corporation
Apr 8, 2019 4:43:41 PM - Info dbclient (pid=5324) Enterprise Edition: Core-based Licensing (64-bit) on Windows Server 2016 Standard 10.0 <X64> (Build 14393: ) (Hypervisor) 
Apr 8, 2019 4:43:41 PM - Info dbclient (pid=5324) Batch = __16_43_31_830_00.bch, Op# = 1
Apr 8, 2019 4:43:44 PM - Info dbclient (pid=5324) INF - Using backup image nikta-sql-clr.dom.ru:NIKTA-SQL-N2/MSSQL7/NIKTA-SQL-AG/db/MontNikta/~/7/001of001/20190408134340//C
Apr 8, 2019 4:43:46 PM - Info dbclient (pid=5324) INF - backup database "MontNikta" to VIRTUAL_DEVICE='VNBU0-5324-10808-1554731024' with  stats = 10, checksum, stop_on_error, blocksize = 65536, maxtransfersize = 4194304, buffercount = 2
Apr 8, 2019 4:43:48 PM - Info dbclient (pid=5324) INF - Availability group database detected. Setting backup catalog name to: nikta-sql-clr.dom.ru
Apr 8, 2019 4:43:48 PM - Info dbclient (pid=5324) INF - Number of stripes: 1, Number of buffers per stripe 2.
Apr 8, 2019 4:43:51 PM - Info dbclient (pid=5324) INF - Created VDI object for SQL Server instance <NIKTA-SQL-N2>. Connection timeout is <300> seconds.
Apr 8, 2019 4:45:27 PM - Info dbclient (pid=5324) INF - ODBC return code <2>, SQL State <01000>, SQL Message <3211><[Microsoft][SQL Server Native Client 11.0][SQL Server]10 percent processed.>.
Apr 8, 2019 4:46:48 PM - Info dbclient (pid=5324) INF - ODBC return code <2>, SQL State <01000>, SQL Message <3211><[Microsoft][SQL Server Native Client 11.0][SQL Server]20 percent processed.>.
Apr 8, 2019 5:09:02 PM - Info dbclient (pid=5324) INF - ODBC return code <2>, SQL State <01000>, SQL Message <3211><[Microsoft][SQL Server Native Client 11.0][SQL Server]30 percent processed.>.
Apr 8, 2019 6:30:33 PM - Info dbclient (pid=5324) INF - ODBC return code <2>, SQL State <01000>, SQL Message <3211><[Microsoft][SQL Server Native Client 11.0][SQL Server]40 percent processed.>.
Apr 8, 2019 8:05:33 PM - Info dbclient (pid=5324) INF - ODBC return code <2>, SQL State <01000>, SQL Message <3211><[Microsoft][SQL Server Native Client 11.0][SQL Server]50 percent processed.>.
Apr 8, 2019 8:51:49 PM - Info dbclient (pid=5324) INF - ODBC return code <2>, SQL State <01000>, SQL Message <3211><[Microsoft][SQL Server Native Client 11.0][SQL Server]60 percent processed.>.
Apr 8, 2019 10:02:46 PM - Info dbclient (pid=5324) INF - ODBC return code <2>, SQL State <01000>, SQL Message <3211><[Microsoft][SQL Server Native Client 11.0][SQL Server]70 percent processed.>.
Apr 8, 2019 11:00:46 PM - Info dbclient (pid=5324) INF - ODBC return code <2>, SQL State <01000>, SQL Message <3211><[Microsoft][SQL Server Native Client 11.0][SQL Server]80 percent processed.>.
Apr 9, 2019 12:06:15 AM - Info dbclient (pid=5324) INF - ODBC return code <2>, SQL State <01000>, SQL Message <3211><[Microsoft][SQL Server Native Client 11.0][SQL Server]90 percent processed.>.
Apr 9, 2019 12:59:23 AM - Info dbclient (pid=5324) ERR - Error in VxBSASendData: 1.
Apr 9, 2019 12:59:26 AM - Info dbclient (pid=5324)     CONTINUATION: - All backup jobs have completed.
Apr 9, 2019 12:59:28 AM - Info dbclient (pid=5324) ERR - Internal error. See the dbclient log for more information.
Apr 9, 2019 12:59:29 AM - Info dbclient (pid=5324) DBMS MSG - ODBC return code <-1>, SQL State <37000>, SQL Message <3202><[Microsoft][SQL Server Native Client 11.0][SQL Server]Write on "VNBU0-5324-10808-1554731024" failed: 995(The I/O operation has been aborted because of either a thread exit or an application request.)>.
Apr 9, 2019 12:59:29 AM - Info dbclient (pid=5324) ERR - Error in VxBSAGetServerError: 6.
Apr 9, 2019 12:59:30 AM - Info dbclient (pid=5324) DBMS MSG - SQL Message <3271><[Microsoft][SQL Server Native Client 11.0][SQL Server]A nonrecoverable I/O error occurred on file "VNBU0-5324-10808-1554731024:" 995(The I/O operation has been aborted because of either a thread exit or an application request.).>
Apr 9, 2019 12:59:30 AM - Info dbclient (pid=5324)     CONTINUATION: - The system cannot find the file specified.
Apr 9, 2019 12:59:31 AM - Info dbclient (pid=5324) DBMS MSG - SQL Message <3013><[Microsoft][SQL Server Native Client 11.0][SQL Server]BACKUP DATABASE is terminating abnormally.>
Apr 9, 2019 12:59:31 AM - Info dbclient (pid=5324) ERR - Error in VxBSAEndData: 6.
Apr 9, 2019 12:59:32 AM - Info dbclient (pid=5324) ERR - Error found executing <backup database "MontNikta" to VIRTUAL_DEVICE='VNBU0-5324-10808-1554731024' with  stats = 10, checksum, stop_on_error, blocksize = 65536, maxtransfersize = 4194304, buffercount = 2>.
Apr 9, 2019 12:59:32 AM - Info dbclient (pid=5324)     CONTINUATION: - The handle used to associate this call with a previous VxBSAInit() call is invalid.
Apr 9, 2019 12:59:34 AM - Info dbclient (pid=5324) INF - OPERATION #1 of batch __16_43_31_830_00.bch FAILED with STATUS 1 (0 is normal). Elapsed time = 29753(29753) seconds.
Apr 9, 2019 12:59:38 AM - Info dbclient (pid=5324) INF - Results of executing <__16_43_31_830_00.bch>: 
Apr 9, 2019 12:59:38 AM - Info dbclient (pid=5324) <0> operations succeeded. <1> operations failed.
Apr 9, 2019 12:59:41 AM - Info dbclient (pid=5324) INF - The following object(s) were not backed up successfully.
Apr 9, 2019 12:59:43 AM - Info dbclient (pid=5324) INF - MontNikta
Apr 9, 2019 12:59:46 AM - Error bpbrm (pid=4992) from client nikta-sql.dom.ru: ERR - exit status: <2>
Apr 9, 2019 12:59:46 AM - Error bpbrm (pid=4992) from client nikta-sql.dom.ru: ERR - bphdb exit status = 2: none of the requested files were backed up
Apr 9, 2019 12:59:47 AM - Info bphdb (pid=11096) done. status: 2: none of the requested files were backed up
Apr 9, 2019 12:59:47 AM - end writing
none of the requested files were backed up  (2)

Job 3:

Apr 8, 2019 4:43:50 PM - Info bpbrm (pid=1660) nikta-sql-n2.dom.ru is the host to backup data from
Apr 8, 2019 4:43:50 PM - Info bpbrm (pid=1660) reading file list for client
Apr 8, 2019 4:43:51 PM - Info bpbrm (pid=1660) listening for client connection
Apr 8, 2019 4:43:52 PM - Info bpbrm (pid=1660) INF - Client read timeout = 900
Apr 8, 2019 4:43:52 PM - Info bpbrm (pid=1660) accepted connection from client
Apr 8, 2019 4:43:52 PM - Info dbclient (pid=5324) Backup started
Apr 8, 2019 4:43:52 PM - Info bptm (pid=2296) start
Apr 8, 2019 4:43:52 PM - Info bptm (pid=2296) using 262144 data buffer size
Apr 8, 2019 4:43:53 PM - Info bptm (pid=2296) setting receive network buffer to 1049600 bytes
Apr 8, 2019 4:43:53 PM - Info bptm (pid=2296) using 30 data buffers
Apr 8, 2019 4:43:54 PM - Info bptm (pid=2296) start backup
Apr 8, 2019 4:43:55 PM - Info nbjm (pid=6452) starting backup job (jobid=8013187) for client nikta-sql-n2.dom.ru, policy NIKTA-DBs, schedule Weekly
Apr 8, 2019 4:43:55 PM - Info nbjm (pid=6452) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=8013187, request id:{8770D3B7-7E05-466C-B93B-F8BA9EC73500})
Apr 8, 2019 4:43:55 PM - requesting resource  DiskStorage-1
Apr 8, 2019 4:43:55 PM - requesting resource  srv-snbu01.dom.ru.NBU_CLIENT.MAXJOBS.nikta-sql-n2.dom.ru
Apr 8, 2019 4:43:55 PM - granted resource  srv-snbu01.dom.ru.NBU_CLIENT.MAXJOBS.nikta-sql-n2.dom.ru
Apr 8, 2019 4:43:55 PM - granted resource  MediaID=@aaaa6;DiskVolume=PureDiskVolume;DiskPool=DDUPool-01;Path=PureDiskVolume;StorageServer=srv-snbu08.dom.ru;MediaServer=srv-snbu02.dom.ru
Apr 8, 2019 4:43:55 PM - granted resource  DiskStorage-1
Apr 8, 2019 4:43:55 PM - estimated 0 kbytes needed
Apr 8, 2019 4:43:55 PM - Info nbjm (pid=6452) started backup (backupid=nikta-sql-clr.dom.ru_1554731035) job for client nikta-sql-n2.dom.ru, policy NIKTA-DBs, schedule Weekly on storage unit DiskStorage-1
Apr 8, 2019 4:43:57 PM - started process bpbrm (pid=1660)
Apr 8, 2019 4:43:58 PM - connecting
Apr 8, 2019 4:44:00 PM - connected; connect time: 0:00:00
Apr 8, 2019 4:44:01 PM - Info bptm (pid=2296) backup child process is pid 6588.8124
Apr 8, 2019 4:44:01 PM - Info bptm (pid=6588) start
Apr 8, 2019 4:44:09 PM - begin writing
Apr 9, 2019 12:58:45 AM - Info dbclient (pid=5324) done. status: 41: network connection timed out
Apr 9, 2019 12:58:55 AM - end writing; write time: 8:14:46
network connection timed out  (41)

dbclient in attachment

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

@svasilev 

My time is very limited to read logs, but I have started to go through the previous logs.

This is what I have seen:

Backup started here:
12:48:37.302 [2252.14528] <4> CreateNewImage: INF - backing up File:</nikta-sql-clr.mont.ru:NIKTA-SQL-N2/MSSQL7/NIKTA-SQL-AG/db/MontNikta/~/7/001of001/20190408094826//C>


There is no indication of what happened between these 2 timestamps:
12:48:37.755
13:27:57.562

But data collection within SQL only started here:

13:29:23.937 [2252.14528] <4> CDBbackmain::CollectFEDS: INF - Database < MontNikta > in SQL Instance < MSSQLSERVER > has a size of < 225000.00 MB >
13:29:23.937 [2252.14528] <4> CDBbackmain::CollectFEDS: INF - FEDS Data: Job ID < 8012046 >, Virtual Name < nikta-sql-clr.mont.ru >, Backup ID < >, Instance < MSSQLSERVER >, AG < NIKTA-SQL-AG >, Database < MontNikta >

13:40:43.291 [2252.6784] <4> CODBCaccess::LogODBCerr: INF - ODBC return code <2>, SQL State <01000>, SQL Message <3211><[Microsoft][SQL Server Native Client 11.0][SQL Server]10 percent processed.>.

14:05:28.979 [2252.6784] <4> CODBCaccess::LogODBCerr: INF - ODBC return code <2>, SQL State <01000>, SQL Message <3211><[Microsoft][SQL Server Native Client 11.0][SQL Server]20 percent processed.>.

15:13:00.754 [2252.6784] <4> CODBCaccess::LogODBCerr: INF - ODBC return code <2>, SQL State <01000>, SQL Message <3211><[Microsoft][SQL Server Native Client 11.0][SQL Server]30 percent processed.>.

It seems that data transfer then got to a halt, with timeout after 30 minutes:

15:33:00.256 [2252.14528] <16> writeToServer: ERR - send() to server on socket failed:
15:33:00.256 [2252.14528] <16> dbc_put: ERR - failed sending data to server
15:33:00.256 [2252.14528] <4> closeApi: INF - EXIT STATUS 6: the backup failed to back up the requested files

Have a look at the timestamps between start, 10, 20 and 30%:
The 1st 10% took 11 minutes. So, acceptable read speed of more than 34 MB/sec.
The next 10% took 25 minutes.
To get from 20% to 30% took 68 minutes. 

So, it looks like possible resource issues on the SQL server during backup.

You will need the assistance of server owner and SQL dba to monitor the server during backup.
The need to check system performance - cpu and memory.
Check Event Viewer Application and System logs.
Check SQL VDI.log, and ERRORLOG.

From NBU point of view, these logs will confirm up to when data and metadata was received from the SQL client:
bpbrm on the media server (connection, metadata and timeout info)
bptm on media server (data received from client)
All of these logs should be at minimum of level 3.