Invalid sync sequence ID for remote ID 'X'

[Former Member]

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

[Former Member]

I don't see a COMMIT for upload. Does your application set the Download Only synchronization parameter?

[Former Member]

We're investigating if there is a potential problem specific to cancelling download-only synchronizations. As an experiment or potential workaround, you could try disabling the Download Only sync parameter in your Android application. (If there are any changes on the remote to downloaded tables, you may also need to define ignored upload_insert and upload_update scripts.)

[Former Member]

There is some scenarios (not in general) where the download-only can be used. But, unfortunatelly, we cannot disable that to avoid data inconsistent (not allowed upload of data which may colide with others). I'll include this scenario in my tests. Tks.

[Former Member]

EDIT: The sequence ID error has happened again in the production servers in the last week, as shown in the third log of my question. A little brief of one of the POSSIBLE user-case scenario (not reproduced!): the user is syncing, then the application is closed, which closes the app process too. Then (and whenever the app process is killed) our sync engine is reinitialized, which may start a new sync immediatly (if the previous one failed). Analysing the logs, it seems the first connection is lost (the process was killed, then the connection became orphan). And when a new sync is started, the Ultralite accepts it without finishing the orphan connection, which leads to the sequence ID error. Could you check the code about this scenario? Please, take in consideration that the process is killed and restarted. Maybe (and makes sense, due the other comments about the sync id and process relation) this can be the root of all the problems.

[Former Member]

What is this connection ID (SPID)? Is it a server-side or client-side information? And what can be happening so that the log has this information of same SPID for different syncs?

[Former Member]

EDIT 2: Added a very complex scenario in the 4th log

[Former Member]

The connection ID identifies which MobiLink database connection is being used out of the MobiLink server's pool of database connections to the consolidated database, as returned from consolidated database.

[Former Member]

The third log shows 3 concurrent syncs! The two things that make me uncomfortable are:
1. Killing the app with every sync cancellation.
2. Retrying sync after less time than the timeout time.

[Former Member]

Maybe the sync is not being canceled, because the process can be killed if the user swype the app from the "recent apps" grid. Perhaps it can be a issue? About the retry, maybe we can implement a mechanism to wait the minimum time from Mobilink at the sync engine startup, but we cannot ignore the user's request, at a button click, for example. That is the way this workaround couldn't be implemented.

[Former Member]

How have you concluded about the concurrent syncs? When a sync is finished? There is a gap between the "End synchronization" message and the sync end that I could not understand.

[Former Member]

The "COMMIT Transaction: End synchronization" message indicates that sync has finished with it's consolidated database connection. However the ML server worker thread from that sync still has a network connection to the remote, and is trying to send the download. Sync 1361 doesn't end till the network timeout 229 seconds later (238s after starting to send download).

If you want the network timeout to be shorter, use SyncParms.setLivenessTimeout.

If you set that to 30 seconds (the minimum recommended) and have your app wait 30 seconds on startup before enabling the sync function, then at least cancelled/killed syncs could complete before new sync requests from the same remote ID.

[Former Member]

In case you weren't aware of it, the MobiLink Performance whitepaper provides an overview of what happens during a synchronization. The description on pages 3-6 of MobiLink 12 Performance applies to version 16 and 17.

[Former Member]

We have already set this timeout in the Production server and avoided the sync engine start until this time (30s) is reached. However we cannot ignore the explicity user request. How should we proceed? Is there any other workaround? It is safe to assume that this is a ML issue or we are doing something wrong in the client side?

[Former Member]

I didn't know this documentation. Tks a lot 😃

[Former Member]

Since your log showed network timeout taking the 238s and the default for Android is 240s, I assumed you were using the default.

Are those logs not from production? If not, why did you stop using -vp verbosity?

This problem could be happening if Android returns success when UltraLite commits, before writing to persistent storage is completed, and the killing of the app prevents persisting of the commit.

If the app has been cleared from memory by user clearing it away, why not show a busy animation and not enable the Sync button for 30s on initial startup?

(My Android phone has at least one app that takes a minute to start up after clearing from memory.)

[Former Member]

