Start a Conversation

Unsolved

This post is more than 5 years old

2830

November 18th, 2015 09:00

EMC CELERA NDMP issue with TSM-ANR1104E NAS Backup process terminated

Hi Team

we have facing below error after triggering the backup from tsm server, as of now we have raised the service request with EMC, but no clue it is. If any one having similar issue along with solution much appreciated.

TSM Error:

11/16/15   18:20:26 ANR1104E NAS Backup process 13625 terminated - NAS

datamover CFIWP04 reported NDMP session errors. (SESSION:

2512285, PROCESS: 13625)

  1. dsmserv.err file

[11-16-2015 17:39:51.680][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128) SnapSure file system creation succeeds

[11-16-2015 18:18:30.848][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128) Medium error

[11-16-2015 18:18:30.849][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128) Write failed on archive volume 1

[11-16-2015 18:18:30.850][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128) server_archive: emctar vol 1, 829167 files, 0 bytes

[11-16-2015 18:18:30.850][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128)  read, 108014338048 bytes wri


NDMP LOG:


2015-11-16 18:18:58: NDMP: 4: < LOG type: 3, msg_id: 0, entry: Write failed on archive volume 1, hasAssociatedMsg: 0, associatedMsgSeq: 0 >

2015-11-16 17:36:38: ADMIN: 6: Command succeeded:  param NDMP scsiReserve=1

2015-11-16 17:36:38: ADMIN: 6: Command succeeded:  param NDMP snapsure=1

2015-11-16 17:36:57: NDMP: 4: Thread config param PAX.readWriteBlockSizeInKB is set to 64

2015-11-16 17:36:57: NDMP: 4: Thread config PAX paxThrCnt is set to concurrentDataStreams 4

2015-11-16 17:36:57: NDMP: 4: Thread config maximum number of buffers per restore job is 256

2015-11-16 17:36:57: NDMP: 4: Thread config number of buffers per restore job is 64

2015-11-16 17:36:57: NDMP: 4: Thread config maximum param PAX.nThread value is 128

2015-11-16 17:36:57: NDMP: 4: Thread config maximum param PAX.nRestore value is 16

2015-11-16 17:36:57: NDMP: 4: Thread config maximum param PAX.nPrefetch value is 8

2015-11-16 17:36:57: NDMP: 4: Thread config maximum param PAX.paxWriteBuff value is 256

2015-11-16 17:36:57: NDMP: 6: MaxBufferSize = 131072

2015-11-16 17:36:57: NDMP: 6: concurrentDataStreams set to 4

2015-11-16 17:36:57: NDMP: 6: maxConcurrentDataStreams set to 4

2015-11-16 17:36:57: NDMP: 6: portRange is 1024-65535, 1024-65535

2015-11-16 17:36:57: NDMP: 6: Listen thread started

2015-11-16 17:36:57: ADMIN: 6: Command succeeded:  ndmp port=10000

2015-11-16 17:36:57: NDMP: 6: Thread pax00 BlockBuffer count in PAX Pool: 268

2015-11-16 17:40:10: NDMP: 6: Active NDMP backup/restore streams: 1, system configured concurrent streams: 4, maximum concurrent sessions supported: 4.

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) < Backup type: dump >

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) Name: FILESYSTEM Value: /root_vdm_1/fs04

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) Name: TYPE Value: dump

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) Name: DATA_BLOCK_SIZE Value: 63

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) Name: LEVEL Value: 0

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) Name: UPDATE Value: Y

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) Name: NON_QUOTA_TREE Value: N

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) Name: NO_ACLS Value: N

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) Name: HIST Value: Y

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) Name: DIRECT Value: N

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) Name: EXTRACT Value: Y

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) Name: EXTRACT_ACL Value: Y

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) Name: DEBUG Value: N

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) Name: VERBOSE Value: N

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) Name: REPLICATE Value: N

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) Name: FORCE Value: N

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) Name: NOWRITE Value: N

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) Name: LIST Value: N

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) Name: LIST_TREES Value: N

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) Name: BASE_DATE Value: 0

2015-11-16 17:40:11: NDMP: 4: Session 001 (thread ndmp001) Name: DMP_NAME Value: TSM /root_vdm_1/fs04

2015-11-16 17:40:17: ADMIN: 6: Command succeeded : serverMount ckpt ro /root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt1-27-1447695611 217=621 ro

2015-11-16 17:40:20: NDMP: 4: Session 001 (thread ndmp001) tape drive: c32t0l2, CALLER_ADDRESS 0x0001671ec0.

2015-11-16 17:40:20: NDMP: 4: Thread ndmp001 uses a set of Pax threads with handle 0.

2015-11-16 17:40:20: NDMP: 6: Thread ndmp001 filterDialect could not be set - prereqs not met [pax_cmd_thread::setFilterDialect]

2015-11-16 17:40:20: NDMP: 4: Thread ndmp001 fsSize of /root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt1-27-1447695611 is 3363213615104 (../pax_ndmp.cxx: 1215)

