cai-pengtao opened a new issue, #67777: URL: https://github.com/apache/doris/issues/67777
### Search before asking - [x] I had searched in the [issues](https://github.com/apache/doris/issues?q=is%3Aissue) and found no similar issues. ### Version `doris-4.1.3-rc02-7126cf65d96 (Cloud Mode)`, official aarch64 build. 5 BE i8g.4xlarge (16 vCPU/128 GB, 3 TB file cache) + MS + FDB, Amazon Linux 2023, kernel 6.18. BE config defaults (`enable_metric_calculator=true`, `webserver_num_workers=128`). ### What's Wrong? `GET :8040/metrics` (~100 KB) takes ~7 ms normally, but stalls **every 15 s for 0.4–0.6 s** and a few times per hour for **2–15 s** (10.9 s, 14.8 s seen); Prometheus scrapes time out. 1 sample/s: ``` 05:57:25.864 0.377946 05:57:41.436 10.754890 05:57:57.252 0.222413 05:58:12.673 0.464823 # 60 samples: avg 0.20 s, max 10.75 s ``` Watching thread `calculate_metrics_thread` via `/proc/<pid>/task/<tid>/{stat,wchan,syscall,stack}` for 8 min shows two mechanisms: **A. Every 15 s the hook run holds the registry lock for ~0.6 s.** The thread wakes every 15 s and runs 0.57–0.68 s in state R; every `/metrics` request arriving in that window blocks until it ends (30 of 480 samples, 0.4–0.6 s). Kernel stack during the run: `__do_sys_newfstatat → vfs_fstatat → vfs_statx → filename_lookup`. From the 4.1.3-rc02 source: - `Daemon::calculate_metrics_thread` → `MetricRegistry::trigger_all_hooks(true)` holds `MetricRegistry::_lock` for the whole hook run ([metrics.cpp#L315-L321](https://github.com/apache/doris/blob/4.1.3-rc02/be/src/common/metrics/metrics.cpp#L315-L321)). `to_prometheus()` (the `/metrics` handler) takes the same lock ([#L323-L326](https://github.com/apache/doris/blob/4.1.3-rc02/be/src/common/metrics/metrics.cpp#L323-L326)) and holds it while serializing; concurrent scrapes serialize too (40 parallel curls: 0.007, 0.014, 0.020 … 0.238 s). - The expensive hook is `DorisMetrics::_update_process_fd_num()` ([doris_metrics.cpp#L479](https://github.com/apache/doris/blob/4.1.3-rc02/be/src/common/metrics/doris_metrics.cpp#L479)): `directory_iterator("/proc/self/fd")` + `entry.is_regular_file()` per entry. Every entry is a symlink, so `is_regular_file()` follows it with a `stat()`: **one `newfstatat` per open fd**. This BE holds ~197k fds (`doris_be_process_fd_num_used 195746`, `doris_be_local_file_open_reading 195503`, file cache readers) → ~197k stat() per run. The same loop in Python on this host: 0.66 s; plain readdir (`ls /proc/<pid>/fd | wc -l`): 0.14 s. **B. Rare multi-second stalls while the hook thread sleeps.** In the same 8 min `/metrics` took 2.917 s, 1.761 s and 9.097 s while `calculate_metrics_thread` was inside its 15 s `futex` wait, so no metrics lock was involved. All handlers run inline on the 128 libevent worker threads (`EvHttpServer::on_request` → `handler->handle()`), and `StreamLoadAction` blocks its thread: `_handle()` does `body_sink->finish()` → `ctx->future.get()` → `pre_commit_txn()/commit_txn()` synchronously ([stream_load.cpp#L168-L200](https://github.com/apache/doris/blob/4.1.3-rc02/be/src/service/http/action/stream_load.cpp#L168-L200)), and `on_chunk_data()` → `StreamLoadPipe::_append()` waits on `_put_cond` when the pipe is full. Any connection already accepted by that worker (e.g. a `/metrics` scrape) waits until the handler returns; ~22 stream loads are in flight here. A second 400 s run sampling `/metrics`, `?type=core` and `/api/health` in parallel confirms it: `/api/health` (no lock at all) stalled 8.561 s at the same moment as the other two; `/metrics` also hit 14.8 s twice. ### What You Expected? `/metrics` answers in milliseconds regardless of hooks or stream loads on the same webserver; fd counting is not O(fds) `stat()` calls; scrapes do not serialize on one mutex. ### How to Reproduce? 1. Cloud-mode BE with many open fds (large file cache, ~200k here), default config, stream loads running. 2. `for i in $(seq 60); do date -u +%T.%N|cut -c1-12|tr '\n' ' '; curl -s -o /dev/null -w '%{time_total}\n' 127.0.0.1:8040/metrics; sleep 1; done | awk '$2>0.05'` → one 0.4–0.6 s stall every 15 s, sometimes several seconds. 3. `TID=$(grep -l '^calculate_metri' /proc/$PID/task/*/comm | awk -F/ '{print $(NF-1)}'); cat /proc/$PID/task/$TID/{wchan,stack}` during a run → `newfstatat`. 4. Hook cost alone: `python3 -c "import os,time;t=time.time();print(sum(1 for e in os.scandir('/proc/PID/fd') if e.is_file()),time.time()-t)"` → 195962 files, 0.66 s. ### Anything Else? Suggestions: (1) `trigger_all_hooks` should copy the entity list and run hooks outside `MetricRegistry::_lock`, or `/metrics` should serve a snapshot refreshed by the calculator thread; (2) `_update_process_fd_num` should count entries without following symlinks (5x cheaper) or run less often; (3) blocking stream-load work (`future.get()`, `commit_txn`, pipe back-pressure) should leave the libevent worker threads, or `/metrics` should get a dedicated worker. #16381 removed the jemalloc call from `trigger_all_hooks` for this same contention. No clean workaround: `enable_metric_calculator=false` just moves the 0.6 s hook run into every scrape. ### Are you willing to submit PR? - [ ] Yes I am willing to submit a PR! ### Code of Conduct - [x] I agree to follow this project's [Code of Conduct](https://www.apache.org/foundation/policies/conduct) -- 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]
