search

HoloArchivists / fc2-live-dl

Tool to download FC2 live streams
https://pypi.org/project/fc2-live-dl/
MIT License
112 stars 11 forks source link

TimeoutError and getting plenty of segmented videos without remux. #31

Open Klamist opened 2 years ago

Klamist commented 2 years ago

I‘m recording with local proxy using v2rayN, everything seems fine but encounter this exception:

(base) PS E:\FC2> autofc2 --config .\test.json
2022-09-06 10:46:52 [autofc2] starting 
2022-09-06 10:46:52 [fc2 58861545] Fetching stream info 
2022-09-06 10:46:53 [autofc2] Setting log level to info 
2022-09-06 10:46:54 [fc2 58861545] Found websocket url 
2022-09-06 10:46:55 [fc2 58861545] Received HLS info 
2022-09-06 10:46:55 [fc2 58861545] Writing stream to 新作アニメ test/2022-09-06 104654 新作色々.ts 
Task exception was never retrieved
future: <Task finished name='Task-10' coro=<AutoFC2.handle_channel() done, defined at e:\anaconda3\lib\site-packages\fc2_live_dl\autofc2.py:90> exception=TimeoutError()>
Traceback (most recent call last):
  File "e:\anaconda3\lib\site-packages\fc2_live_dl\autofc2.py", line 93, in handle_channel
    await fc2.download(channel_id)
  File "e:\anaconda3\lib\site-packages\fc2_live_dl\FC2LiveDL.py", line 193, in download
    raise exited.exception()
  File "e:\anaconda3\lib\site-packages\fc2_live_dl\fc2.py", line 48, in wait_disconnection
    res = await self._task
  File "e:\anaconda3\lib\site-packages\fc2_live_dl\fc2.py", line 85, in _main_loop
    msg = await asyncio.wait_for(
  File "e:\anaconda3\lib\asyncio\tasks.py", line 490, in wait_for
    raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError
2022-09-06 10:50:08 [fc2 58861545] Fetching stream info 
2022-09-06 10:50:09 [fc2 58861545] Found websocket url 
2022-09-06 10:50:10 [fc2 58861545] Received HLS info 
2022-09-06 10:50:10 [fc2 58861545] Writing stream to 新作アニメ test/2022-09-06 105008 新作色々.ts 
......
(repeating this exception then restart again and again)

It got exception after starting writing stream for every several minutes, and then auto restart remaining a segmented video. And I get these files as the picture below. They contain the complete live stream, the next file has about 5 seconds duplication of the past's last 5 seconds (result from 'latency' tag I think). 1 And only the last video can be transfered to .mp4, others are still .ts file.

I've checked earlier issues about 'timeout' (issue #7 )but didn't find some help. The network should be okay, since I don't notice lags while watching FC2-lives on browser.

From: Win10 21H1, anaconda 3.8 powershell prompt, latest ffmpeg, pip installing fc2-live-dl, and the test.json is:

{
  "autofc2": {
    "log_level": "info"
  },
  "default_params": {
    "quality": "2Mbps",
    "latency": "mid", (This is curious since low/high/mid refer to 0/1/2, which means mid is higher than high?)
    "threads": 1,
    "outtmpl": "%(channel_name)s %(_en_name)s/%(date)s %(time)s %(title)s.%(ext)s",
    "write_chat": false,
    "write_info_json": false,
    "write_thumbnail": false,
    "wait_for_live": true,
    "wait_for_quality_timeout": 15,
    "wait_poll_interval": 5,
    "cookies_file": null,
    "remux": true,
    "keep_intermediates": false,
    "extract_audio": false,
    "trust_env_proxy": true
  },
  "channels": {
    "58861545": { "_en_name": "test" }
  }
}

proxy environment vars are HTTPS_PROXY = http://127.0.0.1:10809

hizkifw commented 2 years ago

FC2 requires a Websocket connection. Try setting both HTTPS_PROXY and WSS_PROXY to http://127.0.0.1:10809. Also try setting log_level to debug.

Klamist commented 2 years ago

FC2 requires a Websocket connection. Try setting both HTTPS_PROXY and WSS_PROXY to http://127.0.0.1:10809.

Oh, I missed telling, my fault.

I've already set HTTP/HTTPS/WS/WSS all to http://127.0.0.1:10809. Or I'll get other mistakes, telling ’The semaphore timeout period has expired‘ which I fixed in the morning.

(Btw, I spent 1 hours just to notice it should use http:// not https:// in HTTPS_PROXY of aiohttp. Excellent.)

I'll try log_level debug later. Thanks!

Klamist commented 2 years ago

Also try setting log_level to debug.

Well, I seems to fix this problem by changing heartbeat_interval of line 10 in fc2.py from 30 to 60. Then the exception disappeared. 1 And the video is fine.

heartbeat_interval affacts line 85 in fc2.py which calls asyncio.wait_for(url, timeout, ...) from asyncio\tasks.py where the exception from. heartbeat_interval is the timeout parameter in this line.

Besides, I reset it to 30, then used debug log_level and here is the log.

(base) PS E:\FC2> autofc2 --config .\karin.json
2022-09-06 17:23:56 [autofc2] starting 
2022-09-06 17:23:56 [fc2 58861545] Fetching stream info 
2022-09-06 17:23:57 [autofc2] Setting log level to debug 
2022-09-06 17:23:57 [live] Using anonymous account 
2022-09-06 17:23:57 [fc2 58861545] Found websocket url 
2022-09-06 17:23:58 [ws] connected 
2022-09-06 17:23:58 [ws] heartbeat 
2022-09-06 17:23:58 [fc2 58861545] Received HLS info 
2022-09-06 17:23:58 [fc2 58861545] Writing stream to 新作アニメ test/2022-09-06 172357 新作色々.ts 
2022-09-06 17:23:58 [fc2 58861545] Starting 2 tasks 
2022-09-06 17:23:58 [hls] init 
2022-09-06 17:23:58 [hls] Starting queue worker 
2022-09-06 17:23:59 [hls] Found 12 new fragments 
2022-09-06 17:23:59 [hls] 0 Downloading fragment 0 
2022-09-06 17:24:00 [hls] 0 Downloading fragment 1 
2022-09-06 17:24:00 [hls] 0 Downloading fragment 2 
......
......leave out
......
2022-09-06 17:26:10 [hls] 0 Downloading fragment 271 
2022-09-06 17:26:10 [hls] 0 Downloading fragment 272 
2022-09-06 17:26:10 [hls] 0 Downloading fragment 273 
2022-09-06 17:26:11 [hls] Found 2 new fragments 
2022-09-06 17:26:11 [hls] 0 Downloading fragment 274 
2022-09-06 17:26:11 [hls] 0 Downloading fragment 275 
2022-09-06 17:26:12 [fc2 58861545] Tasks exited 
2022-09-06 17:26:12 [fc2 58861545] Cancelling pending task <Task pending name='Task-30' coro=<FC2LiveDL._download_stream() running at e:\anaconda3\lib\site-packages\fc2_live_dl\FC2LiveDL.py:247> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x000002174FA42EB0>()]>> 
2022-09-06 17:26:12 [fc2 58861545] Exited task was <Task finished name='Task-29' coro=<FC2WebSocket.wait_disconnection() done, defined at e:\anaconda3\lib\site-packages\fc2_live_dl\fc2.py:47> exception=TimeoutError()> 
2022-09-06 17:26:12 [hls] read cancelled 
2022-09-06 17:26:12 [hls] _download cancelled 
2022-09-06 17:26:12 [hls] worker 0 cancelled 
2022-09-06 17:26:12 [ws] closed 
2022-09-06 17:26:12 [fc2 58861545] Cancelling tasks 
Task exception was never retrieved
future: <Task finished name='Task-6' coro=<AutoFC2.handle_channel() done, defined at e:\anaconda3\lib\site-packages\fc2_live_dl\autofc2.py:90> exception=TimeoutError()>
Traceback (most recent call last):
  File "e:\anaconda3\lib\site-packages\fc2_live_dl\autofc2.py", line 93, in handle_channel
    await fc2.download(channel_id)
  File "e:\anaconda3\lib\site-packages\fc2_live_dl\FC2LiveDL.py", line 193, in download
    raise exited.exception()
  File "e:\anaconda3\lib\site-packages\fc2_live_dl\fc2.py", line 48, in wait_disconnection
    res = await self._task
  File "e:\anaconda3\lib\site-packages\fc2_live_dl\fc2.py", line 85, in _main_loop
    msg = await asyncio.wait_for(
  File "e:\anaconda3\lib\asyncio\tasks.py", line 490, in wait_for
    raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError
2022-09-06 17:26:12 [fc2 58861545] Fetching stream info 
2022-09-06 17:26:13 [live] Using anonymous account 
2022-09-06 17:26:13 [fc2 58861545] Found websocket url 
2022-09-06 17:26:14 [ws] connected 
2022-09-06 17:26:14 [ws] heartbeat 
2022-09-06 17:26:14 [fc2 58861545] Received HLS info 
2022-09-06 17:26:14 [fc2 58861545] Writing stream to 新作アニメ test/2022-09-06 172613 新作色々.ts 
2022-09-06 17:26:14 [fc2 58861545] Starting 2 tasks 
2022-09-06 17:26:14 [hls] init 
2022-09-06 17:26:14 [hls] Starting queue worker 
2022-09-06 17:26:15 [hls] Found 12 new fragments 
2022-09-06 17:26:15 [hls] 0 Downloading fragment 0 
2022-09-06 17:26:16 [hls] 0 Downloading fragment 1 
2022-09-06 17:26:16 [hls] 0 Downloading fragment 2 
2022-09-06 17:26:16 [hls] Found 2 new fragments 
2022-09-06 17:26:17 [hls] 0 Downloading fragment 3 
2022-09-06 17:26:17 [hls] 0 Downloading fragment 4 
2022-09-06 17:26:17 [hls] 0 Downloading fragment 5 
......

It would be great if this could help some.

And Thanks for replying! This issue could be closed? You decide.

hizkifw commented 2 years ago

Ah interesting, thanks for debugging. Now that I'm looking at that part of the code, I wonder why I wrote it that way, and why things have been working just fine so far lol. I'll leave this issue open until I fix up that part.

15532th commented 1 year ago

Got this when trying to download random ongoing streams for testing, and simply increasing timeout didn't really help much.

I'm guessing that the reason timeout could never get triggered for the duration of entire stream could be the chat messages.