The fb1 machine broke down Friday evening. This task is on hold until either the machine is operable again or I find other hardware for this.

Stack trace:

#0 str_to_datetime (str=0xd48a228 "1998-12-01", length=10, l_time=0x4fa5ab3c, flags=25165825, was_cut=0x4fa5a974) at sql-common/my_time.c:175
#1 0x083065e0 in str_to_datetime (cs=0x8cae980, str=0xd48a228 "1998-12-01", length=10, l_time=0x4fa5ab3c, flags=25165825, was_cut=0x4fa5a974) at sql/sql_time.cc:277
#2 0x0830666b in str_to_datetime_with_warn (cs=0x8cae980, str=0xd48a228 "1998-12-01", length=10, l_time=0x4fa5ab3c, flags=25165825) at sql/sql_time.cc:300
#3 0x08416406 in Item::get_date (this=0xd48a238, ltime=0x4fa5ab3c, fuzzydate=25165825) at sql/item.cc:1265
#4 0x084b2f35 in Item_date_add_interval::get_date (this=0xd48b8a0, ltime=0x4fa5ab3c, fuzzy_date=1) at sql/item_timefunc.cc:2042
#5 0x08418ca5 in Item::val_string_from_date (this=0xd48b8a0, str=0xd48d2c8) at sql/item.cc:300
#6 0x084b1b1c in Item_temporal_func::val_str (this=0xd48b8a0, str=0xd48d2c8) at sql/item_timefunc.cc:1469
#7 0x08191ba1 in Item::str_result (this=0xd48b8a0, tmp=0xd48d2c8) at sql/item.h:964
#8 0x08409905 in Item_cache_str::cache_value (this=0xd48d1f8) at sql/item.cc:8969
#9 0x0841a64d in Item_cache::has_value (this=0xd48d1f8) at sql/item.h:3973
#10 0x08402439 in Item_cache_str::val_str (this=0xd48d1f8, str=0x4fa5ac40) at sql/item.cc:9019
#11 0x084163a8 in Item::get_date (this=0xd48d1f8, ltime=0x4fa5ad1c, fuzzydate=33554433) at sql/item.cc:1265
#12 0x0842ef61 in get_datetime_value (thd=0xd4253f8, item_arg=0xd48b9d0, cache_arg=0xd48b9f8, warn_item=0xd48a180, is_null=0x4fa5adc6) at sql/item_cmpfunc.cc:902
#13 0x0843014e in Arg_comparator::compare_datetime (this=0xd48b9cc) at sql/item_cmpfunc.cc:956
#14 0x084337af in Arg_comparator::compare (this=0xd48b9cc) at sql/item_cmpfunc.h:78
#15 0x084261ba in Item_func_le::val_int (this=0xd48b940) at sql/item_cmpfunc.cc:1904
#16 0x08270467 in evaluate_join_record (join=0xd48be58, join_tab=0xd48ceb0, error=0) at sql/sql_select.cc:16372
#17 0x0827da3d in sub_select (join=0xd48be58, join_tab=0xd48ceb0, end_of_records=false) at sql/sql_select.cc:16277
#18 0x08280d9d in do_select (join=0xd48be58, fields=0x0, table=0xd4995f8, procedure=0x0) at sql/sql_select.cc:15947
#19 0x08298245 in JOIN::exec (this=0xd48be58) at sql/sql_select.cc:2405

This seems to be hit for every row we get.

In 5.3, str_to_datetime is called only a few times at query start. Per-record evaluation proceed along this stack trace:

#0 Item_cache_int::val_int (this=0x7ffc700256e8) at item.cc:8301
#1 0x00000000005c852f in get_datetime_value (thd=0x283381e8, item_arg=0x7ffc7000d5b8, cache_arg=0x7ffc7000d600, warn_item=0x7ffc7000d198, is_null=0x7ffff41a832e) at item_cmpfunc.cc:883
#2 0x00000000005c876b in Arg_comparator::compare_datetime (this=0x7ffc7000d5b0) at item_cmpfunc.cc:955
#3 0x00000000005aa58b in Arg_comparator::compare (this=0x7ffc7000d5b0) at item_cmpfunc.h:72
#4 0x00000000005cb4be in Item_func_le::val_int (this=0x7ffc7000d4e8) at item_cmpfunc.cc:1899
#5 0x0000000000726585 in evaluate_join_record (join=0x7ffc7000dc58, join_tab=0x7ffc70024fe8, error=0) at sql_select.cc:15973
#6 0x00000000007262dc in sub_select (join=0x7ffc7000dc58, join_tab=0x7ffc70024fe8, end_of_records=false) at sql_select.cc:15917
#7 0x000000000072591d in do_select (join=0x7ffc7000dc58, fields=0x0, table=0x7ffc7001b510, procedure=0x0) at sql_select.cc:15538
#8 0x000000000070485c in JOIN::exec (this=0x7ffc7000dc58) at sql_select.cc:2316

The difference comes from "constant expression caching" that appeared in
mysql-5.5 and was merged into mariadb-5.5.

mariadb-5.3 already had some caching mechanisms. Check out get_datetime_value(),
the line:

if (cache_arg && item->const_item() && item->type() != Item::CACHE_ITEM)
{
...

Item_cache_temporal cache= new Item_cache_temporal(f_type); (*)

At line (**) the datetime value is cached. This kind of caching is not visible
in EXPLAIN EXTENDED, btw, because cache is created at execution phase.

Enter MariaDB-5.5. It has a general-purpose caching mechanism invoked at the
optimization phase by cache_const_exprs(). The problem is that it caches value
of Item_date_add_interval in a Item_cache_str object. That is, it caches it as
a string.

get_datetime_value() in line will see that it is passed a cache item, and
will not create an Item_cache_temporal object for it.

The outcome is: EXPLAIN EXTENDED shows value cache to be used, but actually
we do a string-to-datetime conversion every time we evaluate the WHERE condition.

Looking at the

Item_cache* Item_cache::get_cache(const Item *item, const Item_result type)

function:

in 5.5, the switch(type) has this variant:

case TIME_RESULT:
return new Item_cache_temporal(item->field_type());

The problem is that Item_date_add_interval->result_type() returns STRING_RESULT.

In mysql-5.6, there is no "case TIME_RESULT" part at all, instead there is:

switch (type) {
case INT_RESULT:
....

case STRING_RESULT:
/* Not all functions that return DATE/TIME are actually DATE/TIME funcs. */
if (item->is_temporal())
return new Item_cache_datetime(item->field_type());
return new Item_cache_str(item);
...

The slowdown caused by conversion is filed as MDEV-4265.

Hi Axel,

MDEV-4265 was fixed by Sergei and pushed into 5.5 today. Could you benchmark the latest 5.5 against MySQL 5.5?

(it would be best to benchmark on the same hardware/settings that you did Q1-on-myisam benchmarks on, so that we could compare all results).

Closing as MDEV-4309 has been closed