cancel
Showing results for 
Search instead for 
Did you mean: 
Read only

Invalid sync sequence ID for remote ID 'X'

Former Member
14,092

Hello experts,

I've faced this issue for a long time and I hope you guys could help me with this.

Sometimes when the sync is cancelled in the app an error of upload occurs, with the "invalid sync sequence ID" description in the server.

We've been using the SQLAnywhere 16 2127 and UltraliteJ for Android. The sync is canceled using the 'syncProgress' callback from 'SyncObserver' class.

Looking for evidences in the server log, I've noticed that the transaction of the canceled sync is commited, but after a bit of time a log of 'connection drop' is logged.

This error is a little bit hard to reproduce, but it affects hundred of users every week in my company.

After that, I'm only able to sync again with this user if I start a new sync with a new database.

Any suggestions of what could be happening?

I. 2015-08-26 11:06:49. <1084> Request from "UL 16.0.2127" for: remote ID: 2, user name: 24, version: XXX
I. 2015-08-26 11:06:49. <1084> The current synchronization is using a connection with connection ID 'SPID 262'
I. 2015-08-26 11:06:49. <1084> The authenticate_parameters script returned 1000
I. 2015-08-26 11:06:49. <1084> COMMIT Transaction: Authenticate user
I. 2015-08-26 11:06:49. <1084> COMMIT Transaction: Begin synchronization
I. 2015-08-26 11:06:49. <1084> COMMIT Transaction: Prepare for download
I. 2015-08-26 11:06:50. <1084> Sending the download to the remote database
I. 2015-08-26 11:06:50. <1084> COMMIT Transaction: Download
I. 2015-08-26 11:06:57. <1084> COMMIT Transaction: End synchronization
I. 2015-08-26 11:10:54. <1085> Request from "UL 16.0.2127" for: remote ID: 2, user name: 24, version: XXX
I. 2015-08-26 11:10:54. <1085> The current synchronization is using a connection with connection ID 'SPID 262'
I. 2015-08-26 11:10:54. <1085> The authenticate_parameters script returned 1000
I. 2015-08-26 11:10:54. <1085> COMMIT Transaction: Authenticate user
I. 2015-08-26 11:10:54. <1085> The sync sequence ID in the consolidated database: 66e705a64bc911e58000d4b26ffaac50; the remote previous sequence ID: ac77d1964bc811e58000d4b26ffaac50, and the current sequence ID: f8e572bc4bc911e580009bbc92b92a77
E. 2015-08-26 11:10:54. <1085> [-10400] Invalid sync sequence ID for remote ID '2'
I. 2015-08-26 11:10:54. <1085> Synchronization failed
E. 2015-08-26 11:10:59. <1084> [-10279] Connection was dropped due to lack of network activity
I. 2015-08-26 11:10:59. <1084> Synchronization complete

A new log with verbosity -vp

