Video Screencast Help
Symantec Appoints Michael A. Brown CEO. Learn more.

1 NDMP job is failing with ERR - Cannot write TIR data to media, NDMP return code 20.

Created: 11 Apr 2013 | 4 comments
abhinav trivedi's picture

Hi All,

One of our NDMP job is failing with error code 84. Logs are given below but main error is (Error bptm (pid=12325) ERR - Cannot write TIR data to media, NDMP return code 20):

 

04/11/2013 13:23:37 - granted resource  RS8073
04/11/2013 13:23:37 - granted resource  OY---hcart-010-shared-NDMP
04/11/2013 13:23:37 - granted resource  PNIOYNBMDS02-hcart-robot-tld-0-pnievs1
04/11/2013 13:23:37 - estimated 172987322 kbytes needed
04/11/2013 13:23:37 - Info nbjm (pid=4400) started backup (backupid=pnievs1_1365683017) job for client pnievs1, policy OY-NDMP-PNIEVS1-FULL, schedule Full on storage unit PNIOYNBMDS02-hcart-robot-tld-0-pnievs1
04/11/2013 13:23:38 - Info bpbrm (pid=12319) pnievs1 is the host to backup data from
04/11/2013 13:23:38 - Info bpbrm (pid=12319) reading file list from client
04/11/2013 13:23:38 - started process bpbrm (pid=12319)
04/11/2013 13:23:38 - connecting
04/11/2013 13:23:38 - connected; connect time: 0:00:00
04/11/2013 13:23:39 - Info bpbrm (pid=12319) starting ndmpagent on client
04/11/2013 13:23:39 - Info ndmpagent (pid=12324) Backup started
04/11/2013 13:23:39 - Info bpbrm (pid=12319) bptm pid: 12325
04/11/2013 13:23:39 - Info bptm (pid=12325) start
04/11/2013 13:23:39 - Info bptm (pid=12325) using 64 data buffers
04/11/2013 13:23:39 - Info bptm (pid=12325) using 65536 data buffer size
04/11/2013 13:23:39 - Info bptm (pid=12325) start backup
04/11/2013 13:23:39 - Info bptm (pid=12325) Waiting for mount of media id RS8073 (copy 1) on server PNIOYNBMDS02.
04/11/2013 13:23:39 - mounting RS8073
04/11/2013 13:24:55 - mounted RS8073; mount time: 0:01:16
04/11/2013 13:24:56 - Info bptm (pid=12325) media id RS8073 mounted on drive index 1, drivepath /dev/mt_d4l0, drivename OY---hcart-010-shared-NDMP, copy 1
04/11/2013 13:24:59 - positioning RS8073 to file 2
04/11/2013 13:26:20 - positioned RS8073; position time: 0:01:21
04/11/2013 13:26:20 - begin writing
04/11/2013 13:26:24 - Info ndmpagent (pid=12324) pnievs1: NDMP(3784): Starting (source end) full Backup of file system /transformation-software-repository 
04/11/2013 13:26:24 - Info ndmpagent (pid=12324) pnievs1: NDMP(3784): Backup is being generated from snapshot[name "NDMP_AUTO_SNAPSHOT9188",view id(7527158),creation time(2013-04-11 12:26:22+00:00)], base snapshot[none]
04/11/2013 14:20:55 - Info ndmpagent (pid=12324) pnievs1: NDMP(3784): Backup of /transformation-software-repository complete (source end) (0 warning(s), 0 error(s))
04/11/2013 14:20:55 - Info ndmpagent (pid=12324) pnievs1: NDMP(3784): Action completed (NDMP mover terminated)
04/11/2013 14:20:55 - Info ndmpagent (pid=12324) NDMP backup successfully completed, path = /transformation-software-repository
04/11/2013 14:22:58 - Error bptm (pid=12325) ERR - Cannot write TIR data to media, NDMP return code 20.
04/11/2013 14:23:05 - Info bptm (pid=12325) EXITING with status 84 <----------
04/11/2013 14:23:05 - Info ndmpagent (pid=0) done. status: 84: media write error
04/11/2013 14:23:05 - end writing; write time: 0:56:45
04/11/2013 15:12:25 - job 1530108 was restarted as job 1530156
media write error  (84)
 
