dbstore1005 s8 mariadb instance crashed
Closed, ResolvedPublic
Actions

Assigned To

Authored By

	• jcrespo
	Jul 2 2020, 12:03 PM

Description

wikidata instance on dbstore1005 crashed on 02 Jun 2020:

Jul 02 11:00:53 dbstore1005 mysqld[4259]: 2020-07-02 11:00:53 0x7fdf103d3700  InnoDB: Assertion failure in file /root/mariadb-10.4.13/storage/innobase/row/row0ins.cc line 231
Jul 02 11:00:53 dbstore1005 mysqld[4259]: InnoDB: Failing assertion: !cursor->index->is_committed()
Jul 02 11:00:53 dbstore1005 mysqld[4259]: InnoDB: We intentionally generate a memory trap.
Jul 02 11:00:53 dbstore1005 mysqld[4259]: InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
Jul 02 11:00:53 dbstore1005 mysqld[4259]: InnoDB: If you get repeated assertion failures or crashes, even
Jul 02 11:00:53 dbstore1005 mysqld[4259]: InnoDB: immediately after the mysqld startup, there may be
Jul 02 11:00:53 dbstore1005 mysqld[4259]: InnoDB: corruption in the InnoDB tablespace. Please refer to
Jul 02 11:00:53 dbstore1005 mysqld[4259]: InnoDB: https://mariadb.com/kb/en/library/innodb-recovery-modes/
Jul 02 11:00:53 dbstore1005 mysqld[4259]: InnoDB: about forcing recovery.
Jul 02 11:00:53 dbstore1005 mysqld[4259]: 200702 11:00:53 [ERROR] mysqld got signal 6 ;
Jul 02 11:00:53 dbstore1005 mysqld[4259]: This could be because you hit a bug. It is also possible that this binary
Jul 02 11:00:53 dbstore1005 mysqld[4259]: or one of the libraries it was linked against is corrupt, improperly built,
Jul 02 11:00:53 dbstore1005 mysqld[4259]: or misconfigured. This error can also be caused by malfunctioning hardware.
Jul 02 11:00:53 dbstore1005 mysqld[4259]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
Jul 02 11:00:53 dbstore1005 mysqld[4259]: We will try our best to scrape up some info that will hopefully help
Jul 02 11:00:53 dbstore1005 mysqld[4259]: diagnose the problem, but since we have already crashed,
Jul 02 11:00:53 dbstore1005 mysqld[4259]: something is definitely wrong and this may fail.
Jul 02 11:00:53 dbstore1005 mysqld[4259]: Server version: 10.4.13-MariaDB
Jul 02 11:00:53 dbstore1005 mysqld[4259]: key_buffer_size=1048576
Jul 02 11:00:53 dbstore1005 mysqld[4259]: read_buffer_size=131072
Jul 02 11:00:53 dbstore1005 mysqld[4259]: max_used_connections=77
Jul 02 11:00:53 dbstore1005 mysqld[4259]: max_threads=252
Jul 02 11:00:53 dbstore1005 mysqld[4259]: thread_count=83
Jul 02 11:00:53 dbstore1005 mysqld[4259]: It is possible that mysqld could use up to
Jul 02 11:00:53 dbstore1005 mysqld[4259]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 555578 K  bytes of memory
Jul 02 11:00:53 dbstore1005 mysqld[4259]: Hope that's ok; if not, decrease some variables in the equation.
Jul 02 11:00:53 dbstore1005 mysqld[4259]: Thread pointer: 0x7fa6940014f8
Jul 02 11:00:53 dbstore1005 mysqld[4259]: Attempting backtrace. You can use the following information to find out
Jul 02 11:00:53 dbstore1005 mysqld[4259]: where mysqld died. If you see no messages after this, something went
Jul 02 11:00:53 dbstore1005 mysqld[4259]: terribly wrong...
Jul 02 11:00:53 dbstore1005 mysqld[4259]: stack_bottom = 0x7fdf103d2698 thread_stack 0x49000
Jul 02 11:00:53 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(my_print_stacktrace+0x2e)[0x558719c157de]
Jul 02 11:00:53 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(handle_fatal_signal+0x54d)[0x55871970db4d]
Jul 02 11:00:54 dbstore1005 mysqld[4259]: /lib/x86_64-linux-gnu/libpthread.so.0(+0x12730)[0x7fdf2a0ed730]
Jul 02 11:00:54 dbstore1005 mysqld[4259]: /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x10b)[0x7fdf297557bb]
Jul 02 11:00:54 dbstore1005 mysqld[4259]: /lib/x86_64-linux-gnu/libc.so.6(abort+0x121)[0x7fdf29740535]
Jul 02 11:00:54 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(+0x5a19d5)[0x5587194099d5]
Jul 02 11:00:54 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(+0x5907c1)[0x5587193f87c1]
Jul 02 11:00:54 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(+0xaeee0e)[0x558719956e0e]
Jul 02 11:00:54 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(+0xb22478)[0x55871998a478]
Jul 02 11:00:54 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(+0xb27e0f)[0x55871998fe0f]
Jul 02 11:00:54 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(+0xb0023c)[0x55871996823c]
Jul 02 11:00:54 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(+0xa5043f)[0x5587198b843f]
Jul 02 11:00:55 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(_ZN7handler13ha_update_rowEPKhS1_+0xbb)[0x558719719a0b]
Jul 02 11:00:55 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(_Z12mysql_updateP3THDP10TABLE_LISTR4ListI4ItemES6_PS4_jP8st_orderybPySA_+0x1b27)[0x5587195b5617]
Jul 02 11:00:55 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(_Z21mysql_execute_commandP3THD+0x26ca)[0x5587195084fa]
Jul 02 11:00:55 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x1c9)[0x55871950e179]
Jul 02 11:00:55 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(_ZN15Query_log_event14do_apply_eventEP14rpl_group_infoPKcj+0x682)[0x558719804e52]
Jul 02 11:00:55 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(+0x5faf02)[0x558719462f02]
Jul 02 11:00:55 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(handle_slave_sql+0x12e2)[0x55871946bef2]
Jul 02 11:00:55 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(+0xd5e28b)[0x558719bc628b]
Jul 02 11:00:55 dbstore1005 mysqld[4259]: /lib/x86_64-linux-gnu/libpthread.so.0(+0x7fa3)[0x7fdf2a0e2fa3]
Jul 02 11:00:55 dbstore1005 mysqld[4259]: /lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7fdf298174cf]
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Trying to get some variables.
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Some pointers may be invalid and cause the dump to abort.
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Query (0x7fa6943bd91b): UPDATE /* WikiPage::updateRevisionOn  */  `page` SET page_latest = 1222570180,page_touched = '20200702110053',page_is_new = 0,page_is_redirect = 0,page_len = 8230,page_content_model = 'wikibase-item' WHERE page_id = 16921033
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Connection ID (thread ID): 32
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Status: NOT_KILLED
Jul 02 11:00:55 dbstore1005 mysqld[4259]: 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=on,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
Jul 02 11:00:55 dbstore1005 mysqld[4259]: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
Jul 02 11:00:55 dbstore1005 mysqld[4259]: information that should help you find out what is causing the crash.
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Writing a core file...
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Working directory at /srv/sqldata.s8
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Resource Limits:
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Limit                     Soft Limit           Hard Limit           Units
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max cpu time              unlimited            unlimited            seconds
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max file size             unlimited            unlimited            bytes
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max data size             unlimited            unlimited            bytes
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max stack size            8388608              unlimited            bytes
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max core file size        0                    0                    bytes
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max resident set          unlimited            unlimited            bytes
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max processes             2058623              2058623              processes
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max open files            200001               200001               files
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max locked memory         65536                65536                bytes
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max address space         unlimited            unlimited            bytes
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max file locks            unlimited            unlimited            locks
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max pending signals       2058623              2058623              signals
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max msgqueue size         819200               819200               bytes
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max nice priority         0                    0
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max realtime priority     0                    0
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max realtime timeout      unlimited            unlimited            us
Jul 02 11:00:55 dbstore1005 mysqld[4259]: Core pattern: /var/tmp/core/core.%h.%e.%p....
Jul 02 11:00:56 dbstore1005 systemd[1]: mariadb@s8.service: Main process exited, code=killed, status=6/ABRT
Jul 02 11:00:56 dbstore1005 systemd[1]: mariadb@s8.service: Failed with result 'signal'.
Jul 02 11:01:02 dbstore1005 systemd[1]: mariadb@s8.service: Service RestartSec=5s expired, scheduling restart.
Jul 02 11:01:02 dbstore1005 systemd[1]: mariadb@s8.service: Scheduled restart job, restart counter is at 1.
Jul 02 11:01:02 dbstore1005 systemd[1]: Stopped mariadb database server.
Jul 02 11:01:02 dbstore1005 systemd[1]: Starting mariadb database server...
Jul 02 11:01:02 dbstore1005 mysqld[30251]: 2020-07-02 11:01:02 0 [Note] /opt/wmf-mariadb104/bin/mysqld (mysqld 10.4.13-MariaDB) starting as process 30251 ...
Jul 02 11:01:02 dbstore1005 mysqld[30251]: 2020-07-02 11:01:02 0 [Warning] Could not increase number of max_open_files to more than 200001 (request: 800297)
Jul 02 11:01:02 dbstore1005 mysqld[30251]: 2020-07-02 11:01:02 0 [ERROR] mysqld: Plugin 'unix_socket' already installed
Jul 02 11:01:02 dbstore1005 mysqld[30251]: 2020-07-02 11:01:02 0 [ERROR] Couldn't load plugin 'unix_socket' from 'auth_socket.so'.
Jul 02 11:01:02 dbstore1005 mysqld[30251]: 2020-07-02 11:01:02 0 [Note] mysqld: Aria engine: starting recovery
Jul 02 11:01:02 dbstore1005 mysqld[30251]: recovered pages: 0% 10% 20% 30% 40% 50% 60% 70% 80% 90% 100% (0.0 seconds); tables to flush: 1 0
Jul 02 11:01:02 dbstore1005 mysqld[30251]:  (0.0 seconds);
Jul 02 11:01:02 dbstore1005 mysqld[30251]: 2020-07-02 11:01:02 0 [Note] mysqld: Aria engine: recovery done
Jul 02 11:01:02 dbstore1005 mysqld[30251]: 2020-07-02 11:01:02 0 [Warning] The parameter innodb_file_format is deprecated and has no effect. It may be removed in future releases. See https://mariadb.com/kb/en/library/xtradbinnodb-file-format/
Jul 02 11:01:02 dbstore1005 mysqld[30251]: 2020-07-02 11:01:02 0 [Warning] InnoDB: Using innodb_locks_unsafe_for_binlog is DEPRECATED. This option may be removed in future releases. Please use READ COMMITTED transaction isolation level instead; Please refer to https://mariadb.com/kb/en/library/set-transaction/
Jul 02 11:01:02 dbstore1005 mysqld[30251]: 2020-07-02 11:01:02 0 [Note] InnoDB: Using Linux native AIO
Jul 02 11:01:02 dbstore1005 mysqld[30251]: 2020-07-02 11:01:02 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
Jul 02 11:01:02 dbstore1005 mysqld[30251]: 2020-07-02 11:01:02 0 [Note] InnoDB: Uses event mutexes
Jul 02 11:01:02 dbstore1005 mysqld[30251]: 2020-07-02 11:01:02 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
Jul 02 11:01:02 dbstore1005 mysqld[30251]: 2020-07-02 11:01:02 0 [Note] InnoDB: Number of pools: 1
Jul 02 11:01:02 dbstore1005 mysqld[30251]: 2020-07-02 11:01:02 0 [Note] InnoDB: Using SSE2 crc32 instructions
Jul 02 11:01:02 dbstore1005 mysqld[30251]: 2020-07-02 11:01:02 0 [Note] mysqld: O_TMPFILE is not supported on /srv/tmp.s8 (disabling future attempts)
Jul 02 11:01:02 dbstore1005 mysqld[30251]: 2020-07-02 11:01:02 0 [Note] InnoDB: Initializing buffer pool, total size = 220G, instances = 8, chunk size = 128M
Jul 02 11:01:09 dbstore1005 mysqld[30251]: 2020-07-02 11:01:09 0 [Note] InnoDB: Completed initialization of buffer pool
Jul 02 11:01:09 dbstore1005 mysqld[30251]: 2020-07-02 11:01:09 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
Jul 02 11:01:09 dbstore1005 mysqld[30251]: 2020-07-02 11:01:09 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=54284194317624
Jul 02 11:01:23 dbstore1005 mysqld[30251]: 2020-07-02 11:01:23 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 8 row operations to undo
Jul 02 11:01:23 dbstore1005 mysqld[30251]: 2020-07-02 11:01:23 0 [Note] InnoDB: Trx id counter is 56066264493
Jul 02 11:01:23 dbstore1005 mysqld[30251]: 2020-07-02 11:01:23 0 [Note] InnoDB: Starting final batch to recover 284670 pages from redo log.
Jul 02 11:01:24 dbstore1005 mysqld[30251]: 2020-07-02 11:01:24 0 [Note] InnoDB: To recover: 283194 pages from log
Jul 02 11:01:35 dbstore1005 mysqld[30251]: 2020-07-02 11:01:35 0 [Note] InnoDB: Last binlog file './db2083-bin.000595', position 312969574
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [Note] InnoDB: Starting in background the rollback of recovered transactions
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [Note] InnoDB: Creating shared tablespace for temporary tables
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [Note] InnoDB: Waiting for purge to start
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [Warning] InnoDB: Record in index `page_len` of table `wikidatawiki`.`page` was not found on rollback, trying to insert: TUPLE (info_bits=0, 2 fields): {[4]  %#(0x00002523),[4]  1 (0x010231C9)} at: COMPACT RECORD(info_bits=0, 2 fields): {[4]  %#(0x00002523),[4]    (0x010014A8)}
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [Warning] InnoDB: Record in index `page_redirect_namespace_len` of table `wikidatawiki`.`page` was not found on rollback, trying to insert: TUPLE (info_bits=0, 4 fields): {[1] (0x00),[4]    (0x80000000),[4]  %#(0x00002523),[4]  1 (0x010231C9)} at: COMPACT RECORD(info_bits=0, 4 fields): {[1] (0x00),[4]    (0x80000000),[4]  %#(0x00002523),[4]    (0x010014A8)}
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [Note] InnoDB: Rolled back recovered transaction 56066264492
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [Note] InnoDB: Rollback of non-prepared transactions completed
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [Note] InnoDB: 10.4.13 started; log sequence number 54284194319978; transaction id 56066264496
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [Note] InnoDB: Loading buffer pool(s) from /srv/sqldata.s8/ib_buffer_pool
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [Note] Plugin 'FEEDBACK' is disabled.
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [ERROR] mysqld: Can't open shared library '/opt/wmf-mariadb101/lib/plugin/semisync_slave.so' (errno: 0, cannot open shared object file: No such file or directory)
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [ERROR] mysqld: Plugin 'unix_socket' already installed
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [Note] Server socket created on IP: '::'.
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 3 [Note] Event Scheduler: scheduler thread started with id 3
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [Note] Reading of all Master_info entries succeeded
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [Note] Added new Master_info '' to hash table
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [Warning] Neither --relay-log nor --relay-log-index were used; so replication may break when this MySQL server acts as a slave and has his hostname changed!! Please use '--log-basename=#' or '--relay-log=dbstore1005-relay-bin' to avoid this problem.
Jul 02 11:01:36 dbstore1005 mysqld[30251]: 2020-07-02 11:01:36 0 [Note] /opt/wmf-mariadb104/bin/mysqld: ready for connections.
Jul 02 11:01:36 dbstore1005 mysqld[30251]: Version: '10.4.13-MariaDB'  socket: '/run/mysqld/mysqld.s8.sock'  port: 3318  MariaDB Server
Jul 02 11:01:36 dbstore1005 systemd[1]: Started mariadb database server.
Jul 02 11:15:06 dbstore1005 mysqld[30251]: 2020-07-02 11:15:06 0 [Note] InnoDB: Buffer pool(s) load completed at 200702

Causes yet unknown.

Related Objects

Mentioned Here: P11741 dbstore1005 2020-07-02 mariadb crash.log
T254870: Upgrade analytics dbstore databases to Buster and Mariadb 10.4
T249188: Reimage labsdb1011 to Buster and MariaDB 10.4

Event Timeline

• jcrespo created this task.Jul 2 2020, 12:03 PM

Restricted Application added a subscriber: Aklapper. · View Herald TranscriptJul 2 2020, 12:03 PM

On replication start, instance crashed again- probably there is data/fs corruption.

Same issues as T249188 ?

This host was reimaged to buster recently (2020-06-22) as part of T254870, and the symptoms do sound very like https://jira.mariadb.org/browse/MDEV-22373, with the significant difference that this host is multi-instance, and not multi-source.

Mentioned in SAL (#wikimedia-operations) [2020-07-02T14:03:14Z] <kormat> stopped mariadb@s8 on dbstore1005 for data restoration T256966

• Kormat claimed this task.Jul 2 2020, 2:10 PM

• Kormat triaged this task as High priority.

• Kormat added a project: User-Kormat.

• Kormat moved this task from Unsorted 💣 to Active 🚁 on the User-Kormat board.

• Kormat moved this task from Triage to In progress on the DBA board.

Data restored from backup, machine has finished catching up on s8 replication. There are some extra grants from the backup that should be cleaned up, but otherwise things are in a good place now.

• jcrespo awarded a token.Jul 2 2020, 4:31 PM

hashar awarded a token.Jul 2 2020, 4:43 PM

fgiunchedi awarded a token.Jul 2 2020, 4:44 PM

jijiki awarded a token.Jul 2 2020, 6:22 PM

@Kormat do you want to do the finishing cleanup in order to close the ticket?

Confirm the host is healthy, caught up and no error on log. Making sure all monitoring systems work as intended (prometheus, tendril, ...)
Any possible research about causes/warning on other similar tickets
Remove extra grants (REVOKE)
Confirm with analytics they can query data normally
Clean up sensitive data on /home s and any other hanging files

In T256966#6276329, @jcrespo wrote:

Confirm the host is healthy, caught up and no error on log. Making sure all monitoring systems work as intended (prometheus, tendril, ...)

Everything looks good on prometheus/tendril/icinga. Replication caught up yesterday.

Any possible research about causes/warning on other similar tickets

I don't think there's anything more i can do here.

Remove extra grants (REVOKE)

Done. Also fixed up 'research'@'10.%' not having a default role set.

Confirm with analytics they can query data normally

I've asked them to check this.

Clean up sensitive data on /home s and any other hanging files

Will do as soon as analytics gives me the thumbs up.

@elukey confirms that analytics can query again, and i've removed the temporary grants files from my home dir.

In T256966#6274434, @Kormat wrote:

This host was reimaged to buster recently (2020-06-22) as part of T254870, and the symptoms do sound very like https://jira.mariadb.org/browse/MDEV-22373, with the significant difference that this host is multi-instance, and not multi-source.

From the reported logs, it doesn't really seem related to that bug. It could just be a "normal" crash, but not necessarily related to it. On the other bug, we've seen lots of InnoDB errors (LOTS) before the crashes. It was never such a "clean" crash.

From the reported logs

In that case let me supply more logs :)

The errors from line 15 onwards are what made me think of that mariadb upstream issue.

P11741 dbstore1005 2020-07-02 mariadb crash.log

1	Jul 02 11:00:33 dbstore1005 mysqld[4259]: 2020-07-02 11:00:33 32 [ERROR] InnoDB: Record in index `page_redirect_namespace_len` of table `wikidatawiki`.`page` was not found on update: TUPLE (info_bits=0, 4 fields): {[1] (0x00),[4] (0x80
2	000000),[4] ' (0x000027CB),[4] } (0x01017DA1)} at: COMPACT RECORD(info_bits=0, 4 fields): {[1] (0x00),[4] (0x80000000),[4] ' (0x000027CB),[4] (0x0100C39D)}
3	Jul 02 11:00:33 dbstore1005 mysqld[4259]: 2020-07-02 11:00:33 32 [ERROR] InnoDB: Record in index `pl_backlinks_namespace` of table `wikidatawiki`.`pagelinks` was not found on update: TUPLE (info_bits=0, 4 fields): {[4] (0x80000000),[4]
4	x(0x80000078),[5]P4656(0x5034363536),[4] } (0x01017DA1)} at: COMPACT RECORD(info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[5]P4656(0x5034363536),[4] } (0x01017D97)}
5	Jul 02 11:00:33 dbstore1005 mysqld[4259]: 2020-07-02 11:00:33 32 [ERROR] InnoDB: Record in index `pl_backlinks_namespace` of table `wikidatawiki`.`pagelinks` was not found on update: TUPLE (info_bits=0, 4 fields): {[4] (0x80000000),[4]
6	x(0x80000078),[4]P571(0x50353731),[4] } (0x01017DA1)} at: COMPACT RECORD(info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[4]P571(0x50353731),[4] } (0x01017D97)}
7	Jul 02 11:00:35 dbstore1005 mysqld[4259]: 2020-07-02 11:00:35 32 [ERROR] InnoDB: Record in index `page_len` of table `wikidatawiki`.`page` was not found on update: TUPLE (info_bits=0, 2 fields): {[4] ) (0x000029EE),[4] HT(0x01014854)} a
8	t: COMPACT RECORD(info_bits=0, 2 fields): {[4] ) (0x000029EE),[4] (0x010115D8)}
9	Jul 02 11:00:35 dbstore1005 mysqld[4259]: 2020-07-02 11:00:35 32 [ERROR] InnoDB: Record in index `page_redirect_namespace_len` of table `wikidatawiki`.`page` was not found on update: TUPLE (info_bits=0, 4 fields): {[1] (0x00),[4] (0x80
10	000000),[4] ) (0x000029EE),[4] HT(0x01014854)} at: COMPACT RECORD(info_bits=0, 4 fields): {[1] (0x00),[4] (0x80000000),[4] ) (0x000029EE),[4] (0x010115D8)}
11	Jul 02 11:00:35 dbstore1005 mysqld[4259]: 2020-07-02 11:00:35 32 [ERROR] InnoDB: Record in index `pl_backlinks_namespace` of table `wikidatawiki`.`pagelinks` was not found on update: TUPLE (info_bits=0, 4 fields): {[4] (0x80000000),[4]
12	x(0x80000078),[5]P4656(0x5034363536),[4] HT(0x01014854)} at: COMPACT RECORD(info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[5]P4656(0x5034363536),[4] H2(0x01014832)}
13	Jul 02 11:00:35 dbstore1005 mysqld[4259]: 2020-07-02 11:00:35 32 [ERROR] InnoDB: Record in index `pl_backlinks_namespace` of table `wikidatawiki`.`pagelinks` was not found on update: TUPLE (info_bits=0, 4 fields): {[4] (0x80000000),[4]
14	x(0x80000078),[4]P571(0x50353731),[4] HT(0x01014854)} at: COMPACT RECORD(info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[4]P571(0x50353731),[4] H (0x01014818)}
15	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 2020-07-02 11:00:37 1 [ERROR] InnoDB: Unable to find a record to delete-mark
16	Jul 02 11:00:37 dbstore1005 mysqld[4259]: InnoDB: tuple DATA TUPLE: 4 fields;
17	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 0: len 4; hex 80000000; asc ;;
18	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 1: len 4; hex 80000078; asc x;;
19	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 2: len 4; hex 50353731; asc P571;;
20	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 3: len 4; hex 00ff1b9a; asc ;;
21	Jul 02 11:00:37 dbstore1005 mysqld[4259]: InnoDB: record PHYSICAL RECORD: n_fields 4; compact format; info bits 0
22	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 0: len 4; hex 80000000; asc ;;
23	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 1: len 4; hex 80000078; asc x;;
24	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 2: len 4; hex 50353731; asc P571;;
25	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 3: len 4; hex 00ff1b99; asc ;;
26	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 2020-07-02 11:00:37 1 [ERROR] InnoDB: page [page id: space=1020, page number=6276571] (429 records, index id 3321).
27	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 2020-07-02 11:00:37 1 [ERROR] InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
28	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 2020-07-02 11:00:37 1 [ERROR] InnoDB: Unable to find a record to delete-mark
29	Jul 02 11:00:37 dbstore1005 mysqld[4259]: InnoDB: tuple DATA TUPLE: 4 fields;
30	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 0: len 4; hex 80000000; asc ;;
31	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 1: len 4; hex 80000078; asc x;;
32	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 2: len 5; hex 5034363536; asc P4656;;
33	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 3: len 4; hex 00ff1b9a; asc ;;
34	Jul 02 11:00:37 dbstore1005 mysqld[4259]: InnoDB: record PHYSICAL RECORD: n_fields 4; compact format; info bits 0
35	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 0: len 4; hex 80000000; asc ;;
36	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 1: len 4; hex 80000078; asc x;;
37	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 2: len 5; hex 5034363536; asc P4656;;
38	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 3: len 4; hex 00ff1b99; asc ;;
39	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 2020-07-02 11:00:37 1 [ERROR] InnoDB: page [page id: space=1020, page number=9314226] (519 records, index id 3321).
40	Jul 02 11:00:37 dbstore1005 mysqld[4259]: 2020-07-02 11:00:37 1 [ERROR] InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
41	Jul 02 11:00:39 dbstore1005 mysqld[4259]: 2020-07-02 11:00:39 32 [ERROR] InnoDB: Record in index `page_redirect_namespace_len` of table `wikidatawiki`.`page` was not found on update: TUPLE (info_bits=0, 4 fields): {[1] (0x00),[4] (0x80
42	000000),[4] (0x0000167F),[4] W (0x010157D3)} at: COMPACT RECORD(info_bits=0, 4 fields): {[1] (0x00),[4] (0x80000000),[4] (0x0000167F),[4] ;_(0x00FF3B5F)}
43	Jul 02 11:00:39 dbstore1005 mysqld[4259]: 2020-07-02 11:00:39 32 [ERROR] InnoDB: Record in index `pl_backlinks_namespace` of table `wikidatawiki`.`pagelinks` was not found on update: TUPLE (info_bits=0, 4 fields): {[4] (0x80000000),[4]
44	x(0x80000078),[4]P571(0x50353731),[4] W (0x010157D3)} at: COMPACT RECORD(info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[4]P571(0x50353731),[4] W (0x010157D1)}
45	Jul 02 11:00:39 dbstore1005 mysqld[4259]: 2020-07-02 11:00:39 1 [ERROR] InnoDB: Unable to find a record to delete-mark
46	Jul 02 11:00:39 dbstore1005 mysqld[4259]: InnoDB: tuple DATA TUPLE: 4 fields;
47	Jul 02 11:00:39 dbstore1005 mysqld[4259]: 0: len 4; hex 80000000; asc ;;
48	Jul 02 11:00:39 dbstore1005 mysqld[4259]: 1: len 4; hex 80000078; asc x;;
49	Jul 02 11:00:39 dbstore1005 mysqld[4259]: 2: len 5; hex 5034363536; asc P4656;;
50	Jul 02 11:00:39 dbstore1005 mysqld[4259]: 3: len 4; hex 010157d3; asc W ;;
51	Jul 02 11:00:39 dbstore1005 mysqld[4259]: InnoDB: record PHYSICAL RECORD: n_fields 4; compact format; info bits 0
52	Jul 02 11:00:39 dbstore1005 mysqld[4259]: 0: len 4; hex 80000000; asc ;;
53	Jul 02 11:00:39 dbstore1005 mysqld[4259]: 1: len 4; hex 80000078; asc x;;
54	Jul 02 11:00:39 dbstore1005 mysqld[4259]: 2: len 5; hex 5034363536; asc P4656;;
55	Jul 02 11:00:39 dbstore1005 mysqld[4259]: 3: len 4; hex 010157b6; asc W ;;
56	Jul 02 11:00:39 dbstore1005 mysqld[4259]: 2020-07-02 11:00:39 1 [ERROR] InnoDB: page [page id: space=1020, page number=4847974] (364 records, index id 3321).
57	Jul 02 11:00:39 dbstore1005 mysqld[4259]: 2020-07-02 11:00:39 1 [ERROR] InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
58	Jul 02 11:00:41 dbstore1005 mysqld[4259]: 2020-07-02 11:00:41 32 [ERROR] InnoDB: Record in index `page_len` of table `wikidatawiki`.`page` was not found on update: TUPLE (info_bits=0, 2 fields): {[4] W(0x00001457),[4] !R(0x01022152)} at: COMPACT RECORD(info_bits=0, 2 fields): {[4] W(0x00001457),[4] SM(0x0101534D)}
59	Jul 02 11:00:41 dbstore1005 mysqld[4259]: 2020-07-02 11:00:41 32 [ERROR] InnoDB: Record in index `page_redirect_namespace_len` of table `wikidatawiki`.`page` was not found on update: TUPLE (info_bits=0, 4 fields): {[1] (0x00),[4] (0x80000000),[4] W(0x00001457),[4] !R(0x01022152)} at: COMPACT RECORD(info_bits=0, 4 fields): {[1] (0x00),[4] (0x80000000),[4] W(0x00001457),[4] SM(0x0101534D)}
60	Jul 02 11:00:41 dbstore1005 mysqld[4259]: 2020-07-02 11:00:41 32 [ERROR] InnoDB: Record in index `pl_backlinks_namespace` of table `wikidatawiki`.`pagelinks` was not found on update: TUPLE (info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[5]P4656(0x5034363536),[4] !R(0x01022152)} at: COMPACT RECORD(info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[5]P4656(0x5034363536),[4] !O(0x0102214F)}
61	Jul 02 11:00:41 dbstore1005 mysqld[4259]: 2020-07-02 11:00:41 32 [ERROR] InnoDB: Record in index `pl_backlinks_namespace` of table `wikidatawiki`.`pagelinks` was not found on update: TUPLE (info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[4]P571(0x50353731),[4] !R(0x01022152)} at: COMPACT RECORD(info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[4]P571(0x50353731),[4] !M(0x0102214D)}
62	Jul 02 11:00:42 dbstore1005 mysqld[4259]: 2020-07-02 11:00:42 32 [ERROR] InnoDB: Record in index `page_len` of table `wikidatawiki`.`page` was not found on update: TUPLE (info_bits=0, 2 fields): {[4] S(0x00001553),[4] O (0x011A4FCB)} at: COMPACT RECORD(info_bits=0, 2 fields): {[4] S(0x00001553),[4] 1 (0x011A31EB)}
63	Jul 02 11:00:42 dbstore1005 mysqld[4259]: 2020-07-02 11:00:42 32 [ERROR] InnoDB: Record in index `pl_backlinks_namespace` of table `wikidatawiki`.`pagelinks` was not found on update: TUPLE (info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[5]P4656(0x5034363536),[4] O (0x011A4FCB)} at: COMPACT RECORD(info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[5]P4656(0x5034363536),[4] O (0x011A4FC9)}
64	Jul 02 11:00:44 dbstore1005 mysqld[4259]: 2020-07-02 11:00:44 32 [ERROR] InnoDB: Record in index `pl_backlinks_namespace` of table `wikidatawiki`.`pagelinks` was not found on update: TUPLE (info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[5]P4656(0x5034363536),[4] ](0x0101905D)} at: COMPACT RECORD(info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[5]P4656(0x5034363536),[4] [(0x0101905B)}
65	Jul 02 11:00:44 dbstore1005 mysqld[4259]: 2020-07-02 11:00:44 32 [ERROR] InnoDB: Record in index `pl_backlinks_namespace` of table `wikidatawiki`.`pagelinks` was not found on update: TUPLE (info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[4]P571(0x50353731),[4] ](0x0101905D)} at: COMPACT RECORD(info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[4]P571(0x50353731),[4] [(0x0101905B)}
66	Jul 02 11:00:46 dbstore1005 mysqld[4259]: 2020-07-02 11:00:46 32 [ERROR] InnoDB: Record in index `pl_backlinks_namespace` of table `wikidatawiki`.`pagelinks` was not found on update: TUPLE (info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[4]P571(0x50353731),[4] "(0x01020F22)} at: COMPACT RECORD(info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[4]P571(0x50353731),[4] (0x01020F0D)}
67	Jul 02 11:00:47 dbstore1005 mysqld[4259]: 2020-07-02 11:00:47 32 [ERROR] InnoDB: Record in index `page_redirect_namespace_len` of table `wikidatawiki`.`page` was not found on update: TUPLE (info_bits=0, 4 fields): {[1] (0x00),[4] (0x80000000),[4] ) (0x000029B3),[4] B!(0x01024221)} at: COMPACT RECORD(info_bits=0, 4 fields): {[1] (0x00),[4] (0x80000000),[4] ) (0x000029B3),[4] )1(0x01022931)}
68	Jul 02 11:00:47 dbstore1005 mysqld[4259]: 2020-07-02 11:00:47 32 [ERROR] InnoDB: Record in index `pl_backlinks_namespace` of table `wikidatawiki`.`pagelinks` was not found on update: TUPLE (info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[4]P571(0x50353731),[4] B!(0x01024221)} at: COMPACT RECORD(info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[4]P571(0x50353731),[4] B (0x01024211)}
69	Jul 02 11:00:49 dbstore1005 mysqld[4259]: 2020-07-02 11:00:49 32 [ERROR] InnoDB: Record in index `page_len` of table `wikidatawiki`.`page` was not found on update: TUPLE (info_bits=0, 2 fields): {[4] I(0x00001549),[4] M (0x011A4D88)} at: COMPACT RECORD(info_bits=0, 2 fields): {[4] I(0x00001549),[4] (0x011A160D)}
70	Jul 02 11:00:49 dbstore1005 mysqld[4259]: 2020-07-02 11:00:49 32 [ERROR] InnoDB: Record in index `el_to` of table `wikidatawiki`.`externallinks` was not found on update: TUPLE (info_bits=0, 3 fields): {[60]https://en.wikipedia.org/w/index.php?title=Sunnyside_(Newsom(0x68747470733A2F2F656E2E77696B6970656469612E6F72672F772F696E6465782E7068703F7469746C653D53756E6E79736964655F284E6577736F6D),[4] M (0x011A4D88),[4] (0x04A3A4DC)} at: COMPACT RECORD(info_bits=0, 3 fields): {[60]https://en.wikipedia.org/w/index.php?title=Sunnyside_(Heaths(0x68747470733A2F2F656E2E77696B6970656469612E6F72672F772F696E6465782E7068703F7469746C653D53756E6E79736964655F28486561746873),[4] (0x00F9F111),[4] (0x0205DCF7)}
71	Jul 02 11:00:49 dbstore1005 mysqld[4259]: 2020-07-02 11:00:49 32 [ERROR] InnoDB: Record in index `el_index` of table `wikidatawiki`.`externallinks` was not found on update: TUPLE (info_bits=0, 2 fields): {[60]https://org.wikipedia.en./w/index.php?title=Sunnyside_(Newso(0x68747470733A2F2F6F72672E77696B6970656469612E656E2E2F772F696E6465782E7068703F7469746C653D53756E6E79736964655F284E6577736F),[4] (0x04A3A4DC)} at: COMPACT RECORD(info_bits=0, 2 fields): {[60]https://org.wikipedia.en./w/index.php?title=Sunnyside_(Heath(0x68747470733A2F2F6F72672E77696B6970656469612E656E2E2F772F696E6465782E7068703F7469746C653D53756E6E79736964655F284865617468),[4] (0x0205DCF7)}
72	Jul 02 11:00:51 dbstore1005 mysqld[4259]: 2020-07-02 11:00:51 32 [ERROR] InnoDB: Record in index `page_redirect_namespace_len` of table `wikidatawiki`.`page` was not found on update: TUPLE (info_bits=0, 4 fields): {[1] (0x00),[4] (0x80000000),[4] (0x0000170A),[4] (0x0101F4A2)} at: COMPACT RECORD(info_bits=0, 4 fields): {[1] (0x00),[4] (0x80000000),[4] (0x0000170A),[4] (0x0101F317)}
73	Jul 02 11:00:51 dbstore1005 mysqld[4259]: 2020-07-02 11:00:51 32 [ERROR] InnoDB: Record in index `pl_backlinks_namespace` of table `wikidatawiki`.`pagelinks` was not found on update: TUPLE (info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[5]P4656(0x5034363536),[4] (0x0101F4A2)} at: COMPACT RECORD(info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[5]P4656(0x5034363536),[4] w(0x0101F477)}
74	Jul 02 11:00:51 dbstore1005 mysqld[4259]: 2020-07-02 11:00:51 32 [ERROR] InnoDB: Record in index `pl_backlinks_namespace` of table `wikidatawiki`.`pagelinks` was not found on update: TUPLE (info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[4]P571(0x50353731),[4] (0x0101F4A2)} at: COMPACT RECORD(info_bits=0, 4 fields): {[4] (0x80000000),[4] x(0x80000078),[4]P571(0x50353731),[4] b(0x0101F462)}
75	Jul 02 11:00:53 dbstore1005 mysqld[4259]: 2020-07-02 11:00:53 32 [ERROR] InnoDB: Record in index `page_len` of table `wikidatawiki`.`page` was not found on update: TUPLE (info_bits=0, 2 fields): {[4] %#(0x00002523),[4] 1 (0x010231C9)} at: COMPACT RECORD(info_bits=0, 2 fields): {[4] %#(0x00002523),[4] (0x010014A8)}
76	Jul 02 11:00:53 dbstore1005 mysqld[4259]: 2020-07-02 11:00:53 0x7fdf103d3700 InnoDB: Assertion failure in file /root/mariadb-10.4.13/storage/innobase/row/row0ins.cc line 231
77	Jul 02 11:00:53 dbstore1005 mysqld[4259]: InnoDB: Failing assertion: !cursor->index->is_committed()
78	Jul 02 11:00:53 dbstore1005 mysqld[4259]: InnoDB: We intentionally generate a memory trap.
79	Jul 02 11:00:53 dbstore1005 mysqld[4259]: InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
80	Jul 02 11:00:53 dbstore1005 mysqld[4259]: InnoDB: If you get repeated assertion failures or crashes, even
81	Jul 02 11:00:53 dbstore1005 mysqld[4259]: InnoDB: immediately after the mysqld startup, there may be
82	Jul 02 11:00:53 dbstore1005 mysqld[4259]: InnoDB: corruption in the InnoDB tablespace. Please refer to
83	Jul 02 11:00:53 dbstore1005 mysqld[4259]: InnoDB: https://mariadb.com/kb/en/library/innodb-recovery-modes/
84	Jul 02 11:00:53 dbstore1005 mysqld[4259]: InnoDB: about forcing recovery.
85	Jul 02 11:00:53 dbstore1005 mysqld[4259]: 200702 11:00:53 [ERROR] mysqld got signal 6 ;
86	Jul 02 11:00:53 dbstore1005 mysqld[4259]: This could be because you hit a bug. It is also possible that this binary
87	Jul 02 11:00:53 dbstore1005 mysqld[4259]: or one of the libraries it was linked against is corrupt, improperly built,
88	Jul 02 11:00:53 dbstore1005 mysqld[4259]: or misconfigured. This error can also be caused by malfunctioning hardware.
89	Jul 02 11:00:53 dbstore1005 mysqld[4259]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
90	Jul 02 11:00:53 dbstore1005 mysqld[4259]: We will try our best to scrape up some info that will hopefully help
91	Jul 02 11:00:53 dbstore1005 mysqld[4259]: diagnose the problem, but since we have already crashed,
92	Jul 02 11:00:53 dbstore1005 mysqld[4259]: something is definitely wrong and this may fail.
93	Jul 02 11:00:53 dbstore1005 mysqld[4259]: Server version: 10.4.13-MariaDB
94	Jul 02 11:00:53 dbstore1005 mysqld[4259]: key_buffer_size=1048576
95	Jul 02 11:00:53 dbstore1005 mysqld[4259]: read_buffer_size=131072
96	Jul 02 11:00:53 dbstore1005 mysqld[4259]: max_used_connections=77
97	Jul 02 11:00:53 dbstore1005 mysqld[4259]: max_threads=252
98	Jul 02 11:00:53 dbstore1005 mysqld[4259]: thread_count=83
99	Jul 02 11:00:53 dbstore1005 mysqld[4259]: It is possible that mysqld could use up to
100	Jul 02 11:00:53 dbstore1005 mysqld[4259]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 555578 K bytes of memory
101	Jul 02 11:00:53 dbstore1005 mysqld[4259]: Hope that's ok; if not, decrease some variables in the equation.
102	Jul 02 11:00:53 dbstore1005 mysqld[4259]: Thread pointer: 0x7fa6940014f8
103	Jul 02 11:00:53 dbstore1005 mysqld[4259]: Attempting backtrace. You can use the following information to find out
104	Jul 02 11:00:53 dbstore1005 mysqld[4259]: where mysqld died. If you see no messages after this, something went
105	Jul 02 11:00:53 dbstore1005 mysqld[4259]: terribly wrong...
106	Jul 02 11:00:53 dbstore1005 mysqld[4259]: stack_bottom = 0x7fdf103d2698 thread_stack 0x49000
107	Jul 02 11:00:53 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(my_print_stacktrace+0x2e)[0x558719c157de]
108	Jul 02 11:00:53 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(handle_fatal_signal+0x54d)[0x55871970db4d]
109	Jul 02 11:00:54 dbstore1005 mysqld[4259]: /lib/x86_64-linux-gnu/libpthread.so.0(+0x12730)[0x7fdf2a0ed730]
110	Jul 02 11:00:54 dbstore1005 mysqld[4259]: /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x10b)[0x7fdf297557bb]
111	Jul 02 11:00:54 dbstore1005 mysqld[4259]: /lib/x86_64-linux-gnu/libc.so.6(abort+0x121)[0x7fdf29740535]
112	Jul 02 11:00:54 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(+0x5a19d5)[0x5587194099d5]
113	Jul 02 11:00:54 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(+0x5907c1)[0x5587193f87c1]
114	Jul 02 11:00:54 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(+0xaeee0e)[0x558719956e0e]
115	Jul 02 11:00:54 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(+0xb22478)[0x55871998a478]
116	Jul 02 11:00:54 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(+0xb27e0f)[0x55871998fe0f]
117	Jul 02 11:00:54 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(+0xb0023c)[0x55871996823c]
118	Jul 02 11:00:54 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(+0xa5043f)[0x5587198b843f]
119	Jul 02 11:00:55 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(_ZN7handler13ha_update_rowEPKhS1_+0xbb)[0x558719719a0b]
120	Jul 02 11:00:55 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(_Z12mysql_updateP3THDP10TABLE_LISTR4ListI4ItemES6_PS4_jP8st_orderybPySA_+0x1b27)[0x5587195b5617]
121	Jul 02 11:00:55 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(_Z21mysql_execute_commandP3THD+0x26ca)[0x5587195084fa]
122	Jul 02 11:00:55 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x1c9)[0x55871950e179]
123	Jul 02 11:00:55 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(_ZN15Query_log_event14do_apply_eventEP14rpl_group_infoPKcj+0x682)[0x558719804e52]
124	Jul 02 11:00:55 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(+0x5faf02)[0x558719462f02]
125	Jul 02 11:00:55 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(handle_slave_sql+0x12e2)[0x55871946bef2]
126	Jul 02 11:00:55 dbstore1005 mysqld[4259]: /opt/wmf-mariadb104/bin/mysqld(+0xd5e28b)[0x558719bc628b]
127	Jul 02 11:00:55 dbstore1005 mysqld[4259]: /lib/x86_64-linux-gnu/libpthread.so.0(+0x7fa3)[0x7fdf2a0e2fa3]
128	Jul 02 11:00:55 dbstore1005 mysqld[4259]: /lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7fdf298174cf]
129	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Trying to get some variables.
130	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Some pointers may be invalid and cause the dump to abort.
131	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Query (0x7fa6943bd91b): UPDATE /* WikiPage::updateRevisionOn */ `page` SET page_latest = 1222570180,page_touched = '20200702110053',page_is_new = 0,page_is_redirect = 0,page_len = 8230,page_content_model = 'wikibase-item' WHERE page_id = 16921033
132	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Connection ID (thread ID): 32
133	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Status: NOT_KILLED
134	Jul 02 11:00:55 dbstore1005 mysqld[4259]: 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=on,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
135	Jul 02 11:00:55 dbstore1005 mysqld[4259]: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
136	Jul 02 11:00:55 dbstore1005 mysqld[4259]: information that should help you find out what is causing the crash.
137	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Writing a core file...
138	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Working directory at /srv/sqldata.s8
139	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Resource Limits:
140	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Limit Soft Limit Hard Limit Units
141	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max cpu time unlimited unlimited seconds
142	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max file size unlimited unlimited bytes
143	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max data size unlimited unlimited bytes
144	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max stack size 8388608 unlimited bytes
145	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max core file size 0 0 bytes
146	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max resident set unlimited unlimited bytes
147	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max processes 2058623 2058623 processes
148	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max open files 200001 200001 files
149	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max locked memory 65536 65536 bytes
150	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max address space unlimited unlimited bytes
151	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max file locks unlimited unlimited locks
152	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max pending signals 2058623 2058623 signals
153	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max msgqueue size 819200 819200 bytes
154	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max nice priority 0 0
155	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max realtime priority 0 0
156	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Max realtime timeout unlimited unlimited us
157	Jul 02 11:00:55 dbstore1005 mysqld[4259]: Core pattern: /var/tmp/core/core.%h.%e.%p....
158	Jul 02 11:00:56 dbstore1005 systemd[1]: mariadb@s8.service: Main process exited, code=killed, status=6/ABRT

Ah, I only saw the ones reported on the task initial creation. Those are definitely similar to the ones we did see during the crashes with labsdb hosts. Going to comment on the upstream bug just in case.

Marostegui added a project: Upstream.Jul 6 2020, 7:34 AM

dbstore1005 s8 mariadb instance crashedClosed, ResolvedPublicActions

Description

Related Objects

Event Timeline

dbstore1005 s8 mariadb instance crashed
Closed, ResolvedPublic
Actions