Getting the error in database logs : 14564 [ERROR] /glide/mysql/bin/mysqld: Sort aborted: Query execution was interrupted .

johnsonjacob
Kilo Contributor

We are using On premisis ServiceNow Instance. In the mysql logs we are getting the below error.

14564 [ERROR] /glide/mysql/bin/mysqld: Sort aborted: Query execution was interrupted .

Please advise whether we need to change any parameter from database side. The current sort_buffer_size is set as 1MB.

5 REPLIES 5

sergiu_panaite
ServiceNow Employee
ServiceNow Employee

I've seen this a few times as well on our cloud. It can happen if a user triggers a transaction that starts a SQL statement on database side, then user kills the transaction from UI (which would send a kill signal on the SQL statement on database side while SQL is in the middle of a filesort).


You could probably play with sort_buffer_size but 1MB should be enough from my point of view. If a user canceled the transaction you can see it in the localhost_log (at same time the MySQL log shows the error) and then Enable SQL in the UI and try to do same transaction as the user and capture the SQL statement (you can also capture it directly from database while the transaction is running from UI, especially if it takes longer).


Thank you Sergiu for the reply.



In the logs I can see many transactions getting cancelled after some waiting time and the MySQL log is flooding every minute with 'sort aborted' error. How we can get ride of this kind of warnings.   Did I need to look into any other parameters.


find_real_file.png


This is not a database issue, but more of a symptom.


The warning "cancelled by other transaction" can happen if a user clicks un-patiently almost at the same time on different things (you can see that they are usually cancelled pretty fast, most of the time in less than 1s, for more information on the message see here). A user action can cause multiple transactions to be triggered on server side. As an example if a user loads an incident form, there could be several AJAX calls (xmlhttp.do) for different things, like form fields, etc that will be run after the initial form has loaded, but if the user clicks on something else before the form is loaded completely (so these transactions are in the queue but have not started yet), some of these transactions might get cancelled.


So, from my point of view the warnings you see in the transaction logs of the instance are not causing the MySQL errors.



What you can probably do here is to set temporarily "log_warnings=2" in MySQL and then you should see the query that gets aborted in mysqld.log, something like explain here:



Sort aborted: Query execution was interrupted - Percona Community



Once you get the query if you post the explain plan on it, I can advise if it has the proper indexes or require some new ones.


Below see couple of queries fetched from the mysql log after setting log_warning = 2. Most of the sort aborted queries is from the same table sys_users



===================================================================================================================


2017-07-26 10:23:59 14564 [Warning] Sort aborted, host: xxxx, user: xxxx, thread: 257851, query: /* xxxx004, gs:B767A27FD5C8C300E485B253E62BDD74, tx:bac7cf33d58cc300e485b253e62bdd16 */ SELECT sys_user0.`sys_id` FROM sys_user sys_user0   WHERE (sys_user0.`name` LIKE 'b%' OR sys_user0.`user_name` LIKE 'b%' OR sys_user0.`email` LIKE 'b%') AND sys_user0.`sys_id` NOT IN ('019235fe44511200e4852779951f5523' , '393e1b83d03112009d047c6a77006ef5' , 'e761357e145112009d0437ccc8335736' , 'e24574a5a5c083009d048ebee33bdd1c' , '9b513dbe44511200e4852779951f55a6') AND sys_user0.`active` = 1 ORDER BY sys_user0.`name`,sys_user0.`user_name`,sys_user0.`email` limit 0,250



2017-07-26 10:25:36 14564 [Warning] Sort aborted, host: xxxx, user: xxxx, thread: 257861, query: /* xxxx004, gs:A6570FFFD54CC300E485B253E62BDD46, tx:72874333d58cc300e485b253e62bddd0 */ SELECT sys_journal_field0.`sys_id` FROM sys_journal_field sys_journal_field0   ORDER BY sys_journal_field0.`name` limit 0,100



2017-07-26 10:28:56 14564 [Warning] Sort aborted, host: xxxx, user: xxxx, thread: 257774, query: /* xxxx006, gs:2B7B6973D5C08700E4850C685592A62B, tx:47e847ffd5488700e4850c685592a6f4 */ SELECT sys_user0.`sys_id` FROM sys_user sys_user0   WHERE (sys_user0.`name` LIKE 's%' OR sys_user0.`user_name` LIKE 's%' OR sys_user0.`email` LIKE 's%') AND sys_user0.`active` = 1 ORDER BY sys_user0.`name`,sys_user0.`user_name`,sys_user0.`email` limit 0,250



2017-07-26 10:28:58 14564 [Warning] Sort aborted, host: xxxx, user: xxxx, thread: 257937, query: /* xxxx003, gs:9B288B73614C87009D0453A5E3A83980, tx:3be88373614c87009d0453a5e3a83952 */ SELECT sys_user0.`sys_id` FROM sys_user sys_user0   WHERE (sys_user0.`name` LIKE 'A%' OR sys_user0.`user_name` LIKE 'A%' OR sys_user0.`email` LIKE 'A%') AND sys_user0.`active` = 1 ORDER BY sys_user0.`name`,sys_user0.`user_name`,sys_user0.`email` limit 0,250



2017-07-26 10:29:18 14564 [Warning] Sort aborted, host: xxxx, user: xxxx, thread: 257815, query: /* xxxx006, gs:2B7B6973D5C08700E4850C685592A62B, tx:a4090fffd5488700e4850c685592a620 */ SELECT sys_user0.`sys_id` FROM sys_user sys_user0   WHERE (sys_user0.`name` LIKE 'b%' OR sys_user0.`user_name` LIKE 'b%' OR sys_user0.`email` LIKE 'b%') AND sys_user0.`active` = 1 ORDER BY sys_user0.`name`,sys_user0.`user_name`,sys_user0.`email` limit 0,250



2017-07-26 10:29:25 14564 [Warning] Aborted connection 257978 to db: 'unconnected' user: 'xxxx' host: 'xxxx' (Got an error reading communication packets)



============================================================================================================================



Explain plain



mysql> explain SELECT sys_user0.`sys_id` FROM sys_user sys_user0   WHERE (sys_user0.`name` LIKE 'A%' OR sys_user0.`user_name` LIKE 'A%' OR sys_user0.`email` LIKE 'A%') AND sys_user0.`active` = 1 ORDER BY sys_user0.`name`,sys_user0.`user_name`,sys_user0.`email` limit 0,250\G


*************************** 1. row ***************************


                    id: 1


  select_type: SIMPLE


              table: sys_user0


                type: ref


possible_keys: user_name_2,active,name,email,user_name


                  key: active


          key_len: 2


                  ref: const


                rows: 165869


              Extra: Using where; Using filesort


1 row in set (0.00 sec)