Video Screencast Help
Scheduled Maintenance: Symantec Connect is scheduled to be down Saturday, April 19 from 10am to 2pm Pacific Standard Time (GMT: 5pm to 9pm) for server migration and upgrade.
Please accept our apologies in advance for any inconvenience this might cause.

io_ioctl_ndmp (mtbsf

Created: 27 Feb 2013 | 1 comment

I've been having trouble with NDMP backups since I added two fiber NDMP storage units to master/media server. Before I was just sending info to the robot as a media manager storage type but it would not use the fiber lines connected to the drives. Now I am recieving the following errors when using the NDMP storage units:

02/19/2013 20:31:15 - Info nbjm (pid=3364) starting backup job (jobid=135242) for client ntap1, policy NDMP-ntap1-bigdata, schedule Daily
02/19/2013 20:31:15 - Info nbjm (pid=3364) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=135242, request id:{996CE280-7B05-11E2-92BB-C3FC9C756DC2})
02/19/2013 20:31:15 - requesting resource netapp
02/19/2013 20:31:15 - requesting resource jawa.NBU_CLIENT.MAXJOBS.ntap1
02/19/2013 20:31:15 - requesting resource jawa.NBU_POLICY.MAXJOBS.NDMP-ntap1-bigdata
02/19/2013 20:31:15 - awaiting resource netapp. Waiting for resources.
          Reason: Drives are in use, Media server: jawa,
          Robot Type(Number): TLD(0), Media ID: N/A, Drive Name: N/A,
          Volume Pool: NetBackup, Storage Unit: netapp, Drive Scan Host: N/A,
          Disk Pool: N/A, Disk Volume: N/A
