kvcache-ai/AgentENV
1
0
Fork 0
mirror of https://github.com/kvcache-ai/AgentENV.git synced 2026-11-05 01:17:36 +00:00
Code Issues 91 Projects Packages Wiki Activity

[GH-ISSUE #297] ublk-daemon: idle-pool refill retries add_dev indefinitely (EACCES) once ublk slots are exhausted — burns CPU and may exhaust the disk #80

New issue
Closed
opened 2026-10-29 14:19:19 +00:00 by bsakaguchi · 2 comments
bsakaguchi commented 2026-10-29 14:19:19 +00:00
Owner
Copy link

Originally created by @emailcannotbeblank on GitHub (Sep 16, 2026).
Original GitHub issue: https://github.com/kvcache-ai/AgentENV/issues/297

Affected component

ublk / ublk-daemon

AgentENV version

  • Version or commit: 339e81b (fix(tools-image): bootstrap required paths for minimal images), main branch
  • Local modifications: none.

Host environment

  • OS: openEuler 24.03 (LTS-SP2)
  • Kernel (uname -a): 6.6.0-98.0.0.103.oe2403sp2.aarch64
  • Architecture: aarch64
  • Bare metal, VM, or cloud: bare metal
  • ublk support: ublk_drv module, version 6.6.0-98.0.0.103.oe2403sp2.aarch64 (ships with the kernel; the driver has no separate MODULE_VERSION); ublks_max = 64 (module parameter, default, not resizable while devices are in use); device nodes /dev/ublkcN (char) and /dev/ublkbN (block)
  • CPU: 320 cores (aarch64)
  • Memory: 502 GiB
  • Storage/filesystem: ext4

Operation and configuration

[pool.block]
high_watermark = 100   # exceeds kernel ublks_max = 64
startup_prewarm = true


Once all 64 ublk device slots are allocated, every idle-pool refill attempt calls `add_dev`, which the kernel rejects. The daemon logs the failure and immediately reschedules, retrying forever.

The original implementation (`storage/ublk-daemon/src/server.rs` @ `339e81b`, verbatim):


fn schedule_idle_pool_refill(
    pool: Arc<PoolState>,
    ctrl_ring: IoRingHandle<io_uring::squeue::Entry128>,
    virtual_size: u64,
) {
    if pool
        .refill_inflight
        .compare_exchange(false, true, Ordering::AcqRel, Ordering::Acquire)
        .is_err()
    {
        return;
    }

    tokio::spawn(async move {
        refill_idle_pool_best_effort(&pool, ctrl_ring.clone(), virtual_size).await;
        pool.refill_inflight.store(false, Ordering::Release);

        if matches!(
            pool.idle.compute_maintenance_action(pool.idle.len()),
            PoolMaintenanceAction::Fill(_)
        ) {
            schedule_idle_pool_refill(pool, ctrl_ring, virtual_size);
        }
    });
}


Each cycle is: `add_dev` → `-EACCES` → one WARN → immediate recursive reschedule. The reschedule condition only checks whether the pool still needs filling; it never consults the failure result, and there is no backoff or failure cap. While the `Fill` target (100, from `high_watermark`) can never be satisfied under the kernel cap (64), this recurses at full speed — matching the observed ~14k attempts/second.

Steps to reproduce

  1. Start the server on a host with the default ublks_max = 64 and [pool.block] high_watermark above 64 (e.g. 100).
  2. Create enough sandboxes so that all 64 ublk slots are allocated (ls /dev/ublkc[0-9]* | wc -l reaches 64).
  3. Observe /var/lib/aenv/logs/ublk-daemon.log behavior while the idle pool is below target: it attempts add_dev, fails, and reschedules — indefinitely.

Expected behavior

  • Refill should back off and stop rescheduling when the kernel persistently refuses add_dev (persistent slot exhaustion), instead of retrying at full speed.
  • The daemon log should stay bounded.
  • Refilling should resume automatically once a slot becomes available.

Actual behavior

  • Disk exhaustion: the runaway log filled the filesystem to 100% usage; with no space left, creating new sandboxes fails outright — this alone breaks the service, even when ublk slots are still available.
  • The daemon retries add_dev at ~14k attempts/second. A 10,000-line sample from the live log spans 0.34 s; a tail -30 sample from the previous day shows the identical pattern (~85 µs per attempt).
  • The log file reached 18,310,529,024 bytes (~18.3 GB) by Sep 15 14:05. After a manual truncate, it regrew to 9.1 GiB in under 20 hours, with 1,579,118 "Permission denied" occurrences counted in that regrowth.
  • New/resumed sandboxes fail with HTTP 500 (reproduction section above).

Logs and diagnostics

Log location and how to observe:

- File: `/var/lib/aenv/logs/ublk-daemon.log` (written by `uvm-ublk-daemon`, running as the `aenv` service user)
- Size growth: `ls -lh /var/lib/aenv/logs/ublk-daemon.log`
- Repeating pattern: `tail -30 /var/lib/aenv/logs/ublk-daemon.log`
- Failure count: `grep -c "Permission denied" /var/lib/aenv/logs/ublk-daemon.log`
- Disk usage: `df -h /var/lib/aenv/logs`

Size history: **18,310,529,024 bytes (~18.3 GB)** on Sep 15 14:05; after a manual `truncate`, it regrew to **9.1 GiB in under 20 hours** (~11 GB/day at the storm rate), with **1,579,118** "Permission denied" occurrences in that regrowth.

Impact: the runaway log drove the filesystem to **100% usage** — with no space left, creating new sandboxes fails outright, independent of the `add_dev` EACCES above. This is not merely a logging nuisance.

Sample log pair repeating continuously (ANSI stripped):


2026-09-16T01:36:20.487913Z  INFO uvm_ublk::dev: try add_dev requested_dev_id=4294967295 zero_copy=false
2026-09-16T01:36:20.487972Z  WARN uvm_ublk_daemon::server: failed to refill idle overlaybd pool error=prewarm overlaybd pool device virtual_size=68719476736
2026-09-16T01:36:20.487984Z  INFO uvm_ublk::dev: try add_dev requested_dev_id=4294967295 zero_copy=false


The same pattern a day earlier (`tail -30`, Sep 15) — one full attempt every ~85 µs, stable across days:


2026-09-15T04:30:07.735296Z  INFO uvm_ublk::dev: try add_dev requested_dev_id=4294967295 zero_copy=false
2026-09-15T04:30:07.735363Z  WARN uvm_ublk_daemon::server: failed to refill idle overlaybd pool error=prewarm overlaybd pool device virtual_size=68719476736
2026-09-15T04:30:07.735382Z  INFO uvm_ublk::dev: try add_dev requested_dev_id=4294967295 zero_copy=false
2026-09-15T04:30:07.735449Z  WARN uvm_ublk_daemon::server: failed to refill idle overlaybd pool error=prewarm overlaybd pool device virtual_size=68719476736
2026-09-15T04:30:07.735467Z  INFO uvm_ublk::dev: try add_dev requested_dev_id=4294967295 zero_copy=false
2026-09-15T04:30:07.735533Z  WARN uvm_ublk_daemon::server: failed to refill idle overlaybd pool error=prewarm overlaybd pool device virtual_size=68719476736
2026-09-15T04:30:07.735552Z  INFO uvm_ublk::dev: try add_dev requested_dev_id=4294967295 zero_copy=false


System state at the time:

| Item | Value |
| --- | --- |
| Allocated ublk slots (`/dev/ublkc*`) | 64 / 64 (`ublks_max`) |
| Live block devices (`/dev/ublkb*`, `/sys/block/ublkb*`) | 58 |
| Leaked slots (char node exists, no block device, no owning process) | 6 (ids 0, 1, 2, 3, 4, 6) |

Reproduction frequency

Always

Regression information

No response

Additional context

No response

Pre-submission checklist

  • I searched existing open and closed issues and did not find a duplicate.
  • I provided a minimal reproduction or explained why one cannot be provided.
  • I removed credentials, tokens, private image references, and other sensitive information.
  • This is not a security vulnerability.
Originally created by @emailcannotbeblank on GitHub (Sep 16, 2026). Original GitHub issue: https://github.com/kvcache-ai/AgentENV/issues/297 ### Affected component ublk / ublk-daemon ### AgentENV version - Version or commit: `339e81b` (`fix(tools-image): bootstrap required paths for minimal images`), main branch - Local modifications: none. ### Host environment - OS: openEuler 24.03 (LTS-SP2) - Kernel (`uname -a`): `6.6.0-98.0.0.103.oe2403sp2.aarch64` - Architecture: aarch64 - Bare metal, VM, or cloud: bare metal - ublk support: `ublk_drv` module, version `6.6.0-98.0.0.103.oe2403sp2.aarch64` (ships with the kernel; the driver has no separate `MODULE_VERSION`); `ublks_max = 64` (module parameter, default, not resizable while devices are in use); device nodes `/dev/ublkcN` (char) and `/dev/ublkbN` (block) - CPU: 320 cores (aarch64) - Memory: 502 GiB - Storage/filesystem: ext4 ### Operation and configuration ```shell [pool.block] high_watermark = 100 # exceeds kernel ublks_max = 64 startup_prewarm = true Once all 64 ublk device slots are allocated, every idle-pool refill attempt calls `add_dev`, which the kernel rejects. The daemon logs the failure and immediately reschedules, retrying forever. The original implementation (`storage/ublk-daemon/src/server.rs` @ `339e81b`, verbatim): fn schedule_idle_pool_refill( pool: Arc<PoolState>, ctrl_ring: IoRingHandle<io_uring::squeue::Entry128>, virtual_size: u64, ) { if pool .refill_inflight .compare_exchange(false, true, Ordering::AcqRel, Ordering::Acquire) .is_err() { return; } tokio::spawn(async move { refill_idle_pool_best_effort(&pool, ctrl_ring.clone(), virtual_size).await; pool.refill_inflight.store(false, Ordering::Release); if matches!( pool.idle.compute_maintenance_action(pool.idle.len()), PoolMaintenanceAction::Fill(_) ) { schedule_idle_pool_refill(pool, ctrl_ring, virtual_size); } }); } Each cycle is: `add_dev` → `-EACCES` → one WARN → immediate recursive reschedule. The reschedule condition only checks whether the pool still needs filling; it never consults the failure result, and there is no backoff or failure cap. While the `Fill` target (100, from `high_watermark`) can never be satisfied under the kernel cap (64), this recurses at full speed — matching the observed ~14k attempts/second. ``` ### Steps to reproduce 1. Start the server on a host with the default `ublks_max = 64` and `[pool.block] high_watermark` above 64 (e.g. 100). 2. Create enough sandboxes so that all 64 ublk slots are allocated (`ls /dev/ublkc[0-9]* | wc -l` reaches 64). 3. Observe `/var/lib/aenv/logs/ublk-daemon.log` behavior while the idle pool is below target: it attempts `add_dev`, fails, and reschedules — indefinitely. ### Expected behavior - Refill should back off and stop rescheduling when the kernel persistently refuses `add_dev` (persistent slot exhaustion), instead of retrying at full speed. - The daemon log should stay bounded. - Refilling should resume automatically once a slot becomes available. ### Actual behavior - **Disk exhaustion:** the runaway log filled the filesystem to **100% usage**; with no space left, creating new sandboxes fails outright — this alone breaks the service, even when ublk slots are still available. - The daemon retries `add_dev` at ~14k attempts/second. A 10,000-line sample from the live log spans 0.34 s; a `tail -30` sample from the previous day shows the identical pattern (~85 µs per attempt). - The log file reached **18,310,529,024 bytes (~18.3 GB)** by Sep 15 14:05. After a manual `truncate`, it regrew to **9.1 GiB in under 20 hours**, with **1,579,118** "Permission denied" occurrences counted in that regrowth. - New/resumed sandboxes fail with HTTP 500 (reproduction section above). ### Logs and diagnostics ```text Log location and how to observe: - File: `/var/lib/aenv/logs/ublk-daemon.log` (written by `uvm-ublk-daemon`, running as the `aenv` service user) - Size growth: `ls -lh /var/lib/aenv/logs/ublk-daemon.log` - Repeating pattern: `tail -30 /var/lib/aenv/logs/ublk-daemon.log` - Failure count: `grep -c "Permission denied" /var/lib/aenv/logs/ublk-daemon.log` - Disk usage: `df -h /var/lib/aenv/logs` Size history: **18,310,529,024 bytes (~18.3 GB)** on Sep 15 14:05; after a manual `truncate`, it regrew to **9.1 GiB in under 20 hours** (~11 GB/day at the storm rate), with **1,579,118** "Permission denied" occurrences in that regrowth. Impact: the runaway log drove the filesystem to **100% usage** — with no space left, creating new sandboxes fails outright, independent of the `add_dev` EACCES above. This is not merely a logging nuisance. Sample log pair repeating continuously (ANSI stripped): 2026-09-16T01:36:20.487913Z INFO uvm_ublk::dev: try add_dev requested_dev_id=4294967295 zero_copy=false 2026-09-16T01:36:20.487972Z WARN uvm_ublk_daemon::server: failed to refill idle overlaybd pool error=prewarm overlaybd pool device virtual_size=68719476736 2026-09-16T01:36:20.487984Z INFO uvm_ublk::dev: try add_dev requested_dev_id=4294967295 zero_copy=false The same pattern a day earlier (`tail -30`, Sep 15) — one full attempt every ~85 µs, stable across days: 2026-09-15T04:30:07.735296Z INFO uvm_ublk::dev: try add_dev requested_dev_id=4294967295 zero_copy=false 2026-09-15T04:30:07.735363Z WARN uvm_ublk_daemon::server: failed to refill idle overlaybd pool error=prewarm overlaybd pool device virtual_size=68719476736 2026-09-15T04:30:07.735382Z INFO uvm_ublk::dev: try add_dev requested_dev_id=4294967295 zero_copy=false 2026-09-15T04:30:07.735449Z WARN uvm_ublk_daemon::server: failed to refill idle overlaybd pool error=prewarm overlaybd pool device virtual_size=68719476736 2026-09-15T04:30:07.735467Z INFO uvm_ublk::dev: try add_dev requested_dev_id=4294967295 zero_copy=false 2026-09-15T04:30:07.735533Z WARN uvm_ublk_daemon::server: failed to refill idle overlaybd pool error=prewarm overlaybd pool device virtual_size=68719476736 2026-09-15T04:30:07.735552Z INFO uvm_ublk::dev: try add_dev requested_dev_id=4294967295 zero_copy=false System state at the time: | Item | Value | | --- | --- | | Allocated ublk slots (`/dev/ublkc*`) | 64 / 64 (`ublks_max`) | | Live block devices (`/dev/ublkb*`, `/sys/block/ublkb*`) | 58 | | Leaked slots (char node exists, no block device, no owning process) | 6 (ids 0, 1, 2, 3, 4, 6) | ``` ### Reproduction frequency Always ### Regression information _No response_ ### Additional context _No response_ ### Pre-submission checklist - [x] I searched existing open and closed issues and did not find a duplicate. - [x] I provided a minimal reproduction or explained why one cannot be provided. - [x] I removed credentials, tokens, private image references, and other sensitive information. - [x] This is not a security vulnerability.
bsakaguchi 2026-10-29 14:19:19 +00:00
  • closed this issue
  • added the
    bug
         label
bsakaguchi commented 2026-10-29 14:19:20 +00:00
Author
Owner
Copy link

@yingdi-shan commented on GitHub (Sep 16, 2026):

Could you please upgrade your kernel to see if the problem still exist?

<!-- gh-comment-id:5695154940 --> @yingdi-shan commented on GitHub (Sep 16, 2026): Could you please upgrade your kernel to see if the problem still exist?
bsakaguchi commented 2026-10-29 14:19:20 +00:00
Author
Owner
Copy link

@emailcannotbeblank commented on GitHub (Sep 16, 2026):

Could you please upgrade your kernel to see if the problem still exist?

In general, the semantics of ublks_max differ by kernel version:

  • On Linux 6.3–6.14, ublks_max limits the total number of ublk devices.
  • On Linux 6.15+, ublks_max limits only unprivileged ublk devices.

On older kernels where ublks_max is the global ublk device limit, if high_watermark > ublks_max, the ublk-daemon can get stuck in a tight loop:

schedule_idle_pool_refill → refill failure → immediate retry.

Each failed retry emits log entries, so the log file keeps growing until it can eventually exhaust the filesystem.

From the code path, this issue specifically applies to kernels with the older ublks_max semantics, together with a configuration where high_watermark > ublks_max.

<!-- gh-comment-id:5695426888 --> @emailcannotbeblank commented on GitHub (Sep 16, 2026): > Could you please upgrade your kernel to see if the problem still exist? In general, the semantics of `ublks_max` differ by kernel version: * On Linux 6.3–6.14, `ublks_max` limits the total number of ublk devices. * On Linux 6.15+, `ublks_max` limits only unprivileged ublk devices. On older kernels where `ublks_max` is the global ublk device limit, if `high_watermark > ublks_max`, the `ublk-daemon` can get stuck in a tight loop: `schedule_idle_pool_refill` → refill failure → immediate retry. Each failed retry emits log entries, so the log file keeps growing until it can eventually exhaust the filesystem. From the code path, this issue specifically applies to kernels with the older `ublks_max` semantics, together with a configuration where `high_watermark > ublks_max`.
Sign in to join this conversation.
No Branch/Tag specified
Branches Tags
main
coverage-data
gh-pages
v0.3.0-rc.1
v0.2.4
v0.2.3
v0.2.2
v0.2.1
v0.2.0
v0.1.3
v0.1.2
v0.1.1
v0.1.0
Labels
Clear labels   
bug

   
documentation

   
enhancement

   
enhancement

   
pull-request
Mirrored from GitHub Pull Request

No labels
bug
documentation
enhancement
enhancement
pull-request
Milestone
Clear milestone
No items
No milestone
Projects
Clear projects
No items
No project
Assignees
Clear assignees
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
kvcache-ai/AgentENV#80
No description provided.