Bug #73942 Code gets incorrectly optimized away by gcc
Submitted: 17 Sep 2014 3:20 Modified: 17 Oct 2014 17:49
Reporter: Ramana Yeruva Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S3 (Non-critical)
Version:5.7.5 OS:Any
Assigned to: CPU Architecture:Any

[17 Sep 2014 3:20] Ramana Yeruva
Description:
 While i was looking into 5.7.5-m15 release test results page,i seen server crash with debian32-bit only and i tried to reproduce the issue with new set of packages published for SysQA and found the same crash.
http://pb2.no.oracle.com/?action=archive_download&archive_id=13201429&pretty=please 

How to repeat:
root@viking20:/usr/lib/mysql-test# ./mtr --suite=innodb_zip innodb-wl6045-2
Logging: ./mtr  --suite=innodb_zip innodb-wl6045-2
MySQL Version 5.7.5
Checking supported features...
 - SSL connections supported
Collecting tests...
Checking leftover processes...
Removing old var directory...
Creating var directory '/usr/lib/mysql-test/var'...
Installing system database...

==============================================================================

TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
worker[1] mysql-test-run: WARNING: running this script as _root_ will cause some tests to be skipped
innodb_zip.innodb-wl6045-2               [ fail ]
        Test ended at 2014-09-16 15:22:46

CURRENT_TEST: innodb_zip.innodb-wl6045-2
mysqltest: At line 29: query 'INSERT INTO t1 SELECT * from t1' failed: 2013: Lost connection to MySQL server during query

The result from queries just before the failure was:
SET GLOBAL innodb_file_per_table=on;
SET GLOBAL innodb_file_format='barracuda';
SET GLOBAL innodb_compression_level=0;
SELECT @@innodb_compression_level;
@@innodb_compression_level
0
CREATE TABLE t1 (j LONGBLOB) ENGINE = InnoDB ROW_FORMAT=COMPRESSED KEY_BLOCK_SIZE=1;
INSERT INTO t1 VALUES (repeat('abcdefghijklmnopqrstuvwxyz',200));
INSERT INTO t1 SELECT * from t1;
INSERT INTO t1 SELECT * from t1;
INSERT INTO t1 SELECT * from t1;
INSERT INTO t1 SELECT * from t1;

Server [mysqld.1 - pid: 27375, winpid: 27375, exit: 256] failed during test run
Server log from this test:
----------SERVER LOG START-----------
2014-09-16T13:22:45.335274Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2014-09-16T13:22:45.335461Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.5-m15-log) starting as process 27376 ...
2014-09-16T13:22:45.338975Z 0 [Note] Plugin 'FEDERATED' is disabled.
2014-09-16T13:22:45.339843Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2014-09-16T13:22:45.339860Z 0 [Note] InnoDB: Uses event mutexes
2014-09-16T13:22:45.339871Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2014-09-16T13:22:45.339878Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.7
2014-09-16T13:22:45.339884Z 0 [Note] InnoDB: Using Linux native AIO
2014-09-16T13:22:45.340283Z 0 [Note] InnoDB: Number of pools: 1
2014-09-16T13:22:45.340437Z 0 [Note] InnoDB: Not using CPU crc32 instructions
2014-09-16T13:22:45.341404Z 0 [Note] InnoDB: Initializing buffer pool, total size = 8.0M, instances = 1, chunk size = 8.0M
2014-09-16T13:22:45.343252Z 0 [Note] InnoDB: Completed initialization of buffer pool
2014-09-16T13:22:45.347420Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2014-09-16T13:22:45.362839Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2014-09-16T13:22:45.362962Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2014-09-16T13:22:45.406617Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2014-09-16T13:22:45.408536Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2014-09-16T13:22:45.408554Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2014-09-16T13:22:45.409503Z 0 [Note] InnoDB: Waiting for purge to start
2014-09-16T13:22:45.459939Z 0 [Note] InnoDB: 5.7.5 started; log sequence number 1331653
2014-09-16T13:22:45.460778Z 0 [Warning] unknown variable 'loose-sha256_password_auto_generate_rsa_keys=0'
2014-09-16T13:22:45.460821Z 0 [Warning] unknown variable 'loose-debug-sync-timeout=600'
2014-09-16T13:22:45.462177Z 0 [Warning] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: 8ba3446a-3da4-11e4-9a27-0021f6bb00a9.
2014-09-16T13:22:45.464970Z 0 [Note] Server hostname (bind-address): '*'; port: 13000
2014-09-16T13:22:45.465150Z 0 [Note] IPv6 is available.
2014-09-16T13:22:45.465195Z 0 [Note]   - '::' resolves to '::';
2014-09-16T13:22:45.465227Z 0 [Note] Server socket created on IP: '::'.
2014-09-16T13:22:45.500155Z 0 [Note] Event Scheduler: Loaded 0 events
2014-09-16T13:22:45.500197Z 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.7.5-m15-log'  socket: '/usr/lib/mysql-test/var/tmp/mysqld.1.sock'  port: 13000  MySQL Community Server (GPL)
2014-09-16 16:22:45 0xb091db70  InnoDB: Assertion failure in thread 2962348912 in file btr0btr.cc line 779
InnoDB: Failing assertion: page_rec_is_user_rec(user_rec)
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.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
13:22:45 UTC - 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=1048576
read_buffer_size=131072
max_used_connections=1
max_threads=151
thread_count=1
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 60308 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0xa105600
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 = b091d30c thread_stack 0x30000
/usr/sbin/mysqld(my_print_stacktrace+0x33)[0x8707b53]
/usr/sbin/mysqld(handle_fatal_signal+0x476)[0x82daf46]
[0xb775f400]
[0xb775f424]
/lib/i386-linux-gnu/i686/cmov/libc.so.6(gsignal+0x51)[0xb7466941]
/lib/i386-linux-gnu/i686/cmov/libc.so.6(abort+0x182)[0xb7469d72]
/usr/sbin/mysqld[0x82b4073]
/usr/sbin/mysqld[0x8887425]
/usr/sbin/mysqld[0x8887b7d]
/usr/sbin/mysqld(_Z25btr_page_split_and_insertmP9btr_cur_tPPmPP16mem_block_info_tPK8dtuple_tmP5mtr_t+0x24a)[0x888f83a]
/usr/sbin/mysqld(_Z25btr_root_raise_and_insertmP9btr_cur_tPPmPP16mem_block_info_tPK8dtuple_tmP5mtr_t+0x467)[0x8892247]
/usr/sbin/mysqld(_Z26btr_cur_pessimistic_insertmP9btr_cur_tPPmPP16mem_block_info_tP8dtuple_tPPhPP9big_rec_tmP9que_thr_tP5mtr_t+0x26d)[0x889829d]
/usr/sbin/mysqld(_Z29row_ins_clust_index_entry_lowmmP12dict_index_tmP8dtuple_tmP9que_thr_tb+0x1003)[0x87cf7f3]
/usr/sbin/mysqld(_Z25row_ins_clust_index_entryP12dict_index_tP8dtuple_tP9que_thr_tmb+0x497)[0x87d6a87]
/usr/sbin/mysqld(_Z12row_ins_stepP9que_thr_t+0x350)[0x87d7570]
/usr/sbin/mysqld(_Z20row_insert_for_mysqlPKhP14row_prebuilt_t+0x346)[0x87e80e6]
/usr/sbin/mysqld(_ZN11ha_innobase9write_rowEPh+0x18f)[0x872e7df]
/usr/sbin/mysqld(_ZN7handler12ha_write_rowEPh+0x108)[0x8322708]
/usr/sbin/mysqld(_Z12write_recordP3THDP5TABLEP9COPY_INFOS4_+0x80)[0x8665ab0]
/usr/sbin/mysqld(_ZN13select_insert9send_dataER4ListI4ItemE+0xe8)[0x8666628]
/usr/sbin/mysqld[0x8507795]
/usr/sbin/mysqld[0x8504a6c]
/usr/sbin/mysqld(_ZN13QEP_tmp_table8end_sendEv+0x173)[0x8508d73]
/usr/sbin/mysqld(_Z13sub_select_opP4JOINP7QEP_TABb+0x68)[0x85093c8]
/usr/sbin/mysqld(_Z10sub_selectP4JOINP7QEP_TABb+0x30b)[0x850914b]
/usr/sbin/mysqld(_ZN4JOIN4execEv+0x2c1)[0x8503081]
/usr/sbin/mysqld(_Z12mysql_selectP3THDR4ListI4ItemEyP13select_resultP13st_select_lex+0xee)[0x855703e]
/usr/sbin/mysqld(_Z13handle_selectP3THDP13select_resultm+0x130)[0x8557180]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x4990)[0x852eef0]
/usr/sbin/mysqld(_Z11mysql_parseP3THDP12Parser_state+0x371)[0x8530ab1]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x11db)[0x8531deb]
/usr/sbin/mysqld(_Z10do_commandP3THD+0xe2)[0x8532a52]
/usr/sbin/mysqld(handle_connection+0x28c)[0x85d30bc]
/usr/sbin/mysqld(pfs_spawn_thread+0x1a9)[0x8a12339]
/lib/i386-linux-gnu/i686/cmov/libpthread.so.0(+0x5c39)[0xb7731c39]
/lib/i386-linux-gnu/i686/cmov/libc.so.6(clone+0x5e)[0xb7512d2e]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (a188178): INSERT INTO t1 SELECT * from t1
Connection ID (thread ID): 2
Status: NOT_KILLED

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.
Writing a core file
----------SERVER LOG END-------------

 - the logfile can be found in '/usr/lib/mysql-test/var/log/innodb_zip.innodb-wl6045-2/innodb-wl6045-2.log'
 - found 'core' (0/5)

