iiab / calibre-web

:books: Web app for browsing, reading and downloading eBooks stored in a Calibre database
GNU General Public License v3.0
4 stars 4 forks source link

"Download to IIAB" button fails every time on Ubuntu 24.10 — "An error occurred during the subprocess execution: 'NoneType' object is not subscriptable" and later "failed to download: None" — perhaps b/c xklb marked your video as deleted because it failed to download in previous tries? #267

Open holta opened 4 days ago

holta commented 4 days ago

Both a YouTube Short video (https://www.youtube.com/shorts/M_Zt5K057xs) and a regular YouTube video https://youtu.be/zRM2AnwNY20 (The Wild Story of the Taum Sauk Dam Failure) failed to download repeatedly, to this Ubuntu 24.10 VM.

Rebooting did not help:

image

image

image

root@box:~# yt-dlp --version
2024.10.07
root@box:~# lb --version
2.9.066

iiab-diagnostics: https://paste.centos.org/view/a53f9107 (that'll disappear in 4 weeks!)

[2024-10-17 08:58:49,206] ERROR {cps.tasks.download:131} An error occurred during the subprocess execution: 'NoneType' object is not subscriptable

Full excerpt (Lines 1122-1127) below:

[2024-10-17 08:58:44,004] DEBUG {cps.services.worker:91} Add Task for user: Admin - Metadata fetch task for https://youtu.be/zRM2AnwNY20
[2024-10-17 08:58:44,914]  INFO {cps.tasks.metadata_extract:155} Starting to fetch metadata for URL: https://youtu.be/zRM2AnwNY20
[2024-10-17 08:58:48,179] DEBUG {cps.services.worker:91} Add Task for user: Admin - Download task for https://www.youtube.com/watch?v=zRM2AnwNY20
[2024-10-17 08:58:48,179]  INFO {cps.tasks.download:43} Subprocess args: ['lb-wrapper', 'dl', 'https://www.youtube.com/watch?v=zRM2AnwNY20']
[2024-10-17 08:58:49,206] ERROR {cps.tasks.download:131} An error occurred during the subprocess execution: 'NoneType' object is not subscriptable
[2024-10-17 08:58:49,207]  INFO {cps.tasks.download:138} Download task for https://www.youtube.com/watch?v=zRM2AnwNY20 completed successfully
2024-10-17 08:58:49 - [Debug] [best]: Download was marked as deleted 6 minutes and 49 seconds ago. Skipping!
2024-10-17 08:58:49 - [Info] lb-wrapper's xklb command (dl) completed successfully.

@deldesir suggests this is what happened:

What happened is xklb marked your video as deleted because it failed to download in previous tries. Once a media item is marked as deleted, future iterations of the download function of lb dl will recognize this status and skip attempting to download it again.

https://github.com/chapmanjacobd/library/blob/6b096aac98d3dcc62727579d5e0b7092ef590201/xklb/mediadb/download.py#L125-L160

xklb has lb redownload for this, but it will try to [redownload all failed videos]

image

RECAP QUESTIONS:

  1. @deldesir were you able to learn anything by logging into the .0.10 VM directly?

  2. Is this issue the same as #212 ? Or at least similar?? Or not at all?!

  3. What short-term CLI hack or workaround gets IIAB Calibre-Web machines like this able to download again? So that can quickly be written into https://github.com/iiab/calibre-web/wiki

  4. What long-term fix or reimplementation is most appropriate — so that this stop happening entirely ?

  5. Finally, how can we make real progress in removing errors like An error occurred during the subprocess execution: 'NoneType' object is not subscriptable from educators' web UI — in favor of much more specific and human-readable explanation in 2025?

    • 202 begins to address this serious lack non-specific and non-readable Tasks view messages — but is a new ticket needed to make sure this is solved properly?

holta commented 4 days ago

FYI I tried the following:

systemctl stop calibre-web
cd /library/calibre-web
mv xklb-metadata.db xklb-metadata.db.BKP
systemctl start calibre-web

Then I tried "Download to IIAB" with https://youtu.be/zRM2AnwNY20 again.

Result is:

image

NOTICE the slightly different error message in Tasks view: failed to download: None

New iiab-diagnostics: https://paste.centos.org/view/3eb329f8

@deldesir can you please log in to .0.10 to investigate?

holta commented 3 days ago
  • Is this mysterious msg at the bottom of /var/log/xklb.log relevant/meaningful ❓
2024-10-17 08:58:49 - [Debug] [best]: Download was marked as deleted 6 minutes and 49 seconds ago. Skipping!
2024-10-17 08:58:49 - [Info] lb-wrapper's xklb command (dl) completed successfully.

@deldesir what are all these best messages telling us, can you help explain?

root@box:~# grep -n '\[best\]' /var/log/xklb.log
51:2024-10-17 08:52:00 - [Debug] [best]: yt-dlp ERROR: [generic] 'best' is not a valid URL. Set --default-search "ytsearch" (or run  yt-dlp "ytsearch:best" ) to search YouTube
52:2024-10-17 08:52:00 - [Debug] [best]: yt-dlp returned no info
53:2024-10-17 08:52:00 - [Debug] [best]: Unrecoverable error matched. ERROR: [generic] 'best' is not a valid URL. Set --default-search "ytsearch" (or run yt-dlp "ytsearch:best" ) to search YouTube
79:2024-10-17 08:54:44 - [Debug] [best]: Download was marked as deleted 2 minutes and 45 seconds ago. Skipping!
104:2024-10-17 08:58:49 - [Debug] [best]: Download was marked as deleted 6 minutes and 49 seconds ago. Skipping!
129:2024-10-17 11:59:45 - [Debug] [best]: Download was marked as deleted 3 hours and 8 minutes ago. Skipping!
182:2024-10-18 09:05:50 - [Debug] [best]: yt-dlp ERROR: [generic] 'best' is not a valid URL. Set --default-search "ytsearch" (or run  yt-dlp "ytsearch:best" ) to search YouTube
183:2024-10-18 09:05:50 - [Debug] [best]: yt-dlp returned no info
184:2024-10-18 09:05:50 - [Debug] [best]: Unrecoverable error matched. ERROR: [generic] 'best' is not a valid URL. Set --default-search "ytsearch" (or run yt-dlp "ytsearch:best" ) to search YouTube
holta commented 3 days ago

All 30 mentions of best in /var/log/xklb.log are hereunder if it helps!

root@box:~# grep -n 'best' /var/log/xklb.log
43:2024-10-17 08:51:59 - [Info] Running xklb command: lb dl '/library/calibre-web/xklb-metadata.db' --video --search 'https://www.youtube.com/watch?v=M_Zt5K057xs' --format best --format-sort 'tbr~1000' --write-thumbnail --subs --live --live-from-start -o '/library/downloads/calibre-web/%(extractor_key,extractor)s/%(uploader,uploader_id)s/%(title).170B_%(view_count)3.2D_[%(id).64B].%(ext)s' -vv
45:2024-10-17 08:52:00 - [Debug] ['/usr/local/bin/lb', 'dl', '/library/calibre-web/xklb-metadata.db', '--video', '--search', 'https://www.youtube.com/watch?v=M_Zt5K057xs', '--format', 'best', '--format-sort', 'tbr~1000', '--write-thumbnail', '--subs', '--live', '--live-from-start', '-o', '/library/downloads/calibre-web/%(extractor_key,extractor)s/%(uploader,uploader_id)s/%(title).170B_%(view_count)3.2D_[%(id).64B].%(ext)s', '-vv']
46:2024-10-17 08:52:00 - [Debug] {'include': ['https://www.youtube.com/watch?v=M_Zt5K057xs'], 'subs': True, 'live': True, 'paths': ['best']}
48:2024-10-17 08:52:00 - [Debug] {'path': 'best'}
49:2024-10-17 08:52:00 - [Debug] {'noprogress': True, 'lazy_playlist': True, 'noplaylist': True, 'no_check_certificate': True, 'ignore_no_formats_error': True, 'skip_playlist_after_errors': 21, 'playlistend': 20000, 'extractor_args': {'youtube': {'skip': ['authcheck']}}, 'check_formats': 'selected', 'logger': <xklb.createdb.tube_backend.download.<locals>.DictLogger object at 0x719a57287080>, 'postprocessors': [{'key': 'FFmpegMetadata'}, {'key': 'FFmpegEmbedSubtitle'}], 'playlist_items': '1', 'extractor_retries': 3, 'retries': 12, 'retry_sleep_functions': {'extractor': <function download.<locals>.<lambda> at 0x719a5729f880>, 'http': <function download.<locals>.<lambda> at 0x719a5729f920>, 'fragment': <function download.<locals>.<lambda> at 0x719a5729f9c0>}, 'outtmpl': {'default': '/library/downloads/calibre-web/%(extractor_key,extractor)s/%(uploader,uploader_id)s/%(title).170B_%(view_count)3.2D_[%(id).64B].%(ext)s'}, 'progress_hooks': [<function download.<locals>.<lambda> at 0x719a5729fa60>], 'subtitlesformat': 'srt/best', 'writesubtitles': True, 'writeautomaticsub': True, 'format': '--format-sort', 'writethumbnail': True, 'live_from_start': True, 'include': ['https://www.youtube.com/watch?v=M_Zt5K057xs'], 'subs': True, 'live': True}
50:2024-10-17 08:52:00 - [Debug] [yt-dlp]: Downloading best
51:2024-10-17 08:52:00 - [Debug] [best]: yt-dlp ERROR: [generic] 'best' is not a valid URL. Set --default-search "ytsearch" (or run  yt-dlp "ytsearch:best" ) to search YouTube
52:2024-10-17 08:52:00 - [Debug] [best]: yt-dlp returned no info
53:2024-10-17 08:52:00 - [Debug] [best]: Unrecoverable error matched. ERROR: [generic] 'best' is not a valid URL. Set --default-search "ytsearch" (or run yt-dlp "ytsearch:best" ) to search YouTube
74:2024-10-17 08:54:43 - [Info] Running xklb command: lb dl '/library/calibre-web/xklb-metadata.db' --video --search 'https://www.youtube.com/watch?v=M_Zt5K057xs' --format best --format-sort 'tbr~1000' --write-thumbnail --subs --live --live-from-start -o '/library/downloads/calibre-web/%(extractor_key,extractor)s/%(uploader,uploader_id)s/%(title).170B_%(view_count)3.2D_[%(id).64B].%(ext)s' -vv
76:2024-10-17 08:54:44 - [Debug] ['/usr/local/bin/lb', 'dl', '/library/calibre-web/xklb-metadata.db', '--video', '--search', 'https://www.youtube.com/watch?v=M_Zt5K057xs', '--format', 'best', '--format-sort', 'tbr~1000', '--write-thumbnail', '--subs', '--live', '--live-from-start', '-o', '/library/downloads/calibre-web/%(extractor_key,extractor)s/%(uploader,uploader_id)s/%(title).170B_%(view_count)3.2D_[%(id).64B].%(ext)s', '-vv']
77:2024-10-17 08:54:44 - [Debug] {'include': ['https://www.youtube.com/watch?v=M_Zt5K057xs'], 'subs': True, 'live': True, 'paths': ['best']}
79:2024-10-17 08:54:44 - [Debug] [best]: Download was marked as deleted 2 minutes and 45 seconds ago. Skipping!
99:2024-10-17 08:58:48 - [Info] Running xklb command: lb dl '/library/calibre-web/xklb-metadata.db' --video --search 'https://www.youtube.com/watch?v=zRM2AnwNY20' --format best --format-sort 'tbr~1000' --write-thumbnail --subs --live --live-from-start -o '/library/downloads/calibre-web/%(extractor_key,extractor)s/%(uploader,uploader_id)s/%(title).170B_%(view_count)3.2D_[%(id).64B].%(ext)s' -vv
101:2024-10-17 08:58:48 - [Debug] ['/usr/local/bin/lb', 'dl', '/library/calibre-web/xklb-metadata.db', '--video', '--search', 'https://www.youtube.com/watch?v=zRM2AnwNY20', '--format', 'best', '--format-sort', 'tbr~1000', '--write-thumbnail', '--subs', '--live', '--live-from-start', '-o', '/library/downloads/calibre-web/%(extractor_key,extractor)s/%(uploader,uploader_id)s/%(title).170B_%(view_count)3.2D_[%(id).64B].%(ext)s', '-vv']
102:2024-10-17 08:58:48 - [Debug] {'include': ['https://www.youtube.com/watch?v=zRM2AnwNY20'], 'subs': True, 'live': True, 'paths': ['best']}
104:2024-10-17 08:58:49 - [Debug] [best]: Download was marked as deleted 6 minutes and 49 seconds ago. Skipping!
124:2024-10-17 11:59:44 - [Info] Running xklb command: lb dl '/library/calibre-web/xklb-metadata.db' --video --search 'https://www.youtube.com/watch?v=zRM2AnwNY20' --format best --format-sort 'tbr~1000' --write-thumbnail --subs --live --live-from-start -o '/library/downloads/calibre-web/%(extractor_key,extractor)s/%(uploader,uploader_id)s/%(title).170B_%(view_count)3.2D_[%(id).64B].%(ext)s' -vv
126:2024-10-17 11:59:45 - [Debug] ['/usr/local/bin/lb', 'dl', '/library/calibre-web/xklb-metadata.db', '--video', '--search', 'https://www.youtube.com/watch?v=zRM2AnwNY20', '--format', 'best', '--format-sort', 'tbr~1000', '--write-thumbnail', '--subs', '--live', '--live-from-start', '-o', '/library/downloads/calibre-web/%(extractor_key,extractor)s/%(uploader,uploader_id)s/%(title).170B_%(view_count)3.2D_[%(id).64B].%(ext)s', '-vv']
127:2024-10-17 11:59:45 - [Debug] {'include': ['https://www.youtube.com/watch?v=zRM2AnwNY20'], 'subs': True, 'live': True, 'paths': ['best']}
129:2024-10-17 11:59:45 - [Debug] [best]: Download was marked as deleted 3 hours and 8 minutes ago. Skipping!
174:2024-10-18 09:05:49 - [Info] Running xklb command: lb dl '/library/calibre-web/xklb-metadata.db' --video --search 'https://www.youtube.com/watch?v=zRM2AnwNY20' --format best --format-sort 'tbr~1000' --write-thumbnail --subs --live --live-from-start -o '/library/downloads/calibre-web/%(extractor_key,extractor)s/%(uploader,uploader_id)s/%(title).170B_%(view_count)3.2D_[%(id).64B].%(ext)s' -vv
176:2024-10-18 09:05:49 - [Debug] ['/usr/local/bin/lb', 'dl', '/library/calibre-web/xklb-metadata.db', '--video', '--search', 'https://www.youtube.com/watch?v=zRM2AnwNY20', '--format', 'best', '--format-sort', 'tbr~1000', '--write-thumbnail', '--subs', '--live', '--live-from-start', '-o', '/library/downloads/calibre-web/%(extractor_key,extractor)s/%(uploader,uploader_id)s/%(title).170B_%(view_count)3.2D_[%(id).64B].%(ext)s', '-vv']
177:2024-10-18 09:05:49 - [Debug] {'include': ['https://www.youtube.com/watch?v=zRM2AnwNY20'], 'subs': True, 'live': True, 'paths': ['best']}
179:2024-10-18 09:05:49 - [Debug] {'path': 'best'}
180:2024-10-18 09:05:49 - [Debug] {'noprogress': True, 'lazy_playlist': True, 'noplaylist': True, 'no_check_certificate': True, 'ignore_no_formats_error': True, 'skip_playlist_after_errors': 21, 'playlistend': 20000, 'extractor_args': {'youtube': {'skip': ['authcheck']}}, 'check_formats': 'selected', 'logger': <xklb.createdb.tube_backend.download.<locals>.DictLogger object at 0x7a1068560aa0>, 'postprocessors': [{'key': 'FFmpegMetadata'}, {'key': 'FFmpegEmbedSubtitle'}], 'playlist_items': '1', 'extractor_retries': 3, 'retries': 12, 'retry_sleep_functions': {'extractor': <function download.<locals>.<lambda> at 0x7a106856dbc0>, 'http': <function download.<locals>.<lambda> at 0x7a106856dc60>, 'fragment': <function download.<locals>.<lambda> at 0x7a106856dd00>}, 'outtmpl': {'default': '/library/downloads/calibre-web/%(extractor_key,extractor)s/%(uploader,uploader_id)s/%(title).170B_%(view_count)3.2D_[%(id).64B].%(ext)s'}, 'progress_hooks': [<function download.<locals>.<lambda> at 0x7a106856dda0>], 'subtitlesformat': 'srt/best', 'writesubtitles': True, 'writeautomaticsub': True, 'format': '--format-sort', 'writethumbnail': True, 'live_from_start': True, 'include': ['https://www.youtube.com/watch?v=zRM2AnwNY20'], 'subs': True, 'live': True}
181:2024-10-18 09:05:49 - [Debug] [yt-dlp]: Downloading best
182:2024-10-18 09:05:50 - [Debug] [best]: yt-dlp ERROR: [generic] 'best' is not a valid URL. Set --default-search "ytsearch" (or run  yt-dlp "ytsearch:best" ) to search YouTube
183:2024-10-18 09:05:50 - [Debug] [best]: yt-dlp returned no info
184:2024-10-18 09:05:50 - [Debug] [best]: Unrecoverable error matched. ERROR: [generic] 'best' is not a valid URL. Set --default-search "ytsearch" (or run yt-dlp "ytsearch:best" ) to search YouTube
holta commented 3 days ago

I tried again with longer-form (canonical) URL https://www.youtube.com/watch?v=zRM2AnwNY20 for the same video:

After running this:

systemctl stop calibre-web
cd /library/calibre-web
mv xklb-metadata.db xklb-metadata.db.BKP2
systemctl start calibre-web

The result is the same (failed to download: None) as seen below:

image

holta commented 3 days ago
holta commented 3 days ago
  • Debian 13 should be tested next, to see what happens there?!

Verdict / FYI: Video downloads work on a fresh & fully-updated Debian 13 Trixie VM install❗

holta commented 3 days ago

@deldesir and I were wondering if Ubuntu 24.10's bash version might be causing this new problem. But that would appear not to be true, as Debian 13 (works!) and Ubuntu 24.10 (doesn't work!) are running the exact same version of bash:

root@box:~# bash --version
GNU bash, version 5.2.32(1)-release (x86_64-pc-linux-gnu)
Copyright (C) 2022 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>

This is free software; you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.

Whereas Ubuntu 24.04 shows...

root@u2404-desk:~# bash --version
GNU bash, version 5.2.21(1)-release (x86_64-pc-linux-gnu)
Copyright (C) 2022 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>

This is free software; you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.