Skip to content

[fix](routine load) fix NPE when replaying change routine load job fo…#65555

Open
enocknkhoma wants to merge 1 commit into
apache:masterfrom
enocknkhoma:fix_replay_routine_load_job_npe
Open

[fix](routine load) fix NPE when replaying change routine load job fo…#65555
enocknkhoma wants to merge 1 commit into
apache:masterfrom
enocknkhoma:fix_replay_routine_load_job_npe

Conversation

@enocknkhoma

Copy link
Copy Markdown

What problem does this PR solve?

Issue Number: No related issue

Related PR: #40728, #53768

Problem Summary:

In compute-storage decoupled (cloud) mode, if the edit log contains an OP_CHANGE_ROUTINE_LOAD_JOB (Operation Type 201) entry whose routine load job no longer exists in memory (the job was cleaned up while a later change op for it remains in the journal), FE throws a NullPointerException during journal replay and cannot start. All FEs replaying the same journal crash
identically, so the entire FE cluster becomes unrecoverable. force_skip_journal_id cannot bypass it, as it only covers journals that fail to deserialize, not replay exceptions.

Observed in production on 3.1.0 (replayer thread):

2026-07-11 07:35:25,666 INFO (replayer|15) [EditLog.loadJournal():379] Begin to unprotect drop table: internal.1771306616047.stg_simreg
2026-07-11 07:35:25,666 INFO (replayer|15) [CatalogRecycleBin.recycleTable():188] recycle table[1782934238385-stg_simreg], is force drop: false
2026-07-11 07:35:25,666 INFO (replayer|15) [InternalCatalog.unprotectDropTable():1059] finished dropping table[stg_simreg] in db[cdrs] recycleTable cost: 0ms
2026-07-11 07:35:25,668 INFO (replayer|15) [EditLog.loadJournal():361] Begin to unprotect create table. internal.cdrs.stg_simreg
2026-07-11 07:35:25,669 ERROR (replayer|15) [EditLog.loadJournal():1438] replay Operation Type 201, log id: 24831862
java.lang.NullPointerException: Cannot invoke "org.apache.doris.load.routineload.RoutineLoadJob.setCloudCluster()" because the return value of "org.apache.doris.cloud.load.CloudRoutineLoadManager.getJob(long)" is null
	at org.apache.doris.cloud.load.CloudRoutineLoadManager.replayChangeRoutineLoadJob(CloudRoutineLoadManager.java:70) ~[doris-fe.jar:1.2-SNAPSHOT]
	at org.apache.doris.persist.EditLog.loadJournal(EditLog.java:875) ~[doris-fe.jar:1.2-SNAPSHOT]
	at org.apache.doris.catalog.Env.replayJournal(Env.java:3103) ~[doris-fe.jar:1.2-SNAPSHOT]
	at org.apache.doris.catalog.Env$4.runOneCycle(Env.java:2865) ~[doris-fe.jar:1.2-SNAPSHOT]
	at org.apache.doris.common.util.Daemon.run(Daemon.java:119) ~[doris-fe.jar:1.2-SNAPSHOT]

Reproduced identically on 3.1.1 and 3.1.4 (on 3.1.4 also via the state transfer path during master election: Env.transferToMaster -> Env.replayJournal, same NPE at CloudRoutineLoadManager.java:70). The unguarded call is still present in 4.1.2 and master.

#40728 and #53768 fixed the illegal-state and null-field cases in this same replay path; this PR covers the remaining null-job case with the same defensive pattern (as used in CloudSystemInfoService.replayModifyBackend).

Note: the base RoutineLoadManager.replayChangeRoutineLoadJob has the same unguarded getJob() dereference on the non-cloud path; this PR fixes the cloud override where the crash was observed, the base class can be guarded in a follow-up.

Fix: null-check the job and skip the edit log entry with a warning, consistent with how a change op for an already-removed job should be treated.

Release note

Fix FE start failure (NPE) in cloud mode when replaying OP_CHANGE_ROUTINE_LOAD_JOB for a routine load job that no longer exists.

