04-16-2019 10:57 AM
log
Apr 16, 2019 8:58:11 AM - Info ndmpagent (pid=1540) Backup started
Apr 16, 2019 8:58:11 AM - Info ndmpagent (pid=1540) PATH(s) found in file list = 1
Apr 16, 2019 8:58:11 AM - Info bptm (pid=8372) start
Apr 16, 2019 8:58:11 AM - Info bptm (pid=8372) using 30 data buffers
Apr 16, 2019 8:58:11 AM - Info ndmpagent (pid=1540) PATH[1 of 1]: /vol/users
Apr 16, 2019 8:58:11 AM - Info bptm (pid=8372) using 65536 data buffer size
Apr 16, 2019 8:58:11 AM - Info bptm (pid=8372) start backup
Apr 16, 2019 9:36:07 AM - Info ndmpagent (pid=1540) electra-adm: DUMP: Tue Apr 16 09:35:36 2019 : We have written 9260335 KB.
Apr 16, 2019 9:41:08 AM - Info ndmpagent (pid=1540) electra-adm: DUMP: Tue Apr 16 09:40:36 2019 : We have written 11495897 KB.
Apr 16, 2019 9:53:42 AM - Error bptm (pid=8372) io_ioctl_ndmp (MTBSF) failed on media id 0212L4, drive index 8, return code 19 (NDMP_ILLEGAL_STATE_ERR) (../bptm.c.8504)
Apr 16, 2019 9:53:42 AM - Info bptm (pid=8372) EXITING with status 23 <----------
Apr 16, 2019 9:53:43 AM - Error ndmpagent (pid=1540) send error status = 18 (NDMP_XDR_DECODE_ERR)
Apr 16, 2019 9:53:45 AM - Error ndmpagent (pid=1540) SendControlMessage failed, disabling connection 0000000001223390 and exiting
Apr 16, 2019 9:53:47 AM - Error ndmpagent (pid=1540) terminated by parent process
Apr 16, 2019 9:53:49 AM - Error ndmpagent (pid=1540) MoverGetState called with no session
Apr 16, 2019 9:53:51 AM - Error ndmpagent (pid=1540) NDMP backup failed, path = /vol/users/
Apr 16, 2019 9:53:55 AM - Info ndmpagent (pid=0) done
Apr 16, 2019 9:53:55 AM - Info ndmpagent (pid=0) done. status: 23: socket read failed
Apr 16, 2019 9:53:55 AM - end writing; write time: 0:53:03
Apr 16, 2019 11:07:10 AM - job 160364 was restarted as job 160375
socket read failed (23)
This job has ran for years with no issues.
A smaller job pointing to /vol/users/xyz runs fine.
Added touch file and get same failure.
Fails on Full and Incremental.
Solution
To reduce the load on the bpdbm process, create the MAX_FILES_PER_ADD touch file on the media server.
On a Windows media server:
- Create the file in the install_path\Veritas\NetBackup directory, and in the file, place the value 25000.
04-16-2019 12:57 PM
Hi @baron167
Can you share with us these logs?
bpbrm
bptm
ndmpagent
NetBackup STATUS 23, NDMP backups fail after the data has been transferred to the tape storage
Thiago
04-18-2019 12:38 PM
Sorry for late reply. Logs attached.
04-22-2019 07:58 AM
Hi @baron167
It seems that thare is a problem with your tape drive, maybe it not ready for use or busy...Did you already check your library/robot?
bptm_log_failures.log (5 hits)
Line 239: 07:21:02.820 [7476.8008] <16> check_and_process_ndmpagent_backup_tasks: ndmp_xm_get_kbytes failed
Line 280: 07:23:57.685 [7476.8008] <16> io_ioctl: io_ioctl_ndmp (MTBSF) failed on media id 5992L4, drive index 4, return code 19 (NDMP_ILLEGAL_STATE_ERR) (../bptm.c.8504)
Line 601: 08:04:33.564 [3876.8448] <16> check_and_process_ndmpagent_backup_tasks: ndmp_xm_get_kbytes failed
Line 620: 08:05:15.514 [3876.8448] <16> io_ioctl: io_ioctl_ndmp (MTBSF) failed on media id 0212L4, drive index 6, return code 19 (NDMP_ILLEGAL_STATE_ERR) (../bptm.c.8504)
Line 691: 08:06:19.867 [7184.8172] <16> open_ndmp_device: cannot open ndmp device nrst11a, error code 2 (NDMP_DEVICE_BUSY_ERR)
Take a look this article
Thiago
04-22-2019 08:03 AM
That actual problem is the global 300 sec timeout setting within NBU. The setting was changed to 1000 seconds and the backup is once again completing sucessfully. Apparently the NDMP/NetApp side had recently evolved to a pause or delay beyong the 300 seceonds. We had a very difficult time figuring this one out.