Skip to content

test_cache_CacheDir unit test got timeout on a CI job #13698

Open
Open
test_cache_CacheDir unit test got timeout on a CI job#13698
Labels
CacheTests

Description

@masaori335
masaori335
opened on Sep 16, 2026

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

Activity

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

Metadata

Metadata

Assignees

No one assigned

    Labels

    CacheTests

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions