NDMP リストアのパフォーマンスが非常に遅い
環境
- ONTAP 9
- 3ウェイNDMP
- リストア
- NetWorker
- NetBackup
問題
NDMPログでは PAUSED
、テープからデータを読み取るための一定の状態が表示される
Sun Jul 25 2021 05:21:54 +02:00 [kern_ndmpd:info:5516] [36326] INFO: DATA read at offset 1788662062080 with length 131072 Sun Jul 25 2021 05:21:55 +02:00 [kern_ndmpd:info:5516] [36326] INFO: DATA notification state 3 (SESS_STATE: PAUSED) event 8 (EVENT: SEEK) Sun Jul 25 2021 05:21:55 +02:00 [kern_ndmpd:info:5516] [36326] INFO: DATA read at offset 1793047803904 with length 65536 Sun Jul 25 2021 05:21:56 +02:00 [kern_ndmpd:info:5516] [36326] INFO: DATA notification state 3 (SESS_STATE: PAUSED) event 8 (EVENT: SEEK) Sun Jul 25 2021 05:21:56 +02:00 [kern_ndmpd:info:5516] [36326] INFO: DATA read at offset 1793047869440 with length 131072 Sun Jul 25 2021 05:21:56 +02:00 [kern_ndmpd:info:5516] [36326] INFO: DATA notification state 3 (SESS_STATE: PAUSED) event 8 (EVENT: SEEK)
リストア中にテープからinodeファイル情報を取得する(フェーズI)には時間がかかります。
rst Tue Jul 27 12:26:38 CEST 202 /svm_3/vol3_backup/ Tape_close (ndmp) rst Tue Jul 27 12:26:38 CEST 202 /svm_3/vol3_backup/ End (250 files, 2006 MB) rst Tue Jul 27 12:31:59 CEST 202 /svm_3/vol3_backup/ Start (Level 0, NDMP:36326) rst Tue Jul 27 12:31:59 CEST 202 /svm_3/vol3_backup/ Options (b=0, d, y, H, TCP recv buffer size = 33580, TCP send buffer size = 33580) rst Tue Jul 27 12:31:59 CEST 202 /svm_3/vol3_backup/ Tape_open (ndmp) rst Tue Jul 27 14:49:07 CEST 202 /svm_3/vol3_backup/ Log_msg (Total P2 threads (3)) rst Tue Jul 27 14:49:07 CEST 202 /svm_3/vol3_backup/ Log_msg (P2 thread 0: time (msec) (6), dirs processed (0)) rst Tue Jul 27 14:49:07 CEST 202 /svm_3/vol3_backup/ Log_msg (P2 thread 1: time (msec) (0), dirs processed (0)) rst Tue Jul 27 14:49:07 CEST 202 /svm_3/vol3_backup/ Log_msg (P2 thread 2: time (msec) (0), dirs processed (0)) rst Tue Jul 27 14:49:07 CEST 202 /svm_3/vol3_backup/ Log_msg (VM clrimap : wait_time (msec) (0), lookup_time (msec) (2290)) rst Tue Jul 27 14:49:07 CEST 202 /svm_3/vol3_backup/ Log_msg (VM dumpmap : wait_time (msec) (310), lookup_time (msec) (6170)) rst Tue Jul 27 14:49:07 CEST 202 /svm_3/vol3_backup/ Log_msg (VM inomap : wait_time (msec) (309), lookup_time (msec) (3078748)) rst Tue Jul 27 14:49:07 CEST 202 /svm_3/vol3_backup/ Log_msg (VM inomap : Cache hits (6983253), Cache misses (677340)) rst Tue Jul 27 14:49:07 CEST 202 /svm_3/vol3_backup/ Log_msg (VM basemap : wait_time (msec) (0), lookup_time (msec) (0)) rst Tue Jul 27 14:49:07 CEST 202 /svm_3/vol3_backup/ Log_msg (VM filemap : wait_time (msec) (38), lookup_time (msec) (8440)) rst Tue Jul 27 14:49:07 CEST 202 /svm_3/vol3_backup/ Log_msg (VM dirmap : wait_time (msec) (37), lookup_time (msec) (62875)) rst Tue Jul 27 14:49:07 CEST 202 /svm_3/vol3_backup/ Log_msg (VM inotab : wait_time (msec) (25), lookup_time (msec) (39916)) rst Tue Jul 27 14:49:07 CEST 202 /svm_3/vol3_backup/ Log_msg (Phase 1 percent spent in reading from media: 0%) rst Tue Jul 27 14:49:07 CEST 202 /svm_3/vol3_backup/ Log_msg (Phase 1 total time (msec): 7604422) rst Tue Jul 27 14:49:07 CEST 202 /svm_3/vol3_backup/ Log_msg (Phase 2 total time (msec): 2237) rst Tue Jul 27 14:49:07 CEST 202 /svm_3/vol3_backup/ Log_msg (Phase 3 percent spent in reading from media: 0%) rst Tue Jul 27 14:49:07 CEST 202 /svm_3/vol3_backup/ Log_msg (Phase 3 total time (msec): 620921