locked
SyncProgress event does not work correctly when batching sync data RRS feed

  • Question

  • Since my last posting failed to elicit a response, let me be more blunt.

    I don’t think the SyncProgress event associated with the DbSyncProvider is providing correct information when sync data is being batched.

    My sync application is based on the WebAppDemo that uses a WCF service to provide data to the service side DbSyncProvider via a proxy object. This application also includes batching. The sync framework code is pretty much straight out of the demo application.

    What I am attempting to do is use the SyncProgress event to update a progress bar, which should not be too difficult since the SyncProgress event provides counts of how many records it has to sync and how many it has actually done. Originally, I only planned to update one progress bar with overall sync progress, but I added a second progress bar to update individual table progress because the sync progress update was not behaving correctly.

    My observation is this: when the sync is small enough that it does not require batching then the counts in the SyncProgress event are correct and everything looks fine. However, when the sync is batched the total counts become incorrect and are no longer usable for status updates.

    I added an event logging capability to my application and had it output counts from the SyncProgress event and log when the BatchApplied event is occurring. Here are the raw counts from the event:

    NOTE:

    The ScopeProgress event is outputting TotalChangesApplied, TotalChangesFailed, TotalChangesPending, and TotalChanges.

    The TableProgress event is outputting TableName, ChangesApplied, ChangesFailed, ChangesPending, TotalChanges, Deletes, Inserts, and Updates.

    JUST BEFORE THE BatchApplied Event:

    ScopeProgress--[Changes applied = 8839, Changes Failed = 0, Changes Pending = 0, Total Changes = 8839]
    
    TableProgress--[ItemCategory: Applied = 88, failed = 0, pending = 0, total = 88, deletes = 0, inserts = 88, updates = 0]
    TableProgress--Manual: Applied = 76, failed = 0, pending = 0, total = 76, deletes = 0, inserts = 76, updates = 0]
    TableProgress-- [Part: Applied = 5623, failed = 0, pending = 0, total = 5623, deletes = 0, inserts = 5623, updates = 0]
    TableProgress--PartKit: Applied = 194, failed = 0, pending = 0, total = 194, deletes = 0, inserts = 194, updates = 0]
    TableProgress--Item: Applied = 378, failed = 0, pending = 0, total = 378, deletes = 0, inserts = 378, updates = 0]
    TableProgress-- [ItemLifeCycle: Applied = 0, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]
    TableProgress--ItemManual: Applied = 17, failed = 0, pending = 0, total = 17, deletes = 0, inserts = 17, updates = 0]
    TableProgress--ItemPart: Applied = 2463, failed = 0, pending = 0, total = 2463, deletes = 0, inserts = 2463, updates = 0]
    TableProgress--PMPartKit: Applied = 0, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]
    TableProgress--PMTask: Applied = 0, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]
    TableProgress--PM: Applied = 0, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]
    TableProgress--PartLifeCycle: Applied = 0, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]
    TableProgress--PartKitPart: Applied = 0, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]
    TableProgress--ItemPartKit: Applied = 0, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]
    BatchApplied Event Received
    ScopeProgress--[Changes applied = 8840, Changes Failed = 0, Changes Pending = 0, Total Changes = 8839]
    TableProgress--ItemCategory: Applied = 88, failed = 0, pending = 0, total = 88, deletes = 0, inserts = 88, updates = 0]
    TableProgress--Manual: Applied = 76, failed = 0, pending = 0, total = 76, deletes = 0, inserts = 76, updates = 0]
    TableProgress--Part: Applied = 5623, failed = 0, pending = 0, total = 5623, deletes = 0, inserts = 5623, updates = 0]
    TableProgress--PartKit: Applied = 194, failed = 0, pending = 0, total = 194, deletes = 0, inserts = 194, updates = 0]
    TableProgress--Item: Applied = 378, failed = 0, pending = 0, total = 378, deletes = 0, inserts = 378, updates = 0]
    TableProgress--ItemLifeCycle: Applied = 0, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]
    TableProgress--ItemManual: Applied = 17, failed = 0, pending = 0, total = 17, deletes = 0, inserts = 17, updates = 0]
    TableProgress--ItemPart: Applied = 2496, failed = 0, pending = 0, total = 2463, deletes = 0, inserts = 2463, updates = 0]
    TableProgress--[PMPartKit: Applied = 0, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]
    TableProgress--[PMTask: Applied = 0, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]
    TableProgress--PM: Applied = 0, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]
    TableProgress--[PartLifeCycle: Applied = 0, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]
    TableProgress--PartKitPart: Applied = 0, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]
    TableProgress--ItemPartKit: Applied = 0, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]

    Here are the totals from the end of the run:

    ScopeProgress--[Changes applied = 30342, Changes Failed = 0, Changes Pending = 0, Total Changes = 8839] 
    TableProgress--[ItemCategory: Applied = 88, failed = 0, pending = 0, total = 88, deletes = 0, inserts = 88, updates = 0]
    TableProgress--[Manual: Applied = 76, failed = 0, pending = 0, total = 76, deletes = 0, inserts = 76, updates = 0]
    TableProgress--[Part: Applied = 5623, failed = 0, pending = 0, total = 5623, deletes = 0, inserts = 5623, updates = 0]
    TableProgress--[PartKit: Applied = 194, failed = 0, pending = 0, total = 194, deletes = 0, inserts = 194, updates = 0]
    TableProgress--Item: Applied = 378, failed = 0, pending = 0, total = 378, deletes = 0, inserts = 378, updates = 0]
    TableProgress--[ItemLifeCycle: Applied = 0, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]
    TableProgress--[ItemManual: Applied = 17, failed = 0, pending = 0, total = 17, deletes = 0, inserts = 17, updates = 0]
    TableProgress--[ItemPart: Applied = 12970, failed = 0, pending = 0, total = 2463, deletes = 0, inserts = 2463, updates = 0]
    TableProgress--[PMPartKit: Applied = 196, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]
    TableProgress--[PMTask: Applied = 5090, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]
    TableProgress--[PM: Applied = 874, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]
    TableProgress--[PartLifeCycle: Applied = 3780, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]
    TableProgress--[PartKitPart: Applied = 864, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]
    TableProgress--[ItemPartKit: Applied = 192, failed = 0, pending = 0, total = 0, deletes = 0, inserts = 0, updates = 0]

    The sync operation actually worked fine. This was an initial database sync and I can compare the record insertions between the two databases and they are correct. However, it appears to me that the initial counts are either incorrect or are not being updated correctly when the data is being batched.

    For example, when the first “BatchApplied” event is received, the sync is in the process of syncing the ItemPart table. Even though we will eventually insert 12,970 records, the initial number of inserts never changed from 2463 (I am guessing that this is the number of records synced in the first batch). Data was also inserted for all of the tables listed after that, but at no point did their Table counts ever reflect a total change count other than zero.

    I also looked at the DbSyncContext object in the ApplyingChanges and ChangesApplied events to see if there was any way I could use the data from either of those events to correct the totals. Unfortunately, they are incorrect as well.

    This brings to my mind several possibilities:

    1. I am doing something wrong and either not setting the sync up correctly or am not looking at the right information.
    2. There is another event/interface/something I should be using to get better estimates on the amount of data that is going to be synced. I could count batch files processed, but not all of our syncs will be batched.
    3. The initial table totals are being set up incorrectly. For example, for the ItemPart table the number of Inserts is set to 2463 instead of the 12,970 records it is actually going to do.
    4. The table totals are not being updated correctly per batch. It would be fine to say that we only synced 2463 ItemPart records in the first batch if subsequent batches would simply tell me how many records are included in that batch so I could adjust my overall total record count.

    As an alternative, is there some other method I could call to get estimates of how much data is about to be synced? I wouldn’t mind if the counts were a little off since I am just trying to convey to the application user that their sync operation is currently running and making steady progress.

    Thursday, June 24, 2010 3:14 PM