02/19/2013 20:35:51 - Info bpbrm (pid=18568) ntap1 is the host to backup data from
02/19/2013 20:35:51 - Info bpbrm (pid=18568) reading file list from client
02/19/2013 20:35:51 - Info bpbrm (pid=18568) starting ndmpagent on client
02/19/2013 20:35:51 - granted resource  jawa.NBU_CLIENT.MAXJOBS.ntap1
02/19/2013 20:35:51 - granted resource  jawa.NBU_POLICY.MAXJOBS.NDMP-ntap1-bigdata
02/19/2013 20:35:51 - granted resource  8873L5
02/19/2013 20:35:51 - granted resource  IBM.ULTRIUM-HH5.002
02/19/2013 20:35:51 - granted resource  netapp
02/19/2013 20:35:51 - estimated 192254598 kbytes needed
02/19/2013 20:35:51 - Info nbjm (pid=3364) started backup (backupid=ntap1_1361327751) job for client ntap1, policy NDMP-ntap1-bigdata, schedule Daily on storage unit netapp
02/19/2013 20:35:51 - started process bpbrm (pid=18568)
02/19/2013 20:35:51 - connecting
02/19/2013 20:35:51 - connected; connect time: 0:00:00
02/19/2013 20:35:52 - Info ndmpagent (pid=18577) Backup started
02/19/2013 20:35:52 - Info bpbrm (pid=18568) bptm pid: 18578
02/19/2013 20:35:52 - Info bptm (pid=18578) start
02/19/2013 20:35:52 - Info bptm (pid=18578) using 30 data buffers
02/19/2013 20:35:52 - Info bptm (pid=18578) using 65536 data buffer size
02/19/2013 20:35:52 - Info bptm (pid=18578) start backup
02/19/2013 20:35:52 - Info bptm (pid=18578) media id 8873L5 mounted on drive index 2, drivepath nrst5a, drivename IBM.ULTRIUM-HH5.002, copy 1
02/19/2013 20:35:52 - mounted 8873L5
02/19/2013 20:35:52 - positioning 8873L5 to file 43
02/19/2013 20:35:54 - positioned 8873L5; position time: 0:00:02
02/19/2013 20:35:54 - begin writing
02/19/2013 20:35:55 - Info ndmpagent (pid=18577) ntap1: DUMP: creating "/vol/bigdata/../snapshot_for_backup.29" snapshot.
02/19/2013 20:35:59 - Info ndmpagent (pid=18577) ntap1: DUMP: Using subtree dump
02/19/2013 20:36:08 - Info ndmpagent (pid=18577) ntap1: DUMP: Date of this level 9 dump: Tue Feb 19 20:35:55 2013.
02/19/2013 20:36:08 - Info ndmpagent (pid=18577) ntap1: DUMP: Date of last level 8 dump: Mon Dec 24 06:01:34 2012.
02/19/2013 20:36:08 - Info ndmpagent (pid=18577) ntap1: DUMP: Dumping /vol/bigdata/tickData/futures to NDMP connection
02/19/2013 20:36:08 - Info ndmpagent (pid=18577) ntap1: DUMP: mapping (Pass I)[regular files]
02/19/2013 20:36:16 - Info ndmpagent (pid=18577) ntap1: DUMP: mapping (Pass II)[directories]
02/19/2013 20:36:16 - Info ndmpagent (pid=18577) ntap1: DUMP: estimated 221786988 KB.
02/19/2013 20:36:16 - Info ndmpagent (pid=18577) ntap1: DUMP: dumping (Pass III) [directories]
02/19/2013 20:36:17 - Info ndmpagent (pid=18577) 0 entries sent to bpdbm
02/19/2013 20:36:17 - Info ndmpagent (pid=18577) 5000 entries sent to bpdbm
02/19/2013 20:36:17 - Info ndmpagent (pid=18577) 10000 entries sent to bpdbm
02/19/2013 20:36:18 - Info ndmpagent (pid=18577) 15000 entries sent to bpdbm
02/19/2013 20:36:18 - Info ndmpagent (pid=18577) 20000 entries sent to bpdbm
02/19/2013 20:36:19 - Info ndmpagent (pid=18577) 25000 entries sent to bpdbm
02/19/2013 20:36:19 - Info ndmpagent (pid=18577) 30000 entries sent to bpdbm
02/19/2013 20:36:19 - Info ndmpagent (pid=18577) 35000 entries sent to bpdbm
02/19/2013 20:36:20 - Info ndmpagent (pid=18577) 40000 entries sent to bpdbm
02/19/2013 20:36:20 - Info ndmpagent (pid=18577) 45000 entries sent to bpdbm
02/19/2013 20:36:21 - Info ndmpagent (pid=18577) 50000 entries sent to bpdbm
02/19/2013 20:36:21 - Info ndmpagent (pid=18577) 55000 entries sent to bpdbm
02/19/2013 20:36:21 - Info ndmpagent (pid=18577) 60000 entries sent to bpdbm
02/19/2013 20:36:21 - Info ndmpagent (pid=18577) 65000 entries sent to bpdbm
02/19/2013 20:36:22 - Info ndmpagent (pid=18577) ntap1: DUMP: dumping (Pass IV) [regular files]
02/19/2013 20:41:15 - Info ndmpagent (pid=18577) ntap1: DUMP: Tue Feb 19 20:41:15 2013 : We have written 10951806 KB.
02/19/2013 20:46:32 - Info ndmpagent (pid=18577) ntap1: DUMP: Tape write failed.
02/19/2013 20:46:32 - Info ndmpagent (pid=18577) ntap1: DUMP: Tue Feb 19 20:46:32 2013 : We have written 23412996 KB.
02/19/2013 20:46:32 - Info ndmpagent (pid=18577) ntap1: DUMP: DUMP IS ABORTED
02/19/2013 20:46:34 - Info ndmpagent (pid=18577) ntap1: DUMP: Deleting "/vol/bigdata/../snapshot_for_backup.29" snapshot.
02/19/2013 20:46:41 - Info ndmpagent (pid=18577) ntap1: Connection or IO Error.
02/19/2013 20:46:41 - Info ndmpagent (pid=18577) ntap1: MoveletOutput: Internal Error.
02/19/2013 20:46:41 - Error ndmpagent (pid=18577) NDMP backup failed, path = /vol/bigdata/tickData/futures
02/19/2013 20:46:41 - Error bptm (pid=18578) none of the NDMP backups for client ntap1 completed successfully
02/19/2013 20:46:41 - Error bptm (pid=18578) io_ioctl_ndmp (MTBSF) failed on media id 8873L5, drive index 2, return code 11 (NDMP_WRITE_PROTECT_ERR) (bptm.c.8757)
02/19/2013 20:46:46 - Info bptm (pid=18578) EXITING with status 99 <----------
02/19/2013 20:46:46 - Info ndmpagent (pid=0) done. status: 99: NDMP backup failure
02/19/2013 20:46:46 - end writing; write time: 0:10:52
NDMP backup failure  (99)

I have used tpautoconf to check my connections and vmoprcmd to check my drives. After several failed backups I sometimes have to bring them back up. I have noticed that small jobs usually finish with no problem but big ones go down before they can finish. The fragment size to my drives is 1,048,575 MB if that helps. Any suggestions would be appreciated

My bigger jobs will usually fail after about 10 to 16 minutes.

 

Operating Systems:

Comments 1 CommentJump to latest comment

watsons's picture

Netbackup version? What type of NDMP host (EMC, Netapp or others)?

I notice it falis fairly quick (after 10minutes) so it does not look like a timeout.

If you have access to your NDMP host directly (via a control host), can you try to do a "dump <bigdatapath> to /dev/null" to see if that path can be backup locally (without Netbackup).