cancel
Showing results for 
Search instead for 
Did you mean: 

NDMP Error 99

AlChie
Level 4

Greetings I am recieving this kind of error on NDMP backup.
What could be the cause of it?

This NDMP backup goes in 2 concurrent streams. One of it finished with successfull status 0.
I am ready to gather all needed logs.

These are job details of failed stream:

06/26/2017 15:32:38 - Info nbjm (pid=22242) starting backup job (jobid=2699249) for client loko1.ca.sbrf.ru, policy Loko1_Weekly, schedule Full
06/26/2017 15:32:38 - Info nbjm (pid=22242) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=2699249, request id:{8A56B56A-5A6B-11E7-9844-0010E02070F6})
06/26/2017 15:32:38 - requesting resource Loko1_Q-M522_TLD8
06/26/2017 15:32:38 - requesting resource netback.cgs.sbrf.ru.NBU_CLIENT.MAXJOBS.loko1.ca.sbrf.ru
06/26/2017 15:32:38 - requesting resource netback.cgs.sbrf.ru.NBU_POLICY.MAXJOBS.Loko1_Weekly
06/26/2017 15:32:39 - Waiting for scan drive stop M522_Drive_1, Media server: kamaz52m
06/26/2017 15:32:41 - granted resource  netback.cgs.sbrf.ru.NBU_CLIENT.MAXJOBS.loko1.ca.sbrf.ru
06/26/2017 15:32:41 - granted resource  netback.cgs.sbrf.ru.NBU_POLICY.MAXJOBS.Loko1_Weekly
06/26/2017 15:32:41 - granted resource  Q52692
06/26/2017 15:32:41 - granted resource  M522_Drive_1
06/26/2017 15:32:41 - granted resource  Loko1_Q-M522_TLD8
06/26/2017 15:32:41 - estimated 1000972000 kbytes needed
06/26/2017 15:32:41 - Info nbjm (pid=22242) started backup (backupid=loko1.ca.sbrf.ru_1498480361) job for client loko1.ca.sbrf.ru, policy Loko1_Weekly, schedule Full on storage unit Loko1_Q-M522_TLD8
06/26/2017 15:32:42 - started process bpbrm (pid=18953)
06/26/2017 15:32:43 - connecting
06/26/2017 15:32:43 - Info bpbrm (pid=18953) loko1.ca.sbrf.ru is the host to backup data from
06/26/2017 15:32:43 - Info bpbrm (pid=18953) reading file list for client
06/26/2017 15:32:43 - Info bpbrm (pid=18953) starting ndmpagent on client
06/26/2017 15:32:43 - Info ndmpagent (pid=18961) Backup started
06/26/2017 15:32:43 - Info bpbrm (pid=18953) bptm pid: 18962
06/26/2017 15:32:43 - Info ndmpagent (pid=18961) PATH(s) found in file list = 1
06/26/2017 15:32:43 - Info ndmpagent (pid=18961) PATH[1 of 1]: SET HIST=y
06/26/2017 15:32:43 - Info ndmpagent (pid=18961) PATH[1 of 1]: SET ENHANCED_DAR_ENABLED=Y
06/26/2017 15:32:43 - connected; connect time: 0:00:00
06/26/2017 15:32:44 - Info bptm (pid=18962) start
06/26/2017 15:32:44 - Info ndmpagent (pid=18961) PATH[1 of 1]: /DM1-NT4/vol4/FR_SBT_PDA
06/26/2017 15:32:44 - Info bptm (pid=18962) using 256 data buffers
06/26/2017 15:32:44 - Info bptm (pid=18962) using 65536 data buffer size
06/26/2017 15:32:44 - Info bptm (pid=18962) start backup
06/26/2017 15:32:44 - Info bptm (pid=18962) Waiting for mount of media id Q52692 (copy 1) on server kamaz52m.
06/26/2017 15:32:44 - mounting Q52692
06/26/2017 15:33:34 - Info bptm (pid=18962) media id Q52692 mounted on drive index 88, drivepath c80t0l0, drivename M522_Drive_1, copy 1
06/26/2017 15:33:34 - mounted Q52692; mount time: 0:00:50
06/26/2017 15:33:40 - positioning Q52692 to file 29
06/26/2017 15:35:30 - Info ndmpagent (pid=18961) NDMP Local - tape host and data host match
06/26/2017 15:35:30 - positioned Q52692; position time: 0:01:50
06/26/2017 15:35:30 - begin writing
06/26/2017 16:34:40 - Info ndmpagent (pid=18961) loko1.ca.sbrf.ru: End of tape reached. Load next tape.
06/26/2017 16:34:48 - current media Q52692 complete, requesting next media Any
06/26/2017 16:34:48 - Waiting for scan drive stop M522_Drive_3, Media server: kamaz52m
06/26/2017 16:35:20 - granted resource  3497L5
06/26/2017 16:35:20 - granted resource  M522_Drive_3
06/26/2017 16:35:20 - granted resource  Loko1_Q-M522_TLD8
06/26/2017 16:35:21 - end writing; write time: 0:59:51
06/26/2017 16:35:21 - mounting 3497L5
06/26/2017 16:35:21 - Info bptm (pid=18962) Waiting for mount of media id 3497L5 (copy 1) on server kamaz52m.
06/26/2017 16:36:11 - Info bptm (pid=18962) media id 3497L5 mounted on drive index 84, drivepath c32t0l0, drivename M522_Drive_3, copy 1
06/26/2017 16:36:11 - mounted 3497L5; mount time: 0:00:50
06/26/2017 16:36:17 - positioning 3497L5 to file 1
06/26/2017 16:36:30 - positioned 3497L5; position time: 0:00:13
06/26/2017 16:36:30 - begin writing
06/26/2017 17:07:49 - Error bpbrm (pid=18953) db_FLISTsend failed: file read failed (13)
06/26/2017 17:07:49 - Error ndmpagent (pid=18961) write socket err 4 (Interrupted system call)
06/26/2017 17:07:50 - Error ndmpagent (pid=18961) FH send to BRM failed - Ino - 212654 0 212654 0 650063 0 0 6 33188 44837 301000 212654 1496819903 1490367030 1493795750 000000c4735dfba900000000000b1ef8 728824
06/26/2017 17:07:50 - Error ndmpagent (pid=18961) NDMP backup failed, path = /DM1-NT4/vol4/FR_SBT_PDA
06/26/2017 17:07:50 - Warning ndmpagent (pid=18961) loko1.ca.sbrf.ru: Backup was aborted
06/26/2017 17:07:51 - Info ndmpagent (pid=18961) loko1.ca.sbrf.ru: server_archive: emctar vol 1, 651001 files, 0 bytes read, 844323749888 bytes written
06/26/2017 17:07:51 - Error ndmpagent (pid=18961) loko1.ca.sbrf.ru: Backup is aborted.
06/26/2017 17:07:52 - Error bptm (pid=18962) io_ioctl_ndmp (MTBSF) failed on media id 3497L5, drive index 84, return code 18 (NDMP_XDR_DECODE_ERR) (../bptm.c.8439)
06/26/2017 17:07:52 - Critical bpbrm (pid=18953) unexpected termination of client loko1.ca.sbrf.ru
06/26/2017 17:07:52 - Info bptm (pid=18962) EXITING with status 99 <----------
06/26/2017 17:07:52 - Info ndmpagent (pid=0) done. status: 99: NDMP backup failure
06/26/2017 17:07:52 - end writing; write time: 0:31:22
NDMP backup failure  (99)

