Forum Discussion

Tom_Egger's avatar
Tom_Egger
Level 4
8 years ago

Restore very slow on NDMP ONTAP 9.1P3

the restore on the Netapp take too long. we use DAR and we've Qtrees and we backup on VeritasAppliances;  any Ideas?

15.08.2017 16:31:07 - begin Restore
15.08.2017 16:31:07 - Info bprd (pid=20597) Found (76,018,402) files in (172) images for Restore Job ID 2862183.xxx
15.08.2017 16:31:07 - restoring from image xxxxxx_1502503335
15.08.2017 16:31:07 - requesting resource @aaaae
15.08.2017 16:31:07 - granted resource MediaID=@aaaae;DiskVolume=PureDiskVolume;DiskPool=dp-xxxxxx-msdp;Path=PureDiskVolume;StorageServer=xxxxxx;MediaServer=xxxxxx
15.08.2017 16:31:08 - Info bprd (pid=20597) Searched ( 1) files of (76,018,402) files for Restore Job ID 2862183.xxx
15.08.2017 16:31:08 - Info bprd (pid=20597) Restoring from copy 1 of image created Sat Aug 12 04:02:15 2017 from policy BE_P_NDMP_NetApp_P_MSDP
15.08.2017 16:31:09 - Info bpbrm (pid=328282) xxxxxx is the host to restore to
15.08.2017 16:31:09 - Info bpbrm (pid=328282) reading file list for client
15.08.2017 16:31:09 - connecting
15.08.2017 16:31:09 - Info bpbrm (pid=328282) starting bptm
15.08.2017 16:31:09 - Info ndmpagent (pid=328287) Restore started
15.08.2017 16:31:09 - connected; connect time: 0:00:00
15.08.2017 16:31:09 - Info bpbrm (pid=328282) bptm pid: 328288
15.08.2017 16:31:10 - Info bptm (pid=328288) start
15.08.2017 16:31:10 - started process bptm (pid=328288)
15.08.2017 16:31:10 - Info bptm (pid=328288) reading backup image
15.08.2017 16:31:13 - begin reading
15.08.2017 16:31:14 - Info ndmpagent (pid=328287) INF - Restoring NDMP files from /h000ro/vol_u_07
15.08.2017 16:31:14 - Info ndmpagent (pid=328287) NDMP Remote disk
15.08.2017 16:31:17 - Info ndmpagent (pid=328287) This is CDOT restore
15.08.2017 16:31:17 - Info ndmpagent (pid=328287) DAR enabled
15.08.2017 16:31:18 - Info ndmpagent (pid=328287) xxxxxx: DIRECT ACCESS RECOVERY (DAR) requested
15.08.2017 16:31:18 - Info ndmpagent (pid=328287) xxxxxx: Session identifier for Restore : 9051
15.08.2017 16:36:19 - Info ndmpagent (pid=328287) xxxxxx: RESTORE: Tue Aug 15 16:36:19 2017 : We have read 489117 KB from the backup.
15.08.2017 16:41:19 - Info ndmpagent (pid=328287) xxxxxx: RESTORE: Tue Aug 15 16:41:19 2017 : We have read 979098 KB from the backup.
15.08.2017 16:46:19 - Info ndmpagent (pid=328287) xxxxxx: RESTORE: Tue Aug 15 16:46:19 2017 : We have read 1554107 KB from the backup.
15.08.2017 16:51:19 - Info ndmpagent (pid=328287) xxxxxx: RESTORE: Tue Aug 15 16:51:19 2017 : We have read 2000643 KB from the backup.
15.08.2017 16:52:57 - begin reading
15.08.2017 16:53:01 - begin reading
15.08.2017 16:53:19 - begin reading
15.08.2017 16:54:02 - begin reading
15.08.2017 16:54:16 - begin reading
15.08.2017 16:54:30 - begin reading
15.08.2017 16:54:39 - begin reading
15.08.2017 16:54:54 - begin reading
15.08.2017 16:55:08 - begin reading
15.08.2017 16:55:25 - begin reading
15.08.2017 16:55:40 - begin reading
15.08.2017 16:55:47 - begin reading
15.08.2017 16:56:02 - begin reading
15.08.2017 16:56:19 - begin reading
15.08.2017 16:56:20 - Info ndmpagent (pid=328287) xxxxxx: RESTORE: Tue Aug 15 16:56:20 2017 : We have read 2216056 KB from the backup.
15.08.2017 16:56:36 - begin reading
15.08.2017 16:56:42 - Info ndmpagent (pid=328287) xxxxxx: RESTORE: RESTORE IS DONE
15.08.2017 16:56:42 - Info ndmpagent (pid=328287) NDMP restore successful from path /xxxxxx/vol_u_07
15.08.2017 16:56:43 - Info ndmpagent (pid=328287) done. status: 0
15.08.2017 16:56:43 - end reading; read time: 0:00:07
15.08.2017 16:56:43 - Info bptm (pid=328288) completed reading backup image
15.08.2017 16:56:43 - Info bptm (pid=328288) EXITING with status 0 <----------
15.08.2017 16:56:43 - Info xxxxxx (pid=328288) StorageServer=PureDisk:xxxxxx; Report=PDDO Stats for (xxxxxx): read: 2345454 KB, CR received: 3824602 KB, CR received over FC: 0 KB, dedup: 0.0%
15.08.2017 16:56:44 - restored from image xxxxxx_1502503335; restore time: 0:25:37
15.08.2017 16:56:44 - Info ndmpagent (pid=328287) done. status: 0: the requested operation was successfully completed
15.08.2017 16:56:44 - end Restore; elapsed time 0:25:37
the requested operation was successfully completed (0)

 

  • Have you checked log files?
    ndmpagent and bptm on media server.
    Look for '.... waited for full / empty buffer' towards the end of the restore process  (pid=328288).

  • Have you checked log files?
    ndmpagent and bptm on media server.
    Look for '.... waited for full / empty buffer' towards the end of the restore process  (pid=328288).