tracy1014-hub commented on issue #65416: URL: https://github.com/apache/doris/issues/65416#issuecomment-4933108182
Hi @yiguolei — pstack captured. Gist with the raw pstack + analysis: **https://gist.github.com/tracy1014-hub/7ddbc6340653ead0d701d6ba26550577** Files: - `pstack.txt` — 3.5 MB, partial pstack of doris-be-3 (3,295 of 25,035 threads captured, 26% coverage) - `ANALYSIS.md` — key findings + recommended next step ## Why partial `gdb -batch -ex "thread apply all bt" -p 955` ran for ~33 min and had only walked 26% of the 25k threads (gdb is slow on this many threads — 100% CPU, ~7 min of CPU per 1k threads). I killed it before completion because waiting for full coverage would have taken hours and you'd be waiting on this reply. The 3,295 threads captured are statistically representative — see below. ## Headline finding Every single thread in the pstack is `rs_normal`, and **3,294 / 3,295 (99.97%) have an identical backtrace**: ``` Thread 25035 (Thread 0x7f9dc6cb9640 (LWP 443684) "rs_normal [work"): #0 pthread_cond_wait from /lib/x86_64-linux-gnu/libc.so.6 #1 Parker::park(bool, long) from /usr/lib/jvm/java/lib/server/libjvm.so #2 Unsafe_Park from /usr/lib/jvm/java/lib/server/libjvm.so #3 ?? (JIT-compiled) #4 ?? (JIT-compiled) #5 OptoRuntime::new_instance_C(Klass*, JavaThread*) from /usr/lib/jvm/java/lib/server/libjvm.so ``` (1 thread uses `pthread_cond_timedwait` instead of `pthread_cond_wait`, otherwise identical.) ## Diagnosis The `rs_normal` threads are **not C++ threads** — they're **JVM threads** (created by the JNI scanner, almost certainly Paimon) parking on Java's `Unsafe_Park` primitive waiting for work. This reconciles everything we've seen: 1. `doris_be_thread_pool_active_threads{rs_normal} = 0` — correct from the C++ pool's POV; none of these threads are in that pool. 2. `doris_be_thread_pool_max_threads{rs_normal} = 256` — the cap exists on the C++ pool, but the 22,945 OS threads named `rs_normal` were never created by that pool. They share the thread name (probably because the JNI scanner uses the same naming convention) but bypass the C++ pool entirely. 3. `task_execution_count_total{rs_normal} = 15,297` on be-3 (vs 22,945 actual threads) — the C++ pool has executed ~15k tasks, but ~22.9k JVM threads exist. The two numbers aren't directly comparable because they're counted by different accounting systems (one C++, one JVM), but the JVM-side count being higher is consistent with the JVM spawning threads that the C++ pool never sees. 4. `num_cores = 8` had no effect on rs_normal growth — because the leak isn't on a path that consults `num_cores`. The leak is in the JNI scanner's Java-side thread creation logic. ## Where to look in the code The leak path is in the **Paimon JNI scanner** (or whichever external-catalog scanner is being used), specifically: - A code path that creates a new Java `Thread` (or submits to an unbounded `ExecutorService`) per external scan, parks it on `Unsafe_Park` waiting for work, but never `interrupt()`s or `join()`s it when the scan completes. The parked thread waits forever and accumulates. - The `OptoRuntime::new_instance_C` frame a few levels deeper suggests the parked thread also allocates Java objects while waiting — possibly a fresh `Runnable` / `Callable` per scan that gets GC'd but the carrier thread stays around. - Worth grepping for `LockSupport.park`, `BlockingQueue.take`, `Unsafe.park` in the Paimon scanner JARs (`$DORIS_HOME/lib/java_extensions/paimon-scanner/`) — find the parking site, then check whether the corresponding `unpark` / `put` / `notify` site is reachable on scan completion. ## Cluster state After I killed gdb with `kill -9`, the BE process was left in `T (stopped)` state (gdb didn't get a chance to send SIGCONT before dying). A manual `kill -CONT 955` from inside the container woke it up — it immediately went back to `S (sleeping)`, FE marked it `Alive=true`, `HeartbeatFailureCounter=0`, pod back to `1/1 Running`. So the freeze during pstack was purely ptrace-induced, **not** a real leak-induced freeze at ~27k threads. However, the k8s **liveness probe** had failed during the 38-min gdb pause (BE was unresponsive because ptrace-stopped), so k8s restarted the `be` container shortly after SIGCONT. The pod is now `1/1 Running` with `RESTARTS=1`, BE_PID=992 (was 955), and rs_normal count reset to 8 (fresh start). So the natural-freeze capture I was hoping to get from `doris-be-3` won't happen on this pod instance — it would take another 5+ hours of growth. If you'd like the freeze-time `be.INFO` + `SHOW BACKENDS\G` with `Alive=false` from a natural ~27k-thread freeze, I can either: - Disable the liveness probe on `doris-be-3` so it doesn't get killed during the next gdb attach, then re-run pstack on the natural freeze - Or just let `doris-be-3` (or one of the other control BEs) run to natural freeze without gdb interference — the rotator is currently suspended, and the natural-freeze log would be different from the gdb-induced freeze log Let me know which (if any) you want. Otherwise the pstack analysis above is the main deliverable. -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: [email protected] For queries about this service, please contact Infrastructure at: [email protected] --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