2015-11-16 18:18:58: NDMP: 3: Thread nasw00 DartTapeInterface: write error

2015-11-16 18:18:58: NDMP: 3: Session 001 (thread nasw00) Tape write error: No error reported on drive c32t0l2.

2015-11-16 18:18:58: NDMP: 3: Session 001 (thread nasw00 fails in tapeWrite or tapeWriteMsg for drive c32t0l2, numMsg=9, maxMsg=64, n=-1,  bcnt=65536, length=65536, fileName=../NdmpdMover.cxx, lineNo=694.

2015-11-16 18:18:58: NDMP: 3: Session 001 (thread nasw00) NdmpdSession::ndmpdApiWrite fails in local or remote wirte msg, moverAddressType=0, mp=0x00030165c0

2015-11-16 18:18:58: NDMP: 3: Thread bkup004 Medium error

2015-11-16 18:18:58: NDMP: 3: < LOG type: 2, msg_id: 0, entry: Medium error, hasAssociatedMsg: 0, associatedMsgSeq: 0 >

2015-11-16 18:18:58: NDMP: 4: Thread bkup004 Write failed on archive volume 1

2015-11-16 18:18:58: NDMP: 4: < LOG type: 3, msg_id: 0, entry: Write failed on archive volume 1, hasAssociatedMsg: 0, associatedMsgSeq: 0 >

2015-11-16 18:18:58: PAX: 3: Thread bkup004 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt1-27-1447695611/Users-F/RRAMANAT/Outlook/Ramsiva UK.pst) failed

2015-11-16 18:18:58: PAX: 3: Thread bkup009 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt1-27-1447695611/Users-F/RRAMANAT/Outlook/Ramsiva UK II.pst) failed

2015-11-16 18:18:58: PAX: 3: Thread bkup018 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt1-27-1447695611/Users-F/RRAMANAT/Banked Hours Details.docx) failed

2015-11-16 18:18:58: PAX: 3: Thread bkup008 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt1-27-1447695611/Users-F/RRAMANAT/Outlook/June 2014 2.pst) failed

2015-11-16 18:18:58: PAX: 3: Thread bkup006 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt1-27-1447695611/Users-F/RRAMANAT/Outlook/Outlook/a_rrama0.pst) failed

2015-11-16 18:18:58: PAX: 3: Thread bkup010 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt1-27-1447695611/Users-F/RRAMANAT/Outlook/September 2014.pst) failed

2015-11-16 18:18:58: PAX: 3: Thread bkup007 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt1-27-1447695611/Users-F/RRAMANAT/Outlook/June 2014.pst) failed

2015-11-16 18:18:58: PAX: 3: Thread bkup012 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt1-27-1447695611/Users-F/RRAMANAT/Outlook/October 2014.pst) failed

2015-11-16 18:18:58: PAX: 3: Thread bkup011 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt1-27-1447695611/Users-F/RRAMANAT/Outlook/Novenmber 2014.pst) failed

2015-11-16 18:18:58: PAX: 3: Thread bkup015 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt1-27-1447695611/Users-F/RRAMANAT/Outlook/November 2014.pst) failed

2015-11-16 18:18:58: PAX: 3: Thread bkup016 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt1-27-1447695611/Users-F/RRAMANAT/BO XI.pdf) failed

2015-11-16 18:18:58: NDMP: 4: rw_thread ARCHIVE. Media error happened.

2015-11-16 18:18:58: NDMP: 4: last message repeated 62 times

2015-11-16 18:18:58: NDMP: 4: Thread nasa00 Backup root directory: /root_vdm_1/fs04

2015-11-16 18:18:58: NDMP: 4: Thread nasa00 write count 108014338048

2015-11-16 18:18:58: NDMP: 4: Thread nasa00 time used 2323 sec

2015-11-16 18:18:58: NDMP: 4: Thread nasa00 write rate 45405 KB/Sec

2015-11-16 18:18:58: NDMP: 4: Thread nasa00 read rate 0 KB/Sec

2015-11-16 18:18:58: NDMP: 4: Thread nasa00 average file size: 127KB

2015-11-16 18:18:58: NDMP: 4: Thread nasa00 dir or   0  size file processed: 110775

2015-11-16 18:18:58: NDMP: 4: Thread nasa00   1B -- 8KB  size file processed: 551584

2015-11-16 18:18:58: NDMP: 4: Thread nasa00  8KB -- 16KB size file processed: 34074

2015-11-16 18:18:58: NDMP: 4: Thread nasa00 16KB -- 32KB size file processed: 35013

2015-11-16 18:18:58: NDMP: 4: Thread nasa00 32KB -- 64KB size file processed: 24319

2015-11-16 18:18:58: NDMP: 4: Thread nasa00 64KB -- 1MB size file processed: 60010

2015-11-16 18:18:58: NDMP: 4: Thread nasa00  1MB -- 32MB size file processed: 12915

2015-11-16 18:18:58: NDMP: 4: Thread nasa00 32MB -- 1GB size file processed: 457

2015-11-16 18:18:58: NDMP: 4: Thread nasa00    1G more   size file processed: 20

2015-11-16 18:18:58: NDMP: 4: Thread nasa00 Dedup files processed: 91570

2015-11-16 18:18:58: NDMP: 6: Thread nasa00 server_archive: emctar vol 1, 829167 files, 0 bytes read, 108014338048 bytes written

2015-11-16 18:18:58: NDMP: 4: Got stat buffer with data pointer=NULL at 1576, abort=1

2015-11-16 18:18:58: NDMP: 4: Thread nasa00 cifs_ea new count: 937617, delete count: 937617, freeListCount: 128

2015-11-16 18:19:04: NDMP: 6: Session 001 (thread ndmp001) < receive DATA_ABORT request >

2015-11-16 18:19:04: NDMP: 6: Session 001 (thread ndmp001) < sent DATA_ABORT reply, error: NDMP_NO_ERR >

2015-11-16 18:19:04: NDMP: 6: Cleanup: Active NDMP backup/restore sessions back to: 0, system configured concurrent streams: 4, maximum concurrent sessions allowed: 4.

2 Intern

 • 

20.4K Posts

November 22nd, 2015 06:00

this discussion belongs in VNX forum not Avamar.

Sure looks like media error, what are you backing up to ? Disk pool on TSM or directly to tape ?

6 Posts

November 22nd, 2015 15:00

Sorry Incorrectly posted, its related to EMC celera.

we are backing up to directly to local library with LT04 tapes by using HP MSL 6000 with 2 tape drives, where its connected to EMC celera, TSM server will control NDMP backups remotely.

2 Intern

 • 

20.4K Posts

November 23rd, 2015 09:00

did you invetigate tape library issues with HP ?  Based on errors in the log it could be the library issue.

6 Posts

November 23rd, 2015 09:00

Another file system backup started and its writing data with below stats, previously also its has started writing data but in certain point of  session failing(after 5 % data process),, again its failed after reaching 2 % data process

server_pax server_2 -stats

server_2 :

**************  SUMMARY PAX STATS ****************

----  NASS STATS ----

**  nass thid 0 **

Total    file     processed: 776145

throughput: 481 files/sec

Total nass wait nasa count: 95218

Total nass wait nasa time: 833667 msec

Total time since last reset: 1612 sec

fts_build time: 530 sec

getstatpool: 126 buffers        putstatpool: 0 buffers

nass01 is not doing backup

nass02 is not doing backup

nass03 is not doing backup

nass04 is not doing backup

nass05 is not doing backup

nass06 is not doing backup

nass07 is not doing backup

----  NASA STATS ----

**  nasa thid 0 is running backup with dump format **

1448299619: NDMP: 4: Thread MAC14 Backup root directory: /root_vdm_1/fs04

Total bytes processed: 80664579067

Total    file     processed: 776145

throughput: 47 MB/sec

average file size: 101KB

Total nasa wait nass count: 199975

Total nasa wait nass time: 147150 msec

Total time since last reset: 1612 sec

Tape device name: c32t0l2

nasa01 is not doing backup/restore

nasa02 is not doing backup/restore

nasa03 is not doing backup/restore

nasa04 is not doing backup/restore

nasa05 is not doing backup/restore

nasa06 is not doing backup/restore

nasa07 is not doing backup/restore

----  NASW STATS ----

nasw00 BACKUP  (in progress)

Nasw Total Time: 00:26:52 (h:min:sec)

Nasw Idle  Time: 00:14:26 (h:min:sec)

KB Transferred: 78773952  Block Size: 65536 (64 KB)

Average Transfer Rate: 47 MB/Sec (167 GB/Hour)

__Point-in-Time__ (over the last 10 seconds)

Rate: 17 MB/Sec (62 GB/Hour)  Idle: 865 msec/sec

Get Pool: 0 buffers  Put Pool: 63 buffers

dsmservererr.log

[11-23-2015 16:19:35.586][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128) SnapSure file system creation succeeds

[11-23-2015 16:32:29.473][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128) Medium error

[11-23-2015 16:32:29.473][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128) Write failed on archive volume 1

[11-23-2015 16:32:29.473][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128) server_archive: emctar vol 1, 110202 files, 0 bytes

[11-23-2015 16:32:29.473][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128)  read, 67146219520 bytes writ

[11-23-2015 16:59:39.102][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128) SnapSure file system creation succeeds

[11-23-2015 17:31:34.021][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128) Medium error

[11-23-2015 17:31:34.021][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128) Write failed on archive volume 1

[11-23-2015 17:31:34.021][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128) server_archive: emctar vol 1, 812978 files, 0 bytes

[11-23-2015 17:31:34.021][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128)  read, 89725796352 bytes writ

ndmp log:

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) < Backup type: dump >

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) Name: FILESYSTEM Value: /root_vdm_1/fs04

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) Name: TYPE Value: dump

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) Name: DATA_BLOCK_SIZE Value: 63

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) Name: LEVEL Value: 0

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) Name: UPDATE Value: Y

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) Name: NON_QUOTA_TREE Value: N

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) Name: NO_ACLS Value: N

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) Name: HIST Value: Y

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) Name: DIRECT Value: N

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) Name: EXTRACT Value: Y

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) Name: EXTRACT_ACL Value: Y

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) Name: DEBUG Value: N

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) Name: VERBOSE Value: N

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) Name: REPLICATE Value: N

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) Name: FORCE Value: N

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) Name: NOWRITE Value: N

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) Name: LIST Value: N

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) Name: LIST_TREES Value: N

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) Name: BASE_DATE Value: 0

2015-11-23 17:00:02: NDMP: 4: Session 452 (thread ndmp452) Name: DMP_NAME Value: TSM /root_vdm_1/fs04

2015-11-23 17:00:07: ADMIN: 6: Command succeeded : serverMount ckpt ro /root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt5-27-1448298002 217=633 ro

2015-11-23 17:00:09: NDMP: 4: Session 452 (thread ndmp452) tape drive: c32t0l2, CALLER_ADDRESS 0x0001671ec0.

2015-11-23 17:00:09: NDMP: 4: Thread ndmp452 uses a set of Pax threads with handle 0.

2015-11-23 17:00:09: NDMP: 6: Thread ndmp452 filterDialect could not be set - prereqs not met [pax_cmd_thread::setFilterDialect]

2015-11-23 17:00:09: NDMP: 4: Thread ndmp452 fsSize of /root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt5-27-1448298002 is 3366149734400 (../pax_ndmp.cxx: 1215)

2015-11-23 17:32:04: NDMP: 3: last message repeated 1 times

2015-11-23 17:32:04: NDMP: 3: Thread nasw00 DartTapeInterface: write error

2015-11-23 17:32:04: NDMP: 3: Session 452 (thread nasw00) Tape write error: No error reported  on drive c32t0l2.

2015-11-23 17:32:04: NDMP: 3: Session 452 (thread nasw00 fails in tapeWrite or tapeWriteMsg for drive c32t0l2, numMsg=9, maxMsg=64, n=-1,  bcnt=65536, length=65536, fileName=../NdmpdMover.cxx, lineNo=694.

2015-11-23 17:32:04: NDMP: 3: Session 452 (thread nasw00) NdmpdSession::ndmpdApiWrite fails in local or remote wirte msg, moverAddressType=0, mp=0x009c03e880

2015-11-23 17:32:04: NDMP: 3: Thread bkup006 Medium error

2015-11-23 17:32:04: NDMP: 3: < LOG type: 2, msg_id: 0, entry: Medium error, hasAssociatedMsg: 0, associatedMsgSeq: 0 >

2015-11-23 17:32:04: NDMP: 4: Thread bkup006 Write failed on archive volume 1

2015-11-23 17:32:04: NDMP: 4: < LOG type: 3, msg_id: 0, entry: Write failed on archive volume 1, hasAssociatedMsg: 0, associatedMsgSeq: 0 >

2015-11-23 17:32:04: PAX: 3: Thread bkup006 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt5-27-1448298002/Users-F/ASINGH/MobileCache_Bkp_29_oct14/WW_Assets/MobileCache/MobileCache.db) failed

2015-11-23 17:32:04: PAX: 3: Thread bkup042 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt5-27-1448298002/Users-F/ASINGH/MDM%20WORK%20TRACKER_CAPITAL_PROJECT_2_2(1).xlsx) failed

2015-11-23 17:32:04: PAX: 3: Thread bkup036 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt5-27-1448298002/Users-F/ASINGH/Dropbox - class 4 holiday ip.pdf_files/pdf.viewer-vflTgNf96.js) failed

2015-11-23 17:32:04: PAX: 3: Thread bkup034 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt5-27-1448298002/Users-F/ASINGH/Dropbox - class 4 holiday ip.pdf_files/web_sprites-vflUClSTO.css) failed

2015-11-23 17:32:04: PAX: 3: Thread bkup054 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt5-27-1448298002/Users-F/ASINGH/Dropbox - class 4 holiday ip.pdf_files/components-vflU4bdqj.css) failed

2015-11-23 17:32:04: PAX: 3: Thread bkup044 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt5-27-1448298002/Users-F/ASINGH/Dropbox - class 4 holiday ip.pdf_files/require-vflWDv1yL.js) failed

2015-11-23 17:32:04: PAX: 3: Thread bkup029 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt5-27-1448298002/Users-F/ASINGH/MobileCache_Bkp_29_oct14/WW_Assets/WW/MobileCache/MapSchema.bin) failed

