Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-11638

Encryption causes race conditions in InnoDB shutdown

Details

    • 10.0.29

    Description

      Happened twice on commit 08f79bdeda89f5b8e09d99e7dc07fc9c (the previous one is a suspect, but it was mainly skipped by buildbot due to the arrival of a newer push).
      This particular failure hasn't happened before. The test used to fail, but differently.

      http://buildbot.askmonty.org/buildbot/builders/p8-rhel71-bintar-debug/builds/1484/steps/test/logs/stdio
      (it's not limited to p8, but the output is better in this build).

      encryption.innodb_onlinealter_encryption 'innodb' w2 [ fail ]  Found warnings/errors in server log file!
              Test ended at 2016-12-22 11:21:54
      line
      2016-12-22 11:21:48 70365707497856 [Warning] InnoDB: Trying to access missing tablespace 38
      Attempting backtrace. You can use the following information to find out
      2016-12-22 11:21:48 70366043798912 [ERROR] [FATAL] InnoDB: Page [page id: space=38, page number=743] still fixed or dirty
      ^ Found warnings in /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/mysql-test/var/2/log/mysqld.1.err
      

      Program terminated with signal 6, Aborted.
      #0  0x00003fff80a9eeb8 in __GI_raise (sig=<optimized out>) at ../sysdeps/unix/sysv/linux/raise.c:55
      55	../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
      #0  0x00003fff80a9eeb8 in __GI_raise (sig=<optimized out>) at ../sysdeps/unix/sysv/linux/raise.c:55
      #1  0x00003fff80aa19bc in __GI_abort () at abort.c:89
      #2  0x000000005c4f8fdc in ut_dbg_assertion_failed (expr=0x0, file=0x5cc70e48 "/home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/ut/ut0ut.cc", line=949) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/ut/ut0dbg.cc:67
      #3  0x000000005c4fe1d4 in ib::fatal::~fatal (this=0x3fff5f0b6610, __in_chrg=<optimized out>) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/ut/ut0ut.cc:949
      #4  0x000000005c599430 in buf_all_freed_instance (buf_pool=0x1002ca9b2b0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/buf/buf0buf.cc:6230
      #5  0x000000005c59ccc8 in buf_all_freed () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/buf/buf0buf.cc:7219
      #6  0x000000005c2b8ae0 in logs_empty_and_mark_files_at_shutdown () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/log/log0log.cc:2415
      #7  0x000000005c46f9c8 in innobase_shutdown_for_mysql () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/srv/srv0start.cc:2801
      #8  0x000000005c1d94b4 in innobase_end (hton=0x1002c70e160, type=HA_PANIC_CLOSE) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/handler/ha_innodb.cc:4844
      #9  0x000000005becf0d0 in ha_finalize_handlerton (plugin=0x1002c6d04c8) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/handler.cc:451
      #10 0x000000005bb9c914 in plugin_deinitialize (plugin=0x1002c6d04c8, ref_check=true) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/sql_plugin.cc:1217
      #11 0x000000005bb9cfc8 in reap_plugins () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/sql_plugin.cc:1294
      #12 0x000000005bb9f80c in plugin_shutdown () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/sql_plugin.cc:1945
      #13 0x000000005ba46984 in clean_up (print_message=true) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc:2201
      #14 0x000000005ba462c4 in unireg_end () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc:2076
      #15 0x000000005ba4608c in kill_server (sig_ptr=0x0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc:2003
      #16 0x000000005ba4610c in kill_server_thread (arg=0x3fff5f1d7280) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc:2026
      #17 0x000000005c93da00 in pfs_spawn_thread (arg=0x3fff1c001380) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/perfschema/pfs.cc:1862
      #18 0x00003fff812f7cec in start_thread (arg=0x3fff5f0b7d80) at pthread_create.c:312
      #19 0x00003fff80b91140 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
       
      Thread 12 (LWP 17819):
      #0  __libc_fork () at ../sysdeps/nptl/fork.c:215
      #1  0x00003fff81303f48 in __fork () at pt-fork.c:25
      #2  0x000000005c9eea10 in my_addr_resolve_init () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/mysys/my_addr_resolve.c:245
      #3  0x000000005c9bfe1c in print_with_addr_resolve (addrs=0x3fff4affa720, n=18) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/mysys/stacktrace.c:244
      #4  0x000000005c9c0028 in my_print_stacktrace (stack_bottom=0x0, thread_stack=297984) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/mysys/stacktrace.c:271
      #5  0x000000005becc3b4 in handle_fatal_signal (sig=6) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/signal_handler.cc:166
      #6  <signal handler called>
      #7  0x00003fff80a9eeb8 in __GI_raise (sig=<optimized out>) at ../sysdeps/unix/sysv/linux/raise.c:55
      #8  0x00003fff80aa19bc in __GI_abort () at abort.c:89
      #9  0x000000005c4f8fdc in ut_dbg_assertion_failed (expr=0x5cc8a6e8 "found", file=0x5cc889c0 "/home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/buf/buf0buf.cc", line=4180) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/ut/ut0dbg.cc:67
      #10 0x000000005c591948 in buf_page_get_gen (page_id=..., page_size=..., rw_latch=1, guess=0x0, mode=10, file=0x5cc0b708 "/home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/ibuf/ibuf0ibuf.cc", line=4584, mtr=0x3fff4affd7d0, err=0x3fff4affc178) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/buf/buf0buf.cc:4180
      #11 0x000000005c546094 in btr_cur_search_to_nth_level (index=0x1002cbc6568, level=0, tuple=0x3fff18010238, mode=PAGE_CUR_GE, latch_mode=2, cursor=0x3fff4affd418, has_search_latch=0, file=0x5cc0b708 "/home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/ibuf/ibuf0ibuf.cc", line=4584, mtr=0x3fff4affd7d0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/btr/btr0cur.cc:1108
      #12 0x000000005c55d880 in btr_pcur_open_low (index=0x1002cbc6568, level=0, tuple=0x3fff18010238, mode=PAGE_CUR_GE, latch_mode=2, cursor=0x3fff4affd418, file=0x5cc0b708 "/home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/ibuf/ibuf0ibuf.cc", line=4584, mtr=0x3fff4affd7d0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/include/btr0pcur.ic:457
      #13 0x000000005c55f5b8 in btr_pcur_open_on_user_rec_func (index=0x1002cbc6568, tuple=0x3fff18010238, mode=PAGE_CUR_GE, latch_mode=2, cursor=0x3fff4affd418, file=0x5cc0b708 "/home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/ibuf/ibuf0ibuf.cc", line=4584, mtr=0x3fff4affd7d0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/btr/btr0pcur.cc:599
      #14 0x000000005c278104 in ibuf_merge_or_delete_for_page (block=0x0, page_id=..., page_size=0x3fff4affe0f8, update_ibuf_bitmap=0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/ibuf/ibuf0ibuf.cc:4584
      #15 0x000000005c592e58 in buf_page_get_gen (page_id=..., page_size=..., rw_latch=2, guess=0x0, mode=16, file=0x5ccb00b8 "/home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/fil/fil0crypt.cc", line=1927, mtr=0x3fff4affe100, err=0x3fff4affe004) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/buf/buf0buf.cc:4577
      #16 0x000000005c673928 in fil_crypt_get_page_throttle_func (state=0x3fff4affe6e0, space=38, page_size=..., offset=743, mtr=0x3fff4affe100, sleeptime_ms=0x3fff4affe0b0, file=0x5ccb00b8 "/home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/fil/fil0crypt.cc", line=1927) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/fil/fil0crypt.cc:1812
      #17 0x000000005c673d98 in fil_crypt_rotate_page (key_state=0x3fff4affe6d4, state=0x3fff4affe6e0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/fil/fil0crypt.cc:1924
      #18 0x000000005c6744d0 in fil_crypt_rotate_pages (key_state=0x3fff4affe6d4, state=0x3fff4affe6e0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/fil/fil0crypt.cc:2092
      #19 0x000000005c674f70 in fil_crypt_thread (arg=0x0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/fil/fil0crypt.cc:2324
      #20 0x00003fff812f7cec in start_thread (arg=0x3fff4afff180) at pthread_create.c:312
      #21 0x00003fff80b91140 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
       
      Thread 11 (LWP 17814):
      #0  0x00003fff812ff7d0 in __pthread_cond_wait (cond=0x1002c747090, mutex=0x1002c747068) at pthread_cond_wait.c:188
      #1  0x000000005c301f10 in os_event::wait (this=0x1002c747050) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0event.cc:166
      #2  0x000000005c3013e0 in os_event::wait_low (this=0x1002c747050, reset_sig_count=1) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0event.cc:336
      #3  0x000000005c301a3c in os_event_wait_low (event=0x1002c747050, reset_sig_count=0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0event.cc:535
      #4  0x000000005c45fa88 in srv_master_thread (arg=0x0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/srv/srv0srv.cc:2650
      #5  0x00003fff812f7cec in start_thread (arg=0x3fff59def180) at pthread_create.c:312
      #6  0x00003fff80b91140 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
       
      Thread 10 (LWP 17804):
      #0  0x00003fff81240738 in __io_getevents_0_4 () from /lib64/libaio.so.1
      #1  0x00003fff812407a0 in io_getevents () from /lib64/libaio.so.1
      #2  0x000000005c2ec838 in LinuxAIOHandler::collect (this=0x3fff5e82e5f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:2519
      #3  0x000000005c2ece70 in LinuxAIOHandler::poll (this=0x3fff5e82e5f0, m1=0x3fff5e82e6e0, m2=0x3fff5e82e6e8, request=0x3fff5e82e6f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:2665
      #4  0x000000005c2ed040 in os_aio_linux_handler (global_segment=1, m1=0x3fff5e82e6e0, m2=0x3fff5e82e6e8, request=0x3fff5e82e6f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:2721
      #5  0x000000005c2f33a8 in os_aio_handler (segment=1, m1=0x3fff5e82e6e0, m2=0x3fff5e82e6e8, request=0x3fff5e82e6f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:6450
      #6  0x000000005c6626c8 in fil_aio_wait (segment=1) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/fil/fil0fil.cc:5810
      #7  0x000000005c466e80 in io_handler_thread (arg=0x5d3d5a38 <n+8>) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/srv/srv0start.cc:331
      #8  0x00003fff812f7cec in start_thread (arg=0x3fff5e82f180) at pthread_create.c:312
      #9  0x00003fff80b91140 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
       
      Thread 9 (LWP 17808):
      #0  0x00003fff81240738 in __io_getevents_0_4 () from /lib64/libaio.so.1
      #1  0x00003fff812407a0 in io_getevents () from /lib64/libaio.so.1
      #2  0x000000005c2ec838 in LinuxAIOHandler::collect (this=0x3fff5c82e5f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:2519
      #3  0x000000005c2ece70 in LinuxAIOHandler::poll (this=0x3fff5c82e5f0, m1=0x3fff5c82e6e0, m2=0x3fff5c82e6e8, request=0x3fff5c82e6f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:2665
      #4  0x000000005c2ed040 in os_aio_linux_handler (global_segment=5, m1=0x3fff5c82e6e0, m2=0x3fff5c82e6e8, request=0x3fff5c82e6f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:2721
      #5  0x000000005c2f33a8 in os_aio_handler (segment=5, m1=0x3fff5c82e6e0, m2=0x3fff5c82e6e8, request=0x3fff5c82e6f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:6450
      #6  0x000000005c6626c8 in fil_aio_wait (segment=5) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/fil/fil0fil.cc:5810
      #7  0x000000005c466e80 in io_handler_thread (arg=0x5d3d5a58 <n+40>) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/srv/srv0start.cc:331
      #8  0x00003fff812f7cec in start_thread (arg=0x3fff5c82f180) at pthread_create.c:312
      #9  0x00003fff80b91140 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
       
      Thread 8 (LWP 17807):
      #0  0x00003fff81240738 in __io_getevents_0_4 () from /lib64/libaio.so.1
      #1  0x00003fff812407a0 in io_getevents () from /lib64/libaio.so.1
      #2  0x000000005c2ec838 in LinuxAIOHandler::collect (this=0x3fff5d02e5f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:2519
      #3  0x000000005c2ece70 in LinuxAIOHandler::poll (this=0x3fff5d02e5f0, m1=0x3fff5d02e6e0, m2=0x3fff5d02e6e8, request=0x3fff5d02e6f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:2665
      #4  0x000000005c2ed040 in os_aio_linux_handler (global_segment=4, m1=0x3fff5d02e6e0, m2=0x3fff5d02e6e8, request=0x3fff5d02e6f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:2721
      #5  0x000000005c2f33a8 in os_aio_handler (segment=4, m1=0x3fff5d02e6e0, m2=0x3fff5d02e6e8, request=0x3fff5d02e6f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:6450
      #6  0x000000005c6626c8 in fil_aio_wait (segment=4) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/fil/fil0fil.cc:5810
      #7  0x000000005c466e80 in io_handler_thread (arg=0x5d3d5a50 <n+32>) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/srv/srv0start.cc:331
      #8  0x00003fff812f7cec in start_thread (arg=0x3fff5d02f180) at pthread_create.c:312
      #9  0x00003fff80b91140 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
       
      Thread 7 (LWP 17805):
      #0  0x00003fff81240738 in __io_getevents_0_4 () from /lib64/libaio.so.1
      #1  0x00003fff812407a0 in io_getevents () from /lib64/libaio.so.1
      #2  0x000000005c2ec838 in LinuxAIOHandler::collect (this=0x3fff5e02e5f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:2519
      #3  0x000000005c2ece70 in LinuxAIOHandler::poll (this=0x3fff5e02e5f0, m1=0x3fff5e02e6e0, m2=0x3fff5e02e6e8, request=0x3fff5e02e6f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:2665
      #4  0x000000005c2ed040 in os_aio_linux_handler (global_segment=2, m1=0x3fff5e02e6e0, m2=0x3fff5e02e6e8, request=0x3fff5e02e6f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:2721
      #5  0x000000005c2f33a8 in os_aio_handler (segment=2, m1=0x3fff5e02e6e0, m2=0x3fff5e02e6e8, request=0x3fff5e02e6f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:6450
      #6  0x000000005c6626c8 in fil_aio_wait (segment=2) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/fil/fil0fil.cc:5810
      #7  0x000000005c466e80 in io_handler_thread (arg=0x5d3d5a40 <n+16>) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/srv/srv0start.cc:331
      #8  0x00003fff812f7cec in start_thread (arg=0x3fff5e02f180) at pthread_create.c:312
      #9  0x00003fff80b91140 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
       
      Thread 6 (LWP 17829):
      #0  0x00003fff81305714 in do_sigwait (sig=0x3fff5f1d7280, set=<optimized out>) at ../sysdeps/unix/sysv/linux/sigwait.c:61
      #1  __sigwait (set=<optimized out>, sig=0x3fff5f1d7280) at ../sysdeps/unix/sysv/linux/sigwait.c:98
      #2  0x000000005ba4a624 in signal_hand (arg=0x0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc:3560
      #3  0x000000005c93da00 in pfs_spawn_thread (arg=0x1002cee7b40) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/perfschema/pfs.cc:1862
      #4  0x00003fff812f7cec in start_thread (arg=0x3fff5f1d7d80) at pthread_create.c:312
      #5  0x00003fff80b91140 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
       
      Thread 5 (LWP 17806):
      #0  0x00003fff81240738 in __io_getevents_0_4 () from /lib64/libaio.so.1
      #1  0x00003fff812407a0 in io_getevents () from /lib64/libaio.so.1
      #2  0x000000005c2ec838 in LinuxAIOHandler::collect (this=0x3fff5d82e5f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:2519
      #3  0x000000005c2ece70 in LinuxAIOHandler::poll (this=0x3fff5d82e5f0, m1=0x3fff5d82e6e0, m2=0x3fff5d82e6e8, request=0x3fff5d82e6f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:2665
      #4  0x000000005c2ed040 in os_aio_linux_handler (global_segment=3, m1=0x3fff5d82e6e0, m2=0x3fff5d82e6e8, request=0x3fff5d82e6f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:2721
      #5  0x000000005c2f33a8 in os_aio_handler (segment=3, m1=0x3fff5d82e6e0, m2=0x3fff5d82e6e8, request=0x3fff5d82e6f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:6450
      #6  0x000000005c6626c8 in fil_aio_wait (segment=3) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/fil/fil0fil.cc:5810
      #7  0x000000005c466e80 in io_handler_thread (arg=0x5d3d5a48 <n+24>) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/srv/srv0start.cc:331
      #8  0x00003fff812f7cec in start_thread (arg=0x3fff5d82f180) at pthread_create.c:312
      #9  0x00003fff80b91140 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
       
      Thread 4 (LWP 17801):
      #0  0x00003fff812ffcc0 in __pthread_cond_timedwait (cond=0x5dc006b0 <COND_timer>, mutex=0x5dc00628 <LOCK_timer+40>, abstime=0x3fff7c61e720) at pthread_cond_timedwait.c:199
      #1  0x000000005c9c7eec in safe_cond_timedwait (cond=0x5dc006b0 <COND_timer>, mp=0x5dc00600 <LOCK_timer>, abstime=0x3fff7c61e720, file=0x5cd234f8 "/home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/include/mysql/psi/mysql_thread.h", line=1175) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/mysys/thr_mutex.c:545
      #2  0x000000005c9c97b4 in inline_mysql_cond_timedwait (that=0x5dc006b0 <COND_timer>, mutex=0x5dc00600 <LOCK_timer>, abstime=0x3fff7c61e720, src_file=0x5cd23568 "/home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/mysys/thr_timer.c", src_line=292) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/include/mysql/psi/mysql_thread.h:1175
      #3  0x000000005c9ca7cc in timer_handler (arg=0x0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/mysys/thr_timer.c:292
      #4  0x000000005c93da00 in pfs_spawn_thread (arg=0x1002c6cc080) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/perfschema/pfs.cc:1862
      #5  0x00003fff812f7cec in start_thread (arg=0x3fff7c61f180) at pthread_create.c:312
      #6  0x00003fff80b91140 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
       
      Thread 3 (LWP 17803):
      #0  0x00003fff81240738 in __io_getevents_0_4 () from /lib64/libaio.so.1
      #1  0x00003fff812407a0 in io_getevents () from /lib64/libaio.so.1
      #2  0x000000005c2ec838 in LinuxAIOHandler::collect (this=0x3fff5f02e5f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:2519
      #3  0x000000005c2ece70 in LinuxAIOHandler::poll (this=0x3fff5f02e5f0, m1=0x3fff5f02e6e0, m2=0x3fff5f02e6e8, request=0x3fff5f02e6f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:2665
      #4  0x000000005c2ed040 in os_aio_linux_handler (global_segment=0, m1=0x3fff5f02e6e0, m2=0x3fff5f02e6e8, request=0x3fff5f02e6f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:2721
      #5  0x000000005c2f33a8 in os_aio_handler (segment=0, m1=0x3fff5f02e6e0, m2=0x3fff5f02e6e8, request=0x3fff5f02e6f0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/os/os0file.cc:6450
      #6  0x000000005c6626c8 in fil_aio_wait (segment=0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/fil/fil0fil.cc:5810
      #7  0x000000005c466e80 in io_handler_thread (arg=0x5d3d5a30 <n>) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/srv/srv0start.cc:331
      #8  0x00003fff812f7cec in start_thread (arg=0x3fff5f02f180) at pthread_create.c:312
      #9  0x00003fff80b91140 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
       
      Thread 2 (LWP 17800):
      #0  0x00003fff812ff7d0 in __pthread_cond_wait (cond=0x5d34db40 <COND_thread_count>, mutex=0x5d34c9e8 <LOCK_thread_count+40>) at pthread_cond_wait.c:188
      #1  0x000000005c9c7b10 in safe_cond_wait (cond=0x5d34db40 <COND_thread_count>, mp=0x5d34c9c0 <LOCK_thread_count>, file=0x5cab96b8 "/home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/include/mysql/psi/mysql_thread.h", line=1138) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/mysys/thr_mutex.c:491
      #2  0x000000005ba41560 in inline_mysql_cond_wait (that=0x5d34db40 <COND_thread_count>, mutex=0x5d34c9c0 <LOCK_thread_count>, src_file=0x5cabb690 "/home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc", src_line=6098) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/include/mysql/psi/mysql_thread.h:1138
      #3  0x000000005ba5157c in mysqld_main (argc=151, argv=0x1002c53c180) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc:6098
      #4  0x000000005ba40638 in main (argc=30, argv=0x3fffe9c7fce8) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/main.cc:25
       
      Thread 1 (LWP 18606):
      #0  0x00003fff80a9eeb8 in __GI_raise (sig=<optimized out>) at ../sysdeps/unix/sysv/linux/raise.c:55
      #1  0x00003fff80aa19bc in __GI_abort () at abort.c:89
      #2  0x000000005c4f8fdc in ut_dbg_assertion_failed (expr=0x0, file=0x5cc70e48 "/home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/ut/ut0ut.cc", line=949) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/ut/ut0dbg.cc:67
      #3  0x000000005c4fe1d4 in ib::fatal::~fatal (this=0x3fff5f0b6610, __in_chrg=<optimized out>) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/ut/ut0ut.cc:949
      #4  0x000000005c599430 in buf_all_freed_instance (buf_pool=0x1002ca9b2b0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/buf/buf0buf.cc:6230
      #5  0x000000005c59ccc8 in buf_all_freed () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/buf/buf0buf.cc:7219
      #6  0x000000005c2b8ae0 in logs_empty_and_mark_files_at_shutdown () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/log/log0log.cc:2415
      #7  0x000000005c46f9c8 in innobase_shutdown_for_mysql () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/srv/srv0start.cc:2801
      #8  0x000000005c1d94b4 in innobase_end (hton=0x1002c70e160, type=HA_PANIC_CLOSE) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/handler/ha_innodb.cc:4844
      #9  0x000000005becf0d0 in ha_finalize_handlerton (plugin=0x1002c6d04c8) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/handler.cc:451
      #10 0x000000005bb9c914 in plugin_deinitialize (plugin=0x1002c6d04c8, ref_check=true) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/sql_plugin.cc:1217
      #11 0x000000005bb9cfc8 in reap_plugins () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/sql_plugin.cc:1294
      #12 0x000000005bb9f80c in plugin_shutdown () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/sql_plugin.cc:1945
      #13 0x000000005ba46984 in clean_up (print_message=true) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc:2201
      #14 0x000000005ba462c4 in unireg_end () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc:2076
      #15 0x000000005ba4608c in kill_server (sig_ptr=0x0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc:2003
      #16 0x000000005ba4610c in kill_server_thread (arg=0x3fff5f1d7280) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc:2026
      #17 0x000000005c93da00 in pfs_spawn_thread (arg=0x3fff1c001380) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/perfschema/pfs.cc:1862
      #18 0x00003fff812f7cec in start_thread (arg=0x3fff5f0b7d80) at pthread_create.c:312
      #19 0x00003fff80b91140 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
      

      encryption.innodb-bad-key-change3 - failed several times on d6a1f9f10f21bfb5198b81c40e097556 and 08f79bdeda89f5b8e09d99e7dc07fc9c
      http://buildbot.askmonty.org/buildbot/builders/p8-rhel71-bintar-debug/builds/1484/steps/test/logs/stdio

      encryption.innodb-bad-key-change3 'innodb' w2 [ fail ]  Found warnings/errors in server log file!
              Test ended at 2016-12-22 11:29:29
      line
      Attempting backtrace. You can use the following information to find out
      ^ Found warnings in /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/mysql-test/var/2/log/mysqld.1.err
      

      Program terminated with signal 6, Aborted.
      #0  0x00003fff82cc0ef0 in __pthread_kill (threadid=<optimized out>, signo=<optimized out>) at ../sysdeps/unix/sysv/linux/pthread_kill.c:60
      60	../sysdeps/unix/sysv/linux/pthread_kill.c: No such file or directory.
      #0  0x00003fff82cc0ef0 in __pthread_kill (threadid=<optimized out>, signo=<optimized out>) at ../sysdeps/unix/sysv/linux/pthread_kill.c:60
      #1  0x000000003e0e0180 in my_write_core (sig=6) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/mysys/stacktrace.c:477
      #2  0x000000003d5ec924 in handle_fatal_signal (sig=6) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/signal_handler.cc:294
      #3  <signal handler called>
      #4  0x00003fff8245eeb8 in __GI_raise (sig=<optimized out>) at ../sysdeps/unix/sysv/linux/raise.c:55
      #5  0x00003fff824619bc in __GI_abort () at abort.c:89
      #6  0x00003fff824ac224 in __libc_message (do_abort=<optimized out>, fmt=<optimized out>) at ../sysdeps/posix/libc_fatal.c:175
      #7  0x00003fff824bbd58 in malloc_printerr (ptr=<optimized out>, str=0x3fff825c2b70 "munmap_chunk(): invalid pointer", action=3) at malloc.c:4958
      #8  munmap_chunk (p=<optimized out>) at malloc.c:2815
      #9  __GI___libc_free (mem=<optimized out>) at malloc.c:2940
      #10 0x00003fff82796898 in operator delete(void*) () from /opt/at8.0/lib64/power8/libstdc++.so.6
      #11 0x000000003dba9948 in LatchCounter::~LatchCounter (this=0x100078ed658, __in_chrg=<optimized out>) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/include/sync0types.h:586
      #12 0x000000003dbacd80 in LatchMeta<LatchCounter>::~LatchMeta (this=0x100078ed630, __in_chrg=<optimized out>) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/include/sync0types.h:773
      #13 0x000000003dba9238 in sync_latch_meta_destroy () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/sync/sync0debug.cc:1593
      #14 0x000000003dba9698 in sync_check_close () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/sync/sync0debug.cc:1811
      #15 0x000000003db8fcdc in innobase_shutdown_for_mysql () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/srv/srv0start.cc:2886
      #16 0x000000003d8f94b4 in innobase_end (hton=0x100078cc800, type=HA_PANIC_CLOSE) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/handler/ha_innodb.cc:4844
      #17 0x000000003d5ef0d0 in ha_finalize_handlerton (plugin=0x10007890428) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/handler.cc:451
      #18 0x000000003d2bc914 in plugin_deinitialize (plugin=0x10007890428, ref_check=true) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/sql_plugin.cc:1217
      #19 0x000000003d2bcfc8 in reap_plugins () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/sql_plugin.cc:1294
      #20 0x000000003d2bf80c in plugin_shutdown () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/sql_plugin.cc:1945
      #21 0x000000003d166984 in clean_up (print_message=true) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc:2201
      #22 0x000000003d1662c4 in unireg_end () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc:2076
      #23 0x000000003d16608c in kill_server (sig_ptr=0x0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc:2003
      #24 0x000000003d16610c in kill_server_thread (arg=0x3fff60bc7280) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc:2026
      #25 0x000000003e05da00 in pfs_spawn_thread (arg=0x3fff28001380) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/perfschema/pfs.cc:1862
      #26 0x00003fff82cb7cec in start_thread (arg=0x3fff60aa7d80) at pthread_create.c:312
      #27 0x00003fff82551140 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
       
      Thread 4 (LWP 24982):
      #0  0x00003fff82cbfcc0 in __pthread_cond_timedwait (cond=0x3f3206b0 <COND_timer>, mutex=0x3f320628 <LOCK_timer+40>, abstime=0x3fff7dfde720) at pthread_cond_timedwait.c:199
      #1  0x000000003e0e7eec in safe_cond_timedwait (cond=0x3f3206b0 <COND_timer>, mp=0x3f320600 <LOCK_timer>, abstime=0x3fff7dfde720, file=0x3e4434f8 "/home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/include/mysql/psi/mysql_thread.h", line=1175) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/mysys/thr_mutex.c:545
      #2  0x000000003e0e97b4 in inline_mysql_cond_timedwait (that=0x3f3206b0 <COND_timer>, mutex=0x3f320600 <LOCK_timer>, abstime=0x3fff7dfde720, src_file=0x3e443568 "/home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/mysys/thr_timer.c", src_line=292) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/include/mysql/psi/mysql_thread.h:1175
      #3  0x000000003e0ea7cc in timer_handler (arg=0x0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/mysys/thr_timer.c:292
      #4  0x000000003e05da00 in pfs_spawn_thread (arg=0x1000788bfe0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/perfschema/pfs.cc:1862
      #5  0x00003fff82cb7cec in start_thread (arg=0x3fff7dfdf180) at pthread_create.c:312
      #6  0x00003fff82551140 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
       
      Thread 3 (LWP 25006):
      #0  0x00003fff82cc5714 in do_sigwait (sig=0x3fff60bc7280, set=<optimized out>) at ../sysdeps/unix/sysv/linux/sigwait.c:61
      #1  __sigwait (set=<optimized out>, sig=0x3fff60bc7280) at ../sysdeps/unix/sysv/linux/sigwait.c:98
      #2  0x000000003d16a624 in signal_hand (arg=0x0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc:3560
      #3  0x000000003e05da00 in pfs_spawn_thread (arg=0x1000809cde0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/perfschema/pfs.cc:1862
      #4  0x00003fff82cb7cec in start_thread (arg=0x3fff60bc7d80) at pthread_create.c:312
      #5  0x00003fff82551140 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
       
      Thread 2 (LWP 24981):
      #0  0x00003fff82cbf7d0 in __pthread_cond_wait (cond=0x3ea6db40 <COND_thread_count>, mutex=0x3ea6c9e8 <LOCK_thread_count+40>) at pthread_cond_wait.c:188
      #1  0x000000003e0e7b10 in safe_cond_wait (cond=0x3ea6db40 <COND_thread_count>, mp=0x3ea6c9c0 <LOCK_thread_count>, file=0x3e1d96b8 "/home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/include/mysql/psi/mysql_thread.h", line=1138) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/mysys/thr_mutex.c:491
      #2  0x000000003d161560 in inline_mysql_cond_wait (that=0x3ea6db40 <COND_thread_count>, mutex=0x3ea6c9c0 <LOCK_thread_count>, src_file=0x3e1db690 "/home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc", src_line=6098) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/include/mysql/psi/mysql_thread.h:1138
      #3  0x000000003d17157c in mysqld_main (argc=143, argv=0x100076fc180) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc:6098
      #4  0x000000003d160638 in main (argc=22, argv=0x3ffffddac5e8) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/main.cc:25
       
      Thread 1 (LWP 25019):
      #0  0x00003fff82cc0ef0 in __pthread_kill (threadid=<optimized out>, signo=<optimized out>) at ../sysdeps/unix/sysv/linux/pthread_kill.c:60
      #1  0x000000003e0e0180 in my_write_core (sig=6) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/mysys/stacktrace.c:477
      #2  0x000000003d5ec924 in handle_fatal_signal (sig=6) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/signal_handler.cc:294
      #3  <signal handler called>
      #4  0x00003fff8245eeb8 in __GI_raise (sig=<optimized out>) at ../sysdeps/unix/sysv/linux/raise.c:55
      #5  0x00003fff824619bc in __GI_abort () at abort.c:89
      #6  0x00003fff824ac224 in __libc_message (do_abort=<optimized out>, fmt=<optimized out>) at ../sysdeps/posix/libc_fatal.c:175
      #7  0x00003fff824bbd58 in malloc_printerr (ptr=<optimized out>, str=0x3fff825c2b70 "munmap_chunk(): invalid pointer", action=3) at malloc.c:4958
      #8  munmap_chunk (p=<optimized out>) at malloc.c:2815
      #9  __GI___libc_free (mem=<optimized out>) at malloc.c:2940
      #10 0x00003fff82796898 in operator delete(void*) () from /opt/at8.0/lib64/power8/libstdc++.so.6
      #11 0x000000003dba9948 in LatchCounter::~LatchCounter (this=0x100078ed658, __in_chrg=<optimized out>) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/include/sync0types.h:586
      #12 0x000000003dbacd80 in LatchMeta<LatchCounter>::~LatchMeta (this=0x100078ed630, __in_chrg=<optimized out>) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/include/sync0types.h:773
      #13 0x000000003dba9238 in sync_latch_meta_destroy () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/sync/sync0debug.cc:1593
      #14 0x000000003dba9698 in sync_check_close () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/sync/sync0debug.cc:1811
      #15 0x000000003db8fcdc in innobase_shutdown_for_mysql () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/srv/srv0start.cc:2886
      #16 0x000000003d8f94b4 in innobase_end (hton=0x100078cc800, type=HA_PANIC_CLOSE) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/innobase/handler/ha_innodb.cc:4844
      #17 0x000000003d5ef0d0 in ha_finalize_handlerton (plugin=0x10007890428) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/handler.cc:451
      #18 0x000000003d2bc914 in plugin_deinitialize (plugin=0x10007890428, ref_check=true) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/sql_plugin.cc:1217
      #19 0x000000003d2bcfc8 in reap_plugins () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/sql_plugin.cc:1294
      #20 0x000000003d2bf80c in plugin_shutdown () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/sql_plugin.cc:1945
      #21 0x000000003d166984 in clean_up (print_message=true) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc:2201
      #22 0x000000003d1662c4 in unireg_end () at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc:2076
      #23 0x000000003d16608c in kill_server (sig_ptr=0x0) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc:2003
      #24 0x000000003d16610c in kill_server_thread (arg=0x3fff60bc7280) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld.cc:2026
      #25 0x000000003e05da00 in pfs_spawn_thread (arg=0x3fff28001380) at /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/storage/perfschema/pfs.cc:1862
      #26 0x00003fff82cb7cec in start_thread (arg=0x3fff60aa7d80) at pthread_create.c:312
      #27 0x00003fff82551140 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
      

      Attachments

        Issue Links

          Activity

            Variation of a failure in innobase_shutdown_for_mysql:

            #3  <signal handler called>
            #4  0x00007f7740fef067 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
            #5  0x00007f7740ff0448 in __GI_abort () at abort.c:89
            #6  0x00007f774376e284 in ut_dbg_assertion_failed (expr=expr@entry=0x7f7743c32b03 "node->n_pending == 0", file=file@entry=0x7f7743c30090 "/data/src/10.2/storage/innobase/fil/fil0fil.cc", line=line@entry=880) at /data/src/10.2/storage/innobase/ut/ut0dbg.cc:67
            #7  0x00007f774385ce3e in fil_node_close_file (node=node@entry=0x7f773cff9780) at /data/src/10.2/storage/innobase/fil/fil0fil.cc:880
            #8  0x00007f774385ec0d in fil_close_all_files () at /data/src/10.2/storage/innobase/fil/fil0fil.cc:1820
            #9  0x00007f77435e697a in logs_empty_and_mark_files_at_shutdown () at /data/src/10.2/storage/innobase/log/log0log.cc:2409
            #10 0x00007f7743701b1e in innobase_shutdown_for_mysql () at /data/src/10.2/storage/innobase/srv/srv0start.cc:2802
            #11 0x00007f774355b346 in innobase_end (hton=<optimized out>, type=<optimized out>) at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:4862
            #12 0x00007f774336d2e2 in ha_finalize_handlerton (plugin=0x7f773bfdd880) at /data/src/10.2/sql/handler.cc:451
            #13 0x00007f77431974a2 in plugin_deinitialize (plugin=0x7f773bfdd880, ref_check=ref_check@entry=true) at /data/src/10.2/sql/sql_plugin.cc:1217
            #14 0x00007f774319bba0 in reap_plugins () at /data/src/10.2/sql/sql_plugin.cc:1294
            #15 0x00007f774319c5e6 in plugin_shutdown () at /data/src/10.2/sql/sql_plugin.cc:1945
            #16 0x00007f77430d2e41 in clean_up (print_message=print_message@entry=true) at /data/src/10.2/sql/mysqld.cc:2201
            #17 0x00007f77430d75ae in unireg_end () at /data/src/10.2/sql/mysqld.cc:2076
            #18 0x00007f77430de21b in kill_server (sig_ptr=sig_ptr@entry=0x0) at /data/src/10.2/sql/mysqld.cc:2003
            #19 0x00007f77430de28b in kill_server_thread (arg=arg@entry=0x7f774421d884) at /data/src/10.2/sql/mysqld.cc:2026
            #20 0x00007f77435329d7 in pfs_spawn_thread (arg=0x7f771802c0f0) at /data/src/10.2/storage/perfschema/pfs.cc:1862
            #21 0x00007f77428820a4 in start_thread (arg=0x7f7744140300) at pthread_create.c:309
            #22 0x00007f77410a287d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
            

            elenst Elena Stepanova added a comment - Variation of a failure in innobase_shutdown_for_mysql : #3 <signal handler called> #4 0x00007f7740fef067 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56 #5 0x00007f7740ff0448 in __GI_abort () at abort.c:89 #6 0x00007f774376e284 in ut_dbg_assertion_failed (expr=expr@entry=0x7f7743c32b03 "node->n_pending == 0", file=file@entry=0x7f7743c30090 "/data/src/10.2/storage/innobase/fil/fil0fil.cc", line=line@entry=880) at /data/src/10.2/storage/innobase/ut/ut0dbg.cc:67 #7 0x00007f774385ce3e in fil_node_close_file (node=node@entry=0x7f773cff9780) at /data/src/10.2/storage/innobase/fil/fil0fil.cc:880 #8 0x00007f774385ec0d in fil_close_all_files () at /data/src/10.2/storage/innobase/fil/fil0fil.cc:1820 #9 0x00007f77435e697a in logs_empty_and_mark_files_at_shutdown () at /data/src/10.2/storage/innobase/log/log0log.cc:2409 #10 0x00007f7743701b1e in innobase_shutdown_for_mysql () at /data/src/10.2/storage/innobase/srv/srv0start.cc:2802 #11 0x00007f774355b346 in innobase_end (hton=<optimized out>, type=<optimized out>) at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:4862 #12 0x00007f774336d2e2 in ha_finalize_handlerton (plugin=0x7f773bfdd880) at /data/src/10.2/sql/handler.cc:451 #13 0x00007f77431974a2 in plugin_deinitialize (plugin=0x7f773bfdd880, ref_check=ref_check@entry=true) at /data/src/10.2/sql/sql_plugin.cc:1217 #14 0x00007f774319bba0 in reap_plugins () at /data/src/10.2/sql/sql_plugin.cc:1294 #15 0x00007f774319c5e6 in plugin_shutdown () at /data/src/10.2/sql/sql_plugin.cc:1945 #16 0x00007f77430d2e41 in clean_up (print_message=print_message@entry=true) at /data/src/10.2/sql/mysqld.cc:2201 #17 0x00007f77430d75ae in unireg_end () at /data/src/10.2/sql/mysqld.cc:2076 #18 0x00007f77430de21b in kill_server (sig_ptr=sig_ptr@entry=0x0) at /data/src/10.2/sql/mysqld.cc:2003 #19 0x00007f77430de28b in kill_server_thread (arg=arg@entry=0x7f774421d884) at /data/src/10.2/sql/mysqld.cc:2026 #20 0x00007f77435329d7 in pfs_spawn_thread (arg=0x7f771802c0f0) at /data/src/10.2/storage/perfschema/pfs.cc:1862 #21 0x00007f77428820a4 in start_thread (arg=0x7f7744140300) at pthread_create.c:309 #22 0x00007f77410a287d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
            marko Marko Mäkelä added a comment - - edited

            The assertion node->n_pending==0 fails for the InnoDB system tablespace.
            The call to fil_close_all_files() in logs_empty_and_mark_files_at_shutdown() expects all files to be in an idle state. Somehow we failed to properly finish an I/O request at shutdown.

            The buf_pool_ptr->flush_list is empty, but it is possible that a write from the buffer pool to the file buffers was completed, and the fsync() is still pending. There are 413 pages in the buffer pool. Many of these pages were modified while the server was running.
            One example is (buf_page_t *) 0x7f772b3a79c0 which is space 0 (system tablespace), page 8 (root page of the clustered index of the SYS_TABLES table), newest_modification = 1804026. I suppose that this page was recently changed due to a DROP TABLE that was executed at the end of the test, just before the shutdown.

            Interestingly, log_sys->lsn == log_sys->last_checkpoint_lsn == log_sys->next_checkpoint_lsn == 1804880. That is 854 bytes after the newest_modification of the above block. This should be OK, because newest_modification is never reset to 0. The changes probably were already written to the data file.

            There are no clues in the buffer pool. The fil_node_t for which the assertion fails is this one:

            (gdb) p *fil_system.space_list.start.chain.start 
            $110 = {space = 0x7f7740413a80, name = 0x7f7740418370 "./ibdata1", 
              is_open = true, handle = 3, sync_event = 0x7f772cbf0c00, 
              is_raw_disk = false, size = 768, init_size = 768, 
              max_size = 18446744073709551614, n_pending = 1, n_pending_flushes = 0, 
              being_extended = false, modification_counter = 200, flush_counter = 200, 
              chain = {prev = 0x0, next = 0x0}, LRU = {prev = 0x0, next = 0x0}, 
              punch_hole = true, block_size = 4096, atomic_write = false, magic_n = 89389}
            

            The node->n_pending is incremented by fil_node_prepare_for_io() and decremented by fil_node_complete_io(). The only case where a call to the latter could be missed is when a call to fil_aio_wait() is skipped or os_aio_handler() fails to return the fil_node_t pointer.

            The only caller of fil_aio_wait() is io_handler_thread(). Maybe the termination condition needs to be revised so that pending work by encryption threads will be properly finished?

                    while (srv_shutdown_state != SRV_SHUTDOWN_EXIT_THREADS
                           || buf_page_cleaner_is_active
                           || !os_aio_all_slots_free()) {
                            fil_aio_wait(segment);
                    }
            

            marko Marko Mäkelä added a comment - - edited The assertion node->n_pending==0 fails for the InnoDB system tablespace. The call to fil_close_all_files() in logs_empty_and_mark_files_at_shutdown() expects all files to be in an idle state. Somehow we failed to properly finish an I/O request at shutdown. The buf_pool_ptr->flush_list is empty, but it is possible that a write from the buffer pool to the file buffers was completed, and the fsync() is still pending. There are 413 pages in the buffer pool. Many of these pages were modified while the server was running. One example is (buf_page_t *) 0x7f772b3a79c0 which is space 0 (system tablespace), page 8 (root page of the clustered index of the SYS_TABLES table), newest_modification = 1804026. I suppose that this page was recently changed due to a DROP TABLE that was executed at the end of the test, just before the shutdown. Interestingly, log_sys->lsn == log_sys->last_checkpoint_lsn == log_sys->next_checkpoint_lsn == 1804880. That is 854 bytes after the newest_modification of the above block. This should be OK, because newest_modification is never reset to 0. The changes probably were already written to the data file. There are no clues in the buffer pool. The fil_node_t for which the assertion fails is this one: (gdb) p *fil_system.space_list.start.chain.start $110 = {space = 0x7f7740413a80, name = 0x7f7740418370 "./ibdata1", is_open = true, handle = 3, sync_event = 0x7f772cbf0c00, is_raw_disk = false, size = 768, init_size = 768, max_size = 18446744073709551614, n_pending = 1, n_pending_flushes = 0, being_extended = false, modification_counter = 200, flush_counter = 200, chain = {prev = 0x0, next = 0x0}, LRU = {prev = 0x0, next = 0x0}, punch_hole = true, block_size = 4096, atomic_write = false, magic_n = 89389} The node->n_pending is incremented by fil_node_prepare_for_io() and decremented by fil_node_complete_io(). The only case where a call to the latter could be missed is when a call to fil_aio_wait() is skipped or os_aio_handler() fails to return the fil_node_t pointer. The only caller of fil_aio_wait() is io_handler_thread(). Maybe the termination condition needs to be revised so that pending work by encryption threads will be properly finished? while (srv_shutdown_state != SRV_SHUTDOWN_EXIT_THREADS || buf_page_cleaner_is_active || !os_aio_all_slots_free()) { fil_aio_wait(segment); }

            I cleaned up the test encryption.innodb_scrub (MDEV-8139) so that it creates and populates all tables, then does one slow shutdown, and checks the files while the server is offline. That test fails once in 10 to 20 runs. With that, I believe that I finally have a reliable way of repeating the root cause of these failures.

            I suspect that the root cause is that srv_any_background_threads_are_active() fails to account for the encryption threads.

            marko Marko Mäkelä added a comment - I cleaned up the test encryption.innodb_scrub ( MDEV-8139 ) so that it creates and populates all tables, then does one slow shutdown, and checks the files while the server is offline. That test fails once in 10 to 20 runs. With that, I believe that I finally have a reliable way of repeating the root cause of these failures. I suspect that the root cause is that srv_any_background_threads_are_active() fails to account for the encryption threads.

            See the penultimate commit in bb-10.1-mdev-8139.

            marko Marko Mäkelä added a comment - See the penultimate commit in bb-10.1-mdev-8139.

            ok to push.

            jplindst Jan Lindström (Inactive) added a comment - ok to push.

            People

              marko Marko Mäkelä
              elenst Elena Stepanova
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.