Details
-
Bug
-
Status: Closed (View Workflow)
-
Critical
-
Resolution: Fixed
-
N/A
-
None
Description
CREATE OR REPLACE TABLE t (f VARCHAR(8)); |
INSERT INTO t VALUES ('a'),(''),('b'); |
SET histogram_type=JSON_HB; |
ANALYZE TABLE t PERSISTENT FOR ALL; |
|
|
# Cleanup
|
DROP TABLE t; |
The server hangs upon ANALYZE, or rather falls into a loop with 100% CPU and 3G+ memory consumption somewhere here:
|
preview-10.7-MDEV-26519-json-histograms 656dff975 |
Thread 9 (Thread 0x7f61088ef700 (LWP 62824)):
|
#0 0x0000558913514881 in json_escape (str_cs=0x558914a79a40 <my_charset_utf8mb4_bin>, str=0x7f608412a6da "a", str_end=0x7f608412a6da "a", json_cs=0x558914a79a40 <my_charset_utf8mb4_bin>, json=0x7f5fbefff098 "", json_end=0x7f607ffff090 "h4z\025") at /data/src/preview-10.7-MDEV-26519-json-histograms/strings/json_lib.c:1618
|
#1 0x0000558912199e24 in json_escape_to_string (val=0x7f608412a6da "a", val_len=0, out=0x7f61088ecd10) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/opt_histogram_json.cc:72
|
#2 0x000055891219d92f in Histogram_json_builder::append_column_value (this=0x7f60840aa120, elem=0x7f60840618a0) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/opt_histogram_json.cc:203
|
#3 0x000055891219d776 in Histogram_json_builder::start_bucket (this=0x7f60840aa120, elem=0x7f60840618a0, cnt=1) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/opt_histogram_json.cc:182
|
#4 0x000055891219dce9 in Histogram_json_builder::next (this=0x7f60840aa120, elem=0x7f60840618a0, elem_cnt=1) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/opt_histogram_json.cc:261
|
#5 0x0000558911f4a56c in histogram_build_walk (elem=0x7f60840618a0, elem_cnt=1, arg=0x7f60840aa120) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_statistics.cc:1672
|
#6 0x000055891345fd78 in tree_walk_left_root_right (tree=0x7f6084015ca8, element=0x7f6084061888, action=0x558911f4a51d <histogram_build_walk(void*, element_count, void*)>, argument=0x7f60840aa120) at /data/src/preview-10.7-MDEV-26519-json-histograms/mysys/tree.c:590
|
#7 0x000055891345fcef in tree_walk_left_root_right (tree=0x7f6084015ca8, element=0x7f6084061860, action=0x558911f4a51d <histogram_build_walk(void*, element_count, void*)>, argument=0x7f60840aa120) at /data/src/preview-10.7-MDEV-26519-json-histograms/mysys/tree.c:588
|
#8 0x000055891345fc28 in tree_walk (tree=0x7f6084015ca8, action=0x558911f4a51d <histogram_build_walk(void*, element_count, void*)>, argument=0x7f60840aa120, visit=left_root_right) at /data/src/preview-10.7-MDEV-26519-json-histograms/mysys/tree.c:576
|
#9 0x000055891206e6b0 in Unique::walk (this=0x7f6084015b00, table=0x7f60841ae108, action=0x558911f4a51d <histogram_build_walk(void*, element_count, void*)>, walk_action_arg=0x7f60840aa120) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/uniques.cc:654
|
#10 0x0000558911f5a3d0 in Count_distinct_field::walk_tree_with_histogram (this=0x7f6084015ad0, rows=3) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_statistics.cc:1780
|
#11 0x0000558911f5b823 in Column_statistics_collected::finish (this=0x7f608412a848, mem_root=0x7f60841ae3a0, rows=3, sample_fraction=1) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_statistics.cc:2500
|
#12 0x0000558911f4c7fa in collect_statistics_for_table (thd=0x7f6084000db8, table=0x7f60841ae108) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_statistics.cc:2803
|
#13 0x000055891210da64 in mysql_admin_table (thd=0x7f6084000db8, tables=0x7f6084015130, check_opt=0x7f60840063a8, operator_name=0x558913f0a4a0 <msg_analyze>, lock_type=TL_READ_NO_INSERT, org_open_for_modify=true, repair_table_use_frm=false, extra_open_options=0, prepare_func=0x0, operator_func=(int (handler::*)(class handler * const, class THD *, HA_CHECK_OPT *)) 0x55891248cb82 <handler::ha_analyze(THD*, st_ha_check_opt*)>, view_operator_func=0x0, is_cmd_replicated=true) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_admin.cc:1042
|
#14 0x000055891211166d in Sql_cmd_analyze_table::execute (this=0x7f6084015818, thd=0x7f6084000db8) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_admin.cc:1517
|
#15 0x0000558911d93fb7 in mysql_execute_command (thd=0x7f6084000db8, is_called_from_prepared_stmt=false) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_parse.cc:5989
|
#16 0x0000558911d9fe25 in mysql_parse (thd=0x7f6084000db8, rawbuf=0x7f6084015050 "ANALYZE TABLE t PERSISTENT FOR ALL", length=34, parser_state=0x7f61088ee480) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_parse.cc:8029
|
#17 0x0000558911d760ed in dispatch_command (command=COM_QUERY, thd=0x7f6084000db8, packet=0x7f608412dfc9 "", packet_length=34, blocking=true) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_parse.cc:1894
|
#18 0x0000558911d73183 in do_command (thd=0x7f6084000db8, blocking=true) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_parse.cc:1402
|
#19 0x00005589120dc1c1 in do_handle_one_connection (connect=0x558917cd3998, put_in_cache=true) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_connect.cc:1418
|
#20 0x00005589120db989 in handle_one_connection (arg=0x558917cd22c8) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_connect.cc:1312
|
#21 0x00005589129bf779 in pfs_spawn_thread (arg=0x558917cd34e8) at /data/src/preview-10.7-MDEV-26519-json-histograms/storage/perfschema/pfs.cc:2201
|
#22 0x00007f611319f609 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#23 0x00007f6112d72293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
Probably caused by MDEV-26711 patch, although I didn't check.
Attachments
Issue Links
- is caused by
-
MDEV-21130 Histograms: use JSON as on-disk format
-
- Closed
-
-
-
- Closed
-
- relates to
-
-
- Closed
-
Activity
The patch https://github.com/MariaDB/server/commit/c84cac5934c36fac701cb388d587ec3ab60a6a10 fixes the above.
There are still cases when ANALYZE hangs in a similar way, but so far those which I looked at involved previous corruption, e.g. as an aftermath of MDEV-26748 .
Ok, now, with commit
commit e476577ffd2758cd972189384fe40c12cf3217f3 (HEAD -> preview-10.7-MDEV-26519-json-histograms, origin/preview-10.7-MDEV-26519-json-histograms, tmp)
|
Author: Sergei Petrunia <psergey@askmonty.org>
|
Date: Sun Oct 10 11:51:04 2021 +0300
|
|
|
MDEV-26724 Endless loop in json_escape_to_string upon ... empty string
|
|
Part#3:
|
- make json_escape() return different errors on conversion error
|
and on out-of-space condition.
|
- Make histogram code handle conversion errors.
|
There should not be any cases of endless loops.
In the current code, Histograms are simply not collected if histogram collection code encounters unassigned characters. Handling for unassigned (non-Unicode) characters is covered by MDEV-26764.
The patch https://github.com/MariaDB/server/commit/efa79c9082062c3f032f7f3ec12dc0a7a0ed3939 fixes most cases (the normal ones), but not all of them.
# Cleanupstill hangs/loops with 3G/100% CPU consumption somewhere in
preview-10.7-MDEV-26519-json-histograms da8bb4b4703
Thread 6 (Thread 0x7f44f2aff700 (LWP 1258859)):#0 Binary_string::alloced_length (this=0x7f44f2afcd58) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_string.h:431#1 0x000055f789dbfe9a in json_escape_to_string (val=0x7f44e01f75d9 "Ñ¥\245\245\245\245\245\375Ñ¥\245\245\245\245\245\370u\037\340D\177", val_len=1, out=0x7f44f2afcd50) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/opt_histogram_json.cc:84#2 0x000055f789dc392f in Histogram_json_builder::append_column_value (this=0x7f44e02149e0, elem=0x7f44e0236b48) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/opt_histogram_json.cc:203#3 0x000055f789dc3776 in Histogram_json_builder::start_bucket (this=0x7f44e02149e0, elem=0x7f44e0236b48, cnt=1) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/opt_histogram_json.cc:182#4 0x000055f789dc3ce9 in Histogram_json_builder::next (this=0x7f44e02149e0, elem=0x7f44e0236b48, elem_cnt=1) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/opt_histogram_json.cc:261#5 0x000055f789b7056c in histogram_build_walk (elem=0x7f44e0236b48, elem_cnt=1, arg=0x7f44e02149e0) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_statistics.cc:1672#6 0x000055f78b085d82 in tree_walk_left_root_right (tree=0x7f44e0015f08, element=0x7f44e0236b30, action=0x55f789b7051d <histogram_build_walk(void*, element_count, void*)>, argument=0x7f44e02149e0) at /data/src/preview-10.7-MDEV-26519-json-histograms/mysys/tree.c:590#7 0x000055f78b085c32 in tree_walk (tree=0x7f44e0015f08, action=0x55f789b7051d <histogram_build_walk(void*, element_count, void*)>, argument=0x7f44e02149e0, visit=left_root_right) at /data/src/preview-10.7-MDEV-26519-json-histograms/mysys/tree.c:576#8 0x000055f789c946b0 in Unique::walk (this=0x7f44e0015d60, table=0x7f44e0043248, action=0x55f789b7051d <histogram_build_walk(void*, element_count, void*)>, walk_action_arg=0x7f44e02149e0) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/uniques.cc:654#9 0x000055f789b803d0 in Count_distinct_field::walk_tree_with_histogram (this=0x7f44e0015d30, rows=1) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_statistics.cc:1780#10 0x000055f789b81823 in Column_statistics_collected::finish (this=0x7f44e01f7738, mem_root=0x7f44e00434e0, rows=1, sample_fraction=1) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_statistics.cc:2500#11 0x000055f789b727fa in collect_statistics_for_table (thd=0x7f44e0000db8, table=0x7f44e0043248) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_statistics.cc:2803#12 0x000055f789d33a64 in mysql_admin_table (thd=0x7f44e0000db8, tables=0x7f44e0015370, check_opt=0x7f44e00063a8, operator_name=0x55f78bb304a0 <msg_analyze>, lock_type=TL_READ_NO_INSERT, org_open_for_modify=true, repair_table_use_frm=false, extra_open_options=0, prepare_func=0x0, operator_func=(int (handler::*)(class handler * const, class THD *, HA_CHECK_OPT *)) 0x55f78a0b2b82 <handler::ha_analyze(THD*, st_ha_check_opt*)>, view_operator_func=0x0, is_cmd_replicated=true) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_admin.cc:1042#13 0x000055f789d3766d in Sql_cmd_analyze_table::execute (this=0x7f44e0015a58, thd=0x7f44e0000db8) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_admin.cc:1517#14 0x000055f7899b9fb7 in mysql_execute_command (thd=0x7f44e0000db8, is_called_from_prepared_stmt=false) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_parse.cc:5989#15 0x000055f7899c5e25 in mysql_parse (thd=0x7f44e0000db8, rawbuf=0x7f44e0015290 "ANALYZE TABLE t PERSISTENT FOR ALL", length=34, parser_state=0x7f44f2afe480) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_parse.cc:8029#16 0x000055f78999c0ed in dispatch_command (command=COM_QUERY, thd=0x7f44e0000db8, packet=0x7f44e000b849 "", packet_length=34, blocking=true) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_parse.cc:1894#17 0x000055f789999183 in do_command (thd=0x7f44e0000db8, blocking=true) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_parse.cc:1402#18 0x000055f789d021c1 in do_handle_one_connection (connect=0x55f78df50728, put_in_cache=true) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_connect.cc:1418#19 0x000055f789d01989 in handle_one_connection (arg=0x55f78df4f058) at /data/src/preview-10.7-MDEV-26519-json-histograms/sql/sql_connect.cc:1312#20 0x000055f78a5e5783 in pfs_spawn_thread (arg=0x55f78df50278) at /data/src/preview-10.7-MDEV-26519-json-histograms/storage/perfschema/pfs.cc:2201#21 0x00007f44f87a2609 in start_thread (arg=<optimized out>) at pthread_create.c:477#22 0x00007f44f8375293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95For future reference, while this is a corner case, it is not as artificial as it looks at the first glance. I converted it into a direct binary insert without complications in a hope to simplify analysis, but it was derived from something like this:
Query OK, 1 row affected, 1 warning (0.004 sec)So, it is INSERT of a fairly normal value, but with a wrong charset, that truncates it in the middle.