Important consideration is backup is completing successfully with NDMP drives with same error but completing successfully with Non NDMP drives.

 

Operating Systems:
Discussion Filed Under:

Comments 4 CommentsJump to latest comment

CRZ's picture

Are you backing up lots and lots of files (which may be creating a very large set of TIR data)?

Have you set SIZE_DATA_BUFFERS_NDMP?  If so, what is it? 

Wait...it's probably in your log excerpt:

04/11/2013 13:23:39 - Info bptm (pid=12325) using 65536 data buffer size

That's the default.  Can you set it to 131072?

Could you also add this line to /usr/openv/netbackup/db/config/ndmp.cfg if it's not already there?

NDMP_MOVER_CLIENT_DISABLE

What's that keyword do?  Read this TechNote:

Impact of NDMP_MOVER_CLIENT_DISABLE
 http://symantec.com/docs/TECH162041

 


bit.ly/76LBN | APPLBN | 75LBN

abhinav trivedi's picture

 

Hi CRZ,
 
Could you please let me know the exact use of NDMP_MOVER_CLIENT_DISABLE. We do not have ndmp.cfg in the mentioned path also:
 
[nibackup@XYZ]/usr/openv/netbackup/db/config>ls -lrt
total 12
-rw------- 1 root root    3 Apr 27  2011 NUMBER_DATA_BUFFERS
-rw------- 1 root root    6 Sep 16  2011 SIZE_DATA_BUFFERS
drwxr-xr-x 2 root root 4096 Apr 11 11:00 shm
[nibackup@XYZ]/usr/openv/netbackup/db/config>
 
 
Do we need to create touch file of ndmp.cfg and value in this touch file is NDMP_MOVER_CLIENT_DISABLE.
 
 
For SIZE_DATA_BUFFERS_NDMP:
 
We are using multiplexing in our environment. Might be we will face below issue after these changes:
 
http://www.symantec.com/business/support/index?page=content&id=TECH142417
 
Could you please explain this aswell. Thanks for help.
CRZ's picture
Hi CRZ,
 
Could you please let me know the exact use of NDMP_MOVER_CLIENT_DISABLE. We do not have ndmp.cfg in the mentioned path also:
 
[nibackup@XYZ]/usr/openv/netbackup/db/config>ls -lrt
total 12
-rw------- 1 root root    3 Apr 27  2011 NUMBER_DATA_BUFFERS
-rw------- 1 root root    6 Sep 16  2011 SIZE_DATA_BUFFERS
drwxr-xr-x 2 root root 4096 Apr 11 11:00 shm
[nibackup@XYZ]/usr/openv/netbackup/db/config>
 
 
Do we need to create touch file of ndmp.cfg and value in this touch file is NDMP_MOVER_CLIENT_DISABLE.
Pretty much - this command should cover it:
/usr/openv/netbackup/db/config# echo NDMP_MOVER_CLIENT_DISABLE > ndmp.cfg
For SIZE_DATA_BUFFERS_NDMP:
 
We are using multiplexing in our environment. Might be we will face below issue after these changes:
 
http://www.symantec.com/business/support/index?page=content&id=TECH142417
 
Could you please explain this aswell. Thanks for help.
According to the Tech Alert, this issue ONLY affects 7.0.1.  You didn't say which version you're at, but I believe you marked this thread as "7.5 and up" so assuming you're at 7.1 or above, this issue will not affect you.
 
I didn't really look at your logs, but the bottom line is if your TIR data is larger than the blocksize, it might explain your trouble.  This should work around it, but that keyword may give you a performance hit on other actions (refer to the TechNote I linked above).


bit.ly/76LBN | APPLBN | 75LBN

abhinav trivedi's picture

We have checked ndmpagent logs and found the following:

 

11/04/13 16:41:21.411 [ndmp_logger_vxul] 0xb57780 .   tcp_addr[0].tcp_addr=10.194.125.32
11/04/13 16:41:21.411 [ndmp_logger_vxul] 0xb57780 .   tcp_addr[0].port=1912 (0x778)
11/04/13 16:41:21.411 [ndmp_logger_vxul] 0xb57780 **  End NDMP_MOVER_GET_STATE
11/04/13 16:41:21.411 [ndmp_logger_vxul] 0xb57780 ->  (20) 42 [0] 16:41:21 NDMP_MOVER_ABORT (0xa03) NDMP_NO_ERR (0x0)
11/04/13 16:41:21.412 [ndmp_logger_vxul] 0x68cf80 ->  (7) 251 [0] 16:41:21 NDMP_MOVER_ABORT (0xa03) NDMP_NO_ERR (0x0)
11/04/13 16:41:21.412 [ndmp_logger_vxul] 0x68cf80 <-  (7) 6932 [0] 16:41:21 NDMP_NOTIFY_MOVER_HALTED (0x503) NDMP_NO_ERR (0x0)
11/04/13 16:41:21.412 [ndmp_logger_vxul] 0x68cf80 .   reason=NDMP_MOVER_HALT_ABORTED
11/04/13 16:41:21.412 [ndmp_logger_vxul] 0x68cf80 **  End NDMP_NOTIFY_MOVER_HALTED
11/04/13 16:41:21.412 [ndmp_logger_vxul] 0x68cf80 <-  (7) 6933 [251] 16:41:21 NDMP_MOVER_ABORT (0xa03) NDMP_NO_ERR (0x0)
11/04/13 16:41:21.412 [ndmp_logger_vxul] 0x68cf80 .   error=NDMP_NO_ERR (0x0)
11/04/13 16:41:21.412 [ndmp_logger_vxul] 0x68cf80 **  End NDMP_MOVER_ABORT
11/04/13 16:41:21.413 [ndmp_logger_vxul] 0xb57780 <-  (20) 43 [0] 16:41:21 NDMP_NOTIFY_MOVER_HALTED (0x503) NDMP_NO_ERR (0x0)
11/04/13 16:41:21.413 [ndmp_logger_vxul] 0xb57780 .   reason=NDMP_MOVER_HALT_ABORTED
11/04/13 16:41:21.413 [ndmp_logger_vxul] 0xb57780 **  End NDMP_NOTIFY_MOVER_HALTED
11/04/13 16:41:21.449 [ndmp_logger_vxul] 0xb57780 <-  (20) 44 [42] 16:41:21 NDMP_MOVER_ABORT (0xa03) NDMP_NO_ERR (0x0)
11/04/13 16:41:21.449 [ndmp_logger_vxul] 0xb57780 .   error=NDMP_NO_ERR (0x0)
11/04/13 16:41:21.449 [ndmp_logger_vxul] 0xb57780 **  End NDMP_MOVER_ABORT
11/04/13 16:41:21.449 [ndmp_logger_vxul] 0xb57780 ->  (20) 43 [0] 16:41:21 NDMP_MOVER_STOP (0xa04) NDMP_NO_ERR (0x0)
11/04/13 16:41:21.450 [ndmp_logger_vxul] 0x68cf80 ->  (7) 252 [0] 16:41:21 NDMP_MOVER_STOP (0xa04) NDMP_NO_ERR (0x0)
11/04/13 16:41:21.450 [ndmp_logger_vxul] 0x68cf80 <-  (7) 6934 [252] 16:41:21 NDMP_MOVER_STOP (0xa04) NDMP_NO_ERR (0x0)
11/04/13 16:41:21.450 [ndmp_logger_vxul] 0x68cf80 .   error=NDMP_NO_ERR (0x0)
11/04/13 16:41:21.450 [ndmp_logger_vxul] 0x68cf80 **  End NDMP_MOVER_STOP
11/04/13 16:41:21.450 [ndmp_logger_vxul] 0xb57780 <-  (20) 45 [43] 16:41:21 NDMP_MOVER_STOP (0xa04) NDMP_NO_ERR (0x0)
11/04/13 16:41:21.450 [ndmp_logger_vxul] 0xb57780 .   error=NDMP_NO_ERR (0x0)
11/04/13 16:41:21.450 [ndmp_logger_vxul] 0xb57780 **  End NDMP_MOVER_STOP
11/04/13 16:41:21.472 [ndmp_logger_vxul] 0xb57780 ->  (20) 44 [0] 16:41:21 NDMP_TAPE_CLOSE (0x301) NDMP_NO_ERR (0x0)
11/04/13 16:41:21.472 [ndmp_logger_vxul] 0x68cf80 ->  (7) 253 [0] 16:41:21 NDMP_TAPE_CLOSE (0x301) NDMP_NO_ERR (0x0)
11/04/13 16:41:23.513 [ndmp_logger_vxul] 0x68cf80 <-  (7) 6935 [253] 16:41:23 NDMP_TAPE_CLOSE (0x301) NDMP_NO_ERR (0x0)
11/04/13 16:41:23.513 [ndmp_logger_vxul] 0x68cf80 .   error=NDMP_NO_ERR (0x0)
11/04/13 16:41:23.513 [ndmp_logger_vxul] 0x68cf80 **  End NDMP_TAPE_CLOSE
11/04/13 16:41:23.513 [ndmp_logger_vxul] 0xb57780 <-  (20) 46 [44] 16:41:23 NDMP_TAPE_CLOSE (0x301) NDMP_NO_ERR (0x0)
11/04/13 16:41:23.513 [ndmp_logger_vxul] 0xb57780 .   error=NDMP_NO_ERR (0x0)
11/04/13 16:41:23.513 [ndmp_logger_vxul] 0xb57780 **  End NDMP_TAPE_CLOSE
 
 
In bptm log:
 