These are job details of successfull stream:

06/26/2017 11:06:10 - Info nbjm (pid=22242) starting backup job (jobid=2697438) for client loko1.ca.sbrf.ru, policy Loko1_Weekly, schedule Full
06/26/2017 11:06:11 - estimated 1020639199 kbytes needed
06/26/2017 11:06:11 - Info nbjm (pid=22242) started backup (backupid=loko1.ca.sbrf.ru_1498464371) job for client loko1.ca.sbrf.ru, policy Loko1_Weekly, schedule Full on storage unit Loko1_Q-M522_TLD8
06/26/2017 11:06:12 - started process bpbrm (pid=29353)
06/26/2017 11:06:13 - connecting
06/26/2017 11:06:13 - connected; connect time: 0:00:00
06/26/2017 11:06:13 - Info bpbrm (pid=29353) loko1.ca.sbrf.ru is the host to backup data from
06/26/2017 11:06:13 - Info bpbrm (pid=29353) reading file list for client
06/26/2017 11:06:13 - Info bpbrm (pid=29353) starting ndmpagent on client
06/26/2017 11:06:13 - Info ndmpagent (pid=29355) Backup started
06/26/2017 11:06:13 - Info ndmpagent (pid=29355) PATH(s) found in file list = 1
06/26/2017 11:06:13 - Info bpbrm (pid=29353) bptm pid: 29358
06/26/2017 11:06:13 - Info ndmpagent (pid=29355) PATH[1 of 1]: SET HIST=y
06/26/2017 11:06:13 - Info ndmpagent (pid=29355) PATH[1 of 1]: SET ENHANCED_DAR_ENABLED=Y
06/26/2017 11:06:14 - Info bptm (pid=29358) start
06/26/2017 11:06:14 - Info bptm (pid=29358) using 256 data buffers
06/26/2017 11:06:14 - Info bptm (pid=29358) using 65536 data buffer size
06/26/2017 11:06:14 - Info ndmpagent (pid=29355) PATH[1 of 1]: /DM1-NT1/vol1/AZVCS
06/26/2017 11:06:14 - Info bptm (pid=29358) start backup
06/26/2017 11:06:14 - Info bptm (pid=29358) Waiting for mount of media id Q52692 (copy 1) on server kamaz52m.
06/26/2017 11:06:14 - mounting Q52692
06/26/2017 11:07:04 - Info bptm (pid=29358) media id Q52692 mounted on drive index 88, drivepath c80t0l0, drivename M522_Drive_1, copy 1
06/26/2017 11:07:05 - mounted Q52692; mount time: 0:00:51
06/26/2017 11:07:11 - positioning Q52692 to file 27
06/26/2017 11:07:44 - positioned Q52692; position time: 0:00:33
06/26/2017 11:07:44 - begin writing
06/26/2017 11:07:45 - Info ndmpagent (pid=29355) NDMP Local - tape host and data host match
06/26/2017 12:51:53 - Info ndmpagent (pid=29355) loko1.ca.sbrf.ru: server_archive: emctar vol 1, 1642 files, 0 bytes read, 895783851086 bytes written
06/26/2017 12:51:53 - Info ndmpagent (pid=29355) NDMP backup successfully completed, path = /DM1-NT1/vol1/AZVCS
06/26/2017 12:52:16 - Info bptm (pid=29358) EXITING with status 0 <----------
06/26/2017 12:52:16 - Info bpbrm (pid=29353) validating image for client loko1.ca.sbrf.ru
06/26/2017 12:52:16 - Info ndmpagent (pid=29355) done. status: 0: the requested operation was successfully completed
06/26/2017 12:52:16 - end writing; write time: 1:44:32
the requested operation was successfully completed  (0)

 

Attaching the logs from the media server: ndmpagent, ndmp, bptm, bpbrm

Many thanks,

----
Best Regards, AlChie
4 REPLIES 4

Thiago_Ribeiro
Moderator
Moderator
Partner    VIP    Accredited

Hi,

Have you had opporunity to check this TNs below?


https://www.veritas.com/support/en_US/article.TECH37502

https://www.veritas.com/support/en_US/article.000081335

 

Regards,

 

Thiago Ribeiro

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

This is the actual error:

Error bpbrm (pid=18953) db_FLISTsend failed: file read failed (13)

See if this TN helps:

EMC VNX/Celerra backup fails with db_FLISTsend failed: file read failed (13)
http://www.veritas.com/docs/000082710

 

Greetings!

I was able to solve the issue by expiring the older images on assigned tapes. And also entered
"bpexpdate -emptydeassigned" afterwards.

After this the backup completed successfully.

Thank you for provided TN's

----
Best Regards, AlChie

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

There is nothing in the failed backup that points to insufficient media.

Good luck!