Trying 'dbx' to get a backtrace

Trying 'gdb' to get a backtrace
--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 0.000 of 5 seconds executing testcases

Completed: Failed 1/1 tests, 0.00% were successful.

Failing test(s): innodb_zip.innodb-wl6045-2

The log files in var/log may give you some hint of what went wrong.

If you want to report this error, please read first the documentation
at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html

mysql-test-run: *** ERROR: there were failing test cases

Is there any bug report opened already then please close this bug
[6 Oct 2014 13:18] Marko Mäkelä
Posted by developer:
 
I narrowed down this GCC bug and filed
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=764220
[8 Oct 2014 7:37] Marko Mäkelä
Posted by developer:
 
We work around the gcc bug by removing __attribute__((pure)) from all function declarations that take pointers or references as arguments, and dereference the pointer.

We also removed __attribute__((const)) from functions that dereference pointers or references. This probably was incorrect use of the attribute, according to the GCC documentation (it should have been __attribute__((pure)).) The function page_zip_rec_needs_ext() was incorrectly declared as __attribute__((const)). But, gcc would generate incorrect code even if it were declared __attribute__((pure)).
[17 Oct 2014 17:49] Daniel Price
Posted by developer:
 
Fixed as of the upcoming 5.7.6 release, and here's the changelog entry:

Building MySQL 5.7.5 on a Debian 7 32-bit system with GCC resulted in a
MySQL server failure. The problem was traced to a GCC bug ("Debian Bug
Report #764220") that causes incorrect code to be emitted when a function
that takes a pointer or reference as a parameter is declared as
"attribute((const))" or "attribute((pure))". The problem is known to occur
on Debian Wheezy 7.6 x86 with g++-4.6 (Debian 4.6.3-14) 4.6.3 or g++
(Debian 4.7.2-5) 4.7.2, and on Debian Jessie/Sid amd64 with gcc (Debian
4.9.1-15) 4.9.1 or g++ (Debian 4.9.1-15) 4.9.1. The bug may exist in other
gcc-4.x versions as well any GCC version that accepts the
"attribute((const))" or "attribute((pure))" code. 

To avoid the bug, the potentially problematic attributes have been removed from
MySQL functions that take pointers or references that they are
dereferencing. 

This patch also removed instances of
"attribute((nonnull))", which does not always generate a warning when NULL
is passed, and may not emit code for handling the NULL case.
[22 Oct 2014 13:54] Erlend Dahl
Bug#73799 Assert at page_rec_is_user_rec(user_rec)

was marked as a duplicate.