yt-dlp / yt-dlp

A feature-rich command-line audio/video downloader
https://discord.gg/H5MNcFW63r
The Unlicense
81.81k stars 6.38k forks source link

"[Errno 18] Invalid cross-device link" when temporary path is on a different filesystem in WSL #8088

Open chylex opened 12 months ago

chylex commented 12 months ago

DO NOT REMOVE OR SKIP THE ISSUE TEMPLATE

Checklist

Provide a description that is worded well enough to be understood

Hi!

I have a WSL1 instance connected to an SMB server. The SMB server is the X: drive on Windows, and then mounted to /mnt/x via sudo mount -t drvfs X: /mnt/x.

Running the following command in a WSL1 terminal:

yt-dlp -vU \
        --paths "home:/mnt/x/yt-dlp" \
        --paths "temp:/tmp/yt-dlp" \
        "https://www.youtube.com/watch?v=BaW_jenozKc"

produces the mentioned error when moving the file from temp to home. The file is successfully copied to home, but it never gets deleted from temp.

Provide verbose output that clearly demonstrates the problem

Complete Verbose Output

[debug] Command-line config: ['-vU', '--paths', 'home:/mnt/x/yt-dlp', '--paths', 'temp:/tmp/yt-dlp', 'https://www.youtube.com/watch?v=BaW_jenozKc']
[debug] Encodings: locale UTF-8, fs utf-8, pref UTF-8, out utf-8 (No ANSI), error utf-8 (No ANSI), screen utf-8 (No ANSI)
[debug] yt-dlp version stable@2023.07.06 [b532a3481] (zip)
[debug] Python 3.11.2 (CPython x86_64 64bit) - Linux-4.4.0-19041-Microsoft-x86_64-with-glibc2.36 (OpenSSL 3.0.9 30 May 2023, glibc 2.36)
[debug] exe versions: ffmpeg 6.0-static (setts), ffprobe 6.0-static
[debug] Optional libraries: mutagen-1.46.0, sqlite3-2.6.0
[debug] Proxy map: {}
[debug] Loaded 1855 extractors
[debug] Fetching release info: https://api.github.com/repos/yt-dlp/yt-dlp/releases/latest
Available version: stable@2023.07.06, Current version: stable@2023.07.06
Current Build Hash: cedf44a9cf3c241520a692c1006d276e6f434d4d945727c47cb1a70d32953f4a
yt-dlp is up to date (stable@2023.07.06)
[youtube] Extracting URL: https://www.youtube.com/watch?v=BaW_jenozKc
[youtube] BaW_jenozKc: Downloading webpage
WARNING: [youtube] unable to extract initial player response; please report this issue on  https://github.com/yt-dlp/yt-dlp/issues?q= , filling out the appropriate issue template. Confirm you are on the latest version using  yt-dlp -U
[youtube] BaW_jenozKc: Downloading ios player API JSON
[youtube] BaW_jenozKc: Downloading android player API JSON
[youtube] BaW_jenozKc: Downloading iframe API JS
[youtube] BaW_jenozKc: Downloading player 7ee36b0e
[youtube] BaW_jenozKc: Downloading web player API JSON
[youtube] BaW_jenozKc: Downloading m3u8 information
WARNING: [youtube] unable to extract yt initial data; please report this issue on  https://github.com/yt-dlp/yt-dlp/issues?q= , filling out the appropriate issue template. Confirm you are on the latest version using  yt-dlp -U
WARNING: [youtube] Incomplete data received in embedded initial data; re-fetching using API.
[youtube] BaW_jenozKc: Downloading initial data API JSON
[debug] Sort order given by extractor: quality, res, fps, hdr:12, source, vcodec:vp9.2, channels, acodec, lang, proto
[debug] Formats sorted by: hasvid, ie_pref, quality, res, fps, hdr:12(7), source, vcodec:vp9.2(10), channels, acodec, lang, proto, size, br, asr, vext, aext, hasaud, id
[debug] Default format spec: bestvideo*+bestaudio/best
[info] BaW_jenozKc: Downloading 1 format(s): 248+251
[debug] Invoking http downloader on "https://rr5---sn-2gb7sn7y.googlevideo.com/videoplayback?expire=1694530799&ei=jygAZePACOy06dsP2qujiAE&ip=2a0c%3A8b40%3A120%3A0%3A304f%3A4f63%3A2f8a%3Ae7e5&id=o-AEScU30gbvFYfKer9oaJgSrbYjMalle2yVjEsx8mkBn2&itag=248&source=youtube&requiressl=yes&mh=Rf&mm=31%2C26&mn=sn-2gb7sn7y%2Csn-c0q7lns7&ms=au%2Conr&mv=m&mvi=5&pl=29&initcwndbps=898750&vprv=1&svpuc=1&mime=video%2Fwebm&gir=yes&clen=988479&dur=9.833&lmt=1544741703689523&mt=1694508807&fvip=4&keepalive=yes&fexp=24007246%2C24363393&c=IOS&txp=5432432&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cvprv%2Csvpuc%2Cmime%2Cgir%2Cclen%2Cdur%2Clmt&sig=AOq0QJ8wRgIhAOQfy-arFAP4sVjxITYkc6oRAerhyHJGcSlZJlAH_RxfAiEAnZyuw00oVJDFNK30MX-Ehb9kEC_Q0d33AeVyhEMuhMU%3D&lsparams=mh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Cinitcwndbps&lsig=AG3C_xAwRQIgAImgMjFISfi-qGjSO-M2O29CWeWz97WJ_qAhBrJRp6cCIQDfvfWA_TckI9QbhUQMNvvczh8geL3dAYAz3GKgMKJ2yQ%3D%3D"
[download] Destination: /tmp/yt-dlp/youtube-dl test video "'⧸⧹ä↭𝕐 [BaW_jenozKc].f248.webm

