Skip to content

Commit 573d3ad

Browse files
bsrikanth-mariadbbsrikanth-mariadb
committed
MDEV-33309: for update|delete analyze format=json doesn't show r_other_time_ms
Single-table UPDATE/DELETEs only show r_total_time_ms in top-level query block. Replace it with r_table_time_ms and r_other_time_ms.
1 parent cd36925 commit 573d3ad

9 files changed

+159
-13
lines changed

‎mysql-test/main/analyze_engine_stats.result‎

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -68,7 +68,8 @@ X
6868
"rows": 10000,
6969
"r_rows": 10000,
7070
"r_filtered": 100,
71-
"r_total_time_ms": "REPLACED",
71+
"r_table_time_ms": "REPLACED",
72+
"r_other_time_ms": "REPLACED",
7273
"r_engine_stats": {
7374
"pages_accessed": "REPLACED",
7475
"pages_updated": "REPLACED"
@@ -101,7 +102,8 @@ X
101102
"rows": 10000,
102103
"r_rows": 10000,
103104
"r_filtered": 50,
104-
"r_total_time_ms": "REPLACED",
105+
"r_table_time_ms": "REPLACED",
106+
"r_other_time_ms": "REPLACED",
105107
"r_engine_stats": {
106108
"pages_accessed": "REPLACED",
107109
"pages_updated": "REPLACED"

‎mysql-test/main/analyze_format_json.result‎

Lines changed: 116 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -388,7 +388,8 @@ ANALYZE
388388
"rows": 1000,
389389
"r_rows": 1000,
390390
"r_filtered": 100,
391-
"r_total_time_ms": "REPLACED",
391+
"r_table_time_ms": "REPLACED",
392+
"r_other_time_ms": "REPLACED",
392393
"r_engine_stats": REPLACED
393394
}
394395
}
@@ -449,7 +450,8 @@ ANALYZE
449450
"rows": 10,
450451
"r_rows": 10,
451452
"r_filtered": 50,
452-
"r_total_time_ms": "REPLACED",
453+
"r_table_time_ms": "REPLACED",
454+
"r_other_time_ms": "REPLACED",
453455
"r_engine_stats": REPLACED,
454456
"attached_condition": "t1.pk < 10 and t1.b > 4"
455457
}
@@ -1205,3 +1207,115 @@ ANALYZE
12051207
}
12061208
set join_cache_level=@tmp;
12071209
drop table t10, t11;
1210+
#
1211+
# MDEV-33309: ANALYZE FORMAT=JSON: UPDATE|DELETE don't show r_other_time_ms
1212+
#
1213+
create table t1 (pk int primary key, a int);
1214+
insert into t1 select seq, seq from seq_1_to_1000;
1215+
create table t2 like t1;
1216+
insert into t2 select * from t1;
1217+
# Top-level query block must have r_table_time_ms and r_other_time_ms
1218+
analyze format=json
1219+
update t1 set a=a+1
1220+
where t1.pk > (select max(a) from t2 where t2.pk+1 = t1.pk+1 ) - 10;
1221+
ANALYZE
1222+
{
1223+
"query_optimization": {
1224+
"r_total_time_ms": "REPLACED"
1225+
},
1226+
"query_block": {
1227+
"select_id": 1,
1228+
"r_total_time_ms": "REPLACED",
1229+
"table": {
1230+
"update": 1,
1231+
"table_name": "t1",
1232+
"access_type": "ALL",
1233+
"rows": 1000,
1234+
"r_rows": 1000,
1235+
"r_filtered": 100,
1236+
"r_table_time_ms": "REPLACED",
1237+
"r_other_time_ms": "REPLACED",
1238+
"r_engine_stats": REPLACED,
1239+
"attached_condition": "t1.pk > (subquery#2) - 10"
1240+
},
1241+
"subqueries": [
1242+
{
1243+
"query_block": {
1244+
"select_id": 2,
1245+
"r_loops": 1000,
1246+
"r_total_time_ms": "REPLACED",
1247+
"nested_loop": [
1248+
{
1249+
"table": {
1250+
"table_name": "t2",
1251+
"access_type": "ALL",
1252+
"r_loops": 1000,
1253+
"rows": 1000,
1254+
"r_rows": 1000,
1255+
"r_table_time_ms": "REPLACED",
1256+
"r_other_time_ms": "REPLACED",
1257+
"r_engine_stats": REPLACED,
1258+
"filtered": 100,
1259+
"r_filtered": 0.1,
1260+
"attached_condition": "t2.pk + 1 = t1.pk + 1"
1261+
}
1262+
}
1263+
]
1264+
}
1265+
}
1266+
]
1267+
}
1268+
}
1269+
# Top-level query block must have r_table_time_ms and r_other_time_ms
1270+
analyze format=json
1271+
delete from t1
1272+
where t1.pk > (select max(a) from t2 where t2.pk+1 = t1.pk+1 ) - 10;
1273+
ANALYZE
1274+
{
1275+
"query_optimization": {
1276+
"r_total_time_ms": "REPLACED"
1277+
},
1278+
"query_block": {
1279+
"select_id": 1,
1280+
"r_total_time_ms": "REPLACED",
1281+
"table": {
1282+
"delete": 1,
1283+
"table_name": "t1",
1284+
"access_type": "ALL",
1285+
"rows": 1000,
1286+
"r_rows": 1000,
1287+
"r_filtered": 100,
1288+
"r_table_time_ms": "REPLACED",
1289+
"r_other_time_ms": "REPLACED",
1290+
"r_engine_stats": REPLACED,
1291+
"attached_condition": "t1.pk > (subquery#2) - 10"
1292+
},
1293+
"subqueries": [
1294+
{
1295+
"query_block": {
1296+
"select_id": 2,
1297+
"r_loops": 1000,
1298+
"r_total_time_ms": "REPLACED",
1299+
"nested_loop": [
1300+
{
1301+
"table": {
1302+
"table_name": "t2",
1303+
"access_type": "ALL",
1304+
"r_loops": 1000,
1305+
"rows": 1000,
1306+
"r_rows": 1000,
1307+
"r_table_time_ms": "REPLACED",
1308+
"r_other_time_ms": "REPLACED",
1309+
"r_engine_stats": REPLACED,
1310+
"filtered": 100,
1311+
"r_filtered": 0.1,
1312+
"attached_condition": "t2.pk + 1 = t1.pk + 1"
1313+
}
1314+
}
1315+
]
1316+
}
1317+
}
1318+
]
1319+
}
1320+
}
1321+
drop table t1, t2;

‎mysql-test/main/analyze_format_json.test‎

Lines changed: 21 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -267,4 +267,25 @@ where
267267
set join_cache_level=@tmp;
268268
drop table t10, t11;
269269

270+
--echo #
271+
--echo # MDEV-33309: ANALYZE FORMAT=JSON: UPDATE|DELETE don't show r_other_time_ms
272+
--echo #
273+
--source include/have_sequence.inc
274+
create table t1 (pk int primary key, a int);
275+
insert into t1 select seq, seq from seq_1_to_1000;
276+
create table t2 like t1;
277+
insert into t2 select * from t1;
278+
279+
--echo # Top-level query block must have r_table_time_ms and r_other_time_ms
280+
--source include/analyze-format.inc
281+
analyze format=json
282+
update t1 set a=a+1
283+
where t1.pk > (select max(a) from t2 where t2.pk+1 = t1.pk+1 ) - 10;
284+
285+
--echo # Top-level query block must have r_table_time_ms and r_other_time_ms
286+
--source include/analyze-format.inc
287+
analyze format=json
288+
delete from t1
289+
where t1.pk > (select max(a) from t2 where t2.pk+1 = t1.pk+1 ) - 10;
270290

291+
drop table t1, t2;

‎mysql-test/main/analyze_stmt_orderby.result‎

Lines changed: 6 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -55,7 +55,8 @@ ANALYZE
5555
"rows": 10000,
5656
"r_rows": 10000,
5757
"r_filtered": 100,
58-
"r_total_time_ms": "REPLACED",
58+
"r_table_time_ms": "REPLACED",
59+
"r_other_time_ms": "REPLACED",
5960
"r_engine_stats": REPLACED
6061
}
6162
}
@@ -111,7 +112,8 @@ ANALYZE
111112
"rows": 9,
112113
"r_rows": 10,
113114
"r_filtered": 100,
114-
"r_total_time_ms": "REPLACED",
115+
"r_table_time_ms": "REPLACED",
116+
"r_other_time_ms": "REPLACED",
115117
"r_engine_stats": REPLACED,
116118
"attached_condition": "t2.a < 10"
117119
}
@@ -165,7 +167,8 @@ ANALYZE
165167
"rows": 10000,
166168
"r_rows": 10000,
167169
"r_filtered": 100,
168-
"r_total_time_ms": "REPLACED",
170+
"r_table_time_ms": "REPLACED",
171+
"r_other_time_ms": "REPLACED",
169172
"r_engine_stats": REPLACED
170173
}
171174
}

‎mysql-test/main/explain_json_format_partitions.result‎

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -74,7 +74,8 @@ ANALYZE
7474
"rows": 10,
7575
"r_rows": 10,
7676
"r_filtered": 30,
77-
"r_total_time_ms": "REPLACED",
77+
"r_table_time_ms": "REPLACED",
78+
"r_other_time_ms": "REPLACED",
7879
"r_engine_stats": REPLACED,
7980
"attached_condition": "t1.a in (2,3,4)"
8081
}
@@ -98,7 +99,8 @@ ANALYZE
9899
"rows": 10,
99100
"r_rows": 10,
100101
"r_filtered": 0,
101-
"r_total_time_ms": "REPLACED",
102+
"r_table_time_ms": "REPLACED",
103+
"r_other_time_ms": "REPLACED",
102104
"r_engine_stats": REPLACED,
103105
"attached_condition": "t1.a in (20,30,40)"
104106
}

‎mysql-test/main/subselect_mat.result‎

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -3320,7 +3320,8 @@ ANALYZE
33203320
"rows": 4,
33213321
"r_rows": 4,
33223322
"r_filtered": 25,
3323-
"r_total_time_ms": "REPLACED",
3323+
"r_table_time_ms": "REPLACED",
3324+
"r_other_time_ms": "REPLACED",
33243325
"r_engine_stats": REPLACED,
33253326
"attached_condition": "!(<in_optimizer>(t1.a,t1.a in (subquery#2)))"
33263327
},
@@ -3395,7 +3396,8 @@ ANALYZE
33953396
"rows": 2,
33963397
"r_rows": 2,
33973398
"r_filtered": 0,
3398-
"r_total_time_ms": "REPLACED",
3399+
"r_table_time_ms": "REPLACED",
3400+
"r_other_time_ms": "REPLACED",
33993401
"r_engine_stats": REPLACED,
34003402
"attached_condition": "!(<in_optimizer>(t1.a,t1.a in (subquery#2)))"
34013403
},

‎sql/sql_delete.cc‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -125,6 +125,7 @@ bool Update_plan::save_explain_data_intern(THD *thd,
125125
(thd->variables.log_slow_verbosity &
126126
LOG_SLOW_VERBOSITY_ENGINE))
127127
{
128+
explain->table_tracker.set_gap_tracker(&explain->extra_time_tracker);
128129
table->file->set_time_tracker(&explain->table_tracker);
129130

130131
if (table->file->handler_stats && table->s->tmp_table != INTERNAL_TMP_TABLE)

‎sql/sql_explain.cc‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -2684,8 +2684,8 @@ void Explain_update::print_explain_json(Explain_query *query,
26842684

26852685
if (table_tracker.has_timed_statistics())
26862686
{
2687-
writer->add_member("r_total_time_ms").
2688-
add_double(table_tracker.get_time_ms());
2687+
writer->add_member("r_table_time_ms").add_double(table_tracker.get_time_ms());
2688+
writer->add_member("r_other_time_ms").add_double(extra_time_tracker.get_time_ms());
26892689
}
26902690
}
26912691

‎sql/sql_explain.h‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1007,6 +1007,7 @@ class Explain_update : public Explain_node
10071007
/* TODO: This tracks time to read rows from the table */
10081008
Exec_time_tracker table_tracker;
10091009

1010+
Gap_time_tracker extra_time_tracker;
10101011
/* The same as Explain_table_access::handler_for_stats */
10111012
handler *handler_for_stats;
10121013

0 commit comments

Comments
 (0)