test_cache_CacheDir unit test got timeout on a CI job

Open

#13,698 opened on Sep 16, 2026 0 comments 0 reactions 1 assignee View on GitHub

Nobody has claimed this yet.

Assessment

Difficulty: 4/5
Estimated time: 3-5 days
Newbie friendliness: 45/100

Issue type: Bug
Clarity: Mostly clear
Activity status: Active
Tech stack: cpp
Domain: backend, testing-qa

Research direction

Start with the CacheDir test in src/iocore/cache/unit_tests/test_CacheDir.cc, especially the cache_init_success_callback path and its corrupt_bucket test. Reproduce the filtered CacheDir test on the Debian configuration, then inspect the lock wait at CacheDir.cc:1010 and the repeated check calls in CacheDir.cc:300. Done means the test completes without timing out and still validates the cache directory behavior.

Written by the indexing model from the issue text.

Description

Cache Tests

Debian PRB failed.

1070/1070 Test  #478: test_cache_CacheDir.CacheDir ......................................................................................................................................................***Timeout 1500.00 sec
...
Filters: "CacheDir"
Randomness seeded to: 2015928407
[Sep 16 01:45:49.487] CacheDir DIAG: <Cache.cc:864 (ink_cache_init)> (cache_init) proxy.config.cache.ram_cache.size = -1 = 0Mb
[Sep 16 01:45:49.488] CacheDir DIAG: <Cache.cc:881 (ink_cache_init)> (cache_init) proxy.config.cache.limits.http.max_alts = 5
[Sep 16 01:45:49.488] CacheDir DIAG: <Cache.cc:884 (ink_cache_init)> (cache_init) proxy.config.cache.log.alternate.eviction = 0
[Sep 16 01:45:49.488] CacheDir DIAG: <Cache.cc:887 (ink_cache_init)> (cache_init) cache_config_ram_cache_cutoff = 4194304 = 4Mb
[Sep 16 01:45:49.488] CacheDir DIAG: <Cache.cc:891 (ink_cache_init)> (cache_init) proxy.config.cache.permit.pinning = 0
[Sep 16 01:45:49.489] CacheDir DIAG: <Cache.cc:894 (ink_cache_init)> (cache_init) proxy.config.cache.dir.sync_frequency = 60
[Sep 16 01:45:49.489] CacheDir DIAG: <Cache.cc:897 (ink_cache_init)> (cache_init) proxy.config.cache.dir.sync_delay = 500
[Sep 16 01:45:49.489] CacheDir DIAG: <Cache.cc:900 (ink_cache_init)> (cache_init) proxy.config.cache.dir.sync_max_write = 2097152
[Sep 16 01:45:49.489] CacheDir DIAG: <Cache.cc:903 (ink_cache_init)> (cache_init) proxy.config.cache.select_alternate = 1
[Sep 16 01:45:49.489] CacheDir DIAG: <Cache.cc:906 (ink_cache_init)> (cache_init) proxy.config.cache.max_doc_size = 0 = 0Mb
[Sep 16 01:45:49.489] CacheDir DIAG: <Cache.cc:910 (ink_cache_init)> (cache_init) proxy.config.cache.mutex_retry_delay = 2ms
[Sep 16 01:45:49.489] CacheDir DIAG: <Cache.cc:913 (ink_cache_init)> (cache_init) proxy.config.cache.read_while_writer.max_retries = 10
[Sep 16 01:45:49.490] CacheDir DIAG: <Cache.cc:916 (ink_cache_init)> (cache_init) proxy.config.cache.read_while_writer_retry.delay = 50ms
[Sep 16 01:45:49.490] CacheDir DIAG: <Cache.cc:919 (ink_cache_init)> (cache_init) proxy.config.cache.hit_evacuate_percent = 0
[Sep 16 01:45:49.490] CacheDir DIAG: <Cache.cc:922 (ink_cache_init)> (cache_init) proxy.config.cache.hit_evacuate_size_limit = 0
[Sep 16 01:45:49.490] CacheDir DIAG: <Cache.cc:937 (ink_cache_init)> (cache_init) proxy.config.cache.max_disk_errors = 5
[Sep 16 01:45:49.490] CacheDir DIAG: <Cache.cc:940 (ink_cache_init)> (cache_init) proxy.config.cache.agg_write_backlog = 5242880
[Sep 16 01:45:49.490] CacheDir DIAG: <Cache.cc:943 (ink_cache_init)> (cache_init) proxy.config.cache.enable_checksum = 0
[Sep 16 01:45:49.491] CacheDir DIAG: <Cache.cc:946 (ink_cache_init)> (cache_init) proxy.config.cache.alt_rewrite_max_size = 4096
[Sep 16 01:45:49.491] CacheDir DIAG: <Cache.cc:951 (ink_cache_init)> (cache_init) proxy.config.cache.enable_read_while_writer = 1
[Sep 16 01:45:49.494] CacheDir DIAG: <Cache.cc:958 (ink_cache_init)> (cache_init) proxy.config.cache.dir.sync_parallel_tasks = 1
[Sep 16 01:45:49.495] CacheDir DIAG: <Cache.cc:961 (ink_cache_init)> (cache_init) proxy.config.cache.persist_bad_disks = 0
[Sep 16 01:45:49.495] CacheDir NOTE: storage.yaml loading ...
[Sep 16 01:45:49.499] CacheDir DIAG: <Store.cc:274 (read_config)> (cache_init) Span name="disk-1" path="var/trafficserver" size=268435456 hash_seed=
[Sep 16 01:45:49.499] CacheDir DIAG: <Store.cc:484 (init)> (cache_init) initialized span '/tmp/cachetest.4gRbGk/var/trafficserver'
[Sep 16 01:45:49.499] CacheDir DIAG: <Store.cc:485 (init)> (cache_init) hw_sector_size=4096, size=268435456, blocks=32768, disk_id=66/8539654, file_pathname=0
[Sep 16 01:45:49.499] CacheDir NOTE: storage.yaml finished loading
[Sep 16 01:45:49.499] CacheDir DIAG: <CacheShm.cc:563 (initialize)> (cache_shm) shm disabled
[Sep 16 01:45:49.503] CacheDir DIAG: <CacheProcessor.cc:378 (start_internal)> (cache_hosting) Disk: 1:/tmp/cachetest.4gRbGk/var/trafficserver/cache.db, blocks: 32767
[Sep 16 01:45:49.504] [ET_NET 0] WARNING: disk header different for disk /tmp/cachetest.4gRbGk/var/trafficserver/cache.db: clearing the disk
[Sep 16 01:45:49.506] [ET_NET 0] NOTE: Clearing Disk: /tmp/cachetest.4gRbGk/var/trafficserver/cache.db
[Sep 16 01:45:49.506] [ET_NET 0] DIAG: <CacheProcessor.cc:861 (cplist_reconfigure)> (cache_hosting) blocks = 32766
[Sep 16 01:45:49.507] [ET_NET 0] DIAG: <CacheProcessor.cc:809 (diskInitialized)> (cache_hosting) Disk: 0:/tmp/cachetest.4gRbGk/var/trafficserver/cache.db: Stripe Blocks: 1: Free space: 0
[Sep 16 01:45:49.507] [ET_NET 0] DIAG: <CacheProcessor.cc:812 (diskInitialized)> (cache_hosting) 	Stripe: 0 Size: 32766
[Sep 16 01:45:49.507] [ET_NET 0] DIAG: <CacheProcessor.cc:815 (diskInitialized)> (cache_hosting) 	Block No: 0 Size: 32766 Free: 0
[Sep 16 01:45:49.507] [ET_NET 0] DIAG: <Cache.cc:303 (open)> (cache_init) Cache::open - proxy.config.cache.min_average_object_size = 8000
[Sep 16 01:45:49.508] [ET_NET 0] DIAG: <Stripe.cc:155 (_init_directory)> (cache_init) Stripe /tmp/cachetest.4gRbGk/var/trafficserver/cache.db 16384:32766: allocating 352256 directory bytes for a 268419072 byte volume (0.131234%)
[Sep 16 01:45:49.508] [ET_NET 0] NOTE: clearing cache directory '/tmp/cachetest.4gRbGk/var/trafficserver/cache.db 16384:32766'
[Sep 16 01:45:49.520] [ET_NET 0] WARNING: Cannot open the config file: /home/jenkins/workspace/Github_Builds/debian/src/src/iocore/cache/unit_tests/etc/hosting.config - No such file or directory
[Sep 16 01:45:49.520] [ET_NET 0] NOTE: hosting.config loading ...
[Sep 16 01:45:49.520] [ET_NET 0] DIAG: <CacheHosting.cc:425 (Init)> (cache_hosting) Host Record: 0x7f596c0090f8, Volume: 0, size: 32766
[Sep 16 01:45:49.521] [ET_NET 0] DIAG: <CacheProcessor.cc:638 (build_vol_hash_table)> (cache_init) build_vol_hash_table index 0 mapped to 0 requested 32707 got 32707
[Sep 16 01:45:49.521] [ET_NET 0] DIAG: <CacheProcessor.cc:1475 (cacheInitialized)> (cache_init) theCache, total_size = 32766 = 255 MB
[Sep 16 01:45:49.521] [ET_NET 0] DIAG: <CacheProcessor.cc:1506 (cacheInitialized)> (cache_init) CacheProcessor::cacheInitialized - caches_ready=0x9, gnvol=1
[Sep 16 01:45:49.521] [ET_NET 0] DIAG: <CacheProcessor.cc:1513 (cacheInitialized)> (cache_init) ram_cache algorithm = 1 (LRU)
[Sep 16 01:45:49.521] [ET_NET 0] DIAG: <CacheProcessor.cc:1557 (cacheInitialized)> (cache_init) cache_config_ram_cache_size == AUTO_SIZE_RAM_CACHE
[Sep 16 01:45:49.521] [ET_NET 0] DIAG: <CacheProcessor.cc:1648 (cacheInitialized)> (cache_init) CacheProcessor::cacheInitialized[0] - ram_cache_bytes = 3522560 = 3Mb
[Sep 16 01:45:49.522] [ET_NET 0] DIAG: <CacheProcessor.cc:1660 (cacheInitialized)> (cache_init) total_cache_bytes = 268066816 = 255Mb
[Sep 16 01:45:49.522] [ET_NET 0] NOTE: cache enabled
[Sep 16 01:45:49.526] CacheDir DIAG: <main.h:75 (start_event)> (cache_test) cache init successfully
[Sep 16 01:45:53.957] CacheDir DIAG: <test_CacheDir.cc:142 (cache_init_success_callback)> (cache_dir_test) insert rate = 4825610 / second
[Sep 16 01:45:53.969] CacheDir DIAG: <test_CacheDir.cc:155 (cache_init_success_callback)> (cache_dir_test) probe rate = 2163620 / second
[Sep 16 01:45:53.971] CacheDir WARNING: cache directory overflow on '/tmp/cachetest.4gRbGk/var/trafficserver/cache.db' segment 0, purging...
[Sep 16 01:45:53.975] CacheDir WARNING: cache directory overflow on '/tmp/cachetest.4gRbGk/var/trafficserver/cache.db' segment 0, purging...
[Sep 16 01:45:53.978] CacheDir WARNING: cache directory overflow on '/tmp/cachetest.4gRbGk/var/trafficserver/cache.db' segment 0, purging...
[Sep 16 01:45:53.981] CacheDir WARNING: cache directory overflow on '/tmp/cachetest.4gRbGk/var/trafficserver/cache.db' segment 0, purging...
[Sep 16 01:45:53.985] CacheDir WARNING: cache directory overflow on '/tmp/cachetest.4gRbGk/var/trafficserver/cache.db' segment 0, purging...
[Sep 16 01:45:53.988] CacheDir WARNING: cache directory overflow on '/tmp/cachetest.4gRbGk/var/trafficserver/cache.db' segment 0, purging...
[Sep 16 01:45:53.991] CacheDir WARNING: cache directory overflow on '/tmp/cachetest.4gRbGk/var/trafficserver/cache.db' segment 0, purging...
[Sep 16 01:45:53.995] CacheDir WARNING: cache directory overflow on '/tmp/cachetest.4gRbGk/var/trafficserver/cache.db' segment 0, purging...
[Sep 16 01:45:53.996] CacheDir DIAG: <test_CacheDir.cc:167 (cache_init_success_callback)> (cache_dir_test) corrupt_bucket test
[Sep 16 01:45:53.996] CacheDir DIAG: <CacheDir.cc:300 (check)> (cache_check_dir) inside check dir
[Sep 16 01:45:53.999] CacheDir DIAG: <CacheDir.cc:300 (check)> (cache_check_dir) inside check dir
[Sep 16 01:45:53.999] CacheDir DIAG: <CacheDir.cc:300 (check)> (cache_check_dir) inside check dir
[Sep 16 01:45:54.002] CacheDir DIAG: <CacheDir.cc:300 (check)> (cache_check_dir) inside check dir
[Sep 16 01:45:54.002] CacheDir DIAG: <CacheDir.cc:300 (check)> (cache_check_dir) inside check dir
[Sep 16 01:45:54.003] CacheDir DIAG: <CacheDir.cc:300 (check)> (cache_check_dir) inside check dir
[Sep 16 01:45:54.005] CacheDir DIAG: <CacheDir.cc:300 (check)> (cache_check_dir) inside check dir
[Sep 16 01:45:54.005] CacheDir DIAG: <CacheDir.cc:300 (check)> (cache_check_dir) inside check dir
[Sep 16 01:45:54.007] CacheDir DIAG: <CacheDir.cc:300 (check)> (cache_check_dir) inside check dir
WARNING: waiting on lock CacheDir.cc:1010 (mainEvent) for UNKNOWN
WARNING: waiting on lock CacheDir.cc:1010 (mainEvent) for UNKNOWN
WARNING: waiting on lock CacheDir.cc:1010 (mainEvent) for UNKNOWN
WARNING: waiting on lock CacheDir.cc:1010 (mainEvent) for UNKNOWN
WARNING: waiting on lock CacheDir.cc:1010 (mainEvent) for UNKNOWN
WARNING: waiting on lock CacheDir.cc:1010 (mainEvent) for UNKNOWN
WARNING: waiting on lock CacheDir.cc:1010 (mainEvent) for UNKNOWN
WARNING: waiting on lock CacheDir.cc:1010 (mainEvent) for UNKNOWN
WARNING: waiting on lock CacheDir.cc:1010 (mainEvent) for UNKNOWN
WARNING: waiting on lock CacheDir.cc:1010 (mainEvent) for UNKNOWN
WARNING: waiting on lock CacheDir.cc:1010 (mainEvent) for UNKNOWN
WARNING: waiting on lock CacheDir.cc:1010 (mainEvent) for UNKNOWN
WARNING: waiting on lock CacheDir.cc:1010 (mainEvent) for UNKNOWN
WARNING: waiting on lock CacheDir.cc:1010 (mainEvent) for UNKNOWN
WARNING: waiting on lock CacheDir.cc:1010 (mainEvent) for UNKNOWN
WARNING: waiting on lock CacheDir.cc:1010 (mainEvent) for UNKNOWN
...
...(loop of the same WARNING)

https://ci.trafficserver.apache.org/job/Github_Builds/job/debian/9557/consoleFull

Dominant language: C++
Stars: 2k
Forks: 877
Avg merge: 4d 18h
Merged PRs (30d): 52

Contributor guide

Open the contributing guide

First steps

Read the whole issue, then the project's contributing guide.
Comment on the issue to say you are picking it up — it saves two people doing the same work.
Fork the repository and make your change on a branch.
Open a pull request that references the issue number.

Similar issues

[Bug] NULL pointer dereference in llm_running_callback (NGZA-AX-LLM #3) Open

Difficulty 1/5 Under an hour Newbie friendliness 90/100

AXERA-TECH/ax-llm#77 · Opened Sep 22, 2026
resume() sends a second HTTP response (400) after a successful resume Open

Difficulty 1/5 Under an hour Newbie friendliness 90/100

games-on-whales/wolf#509 · Opened Sep 21, 2026
pn7160: reader goes permanently deaf — post-read IRQ-low check fails reads that succeeded Open

Difficulty 2/5 1-3 hours Newbie friendliness 74/100

esphome/esphome#19452 · Opened Sep 21, 2026
Eval bug: Ministral-3 tool-calls during reasoning are not processed Open

bug-unconfirmed

Difficulty 2/5 1-3 hours Newbie friendliness 76/100

ggml-org/llama.cpp#29248 · Opened Sep 21, 2026
run_tests.py fails on windows, but running tests individually works Open

Difficulty 2/5 1-3 hours Newbie friendliness 74/100

NVIDIA/cuda-samples#453 · Opened Sep 21, 2026

More C++ issues