[download]   0.1% of  965.31KiB at  333.68KiB/s ETA 00:02
[download]   0.3% of  965.31KiB at  927.05KiB/s ETA 00:01
[download]   0.7% of  965.31KiB at    1.98MiB/s ETA 00:00
[download]   1.6% of  965.31KiB at    4.07MiB/s ETA 00:00
[download]   3.2% of  965.31KiB at    2.20MiB/s ETA 00:00
[download]   6.5% of  965.31KiB at    2.27MiB/s ETA 00:00
[download]  13.2% of  965.31KiB at    3.60MiB/s ETA 00:00
[download]  26.4% of  965.31KiB at    5.33MiB/s ETA 00:00
[download]  52.9% of  965.31KiB at    8.57MiB/s ETA 00:00
[download] 100.0% of  965.31KiB at   12.00MiB/s ETA 00:00
[download] 100% of  965.31KiB in 00:00:00 at 7.98MiB/s   
[debug] Invoking http downloader on "https://rr5---sn-2gb7sn7y.googlevideo.com/videoplayback?expire=1694530799&ei=jygAZcbiJouCgQfBk67gAQ&ip=2a0c%3A8b40%3A120%3A0%3A304f%3A4f63%3A2f8a%3Ae7e5&id=o-ALSBS5JhVJjzgiUL3M1SRS0oqsLF9TPQHE2N4pkA-lrm&itag=251&source=youtube&requiressl=yes&mh=Rf&mm=31%2C26&mn=sn-2gb7sn7y%2Csn-c0q7lns7&ms=au%2Conr&mv=m&mvi=5&pl=29&initcwndbps=1226250&spc=UWF9f2mhCL3YCUyt3ZkTtqi1lCgxgbg&vprv=1&svpuc=1&mime=audio%2Fwebm&gir=yes&clen=142292&dur=9.841&lmt=1506055557712479&mt=1694509028&fvip=4&keepalive=yes&fexp=24007246%2C51000022&beids=24350017&c=ANDROID&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cgir%2Cclen%2Cdur%2Clmt&sig=AOq0QJ8wRgIhAMHHDeszkIw8nwGeYNLt59C85vGkl-IRuAoHJAPFj9JcAiEAgdzTKCHibk6K14PMB5SFdA3gckytO7K1oqzAg9tajSU%3D&lsparams=mh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Cinitcwndbps&lsig=AG3C_xAwRgIhANwFCH1yDwtT0wfEj1CJnYxSOCocojMfdw6VCTLqDI-YAiEA6eYGFH3ynFI7StSSKVu3Hs5ni6ieHeEAzRjMy-4dMZQ%3D"
[download] Destination: /tmp/yt-dlp/youtube-dl test video "'⧸⧹ä↭𝕐 [BaW_jenozKc].f251.webm

[download]   0.7% of  138.96KiB at  316.74KiB/s ETA 00:00
[download]   2.2% of  138.96KiB at  888.87KiB/s ETA 00:00
[download]   5.0% of  138.96KiB at    1.92MiB/s ETA 00:00
[download]  10.8% of  138.96KiB at    3.93MiB/s ETA 00:00
[download]  22.3% of  138.96KiB at    3.02MiB/s ETA 00:00
[download]  45.3% of  138.96KiB at    4.02MiB/s ETA 00:00
[download]  91.4% of  138.96KiB at    5.11MiB/s ETA 00:00
[download] 100.0% of  138.96KiB at    5.36MiB/s ETA 00:00
[download] 100% of  138.96KiB in 00:00:00 at 2.02MiB/s   
[Merger] Merging formats into "/tmp/yt-dlp/youtube-dl test video "'⧸⧹ä↭𝕐 [BaW_jenozKc].webm"
[debug] ffmpeg command line: ffmpeg -y -loglevel repeat+info -i 'file:/tmp/yt-dlp/youtube-dl test video "'"'"'⧸⧹ä↭𝕐 [BaW_jenozKc].f248.webm' -i 'file:/tmp/yt-dlp/youtube-dl test video "'"'"'⧸⧹ä↭𝕐 [BaW_jenozKc].f251.webm' -c copy -map 0:v:0 -map 1:a:0 -movflags +faststart 'file:/tmp/yt-dlp/youtube-dl test video "'"'"'⧸⧹ä↭𝕐 [BaW_jenozKc].temp.webm'
Deleting original file /tmp/yt-dlp/youtube-dl test video "'⧸⧹ä↭𝕐 [BaW_jenozKc].f248.webm (pass -k to keep)
Deleting original file /tmp/yt-dlp/youtube-dl test video "'⧸⧹ä↭𝕐 [BaW_jenozKc].f251.webm (pass -k to keep)
[MoveFiles] Moving file "/tmp/yt-dlp/youtube-dl test video "'⧸⧹ä↭𝕐 [BaW_jenozKc].webm" to "/mnt/x/yt-dlp/youtube-dl test video "'⧸⧹ä↭𝕐 [BaW_jenozKc].webm"
ERROR: [Errno 1] Operation not permitted
Traceback (most recent call last):
  File "/usr/lib/python3.11/shutil.py", line 825, in move
    os.rename(src, real_dst)
