goofys icon indicating copy to clipboard operation
goofys copied to clipboard

Published 20 hours ago • verified publisher icon kahing

Goofys read throughput

Open curiousCoder1 opened this issue 3 years ago • 2 comments

I am doing a comparative study between different implementations of file systems backed by object storage, like Goofys, S3FS, Riofs... And when measuring the read throughput of Goofys for large files I get a throughput of about 2MB/s, while the rest of implementations yield a throughput of 70MB/s in the worst case even without using any caching.

I am currently running Goofys on an m5a.xlarge EC2 instance running CentOS8.2 with a Linux 4.18.0-193.6.3.el8_2.x86_64 kernel, and mounted the file system as: goofys -o allow_other --debug_fuse s3Bucket /mnt/s3

When running strace with dd to try to read a 2GB file I get the following log (I have also tried with different block sizes but I always get a throughput of about 2 MB/s:


execve("/usr/bin/dd", ["dd", "if=/mnt/s3/largeF"..., "of=/dev/null", "bs=1MB", "oflag=nocache", "iflag=nocache", "status=progress"], 0x7ffeabee7060 /* 17 vars */) = 0
brk(NULL)                               = 0x5633aee48000
arch_prctl(0x3001 /* ARCH_??? */, 0x7ffcfed9d970) = -1 EINVAL (Invalid argument)
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=45016, ...}) = 0
mmap(NULL, 45016, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f4cb64d0000
close(3)                                = 0
openat(AT_FDCWD, "/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\2607\2\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=4176104, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f4cb64ce000
mmap(NULL, 3938144, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f4cb5ef1000
mprotect(0x7f4cb60aa000, 2093056, PROT_NONE) = 0
mmap(0x7f4cb62a9000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1b8000) = 0x7f4cb62a9000
mmap(0x7f4cb62af000, 14176, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f4cb62af000
close(3)                                = 0
arch_prctl(ARCH_SET_FS, 0x7f4cb64cf580) = 0
mprotect(0x7f4cb62a9000, 16384, PROT_READ) = 0
mprotect(0x5633ad589000, 4096, PROT_READ) = 0
mprotect(0x7f4cb64db000, 4096, PROT_READ) = 0
munmap(0x7f4cb64d0000, 45016)           = 0
rt_sigaction(SIGINT, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGUSR1, {sa_handler=0x5633ad37c320, sa_mask=[INT USR1], sa_flags=SA_RESTORER, sa_restorer=0x7f4cb5f28790}, NULL, 8) = 0
rt_sigaction(SIGINT, {sa_handler=0x5633ad37c310, sa_mask=[INT USR1], sa_flags=SA_RESTORER|SA_NODEFER|SA_RESETHAND, sa_restorer=0x7f4cb5f28790}, NULL, 8) = 0
brk(NULL)                               = 0x5633aee48000
brk(0x5633aee69000)                     = 0x5633aee69000
brk(NULL)                               = 0x5633aee69000
openat(AT_FDCWD, "/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=217796096, ...}) = 0
mmap(NULL, 217796096, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f4ca8f3c000
close(3)                                = 0
openat(AT_FDCWD, "/mnt/s3/largeFile", O_RDONLY) = 3
dup2(3, 0)                              = 0
close(3)                                = 0
lseek(0, 0, SEEK_CUR)                   = 0
openat(AT_FDCWD, "/dev/null", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 3
dup2(3, 1)                              = 1
close(3)                                = 0
mmap(NULL, 1011712, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f4cb63d7000
read(0, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(0, 0, 917504, POSIX_FADV_DONTNEED) = 0
write(1, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
lseek(1, 0, SEEK_CUR)                   = 0
fadvise64(1, -1000000, 917504, POSIX_FADV_DONTNEED) = 0
)                       = 1
openat(AT_FDCWD, "/usr/share/locale/locale.alias", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=2997, ...}) = 0
read(3, "# Locale name alias data base.\n#"..., 4096) = 2997
read(3, "", 4096)                       = 0
close(3)                                = 0
openat(AT_FDCWD, "/usr/share/locale/en_US.UTF-8/LC_MESSAGES/coreutils.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/en_US.utf8/LC_MESSAGES/coreutils.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/en_US/LC_MESSAGES/coreutils.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/en.UTF-8/LC_MESSAGES/coreutils.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/en.utf8/LC_MESSAGES/coreutils.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/en/LC_MESSAGES/coreutils.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
write(2, "1000000 bytes (1.0 MB, 977 KiB) "..., 531000000 bytes (1.0 MB, 977 KiB) copied, 1 s, 945 kB/s) = 53
read(0, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(0, 917504, 1048576, POSIX_FADV_DONTNEED) = 0
write(1, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(1, 0, 1048576, POSIX_FADV_DONTNEED) = 0
read(0, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(0, 1966080, 917504, POSIX_FADV_DONTNEED) = 0
write(1, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(1, 1082496, 917504, POSIX_FADV_DONTNEED) = 0
)                       = 1
write(2, "3000000 bytes (3.0 MB, 2.9 MiB) "..., 533000000 bytes (3.0 MB, 2.9 MiB) copied, 2 s, 1.3 MB/s) = 53
read(0, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(0, 2883584, 1048576, POSIX_FADV_DONTNEED) = 0
write(1, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(1, 2116416, 1048576, POSIX_FADV_DONTNEED) = 0
read(0, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(0, 3932160, 1048576, POSIX_FADV_DONTNEED) = 0
write(1, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(1, 3232832, 1048576, POSIX_FADV_DONTNEED) = 0
)                       = 1
write(2, "5000000 bytes (5.0 MB, 4.8 MiB) "..., 535000000 bytes (5.0 MB, 4.8 MiB) copied, 4 s, 1.4 MB/s) = 53
read(0, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(0, 4980736, 917504, POSIX_FADV_DONTNEED) = 0
write(1, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(1, 4300672, 917504, POSIX_FADV_DONTNEED) = 0
)                       = 1
write(2, "6000000 bytes (6.0 MB, 5.7 MiB) "..., 536000000 bytes (6.0 MB, 5.7 MiB) copied, 4 s, 1.5 MB/s) = 53
read(0, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(0, 5898240, 1048576, POSIX_FADV_DONTNEED) = 0
write(1, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(1, 5319936, 1048576, POSIX_FADV_DONTNEED) = 0
read(0, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(0, 6946816, 1048576, POSIX_FADV_DONTNEED) = 0
write(1, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(1, 6421696, 1048576, POSIX_FADV_DONTNEED) = 0
)                       = 1
write(2, "8000000 bytes (8.0 MB, 7.6 MiB) "..., 538000000 bytes (8.0 MB, 7.6 MiB) copied, 6 s, 1.4 MB/s) = 53
read(0, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(0, 7995392, 917504, POSIX_FADV_DONTNEED) = 0
write(1, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(1, 7474880, 917504, POSIX_FADV_DONTNEED) = 0
)                       = 1
write(2, "9000000 bytes (9.0 MB, 8.6 MiB) "..., 539000000 bytes (9.0 MB, 8.6 MiB) copied, 6 s, 1.5 MB/s) = 53
read(0, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(0, 8912896, 1048576, POSIX_FADV_DONTNEED) = 0
write(1, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(1, 8479488, 1048576, POSIX_FADV_DONTNEED) = 0
read(0, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(0, 9961472, 917504, POSIX_FADV_DONTNEED) = 0
write(1, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(1, 9566592, 917504, POSIX_FADV_DONTNEED) = 0
)                       = 1
write(2, "11000000 bytes (11 MB, 10 MiB) c"..., 5211000000 bytes (11 MB, 10 MiB) copied, 7 s, 1.5 MB/s) = 52
write(2, " ", 1 )                        = 1
read(0, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(0, 10878976, 1048576, POSIX_FADV_DONTNEED) = 0
write(1, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(1, 10605120, 1048576, POSIX_FADV_DONTNEED) = 0
read(0, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(0, 11927552, 1048576, POSIX_FADV_DONTNEED) = 0
write(1, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1000000) = 1000000
fadvise64(1, 11726144, 1048576, POSIX_FADV_DONTNEED) = 0

...

curiousCoder1 avatar Dec 15 '20 21:12 curiousCoder1

Hi,

I would be interested in reading your study, if possible.

Thank you

joanmarcriera avatar Dec 22 '20 22:12 joanmarcriera

this is a very late response, but it'd be useful to have --debug_s3 --debug_fuse log

kahing avatar Jul 12 '21 01:07 kahing