[MDEV-4791] Assertion range_end >= range_start fails in log0online.c on select from I_S.INNODB_CHANGED_PAGES Created: 2013-07-17  Updated: 2014-08-21  Resolved: 2014-08-13

Status: Closed
Project: MariaDB Server
Component/s: None
Affects Version/s: 5.5.32, 10.0.10
Fix Version/s: 5.5.38, 10.0.11

Type: Bug Priority: Minor
Reporter: Elena Stepanova Assignee: Jan Lindström (Inactive)
Resolution: Fixed Votes: 0
Labels: upstream, xtradb

Attachments: File psergey-mdev4791-fix1.diff    
Issue Links:
Blocks
is blocked by MDEV-4909 5.5.33 merge Closed
Relates
relates to MDEV-6620 Assertion range_end >= range_start fa... Closed

 Description   

Introduced with the latest XtraDB merge. Reproducible on the current percona-server-5.5.

Version: '5.5.32-MariaDB-debug-log' 
130717 19:09:03  InnoDB: Assertion failure in thread 139704798648064 in file log0online.c line 1284
InnoDB: Failing assertion: range_end >= range_start

Test case:

# If using MTR, run with --mysqld=--innodb --mysqld=--innodb_changed_pages
 
SELECT * FROM INFORMATION_SCHEMA.INNODB_CHANGED_PAGES WHERE start_lsn < 10 AND end_lsn > 20 ;

#3  <signal handler called>
#4  0x00007f0f94b39425 in __GI_raise (sig=<optimized out>) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#5  0x00007f0f94b3cb8b in __GI_abort () at abort.c:91
#6  0x0000000000af149f in log_online_setup_bitmap_file_range (bitmap_files=0x7f0f8ee56f68, range_start=20, range_end=10) at storage/xtradb/log/log0online.c:1284
#7  0x0000000000af1ec3 in log_online_bitmap_iterator_init (i=0x7f0f8ee56f60, min_lsn=20, max_lsn=10) at storage/xtradb/log/log0online.c:1566
#8  0x0000000000995499 in i_s_innodb_changed_pages_fill (thd=0x402ced0, tables=0x7f0f64007778, cond=0x7f0f64019650) at storage/xtradb/handler/i_s.cc:7354
#9  0x000000000069c631 in do_fill_table (thd=0x402ced0, table_list=0x7f0f64007778, join_table=0x7f0f64019030) at sql/sql_show.cc:7712
#10 0x000000000069ca43 in get_schema_tables_result (join=0x7f0f64008ac0, executed_place=PROCESSED_BY_JOIN_EXEC) at sql/sql_show.cc:7819
#11 0x00000000006464af in JOIN::exec (this=0x7f0f64008ac0) at sql/sql_select.cc:2321
#12 0x0000000000648e87 in mysql_select (thd=0x402ced0, rref_pointer_array=0x4030b28, tables=0x7f0f64007778, wild_num=1, fields=..., conds=0x7f0f64008388, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2684619520, result=0x7f0f64008aa0, unit=0x40301e8, select_lex=0x40308c0) at sql/sql_select.cc:3054
#13 0x000000000063fa3e in handle_select (thd=0x402ced0, lex=0x4030138, result=0x7f0f64008aa0, setup_tables_done_option=0) at sql/sql_select.cc:318
#14 0x0000000000618750 in execute_sqlcom_select (thd=0x402ced0, all_tables=0x7f0f64007778) at sql/sql_parse.cc:4651
#15 0x000000000061119f in mysql_execute_command (thd=0x402ced0) at sql/sql_parse.cc:2205
#16 0x000000000061aff0 in mysql_parse (thd=0x402ced0, rawbuf=0x7f0f640074c8 "SELECT * FROM INFORMATION_SCHEMA.INNODB_CHANGED_PAGES WHERE start_lsn < 10 AND end_lsn > 20", length=91, parser_state=0x7f0f8ee58500) at sql/sql_parse.cc:5769
#17 0x000000000060e669 in dispatch_command (command=COM_QUERY, thd=0x402ced0, packet=0x409e361 "SELECT * FROM INFORMATION_SCHEMA.INNODB_CHANGED_PAGES WHERE start_lsn < 10 AND end_lsn > 20 ", packet_length=92) at sql/sql_parse.cc:1071
#18 0x000000000060d879 in do_command (thd=0x402ced0) at sql/sql_parse.cc:794
#19 0x00000000007146b5 in do_handle_one_connection (thd_arg=0x402ced0) at sql/sql_connect.cc:1266
#20 0x000000000071409c in handle_one_connection (arg=0x402ced0) at sql/sql_connect.cc:1181
#21 0x000000000095fe44 in pfs_spawn_thread (arg=0x40365f0) at storage/perfschema/pfs.cc:1015
#22 0x00007f0f95902e9a in start_thread (arg=0x7f0f8ee59700) at pthread_create.c:308
#23 0x00007f0f94bf6cbd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112

bzr version-info

revision-id: sergii@pisem.net-20130716173039-j2k1nrkd0gmdmsd9
revno: 3836
branch-nick: 5.5



 Comments   
Comment by Sergei Petrunia [ 2014-05-08 ]

A patch that fixes this (without the testcase)

Comment by Jan Lindström (Inactive) [ 2014-05-09 ]

For 5.5:

revno: 4188
committer: Jan Lindström <jplindst@mariadb.org>
branch nick: 5.5
timestamp: Fri 2014-05-09 11:03:39 +0300
message:
MDEV-4791: Assertion range_end >= range_start fails in log0online.c
on select from I_S.INNODB_CHANGED_PAGES

Analysis: limit_lsn_range_from_condition() incorrectly parses
start_lsn and/or end_lsn conditions.

Fix from SergeyP. Added some test cases.

Comment by Jan Lindström (Inactive) [ 2014-05-09 ]

10.0:

revno: 4207
committer: Jan Lindström <jplindst@mariadb.org>
branch nick: 10.0
timestamp: Fri 2014-05-09 11:43:53 +0300
message:
MDEV-4791: Assertion range_end >= range_start fails in log0online.c
on select from I_S.INNODB_CHANGED_PAGES

Analysis: limit_lsn_range_from_condition() incorrectly parses
start_lsn and/or end_lsn conditions.

Fix from SergeyP. Added some test cases.

Comment by Jan Lindström (Inactive) [ 2014-05-09 ]

Send fix candidates to Percona.

Comment by Laurynas Biveinis [ 2014-06-10 ]

Jan, Sergei - thank your for the patch. I am working on it now and have a few questions/comments on https://launchpadlibrarian.net/175006985/patch_55.diff.

  • ICP changed its logic to only use one of start_lsn, end_lsn for lower and upper bound limitation. Have you seen the comments in the middle of i_s_innodb_changed_pages_fill and the header comment of limit_lsn_range_from_condition on why we use both for limiting the range? Is our algorithm wrong?
  • Assuming for a moment that our previous range limitation algorithm is correct, then simply checking whether the boundaries of the resulting range have not crossed passes your testcase:

=== modified file 'storage/innobase/log/log0online.c'
--- storage/innobase/log/log0online.c	2014-02-14 07:44:36 +0000
+++ storage/innobase/log/log0online.c	2014-06-10 11:36:35 +0000
@@ -1590,6 +1590,17 @@
 {
 	ut_a(i);
 
+	if (UNIV_UNLIKELY(min_lsn > max_lsn)) {
+
+		/* Empty range */
+		i->in_files.count = 0;
+		i->in_files.files = NULL;
+		i->in.file = os_file_invalid;
+		i->page = NULL;
+		i->failed = FALSE;
+		return TRUE;
+	}
+
 	if (!log_online_setup_bitmap_file_range(&i->in_files, min_lsn,
 		max_lsn)) {

  • There is some overlap between your testcase innodb-changed-pages and our percona_changed_pages. I will merge the former to the latter while removing duplicates (so that you merge next XtraDB correctly).

Thanks again

Comment by Sergei Petrunia [ 2014-06-19 ]

Hi Laurynas,

ICP changed its logic to only use one of start_lsn, end_lsn for lower and upper bound limitation. Have you seen the comments in the middle of i_s_innodb_changed_pages_fill and the header comment of limit_lsn_range_from_condition on why we use both for limiting the range? Is our algorithm wrong?

Apparently, not. When I was coding my fix, I didn't make any assumptions about the order the records will come in (or even that end_lsn > start_lsn for any given record).

Having studied http://www.slideshare.net/kastauyra/bitmap-33283809 and also how i_s_innodb_changed_pages_fill() uses the upper/lower bound, I will agree that it turns out it's acceptable in this case to use "start_lsn < X" to get upper bound and use "end_lsn>Y" to generate lower bound.

Assuming for a moment that our previous range limitation algorithm is correct, then simply checking whether the boundaries of the resulting range have not crossed passes your testcase:

Agree. This is the best solution, then I guess, you will use this above patch? We should switch to it also, then.

Comment by Laurynas Biveinis [ 2014-06-21 ]

Sergei -

Yes, I am going to use the above patch unless something else comes up during testing. I will let you know.

Comment by Laurynas Biveinis [ 2014-07-16 ]

The above fix has been merged to our 5.5 and 5.6. Your testcase innodb-changed-pages was folded into percona_changed_pages.

Comment by Sergei Petrunia [ 2014-08-02 ]

Laurynas, thanks for the info!

Comment by Jan Lindström (Inactive) [ 2014-08-13 ]

Will be fixed on XtraDB merge.

Generated at Thu Feb 08 06:59:11 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.