We have a dozen of environments using ML 16. And almost all of them is facing this sequence ID error. The verbosity that I've turned on was in another environment (changing production configurations is not so simple, involves service unavailability and other headaches). I can wait the 30s (the app startup takes 5secs only) but let's agree that this is not the best solution for the user POV. All I'd like to know is if someone is going to investigate this problem and treat it like a bug. If so, we can wait for a better solution.

[chris_keating]

We are going to treat this as a bug but we will need to be able to reproduce it or gather sufficient logging information to understand the cause.

[Former Member]

If your app takes 5 seconds to startup, why is there only 1 second between sync requests 1362 and 1363?

I still suspect duplicate remote IDs, since that fits the symptoms. When other customers have reported this problem, that has ultimately been determined to be the cause.

You said that remote IDs are assigned from a sequence in the consolidated. Please detail how that gets back to the remote device before that device's first MobiLink synchronization occurs.

A possible experiment would be to try using default remote IDs, and see if the problem still happens. (If you want a non-GUID identifier for each remote device, then use the synchronization user instead of the remote ID).

[Former Member]

We assign the remote id during the device provision (first app startup in the device), performing the first authentication, creating the remote id (identity SQLServer column) and assigning to the database. So, a pair of user-device is strict related with only one database and vice-versa. There is no way in which duplicated remote ids perform syncs because our sync logic relies on it. Our product do allow the provision of two or more devices for the same user, however each pair of user/device has a different remote id configuration.

In a very simplified representation of our model we have: Entity: mobileDB Properties: idMobileDB (identity), idUser (get from login), deviceIdentifier (get from the device serial number)

All the sequence IDs seems to be related with some connection loss. The reason why the sync starts after 1 sec is explained in the use-case at the beggining of this comment thread (just after the process is killed, the sync engine is automatically initialized again - just the service, not the UI -, which may start another sync immediatly without user interaction).

For the same reason I've talked in the first part of this comment, we cannot change the way the remote ids are assigned (changing back to its default) because we use the remote id within the user id to make relations between entities during the sync download/upload (different data may be downloaded depending on which device an user is syncing or two devices of the same user performing data download). The only scenario in which two mobile DBs can sync at the same time is two device related with the same user containing the same serial number. And I've already checked it and it is not the case.

I'll work on a reproduction as I've made with the download-only scenario. Then, I let you know. Meanwhile, I hope you good luck with some insight about this issue =p

Tks, in advance.

[Former Member]

I was puzzled by 1363 starting 1 second after 1362 because you said a few comments ago that your sync engine waits 30 seconds before retrying, but now you say the sync engine retries right away.

[Former Member]

I've implemented this waiting in one production environment, but after the log retrieving. I have no logs after this change yet. As soon as I have it I let you know.

[Former Member]

A quick update: in the production environment where the sync is restarted after 1 sec an iOS client is executing the sync. I'll check with the iOS team about any potential bug in which concurrent syncs could be performed.

[chris_keating · Accepted solution]

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 · Accepted solution]

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

[chris_keating · Accepted solution]

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 · Accepted solution]

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

[Former Member · Accepted solution]

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?

[Former Member]

This could happen if remote database IDs are not unique. I notice that the remote ID is '2' rather than a UUID (which is the default). Since you are using non-default remote IDs, I suspect this is the cause of the problem.

Further evidence of non-unique remote IDs is found in the sequence IDs. Since they are V1 UUIDs, the last 12 hex digits are a "node id" (often the network interface MAC address); the consolidated sequence ID and previous remote sequence ID came from node id d4b26ffaac50, whereas the current sequence ID came from node id 9bbc92b92a77.

[Former Member]

It is worth investigating whether the remote database IDs are unique.

Just a clarification for UltraLite on Android. The node id's are not MAC addresses - they are generated based on system time and randomness among other things. A node id for a given device will very likely be different after an application restart. It will stay constant for the in-memory life cycle of the application though.

[Former Member]

The remote database IDs are unique, for sure. In fact, I could reproduce this scenario with one single device syncing in a environment with only one user. About the node id, I've restarted my application after the cancelation (in fact, the sync is canceled prior the application closing), which can be the cause of the generation of two different "node ids", as Andy explained. Maybe the Mobilink is accepting a new request before closing the resources from the last one which can be leading to a bug.

[Former Member]

