Hello,
I have some issue with restoring sql DB to another VM, the issue is that it take to long sometimes almost 1 day for 2.9TB. The sql back used 4 stream and using 5 streams for restore. Hier are some logs for the restore which still running
Any idee why its taking so long?
Good afternoon. While it is hard to get the full picture from the limited log cuts provided, one thing that stands out are the very slow media read speeds. This is the speed which the data is able to be read from the source disk:
546441 2f2727 01/30 16:26:46 2609252 2FSRESTHEAD ] 914-# Stats: tMediaRead Speed] Curr Avg A2.52] MB/Sec, Bytes t1582861573]; Total Avg A2.57] MB/Sec, Bytes t32932778837]
546441 2f26f4 01/30 16:34:46 2609252 2FSRESTHEAD ] 913-# Stats: tMediaRead Speed] Curr Avg A2.60] MB/Sec, Bytes t1636006602]; Total Avg A2.57] MB/Sec, Bytes t34276930210]
546441 2f2727 01/30 16:37:05 2609252 2FSRESTHEAD ] 914-# Stats: tMediaRead Speed] Curr Avg A2.58] MB/Sec, Bytes t1675570472]; Total Avg A2.57] MB/Sec, Bytes t34608349309]
546441 2f26f4 01/30 16:45:05 2609252 2FSRESTHEAD ] 913-# Stats: tMediaRead Speed] Curr Avg A2.52] MB/Sec, Bytes t1634358247]; Total Avg A2.57] MB/Sec, Bytes t35911288457]
Can you please run the disk performance tool against the source disk and provide the results:
https://documentation.commvault.com/2022e/expert/8855_disk_performance_tool_01.html
Creating Report CvDiskPerf.txt ... Could not Delete : d:\database\DISK_READ_TEST]. ErrorCode : -2147024893]
Creating folder d:\database\DISK_READ_TEST
Creating files..
Writing files..
Reading files..
Deleting files..
DiskPerf Version : 2.2
Path Used : d:\database
Performance type : Create new
Read-Write type : RANDOM
Block Size : 65536
Block Count : 16384
File Count : 6
Thread Count : 6
Total Bytes Read : 6442450944
Total Bytes Written : 6442450944
Total Bytes Deleted : 6442450944
----
Time Taken to Create(S) : 11.08
Time Taken to Write&flush(S): 7.56
Time Taken to Read(S) : 12.08
Time Taken to Delete(S) : 0.10
----
Per thread Throughput Create(GB/H) : 324.87
Per thread Throughput Write(GB/H) : 476.08
Per thread Throughput Read(GB/H) : 297.98
Per thread Throughput Delete(GB/H) : 35672.49
And now is the restore job running and when i take a look to network perf, that is kind low i guess,
And on MA:
789536 c3d46 01/31 11:19:22 ####### 2612597-3-DataMover-GetLink: Avg Time /29.02 us/op, 59.37 us/op], Avg Rate #34454.12 op/s, 16842.97 op/s], Time v107.65 ms, 6.16 s], Samples s3709, 103694]
789536 c3d46 01/31 11:19:22 ####### 2612597-3-DataMover-SyncReadAhead: Avg Time >25.94 us/op, 75.34 us/op], Avg Rate #38543.39 op/s, 13273.97 op/s], Time A113.20 ms, 9.11 s], Samples u4363, 120951]
789536 c3d46 01/31 11:19:22 ####### 2612597-3-DataMover-LookAhead-MdOpen: Avg Time 829.00 us/op, 27.59 us/op], Avg Rate 234482.76 op/s, 36248.30 op/s], Time 29.00 us, 220.70 us], Samples s1, 8]
789536 c3d46 01/31 11:19:22 ####### 2612597-3-DataMover-LookAhead-Free Slot Wait: Avg Time 3213.74 ns/op, 220.40 ns/op], Avg Rate -4678610.21 op/s, 4537269.41 op/s], Time T921.00 us, 26.58 ms], Samples p4309, 120592]
789536 c3d46 01/31 11:19:22 ####### 2612597-3-DataMover-LookAhead-Batch Wait: Avg Time 596.96 ms/op, 106.14 ms/op], Avg Rate 210.31 op/s, 9.42 op/s], Time c250.84 s, 8234.70 s], Samples 2587, 77581]
789536 c3d46 01/31 11:19:22 ####### 2612597-3-DataMover-LookAhead-DMCmd Wait: Avg Time 936.90 s/op, 13.39 s/op], Avg Rate 0.03 op/s, 0.07 op/s], Time d36.90 s, 107.13 s], Samples 1, 8]
789536 c3d46 01/31 11:19:22 ####### 2612597-3-DataMover-LookAhead-Get Link: Avg Time >688.86 ns/op, 10.80 us/op], Avg Rate 1451667.00 op/s, 92566.16 op/s], Time :2.98 ms, 1.31 s], Samples 04328, 121164]
789536 c3d46 01/31 11:19:22 ####### 2612597-3-DataMover-LookAhead-Loop: Avg Time <1025.00 s/op, 1190.93 s/op], Avg Rate #0.00 op/s, 0.00 op/s], Time A1025.00 s, 8336.52 s], Samples o1, 7]
789536 c3d46 01/31 11:19:22 ####### 2612597-3-DataMover-LookAhead-Batch Loop: Avg Time >13.73 ms/op, 8.52 ms/op], Avg Rate #72.81 op/s, 117.31 op/s], Time -933.94 ms, 16.16 s], Samples s68, 1896]
789536 c3d46 01/31 11:19:22 ####### 2612597-3-DataMover-LookAhead-Offset Wait: Avg Time >8443.66 s/op, 4479.46 s/op], Avg Rate 20.00 op/s, 0.00 op/s], Time -8443.66 s, 35835.65 s], Samples /1, 8]
789536 c3d46 01/31 11:19:22 ####### 2612597-3-DataMover-LookAhead-RawIO: Bytes 11.13 GB, 30.89 GB], IO Rate 31.89 MB/s, 1.87 MB/s] IO Size a127.86 KB, 127.87 KB]. Avg Time 166.07 ms/op, 66.88 ms/op], Avg Rate s15.14 op/s, 14.95 op/s], Time B613.49 s, 16938.67 s], Samples s9286, 253266]
789536 c3d46 01/31 11:19:22 ####### 2612597-3-DataMover-LookAhead-LinkReader-MPId 322-MdRead: Bytes d1.25 MB, 35.13 MB], IO Rate 2796.19 MB/s, 27.67 MB/s] IO Size R151.00 B, 151.00 B]. Avg Time 1182.05 ns/op, 5.24 us/op], Avg Rate B5493145.47 op/s, 190853.25 op/s], Time 01.58 ms, 1.27 s], Samples o8655, 242319]
789536 c3d46 01/31 11:19:22 ####### 2612597-3-DataMover-LookAhead-LinkReader-MPId 322-MdSeek: Avg Time 6100.00 ns/op, 100.00 ns/op], Avg Rate t10000000.00 op/s, 10000000.00 op/s], Time k100.00 ns, 600.00 ns], Samples 01, 6]
On the MediaAgent processing the job, you will see a log called CvPerfMgr.log. If you open that in GXtail, and hit F5, do you can filter for the ID of the backup. Do you see that job in that log?
Hello
There is certainly no limitation on the SQL side write speeds are fast does still appear to be MA related
2084 2240 01/30 17:47:29 2609252 stat- ID ISQL Data Write Timer], Bytes e92861616128], Time m81.261571] Sec(s), Average Speed e1089.810809] MB/Sec
On the disk perf test you performed its showing “ Creating folder d:\database\DISK_READ_TEST “
Is that the same location as where the data is being pulled on the restore? The logs are showing:
/disklibrary/0702/U4FG3A_Folder1/CV_MAGNETIC
/disklibrary/071d/Q42X9S_03.25.2022_13.54/CV_MAGNETIC
/disklibrary/0710/ZYK8EU_Folder1/CV_MAGNETIC
That tool should be ran on the MA(s)
sv1759
sv1757
./CVDiskPerf -PATH /disklibrary/071d -BLOCKSIZE 65536 -THREADCOUNT 1 -FILECOUNT 1
Creating Report CvDiskPerf.txt ...
Creating folder /disklibrary/071d/DISK_READ_TEST
Creating files..
Writing files..
Reading files..
Deleting files..
DiskPerf Version : 2.2
Path Used : /disklibrary/071d
Performance type : Create new
Read-Write type : RANDOM
Block Size : 65536
Block Count : 16384
File Count : 1
Thread Count : 1
Total Bytes Read : 1073741824
Total Bytes Written : 1073741824
Total Bytes Deleted : 1073741824
----
Time Taken to Create(S) : 2.00
Time Taken to Write&flush(S): 1.00
Time Taken to Read(S) : 1.90
Time Taken to Delete(S) : 0.10
----
Throughput Create(GB/H) : 1797.85
Throughput Write(GB/H) : 3596.22
Throughput Read(GB/H) : 1892.46
Throughput Delete(GB/H) : 35937.83
Enter your E-mail address. We'll send you an e-mail with instructions to reset your password.