2015-11-23 17:32:04: PAX: 3: Thread bkup007 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt5-27-1448298002/Users-F/ASINGH/Dropbox - class 4 holiday ip.pdf_files/pkg-a-vflr2BZth.js) failed

2015-11-23 17:32:04: PAX: 3: Thread bkup049 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt5-27-1448298002/Users-F/ASINGH/Dropbox - class 4 holiday ip.pdf_files/react-0.12.0.min-vfl7pWXh9.js) failed

2015-11-23 17:32:04: PAX: 3: Thread bkup057 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt5-27-1448298002/Users-F/ASINGH/Dropbox - class 4 holiday ip.pdf_files/jquery.fs.zoomer-vflukIRnE.js) failed

2015-11-23 17:32:04: PAX: 3: Thread bkup026 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt5-27-1448298002/Users-F/ASINGH/MobileCache_Bkp_29_oct14/WW_Assets/WW/MobileCache/MobileCache.db) failed

2015-11-23 17:32:04: PAX: 3: Thread bkup045 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt5-27-1448298002/Users-F/ASINGH/Dropbox - class 4 holiday ip.pdf_files/main-vflh4KQOF.css) failed

2015-11-23 17:32:04: PAX: 3: Thread bkup025 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt5-27-1448298002/Users-F/ASINGH/MobileCache_Bkp_29_oct14/WW_Redlines/MobileCache/MobileCache.db) failed

2015-11-23 17:32:04: PAX: 3: Thread bkup031 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt5-27-1448298002/Users-F/ASINGH/BRD123_For_Review_KP V4.xlsx) failed

2015-11-23 17:32:04: PAX: 3: Thread bkup050 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt5-27-1448298002/Users-F/ASINGH/INTERIN_TABLE_TEMPLATE.xls) failed

2015-11-23 17:32:04: PAX: 3: Thread bkup032 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt5-27-1448298002/Users-F/ASINGH/Dropbox - class 4 holiday ip.pdf_files/pkg-c-vfl4BDP2G.js) failed

2015-11-23 17:32:04: PAX: 3: Thread bkup010 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt5-27-1448298002/Users-F/ASINGH/MobileCache_Bkp_29_oct14/WW_Redlines/MobileCache/MapSchema.bin) failed

2015-11-23 17:32:04: NDMP: 4: rw_thread ARCHIVE. Media error happened.

2015-11-23 17:32:04: NDMP: 4: last message repeated 62 times

2015-11-23 17:32:04: NDMP: 4: Thread nasa00 Backup root directory: /root_vdm_1/fs04

2015-11-23 17:32:04: NDMP: 4: Thread nasa00 write count 89725796352

2015-11-23 17:32:04: NDMP: 4: Thread nasa00 time used 1918 sec

2015-11-23 17:32:04: NDMP: 4: Thread nasa00 write rate 45679 KB/Sec

2015-11-23 17:32:04: NDMP: 4: Thread nasa00 read rate 0 KB/Sec

2015-11-23 17:32:04: NDMP: 4: Thread nasa00 average file size: 107KB

2015-11-23 17:32:04: NDMP: 4: Thread nasa00 dir  or   0  size file processed: 109897

2015-11-23 17:32:04: NDMP: 4: Thread nasa00   1B -- 8KB  size file processed: 547966

2015-11-23 17:32:04: NDMP: 4: Thread nasa00  8KB -- 16KB size file processed: 33417

2015-11-23 17:32:04: NDMP: 4: Thread nasa00 16KB -- 32KB size file processed: 34377

2015-11-23 17:32:04: NDMP: 4: Thread nasa00 32KB -- 64KB size file processed: 23566

2015-11-23 17:32:04: NDMP: 4: Thread nasa00 64KB -- 1MB  size file processed: 52030

2015-11-23 17:32:04: NDMP: 4: Thread nasa00  1MB -- 32MB size file processed: 11274

2015-11-23 17:32:04: NDMP: 4: Thread nasa00 32MB -- 1GB  size file processed: 435

2015-11-23 17:32:04: NDMP: 4: Thread nasa00    1G more   size file processed: 16

2015-11-23 17:32:04: NDMP: 4: Thread nasa00 Dedup files processed: 83923

2015-11-23 17:32:04: NDMP: 6: Thread nasa00 server_archive: emctar vol 1, 812978 files, 0 bytes read, 89725796352 bytes written

2015-11-23 17:32:04: NDMP: 4: Got stat buffer with data pointer=NULL at 1576, abort=1

2015-11-23 17:32:04: NDMP: 4: Thread nasa00 cifs_ea new count: 1044866, delete count: 1044866, freeListCount: 128

2015-11-23 17:32:09: NDMP: 6: Session 452 (thread ndmp452) < receive DATA_ABORT request >

2015-11-23 17:32:09: NDMP: 6: Session 452 (thread ndmp452) < sent DATA_ABORT reply, error: NDMP_NO_ERR >

2015-11-23 17:32:09: NDMP: 6: Cleanup: Active NDMP backup/restore sessions back to: 0, system configured concurrent streams: 4, maximum concurrent sessions allowed: 4.

2015-11-23 17:32:10: NDMP: 3: Session 468 (thread ndmp468) Error opening SCSI device: c32t0l0 NDMP_DEVICE_BUSY_ERR.

[nasadmin@CFIWP03 ~]$

6 Posts

November 23rd, 2015 09:00

Today again we reran the backup, after adding new LTO4 tapes even though we got same problem, and no luck so far..

Following error log from dsmserver.err log:

[11-23-2015 16:19:35.586][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128) SnapSure file system creation succeeds

[11-23-2015 16:32:29.473][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128) Medium error

[11-23-2015 16:32:29.473][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128) Write failed on archive volume 1

[11-23-2015 16:32:29.473][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128) server_archive: emctar vol 1, 110202 files, 0 bytes

[11-23-2015 16:32:29.473][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128)  read, 67146219520 bytes writ

[11-23-2015 16:59:39.102][ FFDC_MSG_FROM_NDMP_DEVICE ]: (ndlog.c:128) SnapSure file system creation succeeds

Ndmp error log:

[nasadmin@CFIWP03 ~]$ server_log server_2 | grep -i NDMP | tail -100

2015-11-23 16:19:58: NDMP: 4: Session 446 (thread ndmp446) Name: LEVEL Value: 0

2015-11-23 16:19:58: NDMP: 4: Session 446 (thread ndmp446) Name: UPDATE Value: Y

2015-11-23 16:19:58: NDMP: 4: Session 446 (thread ndmp446) Name: NON_QUOTA_TREE Value: N

2015-11-23 16:19:58: NDMP: 4: Session 446 (thread ndmp446) Name: NO_ACLS Value: N

2015-11-23 16:19:58: NDMP: 4: Session 446 (thread ndmp446) Name: HIST Value: Y

2015-11-23 16:19:58: NDMP: 4: Session 446 (thread ndmp446) Name: DIRECT Value: N

2015-11-23 16:19:58: NDMP: 4: Session 446 (thread ndmp446) Name: EXTRACT Value: Y

2015-11-23 16:19:58: NDMP: 4: Session 446 (thread ndmp446) Name: EXTRACT_ACL Value: Y

2015-11-23 16:19:58: NDMP: 4: Session 446 (thread ndmp446) Name: DEBUG Value: N

2015-11-23 16:19:58: NDMP: 4: Session 446 (thread ndmp446) Name: VERBOSE Value: N

2015-11-23 16:19:58: NDMP: 4: Session 446 (thread ndmp446) Name: REPLICATE Value: N

2015-11-23 16:19:58: NDMP: 4: Session 446 (thread ndmp446) Name: FORCE Value: N

2015-11-23 16:19:58: NDMP: 4: Session 446 (thread ndmp446) Name: NOWRITE Value: N

2015-11-23 16:19:58: NDMP: 4: Session 446 (thread ndmp446) Name: LIST Value: N

2015-11-23 16:19:58: NDMP: 4: Session 446 (thread ndmp446) Name: LIST_TREES Value: N

2015-11-23 16:19:58: NDMP: 4: Session 446 (thread ndmp446) Name: BASE_DATE Value: 0

2015-11-23 16:19:58: NDMP: 4: Session 446 (thread ndmp446) Name: DMP_NAME Value: TSM /root_vdm_1/fs02

2015-11-23 16:20:03: ADMIN: 6: Command succeeded : serverMount ckpt ro /root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598 198=632 ro

2015-11-23 16:20:05: NDMP: 4: Session 446 (thread ndmp446) tape drive: c32t0l2, CALLER_ADDRESS 0x0001671ec0.

2015-11-23 16:20:05: NDMP: 4: Thread ndmp446 uses a set of Pax threads with handle 0.

2015-11-23 16:20:05: NDMP: 6: Thread ndmp446 filterDialect could not be set - prereqs not met [pax_cmd_thread::setFilterDialect]

2015-11-23 16:20:05: NDMP: 4: Thread ndmp446 fsSize of /root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598 is 2737213595648 (../pax_ndmp.cxx: 1215)

2015-11-23 16:32:59: NDMP: 3: Thread nasw00 DartTapeInterface: write error

2015-11-23 16:32:59: NDMP: 3: Session 446 (thread nasw00) Tape write error: No error reported  on drive c32t0l2.

