[fix](spill) Record the spill read deserialize timer

[zhuxiangyi]

What problem does this PR solve?

Issue Number: close#67040

Problem Summary:

SpillReadDeserializeBlockTime is always 0 in query profiles — the time spent deserializing spilled blocks has never been recorded.

The counter is registered by SpillReadCounters::init under the shared constant profile::SPILL_READ_DESERIALIZE_BLOCK_TIME, whose value is "SpillReadDeserializeBlockTime":

// be/src/exec/operator/spill_counters.h
spill_read_deserialize_block_timer =
ADD_TIMER_WITH_LEVEL(profile, profile::SPILL_READ_DESERIALIZE_BLOCK_TIME, 1);

But SpillFileReader looked it up with a hand-written literal that is missing an s:

// be/src/exec/spill/spill_file_reader.cpp
_deserialize_timer = custom_profile->get_counter("SpillReadDerializeBlockTime");
// ^^^ Derialize

get_counter() returns nullptr for the unknown name, and ScopedTimer returns early on a null counter, so SCOPED_TIMER(_deserialize_timer) in SpillFileReader::read() silently measures nothing.

Why existing tests did not catch it:spill_file_test.cpp and spill_repartitioner_test.cpp registered the counters by hand and copied the same misspelling, so the reader's lookup resolved in tests while returning null in a real query.

Changes:

1. SpillFileReader now resolves every read counter through the profile:: name constants instead of string literals, and DCHECKs that each one resolves, so a future rename fails loudly instead of silently dropping a counter.
2. The unit tests reuse SpillWriteCounters::init / SpillReadCounters::init rather than re-listing the names, so the registered names and units cannot drift from production again.
3. spillable_operator_test_helper registered SpillReadFileTime and SpillReadDeserializeBlockTime as TUnit::UNIT instead of timers. That was harmless while the timer resolved to null, but trips the DCHECK_EQ(counter->type(), TUnit::TIME_NS) inside ScopedTimer once it resolves, so it is corrected by the same reuse.

Release note

Fix SpillReadDeserializeBlockTime always being 0 in query profiles.

Check List (For Author)

• Test

  • Unit Test

    Added SpillFileTest.ReadDeserializeTimerIsRecorded, which fails before this
    change: with the test registering the canonical name, the reader's misspelled
    lookup yields a null counter and the timer stays at 0 after a real read. The
    test also asserts the misspelled name is absent, so it cannot be reintroduced.

• Behavior changed:

  • No.

    Profile-only fix. The counter already existed and was already reported; it was
    simply never updated. No counter is added, removed, or renamed.

• Does this need documentation?

  • No.

[hello-stephen]

Thank you for your contribution to Apache Doris.
Don't know what should be done next? See How to process your PR.

Please clearly describe your PR:

1. What problem was fixed (it's best to include specific error reporting information). How it was fixed.
2. Which behaviors were modified. What was the previous behavior, what is it now, why was it modified, and what possible impacts might there be.
3. What features were added. Why was this function added?
4. Which code was refactored and why was this part of the code refactored?
5. Which functions were optimized and what is the difference before and after the optimization?

[zhuxiangyi]

run buildall

[hello-stephen]

TPC-H: Total hot run time: 17417 ms

machine: 'aliyun_ecs.c7a.8xlarge_32C64G'
scripts: https://github.com/apache/doris/tree/master/tools/tpch-tools
Tpch sf100 test result on commit 4219697dedd2fc61021600c23cd421db9c0ed84d, data reload: false
------ Round 1 ----------------------------------
============================================
q1	17614	3059	3054	3054
q2	1870	238	158	158
q3	10474	854	510	510
q4	4674	250	204	204
q5	7674	561	385	385
q6	140	119	96	96
q7	527	523	390	390
q8	9252	881	950	881
q9	3482	2460	2440	2440
q10	6511	883	756	756
q11	459	259	239	239
q12	691	409	334	334
q13	17858	1540	1191	1191
q14	163	151	141	141
q15	q16	433	405	368	368
q17	819	758	791	758
q18	3195	2317	2298	2298
q19	1126	876	789	789
q20	687	513	454	454
q21	5249	1731	1952	1731
q22	330	265	240	240
Total cold run time: 93228 ms
Total hot run time: 17417 ms
----- Round 2, with runtime_filter_mode=off -----
============================================
q1	3437	3359	3353	3353
q2	204	220	158	158
q3	2299	2373	2201	2201
q4	1217	1190	901	901
q5	2258	2186	2210	2186
q6	173	127	86	86
q7	1053	945	878	878
q8	1610	1442	1423	1423
q9	3246	3216	3207	3207
q10	1917	1835	1656	1656
q11	362	273	258	258
q12	457	431	348	348
q13	1468	1557	1191	1191
q14	175	175	173	173
q15	q16	399	396	360	360
q17	1048	1027	1026	1026
q18	5150	4459	4912	4459
q19	857	845	860	845
q20	983	973	826	826
q21	3844	3105	3237	3105
q22	415	330	330	330
Total cold run time: 32572 ms
Total hot run time: 28970 ms

[hello-stephen]

TPC-DS: Total hot run time: 84541 ms

machine: 'aliyun_ecs.c7a.8xlarge_32C64G'
scripts: https://github.com/apache/doris/tree/master/tools/tpcds-tools
TPC-DS sf100 test result on commit 4219697dedd2fc61021600c23cd421db9c0ed84d, data reload: false
query5	4266	428	345	345
query6	400	163	160	160
query7	4853	454	262	262
query8	290	123	114	114
query9	8665	2880	2873	2873
query10	407	282	213	213
query11	5375	1079	926	926
query12	120	69	68	68
query13	1208	427	320	320
query14	6067	2267	2143	2143
query14_1	2043	2031	2034	2031
query15	174	124	116	116
query16	925	356	373	356
query17	812	466	372	372
query18	2331	338	243	243
query19	168	140	119	119
query20	71	70	73	70
query21	212	117	103	103
query22	5497	5578	5531	5531
query23	6861	6368	6209	6209
query23_1	6322	6348	6160	6160
query24	7290	1111	779	779
query24_1	795	784	801	784
query25	433	303	267	267
query26	1264	287	169	169
query27	2701	460	297	297
query28	4580	1499	1503	1499
query29	953	455	352	352
query30	273	198	157	157
query31	839	428	370	370
query32	97	51	51	51
query33	461	221	193	193
query34	999	816	471	471
query35	403	410	351	351
query36	564	545	529	529
query37	123	80	71	71
query38	1019	867	843	843
query39	508	479	455	455
query39_1	480	468	479	468
query40	224	127	116	116
query41	58	55	57	55
query42	83	79	82	79
query43	244	245	213	213
query44	1048	534	545	534
query45	119	100	105	100
query46	790	841	510	510
query47	760	768	743	743
query48	323	298	230	230
query49	527	235	197	197
query50	800	321	293	293
query51	8212	8098	8058	8058
query52	77	73	63	63
query53	204	205	156	156
query54	231	179	165	165
query55	82	59	58	58
query56	234	228	212	212
query57	713	684	646	646
query58	217	197	175	175
query59	1259	1269	1140	1140
query60	307	228	196	196
query61	120	129	113	113
query62	382	208	185	185
query63	185	154	151	151
query64	2761	703	591	591
query65	1617	1616	1626	1616
query66	1933	319	254	254
query67	10126	9942	10066	9942
query68	3044	1185	765	765
query69	353	217	190	190
query70	665	601	612	601
query71	291	252	243	243
query72	2308	1734	1564	1564
query73	603	566	353	353
query74	2005	1245	1145	1145
query75	1247	1171	1022	1022
query76	2372	721	560	560
query77	254	257	201	201
query78	4050	3897	3305	3305
query79	1197	826	537	537
query80	1169	406	335	335
query81	486	204	176	176
query82	626	123	94	94
query83	327	254	241	241
query84	307	122	104	104
query85	839	432	378	378
query86	385	175	164	164
query87	1033	989	916	916
query88	2822	2103	2137	2103
query89	302	225	197	197
query90	1972	140	143	140
query91	154	145	122	122
query92	49	50	42	42
query93	1380	1132	811	811
query94	620	262	233	233
query95	601	398	338	338
query96	781	575	255	255
query97	1132	1108	1048	1048
query98	145	135	132	132
query99	418	342	315	315
Total cold run time: 177857 ms
Total hot run time: 84541 ms

[hello-stephen]

ClickBench: Total hot run time: 14.64 s

machine: 'aliyun_ecs.c7a.8xlarge_32C64G'
scripts: https://github.com/apache/doris/tree/master/tools/clickbench-tools
ClickBench test result on commit 4219697dedd2fc61021600c23cd421db9c0ed84d, data reload: false
query1	0.01	0.00	0.00
query2	0.07	0.04	0.03
query3	0.24	0.08	0.11
query4	1.60	0.11	0.09
query5	0.17	0.15	0.17
query6	1.28	0.72	0.67
query7	0.03	0.01	0.00
query8	0.05	0.03	0.03
query9	0.28	0.21	0.21
query10	0.35	0.38	0.34
query11	0.16	0.11	0.11
query12	0.14	0.12	0.12
query13	0.31	0.30	0.30
query14	0.46	0.46	0.46
query15	0.38	0.35	0.34
query16	0.23	0.24	0.21
query17	0.69	0.72	0.69
query18	0.19	0.18	0.18
query19	1.17	1.18	1.17
query20	0.01	0.00	0.00
query21	15.44	0.15	0.13
query22	5.06	0.04	0.04
query23	16.18	0.27	0.10
query24	3.03	0.32	0.24
query25	0.11	0.04	0.03
query26	0.74	0.17	0.11
query27	0.04	0.03	0.03
query28	3.64	0.53	0.26
query29	12.49	3.15	2.56
query30	0.26	0.13	0.13
query31	2.75	0.37	0.17
query32	3.53	0.33	0.23
query33	1.41	1.40	1.58
query34	15.40	2.25	1.79
query35	1.76	1.75	1.76
query36	0.47	0.28	0.29
query37	0.05	0.04	0.03
query38	0.05	0.03	0.03
query39	0.03	0.02	0.02
query40	0.11	0.07	0.08
query41	0.07	0.03	0.02
query42	0.03	0.02	0.03
query43	0.03	0.02	0.03
Total cold run time: 90.5 s
Total hot run time: 14.64 s

[zhuxiangyi]

run beut

[hello-stephen]

BE Regression && UT Coverage Report

Increment line coverage 100% (0/0) 🎉

Increment coverage report
Complete coverage report

Category	Coverage
Function Coverage	75.98% (34292/45133)
Line Coverage	60.88% (386200/634357)
Region Coverage	56.91% (323235/567928)
Branch Coverage	57.81% (147619/255347)

[yiguolei]

/review

[github-actions]

Review opinion: looks good; I found no blocking correctness issue and no inline finding to submit.

Critical checkpoint conclusions:

• Goal and proof: The reader now resolves SpillReadDeserializeBlockTime through the same canonical constant used by SpillReadCounters::init, so the existing profile counter is updated instead of a misspelled lookup returning null. ReadDeserializeTimerIsRecorded starts from a fresh zero-valued canonical counter, performs a real spill read, requires it to become positive, and confirms the old misspelled name is absent; it would fail with the old lookup.
• Scope and clarity: The production change is confined to counter lookup. The three fixture changes reuse the production counter initializers, preserve all reader/writer-required extras, and correct the former timer/byte unit mismatches without changing runtime data behavior.
• Concurrency: No execution scheduling or shared-state protocol changes. RuntimeProfile map access remains locked, counter values remain atomic, and every reader is constructed only after its owning local state has initialized the profile counters.
• Lifecycle: No ownership or release behavior changes. The stack-local SpillWriteCounters/SpillReadCounters holders in tests only retain aliases; RuntimeProfile owns the counters for the fixture lifetime.
• Configuration and compatibility: No configuration, FE-BE field, symbol, storage-format, transaction, persistence, or rolling-upgrade change. The externally visible counter name is unchanged.
• Parallel paths and conditions: All production SpillFileReader construction paths were traced, including spill sort, aggregation, hash join, repartitioning, multi-cast, and Iceberg sorted spill; each receives the canonical read-counter set with matching TIME_NS/UNIT/BYTES types before construction. The new DCHECKs express that registration invariant.
• Tests and results: The added BE unit test directly covers the regression, and the shared fixture setup prevents future test/production name drift. The exact PR head currently has passing COMPILE and BE UT checks; no local build was run in this review-only runner.
• Observability: This directly restores the existing deserialize-time signal and does not add or rename a metric. Existing sibling spill counters and identifiers remain unchanged.
• Performance and memory: Counter resolution remains constructor-only; the read hot path and allocation behavior are unchanged.
• Additional/user focus: No additional user focus was provided. The full changed-file sweep and round-1 full/risk reviews found no further valuable issue.

Review completeness: complete after one round; both normal full-review agents and the separate risk-focused agent returned NO_NEW_VALUABLE_FINDINGS, and the main-agent reconciliation left no unresolved candidate.