Metacache producer failed

Describe the bug
When I was testing the disk container with 4 rustfs nodes (12 * 7TB) for storage space.
Using the local TensorFlow to read the local directory: (144.5 G and 137891 files) and writing to rustfs. A large number of errors occurred, but all the files were uploaded successfully.
However, when I checked the rustfs log, the background kept continuously outputting ERROR logs.

To Reproduce
my test python

import os
import time
import glob
from concurrent.futures import ThreadPoolExecutor
import tensorflow as tf
import tensorflow_io as tfio  

LOCAL_SRC_DIR = "/data1/test_data/tianmu"  # 本地真实小文件目录

# 测试目标 (二选一进行测试):
# 1. RustFS (S3 路径)
TARGET_BASE_PATH = "s3://benchmark-bucket/tianmu_tf_raw"
# 2. HDFS 路径 (如果测试 HDFS，取消下一行的注释并填入你的 HDFS 地址)
# TARGET_BASE_PATH = "hdfs://10.x.x.x:9000/tmp/tianmu_tf_raw"

CONCURRENCY = 32  # 并发写入线程数 (TF 默认原生写 S3 极其消耗 RTT，需要开并发)

# RustFS / S3 环境变量配置
os.environ["S3_ENDPOINT"] = "rust-work.yy.com"
os.environ["AWS_ACCESS_KEY_ID"] = "accessrustfsadmin"
os.environ["AWS_SECRET_ACCESS_KEY"] = "secretrustfsadmin"
os.environ["S3_USE_HTTPS"] = "0"
# ============================================

def process_and_write_single_file(local_path):
    """使用原生 TensorFlow API 读取本地小文件并写入目标存储"""
    relative_path = os.path.relpath(local_path, LOCAL_SRC_DIR)
    target_path = os.path.join(TARGET_BASE_PATH, relative_path)
    
    # 1. 本地文件大小
    file_size = os.path.getsize(local_path)
    
    # 2. 使用 TF 原生 API 读取本地文件内容 (TensorFlow Tensor 形式)
    file_content = tf.io.read_file(local_path)
    
    # 3. 使用 TF 原生 API 直接写入 RustFS / HDFS
    tf.io.write_file(target_path, file_content)
    
    return file_size

def run_tf_raw_benchmark():
    print(f"🔍 [TF 原生压测] 正在扫描本地文件目录: {LOCAL_SRC_DIR}...")
    all_files = [f for f in glob.glob(f"{LOCAL_SRC_DIR}/**/*", recursive=True) if os.path.isfile(f)]
    total_files = len(all_files)
    total_bytes = sum(os.path.getsize(f) for f in all_files)
    
    print(f"✅ 扫描完成！共计 {total_files} 个文件，总体积: {total_bytes / (1024**3):.2f} GB")
    print(f"🚀 开始跑 TF 原生小文件写入 (目标: {TARGET_BASE_PATH} | 并发数: {CONCURRENCY})...")

    start_time = time.time()
    completed_files = 0
    uploaded_bytes = 0

    # 使用 Python 线程池驱动 TensorFlow API 实现并发小文件写入
    with ThreadPoolExecutor(max_workers=CONCURRENCY) as executor:
        futures = [executor.submit(process_and_write_single_file, filepath) for filepath in all_files]
        for future in futures:
            file_size = future.result()
            uploaded_bytes += file_size
            completed_files += 1
            
            if completed_files % 5000 == 0 or completed_files == total_files:
                elapsed = time.time() - start_time
                rps = completed_files / elapsed
                mbps = (uploaded_bytes / (1024**2)) / elapsed
                print(f" 进度: [{completed_files}/{total_files}] | 实时 RPS: {rps:.1f} 文件/秒 | 吞吐: {mbps:.2f} MB/s")

    total_time = time.time() - start_time
    avg_rps = total_files / total_time
    avg_mbps = (total_bytes / (1024**2)) / total_time

    print("=" * 60)
    print(f"🎉 TensorFlow 原生小文件写入压测完成！")
    print(f"⏱️ 总耗时   : {total_time:.2f} 秒")
    print(f"⚡ 处理 QPS  : {avg_rps:.2f} 文件/秒 (RPS)")
    print(f"🚀 平均吞吐 : {avg_mbps:.2f} MB/s")
    print("=" * 60)

if __name__ == "__main__":
    run_tf_raw_benchmark()

Expected behavior
Error logs should not be continuously output.

{"timestamp":"2026-07-23T17:54:53.288538393+08:00","level":"ERROR","message":"Metacache producer failed","event":"metacache_listing","component":"ecstore","subsystem":"metacache","state":"producer_failed","error":"DiskOngoingReq","target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":810,"threadName":"rustfs-worker","threadId":"ThreadId(200)"}

environment

