Closed nlhintz closed 1 year ago
Sorry, trying to follow the changes - what are you seeing in the logs? What does this help / improve?
Thanks!
The first attempt to open a stream following a restart of fHDHR always fails:
Dec 21 14:44:11 hintzn1.lan fHDHR[612409]: [2022-12-21 22:44:11,427] NOOB - Startup Tasks Complete. Dec 21 14:44:11 hintzn1.lan fHDHR[612409]: [2022-12-21 22:44:11,428] NOOB - fHDHR and fHDHR_web should now be running and accessible via the web interface at http://192.168.1.100:5004 Dec 21 14:45:11 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:11,454] INFO - HTTP Server Online. Dec 21 14:45:11 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:11,459] INFO - 192.168.1.100 - - [2022-12-21 22:45:11] "GET /discover.json HTTP/1.1" 200 2747 0.006014 Dec 21 14:45:11 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:11,562] INFO - 192.168.1.100 - - [2022-12-21 22:45:11] "GET /hdhr/ceton/lineup.json HTTP/1.1" 200 125628 0.096440
First attempt: Dec 21 14:45:11 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:11,772] INFO - 192.168.1.100 - - [2022-12-21 22:45:11] "GET /hdhr/ceton/auto/v655 HTTP/1.1" 302 3020 0.003274 Dec 21 14:45:12 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:12,153] NOOB - [ceton] Ceton tuner 0, StopPending "cleared", set status to Inactive Dec 21 14:45:12 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:12,500] NOOB - [ceton] Ceton tuner 1, StopPending "cleared", set status to Inactive Dec 21 14:45:12 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:12,695] NOOB - [ceton] Ceton tuner 2, StopPending "cleared", set status to Inactive Dec 21 14:45:12 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:12,888] NOOB - [ceton] Ceton tuner 3, StopPending "cleared", set status to Inactive Dec 21 14:45:13 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:13,092] NOOB - [ceton] Ceton tuner 4, StopPending "cleared", set status to Inactive Dec 21 14:45:13 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:13,358] NOOB - [ceton] Ceton tuner 5, StopPending "cleared", set status to Inactive Dec 21 14:45:13 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:13,359] ERROR - [ceton] No Ceton tuners available Dec 21 14:45:13 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:13,505] ERROR - Unable to Stream: TunerError: 806 - Tune Failed Dec 21 14:45:13 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:13,510] INFO - 192.168.1.100 - - [2022-12-21 22:45:13] "GET /api/tuners?method=stream&channel=655&origin=ceton&stream_method=ffmpeg&accessed=http%3A//192.168.1.100%3A5004/hdhr/ceton/auto/v655 HTTP/1.1" 503 2471 1.734630
Second Attempt: Dec 21 14:45:21 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:21,266] INFO - 192.168.1.100 - - [2022-12-21 22:45:21] "GET /hdhr/ceton/auto/v655 HTTP/1.1" 302 3017 0.004826 Dec 21 14:45:21 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:21,594] INFO - [ceton] Selected Ceton tuner#: 0 Dec 21 14:45:21 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:21,595] INFO - [ceton] Ceton tuner 0 to be started Dec 21 14:45:21 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:21,751] INFO - [ceton] Preparing Ceton tuner 0 on port: 49990 Dec 21 14:45:22 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:22,503] INFO - [ceton] Initiate streaming channel 1110 from Ceton tuner#: 0 Dec 21 14:45:22 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:22,504] INFO - Attempting to Select an available tuner for this stream. Dec 21 14:45:22 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:22,505] INFO - Tuner #0 Acquired. Dec 21 14:45:22 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:22,506] INFO - ceton Tuner #0 to be used for stream. Dec 21 14:45:22 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:22,507] INFO - Preparing Stream...
Dec 21 14:45:13 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:13,358] NOOB - [ceton] Ceton tuner 5, StopPending "cleared", set status to Inactive Dec 21 14:45:13 hintzn1.lan fHDHR[612409]: [2022-12-21 22:45:13,359] ERROR - [ceton] No Ceton tuners available
I admit, this looks a bit "odd". Meaning ... status is set to Inactive, then the tuner is requested 1 ms later? Too quickly to get a valid response perhaps?
What happens if you start the server, and wait (for testing) a bit ... say 30 seconds. Then does it fail the first try?
Thanks!
The two log statements you are referring to are both issued due to a single attempt to acquire a tuner. The first log occurs because of the call to "get_ceton_tuner_status" here, which essentially searches for an available tuner. The second log occurs just a few lines later here because no tuners were found (although all tuners that were in a state of Stop Pending had just been changed to Inactive and should have all been available).
Ahhh ... yes, I recall adding that now. Stop Pending is because there can be a delay or lag before the tuner is actually really ready (i.e. the HW and FW on the tuner card itself) - in particular if another application is using the tuner (i.e. can't just hog it for fHDHR). You aren't removing the Stop Pending state, are you?
Thanks!
No, it did not remove the "Stop Pending" state. The change allows a tuner that was changed from "Stop Pending" to "Inactive" to be considered for allocation immediately instead of exiting with no tuner found if there were no other tuners available.
OK, that makes sense. I admit, the way the change formats it looks like a lot of mods, very hard to follow to know if it makes sense or not (in my head, that's all I mean 😆).
This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.
Tuner allocation fails on the first attempt (initial, or after tuner is released). Update the tunerstatus, and allocate the tuner immediately if the transport is stopped and the H/W is not in use.
Signed-off-by: Nathan Hintz nlhintz@hotmail.com