[MDEV-13424] InnoDB: Assertion failure in file row0mysql.cc line 691 Created: 2017-08-02  Updated: 2020-08-07  Resolved: 2020-08-07

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB, Storage Engine - XtraDB
Affects Version/s: None
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Jan Lindström (Inactive) Assignee: Thirunarayanan Balathandayuthapani
Resolution: Cannot Reproduce Votes: 2
Labels: None

Attachments: Zip Archive ARM_stack+log.zip     Zip Archive Intel_stack+log.zip     Zip Archive reproduce.zip    

 Comments   
Comment by Jan Lindström (Inactive) [ 2017-08-08 ]

Error code 20 seen on row_mysql_handle_errors function is DB_MISSING_HISTORY i.e. required history data has been deleted due to lack of space in rollback segment. This path of the code is not changed between 10.0 and 10.1. After successful restart there is again buffer overflow message.
That error code is produced in following files:

handler/ha_innodb.cc:	case DB_MISSING_HISTORY:
handler/ha_innodb.cc:		DBUG_RETURN(convert_error_code_to_mysql(DB_MISSING_HISTORY,
handler/handler0alter.cc:	case DB_MISSING_HISTORY:
include/db0err.h:	DB_MISSING_HISTORY,		/*!< required history data has been
include/row0vers.h:@return	DB_SUCCESS or DB_MISSING_HISTORY */
grep: mysql-test/storage_engine: Is a directory
row/row0log.cc:						DB_MISSING_HISTORY or
row/row0log.cc:					*error = DB_MISSING_HISTORY;
row/row0log.cc:	case DB_MISSING_HISTORY:
row/row0log.cc:	case DB_MISSING_HISTORY:
row/row0log.cc:			ut_ad(error == DB_MISSING_HISTORY);
row/row0log.cc:				ut_ad(error == DB_MISSING_HISTORY);
row/row0log.cc:		ut_ad(error == DB_MISSING_HISTORY);
row/row0sel.cc:		return(DB_MISSING_HISTORY);
row/row0vers.cc:@return	DB_SUCCESS or DB_MISSING_HISTORY */
row/row0vers.cc:			? DB_SUCCESS : DB_MISSING_HISTORY;
grep: ut/crc32_power8: Is a directory
ut/ut0ut.cc:	case DB_MISSING_HISTORY:

But any of these cases have not really changed between 10.0 and 10.1.

Comment by Jan Lindström (Inactive) [ 2017-08-10 ]

Selecting a row i.e. row0sel.cc could return this error message if !prebuilt->index_usable, do not see any reason to crash, I will add error handling for this case and add some error diagnostics if row version is not found for some reason.

Comment by Jan Lindström (Inactive) [ 2017-08-11 ]

https://github.com/MariaDB/server/commit/7a4281d1b1b30c1ea76ec557a4a7f0c2e8d64e82

Comment by Marko Mäkelä [ 2017-08-11 ]

Like I wrote on GitHub, I think that we must first repeat the problem. The submitted patch may be useful in that, but it must not be pushed to the main branches in its current form.

Does the problem repeat with both InnoDB and XtraDB?

I believe that prebuilt->index_usable should always hold in row_mysql_handle_errors(), because that flag is being checked before we enter any low-level operations.

The error DB_MISSING_HISTORY should never be returned from the low-level operations. The only low-level operation that can return it is row_vers_build_for_consistent_read() when trx_undo_prev_version_build() fails. And the only failure path is this one:

	if (trx_undo_get_undo_rec(roll_ptr, rec_trx_id, &undo_rec, heap)) {
		/* The undo record may already have been purged,
		during purge or semi-consistent read. */
		return(false);
	}

It maps to this one:

	missing_history = read_view_sees_trx_id(purge_sys->view, trx_id);

I am afraid that the problem could be that the purge view is advancing prematurely. This is a very serious problem. The read view of the oldest active transaction should always be protected from purge.

If this is an XtraDB specific problem, could it be that XtraDB is violating this purge constraint? After all, XtraDB introduced parameters like innodb_kill_idle_transaction.

Comment by Axel Schwenke [ 2018-02-01 ]

I've hit the same error while benchmarking commit bc7a1dc1fbd27e6064d3b40443fe242397668af7

Error log:

2018-01-31 22:31:22 264 [ERROR] [FATAL] InnoDB: Unknown error code 20: Required history data has been deleted
180131 22:31:22 [ERROR] mysqld got signal 6 ;
...
Query (0x7ef8380114f0): SELECT SUM(K) FROM sbtest10 WHERE id BETWEEN 1 AND 1+99

Stack trace:

Thread 1 (Thread 0x7ef8f0267700 (LWP 23919)):                                                                 
#0  0x00007efd3272c611 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linu
x/pthread_kill.c:61                                                                                           
#1  0x0000559efd82d1e2 in handle_fatal_signal (sig=6) at /home/axel/versioned/MariaDB-Server/sql/signal_handle
r.cc:305                                                                                                      
#2  <signal handler called>                                                                                   
#3  0x00007efd31b6cc37 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56          
#4  0x00007efd31b70028 in __GI_abort () at abort.c:89                                                         
#5  0x0000559efdb2e233 in ib::fatal::~fatal (this=0x7ef8f0262b80, __in_chrg=<optimized out>) at /home/axel/ver
sioned/MariaDB-Server/storage/innobase/ut/ut0ut.cc:792                                                        
#6  0x0000559efda9a71c in row_mysql_handle_errors (new_err=new_err@entry=0x7ef8f0262e00, trx=trx@entry=0x7efd3
0e3bc18, thr=thr@entry=0x7ef8680b2f80, savept=savept@entry=0x0) at /home/axel/versioned/MariaDB-Server/storage
/innobase/row/row0mysql.cc:831                                                                                
#7  0x0000559efdab8b74 in row_search_mvcc (buf=buf@entry=0x7ef8680b1ff0 "2_", mode=PAGE_CUR_GE, mode@entry=PAG
E_CUR_UNSUPP, prebuilt=0x7ef8680b2820, match_mode=match_mode@entry=0, direction=direction@entry=1) at /home/ax
el/versioned/MariaDB-Server/storage/innobase/row/row0sel.cc:5587                                              
#8  0x0000559efd9dbc28 in ha_innobase::general_fetch (this=0x7ef8680b1860, buf=0x7ef8680b1ff0 "2_", direction=
1, match_mode=0) at /home/axel/versioned/MariaDB-Server/storage/innobase/handler/ha_innodb.cc:9861            
#9  0x0000559efd832f4f in handler::ha_index_next (this=this@entry=0x7ef8680b1860, buf=0x7ef8680b1ff0 "2_") at 
/home/axel/versioned/MariaDB-Server/sql/handler.cc:2857                                                       
#10 0x0000559efd837260 in handler::read_range_next (this=0x7ef8680b1860) at /home/axel/versioned/MariaDB-Serve
r/sql/handler.cc:5596
...

Full stack trace attached.

Comment by Axel Schwenke [ 2018-02-01 ]

How to reproduce:

$mysqladmin -u root -S /tmp/mysqld.sock.sysbench create sbtest
$sysbench-mariadb --test=oltp.lua --oltp_tables_count=1 --oltp-table-size=1000 --mysql-user=root --mysql-socket=/tmp/mysqld.sock.sysbench prepare
$sysbench-mariadb --test=oltp.lua --oltp_tables_count=1 --oltp-table-size=1000 --mysql-user=root --mysql-socket=/tmp/mysqld.sock.sysbench --num-threads=10 --oltp-read-only=off --report-interval=2 --max-time=0 --max-requests=0 run

The last line runs forever, it stops producing results after ~30 seconds. Then mysqld is crashed.

sysbench-mariadb is https://github.com/hgxl64/sysbench-mariadb

my.cnf and Lua scripts are attached.

Comment by Axel Schwenke [ 2018-02-02 ]

the 10.3 branch is good up to (including) commit c0d5d7c

Comment by Jan Lindström (Inactive) [ 2018-02-05 ]

marko I assigned this to you as you know this part of the code better than me.

Comment by Sergey Vojtovich [ 2018-02-14 ]

10.3 regression is to be fixed within the scope of MDEV-15246, which was in review as of this writing.

Comment by Marko Mäkelä [ 2018-03-14 ]

jplindst, I am reassigning this back to you until we have a reproducible test case for the originally reported bug.

There was a bug that was introduced by MDEV-15104 and fixed by MDEV-15246 during the development of MariaDB 10.3.5. That one repeated relatively easily.

Comment by Thirunarayanan Balathandayuthapani [ 2020-08-07 ]

I think this issue could have fixed by MDEV-15246

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