Answers

  • Thank you for taking the time to reply.  I was beginning to wonder if the sync forums had turned into the WCF forums (I don't think I've ever received an actual answer to a question on the WCF forums).

    I followed the link you provided which lead to another link which indicates that this is a known issue with MSF.  I had already looked at some of the other DbSyncProvider events and found that either their version of this information is also inaccurate or it was not particularly easy (if possible) to parse the event context to determine what was really going on.

    So I solved the problem myself.  Now, when I start syncing a scope I know the tables that are included in the scope so I query the tracking table for each table to find Max(last_change_datetime) and send that over to the service along with the table name and the service then queries its version of the tracking table to see how many changes it has that occurred after that date.  It won't be entirely accurate, but it will be close enough to update a progress bar.  Right now, the MSF-based sync is running so much faster than our original sync that users won't notice any minor errors in progress tracking (which they also didn't have in our original sync).

    It would be nice if the sync progress event worked correctly, but I can deal with it for now.

     

    • Marked as answer by JuneT Wednesday, July 7, 2010 2:25 PM
    Monday, June 28, 2010 11:51 AM

All replies

  • Friday, June 25, 2010 3:36 PM
  • Thank you for taking the time to reply.  I was beginning to wonder if the sync forums had turned into the WCF forums (I don't think I've ever received an actual answer to a question on the WCF forums).

    I followed the link you provided which lead to another link which indicates that this is a known issue with MSF.  I had already looked at some of the other DbSyncProvider events and found that either their version of this information is also inaccurate or it was not particularly easy (if possible) to parse the event context to determine what was really going on.

    So I solved the problem myself.  Now, when I start syncing a scope I know the tables that are included in the scope so I query the tracking table for each table to find Max(last_change_datetime) and send that over to the service along with the table name and the service then queries its version of the tracking table to see how many changes it has that occurred after that date.  It won't be entirely accurate, but it will be close enough to update a progress bar.  Right now, the MSF-based sync is running so much faster than our original sync that users won't notice any minor errors in progress tracking (which they also didn't have in our original sync).

    It would be nice if the sync progress event worked correctly, but I can deal with it for now.

     

    • Marked as answer by JuneT Wednesday, July 7, 2010 2:25 PM
    Monday, June 28, 2010 11:51 AM