InnoDB: Error: trying to do i/o to a tablespace which does not exist. | Assert due to InnoDB: Error: semaphore wait has lasted > 600 seconds

[Roel Van de Paar]

========================= Error log:
130205 14:24:39 InnoDB: Error: trying to do i/o to a tablespace which does not exist.
InnoDB: i/o type 11, space id 281, page no. 59, i/o length 16384 bytes
[...]
InnoDB: Warning: a long semaphore wait:
--Thread 139999765141248 has waited at row0mysql.c line 3283 for 241.00 seconds the semaphore:
X-lock on RW-latch at 0x11c7a60 '&dict_operation_lock'
a writer (thread id 139999764875008) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file row0undo.c line 296
Last time write locked in file /ssd/QA-16724-5.5-2/Percona-Server-5.5.28-rel29.3/storage/innobase/row/row0mysql.c line 3283
InnoDB: Warning: a long semaphore wait:
--Thread 139999765673728 has waited at dict0dict.c line 343 for 241.00 seconds the semaphore:
Mutex at 0x31e5928 '&dict_sys->mutex', lock var 1
waiters flag 1
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
InnoDB: Pending preads 0, pwrites 0
[...]
InnoDB: Error: semaphore wait has lasted > 600 seconds
InnoDB: We intentionally crash the server, because it appears to be hung.
130205 14:40:35 InnoDB: Assertion failure in thread 139999442106112 in file srv0srv.c line 2862
InnoDB: We intentionally generate a memory trap.

========================= gdb :
Abort in srv_error_monitor_thread as per the above. full stacks for other thread review attached.

========================= Run details:
[Roel@qaserver 861716]$ cat cmd1224
ps -ef | grep 'cmdrun_1224' | grep -v grep | awk '{print $2}' | xargs sudo kill -9
rm -Rf /ssd/861716/cmdrun_1224
mkdir /ssd/861716/cmdrun_1224
cd /ssd/randgen
bash -c "set -o pipefail; perl runall.pl --queries=100000000 --seed=21037 --duration=200 --querytimeout=60 --short_column_names --reporter=Shutdown,Backtrace,QueryTimeout,ErrorLog,ErrorLogAlarm --mysqld=--log-output=none --mysqld=--sql_mode=ONLY_FULL_GROUP_BY --grammar=conf/percona_qa/percona_qa.yy --gendata=conf/percona_qa/percona_qa.zz --basedir=/ssd/Percona-Server-5.5.28-rel29.3-422-debug.Linux.x86_64 --threads=25 --views --validator=Transformer --mysqld=--innodb_track_changed_pages=1 --mysqld=--innodb_max_bitmap_file_size=4096 --mysqld=--innodb_changed_pages=ON --mysqld=--innodb_max_changed_pages=0 --mysqld=--innodb_log_file_size=1048576 --mysqld=--innodb_log_files_in_group=10 --mysqld=--innodb_log_buffer_size=10485761 --mysqld=--innodb_log_block_size=16384 --mysqld=--innodb_file_per_table=1 --mtr-build-thread=721 --mask=41351 --vardir1=/ssd/861716/cmdrun_1224 > /ssd/861716/cmdrun1224.log 2>&1"

========================= Notes:
Not QA blocking

[Roel Van de Paar (roel11)]

Debug-only run

[Tiago Bevilaqua (tiagobevilaqua)]

InnoDB: Warning: a long semaphore wait:
--Thread 1309210944 has waited at dict/dict0dict.c line 281 for 241.00 seconds the semaphore:
X-lock on RW-latch at 0xd462e0 '&dict_table_stats_latches[i]'
a writer (thread id 1300425024) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file dict/dict0dict.c line 278
Last time write locked in file dict/dict0dict.c line 281

[...]

InnoDB: ###### Diagnostic info printed to the standard error stream
InnoDB: Error: semaphore wait has lasted > 600 seconds
InnoDB: We intentionally crash the server, because it appears to be hung.
130313 10:48:08 InnoDB: Assertion failure in thread 1232214336 in file srv/srv0srv.c line 2541
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-recovery.html
InnoDB: about forcing recovery.
130313 10:48:08 - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help diagnose
the problem, but since we have already crashed, something is definitely wrong
and this may fail.

key_buffer_size=268435456
read_buffer_size=2097152
max_used_connections=2001
max_threads=2000
threads_connected=2002
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 69915862 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = (nil) thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x84c94e]
/usr/sbin/mysqld(handle_segfault+0x320)[0x590200]
/lib64/libpthread.so.0[0x3bfaa0ebe0]
/lib64/libc.so.6(gsignal+0x35)[0x3bfa230285]
/lib64/libc.so.6(abort+0x110)[0x3bfa231d30]
/usr/sbin/mysqld[0x773826]
/lib64/libpthread.so.0[0x3bfaa0677d]
/lib64/libc.so.6(clone+0x6d)[0x3bfa2d3c1d]
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
130313 10:48:08 mysqld_safe Number of processes running now: 0
130313 10:48:08 mysqld_safe mysqld restarted

[Tiago Bevilaqua (tiagobevilaqua)]

My Server version: 5.1.54-rel12.6-log

[Roel Van de Paar (roel11)]

Tiago: unless you see "InnoDB: Error: trying to do i/o to a tablespace which does not exist." in your error log, you likely ran into another bug. If so, please log another bug report and link to it from this bug report.

[Tiago Bevilaqua (tiagobevilaqua)]

Bug created: https://bugs.launchpad.net/percona-server/+bug/1157403

Thanks!

[Valerii Kravchuk (valerii-kravchuk)]

I wonder is this was ever noted on Percona Server 5.6.x? I'll test, but obviously QA runs more tests than I'll ever be able to...

[Valerii Kravchuk (valerii-kravchuk)]

I can not reproduce this yet with Percona Server 5.6.19-66.1 on Ubuntu 14.04

[Launchpad Janitor (janitor)]

[Expired for Percona Server because there has been no activity for 60 days.]

[Launchpad Janitor (janitor)]

[Expired for Percona Server 5.6 because there has been no activity for 60 days.]

[Launchpad Janitor (janitor)]

[Expired for Percona Server 5.5 because there has been no activity for 60 days.]

[大野木 (dayemu)]

2016-10-07 02:44:12 6228 [ERROR] InnoDB: Trying to do i/o to a tablespace which does not exist. i/o type 10, space id 19798, page no. 466, i/o length 16384 bytes

[sbester (sbester)]

seend on 5.7.17 release build while alter table + dml were running concurrently. no crash.

2017-03-16T08:10:39.503862Z 0 [ERROR] InnoDB: Trying to do I/O to a tablespace which does not exist. I/O type: read, page: [page id: space=25438, page number=12344], I/O length: 4096 bytes
2017-03-16T08:10:39.503862Z 0 [ERROR] InnoDB: Trying to do I/O to a tablespace which does not exist. I/O type: read, page: [page id: space=25438, page number=16401], I/O length: 4096 bytes
2017-03-16T08:10:39.506362Z 0 [ERROR] InnoDB: Trying to do I/O to a tablespace which does not exist. I/O type: read, page: [page id: space=25438, page number=16407], I/O length: 4096 bytes
2017-03-16T08:10:39.506362Z 0 [ERROR] InnoDB: Trying to do I/O to a tablespace which does not exist. I/O type: read, page: [page id: space=25438, page number=8251], I/O length: 4096 bytes
2017-03-16T08:10:39.506362Z 0 [ERROR] InnoDB: Trying to do I/O to a tablespace which does not exist. I/O type: read, page: [page id: space=25438, page number=12310], I/O length: 4096 bytes

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-632