"InnoDB: Warning: a long semaphore wait" during graceful mysqld shutdown

Bug #462992 reported by Alex Yurchenko
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
MySQL patches by Codership
Fix Released
High
Seppo Jaakola

Bug Description

The following was caught during see-saw test (4 tables, 4 nodes, 20 clients):

WSREP: BF victim waiting: 697605
WSREP BF 697616 is waiting for c_lock: 697605
WSREP: BF victim waiting: 697625
WSREP BF 697626 is waiting for c_lock: 697625
091029 1:17:54 [Note] Got signal 15 to shutdown mysqld
091029 1:17:54 [Note] /home/alex/codership/galera/mysql/libexec/mysqld: Normal shutdown

091029 1:17:54 [Note] Event Scheduler: Purging the queue. 0 events
091029 1:17:54 [Note] wsrep closing connection to cluster
091029 1:17:54 [Note] WSREP: rollbacker thread exiting
091029 1:17:54 [Note] gcs.c:gcs_recv_thread():583: RECV thread exiting -107: Transport endpoint is not connected
091029 1:17:54 [Note] gcs.c:gcs_close():692: Closing slave action queue.
091029 1:17:54 [Warning] gu_fifo.c:gu_fifo_close():175: Waiting for 3 items to be fetched.
091029 1:17:54 [ERROR] mm_galera.c:mm_galera_pre_commit():1761: gcs failed for: 697628, len: 448, rcode: -4
091029 1:17:54 [ERROR] WSREP connection failure
091029 1:17:54 [ERROR] mm_galera.c:mm_galera_pre_commit():1761: gcs failed for: 697611, len: 448, rcode: -4
091029 1:17:54 [ERROR] WSREP connection failure
091029 1:17:54 [Warning] MySQL is closing a connection that has an active InnoDB transaction. 1 row modifications will roll back.
091029 1:17:54 [ERROR] mm_galera.c:mm_galera_pre_commit():1761: gcs failed for: 697642, len: 448, rcode: -4
091029 1:17:54 [ERROR] WSREP connection failure
091029 1:17:54 [ERROR] mm_galera.c:mm_galera_pre_commit():1761: gcs failed for: 697630, len: 1204, rcode: -4
091029 1:17:54 [ERROR] WSREP connection failure
InnoDB: Warning: a long semaphore wait:
--Thread 2512362384 has waited at trx/trx0trx.c line 1578 for 241.00 seconds the semaphore:
Mutex at 0xb6a6a168 created file srv/srv0srv.c line 883, lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 2507303824 has waited at trx/trx0roll.c line 138 for 241.00 seconds the semaphore:
Mutex at 0xb6a6a168 created file srv/srv0srv.c line 883, lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 2569714576 has waited at srv/srv0srv.c line 2033 for 241.00 seconds the semaphore:
Mutex at 0xb6a6a168 created file srv/srv0srv.c line 883, lock var 1
waiters flag 1
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
InnoDB: Pending preads 0, pwrites 0
InnoDB: ###### Diagnostic info printed to the standard error stream

<skip>

InnoDB: Error: semaphore wait has lasted > 600 seconds
InnoDB: We intentionally crash the server, because it appears to be hung.
091029 1:33:47 InnoDB: Assertion failure in thread 2561321872 in file srv/srv0srv.c line 2188
--------------------------------------

This seems to cause Galera #184 and prevents graceful shutdown.

Changed in codership-mysql:
assignee: nobody → Seppo Jaakola (seppo-jaakola)
importance: Undecided → High
milestone: none → 0.7
description: updated
Revision history for this message
Alex Yurchenko (ayurchen) wrote :

Getting these messages requires increasing MYSQL_SHUTDOWN_WAIT timeout form 60 seconds to more than 300. Otherwise server is killed just after

[Warning] gu_fifo.c:gu_fifo_close():175: Waiting for 3 items to be fetched.

Which makes it look like the problem is in GCS.

Revision history for this message
Seppo Jaakola (seppo-jaakola) wrote :

It turned out that this issue requires a fix in galera library part. During shutdown, wsrep->abort_pre_commit()
was not performed (library refused to process anything under lack of connectivity)

Fix for this was committed and is under testing now.

Changed in codership-mysql:
status: New → In Progress
status: In Progress → Fix Committed
Changed in codership-mysql:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.