I have recently migrated a client server which has started to produce this error in the mobilink logs. These deadlocks occur almost everyday.

'ml_database' locked (ODBC State = 40001, Native error code = -210) Unable to lock the remote ID '...', will try again

I copied the .db and .log files from the old server shut it down and pasted the files to new server. The network database server and mobilink server started back up just fine.

I have applied the latest EBF MobiLink 12 12.0.1.4086 which has not fixed the issue.

There are about 15 users syncing on the server.

Please let me know if you need more information.

I. 2014-05-07 00:24:43. <72> (,rdhaliwal) begin_synchronization AMessage (no script)
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) begin_synchronization DataFormLine (no script)
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) begin_synchronization DataFormLineEnum (no script)
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) begin_synchronization DataFormRole (no script)
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) begin_synchronization FS_DataFormRegion (no script)
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) begin_synchronization FS_DataFormCustomer (no script)
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) begin_synchronization FS_RoleItemFavourite (no script)
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) begin_synchronization FS_UserRegion (no script)
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) begin_synchronization FS_WorkOrderItemUserShortcut (no script)
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) begin_synchronization FS_WorkOrderItemTemplateItemList (no script)
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) begin_synchronization FS_CustomerSiteItemAccount (no script)
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) begin_synchronization FS_UserItemFavourite (no script)
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) begin_synchronization FS_TimeTypeBonus (no script)
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) begin_synchronization FS_TimeTypeTrade (no script)
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) begin_synchronization DataFormBusinessUnit (no script)
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) begin_synchronization LicenseKeyType (no script)
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) begin_synchronization DataFormResultLine (no script)
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) begin_synchronization ParameterBusinessUnit (no script)
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) begin_publication <connection>
                        call asi_BeginPublication({ml s.publication_name}, {ml ui.statisticID}, {ml s.username})
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) System variable publication_name value: ul_default_pub
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) User variable statisticID value: fcac12c4-914b-4fa9-8c6c-e3b29d0fe873
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) System variable username value: rdhaliwal
I. 2014-05-07 00:24:43. <72> (,rdhaliwal) Translated SQL:
                        call asi_BeginPublication( ?,  ?,  ?)
I. 2014-05-07 00:24:52. <main> System event on shared administrative connection:
                        SELECT property_set_name, property_name, property_value FROM ml_property WHERE component_name = ? ORDER BY property_set_name 
I. 2014-05-07 00:24:52. <main> Translated SQL:
                        SELECT property_set_name, property_name, property_value FROM ml_property WHERE component_name = ? ORDER BY property_set_name 
I. 2014-05-07 00:25:26. <main> System event on shared administrative connection:
                        SELECT count(*) FROM ml_passthrough_script
I. 2014-05-07 00:25:26. <main> Translated SQL:
                        SELECT count(*) FROM ml_passthrough_script
I. 2014-05-07 00:25:53. <main> System event on shared administrative connection:
                        SELECT property_set_name, property_name, property_value FROM ml_property WHERE component_name = ? ORDER BY property_set_name 
I. 2014-05-07 00:25:53. <main> Translated SQL:
                        SELECT property_set_name, property_name, property_value FROM ml_property WHERE component_name = ? ORDER BY property_set_name 
E. 2014-05-07 00:26:00. <71> (,rnorton) [-10279] Connection was dropped due to lack of network activity
I. 2014-05-07 00:26:27. <main> System event on shared administrative connection:
                        SELECT count(*) FROM ml_passthrough_script
I. 2014-05-07 00:26:27. <main> Translated SQL:
                        SELECT count(*) FROM ml_passthrough_script
I. 2014-05-07 00:26:53. <main> System event on shared administrative connection:
                        SELECT property_set_name, property_name, property_value FROM ml_property WHERE component_name = ? ORDER BY property_set_name 
I. 2014-05-07 00:26:53. <main> Translated SQL:
                        SELECT property_set_name, property_name, property_value FROM ml_property WHERE component_name = ? ORDER BY property_set_name 
I. 2014-05-07 00:27:28. <main> System event on shared administrative connection:
                        SELECT count(*) FROM ml_passthrough_script
I. 2014-05-07 00:27:28. <main> Translated SQL:
                        SELECT count(*) FROM ml_passthrough_script