linux: ubuntu22.04
Version (version: master 20260708 git pull https://github.com/rustfs/rustfs.git)

Additional context
rustfs.log

start ERROR：Metacache producer failed","event
{"timestamp":"2026-07-23T17:04:09.058942181+08:00","level":"ERROR","message":"Scanner bucket cache save failed","event":"scanner_cache_persist_state","component":"scanner","subsystem":"io","bucket":"tf-profiler-benchmark","cache_name
":"tf-profiler-benchmark/.usage-cache.bin","state":"save_failed","error":"Lock error: Lock acquisition timeout for resource '.rustfs.sys/buckets/tf-profiler-benchmark/.usage-cache.bin@latest' after 5s","target":"rustfs::scanner::io",
"filename":"crates/scanner/src/scanner_io.rs","line_number":1369,"threadName":"rustfs-worker","threadId":"ThreadId(114)"}
{"timestamp":"2026-07-23T17:04:09.05899336+08:00","level":"ERROR","message":"Scanner bucket cache save failed","event":"scanner_cache_persist_state","component":"scanner","subsystem":"io","bucket":"tf-profiler-benchmark","cache_name"
:"tf-profiler-benchmark/.usage-cache.bin","state":"save_failed","error":"Lock error: Lock acquisition timeout for resource '.rustfs.sys/buckets/tf-profiler-benchmark/.usage-cache.bin@latest' after 5s","target":"rustfs::scanner::io","
filename":"crates/scanner/src/scanner_io.rs","line_number":1369,"threadName":"rustfs-worker","threadId":"ThreadId(143)"}
{"timestamp":"2026-07-23T17:04:24.159410389+08:00","level":"ERROR","message":"save_config_with_opts: err: Lock(Timeout { resource: \".rustfs.sys/buckets/b001/.usage-cache.bin@latest\", timeout: 5s }), file: buckets/b001/.usage-cache.
bin","target":"rustfs_ecstore::config::com","filename":"crates/ecstore/src/config/com.rs","line_number":414,"threadName":"rustfs-worker","threadId":"ThreadId(165)"}
{"timestamp":"2026-07-23T17:04:24.159423526+08:00","level":"ERROR","message":"save_config_with_opts: err: Lock(Timeout { resource: \".rustfs.sys/buckets/b001/.usage-cache.bin@latest\", timeout: 5s }), file: buckets/b001/.usage-cache.
bin","target":"rustfs_ecstore::config::com","filename":"crates/ecstore/src/config/com.rs","line_number":414,"threadName":"rustfs-worker","threadId":"ThreadId(201)"}
{"timestamp":"2026-07-23T17:04:24.159462135+08:00","level":"ERROR","message":"Scanner bucket cache save failed","event":"scanner_cache_persist_state","component":"scanner","subsystem":"io","bucket":"b001","cache_name":"b001/.usage-ca
che.bin","state":"save_failed","error":"Lock error: Lock acquisition timeout for resource '.rustfs.sys/buckets/b001/.usage-cache.bin@latest' after 5s","target":"rustfs::scanner::io","filename":"crates/scanner/src/scanner_io.rs","line
_number":1369,"threadName":"rustfs-worker","threadId":"ThreadId(165)"}
{"timestamp":"2026-07-23T17:04:24.159477638+08:00","level":"ERROR","message":"Scanner bucket cache save failed","event":"scanner_cache_persist_state","component":"scanner","subsystem":"io","bucket":"b001","cache_name":"b001/.usage-ca
che.bin","state":"save_failed","error":"Lock error: Lock acquisition timeout for resource '.rustfs.sys/buckets/b001/.usage-cache.bin@latest' after 5s","target":"rustfs::scanner::io","filename":"crates/scanner/src/scanner_io.rs","line
_number":1369,"threadName":"rustfs-worker","threadId":"ThreadId(201)"}
{"timestamp":"2026-07-23T17:04:24.159586264+08:00","level":"ERROR","message":"save_config_with_opts: err: Lock(Timeout { resource: \".rustfs.sys/buckets/b001/.usage-cache.bin@latest\", timeout: 5s }), file: buckets/b001/.usage-cache.
bin","target":"rustfs_ecstore::config::com","filename":"crates/ecstore/src/config/com.rs","line_number":414,"threadName":"rustfs-worker","threadId":"ThreadId(186)"}
{"timestamp":"2026-07-23T17:04:24.159640226+08:00","level":"ERROR","message":"Scanner bucket cache save failed","event":"scanner_cache_persist_state","component":"scanner","subsystem":"io","bucket":"b001","cache_name":"b001/.usage-ca
che.bin","state":"save_failed","error":"Lock error: Lock acquisition timeout for resource '.rustfs.sys/buckets/b001/.usage-cache.bin@latest' after 5s","target":"rustfs::scanner::io","filename":"crates/scanner/src/scanner_io.rs","line
_number":1369,"threadName":"rustfs-worker","threadId":"ThreadId(186)"}
{"timestamp":"2026-07-23T17:04:53.285405398+08:00","level":"ERROR","message":"Metacache producer failed","event":"metacache_listing","component":"ecstore","subsystem":"metacache","state":"producer_failed","error":"DiskOngoingReq","target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":810,"threadName":"rustfs-worker","threadId":"ThreadId(180)"}
{"timestamp":"2026-07-23T17:04:53.285453276+08:00","level":"ERROR","message":"Metacache producer failed","event":"metacache_listing","component":"ecstore","subsystem":"metacache","state":"producer_failed","error":"DiskOngoingReq","target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":810,"threadName":"rustfs-worker","threadId":"ThreadId(180)"}
{"timestamp":"2026-07-23T17:04:53.285475247+08:00","level":"ERROR","message":"Metacache producer failed","event":"metacache_listing","component":"ecstore","subsystem":"metacache","state":"producer_failed","error":"DiskOngoingReq","target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":810,"threadName":"rustfs-worker","threadId":"ThreadId(180)"}

..... Output once every minute

{"timestamp":"2026-07-23T17:54:53.288538393+08:00","level":"ERROR","message":"Metacache producer failed","event":"metacache_listing","component":"ecstore","subsystem":"metacache","state":"producer_failed","error":"DiskOngoingReq","target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":810,"threadName":"rustfs-worker","threadId":"ThreadId(200)"}
{"timestamp":"2026-07-23T17:54:53.288590174+08:00","level":"ERROR","message":"Metacache producer failed","event":"metacache_listing","component":"ecstore","subsystem":"metacache","state":"producer_failed","error":"DiskOngoingReq","target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":810,"threadName":"rustfs-worker","threadId":"ThreadId(200)"}
{"timestamp":"2026-07-23T17:54:53.288609379+08:00","level":"ERROR","message":"Metacache producer failed","event":"metacache_listing","component":"ecstore","subsystem":"metacache","state":"producer_failed","error":"DiskOngoingReq","target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":810,"threadName":"rustfs-worker","threadId":"ThreadId(200)"}
{"timestamp":"2026-07-23T17:54:53.288630632+08:00","level":"ERROR","message":"Metacache producer failed","event":"metacache_listing","component":"ecstore","subsystem":"metacache","state":"producer_failed","error":"DiskOngoingReq","target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":810,"threadName":"rustfs-worker","threadId":"ThreadId(200)"}
{"timestamp":"2026-07-23T17:54:53.28934324+08:00","level":"ERROR","message":"Metacache producer failed","event":"metacache_listing","component":"ecstore","subsystem":"metacache","state":"producer_failed","error":"DiskOngoingReq","target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":810,"threadName":"rustfs-worker","threadId":"ThreadId(94)"}
{"timestamp":"2026-07-23T17:54:53.289383317+08:00","level":"ERROR","message":"Metacache producer failed","event":"metacache_listing","component":"ecstore","subsystem":"metacache","state":"producer_failed","error":"DiskOngoingReq","target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":810,"threadName":"rustfs-worker","threadId":"ThreadId(94)"}
{"timestamp":"2026-07-23T17:54:53.289398959+08:00","level":"ERROR","message":"Metacache producer failed","event":"metacache_listing","component":"ecstore","subsystem":"metacache","state":"producer_failed","error":"DiskOngoingReq","target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":810,"threadName":"rustfs-worker","threadId":"ThreadId(94)"}
{"timestamp":"2026-07-23T17:54:53.289417142+08:00","level":"ERROR","message":"Metacache producer failed","event":"metacache_listing","component":"ecstore","subsystem":"metacache","state":"producer_failed","error":"DiskOngoingReq","target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":810,"threadName":"rustfs-worker","threadId":"ThreadId(94)"}
{"timestamp":"2026-07-23T17:54:53.289473008+08:00","level":"ERROR","message":"Metacache producer failed","event":"metacache_listing","component":"ecstore","subsystem":"metacache","state":"producer_failed","error":"DiskOngoingReq","target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":810,"threadName":"rustfs-worker","threadId":"ThreadId(77)"}
{"timestamp":"2026-07-23T17:54:53.289512344+08:00","level":"ERROR","message":"Metacache producer failed","event":"metacache_listing","component":"ecstore","subsystem":"metacache","state":"producer_failed","error":"DiskOngoingReq","target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":810,"threadName":"rustfs-worker","threadId":"ThreadId(77)"}
{"timestamp":"2026-07-23T17:54:53.289533003+08:00","level":"ERROR","message":"Metacache producer failed","event":"metacache_listing","component":"ecstore","subsystem":"metacache","state":"producer_failed","error":"DiskOngoingReq","target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":810,"threadName":"rustfs-worker","threadId":"ThreadId(77)"}
{"timestamp":"2026-07-23T17:54:53.289552093+08:00","level":"ERROR","message":"Metacache producer failed","event":"metacache_listing","component":"ecstore","subsystem":"metacache","state":"producer_failed","error":"DiskOngoingReq","target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":810,"threadName":"rustfs-worker","threadId":"ThreadId(77)"}

I checked all the disk monitoring and found that the IO has stopped being used. It's not a problem with the hardware resources. It must be an issue with rustfs itself.

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Metacache producer failed #5156

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Search code, repositories, users, issues, pull requests...

Uh oh!

Metacache producer failed #5156

Description

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions