[MDEV-23922] main.alter_table_mdev539_maria timeouts or crashes server on arch alpha Created: 2020-10-08  Updated: 2023-01-21

Status: Open
Project: MariaDB Server
Component/s: Tests
Affects Version/s: 10.5.5
Fix Version/s: None

Type: Bug Priority: Minor
Reporter: Otto Kekäläinen Assignee: Unassigned
Resolution: Unresolved Votes: 0
Labels: None


 Description   

While importing MariaDB 10.5 to Debian I noticed this failure in the alpha build log:

worker[1] Test still running: main.alter_table_mdev539_maria
worker[1] Trying to dump core for [mysqltest - pid: 16297, winpid: 16297]
worker[1] Trying to dump core for [mysqld.1 - pid: 16192, winpid: 16192]
main.alter_table_mdev539_maria           w1 [ fail ]  timeout after 1800 seconds
        Test ended at 2020-10-07 05:19:44
 
Test case timeout after 1800 seconds
 
== /<<PKGBUILDDIR>>/builddir/mysql-test/var/1/log/alter_table_mdev539_maria.log == 
#
set @@default_storage_engine= Aria;
#
# mdev-539: fast build of unique/primary indexes for MyISAM/Aria
#
call mtr.add_suppression("Can't find record in '.*'");
DROP DATABASE IF EXISTS dbt3_s001;
CREATE DATABASE dbt3_s001;
use dbt3_s001;
 
 == /<<PKGBUILDDIR>>/builddir/mysql-test/var/1/tmp/analyze-timeout-mysqld.1.err ==
mysqltest: Could not open connection 'default' after 500 attempts: 2002 Can't connect to local MySQL server through socket '/<<PKGBUILDDIR>>/builddir/mysql-te' (61)
 
 
 - found 'core' (0/5)
 
Trying 'dbx' to get a backtrace
 
Trying 'gdb' to get a backtrace from coredump /<<PKGBUILDDIR>>/builddir/mysql-test/var/1/log/main.alter_table_mdev539_maria/mysqld.1/data/core
Core generated by '/<<PKGBUILDDIR>>/builddir/sql/mariadbd'
Output from gdb follows. The first stack trace is from the failing thread.
The following stack traces are from all threads (so the failing one is
duplicated).
--------------------------
[New LWP 16193]
[New LWP 16195]
[New LWP 16198]
[New LWP 16194]
[New LWP 16202]
[New LWP 16199]
 
warning: Unexpected size of section `.reg/16193' in core file.
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/alpha-linux-gnu/libthread_db.so.1".
Core was generated by `/<<PKGBUILDDIR>>/builddir/sql/mariadbd --defaults'.
Program terminated with signal SIGABRT, Aborted.
 
warning: Unexpected size of section `.reg/16193' in core file.
#0  0x00000200002a6f64 in pthread_kill () from /lib/alpha-linux-gnu/libpthread.so.0
[Current thread is 1 (Thread 0x20000ae9100 (LWP 16193))]
#0  0x00000200002a6f64 in pthread_kill () from /lib/alpha-linux-gnu/libpthread.so.0
#1  0x000002000215f804 in my_write_core (sig=<optimized out>) at ./mysys/stacktrace.c:519
#2  0x0000020001a333fc in handle_fatal_signal (sig=<optimized out>) at ./sql/signal_handler.cc:330
#3  <signal handler called>
#4  0x0000020000728fb0 in poll () from /lib/alpha-linux-gnu/libc.so.6.1
#5  0x0000020001699908 in poll (__timeout=-1, __nfds=2, __fds=0x11fd6f060) at /usr/include/alpha-linux-gnu/bits/poll2.h:41
#6  handle_connections_sockets () at ./sql/mysqld.cc:6217
#7  0x000002000169d2a8 in mysqld_main (argc=<optimized out>, argv=<optimized out>) at ./sql/mysqld.cc:5666
#8  0x0000020001652070 in main (argc=534179936, argv=0x2) at ./sql/main.cc:25
 
Thread 6 (Thread 0x20007ffc100 (LWP 16199)):
warning: Unexpected size of section `.reg/16199' in core file.
#0  0x00000200002a48e0 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/alpha-linux-gnu/libpthread.so.0
#1  0x00000200016bc4b0 in inline_mysql_cond_wait (src_file=0x200022e14c8 "/<<PKGBUILDDIR>>/sql/slave.cc", src_line=525, mutex=<optimized out>, that=<optimized out>) at ./include/mysql/psi/mysql_thread.h:1220
#2  handle_slave_background (arg=<optimized out>) at ./sql/slave.cc:525
#3  0x0000020001d63fc0 in pfs_spawn_thread (arg=0x2000c8f4838) at ./storage/perfschema/pfs.cc:2201
#4  0x000002000029bc3c in start_thread () from /lib/alpha-linux-gnu/libpthread.so.0
#5  0x0000020000736f44 in ?? () from /lib/alpha-linux-gnu/libc.so.6.1
 
Thread 5 (Thread 0x2000cc1c100 (LWP 16202)):
warning: Unexpected size of section `.reg/16202' in core file.
#0  0x00000200002aa1dc in __lll_lock_wait () from /lib/alpha-linux-gnu/libpthread.so.0
#1  0x000002000029ef08 in pthread_mutex_lock () from /lib/alpha-linux-gnu/libpthread.so.0
#2  0x0000020001d0ef9c in inline_mysql_mutex_lock (src_file=0x200024331e7 "/<<PKGBUILDDIR>>/storage/maria/ma_bitmap.c", src_line=2632, that=0x2001c22fa08) at ./include/mysql/psi/mysql_thread.h:750
#3  _ma_bitmap_flushable (info=0x2001c207618, non_flushable_inc=<optimized out>) at ./storage/maria/ma_bitmap.c:2632
#4  0x0000020001d06b94 in allocate_and_write_block_record (undo_lsn=1, row=0x2001c207698, record=0x2001c2275d0 "", info=0x2001c207618) at ./storage/maria/ma_blockrec.c:3609
#5  _ma_write_init_block_record (info=0x2001c207618, record=0x2001c2275d0 "") at ./storage/maria/ma_blockrec.c:3609
#6  0x0000020001d11a30 in maria_write (info=<optimized out>, record=<optimized out>) at ./storage/maria/ma_write.c:157
#7  0x0000020001ca9124 in ha_maria::write_row (this=0x2001c270bf0, buf=<optimized out>) at ./storage/maria/ha_maria.cc:1259
#8  0x0000020001a4476c in handler::ha_write_row (this=0x2001c270bf0, buf=0x2001c2275d0 "") at ./sql/handler.cc:7137
#9  0x0000020001753210 in write_record (thd=0x2001c000c58, table=0x2001c03a5b8, info=0x2000cc1a950, sink=0x0) at ./sql/sql_insert.cc:2094
#10 0x000002000175c6e0 in mysql_insert (thd=0x2001c000c58, table_list=<optimized out>, fields=..., values_list=..., update_fields=..., update_values=..., duplic=<optimized out>, ignore=<optimized out>, result=<optimized out>) at ./sql/sql_insert.cc:1087
#11 0x000002000179ca00 in mysql_execute_command (thd=0x2001c000c58) at ./sql/sql_parse.cc:4546
#12 0x00000200017a1b64 in mysql_parse (thd=0x2001c000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at ./sql/sql_parse.cc:7994
#13 0x00000200017a4558 in dispatch_command (command=<optimized out>, thd=0x2001c000c58, packet=0x2001c007e99 "INSERT INTO lineitem VALUES \n(2465,68,5,1,27,26137.62,0.05,0.02,'N','O','1995-09-05','1995-09-07','1995-09-17','DELIVER IN PERSON','FOB','furiously re'),\n(2465,51,3,2,34,32335.7,0.02,0.05,'N','O','199"..., packet_length=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at ./sql/sql_class.h:1247
#14 0x00000200017a6240 in do_command (thd=0x2001c000c58) at ./sql/sql_parse.cc:1348
#15 0x00000200018cefd0 in do_handle_one_connection (connect=<optimized out>, put_in_cache=<optimized out>) at ./sql/sql_connect.cc:1410
#16 0x00000200018cf440 in handle_one_connection (arg=0x2000cabd618) at ./sql/sql_connect.cc:1312
#17 0x0000020001d63fc0 in pfs_spawn_thread (arg=0x2000c8a75a8) at ./storage/perfschema/pfs.cc:2201
#18 0x000002000029bc3c in start_thread () from /lib/alpha-linux-gnu/libpthread.so.0
#19 0x0000020000736f44 in ?? () from /lib/alpha-linux-gnu/libc.so.6.1
 
Thread 4 (Thread 0x200072f5100 (LWP 16194)):
warning: Unexpected size of section `.reg/16194' in core file.
#0  0x00000200002a4d68 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/alpha-linux-gnu/libpthread.so.0
#1  0x00000200021658cc in inline_mysql_cond_timedwait (that=0x200033e3540 <COND_timer>, mutex=0x200033e3578 <LOCK_timer>, src_file=0x2000249c9a8 "/<<PKGBUILDDIR>>/mysys/thr_timer.c", src_line=321, abstime=0x0) at ./include/mysql/psi/mysql_thread.h:1257
#2  timer_handler (arg=<optimized out>) at ./mysys/thr_timer.c:321
#3  0x0000020001d63fc0 in pfs_spawn_thread (arg=0x20006e87528) at ./storage/perfschema/pfs.cc:2201
#4  0x000002000029bc3c in start_thread () from /lib/alpha-linux-gnu/libpthread.so.0
#5  0x0000020000736f44 in ?? () from /lib/alpha-linux-gnu/libc.so.6.1
 
