Asked by:
Bulk procedures not being called on client upload?

Question
-
Hi, sorry but I have another newbie question. I have provisioned a database both locally (SQL 2008) and on a Sql Azure server.
When provisioning my scope, I checked the enable bulk procedures box, and can see that the 'bulk artifacts' have been created.
However, when I send a large set of updated entities in an upload request from the client, the regular _update sps are being fired and not the _bulkupdate ones.
Because of this, it is especially slow with an Azure Web Role/Sql Azure database - (4 minutes to process the upload request for 16,000 rows)
The table in question has dynamic filter parameters and so is based on a template.
I hope I have my wording (and facts) correct here, apologies if the answer is obvious, but am I missing something?
Thanks.
Wednesday, March 6, 2013 5:24 PM
All replies
-
can you check your ApplyChangeFailed events if you're running into conflicts?
you don't actually even have to set enable bulk procedures, since it will automatically be enabled for SQL 2008 and above.
Thursday, March 7, 2013 12:07 AM -
Hi June thanks for your help,
We have set up our service using the code generation tools in the toolkit and deployed as an asp.net service. Apart from that, our knowledge is pretty limited (server side). Sorry if this is obvious, but how can I hook into this event using the code generated by the toolkit? My understanding is that this is an event of the dbsyncprovider (sqlsyncprovider) and I cannot see the underlying provider exposed anywhere.
Do you think that the row-by-row updating is being called (instead of the bulk update) because of a conflict? How does syncfx determine whether to use bulk sps or the 'normal' sp?
Your help is greatly appreciated. :)
Thursday, March 7, 2013 10:18 AM -
as i have mentioned, by default it will use bulk procedures for SQL 2008 and above unless you explicitly specify not to use it.
if there's a conflict, a conflict is resolved row by row, so afaik, it should use the non-bulk procedures.
if you're using the Toolkit, then the SQLSyncProvider is well hidden in the service.
you can try using the SyncConflictInterceptor on the service side, just look it up on the documentation.
does your sync report conflicts occurring?
Thursday, March 7, 2013 10:55 AM -
Hi June,
Thanks for that, I have added an interceptor to handle conflicts, the code never gets reached (with my 4000 updated 'DiaryCall' entities).
I have added a SyncRequestInterceptor and can see the fully populated collection of IOfflineEntities (my DiaryCall objects) in the IncomingChanges property.
One thing I didn't mention was that I am using the express version of Sql 2008 and the web version of Sql Azure. Could this be a factor?
You also mention that it uses the bulk procedures unless you explicitly specify not to use it. How do you tell it not to use the bulk procedures? Do you mean via the xml configuration file used to provision the database? Or is it something you switch on / off at the 'sync session' level?
Thanks.
Thursday, March 7, 2013 11:43 AM -
afaik, if Bulk procedures are specified to be created (which is the default), they will always be used.
can you query the table scope_config, and the open the column config_data. that column should show you an XML of the scope configuration, do you see the bulk procedure names there?
Thursday, March 7, 2013 12:45 PM -
Hi June,
Yes can see the bulk sp names in the config xml. The sps exist, and the user defined table types also exist.
Here is an example of config for the scope in question - notice that IsTemplate="true" on the scope and there is a filter clause with a sub-select against the table in question (DiaryCall) - could this be the cause of the problem?
Many thanks.
<SqlSyncProviderScopeConfiguration xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:xsd="http://www.w3.org/2001/XMLSchema" IsTemplate="true">
<Adapter Name="[CustomerDomain]" GlobalName="[CustomerDomain]" TrackingTable="[CustomerDomain_tracking]" SelChngProc="[CustomerDomain_selectchanges]" SelRowProc="[CustomerDomain_selectrow]" InsProc="[CustomerDomain_insert]" UpdProc="[CustomerDomain_update]" DelProc="[CustomerDomain_delete]" InsMetaProc="[CustomerDomain_insertmetadata]" UpdMetaProc="[CustomerDomain_updatemetadata]" DelMetaProc="[CustomerDomain_deletemetadata]" BulkTableType="[CustomerDomain_BulkType]" BulkInsProc="[CustomerDomain_bulkinsert]" BulkUpdProc="[CustomerDomain_bulkupdate]" BulkDelProc="[CustomerDomain_bulkdelete]" InsTrig="[CustomerDomain_insert_trigger]" UpdTrig="[CustomerDomain_update_trigger]" DelTrig="[CustomerDomain_delete_trigger]">
<Col name="UID" type="uniqueidentifier" param="@P_1" pk="true" />
<Col name="CustomerCode" type="nvarchar" size="13" null="true" param="@P_2" />
<Col name="DomainCode" type="nvarchar" size="13" null="true" param="@P_3" />
<FilterClause />
</Adapter>
<Adapter Name="[DiaryCall]" GlobalName="[DiaryCall]" TrackingTable="[DiaryCall_tracking]" SelChngProc="[DiaryCall_selectchanges]" SelRowProc="[DiaryCall_selectrow]" InsProc="[DiaryCall_insert]" UpdProc="[DiaryCall_update]" DelProc="[DiaryCall_delete]" InsMetaProc="[DiaryCall_insertmetadata]" UpdMetaProc="[DiaryCall_updatemetadata]" DelMetaProc="[DiaryCall_deletemetadata]" BulkTableType="[DiaryCall_BulkType]" BulkInsProc="[DiaryCall_bulkinsert]" BulkUpdProc="[DiaryCall_bulkupdate]" BulkDelProc="[DiaryCall_bulkdelete]" InsTrig="[DiaryCall_insert_trigger]" UpdTrig="[DiaryCall_update_trigger]" DelTrig="[DiaryCall_delete_trigger]">
<Col name="UID" type="uniqueidentifier" param="@P_1" pk="true" />
<Col name="CallDateTime" type="datetime" null="true" param="@P_2" />
<Col name="CallDurationMins" type="smallint" null="true" param="@P_3" />
<Col name="CustomerCode" type="nvarchar" size="13" null="true" param="@P_4" />
<Col name="CallStatus" type="nvarchar" size="1" null="true" param="@P_5" />
<Col name="CallNoteShort" type="nvarchar" size="255" null="true" param="@P_6" />
<FilterParam name="@DomainCode" />
<FilterClause>[side].CustomerCode in (select customercode from customerdomain where domaincode=@DomainCode)</FilterClause>
<FilterCol>CustomerCode</FilterCol>
</Adapter>
<Adapter Name="[DiaryNote]" GlobalName="[DiaryNote]" TrackingTable="[DiaryNote_tracking]" SelChngProc="[DiaryNote_selectchanges]" SelRowProc="[DiaryNote_selectrow]" InsProc="[DiaryNote_insert]" UpdProc="[DiaryNote_update]" DelProc="[DiaryNote_delete]" InsMetaProc="[DiaryNote_insertmetadata]" UpdMetaProc="[DiaryNote_updatemetadata]" DelMetaProc="[DiaryNote_deletemetadata]" BulkTableType="[DiaryNote_BulkType]" BulkInsProc="[DiaryNote_bulkinsert]" BulkUpdProc="[DiaryNote_bulkupdate]" BulkDelProc="[DiaryNote_bulkdelete]" InsTrig="[DiaryNote_insert_trigger]" UpdTrig="[DiaryNote_update_trigger]" DelTrig="[DiaryNote_delete_trigger]">
<Col name="UID" type="uniqueidentifier" param="@P_1" pk="true" />
<Col name="NoteDateTime" type="datetime" param="@P_2" />
<Col name="NoteHasTime" type="bit" param="@P_3" />
<Col name="NoteDurationMins" type="smallint" param="@P_4" />
<Col name="NoteTypeCode" type="nvarchar" size="13" param="@P_5" />
<Col name="NoteText" type="nvarchar" size="255" null="true" param="@P_6" />
<Col name="NoteLocationTown" type="nvarchar" size="100" null="true" param="@P_7" />
<Col name="NoteLocationPostCode" type="nvarchar" size="100" null="true" param="@P_8" />
<Col name="NoteUserCode" type="nvarchar" size="13" param="@P_9" />
<FilterParam name="@DomainCode" />
<FilterClause>[side].NoteUserCode in (select usercode from userdomain where domaincode=@DomainCode)</FilterClause>
<FilterCol>NoteUserCode</FilterCol>
</Adapter>
<Adapter Name="[DiaryNoteType]" GlobalName="[DiaryNoteType]" TrackingTable="[DiaryNoteType_tracking]" SelChngProc="[DiaryNoteType_selectchanges]" SelRowProc="[DiaryNoteType_selectrow]" InsProc="[DiaryNoteType_insert]" UpdProc="[DiaryNoteType_update]" DelProc="[DiaryNoteType_delete]" InsMetaProc="[DiaryNoteType_insertmetadata]" UpdMetaProc="[DiaryNoteType_updatemetadata]" DelMetaProc="[DiaryNoteType_deletemetadata]" BulkTableType="[DiaryNoteType_BulkType]" BulkInsProc="[DiaryNoteType_bulkinsert]" BulkUpdProc="[DiaryNoteType_bulkupdate]" BulkDelProc="[DiaryNoteType_bulkdelete]" InsTrig="[DiaryNoteType_insert_trigger]" UpdTrig="[DiaryNoteType_update_trigger]" DelTrig="[DiaryNoteType_delete_trigger]">
<Col name="NoteTypeCode" type="nvarchar" size="13" param="@P_1" pk="true" />
<Col name="NoteTypeText" type="nvarchar" size="100" param="@P_2" />
<FilterClause />
</Adapter>
<Adapter Name="[Customer]" GlobalName="[Customer]" TrackingTable="[Customer_tracking]" SelChngProc="[Customer_selectchanges]" SelRowProc="[Customer_selectrow]" InsProc="[Customer_insert]" UpdProc="[Customer_update]" DelProc="[Customer_delete]" InsMetaProc="[Customer_insertmetadata]" UpdMetaProc="[Customer_updatemetadata]" DelMetaProc="[Customer_deletemetadata]" BulkTableType="[Customer_BulkType]" BulkInsProc="[Customer_bulkinsert]" BulkUpdProc="[Customer_bulkupdate]" BulkDelProc="[Customer_bulkdelete]" InsTrig="[Customer_insert_trigger]" UpdTrig="[Customer_update_trigger]" DelTrig="[Customer_delete_trigger]">
<Col name="CustomerCode" type="nvarchar" size="13" param="@P_1" pk="true" />
<Col name="CustomerName" type="nvarchar" size="100" null="true" param="@P_2" />
<Col name="AddressLine1" type="nvarchar" size="100" null="true" param="@P_3" />
<Col name="AddressLine2" type="nvarchar" size="100" null="true" param="@P_4" />
<Col name="AddressLine3" type="nvarchar" size="100" null="true" param="@P_5" />
<Col name="AddressTown" type="nvarchar" size="100" null="true" param="@P_6" />
<Col name="AddressCounty" type="nvarchar" size="100" null="true" param="@P_7" />
<Col name="AddressPostCode" type="nvarchar" size="100" null="true" param="@P_8" />
<Col name="Telephone1" type="nvarchar" size="100" null="true" param="@P_9" />
<Col name="Telephone2" type="nvarchar" size="100" null="true" param="@P_10" />
<Col name="CallFrequencyWeeks" type="smallint" null="true" param="@P_11" />
<Col name="MasterCode" type="nvarchar" size="100" null="true" param="@P_12" />
<Col name="MasterOwnerCode" type="nvarchar" size="100" null="true" param="@P_13" />
<Col name="BuyingStatusCode" type="nvarchar" size="1" null="true" param="@P_14" />
<FilterParam name="@DomainCode" />
<FilterClause>[side].CustomerCode in (select customercode from customerdomain where domaincode=@DomainCode)</FilterClause>
<FilterCol>CustomerCode</FilterCol>
</Adapter>
</SqlSyncProviderScopeConfiguration>
Thursday, March 7, 2013 2:23 PM -
the filter is only used when selecting changes and the template flag should not have any effect on bulk procedures as well... l'll have a look if there's something different the way the sync toolkit does things...
- Edited by JuneT Thursday, March 7, 2013 2:59 PM
Thursday, March 7, 2013 2:58 PM -
Hi June, thanks again for your help looking into this. Did you find anything?
I have tried tracing the service and also running sql trace to see if I can gain any clues as to what is happening.
My next step is going to be create a simple single table database with no filtering - fill it with a sizeable set of data, and provision it again for bulk apply. I'll then try the mass client side entity update once again to see if anything changes in the way the updates are performed on the server.
Thanks.
Friday, March 8, 2013 12:53 PM -
were you able to get a Sync Fx trace running? I didn't find anything that stands out in the code to suggest that it should use the non-bulk approach.Saturday, March 9, 2013 2:17 AM
-
Hi JuneT, yes I managed to do a trace and I've also used Sql Profiler to back up what I've found.
I've just got back to this today after being side tracked for the last week :)
What I have found is that a set of insert changes from the client - will get applied with the _bulkinsert procedure as expected. However updated rows are also passed to the same sp (tablename_bulkinsert) and then do not get applied because the merge statement in the sp does not handle MATCHED rows, only NOT MATCHED (as expected I guess).
However, the tablename_bulkupdate sp never seems to get called and (for me at least) updates from the client are always applied with the single row tablename_update sp being called.
Here is a trace example of this happening.... (20 updated rows)
INFO , WebDev.WebServer40, 41, 03/19/2013 11:47:56:306, ----- Inserts for Table "DiaryCall" -----
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:307, Executing Command: [DiaryCall_bulkinsert]
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:307, Parameter: @sync_min_timestamp Value: 304583
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:307, Parameter: @sync_scope_local_id Value: 256
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:307, Parameter: @changeTable Value: DiaryCall
INFO , WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Applied 0 of 20 rows with bulk command BulkInsertCommand
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Failed to insert row with PK using bulk apply: UID="00197828-1d55-4e6c-bcad-da335a478c65" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Failed to insert row with PK using bulk apply: UID="002641eb-6d26-4597-b767-cf9b8e452e81" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Failed to insert row with PK using bulk apply: UID="002fce14-d580-40df-b4ed-9350e47d4a06" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Failed to insert row with PK using bulk apply: UID="0062b542-e5c5-4775-bbd4-ca46a78c14ee" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Failed to insert row with PK using bulk apply: UID="007d3df7-8656-451c-b073-22836fae1b86" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Failed to insert row with PK using bulk apply: UID="00882599-8d1c-4303-b44d-d64ae9aa6280" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Failed to insert row with PK using bulk apply: UID="0088a94c-3ed6-42db-89eb-ec83a0f2a041" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Failed to insert row with PK using bulk apply: UID="00a8cccc-7ca4-4372-9ec4-bfb09be11bc8" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Failed to insert row with PK using bulk apply: UID="00b9d242-06a3-46cf-b2d8-776fd2b0fe2e" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Failed to insert row with PK using bulk apply: UID="00ebaf7c-185e-42fa-afef-559707809a43" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Failed to insert row with PK using bulk apply: UID="00eff755-b938-4d99-a248-bcb2315efcb1" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Failed to insert row with PK using bulk apply: UID="00f11756-be52-470c-8487-51bd4d7bc252" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Failed to insert row with PK using bulk apply: UID="011fb854-06ef-4587-9585-54c346178190" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Failed to insert row with PK using bulk apply: UID="01584f70-07db-4f64-8fe8-7a61e8b8cf59" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Failed to insert row with PK using bulk apply: UID="01665386-21e3-43de-9e75-7486e0f486e9" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Failed to insert row with PK using bulk apply: UID="016e5dcf-caed-4cef-8487-eaf32a45db06" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Failed to insert row with PK using bulk apply: UID="0173d742-b717-4352-bbe1-ebf04ed1c1e3" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Failed to insert row with PK using bulk apply: UID="0191919d-d105-4969-bfc3-c502ffee948b" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Failed to insert row with PK using bulk apply: UID="01b61c91-b9f5-4ba5-8cae-8da6c2e8273a" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:356, Failed to insert row with PK using bulk apply: UID="01c5ba6d-c053-4201-8e86-1d75e93fdcf8" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:357,
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:357, RowId: diarycall-00197828-1d55-4e6c-bcad-da335a478c65 UV: 1,20 CV: 1,20 IsTomb: False
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:359, Inserting row with PK: UID="00197828-1d55-4e6c-bcad-da335a478c65" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:359, Executing Command: [DiaryCall_insert]
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:359, Parameter: @P_1 Value: 00197828-1d55-4e6c-bcad-da335a478c65
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:360, Parameter: @P_2 Value: 11/01/2012 00:00:00
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:360, Parameter: @P_3 Value: NULL
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:360, Parameter: @P_4 Len: 13 Value: BURRONOT80AAA
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:360, Parameter: @P_5 Len: 1 Value: A
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:360, Parameter: @P_6 Len: 52 Value: !!PBM424 PBM424 1101121437211101121437...
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:360, Parameter: @sync_row_count Value: 0
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:361, Rows affected: 0
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:362, Executing Command: [DiaryCall_selectrow]
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:362, Parameter: @P_1 Value: 00197828-1d55-4e6c-bcad-da335a478c65
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:362, Parameter: @sync_scope_local_id Value: 256
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:362, Parameter: @sync_scope_restore_count Value: 0
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:364,
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:364, RowId: diarycall-00197828-1d55-4e6c-bcad-da335a478c65 UV: 1,19 CV: 0,24870 IsTomb: False
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:364, Checking for conflict.
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:364, Remote peer contains local change. Returning RemoteSupersedes.
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:364, Executing Command: [DiaryCall_update]
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:364, Parameter: @P_1 Value: 00197828-1d55-4e6c-bcad-da335a478c65
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:364, Parameter: @P_2 Value: 11/01/2012 00:00:00
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:364, Parameter: @P_3 Value: NULL
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:364, Parameter: @P_4 Len: 13 Value: BURRONOT80AAA
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:364, Parameter: @P_5 Len: 1 Value: A
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:364, Parameter: @P_6 Len: 52 Value: !!PBM424 PBM424 1101121437211101121437...
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:364, Parameter: @sync_force_write Value: 0
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:364, Parameter: @sync_min_timestamp Value: 296127
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:364, Parameter: @sync_row_count Value: 0
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:370, Rows affected: 1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:370, Executing Command: [DiaryCall_updatemetadata]
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:370, Parameter: @P_1 Value: 00197828-1d55-4e6c-bcad-da335a478c65
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:370, Parameter: @sync_scope_local_id Value: 256
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:370, Parameter: @sync_row_is_tombstone Value: 0
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:370, Parameter: @sync_create_peer_key Value: 1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:370, Parameter: @sync_create_peer_timestamp Value: 20
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:370, Parameter: @sync_update_peer_key Value: 1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:370, Parameter: @sync_update_peer_timestamp Value: 20
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:370, Parameter: @sync_check_concurrency Value: 0
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:370, Parameter: @sync_row_timestamp Value: 296127
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:370, Parameter: @sync_row_count Value: 0
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:377, Rows affected: 1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:377, Local UV: 1,19 CV: 0,24870 IsTomb: False
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:377,
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:377, RowId: diarycall-002641eb-6d26-4597-b767-cf9b8e452e81 UV: 1,20 CV: 1,20 IsTomb: False
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:377, Inserting row with PK: UID="002641eb-6d26-4597-b767-cf9b8e452e81" on fsproto1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:377, Executing Command: [DiaryCall_insert]
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:377, Parameter: @P_1 Value: 002641eb-6d26-4597-b767-cf9b8e452e81
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:377, Parameter: @P_2 Value: 27/10/2010 00:00:00
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:377, Parameter: @P_3 Value: NULL
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:377, Parameter: @P_4 Len: 13 Value: SASHELEF44AAA
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:377, Parameter: @P_5 Len: 1 Value: X
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:377, Parameter: @P_6 Len: 52 Value: !!PBM424 PBM424 2710100958442710100958...
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:377, Parameter: @sync_row_count Value: 0
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:377, Rows affected: 0
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:377, Executing Command: [DiaryCall_selectrow]
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:377, Parameter: @P_1 Value: 002641eb-6d26-4597-b767-cf9b8e452e81
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:377, Parameter: @sync_scope_local_id Value: 256
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:377, Parameter: @sync_scope_restore_count Value: 0
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:378,
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:378, RowId: diarycall-002641eb-6d26-4597-b767-cf9b8e452e81 UV: 1,19 CV: 0,24870 IsTomb: False
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:378, Checking for conflict.
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:378, Remote peer contains local change. Returning RemoteSupersedes.
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:378, Executing Command: [DiaryCall_update]
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:378, Parameter: @P_1 Value: 002641eb-6d26-4597-b767-cf9b8e452e81
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:378, Parameter: @P_2 Value: 27/10/2010 00:00:00
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:378, Parameter: @P_3 Value: NULL
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:378, Parameter: @P_4 Len: 13 Value: SASHELEF44AAA
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:378, Parameter: @P_5 Len: 1 Value: X
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:378, Parameter: @P_6 Len: 52 Value: !!PBM424 PBM424 2710100958442710100958...
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:378, Parameter: @sync_force_write Value: 0
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:378, Parameter: @sync_min_timestamp Value: 296129
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:378, Parameter: @sync_row_count Value: 1
VERBOSE, WebDev.WebServer40, 41, 03/19/2013 11:47:56:378, Rows affected: 1
Ahem... sorry about the long post! As you can see, the bulk insert sp is called with the full 20 row changeset, but then the provider reverts to using the row-by-row tablename_update sp to apply the updates. (I only copied in the first 2 here - rather than the full 20!)
I have managed to get this working by tweaking the tablename_bulkinsert sp to handle updated rows in it's merge operation like so:
(New bits are in bold):
MERGE [Sales] AS base USING
-- join done here against the side table to get the local timestamp for concurrency check
(SELECT p.*, t.update_scope_local_id, t.scope_update_peer_key, t.local_update_peer_timestamp FROM @changeTable p LEFT JOIN [Sales_tracking] t ON p.[uid] = t.[uid]) AS changes ON changes.[uid] = base.[uid]
WHEN NOT MATCHED BY TARGET AND changes.local_update_peer_timestamp <= @sync_min_timestamp OR changes.local_update_peer_timestamp IS NULL THEN
INSERT ([uid], [CustomerCode], [OrderDate], [DeliveryDate], [WholesalerCode], [ProductCode], [Qty]) VALUES (changes.[uid], changes.[CustomerCode], changes.[OrderDate], changes.[DeliveryDate], changes.[WholesalerCode], changes.[ProductCode], changes.[Qty])
WHEN MATCHED AND (changes.update_scope_local_id = @sync_scope_local_id AND changes.scope_update_peer_key = changes.sync_update_peer_key) OR changes.local_update_peer_timestamp <= @sync_min_timestamp THEN
UPDATE SET [CustomerCode] = changes.[CustomerCode], [OrderDate] = changes.[OrderDate], [DeliveryDate] = changes.[DeliveryDate], [WholesalerCode] = changes.[WholesalerCode], [ProductCode] = changes.[ProductCode], [Qty] = changes.[Qty]
OUTPUT INSERTED.[uid] INTO @changed; -- populates the temp table with successful PKs
Testing this revised sp out with my Azure service and Sql Azure database saw my processing of 6000 changed rows being processed in 11 seconds (instead of around 75 seconds).
So, my predicament is this. I'm not sure if I have introduced a bug somewhere (in the way I am presenting the changeset to the service).... or there is a bug in the sync toolkit somewhere..... or there is a bug in the server side SqlServer Sync provider somewhere.
I hope all this makes sense, I really appreciate the time you've spent helping with this. If you could, please could you investigate a similar scenario to see if you get comparable results.
Many thanks.
Tuesday, March 19, 2013 2:03 PM -
have you looked at your client app to check if the updates are correctly tagged as updates? sync fx will do inserts if the rows are tagged as inserts, otherwise that should have called update in the first place.
what is you client database btw?
Tuesday, March 19, 2013 2:12 PM -
Hi June. Our client db is SQLite. I have taken the sqlce offline provider sample (I think it is the win phone 6.5 sample) and made a number of enhancements. (Framework 4.5, generic crud operations, httpclient utilisation, sync progress events) when it's finished I will upload it to your collaboration site if you would like it. Anyway, I'm not quite sure if I fully understand how to tag changes as new or updated. I do however pass the service provided metadata Id to the service on updated rows. New rows have a null Ids of course I appreciate the help. ThanksWednesday, March 20, 2013 8:04 AM
-
i wrote a blog post on Synchronizing SQLite/WinRT using Sync Framework Toolkit and I think apart from it targeted towards WinRT, the approach should be the same. Have a look if you've done something differently.
there's another one post as well that goes as far as generating the client offline entities. I think you should be able to retarget the platform from WinRT as well. Have a look at this: Synchronization with SQLite on WinRT
Wednesday, March 20, 2013 10:22 AM -
Hi June, thanks for this, as a test, I've taken your sample winrt/sqlite project and got it up and running on my development machine.
Firstly, I had a look through the code, and I couldn't spot anything different....so I decided to take your sample and trace it to see what I find.
First of all, I had to tweak the config file to 'EnableBulkApplyProcedures' (you had it as false) and I also made the scope a template scope.
I then created and provisioned as per your instructions. And fired the store app. I then create a number of rows in both the customer and project tables (using the app) and synced them.
I then used the app to update 10 rows, and then synced them.
I found that I get a similar looking trace to what I was seeing - project_bulkinsert gets called (which is nice and quick for new rows), but the same sp always gets called for updates also. (the updated rows fail on the bulkinsert) and the service then proceeds to call project_insert (fails), followed by project_update (succeeds) for every updated row.
I'm hoping that I've done something wrong somewhere. I'm pretty sure I've got the latest version of the Sync Framework and the Toolkit installed.
Here is a (condensed) snippet of the trace I ran this morning with 10 updated project rows. As you can see, the service is seeing 0 updates, but 10 inserts..... sorry once again if I'm missing something here. I just cannot see what I'm doing wrong!
INFO , iisexpress, 118, 03/25/2013 10:48:07:029, ----- Inserts for Table "Project" -----
VERBOSE, iisexpress, 118, 03/25/2013 10:48:07:304, Executing Command: [Project_bulkinsert]
VERBOSE, iisexpress, 118, 03/25/2013 10:48:07:305, Parameter: @sync_min_timestamp Value: 2065
VERBOSE, iisexpress, 118, 03/25/2013 10:48:07:306, Parameter: @sync_scope_local_id Value: 2
VERBOSE, iisexpress, 118, 03/25/2013 10:48:07:307, Parameter: @changeTable Value: Project
INFO , iisexpress, 118, 03/25/2013 10:48:07:971, Applied 0 of 10 rows with bulk command BulkInsertCommand
VERBOSE, iisexpress, 118, 03/25/2013 10:48:07:973, Failed to insert row with PK using bulk apply: Id="1" on SyncDemo
VERBOSE, iisexpress, 118, 03/25/2013 10:48:07:974, Failed to insert row with PK using bulk apply: Id="2" on SyncDemo
VERBOSE, iisexpress, 118, 03/25/2013 10:48:07:974, Failed to insert row with PK using bulk apply: Id="3" on SyncDemo
VERBOSE, iisexpress, 118, 03/25/2013 10:48:07:975, Failed to insert row with PK using bulk apply: Id="4" on SyncDemo
VERBOSE, iisexpress, 118, 03/25/2013 10:48:07:976, Failed to insert row with PK using bulk apply: Id="5" on SyncDemo
VERBOSE, iisexpress, 118, 03/25/2013 10:48:07:977, Failed to insert row with PK using bulk apply: Id="6" on SyncDemo
VERBOSE, iisexpress, 118, 03/25/2013 10:48:07:978, Failed to insert row with PK using bulk apply: Id="7" on SyncDemo
VERBOSE, iisexpress, 118, 03/25/2013 10:48:07:978, Failed to insert row with PK using bulk apply: Id="8" on SyncDemo
VERBOSE, iisexpress, 118, 03/25/2013 10:48:07:979, Failed to insert row with PK using bulk apply: Id="9" on SyncDemo
VERBOSE, iisexpress, 118, 03/25/2013 10:48:07:980, Failed to insert row with PK using bulk apply: Id="10" on SyncDemo
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:004,
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:004, RowId: project-1 UV: 1,2 CV: 1,2 IsTomb: False
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:048, Inserting row with PK: Id="1" on SyncDemo
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:049, Executing Command: [Project_insert]
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:050, Parameter: @P_1 Value: 1
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:050, Parameter: @P_2 Value: 5
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:051, Parameter: @P_3 Len: 3 Value: azz
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:052, Parameter: @P_4 Len: 2 Value: az
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:053, Parameter: @P_5 Value: 29/03/2013 00:00:00
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:054, Parameter: @sync_row_count Value: 0
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:066, Rows affected: 0
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:068, Executing Command: [Project_selectrow]
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:069, Parameter: @P_1 Value: 1
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:070, Parameter: @sync_scope_local_id Value: 2
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:071, Parameter: @sync_scope_restore_count Value: 0
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:072,
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:072, RowId: project-1 UV: 1,1 CV: 0,2002 IsTomb: False
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:073, Checking for conflict.
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:074, Remote peer contains local change. Returning RemoteSupersedes.
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:075, Executing Command: [Project_update]
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:076, Parameter: @P_1 Value: 1
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:077, Parameter: @P_2 Value: 5
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:077, Parameter: @P_3 Len: 3 Value: azz
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:078, Parameter: @P_4 Len: 2 Value: az
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:079, Parameter: @P_5 Value: 29/03/2013 00:00:00
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:080, Parameter: @sync_force_write Value: 0
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:081, Parameter: @sync_min_timestamp Value: 2045
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:081, Parameter: @sync_row_count Value: 0
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:151, Rows affected: 1
.
.
.
.
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:477,
INFO , iisexpress, 118, 03/25/2013 10:48:08:478, 10 Inserts Applied
INFO , iisexpress, 118, 03/25/2013 10:48:08:479, --- End Inserts for Table "Project" ---
INFO , iisexpress, 118, 03/25/2013 10:48:08:483, ----- Updates for Table "Project" -----
VERBOSE, iisexpress, 118, 03/25/2013 10:48:08:484,
INFO , iisexpress, 118, 03/25/2013 10:48:08:484, 0 Updates Applied
INFO , iisexpress, 118, 03/25/2013 10:48:08:485, --- End Updates for Table "Project" ---
Monday, March 25, 2013 11:17 AM -
must be a bug either in persisting the metadata id when a http response for upload is received or in tagging updates.
dont have much time to play around with it, but if you have time, you can have a look at ApplyItem() inside SqlliteStorageHandler and see if an insert you have uploaded comes down with a metadata id and if the metadata id get's persisted in Sqlite.
you can have a look a the same behaviour inside ProcessUploadRequest() in the HttoCacheRequestHandler sa that's when the metadata id is set.
Monday, March 25, 2013 1:28 PM -
Hi June,
Yes, I can see that the metadataid returned in the response for the upload is being persisted in the sqlite database.
I have also added an interceptor (see code below) so that I can ensure that the metadataid (for updated rows) is getting to the service correctly.
So as far as I can see, the metadata is returned in the response from the service, it is persisted along with the row, and is sent in subsequent update changesets also.
Here is my interceptor code, along with the value of the metadataid for the first row in a changeset of 10 updated rows...
[SyncRequestInterceptor("SqliteDemoScope", SyncOperations.Upload)]
public void Customers_Download(SyncOperationContext operationContext)
{
SyncUploadRequestOperationContext abc = (operationContext as SyncUploadRequestOperationContext);
string rowId = abc.IncomingChanges[0].ServiceMetadata.Id;
int i = 1; //I put a breakpoint here so that I can catch the contents of rowId
}
and on hitting the breakpoint the value of rowId was:
?rowId
"http://localhost:3412/SqliteDemoScopeSyncService.svc/Project(Id=1)"You mention 'tagging updates'. Apart from the metadataid, I cannot see anyway to tag a changeset item as an update. Does the presence of a metadataid value imply that the changeset row is an update?
Thanks.
Monday, March 25, 2013 5:02 PM -
Ok, I think I have found the bug.
In the SyncServiceLib\SqlProvider\DataSetToEntitiesConverter.cs...
In the AddEntityToDataSet method....
The block starting line 526 reads...
// If the entity is a tombstone, set the DataRowState property by calling the Delete or SetAdded method.
if (objectToRead.ServiceMetadata.IsTombstone)
{
row.Delete();
}
else
{
row.SetAdded();
}
I believe the bug to be that this does not handle updated entities. So therefore I changed the code to... (adding in the SetModified() call if the metadata.id is not empty)
// If the entity is a tombstone, set the DataRowState property by calling the Delete or SetAdded method.
if (objectToRead.ServiceMetadata.IsTombstone)
{
row.Delete();
}
else if (!String.IsNullOrEmpty(objectToRead.ServiceMetadata.Id))
{
row.SetModified();
}
else
{
row.SetAdded();
}It now seems to work and correctly calls entity_bulkupdate and entity_update for updated rows.
June, I would appreciate if you would confirm this as a successful bug/fix. Thanks.
- Proposed as answer by JuneT Wednesday, March 27, 2013 11:00 AM
Tuesday, March 26, 2013 11:56 AM -
i believe it's a bug... made the same change and did just a couple of random tests as well last night...
it seems to fix the issue you reported but haven't looked at potential side effects...(i couldn't think of any, but worth testing specially with conflicts...)
good job btw, persistence works :)- Edited by JuneT Tuesday, March 26, 2013 11:48 PM
Tuesday, March 26, 2013 11:47 PM -
Hello All,
I have create a service to my client db with SQLite and the service following this documentation https://github.com/Mimetis/SyncWinRT/wiki/02-Generate-Server-and-Client-code.
My problem is that if locally everything works fine when I deploy the app as webrole on azure the sync framework does not pick up any changes.
There is not error or exception symply do not reconise the db has rows to be downloaded.
I do not know if there is anyone that have experience with this problem but if someone already got this please a help would be really appreciated.
Best Regards
Friday, October 31, 2014 1:19 PM