Airflow scheduler is restarting due to "Out of sort memory, consider increasing server sort buffer size"

[Huthesh]

Hi Team,

Airflow scheduler service is restarting due to "Out of sort memory, consider increasing server sort buffer size"
Seeing following stack strace in log.

Need your assistance to solve this problem.

Thanks

2025-03-07_04:14:14.99425 [2025-03-07T04:14:14.989+0000] {scheduler_job_runner.py:1016} ERROR - Exception when executing SchedulerJob._run_scheduler_loop 2025-03-07_04:14:14.99427 Traceback (most recent call last): 2025-03-07_04:14:14.99427 File "/usr/local/lib64/python3.11/site-packages/sqlalchemy/engine/base.py", line 1910, in _execute_context 2025-03-07_04:14:14.99428 self.dialect.do_execute( 2025-03-07_04:14:14.99428 File "/usr/local/lib64/python3.11/site-packages/sqlalchemy/engine/default.py", line 736, in do_execute 2025-03-07_04:14:14.99428 cursor.execute(statement, parameters) 2025-03-07_04:14:14.99428 File "/usr/local/lib/python3.11/site-packages/pymysql/cursors.py", line 153, in execute 2025-03-07_04:14:14.99429 result = self._query(query) 2025-03-07_04:14:14.99429 ^^^^^^^^^^^^^^^^^^ 2025-03-07_04:14:14.99430 File "/usr/local/lib/python3.11/site-packages/pymysql/cursors.py", line 322, in _query 2025-03-07_04:14:14.99430 conn.query(q) 2025-03-07_04:14:14.99431 File "/usr/local/lib/python3.11/site-packages/pymysql/connections.py", line 563, in query 2025-03-07_04:14:14.99431 self._affected_rows = self._read_query_result(unbuffered=unbuffered) 2025-03-07_04:14:14.99432 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 2025-03-07_04:14:14.99432 File "/usr/local/lib/python3.11/site-packages/pymysql/connections.py", line 825, in _read_query_result 2025-03-07_04:14:14.99433 result.read() 2025-03-07_04:14:14.99433 File "/usr/local/lib/python3.11/site-packages/pymysql/connections.py", line 1206, in read 2025-03-07_04:14:14.99434 self._read_result_packet(first_packet) 2025-03-07_04:14:14.99435 File "/usr/local/lib/python3.11/site-packages/pymysql/connections.py", line 1283, in _read_result_packet 2025-03-07_04:14:14.99435 self._read_rowdata_packet() 2025-03-07_04:14:14.99436 File "/usr/local/lib/python3.11/site-packages/pymysql/connections.py", line 1330, in _read_rowdata_packet 2025-03-07_04:14:14.99436 packet = self.connection._read_packet() 2025-03-07_04:14:14.99436 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 2025-03-07_04:14:14.99436 File "/usr/local/lib/python3.11/site-packages/pymysql/connections.py", line 775, in _read_packet 2025-03-07_04:14:14.99437 packet.raise_for_error() 2025-03-07_04:14:14.99437 File "/usr/local/lib/python3.11/site-packages/pymysql/protocol.py", line 219, in raise_for_error 2025-03-07_04:14:14.99437 err.raise_mysql_exception(self._data) 2025-03-07_04:14:14.99438 File "/usr/local/lib/python3.11/site-packages/pymysql/err.py", line 150, in raise_mysql_exception 2025-03-07_04:14:14.99438 raise errorclass(errno, errval) 2025-03-07_04:14:14.99438 pymysql.err.OperationalError: (1038, 'Out of sort memory, consider increasing server sort buffer size') 2025-03-07_04:14:14.99439 2025-03-07_04:14:14.99440 The above exception was the direct cause of the following exception: 2025-03-07_04:14:14.99440 2025-03-07_04:14:14.99440 Traceback (most recent call last): 2025-03-07_04:14:14.99440 File "/usr/local/lib/python3.11/site-packages/airflow/jobs/scheduler_job_runner.py", line 999, in _execute 2025-03-07_04:14:14.99441 self._run_scheduler_loop() 2025-03-07_04:14:14.99441 File "/usr/local/lib/python3.11/site-packages/airflow/jobs/scheduler_job_runner.py", line 1138, in _run_scheduler_loop 2025-03-07_04:14:14.99441 num_queued_tis = self._do_scheduling(session) 2025-03-07_04:14:14.99441 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 2025-03-07_04:14:14.99442 File "/usr/local/lib/python3.11/site-packages/airflow/jobs/scheduler_job_runner.py", line 1285, in _do_scheduling 2025-03-07_04:14:14.99442 num_queued_tis = self._critical_section_enqueue_task_instances(session=session) 2025-03-07_04:14:14.99442 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 2025-03-07_04:14:14.99443 File "/usr/local/lib/python3.11/site-packages/airflow/jobs/scheduler_job_runner.py", line 743, in _critical_section_enqueue_task_instances 2025-03-07_04:14:14.99443 queued_tis = self._executable_task_instances_to_queued(max_tis, session=session) 2025-03-07_04:14:14.99443 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 2025-03-07_04:14:14.99444 File "/usr/local/lib/python3.11/site-packages/airflow/jobs/scheduler_job_runner.py", line 424, in _executable_task_instances_to_queued 2025-03-07_04:14:14.99445 raise e 2025-03-07_04:14:14.99445 File "/usr/local/lib/python3.11/site-packages/airflow/jobs/scheduler_job_runner.py", line 419, in _executable_task_instances_to_queued 2025-03-07_04:14:14.99445 task_instances_to_examine: list[TI] = session.scalars(query).all() 2025-03-07_04:14:14.99445 ^^^^^^^^^^^^^^^^^^^^^^ 2025-03-07_04:14:14.99446 File "/usr/local/lib64/python3.11/site-packages/sqlalchemy/orm/session.py", line 1778, in scalars 2025-03-07_04:14:14.99446 return self.execute( 2025-03-07_04:14:14.99447 ^^^^^^^^^^^^^ 2025-03-07_04:14:14.99447 File "/usr/local/lib64/python3.11/site-packages/sqlalchemy/orm/session.py", line 1717, in execute 2025-03-07_04:14:14.99447 result = conn._execute_20(statement, params or {}, execution_options) 2025-03-07_04:14:14.99447 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 2025-03-07_04:14:14.99448 File "/usr/local/lib64/python3.11/site-packages/sqlalchemy/engine/base.py", line 1710, in _execute_20 2025-03-07_04:14:14.99448 return meth(self, args_10style, kwargs_10style, execution_options) 2025-03-07_04:14:14.99449 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 2025-03-07_04:14:14.99449 File "/usr/local/lib64/python3.11/site-packages/sqlalchemy/sql/elements.py", line 334, in _execute_on_connection 2025-03-07_04:14:14.99450 return connection._execute_clauseelement( 2025-03-07_04:14:14.99450 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 2025-03-07_04:14:14.99450 File "/usr/local/lib64/python3.11/site-packages/sqlalchemy/engine/base.py", line 1577, in _execute_clauseelement 2025-03-07_04:14:14.99451 ret = self._execute_context( 2025-03-07_04:14:14.99451 ^^^^^^^^^^^^^^^^^^^^^^ 2025-03-07_04:14:14.99451 File "/usr/local/lib64/python3.11/site-packages/sqlalchemy/engine/base.py", line 1953, in _execute_context 2025-03-07_04:14:14.99451 self._handle_dbapi_exception( 2025-03-07_04:14:14.99452 File "/usr/local/lib64/python3.11/site-packages/sqlalchemy/engine/base.py", line 2134, in _handle_dbapi_exception 2025-03-07_04:14:14.99452 util.raise_( 2025-03-07_04:14:14.99452 File "/usr/local/lib64/python3.11/site-packages/sqlalchemy/util/compat.py", line 211, in raise_ 2025-03-07_04:14:14.99452 raise exception 2025-03-07_04:14:14.99453 File "/usr/local/lib64/python3.11/site-packages/sqlalchemy/engine/base.py", line 1910, in _execute_context 2025-03-07_04:14:14.99453 self.dialect.do_execute( 2025-03-07_04:14:14.99453 File "/usr/local/lib64/python3.11/site-packages/sqlalchemy/engine/default.py", line 736, in do_execute 2025-03-07_04:14:14.99455 cursor.execute(statement, parameters) 2025-03-07_04:14:14.99455 File "/usr/local/lib/python3.11/site-packages/pymysql/cursors.py", line 153, in execute 2025-03-07_04:14:14.99455 result = self._query(query) 2025-03-07_04:14:14.99455 ^^^^^^^^^^^^^^^^^^ 2025-03-07_04:14:14.99456 File "/usr/local/lib/python3.11/site-packages/pymysql/cursors.py", line 322, in _query 2025-03-07_04:14:14.99456 conn.query(q) 2025-03-07_04:14:14.99456 File "/usr/local/lib/python3.11/site-packages/pymysql/connections.py", line 563, in query 2025-03-07_04:14:14.99456 self._affected_rows = self._read_query_result(unbuffered=unbuffered) 2025-03-07_04:14:14.99457 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 2025-03-07_04:14:14.99457 File "/usr/local/lib/python3.11/site-packages/pymysql/connections.py", line 825, in _read_query_result 2025-03-07_04:14:14.99457 result.read() 2025-03-07_04:14:14.99458 File "/usr/local/lib/python3.11/site-packages/pymysql/connections.py", line 1206, in read 2025-03-07_04:14:14.99458 self._read_result_packet(first_packet) 2025-03-07_04:14:14.99458 File "/usr/local/lib/python3.11/site-packages/pymysql/connections.py", line 1283, in _read_result_packet 2025-03-07_04:14:14.99458 self._read_rowdata_packet() 2025-03-07_04:14:14.99459 File "/usr/local/lib/python3.11/site-packages/pymysql/connections.py", line 1330, in _read_rowdata_packet 2025-03-07_04:14:14.99460 packet = self.connection._read_packet() 2025-03-07_04:14:14.99460 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 2025-03-07_04:14:14.99460 File "/usr/local/lib/python3.11/site-packages/pymysql/connections.py", line 775, in _read_packet 2025-03-07_04:14:14.99461 packet.raise_for_error() 2025-03-07_04:14:14.99461 File "/usr/local/lib/python3.11/site-packages/pymysql/protocol.py", line 219, in raise_for_error 2025-03-07_04:14:14.99461 err.raise_mysql_exception(self._data) 2025-03-07_04:14:14.99462 File "/usr/local/lib/python3.11/site-packages/pymysql/err.py", line 150, in raise_mysql_exception 2025-03-07_04:14:14.99462 raise errorclass(errno, errval) 2025-03-07_04:14:14.99462 sqlalchemy.exc.OperationalError: (pymysql.err.OperationalError) (1038, 'Out of sort memory, consider increasing server sort buffer size') 2025-03-07_04:14:14.99463 [SQL: SELECT task_instance.task_display_name, task_instance.task_id, task_instance.dag_id, task_instance.run_id, task_instance.map_index, task_instance.start_date, task_instance.end_date, task_instance.duration, task_instance.state, task_instance.try_number, task_instance.max_tries, task_instance.hostname, task_instance.unixname, task_instance.job_id, task_instance.pool, task_instance.pool_slots, task_instance.queue, task_instance.priority_weight, task_instance.operator, task_instance.custom_operator_name, task_instance.queued_dttm, task_instance.queued_by_job_id, task_instance.pid, task_instance.executor, task_instance.executor_config, task_instance.updated_at, task_instance.rendered_map_index, task_instance.external_executor_id, task_instance.trigger_id, task_instance.trigger_timeout, task_instance.next_method, task_instance.next_kwargs, dag_run_1.state AS state_1, dag_run_1.id, dag_run_1.dag_id AS dag_id_1, dag_run_1.queued_at, dag_run_1.execution_date, dag_run_1.start_date AS start_date_1, dag_run_1.end_date AS end_date_1, dag_run_1.run_id AS run_id_1, dag_run_1.creating_job_id, dag_run_1.external_trigger, dag_run_1.run_type, dag_run_1.conf, dag_run_1.data_interval_start, dag_run_1.data_interval_end, dag_run_1.last_scheduling_decision, dag_run_1.dag_hash, dag_run_1.log_template_id, dag_run_1.updated_at AS updated_at_1, dag_run_1.clear_number 2025-03-07_04:14:14.99466 FROM task_instance USE INDEX (ti_state) INNER JOIN dag_run ON dag_run.dag_id = task_instance.dag_id AND dag_run.run_id = task_instance.run_id INNER JOIN dag ON task_instance.dag_id = dag.dag_id INNER JOIN dag_run AS dag_run_1 ON dag_run_1.dag_id = task_instance.dag_id AND dag_run_1.run_id = task_instance.run_id 2025-03-07_04:14:14.99467 WHERE dag_run.run_type != %(run_type_1)s AND dag_run.state = %(state_2)s AND dag.is_paused = 0 AND task_instance.state = %(state_3)s ORDER BY -task_instance.priority_weight, dag_run.execution_date, task_instance.map_index 2025-03-07_04:14:14.99467 LIMIT %(param_1)s FOR UPDATE OF task_instance SKIP LOCKED]

[potiuk]

Also.

Out of sort memory, consider increasing server sort buffer size

This is a very clear message you get from MySQL. And it tells you what to do. Did you try to do what it says - what your investigations about that message show?

I think this is the case where you - deployment manager of your installation - get a clear information from one of the components you manage and deploy that it is misconfigured. So I find a bit strange that you look for "more help" on that since lilkely mysql documentation and using google is likely to give you more answers.

What did your investigation about that show? What are your findings? Maybe you can share with others so that they can also learn from it @Huthesh ?