[MDEV-13616] innodb.innodb-64k-crash 'innodb' failed, lsn_t log_close(): Assertion `!recv_no_log_write' Created: 2017-08-22  Updated: 2017-08-23  Resolved: 2017-08-23

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB, Tests
Affects Version/s: 10.2
Fix Version/s: 10.2.9

Type: Bug Priority: Major
Reporter: Alice Sherepa Assignee: Marko Mäkelä
Resolution: Duplicate Votes: 0
Labels: None

Issue Links:
Duplicate
duplicates MDEV-13452 Assertion `!recv_no_log_write' failed... Closed

 Description   

http://buildbot.askmonty.org/buildbot/builders/p8-rhel6-bintar-debug/builds/1175/steps/test/logs/stdio

innodb.innodb-64k-crash 'innodb'         w2 [ fail ]
        Test ended at 2017-08-21 14:10:49
 
CURRENT_TEST: innodb.innodb-64k-crash
 
 
Server [mysqld.1 - pid: 14970, winpid: 14970, exit: 256] failed during test run
Server log from this test:
----------SERVER LOG START-----------
2017-08-21 14:10:46 17590145216544 [Note] /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld (mysqld 10.2.9-MariaDB-debug-log) starting as process 14971 ...
2017-08-21 14:10:46 17590145216544 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4162)
2017-08-21 14:10:46 17590145216544 [Note] Plugin 'partition' is disabled.
2017-08-21 14:10:46 17590145216544 [Note] Plugin 'SEQUENCE' is disabled.
2017-08-21 14:10:46 17590145216544 [Note] InnoDB: innodb_page_size=65536
2017-08-21 14:10:46 17590145216544 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-08-21 14:10:46 17590145216544 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-08-21 14:10:46 17590145216544 [Note] InnoDB: Uses event mutexes
2017-08-21 14:10:46 17590145216544 [Note] InnoDB: Compressed tables use zlib 1.2.6
2017-08-21 14:10:46 17590145216544 [Note] InnoDB: Using Linux native AIO
2017-08-21 14:10:46 17590145216544 [Note] InnoDB: Number of pools: 1
2017-08-21 14:10:46 17590145216544 [Note] InnoDB: Using generic crc32 instructions
2017-08-21 14:10:46 17590145216544 [Note] InnoDB: Initializing buffer pool, total size = 32M, instances = 1, chunk size = 32M
2017-08-21 14:10:46 17590145216544 [Note] InnoDB: Completed initialization of buffer pool
2017-08-21 14:10:46 17589784801696 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2017-08-21 14:10:46 17590145216544 [Note] InnoDB: Highest supported file format is Barracuda.
2017-08-21 14:10:46 17590145216544 [Note] InnoDB: Starting crash recovery from checkpoint LSN=23251725
2017-08-21 14:10:46 17590145216544 [Note] InnoDB: Starting a batch to recover 219 pages from redo log.
2017-08-21 14:10:47 17590145216544 [Note] InnoDB: Starting a batch to recover 156 pages from redo log.
mysqld: /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/storage/innobase/log/log0log.cc:487: lsn_t log_close(): Assertion `!recv_no_log_write' failed.
170821 14:10:48 [ERROR] 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.
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
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.
 
Server version: 10.2.9-MariaDB-debug-log
key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=0
max_threads=153
thread_count=0
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63096 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 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 = 0x0 thread_stack 0x49000
/home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld(my_print_stacktrace-0xafd210)[0x56045040]
/home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld(handle_fatal_signal-0x1436a00)[0x55651370]
linux-vdso64.so.1(__kernel_sigtramp_rt64+0x0)[0xfff86550448]
/opt/at7.0/lib64/power7/libc.so.6(gsignal-0x174cd8)[0xfff85caf2f0]
/opt/at7.0/lib64/power7/libc.so.6(abort-0x173084)[0xfff85cb13c4]
/opt/at7.0/lib64/power7/libc.so.6(+0x55f3c)[0xfff85ca5f3c]
/opt/at7.0/lib64/power7/libc.so.6(__assert_fail-0x17ce2c)[0xfff85ca602c]
/home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld(+0xeea9e8)[0x559fa9e8]
/home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld(+0xf14850)[0x55a24850]
/home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld(+0xf13500)[0x55a23500]
/home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld(+0x122685c)[0x55d3685c]
/home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld(+0xf010ac)[0x55a110ac]
/home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld(+0x106e9e4)[0x55b7e9e4]
/home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld(+0xe26778)[0x55936778]
/home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld(_Z24ha_initialize_handlertonP13st_plugin_int-0x1434ae4)[0x55654264]
/home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld(+0x82fe84)[0x5533fe84]
/home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld(_Z11plugin_initPiPPci-0x1718194)[0x55340dac]
/home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld(+0x6eac38)[0x551fac38]
/home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld(_Z11mysqld_mainiPPc-0x18463f0)[0x551fc350]
/home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld(main-0x1854688)[0x551ec978]
/opt/at7.0/lib64/power7/libc.so.6(+0x449ac)[0xfff85c949ac]
:0(00000018.plt_call.dlclose@@GLIBC_2.3)[0xfff85c94bd4]
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-------------
mysqltest failed but provided no output
The result from queries just before the failure was:
< snip >
UPDATE t2 SET vb=@i,wb=@i,xb=@i,yb=@i,zb=@i;
UPDATE t2 SET ac=@i,bc=@i,cc=@i,dc=@i;
UPDATE t2 SET ec=@i,fc=@i,gc=@i,hc=@i,ic=@i,jc=@i;
UPDATE t2 SET kc=@i,lc=@i,mc=@i,nc=@i,oc=@i,pc=@i;
UPDATE t2 SET qc=@i,rc=@i,sc=@i,tc=@i,uc=@i;
UPDATE t2 SET vc=@i,wc=@i,xc=@i,yc=@i,zc=@i;
COMMIT;
BEGIN;
UPDATE t1 SET a=@c,b=@c,c=@c,d=@c,e=@c,f=@c,g=@c,h=@c,i=@c,j=@c,
k=@c,l=@c,m=@c,n=@c,o=@c,p=@c,q=@c,r=@c,s=@c,t=@c,u=@c,
v=@c,w=@c,x=@c,y=@c,z=@c,
aa=@c,ba=@c,ca=@c,da=@c,ea=@c,fa=@c,ga=@c,ha=@c,ia=@c,ja=@c,
ka=@c,la=@c,ma=@c,na=@c,oa=@c,pa=@c,qa=@c,ra=@c,sa=@c,ta=@c,ua=@c,
va=@c,wa=@c,xa=@c,ya=@c,za=@c,
ab=@c,bb=@c,cb=@c,db=@c,eb=@c,fb=@c,gb=@c,hb=@c,ib=@c,jb=@c,
kb=@c,lb=@c,mb=@c,nb=@c,ob=@c,pb=@c,qb=@c,rb=@c,sb=@c,tb=@c,ub=@c,
vb=@c,wb=@c,xb=@c,yb=@c,zb=@c,
ac=@c,bc=@c,cc=@c,dc=@c,ec=@c,fc=@c,gc=@c,hc=@c,ic=@c,jc=@c,
kc=@c,lc=@c,mc=@c,nc=@c,oc=@c,pc=@c,qc=@c,rc=@c,sc=@c,tc=@c,uc=@c,
vc=@c,wc=@c,xc=@c,yc=@c,zc=@c;

Thread 1 (Thread 14971):
#0  0x00000fff86523a40 in .pthread_kill () from /opt/at7.0/lib64/power7/libpthread.so.0
#1  0x000000005604518c in .my_write_core ()
#2  0x000000005565188c in .handle_fatal_signal () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/signal_handler.cc:299
#3  <signal handler called>
#4  0x00000fff85caf2f0 in .raise () from /opt/at7.0/lib64/power7/libc.so.6
#5  0x00000fff85cb12f4 in .abort () from /opt/at7.0/lib64/power7/libc.so.6
#6  0x00000fff85ca5f3c in .__assert_fail_base () from /opt/at7.0/lib64/power7/libc.so.6
#7  0x00000fff85ca602c in .__assert_fail () from /opt/at7.0/lib64/power7/libc.so.6
#8  0x00000000559fa9e8 in ._Z9log_closev () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/storage/innobase/log/log0log.cc:487
#9  0x0000000055a24850 in ._ZN5mtr_t7Command12finish_writeEm () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/storage/innobase/mtr/mtr0mtr.cc:907
#10 0x0000000055a23500 in ._ZN5mtr_t17commit_checkpointEmb () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/storage/innobase/mtr/mtr0mtr.cc:624
#11 0x0000000055d3685c in ._Z15fil_names_clearmb () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/storage/innobase/fil/fil0fil.cc:6588
#12 0x0000000055a110ac in ._Z35recv_recovery_from_checkpoint_startm () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/storage/innobase/log/log0recv.cc:3356
#13 0x0000000055b7e9e4 in ._Z34innobase_start_or_create_for_mysqlv () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/storage/innobase/srv/srv0start.cc:2231
#14 0x0000000055936778 in ._ZL13innobase_initPv () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/storage/innobase/handler/ha_innodb.cc:4419
#15 0x0000000055654264 in ._Z24ha_initialize_handlertonP13st_plugin_int () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/handler.cc:512
#16 0x000000005533fe84 in ._ZL17plugin_initializeP11st_mem_rootP13st_plugin_intPiPPcb () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_plugin.cc:1413
#17 0x0000000055340dac in ._Z11plugin_initPiPPci () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_plugin.cc:1695
#18 0x00000000551fac38 in ._ZL22init_server_componentsv () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld.cc:5258
#19 0x00000000551fc350 in ._Z11mysqld_mainiPPc () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld.cc:5848
#20 0x00000000551ec978 in .main ()



 Comments   
Comment by Marko Mäkelä [ 2017-08-23 ]

I fixed this today as a follow-up to MDEV-13452 by removing the bogus assertion.

Generated at Thu Feb 08 08:06:59 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.