`std::io::copy()` doesn't return immediately after copying the file to certain USB devices

mkblast commented 3 weeks ago

What system are you running Yazi on?

Linux Wayland

What terminal are you running Yazi in?

foot version: 1.18.1 +pgo +ime +graphemes -assertions

`yazi --debug` output

Yazi
    Version: 0.3.3 (5eabd7d 2024-10-29)
    Debug  : true
    OS     : linux-x86_64 (unix)

Ya
    Version: 0.3.3 (Arch Linux 2024-09-05)

Emulator
    Emulator.via_env: ("foot", "tmux")
    Emulator.via_csi: Ok(Foot)
    Emulator.detect : Foot

Adapter
    Adapter.matches: Sixel

Desktop
    XDG_SESSION_TYPE           : Some("wayland")
    WAYLAND_DISPLAY            : Some("wayland-1")
    DISPLAY                    : Some(":0")
    SWAYSOCK                   : None
    HYPRLAND_INSTANCE_SIGNATURE: Some("4520b30d498daca8079365bdb909a8dea38e8d55_1730217014_1989512369")
    WAYFIRE_SOCKET             : None

SSH
    shared.in_ssh_connection: false

WSL
    WSL: false

Variables
    SHELL              : Some("/usr/bin/zsh")
    EDITOR             : Some("nvim")
    VISUAL             : Some("nvim")
    YAZI_FILE_ONE      : None
    YAZI_CONFIG_HOME   : None

Text Opener
    default     : Some(Opener { run: "${EDITOR:=vi} \"$@\"", block: true, orphan: false, desc: "$EDITOR", for_: None, spread: true })
    block-create: Some(Opener { run: "${EDITOR:=vi} \"$@\"", block: true, orphan: false, desc: "$EDITOR", for_: None, spread: true })
    block-rename: Some(Opener { run: "${EDITOR:=vi} \"$@\"", block: true, orphan: false, desc: "$EDITOR", for_: None, spread: true })

Multiplexers
    TMUX               : true
    tmux version       : tmux 3.5a
    tmux build flags   : enable-sixel=Unknown
    ZELLIJ_SESSION_NAME: None
    Zellij version     : No such file or directory (os error 2)

Dependencies
    file             : 5.45
    ueberzugpp       : No such file or directory (os error 2)
    ffmpegthumbnailer: 2.2.3
    magick           : 7.1.1-39
    fzf              : 0.55.0
    fd               : 10.2.0
    rg               : 14.1.1
    chafa            : 1.14.2
    zoxide           : 0.9.6
    7z               : 17.05
    7zz              : No such file or directory (os error 2)
    jq               : 1.7.1

Describe the bug

It's not a bug per say, it's just when reading/writing to a usb stick yazi takes forever to finish an operation. Like coping a 1gb file from yazi can take up to 30min unlike the cp command which takes seconds to minute.

Minimal reproducer

Copy a sizeable file with yazi to a usb stick and watch how long it takes.
Same thing with cp command.
For me yazi takes forever unlike cp.

Anything else?

I don't exactly what information that could be helpful. if you need something else tell me.

Also thank for the wonderful project.

Validations

[X] I tried the latest nightly build, and the issue is still reproducible
[X] I updated the debug information (yazi --debug) input box to the nightly that I tried
[X] I can reproduce it after disabling all custom configs/plugins (mv ~/.config/yazi ~/.config/yazi-backup)

sxyazi commented 3 weeks ago

It would be really helpful to see a video demo showing the behavior of Yazi and cp, so I can understand your complete steps.

Yazi's file copying just calls the standard library functions std::fs::copy() and std::io::copy(). Please try calling them directly in a Rust app to see if you run into the same issues - we've faced some problems lately due to bugs in Rust itself, like https://github.com/sxyazi/yazi/issues/1703.

Also, can you confirm if this is a duplicate of https://github.com/sxyazi/yazi/issues/1857? Right now, the progress bar is missing a redraw, meaning that even when a task is complete, the progress bar doesn't disappear if the user isn't interacting (like scrolling the file list). This is a known rendering bug affecting all tasks, not just copying.

mkblast commented 3 weeks ago

Yazi's file copying just calls the standard library functions std::fs::copy() and std::io::copy(). Please try calling them directly in a Rust app to see if you run into the same issues - we've faced some problems lately due to bugs in Rust itself, like https://github.com/sxyazi/yazi/issues/1703.

I did a test with fs::copy

use std::fs;
use std::io;

fn main() -> io::Result<()> {
    let from_path = "/home/karim/Documents/projects/code/copy-test/test";
    let to_path = "/run/media/karim/BRUH/test";

    fs::copy(from_path, to_path)?;
    println!("File copied successfully!");

    Ok(())
}

and this is how long it took compare to cp:

It would be really helpful to see a video demo showing the behavior of Yazi and cp, so I can understand your complete steps.

Kooha-2024-10-30-14-56-10.webm this is not the full video but it will continue staying at 99% and then it finished.

Also, can you confirm if this is a duplicate of https://github.com/sxyazi/yazi/issues/1857? Right now, the progress bar is missing a redraw, meaning that even when a task is complete, the progress bar doesn't disappear if the user isn't interacting (like scrolling the file list). This is a known rendering bug affecting all tasks, not just copying.

the progress bar disappears if i just and without interacting with yazi, it just takes a long time.

sxyazi commented 3 weeks ago

How about io::copy()? If you're on Linux, Yazi uses io::copy() instead of fs::copy(), please try this:

https://github.com/sxyazi/yazi/blob/c6687237e17673bfcd9a75f12730ea078faa0262/yazi-shared/src/fs/fns.rs#L254-L274

continue staying at 99% and then it finished

Did the file content finish copying, but the progress bar and task list items just haven't disappeared? Or is the file content not finished at all? What file system is your USB?

sxyazi commented 3 weeks ago

Also can it be reproduced in the release version, or does it only exist in the latest main branch? The file copying logic in the recent main branch had some changes to fix https://github.com/sxyazi/yazi/issues/1775, so it might be related

mkblast commented 3 weeks ago

How about io::copy()? If you're on Linux, Yazi uses io::copy() instead of fs::copy(), please try this:

I didn't use the same code snippet.

use std::fs::File;
use std::io::{self, copy};
use std::path::Path;

fn main() -> io::Result<()> {
    let source_path = "/home/karim/Documents/projects/code/copy-test/test";
    let destination_path = "/run/media/karim/BRUH/test";

    copy_file(source_path, destination_path)?;
    println!("File copied successfully!");

    Ok(())
}

fn copy_file<P: AsRef<Path>>(from: P, to: P) -> io::Result<u64> {
    let mut reader = File::open(&from)?;
    let mut writer = File::create(&to)?;

    let bytes_copied = copy(&mut reader, &mut writer)?;

    println!("Copied {} bytes from {:?} to {:?}", bytes_copied, from.as_ref(), to.as_ref());

    Ok(bytes_copied)
}

I copied the same file, but this time it was quicker.

idk if this was important, but when i run the program, Copied 921038423 bytes from "/home/karim/Documents/projects/code/copy-test/test" to "/run/media/karim/BRUH/test" this got printed but the program didn't exit for another 2 minutes.

Did the file content finish copying, but the progress bar and task list items just haven't disappeared? Or is the file content not finished at all? What file system is your USB?

I skimmed through the episode while the progress bar haven't disappeared and it seemed fine, this usb is an was FAT 32bit.

Also can it be reproduced in the release version, or does it only exist in the latest main branch? The file copying logic in the recent main branch had some changes to fix https://github.com/sxyazi/yazi/issues/1775, so it might be related

i didn't mention it but i used the latest version 0.3.3.

sxyazi commented 3 weeks ago

this got printed but the program didn't exit for another 2 minutes

Is it 100% to happen, or just occasionally? fs::copy() exits immediately after copying, but io::copy() doesn't, right?

What version of Rust are you using? - the implementation of io::copy() might differ between Rust versions

Also, please make sure to delete the target file on the USB every time you test them to avoid any noise, so it's a fresh copy each time.

i didn't mention it but i used the latest version 0.3.3.

No, I mean the release version 0.3.3 (Use this link https://github.com/sxyazi/yazi/releases/tag/v0.3.3). Your version is 0.3.3 (5eabd7d 2024-10-29), which is a nightly version and is scheduled for the next major version v0.4.

mkblast commented 3 weeks ago

Is it 100% to happen, or just occasionally? fs::copy() exits immediately after copying, but io::copy() doesn't, right?

100% everytime, and only io::copy(). and it's slower than fs::copy() by a long shot.

What version of Rust are you using? - the implementation of io::copy() might differ between Rust versions.

Default host: x86_64-unknown-linux-gnu
rustup home:  /home/karim/.local/share/rustup

stable-x86_64-unknown-linux-gnu (default)
rustc 1.82.0 (f6e511eec 2024-10-15)

No, I mean the release version 0.3.3 (Use this link https://github.com/sxyazi/yazi/releases/tag/v0.3.3). Your version is 0.3.3 (5eabd7d 2024-10-29), which is a nightly version and is scheduled for the next major version v0.4.

it's still the same results.

mkblast commented 3 weeks ago

and also everytime i exit yazi while copying, the terminal freezes and doesn't not response at all. it stays stuck until the operation finished (i say this cuz when i exit the process in io::copy() test it also doesn't respond until the it finishes). 2024-10-30T16:19:00,557795630+01:00

sxyazi commented 3 weeks ago

Please compile the program with io::copy() in release mode and run strace and strace -c separately on them, make sure delete any existing files on the USB before each run:

cargo build --release && strace ./target/release/your-app-name
cargo build --release && strace -c ./target/release/your-app-name

Then paste the outputs here.

mkblast commented 3 weeks ago

cargo build --release && strace ./target/release/your-app-name

execve("./target/release/copy-test", ["./target/release/copy-test"], 0x7ffc69424c60 /* 80 vars */) = 0
brk(NULL)                               = 0x568ec9db1000
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=118519, ...}) = 0
mmap(NULL, 118519, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7918a27a3000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/libgcc_s.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\0\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=915712, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7918a27a1000
mmap(NULL, 184808, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7918a2773000
mmap(0x7918a2777000, 147456, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x4000) = 0x7918a2777000
mmap(0x7918a279b000, 16384, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x28000) = 0x7918a279b000
mmap(0x7918a279f000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2b000) = 0x7918a279f000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/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\340_\2\0\0\0\0\0"..., 832) = 832
pread64(3, "\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"..., 784, 64) = 784
fstat(3, {st_mode=S_IFREG|0755, st_size=2014520, ...}) = 0
pread64(3, "\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"..., 784, 64) = 784
mmap(NULL, 2034616, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7918a2582000
mmap(0x7918a25a6000, 1511424, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x24000) = 0x7918a25a6000
mmap(0x7918a2717000, 319488, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x195000) = 0x7918a2717000
mmap(0x7918a2765000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1e3000) = 0x7918a2765000
mmap(0x7918a276b000, 31672, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7918a276b000
close(3)                                = 0
mmap(NULL, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7918a257f000
arch_prctl(ARCH_SET_FS, 0x7918a257f780) = 0
set_tid_address(0x7918a257fa50)         = 59078
set_robust_list(0x7918a257fa60, 24)     = 0
rseq(0x7918a25800a0, 0x20, 0, 0x53053053) = 0
mprotect(0x7918a2765000, 16384, PROT_READ) = 0
mprotect(0x7918a279f000, 4096, PROT_READ) = 0
mprotect(0x568e9eaa5000, 12288, PROT_READ) = 0
mprotect(0x7918a27fa000, 8192, PROT_READ) = 0
prlimit64(0, RLIMIT_STACK, NULL, {rlim_cur=16384*1024, rlim_max=RLIM64_INFINITY}) = 0
munmap(0x7918a27a3000, 118519)          = 0
poll([{fd=0, events=0}, {fd=1, events=0}, {fd=2, events=0}], 3, 0) = 0 (Timeout)
rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7918a25bf1d0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
getrandom("\xab\xc8\xe0\xf5\x59\xcf\x5f\x0f", 8, GRND_NONBLOCK) = 8
brk(NULL)                               = 0x568ec9db1000
brk(0x568ec9dd2000)                     = 0x568ec9dd2000
openat(AT_FDCWD, "/proc/self/maps", O_RDONLY|O_CLOEXEC) = 3
prlimit64(0, RLIMIT_STACK, NULL, {rlim_cur=16384*1024, rlim_max=RLIM64_INFINITY}) = 0
fstat(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
read(3, "568e9ea4e000-568e9ea54000 r--p 0"..., 1024) = 1024
read(3, "ibc.so.6\n7918a2717000-7918a27650"..., 1024) = 1024
read(3, "918a27c6000-7918a27c7000 r--p 00"..., 1024) = 679
close(3)                                = 0
sched_getaffinity(59078, 32, [0 1])     = 8
rt_sigaction(SIGSEGV, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
sigaltstack(NULL, {ss_sp=NULL, ss_flags=SS_DISABLE, ss_size=0}) = 0
mmap(NULL, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x7918a27bd000
mprotect(0x7918a27bd000, 4096, PROT_NONE) = 0
sigaltstack({ss_sp=0x7918a27be000, ss_flags=0, ss_size=8192}, NULL) = 0
rt_sigaction(SIGSEGV, {sa_handler=0x568e9ea796e0, sa_mask=[], sa_flags=SA_RESTORER|SA_ONSTACK|SA_SIGINFO, sa_restorer=0x7918a25bf1d0}, NULL, 8) = 0
rt_sigaction(SIGBUS, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGBUS, {sa_handler=0x568e9ea796e0, sa_mask=[], sa_flags=SA_RESTORER|SA_ONSTACK|SA_SIGINFO, sa_restorer=0x7918a25bf1d0}, NULL, 8) = 0
openat(AT_FDCWD, "/home/karim/Documents/projects/code/copy-test/test", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/run/media/karim/BRUH/test", O_WRONLY|O_CREAT|O_TRUNC|O_CLOEXEC, 0666) = 4
statx(3, "", AT_STATX_SYNC_AS_STAT|AT_EMPTY_PATH, STATX_ALL, {stx_mask=STATX_ALL|STATX_MNT_ID, stx_attributes=0, stx_mode=S_IFREG|0644, stx_size=921038423, ...}) = 0
statx(4, "", AT_STATX_SYNC_AS_STAT|AT_EMPTY_PATH, STATX_ALL, {stx_mask=STATX_ALL|STATX_MNT_ID, stx_attributes=0, stx_mode=S_IFREG|0644, stx_size=0, ...}) = 0
copy_file_range(3, NULL, 4, NULL, 1073741824, 0) = -1 EXDEV (Invalid cross-device link)
sendfile(4, 3, NULL, 2147479552)        = 921038423
sendfile(4, 3, NULL, 2147479552)        = 0
write(1, "Copied 921038423 bytes from \"/ho"..., 113Copied 921038423 bytes from "/home/karim/Documents/projects/code/copy-test/test" to "/run/media/karim/BRUH/test"
) = 113
close(4)                                = 0
close(3)                                = 0
write(1, "File copied successfully!\n", 26File copied successfully!
) = 26
sigaltstack({ss_sp=NULL, ss_flags=SS_DISABLE, ss_size=8192}, NULL) = 0
munmap(0x7918a27bd000, 12288)           = 0
exit_group(0)                           = ?
+++ exited with 0 +++

cargo build --release && strace -c ./target/release/your-app-name

Copied 921038423 bytes from "/home/karim/Documents/projects/code/copy-test/test" to "/run/media/karim/BRUH/test"
File copied successfully!
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ------------------
 86.72    1.778725      889362         2           sendfile
 13.27    0.272251       45375         6           close
  0.01    0.000109          54         2           write
  0.00    0.000020          10         2           munmap
  0.00    0.000009           3         3           sigaltstack
  0.00    0.000000           0         5           read
  0.00    0.000000           0         4           fstat
  0.00    0.000000           0         1           poll
  0.00    0.000000           0        13           mmap
  0.00    0.000000           0         5           mprotect
  0.00    0.000000           0         3           brk
  0.00    0.000000           0         5           rt_sigaction
  0.00    0.000000           0         2           pread64
  0.00    0.000000           0         1         1 access
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         1           arch_prctl
  0.00    0.000000           0         1           sched_getaffinity
  0.00    0.000000           0         1           set_tid_address
  0.00    0.000000           0         6           openat
  0.00    0.000000           0         1           set_robust_list
  0.00    0.000000           0         2           prlimit64
  0.00    0.000000           0         1           getrandom
  0.00    0.000000           0         1         1 copy_file_range
  0.00    0.000000           0         2           statx
  0.00    0.000000           0         1           rseq
------ ----------- ----------- --------- --------- ------------------
100.00    2.051114       28487        72         2 total

I wish i could read these 😞😞

sxyazi commented 3 weeks ago

Could you please send a fs::copy() with strace and strace -c so I can compare them

mkblast commented 3 weeks ago

cargo build --release && strace ./target/release/your-app-name log.txt in this log file, the program froze in close(4) = 0

cargo build --release && strace -c ./target/release/your-app-name

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ------------------
 72.19    2.619527          23    112433           write
 21.78    0.790411           7    112438           read
  6.01    0.218165       36360         6           close
  0.00    0.000079          13         6           openat
  0.00    0.000049          24         2           munmap
  0.00    0.000047           9         5           mprotect
  0.00    0.000030           2        13           mmap
  0.00    0.000017           3         5           rt_sigaction
  0.00    0.000017           5         3           sigaltstack
  0.00    0.000015           5         3           brk
  0.00    0.000010           5         2           statx
  0.00    0.000009           9         1           fchmod
  0.00    0.000008           4         2           prlimit64
  0.00    0.000006           6         1           poll
  0.00    0.000005           5         1           getrandom
  0.00    0.000004           1         4           fstat
  0.00    0.000004           4         1           arch_prctl
  0.00    0.000004           4         1           sched_getaffinity
  0.00    0.000004           4         1           set_tid_address
  0.00    0.000004           4         1         1 copy_file_range
  0.00    0.000004           4         1           rseq
  0.00    0.000003           3         1           set_robust_list
  0.00    0.000000           0         2           pread64
  0.00    0.000000           0         1         1 access
  0.00    0.000000           0         1           execve
------ ----------- ----------- --------- --------- ------------------
100.00    3.628422          16    224935         2 total

sxyazi commented 3 weeks ago

This is weird, I don't see what the problem is, I'm not an expert on this, my best guess is this may be related to your USB driver, or a bug in the kernel

I suggest submitting it to rust to see what they say, since we have determined that this is a problem only with io::copy() but not fs::copy()

sxyazi / yazi