I. 2014-05-07 00:27:54. <main> System event on shared administrative connection:
                        SELECT property_set_name, property_name, property_value FROM ml_property WHERE component_name = ? ORDER BY property_set_name 
I. 2014-05-07 00:27:54. <main> Translated SQL:
                        SELECT property_set_name, property_name, property_value FROM ml_property WHERE component_name = ? ORDER BY property_set_name 
I. 2014-05-07 00:28:29. <main> System event on shared administrative connection:
                        SELECT count(*) FROM ml_passthrough_script
I. 2014-05-07 00:28:29. <main> Translated SQL:
                        SELECT count(*) FROM ml_passthrough_script
I. 2014-05-07 00:28:54. <main> System event on shared administrative connection:
                        SELECT property_set_name, property_name, property_value FROM ml_property WHERE component_name = ? ORDER BY property_set_name 
I. 2014-05-07 00:28:54. <main> Translated SQL:
                        SELECT property_set_name, property_name, property_value FROM ml_property WHERE component_name = ? ORDER BY property_set_name 
I. 2014-05-07 00:29:06. <main> System event on shared administrative connection:
                        select 1, property_name, cast(property_value as char(254)) from ml_property where component_name = 'MLS' AND property_set_name = 'ml_user_log_verbosity' union select 2, property_name, cast(property_value as char(254)) from ml_property where component_name = 'MLS' AND property_set_name = 'ml_remote_id_log_verbosity'
I. 2014-05-07 00:29:06. <main> Translated SQL:
                        select 1, property_name, cast(property_value as char(254)) from ml_property where component_name = 'MLS' AND property_set_name = 'ml_user_log_verbosity' union select 2, property_name, cast(property_value as char(254)) from ml_property where component_name = 'MLS' AND property_set_name = 'ml_remote_id_log_verbosity'
I. 2014-05-07 00:29:31. <main> System event on shared administrative connection:
                        SELECT count(*) FROM ml_passthrough_script
I. 2014-05-07 00:29:31. <main> Translated SQL:
                        SELECT count(*) FROM ml_passthrough_script
I. 2014-05-07 00:29:54. <main> System event on shared administrative connection:
                        SELECT property_set_name, property_name, property_value FROM ml_property WHERE component_name = ? ORDER BY property_set_name 
I. 2014-05-07 00:29:54. <main> Translated SQL:
                        SELECT property_set_name, property_name, property_value FROM ml_property WHERE component_name = ? ORDER BY property_set_name 
I. 2014-05-07 00:30:32. <main> System event on shared administrative connection:
                        SELECT count(*) FROM ml_passthrough_script
I. 2014-05-07 00:30:32. <main> Translated SQL:
                        SELECT count(*) FROM ml_passthrough_script
I. 2014-05-07 00:30:55. <main> System event on shared administrative connection:
                        SELECT property_set_name, property_name, property_value FROM ml_property WHERE component_name = ? ORDER BY property_set_name 
I. 2014-05-07 00:30:55. <main> Translated SQL:
                        SELECT property_set_name, property_name, property_value FROM ml_property WHERE component_name = ? ORDER BY property_set_name 
I. 2014-05-07 00:31:33. <main> System event on shared administrative connection:
                        SELECT count(*) FROM ml_passthrough_script
I. 2014-05-07 00:31:33. <main> Translated SQL:
                        SELECT count(*) FROM ml_passthrough_script
I. 2014-05-07 00:31:56. <main> System event on shared administrative connection:
                        SELECT property_set_name, property_name, property_value FROM ml_property WHERE component_name = ? ORDER BY property_set_name 
I. 2014-05-07 00:31:56. <main> Translated SQL:
                        SELECT property_set_name, property_name, property_value FROM ml_property WHERE component_name = ? ORDER BY property_set_name 
I. 2014-05-07 00:32:35. <main> System event on shared administrative connection:
                        SELECT count(*) FROM ml_passthrough_script
I. 2014-05-07 00:32:35. <main> Translated SQL:
                        SELECT count(*) FROM ml_passthrough_script
I. 2014-05-07 00:32:56. <main> System event on shared administrative connection:
                        SELECT property_set_name, property_name, property_value FROM ml_property WHERE component_name = ? ORDER BY property_set_name 
