Amazingly slow inital replication

[Bjorn]

Hi,

We are getting rather low read speeds on initial replications, think singled digit MB/s eg

2017-03-23 08:07:22 :: Hard disk 4 (100,0 GB) 14,7 GB read at 1 MB/s [CBT]

This is Veeam B&R 9.5, vSphere 6.0, plenty of proxies, and 10GB network.

Has anyone seen - and solved! - this nuisance?

BR,
Björn

[foggy]

Hi Björn, job bottleneck stats will help to identify the reason.

[Bjorn]

Hi,

The bottleneck is 99% target right now.

In a "incremental" replication we get more reasonable speeds, eg

2017-03-23 01:08:52 :: Hard disk 2 (100,0 GB) 5,9 GB read at 76 MB/s [CBT]

even though the target load is pretty high: Load: Source 58% > Proxy 8% > Network 17% > Target 81%

How would the "treatment" of the target differ between an initial and an incremental replication?
Or am I just misinterpreting the numbers?

[veremin]

One more question - is it direct replication or replication from backups?

[foggy]

Bottleneck "Target" means that the target disk writer component spends most of the time writing data to the storage. What transport mode is used by the target proxy?

[Bjorn]

This is a direct replication and the proxy uses hot add. The proxies are set to automatic selection.
We did some test using network mode, but saw no gain from it.

We have also tried to get some stats out of our storage (dell), but to no avail.

[foggy]

I'd pay attention to the target storage then.

[Bjorn]

We are indeed, and it's not top notch but it should be that crappy...

But why are incremental replications substantially faster than initial replications? The storage should be equally crappy in both cases, right?

[foggy]

The difference shouldn't be that big, indeed (though you're posting figures for different disks, which might explain at least some of the difference - please compare the overall job processing rate numbers).

[Bjorn]

Here's some more info, first the initial replication, then an incremental

Code: Select all

Queued for processing at 2017-03-23 08:03:13 
Required backup infrastructure resources have been assigned 
VM processing started at 2017-03-23 08:03:23 
VM size: 1,5 TB 
Discovering replica VM 0:00:18
Getting VM info from vSphere 0:00:07
Network traffic will be encrypted 
Creating VM snapshot 0:00:09
Processing configuration 0:00:53
Creating helper snapshot 0:00:07
Using source proxy vbpx12.ita.chalmers.se for disk Hard disk 4 [hotadd] 0:00:34
Using source proxy vbpx4.ita.chalmers.se for disk Hard disk 1 [hotadd] 0:00:35
Using source proxy vbpx5.ita.chalmers.se for disk Hard disk 3 [hotadd] 0:00:33
Using source proxy vbpx10.ita.chalmers.se for disk Hard disk 2 [hotadd] 0:00:34
Using target proxy vbpx8.ita.chalmers.se for disk Hard disk 3 [hotadd] 
Using target proxy vbpx8.ita.chalmers.se for disk Hard disk 2 [hotadd] 
Using target proxy vbpx8.ita.chalmers.se for disk Hard disk 4 [hotadd] 
Using target proxy vbpx8.ita.chalmers.se for disk Hard disk 1 [hotadd] 
Hard disk 3 (1,4 TB) 914,9 GB read at 6 MB/s [CBT]44:15:20
Hard disk 2 (25,0 GB) 1020,5 MB read at 3 MB/s [CBT]0:06:06
Hard disk 4 (100,0 GB) 26,3 GB read at 2 MB/s [CBT]3:31:00
Hard disk 1 (55,0 GB) 35,8 GB read at 2 MB/s [CBT]4:16:25
Removing VM snapshot 0:04:16
Deleting helper snapshot 0:00:14
Finalizing 
Busy: Source 0% > Proxy 0% > Network 0% > Target 99% 
Primary bottleneck: Target 
Network traffic verification detected no corrupted blocks 
Processing finished at 2017-03-25 04:28:12 


Queued for processing at 2017-03-25 09:49:14 
Required backup infrastructure resources have been assigned 2:18:09
VM processing started at 2017-03-25 12:07:30 
VM size: 1,5 TB 
Discovering replica VM 0:00:09
Getting VM info from vSphere 0:00:06
Network traffic will be encrypted 
Creating VM snapshot 0:00:08
Preparing replica VM 0:00:11
Processing configuration 0:00:20
Creating helper snapshot 0:00:08
Using source proxy vbpx5.ita.chalmers.se for disk Hard disk 1 [hotadd] 0:01:01
Using source proxy vbpx11.ita.chalmers.se for disk Hard disk 2 [hotadd] 0:00:37
Using source proxy vbpx10.ita.chalmers.se for disk Hard disk 3 [hotadd] 0:00:37
Using source proxy vbpx6.ita.chalmers.se for disk Hard disk 4 [hotadd] 0:01:08
Using target proxy vbpx7.ita.chalmers.se for disk Hard disk 3 [hotadd] 
Using target proxy vbpx7.ita.chalmers.se for disk Hard disk 2 [hotadd] 
Using target proxy vbpx7.ita.chalmers.se for disk Hard disk 1 [hotadd] 
Using target proxy vbpx7.ita.chalmers.se for disk Hard disk 4 [hotadd] 
Hard disk 3 (1,4 TB) 18,8 GB read at 84 MB/s [CBT]0:05:12
Hard disk 2 (25,0 GB) 7,0 MB read at 7 MB/s [CBT]0:00:57
Hard disk 1 (55,0 GB) 1,9 GB read at 54 MB/s [CBT]0:01:08
Hard disk 4 (100,0 GB) 4,2 GB read at 59 MB/s [CBT]0:01:16
Removing VM snapshot 0:00:16
Deleting helper snapshot 0:00:16
Finalizing 
Busy: Source 27% > Proxy 14% > Network 27% > Target 74% 
Primary bottleneck: Target 
Network traffic verification detected no corrupted blocks 
Processing finished at 2017-03-25 12:18:26

[foggy]

Less data write on target, shorter queues, less time for the source to wait for the target (just my speculations, better ask for logs review). Also, I can see that different proxies are used on target, this might play some role as well. Any other (parallel) tasks?

[Bjorn]

Well, the initial (slow) replication was probably the only writer for at least half of its running time. We just replicate evverthing nightly, so it has clashed with to ordinary jobs. The proxiess was created equal, and probably still are.
The faster replication was part of a normal replication job, so there might be 6 proxies each running 8 tasks writing to the target.

All in all, this is very repetable and rather annoying...