Livestreams always fail but archives work

[bcbwatt]

As the title says, archiving livestreams has been failing for me on every stream for the past few days. I'm using version bed6100dfa6f889b22244ad854d5a15983e16433-2023-7-22.

Every livestream fails at the "video download" stage. I see no logs in the folder, and nothing when I open the popup for them. If I restart, it fails immediately like so:

[cli][info] Found matching plugin twitch for URL https://twitch.tv/videos/40494320615
Traceback (most recent call last):
  File "/usr/lib/python3.11/site-packages/streamlink/plugin/api/http_session.py", line 182, in request
    res.raise_for_status()
  File "/usr/lib/python3.11/site-packages/requests/models.py", line 1021, in raise_for_status
    raise HTTPError(http_error_msg, response=self)
requests.exceptions.HTTPError: 400 Client Error: Bad Request for url: https://usher.ttvnw.net/vod/40494320615?player=twitchweb&p=87331&type=any&allow_source=true&allow_audio_only=true&allow_spectre=false&nauthsig=401277994c48ce568cace394c7966c68c60ca7ce&nauth=%7B%22authorization%22%3A%7B%22forbidden%22%3Afalse%2C%22reason%22%3A%22%22%7D%2C%22chansub%22%3A%7B%22restricted_bitrates%22%3Anull%7D%2C%22device_id%22%3Anull%2C%22expires%22%3A4677266623%2C%22https_required%22%3Afalse%2C%22privileged%22%3Afalse%2C%22user_id%22%3Anull%2C%22version%22%3A2%2C%22vod_id%22%3A40494320615%7D

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.11/site-packages/streamlink/plugins/twitch.py", line 867, in _get_hls_streams
    streams = TwitchHLSStream.parse_variant_playlist(
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/streamlink/stream/hls.py", line 701, in parse_variant_playlist
    res = cls._fetch_variant_playlist(session, url, **request_args)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/streamlink/stream/hls.py", line 657, in _fetch_variant_playlist
    res = session.http.get(url, exception=OSError, **request_args)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/requests/sessions.py", line 602, in get
    return self.request("GET", url, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/streamlink/plugin/api/http_session.py", line 190, in request
    raise err
OSError: Unable to open URL: https://usher.ttvnw.net/vod/40494320615?player=twitchweb&p=87331&type=any&allow_source=true&allow_audio_only=true&allow_spectre=false&nauthsig=401277994c48ce568cace394c7966c68c60ca7ce&nauth=%7B%22authorization%22%3A%7B%22forbidden%22%3Afalse%2C%22reason%22%3A%22%22%7D%2C%22chansub%22%3A%7B%22restricted_bitrates%22%3Anull%7D%2C%22device_id%22%3Anull%2C%22expires%22%3A4677266623%2C%22https_required%22%3Afalse%2C%22privileged%22%3Afalse%2C%22user_id%22%3Anull%2C%22version%22%3A2%2C%22vod_id%22%3A40494320615%7D (400 Client Error: Bad Request for url: https://usher.ttvnw.net/vod/40494320615?player=twitchweb&p=87331&type=any&allow_source=true&allow_audio_only=true&allow_spectre=false&nauthsig=401277994c48ce568cace394c7966c68c60ca7ce&nauth=%7B%22authorization%22%3A%7B%22forbidden%22%3Afalse%2C%22reason%22%3A%22%22%7D%2C%22chansub%22%3A%7B%22restricted_bitrates%22%3Anull%7D%2C%22device_id%22%3Anull%2C%22expires%22%3A4677266623%2C%22https_required%22%3Afalse%2C%22privileged%22%3Afalse%2C%22user_id%22%3Anull%2C%22version%22%3A2%2C%22vod_id%22%3A40494320615%7D)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/bin/streamlink", line 8, in <module>
    sys.exit(main())
             ^^^^^^
  File "/usr/lib/python3.11/site-packages/streamlink_cli/main.py", line 924, in main
    handle_url()
  File "/usr/lib/python3.11/site-packages/streamlink_cli/main.py", line 547, in handle_url
    streams = fetch_streams(plugin)
              ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/streamlink_cli/main.py", line 445, in fetch_streams
    return plugin.streams(stream_types=args.stream_types,
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/streamlink/plugin/plugin.py", line 366, in streams
    ostreams = self._get_streams()
               ^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/streamlink/plugins/twitch.py", line 899, in _get_streams
    return self._get_hls_streams_video()
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/streamlink/plugins/twitch.py", line 856, in _get_hls_streams_video
    return self._get_hls_streams(url, restricted_bitrates, force_restart=True)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/streamlink/plugins/twitch.py", line 880, in _get_hls_streams
    raise PluginError(err) from err
TypeError: exception causes must derive from BaseException

I noticed there was a previous ticket regarding the creation of 1 second vods, so I tried the retry settings for streamlink. But they didn't change anything.

Using streamlink to archive the same channel with the same settings works. It only fails through ganymede for me. And as said before, downloading finished streams works just fine.

[Zibbp]

Hi, Can you enable debug logs in /data/config.json and restart the API container? Once enabled, can you post the logs related to when the queue job fails?

Do you have any custom streamlink parameters in Admin > Settings? Are you supplying your Twitch token for ad-free livestreams?

[bcbwatt]

This is what I see from the api logs:

ganymede-api         | {"level":"debug","time":"2023-07-31T23:25:20+01:00","message":"starting task video download for vod c16b7e4c-2fe7-11ee-b9ae-0242ac140002"}
ganymede-api         | {"level":"debug","time":"2023-07-31T23:25:20+01:00","message":"running streamlink for vod video download: https://twitch.tv/videos/40494320615 best,best --force-progress --force --twitch-api-header=Authorization=OAuth my_token_here -o /tmp/40494320615_c16b7e4c-2fe7-11ee-b9ae-0242ac140002-video.mp4"}
ganymede-api         | {"level":"error","error":"exit status 1","time":"2023-07-31T23:25:21+01:00","message":"error running streamlink for vod video download"}
ganymede-api         | {"level":"error","error":"exit status 1","time":"2023-07-31T23:25:21+01:00","message":"error downloading video"}

I am using a token now (to see if that changed anything; it did not).

My current streamlink parameters are:

--force-progress,--force,--twitch-low-latency,--twitch-disable-hosting,--loglevel=debug

[Zibbp]

Can you provide one of the channels it errors with? What architecture is your instance running on x86 or ARM? Also as a double check, is the Streamlink version 6.0.0 in Admin > Info?

[bcbwatt]

Streamlink is at version 6.0.0. I'm running on x86. https://www.twitch.tv/tororo_vtuber, for example. The api logs from scratch are as follows:

ganymede-api         | {"level":"debug","time":"2023-07-31T23:49:21+01:00","message":"getting live streams using the following query param: ?user_login=tororo_vtuber"}
ganymede-api         | {"level":"debug","time":"2023-07-31T23:49:21+01:00","message":"starting task vod create folder for vod 7d64e5e8-2ff4-11ee-b9ae-0242ac140002"}
ganymede-api         | {"level":"debug","time":"2023-07-31T23:49:21+01:00","message":"creating folder: tororo_vtuber/2023-07-31-40495023911-live-7d64e5e8-2ff4-11ee-b9ae-0242ac140002"}
ganymede-api         | {"level":"debug","time":"2023-07-31T23:49:21+01:00","message":"starting task vod download thumbnail for live stream 7d64e5e8-2ff4-11ee-b9ae-0242ac140002"}
ganymede-api         | {"level":"debug","time":"2023-07-31T23:49:21+01:00","message":"getting live streams using the following query param: ?user_login=tororo_vtuber"}
ganymede-api         | {"level":"debug","time":"2023-07-31T23:49:22+01:00","message":"downloading file: https://static-cdn.jtvnw.net/previews-ttv/live_user_tororo_vtuber-1920x1080.jpg"}
ganymede-api         | {"level":"debug","time":"2023-07-31T23:49:23+01:00","message":"downloading file: https://static-cdn.jtvnw.net/previews-ttv/live_user_tororo_vtuber-640x360.jpg"}
ganymede-api         | {"level":"debug","time":"2023-07-31T23:49:23+01:00","message":"starting task vod save info for vod 7d64e5e8-2ff4-11ee-b9ae-0242ac140002"}
ganymede-api         | {"level":"debug","time":"2023-07-31T23:49:23+01:00","message":"refresh live thumbnails called...sleeping for 20 minutes"}
ganymede-api         | {"level":"debug","time":"2023-07-31T23:49:23+01:00","message":"getting live streams using the following query param: ?user_login=tororo_vtuber"}
ganymede-api         | {"level":"debug","time":"2023-07-31T23:49:23+01:00","message":"starting task video download for live stream 7d64e5e8-2ff4-11ee-b9ae-0242ac140002"}
ganymede-api         | {"level":"debug","time":"2023-07-31T23:49:24+01:00","message":"streamlink live args: [--force-progress --force https://twitch.tv/tororo_vtuber best,best --http-header Authorization=OAuth my_token --force-progress --force --twitch-low-latency --twitch-disable-hosting --loglevel=debug -o /tmp/40495023911_7d64e5e8-2ff4-11ee-b9ae-0242ac140002-video.mp4]"}
ganymede-api         | {"level":"debug","time":"2023-07-31T23:49:24+01:00","message":"running: streamlink --force-progress --force https://twitch.tv/tororo_vtuber best,best --http-header Authorization=OAuth my_token --force-progress --force --twitch-low-latency --twitch-disable-hosting --loglevel=debug -o /tmp/40495023911_7d64e5e8-2ff4-11ee-b9ae-0242ac140002-video.mp4"}
ganymede-api         | {"level":"debug","time":"2023-07-31T23:49:24+01:00","message":"notifying chat download that video download is about to start"}

The errors from the previous logs only appear if I try to restart the video download. As it is the download will not progress at all, nor will anything at all be logged past this point.

[Zibbp]

I don't see anything concerning. I replicated your streamlink settings and it's downloading just fine for me. If you edit /data/config.json does the streamlink_live field look OK, i.e. "streamlink_live": "--force-progress,--force,--twitch-low-latency,--loglevel=debug,--twitch-disable-hosting"

As an experiment, can you enable the proxy in Admin > Setting and try archiving a livestream again?

[bcbwatt]

Using the luminous.dev proxy didn't change anything. The streamlink_live settings are the same there, but in a different order.

Going by what I have stored, I think it stopped working after 2023/07/24. After that point I updated to the current version to see if it would fix things.

[bcbwatt]

I tried recreating the containers after wiping the data and database directories, starting from scratch. But the same thing happened. Is it possible that my twitch application token has expired? Though the logs say that authentication was successful on startup.

Edit: I tried making a new application client id and secret (under the same account) and nothing changed there.

[bcbwatt]

Downgrading from latest to v1.3.2 fixes the problem. Are there any database changes I should watch out for if I revert from latest to 1.3.2?

[Zibbp]

There are no database changes but the config schema was updated so your config may get overwritten with updated values.

Using the latest images, can you exec into the API container and manually downgrade the streamlink version to what the v1.3.2 image uses, pip install streamlink==5.5.1, and try again?

[bcbwatt]

I installed 5.5.1 in the latest api container, and restarted all the containers. That version of streamlink is displayed on the info page (interestingly the API version is completely blank). This fails in the same way as before.

After re-downgrading, if I tried to restart that failed queue item (it failed before because I tried to restart it after it displayed nothing, as usual), this retry failed. When I removed it and went to archive the same livestream again, it worked. The retry logs (the end is the same as before):

[cli][info] Found matching plugin twitch for URL https://twitch.tv/videos/40497409191
Traceback (most recent call last):
  File "/usr/lib/python3.11/site-packages/streamlink/plugin/api/http_session.py", line 175, in request
    res.raise_for_status()
  File "/usr/lib/python3.11/site-packages/requests/models.py", line 1021, in raise_for_status
    raise HTTPError(http_error_msg, response=self)
requests.exceptions.HTTPError: 400 Client Error: Bad Request for url: https://usher.ttvnw.net/vod/40497409191?player=twitchweb&p=855432&type=any&allow_source=true&allow_audio_only=true&allow_spectre=false&nauthsig=df4db034af7fcf59ab08d8b69dac63b78fdc2675&nauth=%7B%22authorization%22%3A%7B%22forbidden%22%3Afalse%2C%22reason%22%3A%22%22%7D%2C%22chansub%22%3A%7B%22restricted_bitrates%22%3Anull%7D%2C%22device_id%22%3Anull%2C%22expires%22%3A4677266623%2C%22https_required%22%3Afalse%2C%22privileged%22%3Afalse%2C%22user_id%22%3Anull%2C%22version%22%3A2%2C%22vod_id%22%3A40497409191%7D

The logs from starting the job from scratch:

[cli][info] Found matching plugin twitch for URL https://twitch.tv/virtualgorilla55
[cli][info] Available streams: audio_only, 160p (worst), 360p, 480p, 720p, 720p60, 1080p60 (best)
[cli][info] Opening stream: 1080p60 (hls)
[cli][info] Writing output to
/tmp/40497409191_aa90cd33-30bc-11ee-9679-0242ac1d0002-video.mp4
[plugins.twitch][info] Low latency streaming (HLS live edge: 2)
[warnings][streamlinkdeprecation] The --force-progress option has been deprecated in favor of --progress=force
^M[download] Written 1.64 MiB to …0cd33-30bc-11ee-9679-0242ac1d0002-video.mp4 (0s)^M[download] Written 1.65 MiB to …0cd33-30bc-11ee-9679-0242ac1d0002-video.mp4 (0s)^M[download] Written 1.65 MiB to …0cd33-30bc-11ee-9679-0242ac1d0002-video.mp4 (0s)^M[download] Written 1.65 MiB to …0cd33-30bc-11ee-9679-0242ac1d0002-video.mp4 (1s)^M[download] Written 1.65 MiB to …0cd33-30bc-11ee-9679-0242ac1d0002-video.mp4 (1s)^M[download] Written 2.50 MiB to …0cd33-30bc-11ee-9679-0242ac1d0002-video.mp4 (1s)^M[download] Written 2.69 MiB to …0cd33-30bc-11ee-9679-0242ac1d0002-video.mp4 (1s)^M[download] Written 2.86 MiB to …ee-9679-0242ac1d0002-video.mp4 (2s @ 1.60 MiB/s)^M[download] Written 3.04 MiB to …ee-9679-0242ac1d0002-video.mp4 (2s @ 1.49 MiB/s)^M[download] Written 3.06 MiB to …ee-9679-0242ac1d0002-video.mp4 (2s @ 1

The main difference I can see is that the new version tries to pass the video id to streamlink, while the older version passes the channel url.

One thing I did notice about downgrading is that I can't load the settings or info pages from the UI (I presume because the proxy settings are there in the DB and the old version of the page can't deal with it?). This isn't a big deal as I can always change the config.json directly.

[Zibbp]

I'm unsure why the newer version of Streamlink is wanting to /videos/<id> instead of the channel name. The logs say that it's using the channel name

ganymede-api         | {"level":"debug","time":"2023-07-31T23:49:24+01:00","message":"running: streamlink --force-progress --force https://twitch.tv/tororo_vtuber best,best --http-header Authorization=OAuth my_token --force-progress --force --twitch-low-latency --twitch-disable-hosting --loglevel=debug -o /tmp/40495023911_7d64e5e8-2ff4-11ee-b9ae-0242ac140002-video.mp4"}

One thing I did notice about downgrading is that I can't load the settings or info pages from the UI (I presume because the proxy settings are there in the DB and the old version of the page can't deal with it?). This isn't a big deal as I can always change the config.json directly.

Best course of action is to backup your config.json and restart the container to re-create a config file. You'll have to set db_seeded to true along with the rest of your prior config.

[bcbwatt]

Are you sure it's streamlink switching it? If you look at the log in the third message, it has this (from the retry):

"running streamlink for vod video download: https://twitch.tv/videos/40494320615 best,best --force-progress --force --twitch-api-header=Authorization=OAuth my_token_here -o /tmp/40494320615_c16b7e4c-2fe7-11ee-b9ae-0242ac140002-video.mp4"

Isn't that log coming from exec.go? Though I'm not sure how streamURL gets set to that when to me it looks like it should pick up the channel name every time unless a proxy is set.

Also the first run that does log the channel name, the attempt that never produces any streamlink logs; I think it's probably failing at the actual exec of streamlink somehow. Because even with debug logs enabled in the streamlink args, that first try never produces anything.

[Zibbp]

Oh, you're right. It's trying to add the stream as a VOD for some reason. How is this channel being archived? Via the archive page (as seen below), or via a watched channel schedule?

[bcbwatt]

For those examples they were all via the archive page, because none of my watched channels were live at the time.

[Zibbp]

Sorry, I totally forgot that you shouldn't be able to restart the live video and chat downloads. I pushed a fix to the frontend for this.

As for why nothing logs when you initiate the archive, I've pushed a commit that adds some more debug logging (exit code + stdout) of the streamlink process. Can you use the :main image tags for both the API and frontend and give it another try (with debug logging on). This should hopefully provide some more information.

[bcbwatt]

I tried main with both a manually triggered archive of a livestream and one picked up normally - the results are the same. No logs are generated with debug set to true, no video file is saved in the folder. I don't think streamlink is even starting.

ganymede-api         | {"level":"debug","time":"2023-08-07T09:53:52+01:00","message":"starting task vod save info for vod ed669f9f-34ff-11ee-9b5e-0242c0a83005"}
ganymede-api         | {"level":"debug","time":"2023-08-07T09:53:52+01:00","message":"refresh live thumbnails called...sleeping for 20 minutes"}
ganymede-api         | {"level":"debug","time":"2023-08-07T09:53:52+01:00","message":"getting live streams using the following query param: ?user_login=kamito_jp"}
ganymede-api         | {"level":"debug","time":"2023-08-07T09:53:52+01:00","message":"starting task video download for live stream ed669f9f-34ff-11ee-9b5e-0242c0a83005"}
ganymede-api         | {"level":"debug","time":"2023-08-07T09:53:53+01:00","message":"streamlink live args: [--force-progress --force https://twitch.tv/kamito_jp best,best --http-header Authorization=OAuth my_token --force-progress --force --twitch-low-latency --twitch-disable-hosting -o /tmp/40511479303_ed669f9f-34ff-11ee-9b5e-0242c0a83005-video.mp4]"}
ganymede-api         | {"level":"debug","time":"2023-08-07T09:53:53+01:00","message":"running: streamlink --force-progress --force https://twitch.tv/kamito_jp best,best --http-header Authorization=OAuth my_token --force-progress --force --twitch-low-latency --twitch-disable-hosting -o /tmp/40511479303_ed669f9f-34ff-11ee-9b5e-0242c0a83005-video.mp4"}
ganymede-api         | {"level":"debug","time":"2023-08-07T09:53:53+01:00","message":"notifying chat download that video download is about to start"}

Note that because this is the first time, it appears with the channel name. If could restart it like in earlier versions, it would display the vod id instead.

Additionally this is something I neglected to mention but might be relevant - if I try to remove the item from the queue, I get "error getting pid queue item: exit status 1". I can remove it by the id manually in the admin queue though.

Just for reference, this is what I mean when I say nothing shows.

[bcbwatt]

Current latest works. I'm closing this now.