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

Mariadb crashed and replication got broken after MariaDB services came up

Details

    • Bug
    • Status: Closed (View Workflow)
    • Major
    • Resolution: Incomplete
    • 10.11.5
    • N/A
    • Replication
    • None

    Description

      Mariadb crashed and replication got broken after MariaDB services came up

      MariaDB Logs

      240702 7:44:13 [ERROR] mysqld got signal 11 ;
      This could be because you hit a bug. It is also possible that this binary
      or one of the libraries it was linked against is corrupt, improperly built,
      or misconfigured. This error can also be caused by malfunctioning hardware.

      To report this bug, see https://mariadb.com/kb/en/reporting-bugs

      We will try our best to scrape up some info that will hopefully help
      diagnose the problem, but since we have already crashed,
      something is definitely wrong and this may fail.

      Server version: 10.11.5-MariaDB-log source revision: 7875294b6b74b53dd3aaa723e6cc103d2bb47b2c
      key_buffer_size=67108864
      read_buffer_size=131072
      max_used_connections=456
      max_threads=802
      thread_count=473
      It is possible that mysqld could use up to
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 1831964 K bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.

      Thread pointer: 0x7f41f00043f8
      Attempting backtrace. You can use the following information to find out
      where mysqld died. If you see no messages after this, something went
      terribly wrong...
      stack_bottom = 0x7f419dc10b98 thread_stack 0x49000
      Can't start addr2line
      /usr/sbin/mariadbd(my_print_stacktrace+0x2e)[0x564fe526a12e]
      /usr/sbin/mariadbd(handle_fatal_signal+0x485)[0x564fe4d635b5]
      /lib64/libpthread.so.0(+0x12cf0)[0x7f9188ee7cf0]
      /usr/sbin/mariadbd(_Z10MYSQLparseP3THD+0x19a7)[0x564fe4ce9117]
      /usr/sbin/mariadbd(_Z9parse_sqlP3THDP12Parser_stateP19Object_creation_ctxb+0x13c)[0x564fe4b1981a]
      /usr/sbin/mariadbd(_Z11mysql_parseP3THDPcjP12Parser_state+0xef)[0x564fe4b15a1a]
      /usr/sbin/mariadbd(_Z16dispatch_command19enum_server_commandP3THDPcjb+0x1080)[0x564fe4b1f6e6]
      /usr/sbin/mariadbd(_Z10do_commandP3THDb+0x12f)[0x564fe4b20dab]
      /usr/sbin/mariadbd(_Z24do_handle_one_connectionP7CONNECTb+0x3f7)[0x564fe4c34977]
      /usr/sbin/mariadbd(handle_one_connection+0x5d)[0x564fe4c34cbd]
      /usr/sbin/mariadbd(+0xc42c9d)[0x564fe4f6ac9d]
      /lib64/libpthread.so.0(+0x81ca)[0x7f9188edd1ca]
      /lib64/libc.so.6(clone+0x43)[0x7f918822de73]

      Trying to get some variables.
      Some pointers may be invalid and cause the dump to abort.
      Query (0x7f41f0859c20): Select Users.UserIndex, UserID, Users.Password, GroupName, PasswordSource, UserService, UserIP, FilterName, UserActive, Users.StartDate, UserExpiryDate, CallBackNumber, CallerID, Lockout, Users.PasswordEncryptionMethod, MaxUserSessions, SkipPasswordCheck, HotlineStatus, BarringStatus, BarringReason, MaxVolumeCap, AllowedAccessTypes, CopyRadiusRequests, SubnetIP, SubnetMask, CIDR, CustomField1, CustomField2, CustomField3, CustomField4, CustomField5, CustomNumField1, CustomNumField2, CustomNumField3, CustomNumField4, CustomNumField5, SessionLimit, UserTokens, FirstLogon, FramedInterfaceId, FramedIPv6Prefix, PeriodicTimeUsage, PeriodicVolumeUsage, TimeUsageTriggerThresholds, VolumeUsageTriggerThresholds, CustomReplylist, CustomChecklist, BillingSystemCorrelationId, ChargingSystemCorrelationId, ChargingMode, LockOutTime, LockOutCount, Users.PseudoIdentity, CustomDate1, CustomDate2, CustomDate3, CustomDate4, CustomDate5, CustomField6, CustomField7, CustomField8, CustomField9, CustomField10, RestrictedLocations, MaxTimeCap, PortId, CustomNumField6, CustomNumField7, CustomNumField8, CustomNumField9, CustomNumField10,SpeedMapName,UserIPv6,NetworkService, CustomField11,CustomField12,CustomField13,CustomField14,CustomField15 , PasswordDate From Users Where UserID = '03120156867'

      Connection ID (thread ID): 23829712
      Status: NOT_KILLED
      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,not_null_range_scan=off,hash_join_cardinality=off

      The manual page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/ contains
      information that should help you find out what is causing the crash.
      Writing a core file...
      Working directory at /var/lib/mysql
      Resource Limits:
      Limit Soft Limit Hard Limit Units
      Max cpu time unlimited unlimited seconds
      Max file size unlimited unlimited bytes
      Max data size unlimited unlimited bytes
      Max stack size 8388608 unlimited bytes
      Max core file size unlimited unlimited bytes
      Max resident set unlimited unlimited bytes
      Max processes 2061710 2061710 processes
      Max open files 32768 32768 files
      Max locked memory 65536 65536 bytes
      Max address space unlimited unlimited bytes
      Max file locks unlimited unlimited locks
      Max pending signals 2061710 2061710 signals
      Max msgqueue size 819200 819200 bytes
      Max nice priority 0 0
      Max realtime priority 0 0
      Max realtime timeout unlimited unlimited us
      Core pattern: /var/coredumps/core.%e.%p

      Kernel version: Linux version 4.18.0-477.13.1.el8_8.x86_64 (mockbuild@x86-vm-08.build.eng.bos.redhat.com) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-18) (GCC)) #1 SMP Thu May 18 10:27:05 EDT 2023

      2024-07-02 7:44:50 0 [Note] Starting MariaDB 10.11.5-MariaDB-log source revision 7875294b6b74b53dd3aaa723e6cc103d2bb47b2c as process 2528686
      2024-07-02 7:44:50 0 [Note] mariadbd: Aria engine: starting recovery
      tables to flush: 3 2 1 0
      (0.0 seconds);
      2024-07-02 7:44:50 0 [Note] mariadbd: Aria engine: recovery done
      2024-07-02 7:44:50 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
      2024-07-02 7:44:50 0 [Note] InnoDB: Number of transaction pools: 1
      2024-07-02 7:44:50 0 [Note] InnoDB: Number of transaction pools: 1
      2024-07-02 7:44:50 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions
      2024-07-02 7:44:50 0 [Note] InnoDB: Using Linux native AIO
      2024-07-02 7:44:50 0 [Note] InnoDB: Initializing buffer pool, total size = 300.000GiB, chunk size = 4.688GiB
      2024-07-02 7:44:51 0 [Note] InnoDB: Completed initialization of buffer pool
      2024-07-02 7:44:52 0 [Note] InnoDB: File system buffers for log disabled (block size=512 bytes)
      2024-07-02 7:44:53 0 [Warning] InnoDB: 3027328000 bytes should have been read at 1267639296 from (unknown file), but got only 2147479552. Retrying.
      2024-07-02 7:44:55 0 [Warning] InnoDB: 3161871360 bytes should have been read at 1133095936 from (unknown file), but got only 2147479552. Retrying.
      2024-07-02 7:44:56 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=31139380963342
      2024-07-02 7:44:57 0 [Note] InnoDB: End of log at LSN=31139515623950
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266273 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266275 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266281 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266110 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266283 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266285 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266288 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266289 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266290 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266291 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266292 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266121 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266133 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266297 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266298 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266299 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266301 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266302 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266304 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266303 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266307 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266309 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266147 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266310 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266148 was in the XA prepared state.
      2024-07-02 7:44:57 0 [Note] InnoDB: Transaction 83100266311 was in the XA prepared state.
      2024-07-02 7:44:58 0 [Note] InnoDB: Transaction 83100266149 was in the XA prepared state.
      2024-07-02 7:44:58 0 [Note] InnoDB: Transaction 83100266312 was in the XA prepared state.
      2024-07-02 7:44:58 0 [Note] InnoDB: Transaction 83100266150 was in the XA prepared state.
      2024-07-02 7:44:58 0 [Note] InnoDB: Transaction 83100266151 was in the XA prepared state.
      2024-07-02 7:44:58 0 [Note] InnoDB: Transaction 83100266317 was in the XA prepared state.
      2024-07-02 7:44:58 0 [Note] InnoDB: Transaction 83100266165 was in the XA prepared state.
      2024-07-02 7:44:58 0 [Note] InnoDB: 142 transaction(s) which must be rolled back or cleaned up in total 59 row operations to undo
      2024-07-02 7:44:58 0 [Note] InnoDB: Trx id counter is 83100266335
      2024-07-02 7:44:58 0 [Note] InnoDB: To recover: 128796 pages
      2024-07-02 7:45:00 0 [Note] InnoDB: Last binlog file './db2-binary.166681', position 26292437
      2024-07-02 7:45:00 0 [Note] InnoDB: 128 rollback segments are active.
      2024-07-02 7:45:00 0 [Note] InnoDB: Starting in background the rollback of recovered transactions
      2024-07-02 7:45:00 0 [Note] InnoDB: Rolled back recovered transaction 83100266324
      2024-07-02 7:45:00 0 [Note] InnoDB: Rolled back recovered transaction 83100266295
      2024-07-02 7:45:00 0 [Note] InnoDB: Removed temporary tablespace data file: "./ibtmp1"
      2024-07-02 7:45:00 0 [Note] InnoDB: Setting file './ibtmp1' size to 12.000MiB. Physically writing the file full; Please wait ...
      2024-07-02 7:45:00 0 [Note] InnoDB: Rolled back recovered transaction 83100266276
      2024-07-02 7:45:00 0 [Note] InnoDB: Rolled back recovered transaction 83100266321
      2024-07-02 7:45:00 0 [Note] InnoDB: File './ibtmp1' size is now 12.000MiB.
      2024-07-02 7:45:00 0 [Note] InnoDB: log sequence number 31139515623950; transaction id 83100266340
      2024-07-02 7:45:00 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
      2024-07-02 7:45:00 0 [Note] Plugin 'FEEDBACK' is disabled.
      2024-07-02 7:45:00 0 [Note] InnoDB: Rolled back recovered transaction 83100266316
      2024-07-02 7:45:00 0 [Note] InnoDB: Rolled back recovered transaction 83100266325
      2024-07-02 7:45:00 0 [Note] InnoDB: Rolled back recovered transaction 83100266322
      2024-07-02 7:45:00 0 [Note] InnoDB: Rolled back recovered transaction 83100266326
      2024-07-02 7:45:00 0 [Note] InnoDB: Rolled back recovered transaction 83100266329
      2024-07-02 7:45:00 0 [Note] InnoDB: Rolled back recovered transaction 83100266156
      2024-07-02 7:45:00 0 [Warning] 'thread-concurrency' was removed. It does nothing now and exists only for compatibility with old my.cnf files.
      2024-07-02 7:45:00 0 [Warning] 'innodb-thread-concurrency' was removed. It does nothing now and exists only for compatibility with old my.cnf files.
      2024-07-02 7:45:00 0 [Warning] 'innodb-log-files-in-group' was removed. It does nothing now and exists only for compatibility with old my.cnf files.
      2024-07-02 7:45:00 0 [Note] Recovering after a crash using db2-binary
      2024-07-02 7:45:00 0 [Note] Starting table crash recovery...
      2024-07-02 7:45:00 0 [Note] InnoDB: Starting recovery for XA transactions...
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction 83100266177 in prepared state after recovery
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction contains changes to 1 rows
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction 83100266238 in prepared state after recovery
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction contains changes to 1 rows
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction 83100266185 in prepared state after recovery
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction contains changes to 1 rows
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction 83100266110 in prepared state after recovery
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction contains changes to 1 rows
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction 83100266206 in prepared state after recovery
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction contains changes to 1 rows
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction 83100266121 in prepared state after recovery
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction contains changes to 1 rows
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction 83100266201 in prepared state after recovery
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction contains changes to 1 rows
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction 83100266182 in prepared state after recovery
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction contains changes to 1 rows
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction 83100266150 in prepared state after recovery
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction contains changes to 1 rows
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction 83100266196 in prepared state after recovery
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction contains changes to 1 rows
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction 83100266260 in prepared state after recovery
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction contains changes to 1 rows
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction 83100266288 in prepared state after recovery
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction contains changes to 1 rows
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction contains changes to 1 rows
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction 83100266254 in prepared state after recovery
      2024-07-02 7:45:00 0 [Note] InnoDB: Transaction contains changes to 1 rows
      2024-07-02 7:45:00 0 [Note] InnoDB: 83 transactions in prepared state after recovery
      2024-07-02 7:45:00 0 [Note] Found 83 prepared transaction(s) in InnoDB
      2024-07-02 7:45:00 0 [Note] Crash table recovery finished.
      2024-07-02 7:45:00 0 [Note] InnoDB: Rolled back recovered transaction 83100266331
      2024-07-02 7:45:00 0 [Note] InnoDB: Rolled back recovered transaction 83100266175
      2024-07-02 7:45:00 0 [Note] InnoDB: Rolled back recovered transaction 83100266243
      2024-07-02 7:45:01 0 [Note] Server socket created on IP: '0.0.0.0'.
      2024-07-02 7:45:01 0 [Note] Server socket created on IP: '::'.
      2024-07-02 7:45:01 0 [Warning] 'user' entry '@alepo-db2-ilb' ignored in --skip-name-resolve mode.
      2024-07-02 7:45:01 0 [Warning] 'user' entry 'root@localhost.localdomain' ignored in --skip-name-resolve mode.
      2024-07-02 7:45:01 0 [Warning] 'proxies_priv' entry '@% root@alepo-db2-ilb' ignored in --skip-name-resolve mode.
      2024-07-02 7:45:01 3 [Note] Reading Master_info: 'master-s@002ddb3.info' Relay_info:'relay-log-s@002ddb3.info'
      2024-07-02 7:45:01 3 [Note] Initialized Master_info from 'master-s@002ddb3.info'
      2024-07-02 7:45:01 4 [Note] Master 's-db3': Slave I/O thread: Start asynchronous replication to master '@:3306' in log '' at position 4
      2024-07-02 7:45:01 4 [ERROR] Master 's-db3': Slave I/O: Fatal error: Invalid (empty) username when attempting to connect to the master server. Connection attempt terminated. Internal MariaDB error code: 1593
      2024-07-02 7:45:01 4 [Note] Master 's-db3': Slave I/O thread killed while connecting to master
      2024-07-02 7:45:01 4 [Note] Master 's-db3': Slave I/O thread exiting, read up to log 'FIRST', position 4, master :3306
      2024-07-02 7:45:01 3 [Note] Started replication for 's-db3'
      2024-07-02 7:45:01 5 [Note] Master 's-db3': Slave SQL thread initialized, starting replication in log 'FIRST' at position 0, relay log './db2-relay-s@002ddb3.000014' position: 4
      2024-07-02 7:45:01 3 [Note] Reading Master_info: 'master-s@002ddb4.info' Relay_info:'relay-log-s@002ddb4.info'
      2024-07-02 7:45:01 3 [Note] Initialized Master_info from 'master-s@002ddb4.info'
      2024-07-02 7:45:01 18 [Note] Master 's-db4': Slave I/O thread: Start asynchronous replication to master '@:3306' in log '' at position 4
      2024-07-02 7:45:01 18 [ERROR] Master 's-db4': Slave I/O: Fatal error: Invalid (empty) username when attempting to connect to the master server. Connection attempt terminated. Internal MariaDB error code: 1593
      2024-07-02 7:45:01 18 [Note] Master 's-db4': Slave I/O thread killed while connecting to master
      2024-07-02 7:45:01 18 [Note] Master 's-db4': Slave I/O thread exiting, read up to log 'FIRST', position 4, master :3306
      2024-07-02 7:45:01 3 [Note] Started replication for 's-db4'
      2024-07-02 7:45:01 3 [Note] Reading Master_info: 'master-s@002ddb1.info' Relay_info:'relay-log-s@002ddb1.info'
      2024-07-02 7:45:01 19 [Note] Master 's-db4': Slave SQL thread initialized, starting replication in log 'FIRST' at position 0, relay log './db2-relay-s@002ddb4.000006' position: 4
      2024-07-02 7:45:01 3 [Note] Initialized Master_info from 'master-s@002ddb1.info'
      2024-07-02 7:45:01 20 [Note] Master 's-db1': Slave I/O thread: Start asynchronous replication to master '@:3306' in log '' at position 4
      @@@
      2024-07-02 7:45:01 20 [ERROR] Master 's-db1': Slave I/O: Fatal error: Invalid (empty) username when attempting to connect to the master server. Connection attempt terminated. Internal MariaDB error code: 1593
      2024-07-02 7:45:01 20 [Note] Master 's-db1': Slave I/O thread killed while connecting to master
      2024-07-02 7:45:01 20 [Note] Master 's-db1': Slave I/O thread exiting, read up to log 'FIRST', position 4, master :3306
      2024-07-02 7:45:01 3 [Note] Started replication for 's-db1'
      2024-07-02 7:45:01 3 [Note] Reading Master_info: 'master-s@002ddb5.info' Relay_info:'relay-log-s@002ddb5.info'
      2024-07-02 7:45:01 21 [Note] Master 's-db1': Slave SQL thread initialized, starting replication in log 'FIRST' at position 0, relay log './db2-relay-s@002ddb1.000013' position: 4
      2024-07-02 7:45:01 3 [Note] Initialized Master_info from 'master-s@002ddb5.info'
      2024-07-02 7:45:01 22 [Note] Master 's-db5': Slave I/O thread: Start asynchronous replication to master '@:3306' in log '' at position 4
      2024-07-02 7:45:01 22 [ERROR] Master 's-db5': Slave I/O: Fatal error: Invalid (empty) username when attempting to connect to the master server. Connection attempt terminated. Internal MariaDB error code: 1593
      2024-07-02 7:45:01 22 [Note] Master 's-db5': Slave I/O thread killed while connecting to master
      2024-07-02 7:45:01 22 [Note] Master 's-db5': Slave I/O thread exiting, read up to log 'FIRST', position 4, master :3306
      2024-07-02 7:45:01 3 [Note] Started replication for 's-db5'
      2024-07-02 7:45:01 23 [Note] Master 's-db5': Slave SQL thread initialized, starting replication in log 'FIRST' at position 0, relay log './db2-relay-s@002ddb5.000006' position: 4
      2024-07-02 7:45:01 25 [Note] Slave I/O thread: Start asynchronous replication to master 'gtid@10.76.24.71:3306' in log 'db1-binary.165919' at position 134384110
      2024-07-02 7:45:01 0 [Note] /usr/sbin/mariadbd: ready for connections.
      Version: '10.11.5-MariaDB-log' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server
      2024-07-02 7:45:01 26 [Note] Slave SQL thread initialized, starting replication in log 'db1-binary.165919' at position 4, relay log './db2-relay.433776' position: 304
      2024-07-02 7:45:01 25 [Note] Slave I/O thread: connected to master 'gtid@10.76.24.71:3306',replication started in log 'db1-binary.165919' at position 134384110
      2024-07-02 7:45:01 8 [Note] Detected table cache mutex contention at instance 1: 65% waits. Additional table cache instance activated. Number of instances after activation: 2.
      2024-07-02 7:45:02 0 [Note] InnoDB: Buffer pool(s) load completed at 240702 7:45:02
      2024-07-02 7:45:21 8 [ERROR] mariadbd: Can't find record in 'activesessions'
      2024-07-02 7:45:21 8 [ERROR] Slave SQL: Could not execute Delete_rows_v1 event on table aaadb.activesessions; Can't find record in 'activesessions', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log db1-binary.165919, end_log_pos 168625629, Gtid 0-1-18770872766, Internal MariaDB error code: 1032
      2024-07-02 7:45:21 8 [Warning] Slave: Can't find record in 'activesessions' Error_code: 1032
      2024-07-02 7:45:21 8 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'db1-binary.165919' position 168624875
      2024-07-02 7:45:21 9 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 9 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 9 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'db1-binary.165919' position 168624875
      2024-07-02 7:45:21 7 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 7 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 7 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 7 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'db1-binary.165919' position 168624875
      2024-07-02 7:45:21 6 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 6 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 6 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'db1-binary.165919' position 168624875
      2024-07-02 7:45:21 17 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 17 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 17 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'db1-binary.165919' position 168624875
      2024-07-02 7:45:21 16 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 16 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 16 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'db1-binary.165919' position 168624875
      2024-07-02 7:45:21 14 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 14 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 14 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'db1-binary.165919' position 168624875
      2024-07-02 7:45:21 15 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 15 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 15 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'db1-binary.165919' position 168624875
      2024-07-02 7:45:21 13 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 13 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 13 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'db1-binary.165919' position 168624875
      2024-07-02 7:45:21 12 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 12 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 12 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'db1-binary.165919' position 168624875
      2024-07-02 7:45:21 10 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 10 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 10 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'db1-binary.165919' position 168624875
      2024-07-02 7:45:21 11 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 11 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 7:45:21 11 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'db1-binary.165919' position 168624875
      2024-07-02 7:45:21 26 [Note] Slave SQL thread exiting, replication stopped in log 'db1-binary.165919' at position 168624875, master: 10.76.24.71:3306
      2024-07-02 7:45:30 390 [Note] Start binlog_dump to slave_server(1), pos(db2-binary.166681, 26398943), using_gtid(0), gtid('')
      2024-07-02 9:11:28 25 [Note] Slave I/O thread exiting, read up to log 'db1-binary.165961', position 130356238, master 10.76.24.71:3306
      2024-07-02 9:11:28 25 [Note] Slave I/O thread exiting, read up to log 'db1-binary.165961', position 130356238, master 10.76.24.71:3306
      2024-07-02 9:11:28 4017 [Note] Slave I/O thread: Start asynchronous replication to master 'gtid@10.76.24.71:3306' in log 'db1-binary.165961' at position 130356238
      2024-07-02 9:11:28 4017 [Note] Slave I/O thread: connected to master 'gtid@10.76.24.71:3306',replication started in log 'db1-binary.165961' at position 130356238
      2024-07-02 9:11:28 4019 [Note] Slave SQL thread initialized, starting replication in log 'db1-binary.165919' at position 168624875, relay log './db2-relay.433779' position: 34241321
      2024-07-02 9:11:28 4019 [Note] 'SQL_SLAVE_SKIP_COUNTER=1' executed at relay_log_file='./db2-relay.433779', relay_log_pos='34241321', master_log_name='db1-binary.165919', master_log_pos='168624875' and new position at relay_log_file='./db2-relay.433779', relay_log_pos='34242106', master_log_name='db1-binary.165919', master_log_pos='168625660'
      2024-07-02 9:11:29 12 [ERROR] mariadbd: Can't find record in 'activesessions'
      2024-07-02 9:11:29 12 [ERROR] Slave SQL: Could not execute Delete_rows_v1 event on table aaadb.activesessions; Can't find record in 'activesessions', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log db1-binary.165919, end_log_pos 172632819, Gtid 0-1-18770875301, Internal MariaDB error code: 1032
      2024-07-02 9:11:29 12 [Warning] Slave: Can't find record in 'activesessions' Error_code: 1032
      2024-07-02 9:11:29 12 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'db1-binary.165919' position 172632065
      2024-07-02 9:11:29 13 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 9:11:29 13 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 9:11:29 13 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'db1-binary.165919' position 172632065
      2024-07-02 9:11:29 15 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 9:11:29 15 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 9:11:29 15 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'db1-binary.165919' position 172632065
      2024-07-02 9:11:29 14 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 9:11:29 14 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 9:11:29 14 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'db1-binary.165919' position 172632065
      2024-07-02 9:11:29 16 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 9:11:29 16 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 9:11:29 16 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'db1-binary.165919' position 172632065
      2024-07-02 9:11:29 17 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 9:11:29 17 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 9:11:29 17 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'db1-binary.165919' position 172632065
      2024-07-02 9:11:29 6 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 9:11:29 6 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
      2024-07-02 9:11:29 6 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'db1-binary.165919' position 172632065
      2024-07-02 9:11:29 7 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964

      Attachments

        Issue Links

          Activity

            Hi ashishcyrus,

            The core dump file is of limited use without your specific environment, please provide the output of the following GDB commands when applied to that core dump in the environment of the crash.

            (gdb) set logging on
            (gdb) set pagination off
            (gdb) thread apply all bt full
            

            And please do not change the priority of this ticket. Again, if you need urgent support, I'd recommend exploring our enterprise customer option.

            bnestere Brandon Nesterenko added a comment - Hi ashishcyrus , The core dump file is of limited use without your specific environment, please provide the output of the following GDB commands when applied to that core dump in the environment of the crash. (gdb) set logging on (gdb) set pagination off (gdb) thread apply all bt full And please do not change the priority of this ticket. Again, if you need urgent support, I'd recommend exploring our enterprise customer option.
            ashishcyrus ashish added a comment - - edited

            Hello

            Output of below is already added in below files .

            (gdb) set logging on
            (gdb) set pagination off
            (gdb) thread apply all bt full

            https://filetransfer.io/data-package/wuz4lH3j#link

            ashishcyrus ashish added a comment - - edited Hello Output of below is already added in below files . (gdb) set logging on (gdb) set pagination off (gdb) thread apply all bt full https://filetransfer.io/data-package/wuz4lH3j#link
            bnestere Brandon Nesterenko added a comment - - edited

            Thanks Ashish. I realize now that this issue isn't about the crash, but that replication won't start up again. The error log shows

            2024-07-02 7:45:21 8 [ERROR] mariadbd: Can't find record in 'activesessions'
            2024-07-02 7:45:21 8 [ERROR] Slave SQL: Could not execute Delete_rows_v1 event on table aaadb.activesessions; Can't find record in 'activesessions', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log db1-binary.165919, end_log_pos 168625629, Gtid 0-1-18770872766, Internal MariaDB error code: 1032
            

            It looks like you've used sql_skip_slave_counter to try and skip the problematic transactions, but it seems there are important prior transactions which never executed. It also seems like you use XA transactions, and there's currently an issue where the slave position can increase without actually executing the underlying transaction in the event of a crash (officially formalized in MDEV-21469, though ongoing work aims to supersede that report). To fix, I would recommend finding the dependent transaction which never executed, and then re-execute it. To do so I'd recommend using mariadb-binlog on the binary log of the primary to examine to find the transaction with GTID 0-1-18770872766, which should include a Delete_rows_v1 event, and then to analyze the failing event's contents to find the prior transaction in which it depends (also likely to be identifiable via the XID, which should be present in the mysqlbinlog output). You should be able to manually apply any missing transactions by piping the mariadb-binlog output into the mariadb client.

            You can learn more about doing that via https://mariadb.com/kb/en/using-mariadb-binlog/

            And note too, you can use the command XA RECOVER to view any XA transactions which are prepared on the slave, and use its output to cross-reference the binlog to see if anything is in the wrong state, given the gtid_slave_pos value of the replica. You can learn more about the command in our knowledgebase here.

            bnestere Brandon Nesterenko added a comment - - edited Thanks Ashish. I realize now that this issue isn't about the crash, but that replication won't start up again. The error log shows 2024-07-02 7:45:21 8 [ERROR] mariadbd: Can't find record in 'activesessions' 2024-07-02 7:45:21 8 [ERROR] Slave SQL: Could not execute Delete_rows_v1 event on table aaadb.activesessions; Can't find record in 'activesessions', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log db1-binary.165919, end_log_pos 168625629, Gtid 0-1-18770872766, Internal MariaDB error code: 1032 It looks like you've used sql_skip_slave_counter to try and skip the problematic transactions, but it seems there are important prior transactions which never executed. It also seems like you use XA transactions, and there's currently an issue where the slave position can increase without actually executing the underlying transaction in the event of a crash (officially formalized in MDEV-21469 , though ongoing work aims to supersede that report). To fix, I would recommend finding the dependent transaction which never executed, and then re-execute it. To do so I'd recommend using mariadb-binlog on the binary log of the primary to examine to find the transaction with GTID 0-1-18770872766, which should include a Delete_rows_v1 event, and then to analyze the failing event's contents to find the prior transaction in which it depends (also likely to be identifiable via the XID, which should be present in the mysqlbinlog output). You should be able to manually apply any missing transactions by piping the mariadb-binlog output into the mariadb client. You can learn more about doing that via https://mariadb.com/kb/en/using-mariadb-binlog/ And note too, you can use the command XA RECOVER to view any XA transactions which are prepared on the slave, and use its output to cross-reference the binlog to see if anything is in the wrong state, given the gtid_slave_pos value of the replica. You can learn more about the command in our knowledgebase here .
            Elkin Andrei Elkin added a comment -

            bnestere, those Innodb log records mentioning XA are about the server's internal 2pc. Innodb is sort of unaware (actually it is able to differentiate, just does not) of the nature of the 2p-commitable transaction.

            Elkin Andrei Elkin added a comment - bnestere , those Innodb log records mentioning XA are about the server's internal 2pc. Innodb is sort of unaware (actually it is able to differentiate, just does not) of the nature of the 2p-commitable transaction.

            Hi ashishcyrus,

            I'd just like to check-in to see if the above feedback worked. Is replication back online for you?

            bnestere Brandon Nesterenko added a comment - Hi ashishcyrus , I'd just like to check-in to see if the above feedback worked. Is replication back online for you?

            People

              bnestere Brandon Nesterenko
              ashishcyrus ashish
              Votes:
              0 Vote for this issue
              Watchers:
              7 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.