Channels DVR caused exception in FrndlyTV for Channels docker?

Continuing the discussion from Frndly TV for Channels:

Channels DVR refreshed the playlist for FrndlyTV after updating to the latest pre-release. Appears to be some timing issue that created an exception with the FrndlyTV for Channels docker container.
Here are the Channels DVR and FrndlyTV for Channels docker logs interspersed to show the time sequence.

2023/09/06 15:51:31.198590 [SYS] Downloading new version v2023.09.06.1846
2023/09/06 15:51:38.375309 [SYS] Update downloaded and verified successfully.
2023/09/06 15:51:38.528185 [SYS] Created database snapshot: backup-20230906.225138
2023/09/06 15:51:38.528444 [SYS] Shutting down for upgrade from v2023.09.06.0024 to v2023.09.06.1846
2023/09/06 15:51:38.529930 [DVR] Recording engine stopped.
2023/09/06 15:51:39.670162 [SYS] Starting Channels DVR v2023.09.06.1846 (linux-x86_64 pid:8) in /channels-dvr/data
2023/09/06 15:51:39.730670 [SYS] Started HTTP Server on 8089
2023-09-06T22:51:40.561230740Z 401
2023-09-06T22:51:40.562207476Z Unauthorized access
2023-09-06T22:51:40.562543340Z logging in....
2023-09-06T22:51:43.568227310Z Logged in!
2023/09/06 15:51:52.199028 [ERR] Failed to request m3u for frndlyTV: Get "http://192.168.1.3:8183/playlist.m3u?gracenote=include": context deadline exceeded (Client.Timeout exceeded while awaiting headers)
2023-09-06T22:51:53.109810260Z 172.18.0.1 - - [06/Sep/2023 15:51:53] "GET /playlist.m3u?gracenote=exclude HTTP/1.1" 200 -
2023/09/06 15:51:53.117942 [M3U] Refreshed lineup for frndlyTVNoEpg with 5 channels
2023/09/06 15:51:53.848218 [DVR] Recording engine started in /shares/dvr
2023/09/06 15:51:53.848965 [SYS] Removing old update 2023.09.03.2244
2023/09/06 15:51:54.027982 [SYS] Created database snapshot: backup-20230906.225154
2023-09-06T22:51:57.309398102Z 172.18.0.1 - - [06/Sep/2023 15:51:57] "GET /playlist.m3u?gracenote=include HTTP/1.1" 200 -
2023-09-06T22:51:57.310767541Z 172.18.0.1 - - [06/Sep/2023 15:51:57] "GET /playlist.m3u?gracenote=include HTTP/1.1" 500 -
2023-09-06T22:51:57.311177721Z ----------------------------------------
2023-09-06T22:51:57.311416424Z Exception happened during processing of request from ('172.18.0.1', 35089)
2023-09-06T22:51:57.312023359Z Traceback (most recent call last):
2023-09-06T22:51:57.312295606Z   File "./app.py", line 53, in do_GET
2023-09-06T22:51:57.312528780Z     routes[func]()
2023-09-06T22:51:57.312713166Z   File "./app.py", line 118, in _playlist
2023-09-06T22:51:57.312894550Z     self.wfile.write(f'#EXTINF:-1 channel-id="{channel_id}" tvg-id="{channel_id}" tvg-logo="{logo}"{gracenote_id}{chno},{name}\n{url}\n'.encode('utf8'))
2023-09-06T22:51:57.313063392Z   File "/usr/local/lib/python3.8/socketserver.py", line 826, in write
2023-09-06T22:51:57.313200405Z     self._sock.sendall(b)
2023-09-06T22:51:57.313299780Z BrokenPipeError: [Errno 32] Broken pipe
2023-09-06T22:51:57.313485836Z 
2023-09-06T22:51:57.313587099Z During handling of the above exception, another exception occurred:
2023-09-06T22:51:57.313865133Z 
2023-09-06T22:51:57.313972677Z Traceback (most recent call last):
2023-09-06T22:51:57.314080808Z   File "/usr/local/lib/python3.8/socketserver.py", line 683, in process_request_thread
2023-09-06T22:51:57.314193236Z     self.finish_request(request, client_address)
2023-09-06T22:51:57.314287785Z   File "/usr/local/lib/python3.8/socketserver.py", line 360, in finish_request
2023-09-06T22:51:57.314445226Z     self.RequestHandlerClass(request, client_address, self)
2023-09-06T22:51:57.314553026Z   File "./app.py", line 25, in __init__
2023-09-06T22:51:57.314651969Z     super().__init__(*args, **kwargs)
2023-09-06T22:51:57.314751022Z   File "/usr/local/lib/python3.8/socketserver.py", line 747, in __init__
2023-09-06T22:51:57.314851514Z     self.handle()
2023-09-06T22:51:57.314939037Z   File "/usr/local/lib/python3.8/http/server.py", line 435, in handle
2023-09-06T22:51:57.315040469Z     self.handle_one_request()
2023-09-06T22:51:57.315132571Z   File "/usr/local/lib/python3.8/http/server.py", line 423, in handle_one_request
2023-09-06T22:51:57.315232514Z     method()
2023-09-06T22:51:57.315319537Z   File "./app.py", line 55, in do_GET
2023-09-06T22:51:57.315444593Z     self._error(e)
2023-09-06T22:51:57.315538390Z   File "./app.py", line 29, in _error
2023-09-06T22:51:57.315642954Z     self.end_headers()
2023-09-06T22:51:57.315736112Z   File "/usr/local/lib/python3.8/http/server.py", line 537, in end_headers
2023-09-06T22:51:57.315838469Z     self.flush_headers()
2023-09-06T22:51:57.315931251Z   File "/usr/local/lib/python3.8/http/server.py", line 541, in flush_headers
2023-09-06T22:51:57.316031368Z     self.wfile.write(b"".join(self._headers_buffer))
2023-09-06T22:51:57.316128545Z   File "/usr/local/lib/python3.8/socketserver.py", line 826, in write
2023-09-06T22:51:57.316226146Z     self._sock.sendall(b)
2023-09-06T22:51:57.316313297Z BrokenPipeError: [Errno 32] Broken pipe
2023-09-06T22:51:57.316453382Z ----------------------------------------
2023/09/06 15:52:03.887383 [IDX] Pruned 53 expired airings from XMLTV-frndlyTVNoEpg in 44.147382ms.
2023-09-06T22:52:53.650749217Z 172.18.0.1 - - [06/Sep/2023 15:52:53] "GET /playlist.m3u?gracenote=include HTTP/1.1" 200 -
2023/09/06 15:52:53.661488 [M3U] Refreshed lineup for frndlyTV with 40 channels

Logs have been submitted as ebe216c6-4afb-4f31-bae3-04f295f5ca25
It's working fine now, just wanted to point it out.

2023/09/06 15:51:52.199028 [ERR] Failed to request m3u for frndlyTV: Get "http://192.168.1.3:8183/playlist.m3u?gracenote=include": context deadline exceeded (Client.Timeout exceeded while awaiting headers)

Channels will wait 12 seconds for a response before timing out. At that point it closes the connection.

2023-09-06T22:51:57.313299780Z BrokenPipeError: [Errno 32] Broken pipe

"Broken pipe" is the description of an error when something tries to write to a socket connection where the other side of the connection has been closed.

Channels isn't doing anything wrong. It closed a connection after reaching a timeout.

2 Likes

Eric,
Thanks for the explanation on the 12 second timeout. That I can understand.

What puzzles me is what caused the exception.
It looks like there were 2 back-back GETs for the same playlist 5 seconds after that 12 second timeout error.

This topic was automatically closed 365 days after the last reply. New replies are no longer allowed.