Check List (For Author)

  • Test

    • Manual test (add detailed scripts or steps below)
      Replayed a production edit log containing an orphaned OP_CHANGE_ROUTINE_LOAD_JOB entry in a 3-FE cloud-mode sandbox (FDB + Meta Service). Without this fix, all FEs crash-loop at the same log id (verified on 3.1.0/3.1.1/3.1.4). With the fix, the FE logs a warning, replay completes, master election succeeds, and routine load jobs resume normally.
  • Behavior changed:

    • No.
  • Does this need documentation?

    • No.

Check List (For Reviewer who merge this PR)

  • Confirm the release note
  • Confirm test cases
  • Confirm document
  • Add branch pick label

…r non-existent job in cloud mode

Add null check for routine load job before setting cloud cluster.
@enocknkhoma enocknkhoma requested a review from gavinchou as a code owner July 13, 2026 12:59
@hello-stephen

Copy link
Copy Markdown
Contributor

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?

@enocknkhoma

Copy link
Copy Markdown
Author

run buildall

@hello-stephen

Copy link
Copy Markdown
Contributor
TPC-H: Total hot run time: 29743 ms
machine: 'aliyun_ecs.c7a.8xlarge_32C64G'
scripts: https://github.com/apache/doris/tree/master/tools/tpch-tools
Tpch sf100 test result on commit e7965674ede140776c38a34cd2be1dd241af7511, data reload: false

------ Round 1 ----------------------------------
============================================
q1	17591	4002	3983	3983
q2	2015	314	197	197
q3	10292	1427	844	844
q4	4683	479	343	343
q5	7494	840	566	566
q6	179	171	139	139
q7	771	837	621	621
q8	9361	1383	1407	1383
q9	5579	4407	4351	4351
q10	6782	1799	1516	1516
q11	505	349	324	324
q12	723	547	418	418
q13	18140	3355	2798	2798
q14	263	264	248	248
q15	q16	789	773	722	722
q17	982	978	935	935
q18	6888	5732	5698	5698
q19	1358	1347	1082	1082
q20	747	662	562	562
q21	6382	2852	2685	2685
q22	468	366	328	328
Total cold run time: 101992 ms
Total hot run time: 29743 ms

----- Round 2, with runtime_filter_mode=off -----
============================================
q1	5177	4881	4782	4782
q2	285	313	217	217
q3	4901	5321	4688	4688
q4	2081	2159	1368	1368
q5	4791	4848	4661	4661
q6	233	183	131	131
q7	1907	1794	1578	1578
q8	2381	2062	2123	2062
q9	7710	7397	7203	7203
q10	4704	4610	4166	4166
q11	524	378	348	348
q12	744	742	529	529
q13	2991	3325	2777	2777
q14	270	283	255	255
q15	q16	672	699	605	605
q17	1258	1238	1233	1233
q18	7334	6802	6760	6760
q19	1055	1047	1103	1047
q20	2205	2196	1940	1940
q21	5219	4532	4384	4384
q22	533	454	396	396
Total cold run time: 56975 ms
Total hot run time: 51130 ms

@hello-stephen

Copy link
Copy Markdown
Contributor
TPC-DS: Total hot run time: 179522 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 e7965674ede140776c38a34cd2be1dd241af7511, data reload: false

query5	4334	652	494	494
query6	456	209	207	207
query7	4938	620	340	340
query8	337	194	170	170
query9	8759	4085	4103	4085
query10	496	332	300	300
query11	5917	2355	2162	2162
query12	164	104	102	102
query13	1280	618	439	439
query14	6298	5303	4920	4920
query14_1	4316	4300	4272	4272
query15	209	212	180	180
query16	970	464	434	434
query17	969	743	582	582
query18	2457	505	354	354
query19	212	191	154	154
query20	116	111	109	109
query21	234	156	131	131
query22	13657	13698	13350	13350
query23	17322	16493	16139	16139
query23_1	16311	16297	16231	16231
query24	7659	1817	1315	1315
query24_1	1330	1259	1297	1259
query25	577	477	388	388
query26	1343	349	219	219
query27	2569	589	388	388
query28	4426	2008	2002	2002
query29	1116	657	508	508
query30	332	258	223	223
query31	1115	1114	980	980
query32	109	65	61	61
query33	542	321	247	247
query34	1161	1149	682	682
query35	782	792	688	688
query36	1412	1385	1232	1232
query37	159	151	94	94
query38	1867	1691	1634	1634
query39	930	910	882	882
query39_1	872	867	895	867
query40	239	150	137	137
query41	63	64	63	63
query42	91	89	89	89
query43	325	332	280	280
query44	1453	798	785	785
query45	195	188	176	176
query46	1086	1265	719	719
query47	2353	2291	2291	2291
query48	402	424	306	306
query49	572	432	315	315
query50	1038	416	344	344
query51	10652	10559	10850	10559
query52	85	86	74	74
query53	262	283	211	211
query54	283	253	227	227
query55	74	69	66	66
query56	293	294	291	291
query57	1432	1398	1333	1333
query58	291	256	259	256
query59	1585	1641	1453	1453
query60	306	272	253	253
query61	151	151	147	147
query62	703	648	589	589
query63	244	206	211	206
query64	2827	1022	840	840
query65	4870	4759	4750	4750
query66	1857	512	377	377
query67	29581	29481	29249	29249
query68	3217	1637	969	969
query69	395	305	268	268
query70	1029	947	977	947
query71	349	329	315	315
query72	3049	2792	2379	2379
query73	851	833	424	424
query74	5082	4915	4772	4772
query75	2595	2579	2233	2233
query76	2321	1191	786	786
query77	358	374	292	292
query78	12301	12298	11812	11812
query79	1415	1194	704	704
query80	1281	546	443	443
query81	530	314	281	281
query82	602	155	126	126
query83	373	320	291	291
query84	327	156	128	128
query85	1002	604	503	503
query86	419	312	286	286
query87	1838	1815	1741	1741
query88	3669	2737	2780	2737
query89	462	402	365	365
query90	1990	204	193	193
query91	203	192	162	162
query92	63	60	59	59
query93	1717	1497	903	903
query94	720	341	325	325
query95	790	583	468	468
query96	1048	830	355	355
query97	2686	2692	2529	2529
query98	211	206	205	205
query99	1160	1169	1037	1037
Total cold run time: 265875 ms
Total hot run time: 179522 ms

@hello-stephen

Copy link
Copy Markdown
Contributor
ClickBench: Total hot run time: 24.98 s
machine: 'aliyun_ecs.c7a.8xlarge_32C64G'
scripts: https://github.com/apache/doris/tree/master/tools/clickbench-tools
ClickBench test result on commit e7965674ede140776c38a34cd2be1dd241af7511, data reload: false

query1	0.01	0.01	0.01
query2	0.09	0.05	0.05
query3	0.25	0.14	0.14
query4	1.61	0.14	0.13
query5	0.23	0.22	0.22
query6	1.19	1.07	1.32
query7	0.04	0.01	0.00
query8	0.06	0.03	0.03
query9	0.37	0.30	0.31
query10	0.55	0.55	0.58
query11	0.20	0.14	0.13
query12	0.19	0.15	0.14
query13	0.48	0.47	0.47
query14	1.03	1.02	0.99
query15	0.61	0.58	0.59
query16	0.32	0.33	0.32
query17	1.10	1.08	1.08
query18	0.23	0.21	0.21
query19	2.03	1.90	1.91
query20	0.02	0.01	0.01
query21	15.44	0.22	0.13
query22	4.78	0.05	0.05
query23	16.12	0.32	0.12
query24	2.90	0.42	0.34
query25	0.11	0.06	0.04
query26	0.73	0.20	0.16
query27	0.04	0.04	0.04
query28	3.58	0.89	0.50
query29	12.49	4.10	3.24
query30	0.28	0.15	0.15
query31	2.76	0.59	0.32
query32	3.25	0.60	0.51
query33	3.18	3.17	3.29
query34	15.57	4.23	3.55
query35	3.54	3.53	3.56
query36	0.54	0.43	0.42
query37	0.09	0.07	0.06
query38	0.04	0.04	0.03
query39	0.04	0.03	0.04
query40	0.18	0.17	0.17
query41	0.07	0.03	0.03
query42	0.04	0.03	0.03
query43	0.04	0.03	0.04
Total cold run time: 96.42 s
Total hot run time: 24.98 s

