InnoDB: Failing assertion: log_sys->buf == ut_align(log_sys->buf_ptr, srv_log_write_ahead_size) in file log0log.cc line 1251

Upstream does not crash

mysql> SHOW WARNINGS;
+---------+------+------------------------------------------------------------+
| Level | Code | Message |
+---------+------+------------------------------------------------------------+
| Warning | 1292 | Truncated incorrect innodb_log_write_ahead_size value: '0' |
+---------+------+------------------------------------------------------------+
1 row in set (0.00 sec)

Adding qafix, this bug is a screenfiller

log0log.cc line 1251 (Seen 384 times: reducers 10043,10057,10121,10127,10146,10169,10183,10252,10259,10262,1026,10275,10293,10327,10357,10400,10466,10528,10532,10578,10623,1065,10676,10688,1069,10821,10822,10840,10849,10862,10874,10947,10950,10955,10996,11014,11027,11040,11093,11113,11124,11131,11167,11190,11219,11249,11427,1142,11444,1147,11498,11508,11509,11524,11530,11572,11582,11604,11618,11650,11666,11670,1194,1229,1271,1297,1358,1366,1375,1389,143,1444,1461,1494,1503,1509,1540,1550,1583,1587,1590,1612,1635,164,1680,1728,1747,1801,1818,1820,1852,186,1887,1919,1926,1934,1939,1940,1954,195,1968,1990,210,2134,2140,2195,2206,2220,2224,2245,2284,2340,2379,239,2456,2471,2516,2546,2548,2598,259,2648,264,2730,2768,2796,2798,2870,2882,2892,2904,2967,2973,2976,2983,2992,3000,3005,302,3089,308,3109,312,3183,323,3251,3256,3282,3333,3354,3360,3417,347,3497,3575,3600,3616,3646,3666,3693,3700,3709,3712,3723,37,3862,3874,3883,3895,3954,3989,4007,405,4082,4094,4100,4106,4144,4152,4164,4181,4188,4214,4228,4261,4369,4438,4515,458,4618,4638,466,4719,4724,4736,4744,4761,4776,4777,482,4872,4894,4931,4945,4997,5040,506,5105,5161,5165,5236,523,5251,5261,529,5303,5322,5358,5405,540,5460,5561,5567,5585,5599,5712,5746,5761,5835,5866,5902,5996,6003,6012,6026,6040,6055,605,607,609,6150,6170,6219,6227,6269,6302,6309,6317,6336,6350,6366,6373,6376,6388,6402,6438,6472,6476,6525,6536,6605,6656,6666,6710,671,6804,6888,6889,6904,6934,695,6989,7000,7037,7044,7144,7193,7206,7247,7263,7280,7291,7356,7378,7452,7453,745,7502,7560,7580,7584,7625,7635,7636,763,7662,7709,7730,7744,7759,7777,7791,7835,786,789,7907,7913,7925,7940,8002,8009,800,8046,8099,8146,8169,8177,8192,8202,8240,8253,8276,8279,8316,8321,8329,8360,8395,8411,8447,8462,8477,847,8490,8513,8522,860,8707,8725,8726,873,8740,8761,8780,8814,8864,8904,8920,9018,9021,9050,9096,9137,9139,9189,9245,9262,9285,9303,9310,9317,9364,9411,944,9466,9481,9501,950,9543,9595,961,9644,9661,9686,9712,9714,9725,9751,9784,9788,9843,9881,9925,992)

In order to support innodb_flush_method=ALL_O_DIRECT, the log I/O buffers were aligned to innodb_log_write_ahead_size. This missed that the variable is dynamic. Re-aligning the buffers on updating the variable seems like an overkill, and the simplest fix is to align them on the maximum allowed value (UNIV_PAGE_SIZE_DEF) instead.

Another qafix issue ended up being related;

