Regression between 1.4.0 and 1.6.0 when overwriting files with --allow-overwrite enabled #862
Comments
|
Hey @thundergolfer, thank you for opening the bug report. The first thing I'd note is that v1.4.0 is recalled, and we would not recommend using it. Regarding the error message you received: v1.4.0 introduced file overwrites. One downside with the recall is that the behavior you were able to achieve - opening a file for both reading and writing simultaneously - is reverted with v1.4.1+ and is not permitted. We don't plan to allow that behavior to occur, although if that's important for you then I'd recommend opening a feature request for it so we can learn about your use case. That being said, I was not able to reproduce the issue you are experiencing with v1.6.0. I was able to run this code fine: # using Python 3.8.19
from pathlib import Path
TEST_FILE_PATH: Path = Path("/mnt/s3/test.txt")
for i in range(50):
TEST_FILE_PATH.write_text(f"Writing text for iteration {i}")I note in your example that the simple reproduction only appears to write to the file. Is that script definitely able to reproduce the issue for you? Could there be another application that has this file open for reading? |
If this is an issue, please do open a bug report for it with some reproduction steps. |
|
Hi @dannycjones, adding context regarding
We filed an issue here and solved here. 1.6.0 includes a fix for that issue that's why we upgraded. |
|
Thanks for the response @dannycjones. Interesting that you can't repro. Prompted me to check if it was due to container runtime and it is! If we run the program with Appendix This is the entirety of the Modal program for posterity. from pathlib import Path
from uuid import uuid4
import modal
MOUNT_PATH: Path = Path("/mnt/s3_bucket")
S3_BUCKET_TEST_PATH: Path = MOUNT_PATH / "synmon/test_file.txt"
app = modal.App(
volumes={
MOUNT_PATH: modal.CloudBucketMount(
"modal-s3mount-test-bucket",
secret=modal.Secret.from_name("cloud-bucket-mount-secret", environment_name="main"),
)
},
image=modal.Image.debian_slim(python_version="3.11"),
)
@app.function()
def write() -> str:
data = uuid4().hex
S3_BUCKET_TEST_PATH.write_text(data)
return data
if __name__ == "__main__":
with app.run():
write_data = write.remote() |
|
@dannycjones I've done some more investigation into the behavior difference between gVisor and runc. A gVisor trace of the reproduction program shows that it's only make 1 From mount-s3's debug logs though, I can see:
Full logs snippet (gvisor) With
|
The issue is that gVisor's gofer client (pkg/fsimpl/gofer/) opens the file I think we should change that logic to open regular files with O_PATH only. Directories and FIFOs can continue to be opened with O_RDONLY. |
|
@dannycjones Interested to know what the consequences of violating the concurrent read and write restriction would be. Is it just an inconsistent (empty) read? I've looked through these PRs because didn't gather the consequence:
|
|
Yeah, the reason we forbid this is that S3 doesn't allow reading from an inflight multi-part upload. So if you try reading concurrently, you'll observe the results of the new writes as long as they're still in the page cache, but then start seeing the old object again if they ever get evicted or dropped from cache. |
|
Ok opened google/gvisor#10389 in gvisor repo @ayushr2. @jamesbornholt happy for this to be closed on your end 🙂 . |
|
Glad that you have a path forward. I'm closing this issue as it's expected behavior in mountpoint. |
cc @luiscape
Mountpoint for Amazon S3 version
mount-s3 1.6.0
AWS Region
No response
Describe the running environment
Linux ip-10-1-1-198 5.15.0-1058-aws #64~20.04.1-Ubuntu SMP Tue Apr 9 11:12:27 UTC 2024 x86_64 x86_64 x86_64 GNU/Linux
Mountpoint options
What happened?
This trivial program produces the error:
If
S3_BUCKET_TEST_PATHalready exists we get this error:The key error log from mount-s3 is this:
If I downgrade to 1.4.0 this problem goes away. Version 1.5.0 also seems to have this bug.
We upgraded to 1.6.0 because 1.4.0 had a bug where listing the root of the mount twice failed.
Relevant log output
2024-04-30T21:57:23.744366Z INFO mountpoint_s3::cli: mount-s3 1.6.0 2024-04-30T21:57:23.744387Z DEBUG mountpoint_s3::cli: CliArgs { bucket_name: "modal-s3mount-test-bucket", mount_point: "/tmp/task-data-nDwLcA/ta-123abc/mountpoint-fpgEbu", prefix: None, region: None, endpoint_url: None, force_path_style: false, transfer_acceleration: false, dual_stack: false, requester_pays: false, bucket_type: None, no_sign_request: false, profile: None, read_only: false, storage_class: None, allow_delete: true, allow_overwrite: true, auto_unmount: false, allow_root: false, allow_other: false, maximum_throughput_gbps: None, max_threads: 16, part_size: 8388608, uid: None, gid: None, dir_mode: None, file_mode: None, foreground: false, expected_bucket_owner: None, log_directory: Some("/tmp/mount-s3/"), log_metrics: false, debug: true, debug_crt: false, no_log: false, cache: None, metadata_ttl: None, max_cache_size: None, user_agent_prefix: Some("modal-task-id-ta-123abc"), sse: None, sse_kms_key_id: None } 2024-04-30T21:57:23.751615Z DEBUG mountpoint_s3_client::instance_info: got instance info from IMDS identity_document=IdentityDocument { instance_type: "m6i.12xlarge", region: "us-east-1" } 2024-04-30T21:57:23.751823Z INFO mountpoint_s3::cli: target network throughput 18.75 Gbps 2024-04-30T21:57:23.751837Z DEBUG mountpoint_s3::cli: using instance region us-east-1 2024-04-30T21:57:23.814845Z DEBUG list_objects{id=0 bucket="modal-s3mount-test-bucket" continued=false delimiter="" max_keys="0" prefix=""}: mountpoint_s3_client::s3_crt_client::list_objects: new request 2024-04-30T21:57:23.842197Z DEBUG list_objects{id=0 bucket="modal-s3mount-test-bucket" continued=false delimiter="" max_keys="0" prefix=""}: mountpoint_s3_client::s3_crt_client: S3 request finished request_type=Default crt_error=None http_status=200 range=None duration=27.185409ms ttfb=Some(21.431496ms) request_id=SYJYK8CZNYT40T4X 2024-04-30T21:57:23.842295Z DEBUG list_objects{id=0 bucket="modal-s3mount-test-bucket" continued=false delimiter="" max_keys="0" prefix=""}: mountpoint_s3_client::s3_crt_client: meta request finished duration=27.405097ms 2024-04-30T21:57:23.844146Z INFO fuser::session: Mounting /tmp/task-data-nDwLcA/ta-01HWRG6BXQPV2495720REFPSSN/mountpoint-fpgEbu 2024-04-30T21:57:23.844723Z INFO mountpoint_s3::cli: successfully mounted bucket modal-s3mount-test-bucket at /tmp/task-data-nDwLcA/ta-123abc/mountpoint-fpgEbu 2024-04-30T21:57:23.844756Z DEBUG mountpoint_s3::fuse::session: starting fuse worker 0 (thread id 1076177) 2024-04-30T21:57:23.844787Z DEBUG mountpoint_s3::cli: success status flag received from child process 2024-04-30T21:57:23.844819Z DEBUG fuser::request: FUSE( 2) ino 0x0000000000000000 INIT kernel ABI 7.34, capabilities 0x33fffffb, max readahead 131072 2024-04-30T21:57:23.844865Z DEBUG fuser::request: INIT response: ABI 7.28, flags 0x402029, max readahead 131072, max write 16777216 2024-04-30T21:57:23.844874Z DEBUG mountpoint_s3::fuse::session: starting fuse worker 1 (thread id 1076178) 2024-04-30T21:57:23.922680Z DEBUG fuser::request: FUSE( 4) ino 0x0000000000000001 GETATTR 2024-04-30T21:57:23.974062Z DEBUG fuser::request: FUSE( 6) ino 0x0000000000000001 STATFS 2024-04-30T21:57:24.250443Z DEBUG fuser::request: FUSE( 8) ino 0x0000000000000001 OPENDIR flags 0x28800 2024-04-30T21:57:24.250541Z DEBUG fuser::request: FUSE( 10) ino 0x0000000000000001 RELEASEDIR fh FileHandle(1), flags 0x28800, flush false, lock owner None 2024-04-30T21:57:24.250619Z DEBUG fuser::request: FUSE( 12) ino 0x0000000000000001 OPENDIR flags 0x28800 2024-04-30T21:57:24.250683Z DEBUG fuser::request: FUSE( 14) ino 0x0000000000000001 OPENDIR flags 0x28800 2024-04-30T21:57:25.086239Z DEBUG fuser::request: FUSE( 16) ino 0x0000000000000001 LOOKUP name "synmon" 2024-04-30T21:57:25.088022Z DEBUG lookup{req=16 ino=1 name="synmon"}:head_object{id=1 bucket="modal-s3mount-test-bucket" key="synmon"}: mountpoint_s3_client::s3_crt_client::head_object: new request 2024-04-30T21:57:25.089553Z DEBUG lookup{req=16 ino=1 name="synmon"}:list_objects{id=2 bucket="modal-s3mount-test-bucket" continued=false delimiter="/" max_keys="1" prefix="synmon/"}: mountpoint_s3_client::s3_crt_client::list_objects: new request 2024-04-30T21:57:25.097718Z DEBUG lookup{req=16 ino=1 name="synmon"}:head_object{id=1 bucket="modal-s3mount-test-bucket" key="synmon"}: mountpoint_s3_client::s3_crt_client: S3 request failed request_type=Default crt_error=Some(Error(14343, "aws-c-s3: AWS_ERROR_S3_INVALID_RESPONSE_STATUS, Invalid response status from request")) http_status=404 range=None duration=9.551408ms ttfb=Some(9.291372ms) request_id=4MV4JAGTVBPMMSD2 2024-04-30T21:57:25.097807Z DEBUG lookup{req=16 ino=1 name="synmon"}:head_object{id=1 bucket="modal-s3mount-test-bucket" key="synmon"}: mountpoint_s3_client::s3_crt_client: duration=9.748663ms request_id=4MV4JAGTVBPMMSD2 error=ServiceError(NotFound) meta request failed 2024-04-30T21:57:25.097822Z DEBUG lookup{req=16 ino=1 name="synmon"}:head_object{id=1 bucket="modal-s3mount-test-bucket" key="synmon"}: mountpoint_s3_client::s3_crt_client: meta request result: MetaRequestResult { response_status: 404, crt_error: Error(14343, "aws-c-s3: AWS_ERROR_S3_INVALID_RESPONSE_STATUS, Invalid response status from request"), error_response_headers: Some(Headers { inner: 0x7f1a6c0187d0 }), error_response_body: None } 2024-04-30T21:57:25.121002Z DEBUG lookup{req=16 ino=1 name="synmon"}:list_objects{id=2 bucket="modal-s3mount-test-bucket" continued=false delimiter="/" max_keys="1" prefix="synmon/"}: mountpoint_s3_client::s3_crt_client: S3 request finished request_type=Default crt_error=None http_status=200 range=None duration=31.359805ms ttfb=Some(27.951583ms) request_id=4MV9SPV43ZH3H789 2024-04-30T21:57:25.121049Z DEBUG lookup{req=16 ino=1 name="synmon"}:list_objects{id=2 bucket="modal-s3mount-test-bucket" continued=false delimiter="/" max_keys="1" prefix="synmon/"}: mountpoint_s3_client::s3_crt_client: meta request finished duration=31.46915ms 2024-04-30T21:57:25.121480Z DEBUG fuser::request: FUSE( 18) ino 0x0000000000000002 OPENDIR flags 0x28800 2024-04-30T21:57:25.121556Z DEBUG fuser::request: FUSE( 20) ino 0x0000000000000002 RELEASEDIR fh FileHandle(4), flags 0x28800, flush false, lock owner None 2024-04-30T21:57:25.121697Z DEBUG fuser::request: FUSE( 22) ino 0x0000000000000002 OPENDIR flags 0x28800 2024-04-30T21:57:25.121724Z DEBUG fuser::request: FUSE( 24) ino 0x0000000000000002 LOOKUP name "test_file.txt" 2024-04-30T21:57:25.123065Z DEBUG lookup{req=24 ino=2 name="test_file.txt"}:head_object{id=3 bucket="modal-s3mount-test-bucket" key="synmon/test_file.txt"}: mountpoint_s3_client::s3_crt_client::head_object: new request 2024-04-30T21:57:25.124570Z DEBUG lookup{req=24 ino=2 name="test_file.txt"}:list_objects{id=4 bucket="modal-s3mount-test-bucket" continued=false delimiter="/" max_keys="1" prefix="synmon/test_file.txt/"}: mountpoint_s3_client::s3_crt_client::list_objects: new request 2024-04-30T21:57:25.130148Z DEBUG lookup{req=24 ino=2 name="test_file.txt"}:head_object{id=3 bucket="modal-s3mount-test-bucket" key="synmon/test_file.txt"}: mountpoint_s3_client::s3_crt_client: S3 request finished request_type=Default crt_error=None http_status=200 range=None duration=7.013744ms ttfb=Some(6.831594ms) request_id=4MV2AC2ZBB7VN2A6 2024-04-30T21:57:25.130193Z DEBUG lookup{req=24 ino=2 name="test_file.txt"}:head_object{id=3 bucket="modal-s3mount-test-bucket" key="synmon/test_file.txt"}: mountpoint_s3_client::s3_crt_client: meta request finished duration=7.115345ms 2024-04-30T21:57:25.151649Z DEBUG lookup{req=24 ino=2 name="test_file.txt"}:list_objects{id=4 bucket="modal-s3mount-test-bucket" continued=false delimiter="/" max_keys="1" prefix="synmon/test_file.txt/"}: mountpoint_s3_client::s3_crt_client: S3 request finished request_type=Default crt_error=None http_status=200 range=None duration=27.000246ms ttfb=Some(23.916368ms) request_id=4MV34YXJAED7M5HC 2024-04-30T21:57:25.151682Z DEBUG lookup{req=24 ino=2 name="test_file.txt"}:list_objects{id=4 bucket="modal-s3mount-test-bucket" continued=false delimiter="/" max_keys="1" prefix="synmon/test_file.txt/"}: mountpoint_s3_client::s3_crt_client: meta request finished duration=27.099295ms 2024-04-30T21:57:25.151976Z DEBUG fuser::request: FUSE( 26) ino 0x0000000000000003 OPEN flags 0x28800 2024-04-30T21:57:25.153669Z DEBUG open{req=26 ino=3 pid=1076390 name="test_file.txt"}:head_object{id=5 bucket="modal-s3mount-test-bucket" key="synmon/test_file.txt"}: mountpoint_s3_client::s3_crt_client::head_object: new request 2024-04-30T21:57:25.155144Z DEBUG open{req=26 ino=3 pid=1076390 name="test_file.txt"}:list_objects{id=6 bucket="modal-s3mount-test-bucket" continued=false delimiter="/" max_keys="1" prefix="synmon/test_file.txt/"}: mountpoint_s3_client::s3_crt_client::list_objects: new request 2024-04-30T21:57:25.161249Z DEBUG open{req=26 ino=3 pid=1076390 name="test_file.txt"}:head_object{id=5 bucket="modal-s3mount-test-bucket" key="synmon/test_file.txt"}: mountpoint_s3_client::s3_crt_client: S3 request finished request_type=Default crt_error=None http_status=200 range=None duration=7.506554ms ttfb=Some(7.321655ms) request_id=4MVBRNMD7VGDD762 2024-04-30T21:57:25.161292Z DEBUG open{req=26 ino=3 pid=1076390 name="test_file.txt"}:head_object{id=5 bucket="modal-s3mount-test-bucket" key="synmon/test_file.txt"}: mountpoint_s3_client::s3_crt_client: meta request finished duration=7.609402ms 2024-04-30T21:57:25.167079Z DEBUG open{req=26 ino=3 pid=1076390 name="test_file.txt"}:list_objects{id=6 bucket="modal-s3mount-test-bucket" continued=false delimiter="/" max_keys="1" prefix="synmon/test_file.txt/"}: mountpoint_s3_client::s3_crt_client: S3 request finished request_type=Default crt_error=None http_status=200 range=None duration=11.879062ms ttfb=Some(11.21302ms) request_id=4MV2X2RJ07YPJ7GQ 2024-04-30T21:57:25.167114Z DEBUG open{req=26 ino=3 pid=1076390 name="test_file.txt"}:list_objects{id=6 bucket="modal-s3mount-test-bucket" continued=false delimiter="/" max_keys="1" prefix="synmon/test_file.txt/"}: mountpoint_s3_client::s3_crt_client: meta request finished duration=11.960271ms 2024-04-30T21:57:25.167345Z DEBUG open{req=26 ino=3 pid=1076390 name="test_file.txt"}: mountpoint_s3::fs: new file handle created fh=6 ino=3 2024-04-30T21:57:25.167412Z DEBUG fuser::request: FUSE( 28) ino 0x0000000000000003 OPEN flags 0x28201 2024-04-30T21:57:25.168799Z DEBUG open{req=28 ino=3 pid=1076390 name="test_file.txt"}:head_object{id=7 bucket="modal-s3mount-test-bucket" key="synmon/test_file.txt"}: mountpoint_s3_client::s3_crt_client::head_object: new request 2024-04-30T21:57:25.170286Z DEBUG open{req=28 ino=3 pid=1076390 name="test_file.txt"}:list_objects{id=8 bucket="modal-s3mount-test-bucket" continued=false delimiter="/" max_keys="1" prefix="synmon/test_file.txt/"}: mountpoint_s3_client::s3_crt_client::list_objects: new request 2024-04-30T21:57:25.178028Z DEBUG open{req=28 ino=3 pid=1076390 name="test_file.txt"}:head_object{id=7 bucket="modal-s3mount-test-bucket" key="synmon/test_file.txt"}: mountpoint_s3_client::s3_crt_client: S3 request finished request_type=Default crt_error=None http_status=200 range=None duration=9.161958ms ttfb=Some(9.010258ms) request_id=4MV4QJ0Y5WXJ9WKS 2024-04-30T21:57:25.178062Z DEBUG open{req=28 ino=3 pid=1076390 name="test_file.txt"}:head_object{id=7 bucket="modal-s3mount-test-bucket" key="synmon/test_file.txt"}: mountpoint_s3_client::s3_crt_client: meta request finished duration=9.250622ms 2024-04-30T21:57:25.181209Z DEBUG open{req=28 ino=3 pid=1076390 name="test_file.txt"}:list_objects{id=8 bucket="modal-s3mount-test-bucket" continued=false delimiter="/" max_keys="1" prefix="synmon/test_file.txt/"}: mountpoint_s3_client::s3_crt_client: S3 request finished request_type=Default crt_error=None http_status=200 range=None duration=10.851084ms ttfb=Some(9.577889ms) request_id=4MVFZAMJNCAK44XP 2024-04-30T21:57:25.181249Z DEBUG open{req=28 ino=3 pid=1076390 name="test_file.txt"}:list_objects{id=8 bucket="modal-s3mount-test-bucket" continued=false delimiter="/" max_keys="1" prefix="synmon/test_file.txt/"}: mountpoint_s3_client::s3_crt_client: meta request finished duration=10.952487ms 2024-04-30T21:57:25.181493Z WARN open{req=28 ino=3 pid=1076390 name="test_file.txt"}: mountpoint_s3::fuse: open failed: inode error: inode 3 (full key "synmon/test_file.txt") is not writable while being read 2024-04-30T21:57:25.181536Z DEBUG fuser::request: FUSE( 30) ino 0x0000000000000003 FLUSH fh FileHandle(6), lock owner LockOwner(2957524987048005100) 2024-04-30T21:57:25.181569Z DEBUG fuser::request: FUSE( 32) ino 0x0000000000000003 RELEASE fh FileHandle(6), flags 0x28800, flush false, lock owner None 2024-04-30T21:57:25.181623Z DEBUG fuser::request: FUSE( 34) ino 0x0000000000000002 RELEASEDIR fh FileHandle(5), flags 0x28800, flush false, lock owner None 2024-04-30T21:57:25.181670Z DEBUG mountpoint_s3::fuse::session: starting fuse worker 2 (thread id 1076451) 2024-04-30T21:57:25.281160Z DEBUG fuser::request: FUSE( 36) ino 0x0000000000000001 RELEASEDIR fh FileHandle(2), flags 0x28800, flush false, lock owner None 2024-04-30T21:57:25.281183Z DEBUG fuser::request: FUSE( 38) ino 0x0000000000000001 RELEASEDIR fh FileHandle(3), flags 0x28800, flush false, lock owner None 2024-04-30T21:57:25.516852Z DEBUG fuser::request: FUSE( 40) ino 0x0000000000000001 STATFS 2024-04-30T21:57:25.517065Z INFO fuser::session: Unmounted /tmp/task-data-nDwLcA/ta-01HWRG6BXQPV2495720REFPSSN/mountpoint-fpgEbu 2024-04-30T21:57:25.517230Z WARN fuser::mnt::fuse2: umount failed with Os { code: 22, kind: InvalidInput, message: "Invalid argument" } 2024-04-30T21:57:25.517517Z INFO mountpoint_s3::metrics: fs.current_handles[type=read]: 0 2024-04-30T21:57:25.517527Z INFO mountpoint_s3::metrics: fs.inode_kinds[kind=directory]: 2 2024-04-30T21:57:25.517528Z INFO mountpoint_s3::metrics: fs.inode_kinds[kind=file]: 1 2024-04-30T21:57:25.517530Z INFO mountpoint_s3::metrics: fs.inodes: 3 2024-04-30T21:57:25.517531Z INFO mountpoint_s3::metrics: fuse.op_failures[op=open]: 1 2024-04-30T21:57:25.517533Z INFO mountpoint_s3::metrics: fuse.op_latency_us[op=flush]: n=1: min=10 p10=10 p50=10 avg=10.00 p90=10 p99=10 p99.9=10 max=10 2024-04-30T21:57:25.517534Z INFO mountpoint_s3::metrics: fuse.op_latency_us[op=getattr]: n=1: min=37 p10=37 p50=37 avg=37.00 p90=37 p99=37 p99.9=37 max=37 2024-04-30T21:57:25.517536Z INFO mountpoint_s3::metrics: fuse.op_latency_us[op=init]: n=1: min=18 p10=18 p50=18 avg=18.00 p90=18 p99=18 p99.9=18 max=18 2024-04-30T21:57:25.517537Z INFO mountpoint_s3::metrics: fuse.op_latency_us[op=lookup]: n=2: min=30208 p10=30335 p50=30335 avg=32736.00 p90=35327 p99=35327 p99.9=35327 max=35327 2024-04-30T21:57:25.517539Z INFO mountpoint_s3::metrics: fuse.op_latency_us[op=open]: n=2: min=14080 p10=14143 p50=14143 avg=14752.00 p90=15423 p99=15423 p99.9=15423 max=15423 2024-04-30T21:57:25.517540Z INFO mountpoint_s3::metrics: fuse.op_latency_us[op=opendir]: n=5: min=7 p10=7 p50=15 avg=19.60 p90=44 p99=44 p99.9=44 max=44 2024-04-30T21:57:25.517541Z INFO mountpoint_s3::metrics: fuse.op_latency_us[op=release]: n=1: min=15 p10=15 p50=15 avg=15.00 p90=15 p99=15 p99.9=15 max=15 2024-04-30T21:57:25.517543Z INFO mountpoint_s3::metrics: fuse.op_latency_us[op=releasedir]: n=5: min=6 p10=6 p50=14 avg=12.20 p90=18 p99=18 p99.9=18 max=18 2024-04-30T21:57:25.517544Z INFO mountpoint_s3::metrics: prefetch.contiguous_read_len: n=1: min=0 p10=0 p50=0 avg=0.00 p90=0 p99=0 p99.9=0 max=0 2024-04-30T21:57:25.517546Z INFO mountpoint_s3::metrics: process.memory_usage: 16654336 2024-04-30T21:57:25.517547Z INFO mountpoint_s3::metrics: s3.client.buffer_pool.mem_limit: 2013265920 2024-04-30T21:57:25.517548Z INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_allocated: 0 2024-04-30T21:57:25.517550Z INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_cutoff: 33554432 2024-04-30T21:57:25.517551Z INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_num_blocks: 0 2024-04-30T21:57:25.517554Z INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_reserved: 0 2024-04-30T21:57:25.517555Z INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_used: 0 2024-04-30T21:57:25.517556Z INFO mountpoint_s3::metrics: s3.client.buffer_pool.secondary_reserved: 0 2024-04-30T21:57:25.517564Z INFO mountpoint_s3::metrics: s3.client.buffer_pool.secondary_used: 0 2024-04-30T21:57:25.517566Z INFO mountpoint_s3::metrics: s3.client.host_count[host=modal-s3mount-test-bucket.s3.us-east-1.amazonaws.com]: 16 2024-04-30T21:57:25.517567Z INFO mountpoint_s3::metrics: s3.client.num_auto_default_network_io: 1 2024-04-30T21:57:25.517569Z INFO mountpoint_s3::metrics: s3.client.num_auto_ranged_copy_network_io: 0 2024-04-30T21:57:25.517570Z INFO mountpoint_s3::metrics: s3.client.num_auto_ranged_get_network_io: 0 2024-04-30T21:57:25.517571Z INFO mountpoint_s3::metrics: s3.client.num_auto_ranged_put_network_io: 0 2024-04-30T21:57:25.517573Z INFO mountpoint_s3::metrics: s3.client.num_requests_being_prepared: 0 2024-04-30T21:57:25.517574Z INFO mountpoint_s3::metrics: s3.client.num_requests_being_processed: 1 2024-04-30T21:57:25.517575Z INFO mountpoint_s3::metrics: s3.client.num_requests_stream_queued_waiting: 0 2024-04-30T21:57:25.517577Z INFO mountpoint_s3::metrics: s3.client.num_requests_streaming_response: 0 2024-04-30T21:57:25.517578Z INFO mountpoint_s3::metrics: s3.client.num_total_network_io: 1 2024-04-30T21:57:25.517579Z INFO mountpoint_s3::metrics: s3.client.request_queue_size: 0 2024-04-30T21:57:25.517581Z INFO mountpoint_s3::metrics: s3.meta_requests.failures[op=head_object,status=404]: 1 2024-04-30T21:57:25.517582Z INFO mountpoint_s3::metrics: s3.meta_requests.first_byte_latency_us[op=head_object]: n=4: min=7104 p10=7135 p50=7615 avg=8432.00 p90=9791 p99=9791 p99.9=9791 max=9791 2024-04-30T21:57:25.517583Z INFO mountpoint_s3::metrics: s3.meta_requests.first_byte_latency_us[op=list_objects]: n=5: min=10880 p10=10943 p50=27135 avg=21734.40 p90=31487 p99=31487 p99.9=31487 max=31487 2024-04-30T21:57:25.517585Z INFO mountpoint_s3::metrics: s3.meta_requests.total_latency_us[op=head_object]: n=4: min=7104 p10=7135 p50=7615 avg=8432.00 p90=9791 p99=9791 p99.9=9791 max=9791 2024-04-30T21:57:25.517586Z INFO mountpoint_s3::metrics: s3.meta_requests.total_latency_us[op=list_objects]: n=5: min=10944 p10=11007 p50=27135 avg=21772.80 p90=31487 p99=31487 p99.9=31487 max=31487 2024-04-30T21:57:25.517587Z INFO mountpoint_s3::metrics: s3.meta_requests[op=head_object]: 4 (n=4) 2024-04-30T21:57:25.517589Z INFO mountpoint_s3::metrics: s3.meta_requests[op=list_objects]: 5 (n=5) 2024-04-30T21:57:25.517590Z INFO mountpoint_s3::metrics: s3.requests.failures[op=head_object,type=Default,status=404]: 1 2024-04-30T21:57:25.517591Z INFO mountpoint_s3::metrics: s3.requests.first_byte_latency_us[op=head_object,type=Default]: n=4: min=6816 p10=6847 p50=7327 avg=8112.00 p90=9343 p99=9343 p99.9=9343 max=9343 2024-04-30T21:57:25.517593Z INFO mountpoint_s3::metrics: s3.requests.first_byte_latency_us[op=list_objects,type=Default]: n=5: min=9536 p10=9599 p50=21503 avg=18816.00 p90=28031 p99=28031 p99.9=28031 max=28031 2024-04-30T21:57:25.517594Z INFO mountpoint_s3::metrics: s3.requests.total_latency_us[op=head_object,type=Default]: n=4: min=7008 p10=7039 p50=7519 avg=8320.00 p90=9599 p99=9599 p99.9=9599 max=9599 2024-04-30T21:57:25.517595Z INFO mountpoint_s3::metrics: s3.requests.total_latency_us[op=list_objects,type=Default]: n=5: min=10816 p10=10879 p50=27007 avg=21632.00 p90=31359 p99=31359 p99.9=31359 max=31359 2024-04-30T21:57:25.517597Z INFO mountpoint_s3::metrics: s3.requests[op=head_object,type=Default]: 4 (n=4) 2024-04-30T21:57:25.517598Z INFO mountpoint_s3::metrics: s3.requests[op=list_objects,type=Default]: 5 (n=5) 2024-04-30T21:57:25.517599Z INFO mountpoint_s3::metrics: system.available_memory: 186636877824The text was updated successfully, but these errors were encountered: