Warning: a long semaphore wait

[Chris]

When doing two operations on tables at the same time inside a single schema, I get the error as below.

This has happened twice to me. First when running 'alter table table1 engine=innodb' and 'alter table table2 engine=innodb row_format=compressed' at the same time. After 30 mins or so, I got an error similar to below.

The seond time, I was running 'alter table table2 engine=innodb row_format=compressed' and 'create table table3 like table1' at the same time.

When the error is thrown, both tables are locked up, and I cannot abort the transactions.

# rpm -qa | egrep -i 'mysql|percona'
MySQL-client-community-5.1.30-0.rhel5
MySQL-shared-compat-5.1.30-0.rhel5
perl-DBD-MySQL-3.0007-1.fc6
Percona-XtraDB-1.0.2-2-5.1.30-2.rhel5
MySQL-server-community-5.1.30-0.rhel5

# uname -a
Linux mysql-store 2.6.18-92.el5 #1 SMP Tue Jun 10 18:51:06 EDT 2008 x86_64 x86_64 x86_64 GNU/Linux

InnoDB: Warning: a long semaphore wait:
--Thread 1169545536 has waited at buf/buf0lru.c line 133 for 241.00 seconds the semaphore:
Mutex at 0x2aaabc7047a0 created file buf/buf0buf.c line 938, lock var 1
waiters flag 1
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
InnoDB: Pending preads 0, pwrites 0

=====================================
090220 23:42:39 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 45 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 2808, signal count 2745
--Thread 1169545536 has waited at buf/buf0lru.c line 133 for 241.00 seconds the semaphore:
Mutex at 0x2aaabc7047a0 created file buf/buf0buf.c line 938, lock var 1
waiters flag 1
--Thread 1169013056 has waited at trx/trx0purge.c line 722 for 233.00 seconds the semaphore:
Mutex at 0x2aaabcae4ec0 created file trx/trx0rseg.c line 151, lock var 1
waiters flag 1
--Thread 1169811776 has waited at buf/buf0buf.c line 1911 for 228.00 seconds the semaphore:
Mutex at 0x2aaabc7046a0 created file buf/buf0buf.c line 940, lock var 1
waiters flag 1
Mutex spin waits 0, rounds 53140, OS waits 2543
RW-shared spins 490, OS waits 245; RW-excl spins 8, OS waits 8
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (write thread)
Pending normal aio reads: 0, aio writes: 0,
 ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
6912 OS file reads, 14559 OS file writes, 6954 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 483, seg size 485,
0 inserts, 0 merged recs, 0 merges
Hash table size 5188061, node heap has 2 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 77371341145
Log flushed up to 77371341145
Last checkpoint at 76982513763
Max checkpoint age 433682474
Modified age 378274123
Checkpoint age 388827382
0 pending log writes, 0 pending chkp writes
8294 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 2909642675; in additional pool allocated 193024
Internal hash tables (constant factor + variable factor)
    Adaptive hash index 41545424 (41504488 + 40936)
    Page hash 2594888
    Dictionary cache 10439584 (10377712 + 61872)
    File system 87392 (82672 + 4720)
    Lock system 6487360 (6485896 + 1464)
    Recovery system 0 (0 + 0)
    Threads 407256 (406936 + 320)
Dictionary memory allocated 61872
InnoDB: ###### Diagnostic info printed to the standard error stream
InnoDB: Warning: a long semaphore wait:
--Thread 1169545536 has waited at buf/buf0lru.c line 133 for 272.00 seconds the semaphore:
Mutex at 0x2aaabc7047a0 created file buf/buf0buf.c line 938, lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 1169013056 has waited at trx/trx0purge.c line 722 for 264.00 seconds the semaphore:
Mutex at 0x2aaabcae4ec0 created file trx/trx0rseg.c line 151, lock var 1
waiters flag 1
InnoDB: Warning: a long semaphore wait:
--Thread 1169811776 has waited at buf/buf0buf.c line 1911 for 259.00 seconds the semaphore:
Mutex at 0x2aaabc7046a0 created file buf/buf0buf.c line 940, 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

[Feifei Jia (ffjia)]

I've also encountered this days ago when loading a large file (31GB) to a compressed table.

To reproduce:

mysql> create table t engine=innodb row_format=compressed;
mysql> load data infile '/path/to/file' into table t;

wait...

and the same (as above) error output shows up in the *.err file, cannot abort transaction...

############################################################
Server version: 5.1.33-log MySQL 5.1.33snapshot

# uname -a
Linux mysql-server 2.6.18-92.1.22.el5 #1 SMP Tue Dec 16 11:57:43 EST 2008 x86_64 x86_64 x86_64 GNU/Linux

[Vadim Tkachenko (vadim-tk)]

Feifei,

It should be fixed in incoming release5, can you try it ?

http://www.percona.com/mysql/5.1.34-5

Feifei Jia wrote:
> I've also encountered this days ago when loading a large file (31GB) to
> a compressed table.
>
> To reproduce:
>
> mysql> create table t engine=innodb row_format=compressed;
> mysql> load data infile '/path/to/file' into table t;
>
> wait...
>
> and the same (as above) error output shows up in the *.err file, cannot
> abort transaction...
>
> ############################################################
> Server version: 5.1.33-log MySQL 5.1.33snapshot
>
> # uname -a
> Linux mysql-server 2.6.18-92.1.22.el5 #1 SMP Tue Dec 16 11:57:43 EST 2008 x86_64 x86_64 x86_64 GNU/Linux
>

--
Vadim Tkachenko, CTO
Percona Inc.
ICQ: 369-510-335, Skype: vadimtk153, Phone [phone]
MySQL Performance Blog - http://www.mysqlperformanceblog.com
MySQL Consulting http://www.percona.com/

[Feifei Jia (ffjia)]

Vadim,

yeah, I can do the load task successfully this time, with your release5, thank you