← Back to team overview

percona-discussion team mailing list archive

[Bug 332280] Re: Warning: a long semaphore wait

 

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

-- 
Warning: a long semaphore wait
https://bugs.launchpad.net/bugs/332280
You received this bug notification because you are a member of Percona
developers, which is the registrant for Percona-XtraDB.

Status in Percona XtraDB Storage Engine for MySQL: New

Bug description:
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



Follow ups

References