I. 2015-08-27 16:05:16. <38> Request from "UL 16.0.2127" for: remote ID: 2, user name: 24, version: XXX
I. 2015-08-27 16:05:16. <38> The current synchronization is using a connection with connection ID 'SPID 366'
I. 2015-08-27 16:05:16. <38> The authenticate_parameters script returned 1000
I. 2015-08-27 16:05:16. <38> COMMIT Transaction: Authenticate user
I. 2015-08-27 16:05:16. <38> Publication #1: ul_default_pub, subscription id: 1, last download time: 2015-08-27 16:05:06.727000
I. 2015-08-27 16:05:16. <38> The sync sequence ID in the consolidated database: 3c4236b04cbc11e58000c12fcb6170e4; the remote previous sequence ID: 3c4236b04cbc11e58000c12fcb6170e4, and the current sequence ID: 41d955e04cbc11e58000c12fcb6170e4
I. 2015-08-27 16:05:16. <38> Last upload time for subscription id 1: 2015-08-27 15:41:13.180000
I. 2015-08-27 16:05:16. <38> Generation number for publication 'ul_default_pub' is 1
I. 2015-08-27 16:05:16. <38> COMMIT Transaction: Begin synchronization
I. 2015-08-27 16:05:17. <38> COMMIT Transaction: Prepare for download
I. 2015-08-27 16:05:17. <38> Next last download timestamp fetched from the consolidated database is "2015-08-27 16:05:16.297000"
I. 2015-08-27 16:05:18. <38> Sending the download to the remote database
I. 2015-08-27 16:05:18. <38> COMMIT Transaction: Download
I. 2015-08-27 16:05:24. <38> COMMIT Transaction: End synchronization
I. 2015-08-27 16:06:13. <39> Request from "UL 16.0.2087" for: remote ID: 1009, user name: 17, version: XXX
I. 2015-08-27 16:06:13. <39> The current synchronization is using a connection with connection ID 'SPID 366'
I. 2015-08-27 16:06:13. <39> The authenticate_parameters script returned 1000
I. 2015-08-27 16:06:13. <39> COMMIT Transaction: Authenticate user
I. 2015-08-27 16:06:13. <39> Publication #1: ul_default_pub, subscription id: 1, last download time: 2015-08-27 16:04:35.817000
I. 2015-08-27 16:06:13. <39> The sync sequence ID in the consolidated database: 874340d9d4404fc995874938ed708bc5; the remote previous sequence ID: 874340d9d4404fc995874938ed708bc5, and the current sequence ID: 137635d70da644e089e8e42c3ab092cb
I. 2015-08-27 16:06:13. <40> Request from "UL 16.0.2127" for: remote ID: 2, user name: 24, version: XXX
I. 2015-08-27 16:06:13. <40> The current synchronization is using a connection with connection ID 'SPID 357'
I. 2015-08-27 16:06:13. <40> The authenticate_parameters script returned 1000
I. 2015-08-27 16:06:13. <40> COMMIT Transaction: Authenticate user
I. 2015-08-27 16:06:13. <40> Publication #1: ul_default_pub, subscription id: 1, last download time: 2015-08-27 16:05:06.727000
I. 2015-08-27 16:06:13. <40> The sync sequence ID in the consolidated database: 41d955e04cbc11e58000c12fcb6170e4; the remote previous sequence ID: 3c4236b04cbc11e58000c12fcb6170e4, and the current sequence ID: 64255a684cbc11e58000d4570e72fa59
E. 2015-08-27 16:06:13. <40> [-10400] Invalid sync sequence ID for remote ID '2'
I. 2015-08-27 16:06:14. <40> Synchronization failed

A new log with download/upload scenario:

I. 2015-07-31 05:44:16. <1361> Request from "UL 16.0.2087" for: remote ID: 190, user name: 99, version: XXX
I. 2015-07-31 05:44:16. <1361> The current synchronization is using a connection with connection ID 'SPID 110'
I. 2015-07-31 05:44:16. <1361> The authenticate_parameters script returned 1000
I. 2015-07-31 05:44:16. <1361> COMMIT Transaction: Authenticate user
I. 2015-07-31 05:44:16. <1361> COMMIT Transaction: Begin synchronization
I. 2015-07-31 05:44:16. <1361> COMMIT Transaction: Upload
I. 2015-07-31 05:44:17. <1361> COMMIT Transaction: Prepare for download
I. 2015-07-31 05:44:28. <1361> Sending the download to the remote database
I. 2015-07-31 05:44:30. <1361> COMMIT Transaction: Download
I. 2015-07-31 05:44:31. <1362> Request from "UL 16.0.2087" for: remote ID: 190, user name: 99, version: XXX
E. 2015-07-31 05:44:31. <1362> [-10341] The remote database identified by remote ID '190' may already be synchronizing: unable to lock that remote ID
I. 2015-07-31 05:44:32. <1363> Request from "UL 16.0.2087" for: remote ID: 190, user name: 99, version: XXX
E. 2015-07-31 05:44:32. <1363> [-10341] The remote database identified by remote ID '190' may already be synchronizing: unable to lock that remote ID
I. 2015-07-31 05:44:33. <1363> The current synchronization is using a connection with connection ID 'SPID 112'
I. 2015-07-31 05:44:33. <1363> The authenticate_parameters script returned 1000
I. 2015-07-31 05:44:33. <1363> COMMIT Transaction: Authenticate user
E. 2015-07-31 05:44:33. <1363> [-10341] The remote database identified by remote ID '190' may already be synchronizing: unable to lock that remote ID
I. 2015-07-31 05:44:33. <1363> Synchronization failed
I. 2015-07-31 05:44:37. <1361> COMMIT Transaction: End synchronization
I. 2015-07-31 05:45:25. <1364> Request from "UL 16.0.2087" for: remote ID: 190, user name: 99, version: XXX
I. 2015-07-31 05:45:25. <1364> The current synchronization is using a connection with connection ID 'SPID 110'
I. 2015-07-31 05:45:25. <1364> The authenticate_parameters script returned 1000
I. 2015-07-31 05:45:25. <1364> COMMIT Transaction: Authenticate user
I. 2015-07-31 05:45:25. <1364> The sync sequence ID in the consolidated database: e41b0e0add35460091ca651ce0ee2633; the remote previous sequence ID: 25acf6af47234c1192f7203343b5e93e, and the current sequence ID: 1c20ad4023d44353a7b32d021c698c74
E. 2015-07-31 05:45:25. <1364> [-10400] Invalid sync sequence ID for remote ID '190'
I. 2015-07-31 05:45:26. <1364> Synchronization failed
E. 2015-07-31 05:48:26. <1361> [-10279] Connection was dropped due to lack of network activity
I. 2015-07-31 05:48:26. <1361> Synchronization complete

And a very complex scenario which I couldn't figure out what could be happening? Maybe a simultaneos sync in the same device?

I. 2015-07-29 08:07:32. <1112> Request from "UL 16.0.2087" for: remote ID: 170, user name: 11, version: XXX
I. 2015-07-29 08:07:46. <1113> Request from "UL 16.0.2087" for: remote ID: 170, user name: 11, version: XXX
I. 2015-07-29 08:07:46. <1113> The current synchronization is using a connection with connection ID 'SPID 91'
I. 2015-07-29 08:07:46. <1113> The authenticate_parameters script returned 1000
I. 2015-07-29 08:07:46. <1113> COMMIT Transaction: Authenticate user
I. 2015-07-29 08:07:46. <1113> COMMIT Transaction: Begin synchronization
I. 2015-07-29 08:07:46. <1113> COMMIT Transaction: Upload
I. 2015-07-29 08:07:48. <1113> COMMIT Transaction: Prepare for download
I. 2015-07-29 08:07:58. <1113> Sending the download to the remote database
I. 2015-07-29 08:08:00. <1113> COMMIT Transaction: Download
I. 2015-07-29 08:08:08. <1113> COMMIT Transaction: End synchronization
I. 2015-07-29 08:08:12. <1114> Request from "UL 16.0.2087" for: remote ID: 170, user name: 11, version: XXX
I. 2015-07-29 08:08:12. <1114> The current synchronization is using a connection with connection ID 'SPID 91'
I. 2015-07-29 08:08:12. <1114> The authenticate_parameters script returned 1000
I. 2015-07-29 08:08:12. <1114> COMMIT Transaction: Authenticate user
I. 2015-07-29 08:08:12. <1114> COMMIT Transaction: Begin synchronization
I. 2015-07-29 08:08:12. <1114> COMMIT Transaction: Upload
I. 2015-07-29 08:08:13. <1114> COMMIT Transaction: Prepare for download
I. 2015-07-29 08:08:21. <1115> Request from "UL 16.0.2087" for: remote ID: 170, user name: 11, version: XXX
I. 2015-07-29 08:08:21. <1115> The current synchronization is using a connection with connection ID 'SPID 82'
I. 2015-07-29 08:08:21. <1115> The authenticate_parameters script returned 1000
I. 2015-07-29 08:08:21. <1115> COMMIT Transaction: Authenticate user
E. 2015-07-29 08:08:21. <1115> [-10341] The remote database identified by remote ID '170' may already be synchronizing: unable to lock that remote ID
I. 2015-07-29 08:08:21. <1115> Synchronization failed
I. 2015-07-29 08:08:22. <1114> Sending the download to the remote database
I. 2015-07-29 08:08:25. <1114> COMMIT Transaction: Download
I. 2015-07-29 08:08:33. <1114> COMMIT Transaction: End synchronization
I. 2015-07-29 08:08:40. <1116> Request from "UL 16.0.2087" for: remote ID: 170, user name: 11, version: XXX
I. 2015-07-29 08:08:40. <1116> The current synchronization is using a connection with connection ID 'SPID 91'
I. 2015-07-29 08:08:40. <1116> The authenticate_parameters script returned 1000
I. 2015-07-29 08:08:40. <1116> COMMIT Transaction: Authenticate user
I. 2015-07-29 08:08:41. <1116> COMMIT Transaction: Begin synchronization
I. 2015-07-29 08:08:41. <1116> COMMIT Transaction: Upload
I. 2015-07-29 08:08:42. <1116> COMMIT Transaction: Prepare for download
I. 2015-07-29 08:08:48. <1117> Request from "UL 16.0.2087" for: remote ID: 170, user name: 11, version: XXX
I. 2015-07-29 08:08:48. <1117> The current synchronization is using a connection with connection ID 'SPID 82'
I. 2015-07-29 08:08:48. <1117> The authenticate_parameters script returned 1000
I. 2015-07-29 08:08:48. <1117> COMMIT Transaction: Authenticate user
E. 2015-07-29 08:08:48. <1117> [-10341] The remote database identified by remote ID '170' may already be synchronizing: unable to lock that remote ID
I. 2015-07-29 08:08:48. <1117> Synchronization failed
I. 2015-07-29 08:08:52. <1116> Sending the download to the remote database
I. 2015-07-29 08:08:54. <1116> COMMIT Transaction: Download
I. 2015-07-29 08:09:02. <1116> COMMIT Transaction: End synchronization
I. 2015-07-29 08:09:13. <1118> Request from "UL 16.0.2087" for: remote ID: 170, user name: 11, version: XXX
I. 2015-07-29 08:09:13. <1118> The current synchronization is using a connection with connection ID 'SPID 91'
I. 2015-07-29 08:09:13. <1118> The authenticate_parameters script returned 1000
I. 2015-07-29 08:09:13. <1118> COMMIT Transaction: Authenticate user
I. 2015-07-29 08:09:13. <1118> COMMIT Transaction: Begin synchronization
I. 2015-07-29 08:09:13. <1118> COMMIT Transaction: Upload
I. 2015-07-29 08:09:15. <1118> COMMIT Transaction: Prepare for download
I. 2015-07-29 08:09:20. <1119> Request from "UL 16.0.2087" for: remote ID: 170, user name: 11, version: XXX
I. 2015-07-29 08:09:20. <1119> The current synchronization is using a connection with connection ID 'SPID 82'
I. 2015-07-29 08:09:20. <1119> The authenticate_parameters script returned 1000
I. 2015-07-29 08:09:20. <1119> COMMIT Transaction: Authenticate user
E. 2015-07-29 08:09:20. <1119> [-10341] The remote database identified by remote ID '170' may already be synchronizing: unable to lock that remote ID
I. 2015-07-29 08:09:20. <1119> Synchronization failed
I. 2015-07-29 08:09:25. <1118> Sending the download to the remote database
I. 2015-07-29 08:09:27. <1118> COMMIT Transaction: Download
I. 2015-07-29 08:09:27. <1120> Request from "UL 16.0.2087" for: remote ID: 170, user name: 11, version: XXX
I. 2015-07-29 08:09:27. <1120> The current synchronization is using a connection with connection ID 'SPID 82'
I. 2015-07-29 08:09:27. <1120> The authenticate_parameters script returned 1000
I. 2015-07-29 08:09:27. <1120> COMMIT Transaction: Authenticate user
E. 2015-07-29 08:09:27. <1120> [-10341] The remote database identified by remote ID '170' may already be synchronizing: unable to lock that remote ID
I. 2015-07-29 08:09:33. <1121> Request from "UL 16.0.2087" for: remote ID: 170, user name: 11, version: XXX
E. 2015-07-29 08:09:33. <1121> [-10341] The remote database identified by remote ID '170' may already be synchronizing: unable to lock that remote ID
I. 2015-07-29 08:09:33. <1121> The current synchronization is using a connection with connection ID 'SPID 82'
I. 2015-07-29 08:09:33. <1121> The authenticate_parameters script returned 1000
I. 2015-07-29 08:09:33. <1121> COMMIT Transaction: Authenticate user
E. 2015-07-29 08:09:33. <1121> [-10341] The remote database identified by remote ID '170' may already be synchronizing: unable to lock that remote ID
I. 2015-07-29 08:09:35. <1118> COMMIT Transaction: End synchronization
I. 2015-07-29 08:09:39. <1122> Request from "UL 16.0.2087" for: remote ID: 170, user name: 11, version: XXX
I. 2015-07-29 08:09:39. <1122> The sync sequence ID in the consolidated database: 8064c8e9c74d496daacfc651456dbece; the remote previous sequence ID: 3a1fe564a0eb4d0b808709e078925e3b, and the current sequence ID: 7f42f25b36854bacb328cacb822bd6fc
E. 2015-07-29 08:09:39. <1122> [-10400] Invalid sync sequence ID for remote ID '170'
I. 2015-07-29 08:09:39. <1122> Synchronization failed
E. 2015-07-29 08:11:36. <1112> [-10279] Connection was dropped due to lack of network activity
I. 2015-07-29 08:11:36. <1112> Synchronization complete
E. 2015-07-29 08:12:00. <1113> [-10279] Connection was dropped due to lack of network activity
I. 2015-07-29 08:12:00. <1113> Synchronization complete
E. 2015-07-29 08:12:20. <1114> [-10279] Connection was dropped due to lack of network activity
I. 2015-07-29 08:12:20. <1114> Synchronization complete
E. 2015-07-29 08:12:47. <1116> [-10279] Connection was dropped due to lack of network activity
I. 2015-07-29 08:12:47. <1116> Synchronization complete
E. 2015-07-29 08:13:18. <1118> [-10279] Connection was dropped due to lack of network activity
I. 2015-07-29 08:13:18. <1118> Synchronization complete
E. 2015-07-29 08:13:32. <1120> [-10279] Connection was dropped due to lack of network activity
I. 2015-07-29 08:13:32. <1120> Synchronization failed
View Entire Topic
chris_keating
Product and Topic Expert
Product and Topic Expert

This issue has now been fixed and will be available in future SPs containing 17.0.0 Build 1253 or later and 16.0.0 Build 2177 or later. The details of the problem that was addressed follows:

If an UltraLite client crashed or was terminated in the middle of a download-only synchronization, it was possible for the client to enter a state where all subsequent synchronizations would fail with SQLE_UPLOAD_FAILED_AT_SERVER and the MobiLink log would report mismatched sequence IDs.

Former Member
0 Likes

Thanks by this fix! Are there any plans about when it will be released?

chris_keating
Product and Topic Expert
Product and Topic Expert
0 Likes

An SP has been requested for this change and QA is scheduling that work. However, we are not yet able to provide a specific timeframe for that SP to be ready.

Former Member
0 Likes

Chris, the error has happened again in other scenario (download/upload configuration). Could you check the third log of my question?

Former Member
0 Likes

Hi @Chris Keating, we could reproduce this error again, but in a slight different scenario. If the sync request that is canceled is executed in a different server than the second sync (that fails because there is a pending syncing already being executed) the "sequence id error" will occur. Could you take a look on it, please?