Unsolved
This post is more than 5 years old
6 Posts
0
2830
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)
- 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.
dynamox
2 Intern
2 Intern
•
20.4K Posts
0
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 ?
kkmedasani
6 Posts
0
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.
dynamox
2 Intern
2 Intern
•
20.4K Posts
0
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.
kkmedasani
6 Posts
0
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 ~]$
kkmedasani
6 Posts
0
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)
kkmedasani
6 Posts
0
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.