The memory usage of mount-s3 increases and the process terminates abnormally

[mura890]

Mountpoint for Amazon S3 version

mount-s3 version：1.7.2

AWS Region

ap-northeast-1

Describe the running environment

I am running an S3 bucket in the same account mounted on EC2 (OS: Rocky Linux 8.10)

Mountpoint options

mount-s3 test-S3-bucket --prefix archives/ /mnt/applications/classtream/archives --uid 1001 --gid 1001 --file-mode 0660 --dir-mode 0770 --allow-delete --allow-other --allow-overwrite --cache /mnt/s3-cache --metadata-ttl 300 --debug --log-metrics --log-directory /mnt/mounts3-log/

What happened?

I created a service file for mount-s3 as follows, registered it as a service, and made it work.

/lib/systemd/system/mount-s3.service

[Unit]
Description=Mountpoint for Amazon S3 mount
Wants=network-online.target
After=network-online.target

[Service]
Type=oneshot
RemainAfterExit=yes
ExecStart=/usr/bin/mount-s3 test-S3-bucket --prefix archives/ /mnt/applications/classtream/archives --uid 1001 --gid 1001 --file-mode 0660 --dir-mode 0770 --allow-delete --allow-other --allow-overwrite --metadata-ttl 300 --debug --log-metrics --log-directory /mnt/mounts3-log/
ExecStop=/usr/bin/fusermount -u /mnt/applications/classtream/archives
[Install]
WantedBy=default.target

The archives folder contains a 12GB file, and accessing it a few times through an application causes the memory usage of mount-s3 to increase. After 10 minutes, the following message is output to the messages log and the program terminates abnormally.

Sep 10 04:38:53 test-server systemd-coredump[15268]: Resource limits disable core dumping for process 12815 (mount-s3).
Sep 10 04:38:53 test-server systemd-coredump[15268]: Process 12815 (mount-s3) of user 0 dumped core.

The EC2 instance type is c6in.2xlarge, with 16GB memory and 10GB swap.

The memory increase rate is so high, is there any way or measure to reduce it?]

Attach the log obtained with the "--debug --log-metrics" option.
mountpoint-s3-2024-09-10T04-26-12Z.log

Relevant log output

・・・
2024-09-10T04:38:53.139996Z  INFO mountpoint_s3::metrics: disk_data_cache.block_hit: 603 (n=603)
2024-09-10T04:38:53.140018Z  INFO mountpoint_s3::metrics: disk_data_cache.read_duration_us: n=603: min=1608 p10=2063 p50=7967 avg=8239.87 p90=9215 p99=72703 p99.9=167935 max=167935
2024-09-10T04:38:53.140019Z  INFO mountpoint_s3::metrics: disk_data_cache.total_bytes[type=read]: 632291328 (n=603)
2024-09-10T04:38:53.140021Z  INFO mountpoint_s3::metrics: fuse.io_size[type=read]: n=326: min=16384 p10=132095 p50=132095 avg=123788.76 p90=132095 p99=132095 p99.9=132095 max=132095
2024-09-10T04:38:53.140022Z  INFO mountpoint_s3::metrics: fuse.op_latency_us[op=read]: n=326: min=67 p10=78 p50=124 avg=53482.93 p90=26111 p99=942079 p99.9=954367 max=954367
2024-09-10T04:38:53.140023Z  INFO mountpoint_s3::metrics: fuse.total_bytes[type=read]: 40198144 (n=326)
2024-09-10T04:38:53.140024Z  INFO mountpoint_s3::metrics: prefetch.bytes_in_queue: 11584950272
2024-09-10T04:38:53.140025Z  INFO mountpoint_s3::metrics: prefetch.seek_distance[dir=backward]: n=14: min=98304 p10=98815 p50=254975 avg=228242.29 p90=264191 p99=264191 p99.9=264191 max=264191
2024-09-10T04:38:53.140026Z  INFO mountpoint_s3::metrics: prefetch.seek_distance[dir=forward]: n=11: min=32768 p10=33023 p50=132095 avg=105029.82 p90=132095 p99=168959 p99.9=168959 max=168959
2024-09-10T04:38:53.140027Z  INFO mountpoint_s3::metrics: process.memory_usage: 13619433472
2024-09-10T04:38:53.140028Z  INFO mountpoint_s3::metrics: system.available_memory: 56147968
2024-09-10T04:38:53.343652Z DEBUG fuser::request: FUSE(183416) ino 0x000000000000002b READ fh FileHandle(4), offset 2495815680, size 131072    
2024-09-10T04:38:53.343775Z DEBUG fuser::request: FUSE(183418) ino 0x000000000000002b READ fh FileHandle(4), offset 2495946752, size 131072    
2024-09-10T04:38:53.343947Z DEBUG fuser::request: FUSE(183420) ino 0x000000000000002b READ fh FileHandle(4), offset 2496077824, size 131072    
2024-09-10T04:38:53.344045Z DEBUG fuser::request: FUSE(183422) ino 0x000000000000002b READ fh FileHandle(4), offset 2496208896, size 131072    
2024-09-10T04:38:53.344177Z DEBUG fuser::request: FUSE(183424) ino 0x000000000000002b READ fh FileHandle(4), offset 2496339968, size 131072    
2024-09-10T04:38:53.344304Z DEBUG fuser::request: FUSE(183426) ino 0x000000000000002b READ fh FileHandle(4), offset 2496471040, size 131072    
2024-09-10T04:38:53.344435Z DEBUG fuser::request: FUSE(183428) ino 0x000000000000002b READ fh FileHandle(4), offset 2496602112, size 131072    
2024-09-10T04:38:53.344565Z DEBUG fuser::request: FUSE(183430) ino 0x000000000000002b READ fh FileHandle(4), offset 2496733184, size 131072    
2024-09-10T04:38:53.353587Z DEBUG fuser::request: FUSE(183432) ino 0x000000000000002b READ fh FileHandle(4), offset 2496864256, size 131072    
2024-09-10T04:38:53.353765Z DEBUG fuser::request: FUSE(183434) ino 0x000000000000002b READ fh FileHandle(4), offset 2496995328, size 131072    
2024-09-10T04:38:53.353878Z DEBUG fuser::request: FUSE(183436) ino 0x000000000000002b READ fh FileHandle(4), offset 2497126400, size 131072    
2024-09-10T04:38:53.354033Z DEBUG fuser::request: FUSE(183438) ino 0x000000000000002b READ fh FileHandle(4), offset 2497257472, size 131072    
2024-09-10T04:38:53.354145Z DEBUG fuser::request: FUSE(183440) ino 0x000000000000002b READ fh FileHandle(4), offset 2497388544, size 131072    
2024-09-10T04:38:53.354274Z DEBUG fuser::request: FUSE(183442) ino 0x000000000000002b READ fh FileHandle(4), offset 2497519616, size 131072    
2024-09-10T04:38:53.354406Z DEBUG fuser::request: FUSE(183444) ino 0x000000000000002b READ fh FileHandle(4), offset 2497650688, size 131072    
2024-09-10T04:38:53.354559Z DEBUG fuser::request: FUSE(183446) ino 0x000000000000002b READ fh FileHandle(4), offset 2497781760, size 131072    
2024-09-10T04:38:53.362476Z DEBUG fuser::request: FUSE(183448) ino 0x000000000000002b READ fh FileHandle(4), offset 2497912832, size 131072    
2024-09-10T04:38:53.362585Z DEBUG fuser::request: FUSE(183450) ino 0x000000000000002b READ fh FileHandle(4), offset 2498043904, size 131072    
2024-09-10T04:38:53.362722Z DEBUG fuser::request: FUSE(183452) ino 0x000000000000002b READ fh FileHandle(4), offset 2498174976, size 131072    
2024-09-10T04:38:53.362823Z DEBUG fuser::request: FUSE(183454) ino 0x000000000000002b READ fh FileHandle(4), offset 2498306048, size 131072    
2024-09-10T04:38:53.362947Z DEBUG fuser::request: FUSE(183456) ino 0x000000000000002b READ fh FileHandle(4), offset 2498437120, size 131072    
2024-09-10T04:38:53.363102Z DEBUG fuser::request: FUSE(183458) ino 0x000000000000002b READ fh FileHandle(4), offset 2498568192, size 131072    
2024-09-10T04:38:53.363211Z DEBUG fuser::request: FUSE(183460) ino 0x000000000000002b READ fh FileHandle(4), offset 2498699264, size 131072    
2024-09-10T04:38:53.363344Z DEBUG fuser::request: FUSE(183462) ino 0x000000000000002b READ fh FileHandle(4), offset 2498830336, size 131072    
2024-09-10T04:38:53.371055Z DEBUG fuser::request: FUSE(183464) ino 0x000000000000002b READ fh FileHandle(4), offset 2498961408, size 131072    
2024-09-10T04:38:53.371175Z DEBUG fuser::request: FUSE(183466) ino 0x000000000000002b READ fh FileHandle(4), offset 2499092480, size 131072    
2024-09-10T04:38:53.371318Z DEBUG fuser::request: FUSE(183468) ino 0x000000000000002b READ fh FileHandle(4), offset 2499223552, size 131072    
2024-09-10T04:38:53.371468Z DEBUG fuser::request: FUSE(183470) ino 0x000000000000002b READ fh FileHandle(4), offset 2499354624, size 131072    
2024-09-10T04:38:53.371627Z DEBUG fuser::request: FUSE(183472) ino 0x000000000000002b READ fh FileHandle(4), offset 2499485696, size 131072    
2024-09-10T04:38:53.371737Z DEBUG fuser::request: FUSE(183474) ino 0x000000000000002b READ fh FileHandle(4), offset 2499616768, size 131072    
2024-09-10T04:38:53.371850Z DEBUG fuser::request: FUSE(183476) ino 0x000000000000002b READ fh FileHandle(4), offset 2499747840, size 131072    
2024-09-10T04:38:53.371962Z DEBUG fuser::request: FUSE(183478) ino 0x000000000000002b READ fh FileHandle(4), offset 2499878912, size 131072    
2024-09-10T04:38:53.383196Z DEBUG fuser::request: FUSE(183480) ino 0x000000000000002b READ fh FileHandle(4), offset 2500009984, size 131072    
2024-09-10T04:38:53.383321Z DEBUG fuser::request: FUSE(183482) ino 0x000000000000002b READ fh FileHandle(4), offset 2500141056, size 131072    
2024-09-10T04:38:53.383485Z DEBUG fuser::request: FUSE(183484) ino 0x000000000000002b READ fh FileHandle(4), offset 2500272128, size 131072    

添付したログの異常終了前のログを抜粋しました。

[vladem]

Hi @mura890, thanks for sharing your use case. We are aware about the issue and are actively working on a fix for that in #987, but can not provide any dates for resolution just yet. Unfortunately, with current Mountpoint version there is no way of limiting the memory consumption apart from adjusting the workload (reducing the number of concurrently open files and the reading speed).

Regarding your case, from the logs I can see that you are having a non-containerised read workload, with peak memory consumption at around 13.5GiB. The memory usage is dominated by prefetch queue (reported by prefetch.bytes_in_queue metric), which is exactly the case we're focused on.

Please, use #987 to track resolution and let us know if you have any further questions. We may close this issue as a duplicate in a while.

[vladem]

I forgot to mention --maximum-throughput-gbps CLI option of Mountpoint, which may be used to reduce the memory consumption. It's actual effect depends on the workload pattern, but it is definitely an option to explore. Generally, the lower value you set to it, the lower memory consumption you should expect.

[muddyfish]

Closing, tracking in #987.