locked
Data continually being synced? RRS feed

  • Question

  • I have a situation where I am seeing data continually being synced between two database tables within a scope that contains multiple tables.  For testing, I have 2 peers with identical database definitions that have both been provisioned.  I load data into the host peer, connect the client peer, then sync.  The first time, no data is sent from the client to the host and all of the data is sent from the host to the client.  On subsequent syncs, there is repetitive data being sent from the host to the client and from the client to the host for some tables.

    On the tables when data is being re-sent, there are more than 75 rows.  This appears to be the result of some setting to break the data into chunks of 75 rows.  On the re-sent data, the host re-sends the first 75 rows to the client and the client re-sends the remaining rows back to the host.  In looking at the tracking table, it seems that the update_scope_local_id column is not getting set for the first 75 rows.  On the first 75 rows, the value is null and the remaining rows have an actual value.  If I manually set this column for the 75 rows, all works.  No data is re-sent on subsequent syncs.

    Details:

    First, we upload from the client to the host.

    Client log:

    VERBOSE, vshost, 18, 10/02/2012 13:00:39:512,       Executing Command: [SYS_USER_ROLE_selectchanges]
    VERBOSE, vshost, 18, 10/02/2012 13:00:39:513,          Parameter: @sync_min_timestamp Value: 0
    VERBOSE, vshost, 18, 10/02/2012 13:00:39:514,          Parameter: @sync_scope_local_id Value: 1
    VERBOSE, vshost, 18, 10/02/2012 13:00:39:515,          Parameter: @sync_scope_restore_count Value: 0
    VERBOSE, vshost, 18, 10/02/2012 13:00:39:515,          Parameter: @sync_update_peer_key Value: 1
    INFO   , vshost, 18, 10/02/2012 13:00:39:526,    RelationalSyncProvider.BatchedEnum: --- End Table "SYS_USER_ROLE" ---
    INFO   , vshost, 18, 10/02/2012 13:00:39:527, 
    VERBOSE, vshost, 18, 10/02/2012 13:00:39:527,       RelationalSyncProvider.BatchedEnum: Closing DataReader
    INFO   , vshost, 18, 10/02/2012 13:00:39:528,       RelationalSyncProvider.BatchedEnum: Finished enumerating adapter SYS_USER_ROLE
    
    INFO   , vshost, 18, 10/02/2012 13:00:39:529,       RelationalSyncProvider.BatchedEnum: Adding rows enumerated for adapter SYS_USER_ROLE to DataSet.
    VERBOSE, vshost, 18, 10/02/2012 13:00:39:529,       Checking to see if batch producer has table watermarks available from previous sync.
    VERBOSE, vshost, 18, 10/02/2012 13:00:39:530,       RelationalSyncProvider.BatchedEnum
    

    Host Log:

    INFO   , vshost, 9, 10/02/2012 13:00:39:896,    ----- Deletes for Table "SYS_USER_ROLE" -----
    VERBOSE, vshost, 9, 10/02/2012 13:00:39:897, 
    INFO   , vshost, 9, 10/02/2012 13:00:39:897,       0 Deletes Applied
    INFO   , vshost, 9, 10/02/2012 13:00:39:898,    --- End Deletes for Table "SYS_USER_ROLE" ---
    
    INFO   , vshost, 9, 10/02/2012 13:00:39:984,    ----- Inserts for Table "SYS_USER_ROLE" -----
    VERBOSE, vshost, 9, 10/02/2012 13:00:39:985, 
    INFO   , vshost, 9, 10/02/2012 13:00:39:986,       0 Inserts Applied
    INFO   , vshost, 9, 10/02/2012 13:00:39:986,    --- End Inserts for Table "SYS_USER_ROLE" ---
    

    Next we do a download from the host to the client.

    Host log:

    VERBOSE, vshost, 11, 10/02/2012 13:00:42:413, Executing Command: [SYS_USER_ROLE_selectchanges] VERBOSE, vshost, 11, 10/02/2012 13:00:42:414, Parameter: @sync_min_timestamp Value: 0 VERBOSE, vshost, 11, 10/02/2012 13:00:42:415, Parameter: @sync_scope_local_id Value: 1 VERBOSE, vshost, 11, 10/02/2012 13:00:42:415, Parameter: @sync_scope_restore_count Value: 0 VERBOSE, vshost, 11, 10/02/2012 13:00:42:417, Parameter: @sync_update_peer_key Value: 1 VERBOSE, vshost, 11, 10/02/2012 13:00:42:431, Insert for row with PK: SYS_USER_ROLE_ID = 68626d1b-7803-e211-b4e2-005056c00008 on ProForma2 VERBOSE, vshost, 11, 10/02/2012 13:00:42:432, UV: 0,95533 CV: 0,89427 VERBOSE, vshost, 11, 10/02/2012 13:00:42:433, RelationalSyncProvider.BatchedEnum: Memory data cache size after reading row: 25768 Bytes VERBOSE, vshost, 11, 10/02/2012 13:00:42:433, Insert for row with PK: SYS_USER_ROLE_ID = 69626d1b-7803-e211-b4e2-005056c00008 on ProForma2 VERBOSE, vshost, 11, 10/02/2012 13:00:42:434, UV: 0,95527 CV: 0,89475 VERBOSE, vshost, 11, 10/02/2012 13:00:42:435, RelationalSyncProvider.BatchedEnum: Memory data cache size after reading row: 25847 Bytes VERBOSE, vshost, 11, 10/02/2012 13:00:42:435, Insert for row with PK: SYS_USER_ROLE_ID = 6a626d1b-7803-e211-b4e2-005056c00008 on ProForma2 VERBOSE, vshost, 11, 10/02/2012 13:00:42:436, UV: 0,95521 CV: 0,89595 VERBOSE, vshost, 11, 10/02/2012 13:00:42:436, RelationalSyncProvider.BatchedEnum: Memory data cache size after reading row: 25926 Bytes VERBOSE, vshost, 11, 10/02/2012 13:00:42:437, Insert for row with PK: SYS_USER_ROLE_ID = 6b626d1b-7803-e211-b4e2-005056c00008 on ProForma2 VERBOSE, vshost, 11, 10/02/2012 13:00:42:438, UV: 0,95515 CV: 0,89788 VERBOSE, vshost, 11, 10/02/2012 13:00:42:438, RelationalSyncProvider.BatchedEnum: Memory data cache size after reading row: 26005 Bytes VERBOSE, vshost, 11, 10/02/2012 13:00:42:439, Insert for row with PK: SYS_USER_ROLE_ID = 6c626d1b-7803-e211-b4e2-005056c00008 on ProForma2 VERBOSE, vshost, 11, 10/02/2012 13:00:42:439, UV: 0,95497 CV: 0,90800 VERBOSE, vshost, 11, 10/02/2012 13:00:42:440, RelationalSyncProvider.BatchedEnum: Memory data cache size after reading row: 26084 Bytes VERBOSE, vshost, 11, 10/02/2012 13:00:42:441, Insert for row with PK: SYS_USER_ROLE_ID = 6d626d1b-7803-e211-b4e2-005056c00008 on ProForma2 VERBOSE, vshost, 11, 10/02/2012 13:00:42:441, UV: 0,95532 CV: 0,89430 VERBOSE, vshost, 11, 10/02/2012 13:00:42:442, RelationalSyncProvider.BatchedEnum: Memory data cache size after reading row: 26163 Bytes

    *** Data deleted to reduce the size ***

    VERBOSE, vshost, 11, 10/02/2012 13:00:42:564, Insert for row with PK: SYS_USER_ROLE_ID = 50ebbe5e-3503-e211-bff4-005056c00008 on ProForma2 VERBOSE, vshost, 11, 10/02/2012 13:00:42:565, UV: 0,95472 CV: 0,93161 VERBOSE, vshost, 11, 10/02/2012 13:00:42:565, RelationalSyncProvider.BatchedEnum: Memory data cache size after reading row: 31377 Bytes VERBOSE, vshost, 11, 10/02/2012 13:00:42:566, Insert for row with PK: SYS_USER_ROLE_ID = 51ebbe5e-3503-e211-bff4-005056c00008 on ProForma2 VERBOSE, vshost, 11, 10/02/2012 13:00:42:566, UV: 0,95466 CV: 0,93932 VERBOSE, vshost, 11, 10/02/2012 13:00:42:567, RelationalSyncProvider.BatchedEnum: Memory data cache size after reading row: 31456 Bytes VERBOSE, vshost, 11, 10/02/2012 13:00:42:567, Insert for row with PK: SYS_USER_ROLE_ID = 52ebbe5e-3503-e211-bff4-005056c00008 on ProForma2 VERBOSE, vshost, 11, 10/02/2012 13:00:42:568, UV: 0,95460 CV: 0,94776 VERBOSE, vshost, 11, 10/02/2012 13:00:42:568, RelationalSyncProvider.BatchedEnum: Memory data cache size after reading row: 31535 Bytes VERBOSE, vshost, 11, 10/02/2012 13:00:42:569, Insert for row with PK: SYS_USER_ROLE_ID = 53ebbe5e-3503-e211-bff4-005056c00008 on ProForma2 VERBOSE, vshost, 11, 10/02/2012 13:00:42:570, UV: 0,95529 CV: 0,89451 VERBOSE, vshost, 11, 10/02/2012 13:00:42:570, RelationalSyncProvider.BatchedEnum: Memory data cache size after reading row: 31614 Bytes VERBOSE, vshost, 11, 10/02/2012 13:00:42:571, Insert for row with PK: SYS_USER_ROLE_ID = 8002c87e-3b03-e211-bff4-005056c00008 on ProForma2 VERBOSE, vshost, 11, 10/02/2012 13:00:42:571, UV: 0,95523 CV: 0,89547 VERBOSE, vshost, 11, 10/02/2012 13:00:42:572, RelationalSyncProvider.BatchedEnum: Memory data cache size after reading row: 31693 Bytes VERBOSE, vshost, 11, 10/02/2012 13:00:42:573, Insert for row with PK: SYS_USER_ROLE_ID = 8102c87e-3b03-e211-bff4-005056c00008 on ProForma2 VERBOSE, vshost, 11, 10/02/2012 13:00:42:573, UV: 0,95517 CV: 0,89716 VERBOSE, vshost, 11, 10/02/2012 13:00:42:574, RelationalSyncProvider.BatchedEnum: Memory data cache size after reading row: 31772 Bytes VERBOSE, vshost, 11, 10/02/2012 13:00:42:575, Insert for row with PK: SYS_USER_ROLE_ID = 8202c87e-3b03-e211-bff4-005056c00008 on ProForma2 VERBOSE, vshost, 11, 10/02/2012 13:00:42:575, UV: 0,95511 CV: 0,89957 VERBOSE, vshost, 11, 10/02/2012 13:00:42:577, RelationalSyncProvider.BatchedEnum: Memory data cache size after reading row: 31851 Bytes INFO , vshost, 11, 10/02/2012 13:00:42:577, RelationalSyncProvider.BatchedEnum: --- End Table "SYS_USER_ROLE" --- INFO , vshost, 11, 10/02/2012 13:00:42:578, VERBOSE, vshost, 11, 10/02/2012 13:00:42:579, RelationalSyncProvider.BatchedEnum: Closing DataReader INFO , vshost, 11, 10/02/2012 13:00:42:579, RelationalSyncProvider.BatchedEnum: Finished enumerating adapter SYS_USER_ROLE INFO , vshost, 11, 10/02/2012 13:00:42:580, RelationalSyncProvider.BatchedEnum: Adding rows enumerated for adapter SYS_USER_ROLE to DataSet. VERBOSE, vshost, 11, 10/02/2012 13:00:42:580, SyncBatchProducer: Read last row's Sync_row_timestamp value for table SYS_USER_ROLE as 95511. VERBOSE, vshost, 11, 10/02/2012 13:00:42:581, Checking to see if batch producer has table watermarks available from previous sync. VERBOSE, vshost, 11, 10/02/2012 13:00:42:582, RelationalSyncProvider.BatchedEnum

    Client log:

    INFO , vshost, 15, 10/02/2012 13:00:42:908, ----- Deletes for Table "SYS_USER_ROLE" ----- VERBOSE, vshost, 15, 10/02/2012 13:00:42:909, INFO , vshost, 15, 10/02/2012 13:00:42:910, 0 Deletes Applied INFO , vshost, 15, 10/02/2012 13:00:42:910, --- End Deletes for Table "SYS_USER_ROLE" --- INFO , vshost, 15, 10/02/2012 13:00:44:475, ----- Inserts for Table "SYS_USER_ROLE" ----- VERBOSE, vshost, 15, 10/02/2012 13:00:44:489, Executing Command: [sync_SYS_USER_ROLE_bulkinsert] VERBOSE, vshost, 15, 10/02/2012 13:00:44:490, Parameter: @sync_min_timestamp Value: 6000 VERBOSE, vshost, 15, 10/02/2012 13:00:44:491, Parameter: @sync_scope_local_id Value: 1 VERBOSE, vshost, 15, 10/02/2012 13:00:44:491, Parameter: @changeTable Value: SYS_USER_ROLE INFO , vshost, 15, 10/02/2012 13:00:44:547, Applied 75 of 75 rows with bulk command BulkInsertCommand VERBOSE, vshost, 15, 10/02/2012 13:00:44:548, Executing Command: [sync_SYS_USER_ROLE_bulkinsert] VERBOSE, vshost, 15, 10/02/2012 13:00:44:549, Parameter: @sync_min_timestamp Value: 6000 VERBOSE, vshost, 15, 10/02/2012 13:00:44:549, Parameter: @sync_scope_local_id Value: 1 VERBOSE, vshost, 15, 10/02/2012 13:00:44:550, Parameter: @changeTable Value: SYS_USER_ROLE INFO , vshost, 15, 10/02/2012 13:00:44:579, Applied 3 of 3 rows with bulk command BulkInsertCommand VERBOSE, vshost, 15, 10/02/2012 13:00:44:581, Inserted row with PK using bulk apply: SYS_USER_ROLE_ID="68626d1b-7803-e211-b4e2-005056c00008" on ProForma VERBOSE, vshost, 15, 10/02/2012 13:00:44:581, Inserted row with PK using bulk apply: SYS_USER_ROLE_ID="69626d1b-7803-e211-b4e2-005056c00008" on ProForma VERBOSE, vshost, 15, 10/02/2012 13:00:44:582, Inserted row with PK using bulk apply: SYS_USER_ROLE_ID="6a626d1b-7803-e211-b4e2-005056c00008" on ProForma VERBOSE, vshost, 15, 10/02/2012 13:00:44:583, Inserted row with PK using bulk apply: SYS_USER_ROLE_ID="6b626d1b-7803-e211-b4e2-005056c00008" on ProForma

    *** Data deleted to reduce the size ***

    VERBOSE, vshost, 15, 10/02/2012 13:00:44:634, Inserted row with PK using bulk apply: SYS_USER_ROLE_ID="50ebbe5e-3503-e211-bff4-005056c00008" on ProForma VERBOSE, vshost, 15, 10/02/2012 13:00:44:634, Inserted row with PK using bulk apply: SYS_USER_ROLE_ID="51ebbe5e-3503-e211-bff4-005056c00008" on ProForma VERBOSE, vshost, 15, 10/02/2012 13:00:44:635, Inserted row with PK using bulk apply: SYS_USER_ROLE_ID="52ebbe5e-3503-e211-bff4-005056c00008" on ProForma VERBOSE, vshost, 15, 10/02/2012 13:00:44:636, Inserted row with PK using bulk apply: SYS_USER_ROLE_ID="53ebbe5e-3503-e211-bff4-005056c00008" on ProForma VERBOSE, vshost, 15, 10/02/2012 13:00:44:636, Inserted row with PK using bulk apply: SYS_USER_ROLE_ID="8002c87e-3b03-e211-bff4-005056c00008" on ProForma VERBOSE, vshost, 15, 10/02/2012 13:00:44:637, Inserted row with PK using bulk apply: SYS_USER_ROLE_ID="8102c87e-3b03-e211-bff4-005056c00008" on ProForma VERBOSE, vshost, 15, 10/02/2012 13:00:44:638, Inserted row with PK using bulk apply: SYS_USER_ROLE_ID="8202c87e-3b03-e211-bff4-005056c00008" on ProForma VERBOSE, vshost, 15, 10/02/2012 13:00:44:638, INFO , vshost, 15, 10/02/2012 13:00:44:639, 78 Inserts Applied INFO , vshost, 15, 10/02/2012 13:00:44:639, --- End Inserts for Table "SYS_USER_ROLE" ---

    This is what is in the tracking table for this table:

    SYS_USER_ROLE_ID update_scope_local_id scope_update_peer_key scope_update_peer_timestamp local_update_peer_key local_update_peer_timestamp create_scope_local_id scope_create_peer_key scope_create_peer_timestamp local_create_peer_key local_create_peer_timestamp sync_row_is_tombstone restore_timestamp last_change_datetime
    68626D1B-7803-E211-B4E2-005056C00008 NULL 1 95533 0 0x0000000000002096 1 1 89427 0 6850 0 NULL 2012-10-02 09:15:54.910
    69626D1B-7803-E211-B4E2-005056C00008 NULL 1 95527 0 0x0000000000002090 1 1 89475 0 6850 0 NULL 2012-10-02 09:15:54.910

    ** Data deleted to reduce the size ***

    50EBBE5E-3503-E211-BFF4-005056C00008 NULL 1 95472 0 0x000000000000205A 1 1 93161 0 6850 0 NULL 2012-10-02 09:15:54.910
    51EBBE5E-3503-E211-BFF4-005056C00008 NULL 1 95466 0 0x0000000000002054 1 1 93932 0 6850 0 NULL 2012-10-02 09:15:54.910
    52EBBE5E-3503-E211-BFF4-005056C00008 NULL 1 95460 0 0x000000000000204E 1 1 94776 0 6850 0 NULL 2012-10-02 09:15:54.910
    53EBBE5E-3503-E211-BFF4-005056C00008 NULL 1 95529 0 0x0000000000002092 1 1 89451 0 6850 0 NULL 2012-10-02 09:15:54.910
    8002C87E-3B03-E211-BFF4-005056C00008 1 1 234970 0 0x000000000000209A 1 1 89547 0 7151 0 NULL 2012-10-02 09:15:54.913
    8102C87E-3B03-E211-BFF4-005056C00008 1 1 234969 0 0x000000000000209B 1 1 89716 0 7151 0 NULL 2012-10-02 09:15:54.913
    8202C87E-3B03-E211-BFF4-005056C00008 1 1 234968 0 0x000000000000209C 1 1 89957 0 7151 0 NULL 2012-10-02 09:15:54.9131 89957 0 7151 0 NULL 2012-10-02 09:15:54.913

    The nulls in the 2nd column seem to be causing the data to be re-synced.  If I change the nulls to 1 like is present in the last few rows, everything works correctly.  Any suggestions how to correct this?

    Tuesday, October 2, 2012 2:16 PM

All replies

  • do you have batching enabled? are you using WCF?
    Wednesday, October 3, 2012 2:09 AM
  • Batching is enabled with a batch size of 2 GB or so.  We are using WCF.
    Wednesday, October 3, 2012 11:14 AM