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

Crash with prepared statements and NEXTVAL()

    XMLWordPrintable

    Details

      Description

      Update: Test case is in the comments.


      Hello,

      mariaDB crashed with signal 11. Can you help me, to find out the cause?

      Regards,
      Karsten

      Here the part from log:

      Jun  3 08:24:21 hw4serv mysqld: 200603  8:24:21 [ERROR] mysqld got signal 11 ;
      Jun  3 08:24:21 hw4serv mysqld: This could be because you hit a bug. It is also possible that this binary
      Jun  3 08:24:21 hw4serv mysqld: or one of the libraries it was linked against is corrupt, improperly built,
      Jun  3 08:24:21 hw4serv mysqld: or misconfigured. This error can also be caused by malfunctioning hardware.
      Jun  3 08:24:21 hw4serv mysqld: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
      Jun  3 08:24:21 hw4serv mysqld: We will try our best to scrape up some info that will hopefully help
      Jun  3 08:24:21 hw4serv mysqld: diagnose the problem, but since we have already crashed,
      Jun  3 08:24:21 hw4serv mysqld: something is definitely wrong and this may fail.
      Jun  3 08:24:21 hw4serv mysqld: Server version: 10.4.12-MariaDB-log
      Jun  3 08:24:21 hw4serv mysqld: key_buffer_size=134217728
      Jun  3 08:24:21 hw4serv mysqld: read_buffer_size=131072
      Jun  3 08:24:21 hw4serv mysqld: max_used_connections=16
      Jun  3 08:24:21 hw4serv mysqld: max_threads=153
      Jun  3 08:24:21 hw4serv mysqld: thread_count=23
      Jun  3 08:24:21 hw4serv mysqld: It is possible that mysqld could use up to
      Jun  3 08:24:21 hw4serv mysqld: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467752 K  bytes of memory
      Jun  3 08:24:21 hw4serv mysqld: Hope that's ok; if not, decrease some variables in the equation.
      Jun  3 08:24:21 hw4serv mysqld: Thread pointer: 0x7f8d040009a8
      Jun  3 08:24:21 hw4serv mysqld: Attempting backtrace. You can use the following information to find out
      Jun  3 08:24:21 hw4serv mysqld: where mysqld died. If you see no messages after this, something went
      Jun  3 08:24:21 hw4serv mysqld: terribly wrong...
      Jun  3 08:24:21 hw4serv mysqld: stack_bottom = 0x7f8dcca87cf0 thread_stack 0x49000
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x55cdff784a1e]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(handle_fatal_signal+0x30f)[0x55cdff218d8f]
      Jun  3 08:24:21 hw4serv mysqld: sigaction.c:0(__restore_rt)[0x7f8dea9785f0]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_ZN17Item_func_nextval7val_intEv+0xa6)[0x55cdff289346]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_ZN4Item17save_int_in_fieldEP5Fieldb+0x1f)[0x55cdff23e9cf]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_ZN4Item13save_in_fieldEP5Fieldb+0x36)[0x55cdff22ff86]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_ZN5TABLE21update_default_fieldsEb+0xad)[0x55cdff0c632d]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_Z11fill_recordP3THDP5TABLER4ListI4ItemES6_bb+0x40e)[0x55cdfefa9bfe]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_Z36fill_record_n_invoke_before_triggersP3THDP5TABLER4ListI4ItemES6_b14trg_event_type+0x39)[0x55cdfefa9d89]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_Z12mysql_insertP3THDP10TABLE_LISTR4ListI4ItemERS3_IS5_ES6_S6_15enum_duplicatesb+0x11cd)[0x55cdfefd6b6d]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x3dd2)[0x55cdff005c52]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_ZN13sp_instr_stmt9exec_coreEP3THDPj+0x36)[0x55cdfef68c26]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_ZN13sp_lex_keeper23reset_lex_and_exec_coreEP3THDPjbP8sp_instr+0x155)[0x55cdfef713a5]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_ZN13sp_instr_stmt7executeEP3THDPj+0x64c)[0x55cdfef71e2c]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_ZN7sp_head7executeEP3THDb+0xa64)[0x55cdfef6cb94]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_ZN7sp_head17execute_procedureEP3THDP4ListI4ItemE+0x779)[0x55cdfef6e2e9]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(+0x69f18a)[0x55cdfeffa18a]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(+0x6a0a46)[0x55cdfeffba46]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_ZN12Sql_cmd_call7executeEP3THD+0x90)[0x55cdfeffc260]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x27c8)[0x55cdff004648]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_ZN18Prepared_statement7executeEP6Stringb+0x4b6)[0x55cdff01ecc6]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_ZN18Prepared_statement12execute_loopEP6StringbPhS2_+0x92)[0x55cdff01ee82]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(+0x6c47e7)[0x55cdff01f7e7]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_Z19mysqld_stmt_executeP3THDPcj+0x27)[0x55cdff01f877]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0x17f5)[0x55cdff00df85]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_Z10do_commandP3THD+0x11c)[0x55cdff00fa4c]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(_Z24do_handle_one_connectionP7CONNECT+0x1fa)[0x55cdff0ee32a]
      Jun  3 08:24:21 hw4serv mysqld: /usr/sbin/mysqld(handle_one_connection+0x3d)[0x55cdff0ee40d]
      Jun  3 08:24:21 hw4serv mysqld: pthread_create.c:0(start_thread)[0x7f8dea970e65]
      Jun  3 08:24:21 hw4serv mysqld: /lib64/libc.so.6(clone+0x6d)[0x7f8de8d1188d]
      Jun  3 08:24:21 hw4serv mysqld: Trying to get some variables.
      Jun  3 08:24:21 hw4serv mysqld: Some pointers may be invalid and cause the dump to abort.
      Jun  3 08:24:21 hw4serv kernel: mysqld[9540]: segfault at 39e4 ip 000055cdff289346 sp 00007f8dcca800c0 error 4 in mysqld[55cdfe95b000+1483000]
      Jun  3 08:24:21 hw4serv mysqld: Query (0x7f8d05292fe0): insert into hzodelivery.deliverJob       (supplier ,clientId ,hierarchyDefId ,ownerId ,obId)      values      ('{"source": "XOIS-Abgleich"}' ,6 , 290 , NAME_CONST('iFirmObId',41069873) , NAME_CONST('iFirmObId',41069873) )
      Jun  3 08:24:21 hw4serv mysqld: Connection ID (thread ID): 367077
      Jun  3 08:24:21 hw4serv mysqld: Status: NOT_KILLED
      Jun  3 08:24:21 hw4serv mysqld: Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from_having=on
      Jun  3 08:24:21 hw4serv mysqld: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
      Jun  3 08:24:21 hw4serv mysqld: information that should help you find out what is causing the crash.
      Jun  3 08:24:21 hw4serv mysqld: Writing a core file...
      Jun  3 08:24:21 hw4serv mysqld: Working directory at /var/lib/mysql
      Jun  3 08:24:21 hw4serv mysqld: Resource Limits:
      Jun  3 08:24:21 hw4serv mysqld: Limit                     Soft Limit           Hard Limit           Units
      Jun  3 08:24:21 hw4serv mysqld: Max cpu time              unlimited            unlimited            seconds
      Jun  3 08:24:21 hw4serv mysqld: Max file size             unlimited            unlimited            bytes
      Jun  3 08:24:21 hw4serv mysqld: Max data size             unlimited            unlimited            bytes
      Jun  3 08:24:21 hw4serv mysqld: Max stack size            8388608              unlimited            bytes
      Jun  3 08:24:21 hw4serv mysqld: Max core file size        0                    unlimited            bytes
      Jun  3 08:24:21 hw4serv mysqld: Max resident set          unlimited            unlimited            bytes
      Jun  3 08:24:21 hw4serv mysqld: Max processes             31204                31204                processes
      Jun  3 08:24:21 hw4serv mysqld: Max open files            1048576              1048576              files
      Jun  3 08:24:21 hw4serv mysqld: Max locked memory         65536                65536                bytes
      Jun  3 08:24:21 hw4serv mysqld: Max address space         unlimited            unlimited            bytes
      Jun  3 08:24:21 hw4serv mysqld: Max file locks            unlimited            unlimited            locks
      Jun  3 08:24:21 hw4serv mysqld: Max pending signals       31204                31204                signals
      Jun  3 08:24:21 hw4serv mysqld: Max msgqueue size         819200               819200               bytes
      Jun  3 08:24:22 hw4serv mysqld: Max nice priority         0                    0
      Jun  3 08:24:22 hw4serv mysqld: Max realtime priority     0                    0
      Jun  3 08:24:22 hw4serv mysqld: Max realtime timeout      unlimited            unlimited            us
      Jun  3 08:24:22 hw4serv mysqld: Core pattern: core
      Jun  3 08:24:22 hw4serv systemd: mariadb.service: main process exited, code=killed, status=11/SEGV
      Jun  3 08:24:22 hw4serv systemd: Unit mariadb.service entered failed state.
      Jun  3 08:24:22 hw4serv systemd: mariadb.service failed.
      Jun  3 08:24:27 hw4serv systemd: mariadb.service holdoff time over, scheduling restart.
      Jun  3 08:24:27 hw4serv systemd: Stopped MariaDB 10.4.12 database server.
      Jun  3 08:24:27 hw4serv systemd: Starting MariaDB 10.4.12 database server...
      Jun  3 08:24:27 hw4serv mysqld: 2020-06-03  8:24:27 0 [Note] /usr/sbin/mysqld (mysqld 10.4.12-MariaDB-log) starting as process 16499 ...
      Jun  3 08:24:27 hw4serv mysqld: 2020-06-03  8:24:27 0 [Note] mysqld: Aria engine: starting recovery
      Jun  3 08:24:27 hw4serv mysqld: recovered pages: 0% 24% 49% 74% 99% 100% (0.0 seconds); tables to flush: 1 0
      Jun  3 08:24:27 hw4serv mysqld: (0.0 seconds);
      Jun  3 08:24:27 hw4serv mysqld: 2020-06-03  8:24:27 0 [Note] mysqld: Aria engine: recovery done
      Jun  3 08:24:27 hw4serv mysqld: 2020-06-03  8:24:27 0 [Note] CONNECT: Version 1.07.0001 November 12, 2019
      Jun  3 08:24:27 hw4serv mysqld: 2020-06-03  8:24:27 0 [Note] InnoDB: Using Linux native AIO
      Jun  3 08:24:27 hw4serv mysqld: 2020-06-03  8:24:27 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
      Jun  3 08:24:27 hw4serv mysqld: 2020-06-03  8:24:27 0 [Note] InnoDB: Uses event mutexes
      Jun  3 08:24:27 hw4serv mysqld: 2020-06-03  8:24:27 0 [Note] InnoDB: Compressed tables use zlib 1.2.7
      Jun  3 08:24:27 hw4serv mysqld: 2020-06-03  8:24:27 0 [Note] InnoDB: Number of pools: 1
      Jun  3 08:24:27 hw4serv mysqld: 2020-06-03  8:24:27 0 [Note] InnoDB: Using SSE2 crc32 instructions
      Jun  3 08:24:28 hw4serv mysqld: 2020-06-03  8:24:28 0 [Note] InnoDB: Initializing buffer pool, total size = 1G, instances = 8, chunk size = 128M
      Jun  3 08:24:28 hw4serv mysqld: 2020-06-03  8:24:28 0 [Note] InnoDB: Completed initialization of buffer pool
      Jun  3 08:24:28 hw4serv mysqld: 2020-06-03  8:24:28 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
      Jun  3 08:24:28 hw4serv mysqld: 2020-06-03  8:24:28 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=82779655053
      Jun  3 08:24:28 hw4serv mysqld: 2020-06-03  8:24:28 0 [Note] InnoDB: Transaction 34583871 was in the XA prepared state.
      Jun  3 08:24:28 hw4serv mysqld: 2020-06-03  8:24:28 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 0 row operations to undo
      Jun  3 08:24:28 hw4serv mysqld: 2020-06-03  8:24:28 0 [Note] InnoDB: Trx id counter is 34583872
      Jun  3 08:24:28 hw4serv mysqld: 2020-06-03  8:24:28 0 [Note] InnoDB: Starting final batch to recover 339 pages from redo log.
      Jun  3 08:24:29 hw4serv mysqld: 2020-06-03  8:24:29 0 [Note] InnoDB: Last binlog file '/marialogs/binlog.000083', position 397596788
      Jun  3 08:24:29 hw4serv mysqld: 2020-06-03  8:24:29 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
      Jun  3 08:24:29 hw4serv mysqld: 2020-06-03  8:24:29 0 [Note] InnoDB: Starting in background the rollback of recovered transactions
      Jun  3 08:24:29 hw4serv mysqld: 2020-06-03  8:24:29 0 [Note] InnoDB: Rollback of non-prepared transactions completed
      Jun  3 08:24:29 hw4serv mysqld: 2020-06-03  8:24:29 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
      Jun  3 08:24:29 hw4serv mysqld: 2020-06-03  8:24:29 0 [Note] InnoDB: Creating shared tablespace for temporary tables
      Jun  3 08:24:29 hw4serv mysqld: 2020-06-03  8:24:29 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
      Jun  3 08:24:29 hw4serv mysqld: 2020-06-03  8:24:29 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
      Jun  3 08:24:29 hw4serv mysqld: 2020-06-03  8:24:29 0 [Note] InnoDB: Waiting for purge to start
      Jun  3 08:24:29 hw4serv mysqld: 2020-06-03  8:24:29 0 [Note] InnoDB: 10.4.12 started; log sequence number 82779988762; transaction id 34583874
      Jun  3 08:24:29 hw4serv mysqld: 2020-06-03  8:24:29 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
      Jun  3 08:24:29 hw4serv mysqld: 2020-06-03  8:24:29 0 [Note] Plugin 'FEEDBACK' is disabled.
      Jun  3 08:24:29 hw4serv mysqld: 2020-06-03  8:24:29 0 [ERROR] mysqld: Plugin 'CONNECT' already installed
      Jun  3 08:24:29 hw4serv mysqld: 2020-06-03  8:24:29 0 [ERROR] mysqld: Plugin 'FEDERATED' already installed
      Jun  3 08:24:29 hw4serv mysqld: 2020-06-03  8:24:29 0 [Note] Recovering after a crash using /marialogs/binlog
      Jun  3 08:24:34 hw4serv mysqld: 2020-06-03  8:24:34 0 [Note] Starting crash recovery...
      Jun  3 08:24:34 hw4serv mysqld: 2020-06-03  8:24:34 0 [Note] InnoDB: Starting recovery for XA transactions...
      Jun  3 08:24:34 hw4serv mysqld: 2020-06-03  8:24:34 0 [Note] InnoDB: Transaction 34583871 in prepared state after recovery
      Jun  3 08:24:34 hw4serv mysqld: 2020-06-03  8:24:34 0 [Note] InnoDB: Transaction contains changes to 1 rows
      Jun  3 08:24:34 hw4serv mysqld: 2020-06-03  8:24:34 0 [Note] InnoDB: 1 transactions in prepared state after recovery
      Jun  3 08:24:34 hw4serv mysqld: 2020-06-03  8:24:34 0 [Note] Found 1 prepared transaction(s) in InnoDB
      Jun  3 08:24:34 hw4serv mysqld: 2020-06-03  8:24:34 0 [Note] Crash recovery finished.
      Jun  3 08:24:34 hw4serv mysqld: 2020-06-03  8:24:34 0 [Note] Server socket created on IP: '::'.
      Jun  3 08:24:35 hw4serv mysqld: 2020-06-03  8:24:35 0 [Note] Reading of all Master_info entries succeeded
      Jun  3 08:24:35 hw4serv mysqld: 2020-06-03  8:24:35 0 [Note] Added new Master_info '' to hash table
      Jun  3 08:24:35 hw4serv mysqld: 2020-06-03  8:24:35 0 [Note] /usr/sbin/mysqld: ready for connections.
      Jun  3 08:24:35 hw4serv mysqld: Version: '10.4.12-MariaDB-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MariaDB Server
      Jun  3 08:24:35 hw4serv systemd: Started MariaDB 10.4.12 database server.
      Jun  3 08:24:35 hw4serv mysqld: 2020-06-03  8:24:35 13 [Note] Detected table cache mutex contention at instance 1: 34% waits. Additional table cache instance activated. Number of instances after activation: 2.
      Jun  3 08:24:50 hw4serv mysqld: 2020-06-03  8:24:50 0 [Note] InnoDB: Buffer pool(s) load completed at 200603  8:24:50
      

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              monty Michael Widenius
              Reporter:
              KB_Heinze Karsten Budde
              Votes:
              0 Vote for this issue
              Watchers:
              7 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved:

                  Git Integration