Sort aborted: Query execution was interrupted

[flavio.tobias]

I have a Percona XtraDB cluster 5.6 with 3 nodes, however few hours ago it started to log the following error message:
18566 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted

The bootstrap node has crashed and few hours later the other two nodes did crash too.

I have restarted all three nodes but I still getting this error on the log.

I read few threads about this problem but none of them gave me an answer.
I’d increase the sort_buffer_size to 7MB, my disk has plenty space, my Galera is 3.8.

This message are being logged by all three nodes.

Does anyone have an idea of what is happening?

Thanks,

[mirfan]

I noticed this error usually occurs with queries does sorting i.e. queries with ORDER BY non_index_column. You can monitor sort_merge_passes variable to verify If sort_buffer_size is set appropriately or not, check further in manual. This particular occurs when you kill/interrupt query in middle. I also had written blogpost you may find useful https://www.percona.com/blog/2013/12/30/error-mysqld-sort-aborted-server-shutdown-in-progress/

[flavio.tobias]

Hi Muhammad, thank you very much for the attention.
I have read your post yestarday while I was looking for a solution, but the situation you describe there does not look like what I’m facing here.

All three server are running, as you can see on the timestamp of the messages below, the messages appear to be being logged randomically.
I’d check the sort_merge_passes as you asked and looks OK, I’m getting 0 constantly on all three nodes.

Is there someway to find out which query is triggering this message?

2015-05-16 15:51:49 23767 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted
2015-05-16 15:51:53 23767 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted
2015-05-16 15:52:41 23767 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted
2015-05-16 15:52:47 23767 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted
2015-05-16 15:58:19 23767 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted
2015-05-16 15:59:43 23767 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted
2015-05-16 15:59:44 23767 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted
2015-05-16 16:02:06 23767 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted
2015-05-16 16:02:10 23767 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted
2015-05-16 16:03:06 23767 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted
2015-05-16 16:03:11 23767 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted
2015-05-16 16:03:19 23767 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted
2015-05-16 16:03:21 23767 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted
2015-05-16 16:03:24 23767 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted
2015-05-16 16:03:26 23767 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted

Thanks again,

[shahzaibcb]

Hi,

We’re also getting ‘Abort’ messages in error log. It looks to us percona mysql server intermittently restarting and causing these errors but not sure about it . Following is the sample error log :

141221 23:11:21 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted
141221 23:11:21 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted
141221 23:11:21 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted
141221 23:11:21 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted
141221 23:11:23 InnoDB: Starting shutdown…
141221 23:11:24 InnoDB: Waiting for 156 pages to be flushed
141221 23:11:28 InnoDB: Shutdown completed; log sequence number 81825329988
141221 23:11:28 [Note] /usr/sbin/mysqld: Shutdown complete

141221 23:11:29 mysqld_safe mysqld from pid file /var/lib/mysql/db.tune.pk.pid ended
141221 23:11:29 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
141221 23:11:29 [Note] Plugin ‘FEDERATED’ is disabled.
141221 23:11:29 InnoDB: The InnoDB memory heap is disabled
141221 23:11:29 InnoDB: Mutexes and rw_locks use GCC atomic builtins
141221 23:11:29 InnoDB: Compressed tables use zlib 1.2.3
141221 23:11:29 InnoDB: Using Linux native AIO
141221 23:11:29 InnoDB: Initializing buffer pool, size = 12.0G
141221 23:11:30 InnoDB: Completed initialization of buffer pool
141221 23:11:30 InnoDB: highest supported file format is Barracuda.
141221 23:11:31 InnoDB: Waiting for the background threads to start
141221 23:11:32 Percona XtraDB (http://www.percona.com) 5.5.35-rel33.0 started; log sequence number 81825329988
141221 23:11:32 [Warning] ‘proxies_priv’ entry ‘@ root@db2.adzmedia.com’ ignored in --skip-name-resolve mode.
141221 23:11:32 [Warning] Neither --relay-log nor --relay-log-index were used; so replication may break when this MySQL server acts as a slave and has his hostname changed!! Please use ‘–relay-log=db-relay-bin’ to avoid this problem.
141221 23:11:32 [ERROR] Failed to open the relay log ‘./db2-relay-bin.000008’ (relay_log_pos 251)
141221 23:11:32 [ERROR] Could not find target log during relay log initialization
141221 23:11:32 [ERROR] Failed to initialize the master info structure
141221 23:11:32 [Note] Event Scheduler: Loaded 0 events
141221 23:11:32 [Note] /usr/sbin/mysqld: ready for connections.
Version: ‘5.5.35-33.0-log’ socket: ‘/var/lib/mysql/mysql.sock’ port: 3306 Percona Server (GPL), Release rel33.0, Revision 611
141222 00:05:00 mysqld_safe Number of processes running now: 0
141222 00:05:00 mysqld_safe mysqld restarted

[root@db mysql]# mysql -V
mysql Ver 14.14 Distrib 5.5.36-34.2, for Linux (x86_64) using readline 5.1

Thanks.
Shahzaib

[mirfan]

To track aborted connection source I would suggest to try solutions described here https://www.percona.com/blog/2008/08/23/how-to-track-down-the-source-of-aborted_connects/ and check if you are impacted by any possible causes listed here https://dev.mysql.com/doc/refman/5.5/en/communication-errors.html
“Sort Aborted” errors can be identified by enabling general query log for some period (beware it will eat up disk space quickly) and then match timestamp with timestamp reported in error log may be. Is there any possibility that some cron/monitoring tool kills query in middle of execution or MySQL server restarts ?

[wagnerbianchi]

If you set the log_warnings=2, the interrupted query is written the error log and the you can check it using tail.

[bianchi@dbxserver101 logs]$ my_print_defaults mysqld | grep log-warnings
--log-warnings=2

2015-06-10 16:11:19 12964 [ERROR] /usr/sbin/mysqld: Sort aborted: Query execution was interrupted
2015-06-10 16:11:19 12964 [Warning] Sort aborted, host: 10.172.16.19, user: dbx, thread: 5932641, query: SELECT [...]

Try this out!