Thread 3 (Thread 0x20007e7a100 (LWP 16198)):
warning: Unexpected size of section `.reg/16198' in core file.
#0  0x0000020000665bbc in sigtimedwait () from /lib/alpha-linux-gnu/libc.so.6.1
#1  0x0000020001690a70 in my_sigwait (code=<synthetic pointer>, sig=0x20007e798a0, set=0x20007e79820) at ./include/my_pthread.h:196
#2  signal_hand (arg=<optimized out>) at ./sql/mysqld.cc:2987
#3  0x0000020001d63fc0 in pfs_spawn_thread (arg=0x20007fafa48) at ./storage/perfschema/pfs.cc:2201
#4  0x000002000029bc3c in start_thread () from /lib/alpha-linux-gnu/libpthread.so.0
#5  0x0000020000736f44 in ?? () from /lib/alpha-linux-gnu/libc.so.6.1
 
Thread 2 (Thread 0x2000c801100 (LWP 16195)):
warning: Unexpected size of section `.reg/16195' in core file.
#0  0x00000200002a48e0 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/alpha-linux-gnu/libpthread.so.0
#1  0x0000020001cc1128 in inline_mysql_cond_wait (src_file=0x200024303de "/<<PKGBUILDDIR>>/storage/maria/ma_loghandler.c", src_line=7851, mutex=0x2000333f760 <log_descriptor+8391616>, that=0x2000333f790 <log_descriptor+8391664>) at ./include/mysql/psi/mysql_thread.h:1220
#2  translog_flush_set_new_goal_and_wait (lsn=<optimized out>) at ./storage/maria/ma_loghandler.c:7851
#3  0x0000020001cc2094 in translog_flush (lsn=<optimized out>) at ./storage/maria/ma_loghandler.c:8140
#4  0x0000020001d0b4a4 in flush_log_for_bitmap (args=<optimized out>) at ./storage/maria/ma_bitmap.c:3116
#5  0x0000020001cc96c4 in pagecache_fwrite (pagecache=0x20002b3d3e0 <maria_pagecache_var>, filedesc=0x80, buffer=0x0, pageno=1, flags=2199061201886, type=<optimized out>) at ./storage/maria/ma_pagecache.c:675
#6  0x0000020001ccac6c in flush_cached_blocks (pagecache=0x20002b3d3e0 <maria_pagecache_var>, file=<optimized out>, cache=0x2000c7fc4d0, end=0x2000c7fc4d8, type=<optimized out>, first_errno=<optimized out>) at ./storage/maria/ma_pagecache.c:4812
#7  0x0000020001ccb61c in flush_pagecache_blocks_int (pagecache=0x20002b3d3e0 <maria_pagecache_var>, file=<optimized out>, type=<optimized out>, filter=<optimized out>, filter_arg=<optimized out>) at ./storage/maria/ma_pagecache.c:5108
#8  0x0000020001cd0a30 in flush_pagecache_blocks_with_filter (pagecache=0x20002b3d3e0 <maria_pagecache_var>, file=<optimized out>, type=<optimized out>, filter=0x20001d0aa10 <filter_flush_bitmap_pages>, filter_arg=0x2001c22faa0) at ./storage/maria/ma_pagecache.c:5223
#9  0x0000020001d0d510 in _ma_bitmap_flush_all (share=0x2001c22f028) at ./storage/maria/ma_bitmap.c:551
#10 0x0000020001cd1f48 in collect_tables (checkpoint_start_log_horizon=<optimized out>, str=0x2000c8006e0) at ./storage/maria/ma_checkpoint.c:1082
#11 really_execute_checkpoint () at ./storage/maria/ma_checkpoint.c:198
#12 0x0000020001cd292c in ma_checkpoint_execute (level=<optimized out>, no_wait=<optimized out>) at ./storage/maria/ma_checkpoint.c:132
#13 0x0000020001cd2e90 in ma_checkpoint_execute (no_wait=1 '\001', level=CHECKPOINT_MEDIUM) at ./storage/maria/ma_checkpoint.c:723
#14 ma_checkpoint_background (arg=0x1e) at ./storage/maria/ma_checkpoint.c:621
#15 0x0000020001d63fc0 in pfs_spawn_thread (arg=0x20006ee1bf8) at ./storage/perfschema/pfs.cc:2201
#16 0x000002000029bc3c in start_thread () from /lib/alpha-linux-gnu/libpthread.so.0
#17 0x0000020000736f44 in ?? () from /lib/alpha-linux-gnu/libc.so.6.1
 
Thread 1 (Thread 0x20000ae9100 (LWP 16193)):
#0  0x00000200002a6f64 in pthread_kill () from /lib/alpha-linux-gnu/libpthread.so.0
#1  0x000002000215f804 in my_write_core (sig=<optimized out>) at ./mysys/stacktrace.c:519
#2  0x0000020001a333fc in handle_fatal_signal (sig=<optimized out>) at ./sql/signal_handler.cc:330
#3  <signal handler called>
#4  0x0000020000728fb0 in poll () from /lib/alpha-linux-gnu/libc.so.6.1
#5  0x0000020001699908 in poll (__timeout=-1, __nfds=2, __fds=0x11fd6f060) at /usr/include/alpha-linux-gnu/bits/poll2.h:41
#6  handle_connections_sockets () at ./sql/mysqld.cc:6217
#7  0x000002000169d2a8 in mysqld_main (argc=<optimized out>, argv=<optimized out>) at ./sql/mysqld.cc:5666
#8  0x0000020001652070 in main (argc=534179936, argv=0x2) at ./sql/main.cc:25

Full log at https://buildd.debian.org/status/fetch.php?pkg=mariadb-10.5&arch=alpha&ver=1%3A10.5.5-2&stamp=1602049326&raw=0

I cannot compare to the builds of 10.3 and 10.4 as in those alpha did not even build and thus the test suite has not run before.

Test name references https://jira.mariadb.org/browse/MDEV-539 by igor



 Comments   
Comment by Otto Kekäläinen [ 2020-10-11 ]

I filed this now downstream in Debian at https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=972061 in case some Alpha experts from Debian could help debug/fix this.

Comment by Tuukka Pasanen [ 2022-02-22 ]

@ottok Does this happen on 10.6 builds also? Can this be reproduced on any other arch as this little bit smells like out of memory or something.

Comment by Otto Kekäläinen [ 2023-01-21 ]

In 10.6 and 10.11 the Alpha arch does not even build anymore, so test suite has not been tested.
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1024040

Generated at Thu Feb 08 09:26:05 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.