2015-11-23 16:32:59: NDMP: 3: Session 446 (thread nasw00 fails in tapeWrite or tapeWriteMsg for drive c32t0l2, numMsg=9, maxMsg=64, n=-1,  bcnt=65536, length=65536, fileName=../NdmpdMover.cxx, lineNo=694.

2015-11-23 16:32:59: NDMP: 3: Session 446 (thread nasw00) NdmpdSession::ndmpdApiWrite fails in local or remote wirte msg, moverAddressType=0, mp=0x0003012450

2015-11-23 16:32:59: NDMP: 3: Thread bkup033 Medium error

2015-11-23 16:32:59: NDMP: 3: < LOG type: 2, msg_id: 0, entry: Medium error, hasAssociatedMsg: 0, associatedMsgSeq: 0 >

2015-11-23 16:32:59: NDMP: 4: Thread bkup033 Write failed on archive volume 1

2015-11-23 16:32:59: NDMP: 4: < LOG type: 3, msg_id: 0, entry: Write failed on archive volume 1, hasAssociatedMsg: 0, associatedMsgSeq: 0 >

2015-11-23 16:32:59: PAX: 3: Thread bkup028 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598/Users-D/T1SANDER/my office/Portal Migration/Portal Migration Master.xls) failed

2015-11-23 16:32:59: PAX: 3: Thread bkup042 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598/Users-D/T1SANDER/my office/Portal Migration/Shared Migration Spreads/Human Resources.xls) failed

2015-11-23 16:32:59: PAX: 3: Thread bkup030 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598/Users-D/T1SANDER/my office/Portal Migration/Shared Migration Spreads/Asset Management.xls) failed

2015-11-23 16:32:59: PAX: 3: Thread bkup056 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598/Users-D/T1SANDER/my office/My Pictures/Thumbs.db) failed

2015-11-23 16:32:59: PAX: 3: Thread bkup036 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598/Users-D/T1SANDER/my office/Portal Migration/Shared Migration Spreads/External Affairs.xls) failed

2015-11-23 16:32:59: PAX: 3: Thread bkup045 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598/Users-D/T1SANDER/my office/Portal Migration/Shared Migration Spreads/Our Company.xls) failed

2015-11-23 16:32:59: PAX: 3: Thread bkup040 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598/Users-D/T1SANDER/my office/Portal Migration/Shared Migration Spreads/Finance & Business Services.xls) failed

2015-11-23 16:32:59: PAX: 3: Thread bkup043 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598/Users-D/T1SANDER/my office/Portal Migration/Shared Migration Spreads/Customer Services.xls) failed

2015-11-23 16:32:59: PAX: 3: Thread bkup051 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598/Users-D/T1SANDER/my office/Portal Migration/Shared Migration Spreads/Operations.xls) failed

2015-11-23 16:32:59: PAX: 3: Thread bkup037 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598/Users-D/T1SANDER/my office/Portal Migration/SME Instructions.doc) failed

2015-11-23 16:32:59: PAX: 3: Thread bkup009 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598/Users-D/T1SANDER/my office/Portal Migration/Current CE list.xls) failed

2015-11-23 16:32:59: PAX: 3: Thread bkup012 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598/Users-D/T1SANDER/my office/Adjusted times.xls) failed

2015-11-23 16:32:59: PAX: 3: Thread bkup010 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598/Users-D/T1SANDER/Documentum Package/Recharge Spreadsheets/May 10 - Recharge Cut_CS.xls) failed

2015-11-23 16:32:59: PAX: 3: Thread bkup011 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598/Users-D/T1SANDER/my office/Portal Migration/Archived/PMMShared.xls) failed

2015-11-23 16:32:59: PAX: 3: Thread bkup018 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598/Users-D/T1SANDER/my office/Portal Migration/Archived/Portal Migration MasterSpreadVtrial.xls) failed

2015-11-23 16:32:59: PAX: 3: Thread bkup024 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598/Users-D/T1SANDER/my office/Portal Migration/Archived/Portal Update Input 1.xls) failed

2015-11-23 16:32:59: PAX: 3: Thread bkup013 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598/Users-D/T1SANDER/my office/Portal Migration/Archived/Portal Migration MasterSpread.xls) failed

2015-11-23 16:32:59: PAX: 3: Thread bkup027 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598/Users-D/T1SANDER/my office/Portal Migration/Archived/SimpleSpread.xls) failed

2015-11-23 16:32:59: PAX: 3: Thread bkup023 dedup_backup(/root_vdm_1/automaticNDMPCkpts/automaticTempNDMPCkpt4-22-1448295598/Users-D/T1SANDER/my office/Portal Migration/Migration Input forms.xls) failed

2015-11-23 16:32:59: NDMP: 4: rw_thread ARCHIVE. Media error happened.

2015-11-23 16:32:59: NDMP: 4: last message repeated 62 times

2015-11-23 16:32:59: NDMP: 4: Thread nasa00 Backup root directory: /root_vdm_1/fs02

2015-11-23 16:32:59: NDMP: 4: Thread nasa00 write count 67146219520

2015-11-23 16:32:59: NDMP: 4: Thread nasa00 time used 774 sec

2015-11-23 16:32:59: NDMP: 4: Thread nasa00 write rate 84617 KB/Sec

2015-11-23 16:32:59: NDMP: 4: Thread nasa00 read rate 0 KB/Sec

2015-11-23 16:32:59: NDMP: 4: Thread nasa00 average file size: 595KB

2015-11-23 16:32:59: NDMP: 4: Thread nasa00 dir  or   0  size file processed: 12330

2015-11-23 16:32:59: NDMP: 4: Thread nasa00   1B -- 8KB  size file processed: 29664

2015-11-23 16:32:59: NDMP: 4: Thread nasa00  8KB -- 16KB size file processed: 4841

2015-11-23 16:32:59: NDMP: 4: Thread nasa00 16KB -- 32KB size file processed: 12137

2015-11-23 16:32:59: NDMP: 4: Thread nasa00 32KB -- 64KB size file processed: 13040

2015-11-23 16:32:59: NDMP: 4: Thread nasa00 64KB -- 1MB  size file processed: 29914

2015-11-23 16:32:59: NDMP: 4: Thread nasa00  1MB -- 32MB size file processed: 8160

2015-11-23 16:32:59: NDMP: 4: Thread nasa00 32MB -- 1GB  size file processed: 108

2015-11-23 16:32:59: NDMP: 4: Thread nasa00    1G more   size file processed: 8

2015-11-23 16:32:59: NDMP: 4: Thread nasa00 Dedup files processed: 40584

2015-11-23 16:32:59: NDMP: 6: Thread nasa00 server_archive: emctar vol 1, 110202 files, 0 bytes read, 67146219520 bytes written

2015-11-23 16:32:59: NDMP: 4: Got stat buffer with data pointer=NULL at 1576, abort=1

2015-11-23 16:32:59: NDMP: 4: Thread nasa00 cifs_ea new count: 124322, delete count: 124322, freeListCount: 128

2015-11-23 16:33:04: NDMP: 6: Session 446 (thread ndmp446) < receive DATA_ABORT request >

2015-11-23 16:33:04: NDMP: 6: Session 446 (thread ndmp446) < sent DATA_ABORT reply, error: NDMP_NO_ERR >

2015-11-23 16:33:04: NDMP: 6: Cleanup: Active NDMP backup/restore sessions back to: 0, system configured concurrent streams: 4, maximum concurrent sessions allowed: 4.

2015-11-23 17:00:01: NDMP: 6: Active NDMP backup/restore streams: 1, system configured concurrent streams: 4, maximum concurrent sessions supported: 4.

TSM actlog;

11/23/2015 16:19:19  ANR0513I Process 184 opened output volume CWC203L4.

                      (SESSION: 55778, PROCESS: 184)

11/23/2015 16:32:34  ANR0515I Process 184 closed volume CWC203L4. (SESSION:

                      55778, PROCESS: 184)

11/23/2015 16:32:34  ANR8336I Verifying label of NAS volume CWC203L4 in drive

                      DRIVE01 (c32t0l2). (SESSION: 55778, PROCESS: 184)

11/23/2015 16:33:29  ANR8468I NAS volume CWC203L4 dismounted from drive DRIVE01

                      (c32t0l2) in library CWCNASLIB. (SESSION: 55778, PROCESS:

                      184)

11/23/2015 16:33:29  ANR1104E NAS Backup process 184 terminated - NAS datamover

                      CFIWP04 reported NDMP session errors. (SESSION: 55778,

                      PROCESS: 184)

11/23/2015 16:33:29  ANR3616E An error occurred. More information might be

                      available in the dsmserv.err file. (SESSION: 55778,

                      PROCESS: 184)

11/23/2015 16:33:29  ANR0988I Process 184 for BACKUP NAS (FULL) running in the

                      FOREGROUND processed 67,146,219,520 bytes with a

                      completion state of FAILURE at 16:33:29. (SESSION: 55778,

                      PROCESS: 184)

11/23/2015 16:33:29  ANR1893E Process 184 for BACKUP NAS (FULL) completed with

                      a completion state of FAILURE. (SESSION: 55778, PROCESS:

                      184)

6 Posts

January 27th, 2016 00:00

Hi All

we have succeed to get ride of this problem in our environment, but out of two tape drives only one tape drive functional , drive wise it does not have any issues.

Library side tape drives's changed, cables changed. NAS box side parameters we reverted as default settings which is not created any difference.

Finally its HP tape library hardware and its LTO4 drives issues. Nearly we have replaced randomly more than 6 tape drives and started working at one point of time. its took more than 2 months to get ride of this problem, in this entire process we have fixed all other problems as well. SP-B replacements and faulty disk replacements etc..

Thanks everyone who has supported on this issue and our team got confidence to deal NAS problems with other customers combination of 3 different vendors.

1) NAS head- EMC Celera NAS NX 120

2) Tape library - HP MSL 6000

3) Backup-IBM TSM 6.3.4

4) Support-Thrid party contractors

Its Big Experience to co-ordinate and close this call successfully by Dec 15th. SR reference 75342954, can link this which is usefull for other customers for same problem.

No Events found!

Top