Thanks Andy. In other words, the Android device would have to have be rebooted, or the application closed, cleared from memory, and then restarted, for there to be two different "node ids" from the same remote. In this case, that would have to be between 11:06:50 and 11:10:54. If that didn't happen, then it seems two remote databases have the remote ID of '2'. Remote IDs must be unique!

[Former Member]

Did you see different "node ids" (in the sequence IDs) after restarting the application? Normally an Android app stays in memory after closing, which is what Andy meant by "in-memory life cycle of the application".

(A different "node id" in sequence IDs isn't a problem for MobiLink. It just seemed like evidence of non-unique remote IDs.)

A new request from the same remote ID kicks out an in-progress sync, but it may be that your application is not handling failed downloads correctly.

[Former Member]

Also, since you can reproduce the scenario, please provide the steps to reproduce and/or a MobiLink server log where -vp verbosity was specified.

[Former Member]

The application doesn't stay in memory because we force kill the process. I've made some tests and the node id do change if I restart the application. About the remote IDs, they are assigned at the moment of the first application run, server-side, stored in a identity database column. We don't have any evidences of duplicated remote IDs so far.

[Former Member]

I'll try to reproduce again with a higher verbosity and I'll post the log. Thanks!

[Former Member]

About the download error handling, I'm not sure what it is. Since we cancel the sync using the Ultralite callbacks and, after the Ultralite return (which its thread has been locked during the synchronize method call) we kill the process. So, where am I supposed to handle the download failure if I want to abort the process?

[Former Member]

How does the remote get the remote ID from server?

[Former Member]

You shouldn't need to kill the process to cancel the sync! I think you just need to return True from SyncObserver.syncProgress. These posts might help:
http://sqlanywhere-forum.sap.com/questions/8110/mobilink-synchronization-with-progress-bar-in-ultral...
http://sqlanywhere-forum.sap.com/questions/10734/mobilink-connection-timeout

A partial download should be automatically rolled back as long as you have not enabled the Keep partial download synchronization parameter. But killing the process may cause problems with rollback.

The reason we want to see -vp verbosity is to make sure that your application is doing a "check status" sync after a failed download (if not keeping partial downloads) or a "resume" sync (if keeping partial downloads).

[Former Member]

I'm not killing the process because the sync. I'm canceling the sync to kill the process for other reasons. I've checked here and we don't use partial downloads, since we have such a complex download preparation logics which don't fit to this feature. I couldn't reproduce the error yet (it is hard to reproduce), but as soon as I do it I update the question with this information. Thanks again!

[Former Member]

My concern was that the force kill of the process may interfere with proper clean up of the cancelled sync, eg. if it is killed after UltraLite returns, but Android may still be flushing to persistent storage, such as an SD card.

(BTW the box with an arrow on a comment is for replying to that comment.)

[Former Member]

Only if the Ultralite performs IO operations asynchronously, what I doubt. We kill the process only after the Ultralite fininshes the synchronize call.

(BTW, tks for the tip, but not a suggestive icon anyway)

[Former Member]

Question edited with a new log with higher verbosity, as requested.

[Former Member]

Correction: Starting with version 16, a new request from the same remote ID does not kick out an in-progress sync. (That was the behavior in an earlier version.)

[Former Member]

We have a retry logic for checking sync status, if the ODBC driver returns a timeout ODBC state when the MobiLink server was not able to lock the remote ID. This logic seems working well with a Microsoft SQL Server. However, we did not see this retry logic shown in your MobiLink server log file. So I was wondering if you could tell us what kind of consolidated database servers you are current using?

[Former Member]

Microsoft SQL Server 2014

[Former Member]

Thanks! Hopefully, there are no other problems, because Microsoft SQL server 2014 is not officially supported by the MobiLink Server 16.0. I have two more questions: 1) the ODBC driver version; and 2) The MobiLink server command line options (Please don't let me your -c setting). Could you please give us this information?

[Former Member]

ODBC DBMS Name: Microsoft SQL Server

ODBC DBMS Version: 12.00.2000

ODBC DBMS Driver Version: 11.00.3000

ODBC Version supported by the driver: 3.80

-v -c dsn=XXX;uid=XXX;pwd=XXX -x http{port=###} -o "XXX\\LogML.txt" -os 10000000 -w 10 -vp -zs SQLANYm_XXX_###

[Former Member]

It looks reasonable good and the ODBC driver is the same as the one we have recommended for MobiLink server version 17.0 to use.

[Former Member]

We are not able to reproduce the problem you have seen, because the MobiLink server always retried on status check with our tests until it was able to lock the remote ID. Could you please let us know your database options? You can get the options by issuing the following query against your SQL Server database: select * from sys.databases where name = 'your_sql_server_database_name'

Please give us the query result set including the column names, so that we can compare your options with ours.

[Former Member]

The properties that were not here are null

"compatibility_level": "120", "collation_name": "Latin1_General_CI_AS", "user_access": "0", "user_access_desc": "MULTI_USER", "is_read_only": "0", "is_auto_close_on": "0", "is_auto_shrink_on": "0", "state": "0", "state_desc": "ONLINE", "is_in_standby": "0", "is_cleanly_shutdown": "0", "is_supplemental_logging_enabled": "0", "snapshot_isolation_state": "0", "snapshot_isolation_state_desc": "OFF", "is_read_committed_snapshot_on": "0", "recovery_model": "3", "recovery_model_desc": "SIMPLE", "page_verify_option": "2", "page_verify_option_desc": "CHECKSUM", "is_auto_create_stats_on": "1", "is_auto_create_stats_incremental_on": "0", "is_auto_update_stats_on": "1", "is_auto_update_stats_async_on": "0", "is_ansi_null_default_on": "0", "is_ansi_nulls_on": "0", "is_ansi_padding_on": "0", "is_ansi_warnings_on": "0", "is_arithabort_on": "0", "is_concat_null_yields_null_on": "0", "is_numeric_roundabort_on": "0", "is_quoted_identifier_on": "0", "is_recursive_triggers_on": "0", "is_cursor_close_on_commit_on": "0", "is_local_cursor_default": "0", "is_fulltext_enabled": "1", "is_trustworthy_on": "0", "is_db_chaining_on": "0", "is_parameterization_forced": "0"

[Former Member]

Your database setting is slightly different than ours. However, we are still not able to reproduce this problem, even after we reconfigured our SQL Server database setting to match yours, the MobiLink server always keeps retry on sync status, when there is a problem on lock remote ID locking. However, we have found a problem within the MobiLink server, if the retry logic does not work for sync status check. This problem will be fixed as soon as we can. To workaround this problem, please try to reduce the sync frequency for individual remotes whose last sync status was unknown. By the way, what are the OS type and OS version you are currently running your MobiLink server?

[Former Member]

Windows Server 2012

[ddeconin]

Hi, in the meantime , the patch that has a fix for the download_only scenario was released and can be downloaded from sap.

[chris_keating]

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.

[Former Member]

Are these two fixes in the same patch? Also, could you please inform me the build number of this patch? Tks a lot by the fixes =]

[chris_keating]

Both fixes are in that SP. The second fix is Engineering Case#788991. Recall, that was the 'download-only' case.

[Former Member]

Got it. I downloaded the build 2193 which contains these fixes. As soon as I install and test it in the production environments I let you know. Tks a lot!

[Former Member]

Unfortunatelly the patch didn't solve the issue. The sequence id errors continue to happen. As soon as I have the logs I update the question with more informations.

[VolkerBarth]

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:)

[chris_keating]

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.

[Former Member]

I've reproduced an scenario which leads to this issue (and I hope all the others derives from this one, for the sake of simplicity =p)

Steps to reproduce (using an Android device with UltraliteJ 16 2127):

1) Synchronize the client 2) As soon as the message "COMMIT Transaction: Download" is logged on the Mobilink log, close the application 3) Start the application again the synchronize the client. The error will occurs.

Note that the first synchronization hangs on the connection until the timeout of this connection is reached.

I've tried different sync parameters, even enabling/disabling the download ack, but without success.

Can I consider this issue as a bug?

I. 2015-08-27 16:50:40. <435> Request from "UL 16.0.2127" for: remote ID: 2, user name: 24, version: XXX
I. 2015-08-27 16:50:40. <435> The current synchronization is using a connection with connection ID 'SPID 357'
I. 2015-08-27 16:50:40. <435> The authenticate_parameters script returned 1000
I. 2015-08-27 16:50:40. <435> COMMIT Transaction: Authenticate user
I. 2015-08-27 16:50:40. <435> Publication #1: ul_default_pub, subscription id: 1, last download time: 2015-08-27 16:50:23.517000
I. 2015-08-27 16:50:40. <435> The sync sequence ID in the consolidated database: 8fbe74104cc211e58000a93d68080ea7; the remote previous sequence ID: 8fbe74104cc211e58000a93d68080ea7, and the current sequence ID: 992957904cc211e58000a93d68080ea7
I. 2015-08-27 16:50:40. <435> Last upload time for subscription id 1: 2015-08-27 15:41:13.180000
I. 2015-08-27 16:50:40. <435> Generation number for publication 'ul_default_pub' is 1
I. 2015-08-27 16:50:40. <435> COMMIT Transaction: Begin synchronization
I. 2015-08-27 16:50:40. <435> COMMIT Transaction: Prepare for download
I. 2015-08-27 16:50:40. <435> Next last download timestamp fetched from the consolidated database is "2015-08-27 16:50:39.337000"
I. 2015-08-27 16:50:41. <435> Sending the download to the remote database
I. 2015-08-27 16:50:41. <435> COMMIT Transaction: Download
I. 2015-08-27 16:50:47. <435> COMMIT Transaction: End synchronization
I. 2015-08-27 16:51:13. <436> Request from "UL 16.0.2127" for: remote ID: 2, user name: 24, version: XXX
I. 2015-08-27 16:51:13. <436> The current synchronization is using a connection with connection ID 'SPID 357'
I. 2015-08-27 16:51:13. <436> The authenticate_parameters script returned 1000
I. 2015-08-27 16:51:13. <436> COMMIT Transaction: Authenticate user
I. 2015-08-27 16:51:13. <436> Publication #1: ul_default_pub, subscription id: 1, last download time: 2015-08-27 16:50:23.517000
I. 2015-08-27 16:51:13. <436> The sync sequence ID in the consolidated database: 992957904cc211e58000a93d68080ea7; the remote previous sequence ID: 8fbe74104cc211e58000a93d68080ea7, and the current sequence ID: ad024bd24cc211e58000e6d39f5d0b49
E. 2015-08-27 16:51:13. <436> [-10400] Invalid sync sequence ID for remote ID '2'
I. 2015-08-27 16:51:13. <436> Synchronization failed
E. 2015-08-27 16:54:48. <435> [-10279] Connection was dropped due to lack of network activity
I. 2015-08-27 16:54:48. <435> Synchronization complete