16:41:16.171 [5865] <2> bptm: EXITING with status 0 <----------
16:41:21.398 [4103] <16> NdmpMoverSession[0]: ERROR Flush - timeout waiting for CONNECT_CLOSED
16:41:21.400 [4103] <16> NdmpMediaSession_flush_mover[0]: NDMP Flush to tape failed.
16:41:21.413 [4103] <2> NdmpMoverSession[0]: mover halted reason NDMP_MOVER_HALT_ABORTED
16:41:21.449 [4103] <2> NdmpMoverSession[0]: ndmp_mover_abort status = 0
16:41:21.451 [4103] <2> NdmpMoverSession[0]: ndmp_mover_stop status = 0
16:41:21.451 [4103] <2> NdmpMoverSession[0]: Shutdown complete
24940 -mds 0 -alocid 261295 -nh pnievs1 -nu nbaadmin -nk 61383 -np 3269bfb6ab90c470f112c8d7801b872dd16518b04d091aaba02db67a5f48187133b14d8777478376de97386d63326b139592ee7aae9e9884b3bef339aaf8cdc9 -jobid -1364280962 -jm 
16:41:29.197 [5875] <8> vnet_same_host_and_update: [vnet_addrinfo.c:2829] name2 is empty 0 0x0
16:41:29.197 [5875] <4> bptm: emmserver_name = pnioynbmst01
16:41:29.197 [5875] <4> bptm: emmserver_port = 155616:41:21.451 [4103] <2> ConnectionCache::connectAndCache: Acquiring new connection for host pnioynbmst01, query type 1
16:41:21.453 [4103] <2> vnet_pbxConnect: pbxConnectEx Succeeded
16:41:21.453 [4103] <2> logconnections: BPDBM CONNECT FROM 10.194.125.32.35068 TO 10.194.124.31.1556 fd = 24
16:41:21.453 [4103] <8> vnet_check_vxss_client_magic_with_info: [vnet_vxss_helper.c:871] Ignoring VxSS authentication 2 0x2
16:41:21.456 [4103] <2> db_end: Need to collect reply
16:41:21.457 [4103] <16> write_data_tir: ERR - Cannot write TIR data to media, NDMP return code 20.
16:41:21.458 [4103] <2> send_MDS_msg: DEVICE_STATUS 1 261295 pnioynbmds01 RS8073 4024940 OY---hcart-010-shared-NDMP 2000723 WRITE_ERROR 0 0
16:41:21.469 [4103] <2> log_media_error: successfully wrote to error file - 04/11/13 16:41:21 RS8073 1 WRITE_ERROR OY---hcart-010-shared-NDMP
16:41:21.469 [4103] <2> check_error_history: just tpunmount: called from bptm line 21443, EXIT_Status = 84
16:41:21.469 [4103] <2> io_close: closing /usr/openv/netbackup/db/media/tpreq/drive_OY---hcart-010-shared-NDMP, from bptm.c.16433
16:41:23.513 [4103] <2> NdmpMediaSession_close_public_and_ndmpagent[0]: closing public session, force = 0, agent_session_index = 0
16:41:28.515 [4103] <2> drivename_write: Called with mode 1
16:41:28.515 [4103] <2> drivename_unlock: unlocked
16:41:28.515 [4103] <2> drivename_close: Called for file OY---hcart-010-shared-NDMP
16:41:28.515 [4103] <2> tpunmount: NOP: MEDIA_DONE 0 1530198 0 RS8073 4024940 0 {A64E913C-A2B6-11E2-AD5C-1EEE10464DD9}
16:41:28.515 [4103] <2> bptm: EXITING with status 84 <----------
16:41:29.197 [5875] <2> bptm: INITIATING (VERBOSE = 0): -unload -dn OY---hcart-010-shared-NDMP -dp /dev/mt_d4l0 -dk 2000723 -m RS8073 -mk 40
16:41:29.207 [5875] <8> file_to_cache_item: [vnet_addrinfo.c:6574] fopen() failed ERRNO=2 FILE=/usr/openv/var/host_cache/1ff/ffffffff+veritas_pbx,1,1,0,1,0+.txt
16:41:29.208 [5875] <2> Orb::init: Enabling ORBNativeCharCodeSet UTF-8(Orb.cpp:594)
 
 
Job detailed status:
 
