Progression¶
IProgress<ProgressArgs>
: A best practice using IProgress<T> to handle progress from within an awaitable method.Ìnterceptor<T>
: A more advanced technic to handle a lot of more events from within DMS
Overview¶
During a full synchronization, we have two distincts type of progression:
- The Progression from the client side.
- The Progression from the server side.
We have a lot of progress values raised from both the server and the client side:
- Each progress value is catched at the end of a method called by the Orchestrator instance.
- Each progress value in a sync process corresponds to a specific stage, represented by a
SyncStage
enumeration.
public enum SyncStage
{
None = 0,
BeginSession,
EndSession,
ScopeLoading,
ScopeWriting,
SnapshotCreating,
SnapshotApplying,
SchemaReading,
Provisioning,
Deprovisioning,
ChangesSelecting,
ChangesApplying,
Migrating,
MetadataCleaning,
}
To explain how things work, we are starting from a really straightforward sync process example, using the sample from Hello sync sample:
var serverProvider = new SqlSyncChangeTrackingProvider(serverConnectionString);
var clientProvider = new SqlSyncProvider(clientConnectionString);
var setup = new SyncSetup("ProductCategory", "ProductModel", "Product",
"Address", "Customer", "CustomerAddress", "SalesOrderHeader",
"SalesOrderDetail" );
var agent = new SyncAgent(clientProvider, serverProvider);
do
{
// Launch the sync process
var s1 = await agent.SynchronizeAsync(setup);
// Write results
Console.WriteLine(s1);
} while (Console.ReadKey().Key != ConsoleKey.Escape);
Console.WriteLine("End");
We are going to see how to get useful information, from each stage involved during the sync processus, thanks to IProgress<T>
and then we will go deeper with the notion of Interceptor<T>
.
Note
You will find this complete sample here : Progression sample
IProgress<T>¶
As we said, the progress values are triggered from both side : Server side and Client side, ordered.
In our sample, we can say that :
- The
RemoteOrchestrator
instance, using the server provider instance, will report all the progress from the server side. - The
LocalOrchestrator
instance using the client provider instance, will report all the progress from the client side.
Note
A syncAgent
object is always running on the client side of any architecture.
Since our main method SynchronizeAsync()
is marked async
method, we will use the Progress<T> to be able to report progress value.
So far, the most straightforward way to get feedback from a current sync, is to pass an instance of IProgress<T>
when calling the method SynchronizeAsync()
.
Note
Progress<T>
is not synchronous. So far, no guarantee that the progress callbacks will be raised in an ordered way.
That’s why you can use a DMS progess class called SynchronousProgress<T>
which is synchronous, using the correct synchronization context.
Here is a quick example used to provide some feedback to the user:
var serverProvider = new SqlSyncChangeTrackingProvider(serverConnectionString);
var clientProvider = new SqlSyncProvider(clientConnectionString);
// Tables involved in the sync process:
var setup = new SyncSetup ("ProductCategory", "ProductModel", "Product",
"Address", "Customer", "CustomerAddress", "SalesOrderHeader", "SalesOrderDetail" );
// Creating an agent that will handle all the process
var agent = new SyncAgent(clientProvider, serverProvider);
// Using the IProgress<T> pattern to handle progession dring the synchronization
var progress = new SynchronousProgress<ProgressArgs>(args =>
Console.WriteLine($"{s.ProgressPercentage:p}: \t[{s.Source[..Math.Min(4, s.Source.Length)]}] {s.TypeName}: {s.Message}"));
do
{
// Launch the sync process
var s1 = await agent.SynchronizeAsync(setup, progress);
// Write results
Console.WriteLine(s1);
} while (Console.ReadKey().Key != ConsoleKey.Escape);
Console.WriteLine("End");
Here is the result, after the first synchronization, assuming the Client database is empty:
0,00 %: [Clie] ProvisionedArgs: Provisioned 9 Tables. Provision:Table, TrackingTable, StoredProcedures, Triggers.
55,00 %: [Adve] TableChangesSelectedArgs: [SalesOrderHeader] [Total] Upserts:32. Deletes:0. Total:32.
75,00 %: [Adve] TableChangesSelectedArgs: [Address] [Total] Upserts:450. Deletes:0. Total:450.
75,00 %: [Adve] TableChangesSelectedArgs: [SalesOrderDetail] [Total] Upserts:542. Deletes:0. Total:542.
75,00 %: [Adve] TableChangesSelectedArgs: [ProductCategory] [Total] Upserts:41. Deletes:0. Total:41.
75,00 %: [Adve] TableChangesSelectedArgs: [ProductModel] [Total] Upserts:128. Deletes:0. Total:128.
75,00 %: [Adve] TableChangesSelectedArgs: [CustomerAddress] [Total] Upserts:417. Deletes:0. Total:417.
75,00 %: [Adve] TableChangesSelectedArgs: [ProductDescription] [Total] Upserts:762. Deletes:0. Total:762.
75,00 %: [Adve] TableChangesSelectedArgs: [Product] [Total] Upserts:295. Deletes:0. Total:295.
75,00 %: [Adve] TableChangesSelectedArgs: [Customer] [Total] Upserts:847. Deletes:0. Total:847.
75,00 %: [Adve] DatabaseChangesSelectedArgs: [Total] Upserts:3514. Deletes:0. Total:3514. [C:\Temp\DotmimSync\2022_07_17_12iks12xfjrzx]
80,42 %: [Clie] TableChangesAppliedArgs: [ProductDescription] Changes Modified Applied:762. Resolved Conflicts:0.
80,71 %: [Clie] TableChangesAppliedArgs: [ProductCategory] Changes Modified Applied:41. Resolved Conflicts:0.
81,62 %: [Clie] TableChangesAppliedArgs: [ProductModel] Changes Modified Applied:128. Resolved Conflicts:0.
83,72 %: [Clie] TableChangesAppliedArgs: [Product] Changes Modified Applied:295. Resolved Conflicts:0.
86,92 %: [Clie] TableChangesAppliedArgs: [Address] Changes Modified Applied:450. Resolved Conflicts:0.
92,95 %: [Clie] TableChangesAppliedArgs: [Customer] Changes Modified Applied:847. Resolved Conflicts:0.
95,92 %: [Clie] TableChangesAppliedArgs: [CustomerAddress] Changes Modified Applied:417. Resolved Conflicts:0.
96,14 %: [Clie] TableChangesAppliedArgs: [SalesOrderHeader] Changes Modified Applied:32. Resolved Conflicts:0.
100,00 %: [Clie] TableChangesAppliedArgs: [SalesOrderDetail] Changes Modified Applied:542. Resolved Conflicts:0.
100,00 %: [Clie] DatabaseChangesAppliedArgs: [Total] Applied:3514. Conflicts:0.
100,00 %: [Clie] SessionEndArgs: [Client] Session Ends. Id:3b69c8ab-cce8-4b94-bf75-db22ea43169d. Scope name:DefaultScope.
Synchronization done.
Total changes uploaded: 0
Total changes downloaded: 3514
Total changes applied: 3514
Total resolved conflicts: 0
Total duration :00.00:02.042
Sync Ended. Press a key to start again, or Escapte to end
As you can see, it’s a first synchronization, so:
- Session begins
- Server creates all metadatas needed for AdventureWorks database
- Client creates all metadatas needed for Client database
- Server selects all changes to upserts
- Client applies all changes sent from ths server
- Client selects changes to send (nothing, obviously, because the tables have just been created on the client)
- Session ends
You can have more information, depending on your need, and still based on IProgress<T>
.
Using a SyncProgressLevel
enumeration affected to the ProgressLevel property of your SyncOptions instance:
public enum SyncProgressLevel
{
/// <summary>
/// Progress that contain the most detailed messages and the Sql statement executed
/// </summary>
Sql,
/// <summary>
/// Progress that contain the most detailed messages. These messages may contain sensitive application data
/// </summary>
Trace,
/// <summary>
/// Progress that are used for interactive investigation during development
/// </summary>
Debug,
/// <summary>
/// Progress that track the general flow of the application.
/// </summary>
Information,
/// <summary>
/// Specifies that a progress output should not write any messages.
/// </summary>
None
}
Warning
Be careful: The Sql level may contains sensitive data !
var syncOptions = new SyncOptions
{
ProgressLevel = SyncProgressLevel.Debug
};
// Creating an agent that will handle all the process
var agent = new SyncAgent(clientProvider, serverProvider, syncOptions);
var progress = new SynchronousProgress<ProgressArgs>(s =>
{
Console.WriteLine($"{s.ProgressPercentage:p}: \t[{s.Source[..Math.Min(4, s.Source.Length)]}] {s.TypeName}: {s.Message}");
});
var s = await agent.SynchronizeAsync(setup, SyncType.Reinitialize, progress);
Console.WriteLine(s);
And the details result with a SyncProgressLevel.Debug
flag:
0,00 %: [Clie] SessionBeginArgs: [Client] Session Begins. Id:f62adec4-21a7-4a35-b86e-d3d7d52bc590. Scope name:DefaultScope.
0,00 %: [Clie] ClientScopeInfoLoadingArgs: [Client] Client Scope Table Loading.
0,00 %: [Clie] ClientScopeInfoLoadedArgs: [Client] [DefaultScope] [Version 0.9.5] Last sync:17/07/2022 20:06:57 Last sync duration:0:0:2.172.
0,00 %: [Adve] ServerScopeInfoLoadingArgs: [AdventureWorks] Server Scope Table Loading.
0,00 %: [Adve] ServerScopeInfoLoadedArgs: [AdventureWorks] [DefaultScope] [Version 0.9.5] Last cleanup timestamp:0.
0,00 %: [Adve] OperationArgs: Client Operation returned by server.
10,00 %: [Clie] LocalTimestampLoadingArgs: [Client] Getting Local Timestamp.
10,00 %: [Clie] LocalTimestampLoadedArgs: [Client] Local Timestamp Loaded:17055.
30,00 %: [Adve] ServerScopeInfoLoadingArgs: [AdventureWorks] Server Scope Table Loading.
30,00 %: [Adve] ServerScopeInfoLoadedArgs: [AdventureWorks] [DefaultScope] [Version 0.9.5] Last cleanup timestamp:0.
30,00 %: [Adve] DatabaseChangesApplyingArgs: Applying Changes. Total Changes To Apply: 0
30,00 %: [Adve] DatabaseChangesAppliedArgs: [Total] Applied:0. Conflicts:0.
55,00 %: [Adve] LocalTimestampLoadingArgs: [AdventureWorks] Getting Local Timestamp.
55,00 %: [Adve] LocalTimestampLoadedArgs: [AdventureWorks] Local Timestamp Loaded:2000.
55,00 %: [Adve] DatabaseChangesSelectingArgs: [AdventureWorks] Getting Changes. [C:\Users\spertus\AppData\Local\Temp\DotmimSync]. Batch size:5000. IsNew:True.
55,00 %: [Adve] TableChangesSelectingArgs: [Customer] Getting Changes.
55,00 %: [Adve] TableChangesSelectingArgs: [Address] Getting Changes.
55,00 %: [Adve] TableChangesSelectingArgs: [SalesOrderDetail] Getting Changes.
55,00 %: [Adve] TableChangesSelectingArgs: [Product] Getting Changes.
55,00 %: [Adve] TableChangesSelectingArgs: [ProductCategory] Getting Changes.
55,00 %: [Adve] TableChangesSelectingArgs: [ProductModel] Getting Changes.
55,00 %: [Adve] TableChangesSelectingArgs: [SalesOrderHeader] Getting Changes.
55,00 %: [Adve] TableChangesSelectingArgs: [CustomerAddress] Getting Changes.
55,00 %: [Adve] TableChangesSelectingArgs: [ProductDescription] Getting Changes.
55,00 %: [Adve] TableChangesSelectedArgs: [ProductCategory] [Total] Upserts:41. Deletes:0. Total:41.
75,00 %: [Adve] TableChangesSelectedArgs: [SalesOrderHeader] [Total] Upserts:32. Deletes:0. Total:32.
75,00 %: [Adve] TableChangesSelectedArgs: [ProductModel] [Total] Upserts:128. Deletes:0. Total:128.
75,00 %: [Adve] TableChangesSelectedArgs: [Address] [Total] Upserts:450. Deletes:0. Total:450.
75,00 %: [Adve] TableChangesSelectedArgs: [CustomerAddress] [Total] Upserts:417. Deletes:0. Total:417.
75,00 %: [Adve] TableChangesSelectedArgs: [SalesOrderDetail] [Total] Upserts:542. Deletes:0. Total:542.
75,00 %: [Adve] TableChangesSelectedArgs: [ProductDescription] [Total] Upserts:762. Deletes:0. Total:762.
75,00 %: [Adve] TableChangesSelectedArgs: [Product] [Total] Upserts:295. Deletes:0. Total:295.
75,00 %: [Adve] TableChangesSelectedArgs: [Customer] [Total] Upserts:847. Deletes:0. Total:847.
75,00 %: [Adve] DatabaseChangesSelectedArgs: [Total] Upserts:3514. Deletes:0. Total:3514. [C:\Users\spertus\AppData\Local\Temp\DotmimSync\2022_07_17_00fbihwicdj11]
75,00 %: [Adve] ScopeSavingArgs: [AdventureWorks] Scope Table [ServerHistory] Saving.
75,00 %: [Adve] ScopeSavedArgs: [AdventureWorks] Scope Table [ServerHistory] Saved.
75,00 %: [Clie] DatabaseChangesApplyingArgs: Applying Changes. Total Changes To Apply: 3514
75,00 %: [Clie] TableChangesApplyingArgs: Applying Changes To ProductDescription.
75,00 %: [Clie] TableChangesApplyingSyncRowsArgs: Applying [ProductDescription] batch rows. State:Modified. Count:762
80,42 %: [Clie] TableChangesBatchAppliedArgs: [ProductDescription] [Modified] Applied:(762) Total:(762/3514).
80,42 %: [Clie] TableChangesAppliedArgs: [ProductDescription] Changes Modified Applied:762. Resolved Conflicts:0.
80,42 %: [Clie] TableChangesApplyingArgs: Applying Changes To ProductCategory.
80,42 %: [Clie] TableChangesApplyingSyncRowsArgs: Applying [ProductCategory] batch rows. State:Modified. Count:41
80,71 %: [Clie] TableChangesBatchAppliedArgs: [ProductCategory] [Modified] Applied:(41) Total:(803/3514).
80,71 %: [Clie] TableChangesAppliedArgs: [ProductCategory] Changes Modified Applied:41. Resolved Conflicts:0.
80,71 %: [Clie] TableChangesApplyingArgs: Applying Changes To ProductModel.
80,71 %: [Clie] TableChangesApplyingSyncRowsArgs: Applying [ProductModel] batch rows. State:Modified. Count:128
81,62 %: [Clie] TableChangesBatchAppliedArgs: [ProductModel] [Modified] Applied:(128) Total:(931/3514).
81,62 %: [Clie] TableChangesAppliedArgs: [ProductModel] Changes Modified Applied:128. Resolved Conflicts:0.
81,62 %: [Clie] TableChangesApplyingArgs: Applying Changes To Product.
81,62 %: [Clie] TableChangesApplyingSyncRowsArgs: Applying [Product] batch rows. State:Modified. Count:295
83,72 %: [Clie] TableChangesBatchAppliedArgs: [Product] [Modified] Applied:(295) Total:(1226/3514).
83,72 %: [Clie] TableChangesAppliedArgs: [Product] Changes Modified Applied:295. Resolved Conflicts:0.
83,72 %: [Clie] TableChangesApplyingArgs: Applying Changes To Address.
83,72 %: [Clie] TableChangesApplyingSyncRowsArgs: Applying [Address] batch rows. State:Modified. Count:450
86,92 %: [Clie] TableChangesBatchAppliedArgs: [Address] [Modified] Applied:(450) Total:(1676/3514).
86,92 %: [Clie] TableChangesAppliedArgs: [Address] Changes Modified Applied:450. Resolved Conflicts:0.
86,92 %: [Clie] TableChangesApplyingArgs: Applying Changes To Customer.
86,92 %: [Clie] TableChangesApplyingSyncRowsArgs: Applying [Customer] batch rows. State:Modified. Count:847
92,95 %: [Clie] TableChangesBatchAppliedArgs: [Customer] [Modified] Applied:(847) Total:(2523/3514).
92,95 %: [Clie] TableChangesAppliedArgs: [Customer] Changes Modified Applied:847. Resolved Conflicts:0.
92,95 %: [Clie] TableChangesApplyingArgs: Applying Changes To CustomerAddress.
92,95 %: [Clie] TableChangesApplyingSyncRowsArgs: Applying [CustomerAddress] batch rows. State:Modified. Count:417
95,92 %: [Clie] TableChangesBatchAppliedArgs: [CustomerAddress] [Modified] Applied:(417) Total:(2940/3514).
95,92 %: [Clie] TableChangesAppliedArgs: [CustomerAddress] Changes Modified Applied:417. Resolved Conflicts:0.
95,92 %: [Clie] TableChangesApplyingArgs: Applying Changes To SalesOrderHeader.
95,92 %: [Clie] TableChangesApplyingSyncRowsArgs: Applying [SalesOrderHeader] batch rows. State:Modified. Count:32
96,14 %: [Clie] TableChangesBatchAppliedArgs: [SalesOrderHeader] [Modified] Applied:(32) Total:(2972/3514).
96,14 %: [Clie] TableChangesAppliedArgs: [SalesOrderHeader] Changes Modified Applied:32. Resolved Conflicts:0.
96,14 %: [Clie] TableChangesApplyingArgs: Applying Changes To SalesOrderDetail.
96,14 %: [Clie] TableChangesApplyingSyncRowsArgs: Applying [SalesOrderDetail] batch rows. State:Modified. Count:542
100,00 %: [Clie] TableChangesBatchAppliedArgs: [SalesOrderDetail] [Modified] Applied:(542) Total:(3514/3514).
100,00 %: [Clie] TableChangesAppliedArgs: [SalesOrderDetail] Changes Modified Applied:542. Resolved Conflicts:0.
100,00 %: [Clie] TableChangesApplyingArgs: Applying Changes To SalesOrderDetail.
100,00 %: [Clie] TableChangesApplyingSyncRowsArgs: Applying [SalesOrderDetail] batch rows. State:Deleted. Count:0
100,00 %: [Clie] TableChangesApplyingArgs: Applying Changes To SalesOrderHeader.
100,00 %: [Clie] TableChangesApplyingSyncRowsArgs: Applying [SalesOrderHeader] batch rows. State:Deleted. Count:0
100,00 %: [Clie] TableChangesApplyingArgs: Applying Changes To CustomerAddress.
100,00 %: [Clie] TableChangesApplyingSyncRowsArgs: Applying [CustomerAddress] batch rows. State:Deleted. Count:0
100,00 %: [Clie] TableChangesApplyingArgs: Applying Changes To Customer.
100,00 %: [Clie] TableChangesApplyingSyncRowsArgs: Applying [Customer] batch rows. State:Deleted. Count:0
100,00 %: [Clie] TableChangesApplyingArgs: Applying Changes To Address.
100,00 %: [Clie] TableChangesApplyingSyncRowsArgs: Applying [Address] batch rows. State:Deleted. Count:0
100,00 %: [Clie] TableChangesApplyingArgs: Applying Changes To Product.
100,00 %: [Clie] TableChangesApplyingSyncRowsArgs: Applying [Product] batch rows. State:Deleted. Count:0
100,00 %: [Clie] TableChangesApplyingArgs: Applying Changes To ProductModel.
100,00 %: [Clie] TableChangesApplyingSyncRowsArgs: Applying [ProductModel] batch rows. State:Deleted. Count:0
100,00 %: [Clie] TableChangesApplyingArgs: Applying Changes To ProductCategory.
100,00 %: [Clie] TableChangesApplyingSyncRowsArgs: Applying [ProductCategory] batch rows. State:Deleted. Count:0
100,00 %: [Clie] TableChangesApplyingArgs: Applying Changes To ProductDescription.
100,00 %: [Clie] TableChangesApplyingSyncRowsArgs: Applying [ProductDescription] batch rows. State:Deleted. Count:0
100,00 %: [Clie] DatabaseChangesAppliedArgs: [Total] Applied:3514. Conflicts:0.
100,00 %: [Clie] ClientScopeInfoLoadingArgs: [Client] Client Scope Table Loading.
100,00 %: [Clie] ClientScopeInfoLoadedArgs: [Client] [DefaultScope] [Version 0.9.5] Last sync:17/07/2022 20:06:57 Last sync duration:0:0:2.172.
100,00 %: [Clie] MetadataCleaningArgs: Cleaning Metadatas.
100,00 %: [Clie] MetadataCleanedArgs: Tables Cleaned:0. Rows Cleaned:0.
100,00 %: [Clie] ScopeSavingArgs: [Client] Scope Table [Client] Saving.
100,00 %: [Clie] ScopeSavedArgs: [Client] Scope Table [Client] Saved.
100,00 %: [Clie] SessionEndArgs: [Client] Session Ends. Id:f62adec4-21a7-4a35-b86e-d3d7d52bc590. Scope name:DefaultScope.
Synchronization done.
Total changes uploaded: 0
Total changes downloaded: 3514
Total changes applied: 3514
Total resolved conflicts: 0
Total duration :00.00:00.509
Sync Ended. Press a key to start again, or Escapte to end