Slow replication after V7 upgrade from 6.5

[johnlong]

Edit,
This log I thought was pre upgrade but it tuns out it was post upgrade. Multiple jobs on this VM have run after the upgrade just fine. This is the log from the last job that ran fast. Below this log is the job that is taking forever to finish.

Code: Select all

10/14/2013 2:15:45 AM :: Queued for processing at 10/14/2013 2:15:45 AM
10/14/2013 2:15:46 AM :: Required backup infrastructure resources have been assigned
10/14/2013 2:35:49 AM :: VM processing started at 10/14/2013 2:35:49 AM
10/14/2013 2:35:49 AM :: VM size: 475.0 GB
10/14/2013 2:35:52 AM :: Discovering replica VM
10/14/2013 2:36:02 AM :: Creating VM snapshot
10/14/2013 2:36:15 AM :: Preparing replica VM
10/14/2013 2:36:41 AM :: Processing configuration
10/14/2013 2:37:03 AM :: Creating helper snapshot
10/14/2013 2:37:11 AM :: Using backup proxy timmy-hou for disk Hard disk 1 [san]
10/14/2013 2:37:11 AM :: Using target proxy rd-aus for disk Hard disk 1 [nbd]
10/14/2013 2:37:14 AM :: Hard disk 1 (60.0 GB)
10/14/2013 2:37:51 AM :: Using backup proxy timmy-hou for disk Hard disk 2 [san]
10/14/2013 2:37:51 AM :: Using target proxy rd-aus for disk Hard disk 2 [nbd]
10/14/2013 2:37:56 AM :: Hard disk 2 (325.0 GB)
10/14/2013 2:46:04 AM :: Using backup proxy timmy-hou for disk Hard disk 3 [san]
10/14/2013 2:46:05 AM :: Using target proxy rd-aus for disk Hard disk 3 [nbd]
10/14/2013 2:46:10 AM :: Hard disk 3 (90.0 GB)
10/14/2013 2:48:47 AM :: Removing VM snapshot
10/14/2013 2:49:40 AM :: Deleting helper snapshot
10/14/2013 2:50:23 AM :: 1 restore point removed by retention policy
10/14/2013 2:51:27 AM :: Finalizing
10/14/2013 2:51:29 AM :: Busy: Source 37% > Proxy 24% > Network 75% > Target 5%
10/14/2013 2:51:29 AM :: Primary bottleneck: Network
10/14/2013 2:51:29 AM :: Network traffic verification detected no corrupted blocks
10/14/2013 2:51:29 AM :: Processing finished at 10/14/2013 2:51:29 AM

Job taking too long. When CBT has an error the replication job doesn't take this long.

Code: Select all

10/16/2013 9:29:09 PM :: Queued for processing at 10/16/2013 9:29:09 PM
10/16/2013 9:29:09 PM :: Required backup infrastructure resources have been assigned
10/16/2013 9:29:11 PM :: VM processing started at 10/16/2013 9:29:11 PM
10/16/2013 9:29:11 PM :: VM size: 475.0 GB
10/16/2013 9:29:13 PM :: Discovering replica VM
10/16/2013 9:29:22 PM :: Creating VM snapshot
10/16/2013 9:29:36 PM :: Preparing replica VM
10/16/2013 9:29:38 PM :: Processing configuration
10/16/2013 9:30:23 PM :: Using backup proxy timmy-hou for disk Hard disk 1 [san]
10/16/2013 9:30:23 PM :: Using target proxy rd-aus for disk Hard disk 1 [nbd]
10/16/2013 9:30:26 PM :: Hard disk 1 (60.0 GB)
10/16/2013 9:30:57 PM :: Swap file blocks skipped: 1.3 MB
10/16/2013 9:30:59 PM :: Using backup proxy timmy-hou for disk Hard disk 2 [san]
10/16/2013 9:31:00 PM :: Using target proxy rd-aus for disk Hard disk 2 [nbd]
10/16/2013 9:31:05 PM :: Hard disk 2 (325.0 GB)

56% complete HD 2 [cbt] 17:26:46

It's almost like a full replication is taking place. I didn't do anything to trigger a complete replication and the snapshots are still intact on the replica.

Nothing else has changed.

Here is another VM post upgrade and the replication is fine.

Code: Select all

10/16/2013 6:01:42 PM :: Queued for processing at 10/16/2013 6:01:42 PM
10/16/2013 6:01:50 PM :: Required backup infrastructure resources have been assigned
10/16/2013 9:09:47 PM :: VM processing started at 10/16/2013 9:09:47 PM
10/16/2013 9:09:47 PM :: VM size: 550.0 GB
10/16/2013 9:09:49 PM :: Discovering replica VM
10/16/2013 9:09:58 PM :: Creating VM snapshot
10/16/2013 9:10:18 PM :: Preparing replica VM
10/16/2013 9:10:41 PM :: Processing configuration
10/16/2013 9:11:02 PM :: Creating helper snapshot
10/16/2013 9:11:09 PM :: Using backup proxy timmy-hou for disk Hard disk 1 [san]
10/16/2013 9:11:09 PM :: Using target proxy rd-aus for disk Hard disk 1 [nbd]
10/16/2013 9:11:12 PM :: Hard disk 1 (50.0 GB)
10/16/2013 9:11:38 PM :: Using backup proxy timmy-hou for disk Hard disk 2 [san]
10/16/2013 9:11:38 PM :: Using target proxy rd-aus for disk Hard disk 2 [nbd]
10/16/2013 9:11:44 PM :: Hard disk 2 (500.0 GB)
10/16/2013 9:26:14 PM :: Removing VM snapshot
10/16/2013 9:26:58 PM :: Deleting helper snapshot
10/16/2013 9:27:41 PM :: 1 restore point removed by retention policy
10/16/2013 9:28:17 PM :: Finalizing
10/16/2013 9:28:19 PM :: Busy: Source 36% > Proxy 4% > Network 78% > Target 6%
10/16/2013 9:28:19 PM :: Primary bottleneck: Network
10/16/2013 9:28:19 PM :: Network traffic verification detected no corrupted blocks
10/16/2013 9:28:19 PM :: Processing finished at 10/16/2013 9:28:19 PM

[foggy]

Are you saying that after the upgrade your jobs continue to run fine but then began to run slower, starting from some moment? What is the "Read" counter for the long job run? I cannot see anything suspicious that could cause this VM backup to take longer than usual in the job session logs you've provided, so I recommend opening a case and providing full debug logs to our technical support to investigate further. Thanks.