TimeoutError and getting plenty of segmented videos without remux.

[Klamist]

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 �[0m�[K
2022-09-06 10:46:52 [fc2 58861545] Fetching stream info �[0m
2022-09-06 10:46:53 [autofc2] Setting log level to info �[0m
2022-09-06 10:46:54 [fc2 58861545] Found websocket url �[0m
2022-09-06 10:46:55 [fc2 58861545] Received HLS info �[0m
2022-09-06 10:46:55 [fc2 58861545] Writing stream to 新作アニメ test/2022-09-06 104654 新作色々.ts �[0m
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 �[0m
2022-09-06 10:50:09 [fc2 58861545] Found websocket url �[0m
2022-09-06 10:50:10 [fc2 58861545] Received HLS info �[0m
2022-09-06 10:50:10 [fc2 58861545] Writing stream to 新作アニメ test/2022-09-06 105008 新作色々.ts �[0m
......
(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).

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]

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]

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]

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.

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 �[0m�[K
2022-09-06 17:23:56 [fc2 58861545] Fetching stream info �[0m
2022-09-06 17:23:57 [autofc2] Setting log level to debug �[0m
2022-09-06 17:23:57 �[36m[live] Using anonymous account �[0m
2022-09-06 17:23:57 [fc2 58861545] Found websocket url �[0m
2022-09-06 17:23:58 �[36m[ws] connected �[0m
2022-09-06 17:23:58 �[36m[ws] heartbeat �[0m
2022-09-06 17:23:58 [fc2 58861545] Received HLS info �[0m
2022-09-06 17:23:58 [fc2 58861545] Writing stream to 新作アニメ test/2022-09-06 172357 新作色々.ts �[0m
2022-09-06 17:23:58 �[36m[fc2 58861545] Starting 2 tasks �[0m
2022-09-06 17:23:58 �[36m[hls] init �[0m
2022-09-06 17:23:58 �[36m[hls] Starting queue worker �[0m
2022-09-06 17:23:59 �[36m[hls] Found 12 new fragments �[0m
2022-09-06 17:23:59 �[36m[hls] 0 Downloading fragment 0 �[0m
2022-09-06 17:24:00 �[36m[hls] 0 Downloading fragment 1 �[0m
2022-09-06 17:24:00 �[36m[hls] 0 Downloading fragment 2 �[0m
......
......leave out
......
2022-09-06 17:26:10 �[36m[hls] 0 Downloading fragment 271 �[0m
2022-09-06 17:26:10 �[36m[hls] 0 Downloading fragment 272 �[0m
2022-09-06 17:26:10 �[36m[hls] 0 Downloading fragment 273 �[0m
2022-09-06 17:26:11 �[36m[hls] Found 2 new fragments �[0m
2022-09-06 17:26:11 �[36m[hls] 0 Downloading fragment 274 �[0m
2022-09-06 17:26:11 �[36m[hls] 0 Downloading fragment 275 �[0m
2022-09-06 17:26:12 �[36m[fc2 58861545] Tasks exited �[0m
2022-09-06 17:26:12 �[36m[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>()]>> �[0m
2022-09-06 17:26:12 �[36m[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()> �[0m
2022-09-06 17:26:12 �[36m[hls] read cancelled �[0m
2022-09-06 17:26:12 �[36m[hls] _download cancelled �[0m
2022-09-06 17:26:12 �[36m[hls] worker 0 cancelled �[0m
2022-09-06 17:26:12 �[36m[ws] closed �[0m
2022-09-06 17:26:12 �[36m[fc2 58861545] Cancelling tasks �[0m
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 �[0m
2022-09-06 17:26:13 �[36m[live] Using anonymous account �[0m
2022-09-06 17:26:13 [fc2 58861545] Found websocket url �[0m
2022-09-06 17:26:14 �[36m[ws] connected �[0m
2022-09-06 17:26:14 �[36m[ws] heartbeat �[0m
2022-09-06 17:26:14 [fc2 58861545] Received HLS info �[0m
2022-09-06 17:26:14 [fc2 58861545] Writing stream to 新作アニメ test/2022-09-06 172613 新作色々.ts �[0m
2022-09-06 17:26:14 �[36m[fc2 58861545] Starting 2 tasks �[0m
2022-09-06 17:26:14 �[36m[hls] init �[0m
2022-09-06 17:26:14 �[36m[hls] Starting queue worker �[0m
2022-09-06 17:26:15 �[36m[hls] Found 12 new fragments �[0m
2022-09-06 17:26:15 �[36m[hls] 0 Downloading fragment 0 �[0m
2022-09-06 17:26:16 �[36m[hls] 0 Downloading fragment 1 �[0m
2022-09-06 17:26:16 �[36m[hls] 0 Downloading fragment 2 �[0m
2022-09-06 17:26:16 �[36m[hls] Found 2 new fragments �[0m
2022-09-06 17:26:17 �[36m[hls] 0 Downloading fragment 3 �[0m
2022-09-06 17:26:17 �[36m[hls] 0 Downloading fragment 4 �[0m
2022-09-06 17:26:17 �[36m[hls] 0 Downloading fragment 5 �[0m
......

It would be great if this could help some.

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

[hizkifw]

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]

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.