04/11/2013 15:50:21 - Info ndmpagent (pid=4102) pnievs1: NDMP(3812): Starting (source end) full Backup of file system /transformation-software-repository 
04/11/2013 15:50:21 - Info ndmpagent (pid=4102) pnievs1: NDMP(3812): Backup is being generated from snapshot[name "NDMP_AUTO_SNAPSHOT9196",view id(7529675),creation time(2013-04-11 14:50:20+00:00)], base snapshot[none]
04/11/2013 15:50:22 - Info ndmpagent (pid=4102) 0 entries sent to bpdbm
04/11/2013 16:03:23 - Info ndmpagent (pid=4102) 5000 entries sent to bpdbm
04/11/2013 16:05:28 - Info ndmpagent (pid=4102) 10000 entries sent to bpdbm
04/11/2013 16:08:33 - Info ndmpagent (pid=4102) 15000 entries sent to bpdbm
04/11/2013 16:08:54 - Info ndmpagent (pid=4102) 20000 entries sent to bpdbm
04/11/2013 16:08:56 - Info ndmpagent (pid=4102) 25000 entries sent to bpdbm
04/11/2013 16:09:00 - Info ndmpagent (pid=4102) 30000 entries sent to bpdbm
04/11/2013 16:09:12 - Info ndmpagent (pid=4102) 35000 entries sent to bpdbm
04/11/2013 16:09:18 - Info ndmpagent (pid=4102) 40000 entries sent to bpdbm
04/11/2013 16:09:24 - Info ndmpagent (pid=4102) 45000 entries sent to bpdbm
04/11/2013 16:39:18 - Info ndmpagent (pid=4102) pnievs1: NDMP(3812): Backup of /transformation-software-repository complete (source end) (0 warning(s), 0 error(s))
04/11/2013 16:39:18 - Info ndmpagent (pid=4102) pnievs1: NDMP(3812): Action completed (NDMP mover terminated)
04/11/2013 16:39:19 - Info ndmpagent (pid=4102) NDMP backup successfully completed, path = /transformation-software-repository
04/11/2013 16:39:19 - Info ndmpagent (pid=4102) 46240 entries sent to bpdbm
04/11/2013 16:41:21 - Error bptm (pid=4103) ERR - Cannot write TIR data to media, NDMP return code 20.
04/11/2013 16:41:28 - Info bptm (pid=4103) EXITING with status 84 <----------
04/11/2013 16:41:28 - Info ndmpagent (pid=0) done. status: 84: media write error
04/11/2013 16:41:28 - end writing; write time: 0:51:11
media write error  (84)