OSError: [Errno 18] Invalid cross-device link: "/tmp/yt-dlp/youtube-dl test video "'⧸⧹ä↭𝕐 [BaW_jenozKc].webm" -> "/mnt/x/yt-dlp/youtube-dl test video "'⧸⧹ä↭𝕐 [BaW_jenozKc].webm"

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/chylex/.local/bin/yt-dlp/yt_dlp/YoutubeDL.py", line 1560, in wrapper
    return func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/chylex/.local/bin/yt-dlp/yt_dlp/YoutubeDL.py", line 1709, in __extract_info
    return self.process_ie_result(ie_result, download, extra_info)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/chylex/.local/bin/yt-dlp/yt_dlp/YoutubeDL.py", line 1768, in process_ie_result
    ie_result = self.process_video_result(ie_result, download=download)
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/chylex/.local/bin/yt-dlp/yt_dlp/YoutubeDL.py", line 2897, in process_video_result
    self.process_info(new_info)
  File "/home/chylex/.local/bin/yt-dlp/yt_dlp/YoutubeDL.py", line 3439, in process_info
    replace_info_dict(self.post_process(dl_filename, info_dict, files_to_move))
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/chylex/.local/bin/yt-dlp/yt_dlp/YoutubeDL.py", line 3622, in post_process
    info = self.run_pp(MoveFilesAfterDownloadPP(self), info)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/chylex/.local/bin/yt-dlp/yt_dlp/YoutubeDL.py", line 3581, in run_pp
    files_to_delete, infodict = pp.run(infodict)
                                ^^^^^^^^^^^^^^^^
  File "/home/chylex/.local/bin/yt-dlp/yt_dlp/postprocessor/common.py", line 24, in run
    ret = func(self, info, *args, **kwargs)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/chylex/.local/bin/yt-dlp/yt_dlp/postprocessor/movefilesafterdownload.py", line 50, in run
    shutil.move(oldfile, newfile)  # os.rename cannot move between volumes
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/shutil.py", line 845, in move
    copy_function(src, real_dst)
  File "/usr/lib/python3.11/shutil.py", line 437, in copy2
    copystat(src, dst, follow_symlinks=follow_symlinks)
  File "/usr/lib/python3.11/shutil.py", line 376, in copystat
    lookup("utime")(dst, ns=(st.st_atime_ns, st.st_mtime_ns),
PermissionError: [Errno 1] Operation not permitted
chylex commented 12 months ago

It looks like this breaks the functionality of --download-archive, it hasn't added any new entries since I started using the --paths parameter to set a different temp folder.

bashonly commented 12 months ago

Where is the rest of the log? Please do not remove debug header info

OSError: [Errno 18] Invalid cross-device link is not the error being thrown, it is caught and being handled, during which the actual error PermissionError: [Errno 1] Operation not permitted is thrown.

shutil.move is used to move the file from temp dir to final dir, because as the code comment notes: "os.rename cannot move between volumes"

But shutil.move first tries os.rename, and catches the OSError (the above-mentioned Errno 18), and then retries with platform-specific methods meant to handle moving files between different filesystems.

The fallback method tries to copy the file to the destination directory and then remove it from the source directory in separate steps. After the file itself is copied, then it tries to copy over the file's permissions and metadata, and it is on this line that it throws the PermissionError:

lookup("utime")(dst, ns=(st.st_atime_ns, st.st_mtime_ns),

I did some digging into this, and it appears that this is due to a bug/limitation in WSL1: https://github.com/microsoft/WSL/issues/5742

Unfortunately, the WSL developers have opted not to fix this in WSL1, and have closed the issue as fixed-in-wsl2

You could try running yt-dlp with sudo to see if that works around the issue. Or else you may need to upgrade to WSL2

dirkf commented 12 months ago

--paths allows what have always been simple file moves to become potentially lengthy copy operations, but let's assume that, as implied by the code comment, this is an intended feature.

Python documentation, echoed by the code comment, states that shutil.move() should be used rather than os.rename() to avoid an error when the destination isn't on the same filesystem, but SO commenters suggest that this can also fail, and this shows one failure mode, apparently a Python library bug. The source says:

A lot more could be done here... A look at a mv.c shows a lot of the issues this implementation glosses over.

The sequence here is that the file is moved by copying it, then copying some file metadata, and finally deleting the original. As step 2 fails, the original file isn't deleted. Stricter, but perhaps less useful, error handling would have erased the copied file rather than leaving the operation half-complete.

A hint as to how this should be fixed is that the _copytree() routine actually catches the specific error

    try:
        copystat(src, dst)
    except OSError as why:
        # Copying file access times may fail on Windows
        if getattr(why, 'winerror', None) is None:
            errors.append((src, dst, str(why)))

whereas the copy2() routine that just copies a single file doesn't, because as the specification of shutil.copystat() notes:

... copystat() never returns failure.

If the above were true (and assuming, since the function doesn't return anything, that "returns failure" means "raises any Exception"), the error reported here could not happen.

chylex commented 12 months ago

Where is the rest of the log? Please do not remove debug header info

It's there, but for some reason it's formatted on one line.

image

It looks ok in GitHub's editor, not sure what's going on. Tried copy/pasting the log again but it did the exact same thing.

image

EDIT: I ran the command again and piped the log to a file instead of copying it from tmux, it looks ok now. Out of interest, this is the original debug header with the weird scrolling:

[debug] Command-line config: ['-vU', '--paths', 'home:/mnt/x/yt-dlp', '--paths', 'temp:/tmp/yt-dlp', 'https://www.youtube.com/watch?v=BaW_jenozKc']                                                                                                                                     [debug] Encodings: locale UTF-8, fs utf-8, pref UTF-8, out utf-8, error utf-8, screen utf-8                                                                                                                                                                                             [debug] yt-dlp version stable@2023.07.06 [b532a3481] (zip)                                                                                                                                                                                                                              [debug] Python 3.11.2 (CPython x86_64 64bit) - Linux-4.4.0-19041-Microsoft-x86_64-with-glibc2.36 (OpenSSL 3.0.9 30 May 2023, glibc 2.36)                                                                                                                                                [debug] exe versions: ffmpeg 6.0-static (setts), ffprobe 6.0-static                                                                                                                                                                                                                     [debug] Optional libraries: mutagen-1.46.0, sqlite3-2.6.0                                                                                                                                                                                                                               [debug] Proxy map: {}                                                                                                                                                                                                                                                                   [debug] Loaded 1855 extractors                                                                                                                                                                                                                                                          [debug] Fetching release info: https://api.github.com/repos/yt-dlp/yt-dlp/releases/latest                                                                                                                                                                                               Available version: stable@2023.07.06, Current version: stable@2023.07.06                                                                                                                                                                                                                Current Build Hash: cedf44a9cf3c241520a692c1006d276e6f434d4d945727c47cb1a70d32953f4a                                                                                                                                                                                                    yt-dlp is up to date (stable@2023.07.06)                                         
chylex commented 12 months ago

You could try running yt-dlp with sudo to see if that works around the issue.

That does appear to work around the issue, thanks for the tip. Since this seems to be an issue with Python's error handling, do you think it'd be an acceptable solution to catch this error when shutil.move is called, and fallback to a simple copy+delete? I could make a PR for it.

dirkf commented 12 months ago

Does the compat mechanism support replacing shutil.copystat() with a version wrapped in with contextlib.suppress(Exception): such that the wrapped version is used by shutil.copy2()? That would make the module behaviour match the doc/spec:

... On platforms where some or all of this functionality is unavailable, copy2() will preserve all the metadata it can; copy2() never raises an exception because it cannot preserve file metadata.

copy2() uses copystat() to copy the file metadata. ...