[Former Member]

As I feared, for a download-only sync killing the app before UltraLite has finished a sync may leave the UltraLite database in a bad state.

As a workaround, try disabling the Download Only sync parameter in your Android application.

To avoid any changes from remotes being applied to the consolidated database, for each synchronized table define upload_insert and upload_update scripts as '--{ml_ignore}'. That will prevent any changes from the remotes, equivalent to using download-only syncs.

[Former Member]

We are not using the download-only parameter. In this case, the Ultralite is skipping the upload because there is no data to upload. So, this workaround is not valid for us. Any other possible workaround?

[Former Member]

Another developer double checked the MobiLink server source code, and you would have upload commit messages in the log if your app is doing bidirectional syncs. Look for calls to SyncParms.setDownloadOnly (and maybe call that with false).

BTW, instead of recreating a remote after the problem hits, you should be able to get that remote syncing again by using the ml_reset_sync_state stored procedure.

[Former Member]

Sorry Graham, you were right. In my reproduction I was using the download-only configuration. With download/upload syncs I couldn't reproduce this issue. I've already known this procedure to reset the sync state, tks. We've been using it for months. This sequence ID issue could be reproduced more frequently in old versions of Mobilink. Subsequentials canceled syncs could lead to this issue. But we've got rid of a part of these issues (about canceled/restarted syncs) after migrating to the 2127 patch. We've still some users dealing with this sequence ID error, as reported in other questions, like the following one. I hope you guys have a better luck looking into this =] http://scn.sap.com/message/15859094#15859094

[Former Member]

Graham, the sequence ID error has happened again with a dozen of users in the last week. All the users had performed download/upload operations, instead of the download-only scenario that I've reproduced. Could you check the third code of my question to analyze it? I couldn't reproduce this scenario, but checking the logs, it seems the Ultralite is accepting a new sync request before finishing the last operation (that failed with connectivity issues).