DROP DATABASE test;CREATE DATABASE test;USE test;
INSTALL PLUGIN rpl_semi_sync_master SONAME 'semisync_master.so';
INSTALL PLUGIN rpl_semi_sync_slave SONAME 'semisync_slave.so';
INSTALL PLUGIN auth_pam SONAME 'auth_pam.so';
INSTALL PLUGIN auth_pam_compat SONAME 'auth_pam_compat.so';
INSTALL PLUGIN QUERY_RESPONSE_TIME SONAME 'query_responset.so';
INSTALL PLUGIN QUERY_RESPONSE_TIME_AUDIT SONAME 'query_responset.so';
INSTALL PLUGIN QUERY_RESPONSE_TIME_READ SONAME 'query_responset.so';
INSTALL PLUGIN QUERY_RESPONSE_TIME_WRITE SONAME 'query_responset.so';
INSTALL PLUGIN validate_password SONAME 'validate_password.so';
INSTALL PLUGIN version_tokens SONAME 'version_token.so';
INSTALL PLUGIN auth_socket SONAME 'auth_socket.so';
INSTALL PLUGIN mysql_no_login SONAME 'mysql_no_login.so';
INSTALL PLUGIN rewriter SONAME 'rewriter.so';
INSTALL PLUGIN tokudb_file_map SONAME 'ha_tokudb.so';
INSTALL PLUGIN tokudb_fractal_tree_info SONAME 'ha_tokudb.so';
INSTALL PLUGIN tokudb_fractal_tree_block_map SONAME 'ha_tokudb.so';
INSTALL PLUGIN tokudb_trx SONAME 'ha_tokudb.so';
INSTALL PLUGIN tokudb_locks SONAME 'ha_tokudb.so';
INSTALL PLUGIN tokudb_lock_waits SONAME 'ha_tokudb.so';
INSTALL PLUGIN tokudb_background_job_status SONAME 'ha_tokudb.so';
INSTALL PLUGIN mysqlx SONAME 'mysqlx.so';
CREATE TABLE t0(a INT,b CHAR)ENGINE=InnoDB;
create table t0_myisam as select * from t0;
SET global innodb_log_write_ahead_size=0;

The outcome from that one is slightly different;

2016-06-29 15:25:32 0x7f2f789fd700 InnoDB: Assertion failure in thread 139841863931648 in file log0log.cc line 1256
InnoDB: Failing assertion: log_sys->buf == ut_align(log_sys->buf_ptr, srv_log_write_ahead_size)

>> Note line 1256 instead of 1251

+bt
#0 0x00007f2f9c85d741 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
#1 0x000000000183b0e8 in my_write_core (sig=6) at /git/PS-5.7_dbg/mysys/stacktrace.c:247
#2 0x0000000000e76cd3 in handle_fatal_signal (sig=6) at /git/PS-5.7_dbg/sql/signal_handler.cc:223
#3 <signal handler called>
#4 0x00007f2f9abf65f7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#5 0x00007f2f9abf7ce8 in __GI_abort () at abort.c:90
#6 0x0000000001bab987 in ut_dbg_assertion_failed (expr=0x21be938 "log_sys->buf == ut_align(log_sys->buf_ptr, srv_log_write_ahead_size)", file=0x21be0d8 "/git/PS-5.7_dbg/storage/innobase/log/log0log.cc", line=1256) at /git/PS-5.7_dbg/storage/innobase/ut/ut0dbg.cc:67
#7 0x0000000001a10fee in log_buffer_switch () at /git/PS-5.7_dbg/storage/innobase/log/log0log.cc:1255
#8 0x0000000001a11636 in log_write_up_to (lsn=2501989, flush_to_disk=true) at /git/PS-5.7_dbg/storage/innobase/log/log0log.cc:1414
#9 0x0000000001a11988 in log_buffer_sync_in_background (flush=true) at /git/PS-5.7_dbg/storage/innobase/log/log0log.cc:1518
#10 0x0000000001b40791 in srv_sync_log_buffer_in_background () at /git/PS-5.7_dbg/storage/innobase/srv/srv0srv.cc:2342
#11 0x0000000001b40d4b in srv_master_do_active_tasks () at /git/PS-5.7_dbg/storage/innobase/srv/srv0srv.cc:2515
#12 0x0000000001b419c4 in srv_master_thread (arg=0x0) at /git/PS-5.7_dbg/storage/innobase/srv/srv0srv.cc:2772
#13 0x00007f2f9c858dc5 in start_thread (arg=0x7f2f789fd700) at pthread_create.c:308
#14 0x00007f2f9acb721d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

Laurynas confirms second item is same bug

Second issue just a prevalent;

log0log.cc line 1256 (Seen 408 times:....

https://github.com/percona/percona-server/pull/634

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