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
Request clarification before answering.
Hi, in the meantime , the patch that has a fix for the download_only scenario was released and can be downloaded from sap.
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
There were 2 changes made related to Invalid Sync Sequence - one was related to the download_only case and the other change was related to the non download_only behaviour reported. The second fix is Engineering Case# 789932.
Hm, given the many nested comments here, it seems quite difficult to follow the discussion - I'd recommend to ask a separate question with your issue even if it's still the same cause... - possibly with a backlink to this one.
Just my 2 cents, anyway:)
I too am going to suggest that a new thread be opened as this one is getting deeply nested.
The software update addresses the conditions in which your sync environment can get into this state. It does not fix broken remotes.
If you are seeing this problem after applying this update starting with healthy remotes, please run with -vpe level logging at minimum and capture in that log a remote that transitions from working to broken.
| User | Count |
|---|---|
| 5 | |
| 4 | |
| 4 | |
| 3 | |
| 2 | |
| 2 | |
| 2 | |
| 2 | |
| 2 | |
| 2 |
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.