I. 2014-05-07 00:32:56. <main> Translated SQL:
                        SELECT property_set_name, property_name, property_value FROM ml_property WHERE component_name = ? ORDER BY property_set_name 
I. 2014-05-07 00:33:36. <main> System event on shared administrative connection:
                        SELECT count(*) FROM ml_passthrough_script
I. 2014-05-07 00:33:36. <main> Translated SQL:
                        SELECT count(*) FROM ml_passthrough_script
I. 2014-05-07 00:33:57. <main> System event on shared administrative connection:
                        SELECT property_set_name, property_name, property_value FROM ml_property WHERE component_name = ? ORDER BY property_set_name 
I. 2014-05-07 00:33:57. <main> Translated SQL:
                        SELECT property_set_name, property_name, property_value FROM ml_property WHERE component_name = ? ORDER BY property_set_name 
I. 2014-05-07 00:34:11. <main> System event on shared administrative connection:
                        select 1, property_name, cast(property_value as char(254)) from ml_property where component_name = 'MLS' AND property_set_name = 'ml_user_log_verbosity' union select 2, property_name, cast(property_value as char(254)) from ml_property where component_name = 'MLS' AND property_set_name = 'ml_remote_id_log_verbosity'
I. 2014-05-07 00:34:11. <main> Translated SQL:
                        select 1, property_name, cast(property_value as char(254)) from ml_property where component_name = 'MLS' AND property_set_name = 'ml_user_log_verbosity' union select 2, property_name, cast(property_value as char(254)) from ml_property where component_name = 'MLS' AND property_set_name = 'ml_remote_id_log_verbosity'
I. 2014-05-07 00:34:14. <73> (,rnorton) Request from "UL 12.0.1.3605" for: remote ID: b06d1b50-870a-11e3-8000-ec206ffcadef, user name: rnorton, version: FieldServiceV3_3_8
I. 2014-05-07 00:34:14. <73> (,rnorton) System event on shared administrative connection:
                        SELECT user_id FROM ml_user WHERE name = ?
I. 2014-05-07 00:34:14. <73> (,rnorton) Translated SQL:
                        SELECT user_id FROM ml_user WHERE name = ?
I. 2014-05-07 00:34:14. <73> (,rnorton) System event on shared administrative connection:
                        SET TEMPORARY OPTION blocking='off'
I. 2014-05-07 00:34:14. <73> (,rnorton) Translated SQL:
                        SET TEMPORARY OPTION blocking='off'
I. 2014-05-07 00:34:14. <73> (,rnorton) System event on shared administrative connection:
                        SELECT rid, sync_key FROM ml_database WHERE remote_id = ?
I. 2014-05-07 00:34:14. <73> (,rnorton) Translated SQL:
                        SELECT rid, sync_key FROM ml_database WHERE remote_id = ?
W. 2014-05-07 00:34:14. <73> (,rnorton) [10050] ODBC: [Sybase][ODBC Driver][SQL Anywhere]User 'AWADMIN' has the row in 'ml_database' locked (ODBC State = 40001, Native error code = -210)
I. 2014-05-07 00:34:14. <73> (,rnorton) System event on shared administrative connection:
                        SET TEMPORARY OPTION blocking='on'
I. 2014-05-07 00:34:14. <73> (,rnorton) Translated SQL:
                        SET TEMPORARY OPTION blocking='on'
W. 2014-05-07 00:34:14. <73> (,rnorton) [10106] Unable to lock the remote ID 'b06d1b50-870a-11e3-8000-ec206ffcadef', will try again
I. 2014-05-07 00:34:14. <73> (,rnorton) System event on shared administrative connection:
                        SELECT user_id FROM ml_user WHERE name = ?
I. 2014-05-07 00:34:14. <73> (,rnorton) Translated SQL:
                        SELECT user_id FROM ml_user WHERE name = ?
I. 2014-05-07 00:34:14. <73> (,rnorton) System event on shared administrative connection:
                        SET TEMPORARY OPTION blocking='off'
I. 2014-05-07 00:34:14. <73> (,rnorton) Translated SQL:
                        SET TEMPORARY OPTION blocking='off'
I. 2014-05-07 00:34:14. <73> (,rnorton) System event on shared administrative connection:
                        SELECT rid, sync_key FROM ml_database WHERE remote_id = ?
I. 2014-05-07 00:34:14. <73> (,rnorton) Translated SQL:
                        SELECT rid, sync_key FROM ml_database WHERE remote_id = ?
W. 2014-05-07 00:34:14. <73> (,rnorton) [10050] ODBC: [Sybase][ODBC Driver][SQL Anywhere]User 'AWADMIN' has the row in 'ml_database' locked (ODBC State = 40001, Native error code = -210)
I. 2014-05-07 00:34:14. <73> (,rnorton) System event on shared administrative connection:
                        SET TEMPORARY OPTION blocking='on'
I. 2014-05-07 00:34:14. <73> (,rnorton) Translated SQL:
                        SET TEMPORARY OPTION blocking='on'
W. 2014-05-07 00:34:14. <73> (,rnorton) [10106] Unable to lock the remote ID 'b06d1b50-870a-11e3-8000-ec206ffcadef', will try again
I. 2014-05-07 00:34:15. <73> (,rnorton) System event on shared administrative connection:
                        SELECT user_id FROM ml_user WHERE name = ?
I. 2014-05-07 00:34:15. <73> (,rnorton) Translated SQL:
                        SELECT user_id FROM ml_user WHERE name = ?
I. 2014-05-07 00:34:15. <73> (,rnorton) System event on shared administrative connection:
                        SET TEMPORARY OPTION blocking='off'
I. 2014-05-07 00:34:15. <73> (,rnorton) Translated SQL:
                        SET TEMPORARY OPTION blocking='off'
I. 2014-05-07 00:34:15. <73> (,rnorton) System event on shared administrative connection:
                        SELECT rid, sync_key FROM ml_database WHERE remote_id = ?
I. 2014-05-07 00:34:15. <73> (,rnorton) Translated SQL:
                        SELECT rid, sync_key FROM ml_database WHERE remote_id = ?
W. 2014-05-07 00:34:15. <73> (,rnorton) [10050] ODBC: [Sybase][ODBC Driver][SQL Anywhere]User 'AWADMIN' has the row in 'ml_database' locked (ODBC State = 40001, Native error code = -210)
I. 2014-05-07 00:34:15. <73> (,rnorton) System event on shared administrative connection:
                        SET TEMPORARY OPTION blocking='on'
I. 2014-05-07 00:34:15. <73> (,rnorton) Translated SQL:
                        SET TEMPORARY OPTION blocking='on'
W. 2014-05-07 00:34:15. <73> (,rnorton) [10106] Unable to lock the remote ID 'b06d1b50-870a-11e3-8000-ec206ffcadef', will try again
I. 2014-05-07 00:34:16. <73> (,rnorton) System event on shared administrative connection:
                        SELECT user_id FROM ml_user WHERE name = ?
I. 2014-05-07 00:34:16. <73> (,rnorton) Translated SQL:
                        SELECT user_id FROM ml_user WHERE name = ?
I. 2014-05-07 00:34:16. <73> (,rnorton) System event on shared administrative connection:
                        SET TEMPORARY OPTION blocking='off'
I. 2014-05-07 00:34:16. <73> (,rnorton) Translated SQL:
                        SET TEMPORARY OPTION blocking='off'
I. 2014-05-07 00:34:16. <73> (,rnorton) System event on shared administrative connection:
                        SELECT rid, sync_key FROM ml_database WHERE remote_id = ?
I. 2014-05-07 00:34:16. <73> (,rnorton) Translated SQL:
                        SELECT rid, sync_key FROM ml_database WHERE remote_id = ?

asked 06 May '14, 12:38

AdeelSHAHID's gravatar image

AdeelSHAHID
61117
accept rate: 0%

edited 07 May '14, 08:46

Please run mlsrv12 with the -o option to capture diagnostic information to a text file, and the -vcefhkmnopstuU option to increase verbosity. Then paste the file into your question (type <pre> and </pre> tags around the text to stop the formatting).

(06 May '14, 14:34) Breck Carter

The issue was with a batch file not using -nogui under sybase 12 causing the interactive sql window to remain open in the background and causing a lock when the over right process ran. I believe this switch is not required in sybase 11.

permanent link

answered 14 May '14, 08:31

AdeelSHAHID's gravatar image

AdeelSHAHID
61117
accept rate: 0%

Thanks for sharing the solution.

(14 May '14, 08:55) Reg Domaratzki
permanent link

answered 06 May '14, 14:39

Breck%20Carter's gravatar image

Breck Carter
32.5k5417261050
accept rate: 20%

Thanks Breck, I had reviewed this question before I posted mine. I have updated my question with verbose ml logs.

(07 May '14, 08:49) AdeelSHAHID
Replies hidden

The log doesn't show earlier activity; e.g., it doesn't show when the various synchronizations started.

The following "Connection was dropped" message is very suspicious; please show us the command line used to start mlsrv12.exe.

You may have to call tech support to resolve this problem.

E. 2014-05-07 00:26:00. <71> (,rnorton) [-10279] Connection was dropped due to lack of network activity
...
I. 2014-05-07 00:34:14. <73> (,rnorton) Request from "UL 12.0.1.3605" for: remote ID: b06d1b50-870a-11e3-8000-ec206ffcadef, user name: rnorton, version: FieldServiceV3_3_8
(07 May '14, 10:15) Breck Carter

I added the -tf switch to kill hung connections, but mobilink kept on retrying and the following log messages were recorded:

W. <227> [10050] ODBC: [Sybase][ODBC Driver][SQL Anywhere]User 'AWADMIN' has the row in 'PushRequest_non_sync' locked (ODBC State = 40001, Native error code = -210)
W. <227> [10048] Retrying the begin_synchronization transaction after deadlock in the consolidated database
E. <227> [-10002] Consolidated database server or ODBC error:  ODBC: [Sybase][ODBC Driver][SQL Anywhere]Item '#FS_InventoryTrans' already exists (ODBC State = 42S01

(08 May '14, 13:15) AdeelSHAHID
-c "dsn=FSv32_Scottys" -tf -v n -x tcpip{port=2400} -x http{port=2401} -ct 5 -s 100 -o D:\APEX\DB\FSv32_Scottys_ML.txt -os 2m -w 20 -wu 10 -cn 20 -zs FSv32_Scottys
(08 May '14, 13:31) AdeelSHAHID
Comment Text Removed

Is there a reason you didn't specify the -vcefhkmnopstuU option as suggested earlier?

The -os 2m option tells mlsrv12.exe to rename and restart the -o file, so look around for files named yymmddxx.mls which contain the earlier diagnostic data.

On a busy system, -os 2m will restart the -o file too rapidly for easy diagnostic work. Modern text browsers and editors can easily let you search much larger files, so set it to at least -os 10m... or larger if there's a lot of traffic.

Is there some reason you have specified -ct 5? If you don't have any specific documented explainable reason for such a radical setting, take it out... the rule of thumb with all of this software is to leave the defaults alone unless you absolutely positively know what you're doing.

Do you have reasons for all the settings -s 100 -w 20 -wu 10 -cn 20? Same as above... if you don't have reasons for those settings, rip them out. Many problems are caused by administrators browsing through the docs and picking option settings on a whim... I AM NOT SAYING THAT IS THE CASE HERE, but the statement "The log doesn't show earlier activity" does show a certain [cough] misunderstanding of the options.

(09 May '14, 11:27) Breck Carter

99.999% of the time deadlock is a design error, not in MobiLink but in the application which in this case includes the synchronization scripts, database triggers and so on. We can help if you show us the code... without seeing the code, we can make wild guesses :)

At the very least, show us all ALL the code that touches PushRequest_non_sync, and tell us what user ASADMIN is used for.

(09 May '14, 11:30) Breck Carter
showing 1 of 6 show all flat view
Your answer
toggle preview

Follow this question

By Email:

Once you sign in you will be able to subscribe for any updates here

By RSS:

Answers

Answers and Comments

Markdown Basics

  • *italic* or _italic_
  • **bold** or __bold__
  • link:[text](http://url.com/ "title")
  • image?![alt text](/path/img.jpg "title")
  • numbered list: 1. Foo 2. Bar
  • to add a line break simply add two spaces to where you would like the new line to be.
  • basic HTML tags are also supported

Question tags:

×371
×37
×34
×21

question asked: 06 May '14, 12:38

question was seen: 6,123 times

last updated: 14 May '14, 08:55