@hello-stephen

Copy link
Copy Markdown
Contributor

FE Regression Coverage Report

Increment line coverage 33.33% (2/6) 🎉
Increment coverage report
Complete coverage report

@sollhui

sollhui commented Jul 14, 2026

Copy link
Copy Markdown
Contributor

/review

@github-actions github-actions Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I found one replay-equivalence issue that should be fixed before merge.

Part 1.3 checkpoint conclusions:

  • Goal/test: the patch prevents the cloud replay NPE for an orphaned routine-load change record, but it does not preserve all state cleanup from the original final-state transition. No automated test for the cloud missing-job replay/callback case is added; I did not run builds or tests because this review runner is review-only.
  • Scope: the code change is small and localized to CloudRoutineLoadManager.replayChangeRoutineLoadJob(), but the affected behavior crosses image load, edit-log replay, old-job cleanup, and transaction callbacks.
  • Concurrency/lifecycle/persistence: a remove-before-change replay ordering is valid when final-state update and old-job cleanup interleave; the accepted inline comment covers the missing callback cleanup in that lifecycle.
  • Config/compatibility/FE-BE/protocol: no new config, persisted format, or FE-BE protocol fields are introduced.
  • Parallel paths/observability/performance: non-cloud replay already avoids crashing after the null dereference is caught; cloud replay now needs equivalent cleanup semantics. The warning is useful and there is no hot-path performance concern.
  • User focus: no additional user-provided focus points were present.

Two subagent rounds completed. After accepting the callback-cleanup issue, both convergence subagents returned NO_NEW_VALUABLE_FINDINGS, and there are no remaining unresolved candidates.

if (job == null) {
LOG.warn("routine load job {} does not exist when replaying change routine load job, ignore it",
operation.getId());
return;

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This makes the orphaned change record replayable, but it still leaves the transaction callback state different from the original master. A valid ordering for this failure is: the job is loaded from image as non-final, so readFields() registers its txn callback; cleanup replays OP_REMOVE_ROUTINE_LOAD_JOB first and removes the job from idToRoutineLoadJob but does not remove that callback; then this branch sees the later OP_CHANGE_ROUTINE_LOAD_JOB and returns before updateState(..., isReplay=true) can perform the final-state removeCallback(id). After replay continues, TransactionState.replaySetTransactionStatus() and the cloud commit path look callbacks up directly by id, so that stale RoutineLoadJob can still receive txn callbacks even though the manager no longer contains the job. Please clear the callback in this missing-job path, or preferably in replayRemoveOldRoutineLoad(), before ignoring the orphaned change.

@sollhui

sollhui commented Jul 14, 2026

Copy link
Copy Markdown
Contributor

Thanks for making the replay path tolerant of a missing routine load job. This prevents FE startup from being blocked by an orphan OP_CHANGE_ROUTINE_LOAD_JOB.

However, this appears to address the replay symptom without explaining how the orphan journal entry is generated. Could you please clarify the root cause and the exact ordering that allows a change operation to remain after the job has been removed?

For example, is there a race between transitioning a job to a final state and cleanOldRoutineLoadJobs() / cleanOverLimitRoutineLoadJobs() that may produce OP_REMOVE_ROUTINE_LOAD_JOB before OP_CHANGE_ROUTINE_LOAD_JOB?

If Doris can still generate this ordering, should we also fix the journal ordering or locking to prevent new orphan entries, instead of relying only on replay-time tolerance? A focused unit test covering the missing-job replay case would also be helpful.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants