mackworth / cTiVo

TiVo Show Downloads for MacOS
220 stars 36 forks source link

cTiVo not reconnecting with TiVo Bolt after TiVo was power cycled #491

Closed magsdev closed 1 year ago

magsdev commented 2 years ago

Thanks a lot for an awesome app!

Once in a while I've noticed the cTiVo is not refreshing with my TiVo Bolt and it seems this happens whenever the TiVo Bolt lost WiFi/rebooted/power cycled.

To restore connection between cTiVo and the TiVo Bolt, I would need to go to File -> Refresh TiVo. It does not start refreshing on its own whenever the TiVo Bolt comes back online even though cTiVo has the following setting set "TiVo Refresh Rate" = 1.

I am running:

cTiVo 3.5.2 macOS Monterey 12.4 (APFS Case-Sensitive)

Log files: cTiVo Logs.zip

mackworth commented 2 years ago

Thanks for the compliment!

I note a couple of things in your logs. First, definitely wouldn't recommend a 1 minute refresh cycle. There's a lot of data transmitted on a refresh, so that's a lot of unnecessary load on the TiVo. I'd do (at fastest) 5 minutes. Second, your cTiVo is getting into a bad state with respect to TVDB, attempting to reconnect over and over again.

So can you decrease the retry rate and switch Debug Log mode to Major, and then restart cTiVo. Then after things settle down, try restarting the Bolt again to see how it handles it. Haven't looked at the retry code in a while, but when the RPC connection fails, it should eventually see the TiVo restart and request a complete refresh immediately, but I won't know what's happening with yours without a Major-level log.
Thanks

magsdev commented 2 years ago

Thanks for the suggestions, unfortunately it did not work. I let cTiVo sit overnight and it was still stuck when I checked today at 2:15 PM CDT - attached new logs, captured after I did a File -> Refresh TiVo

Thanks for your help!

cTiVo Logs 2.zip .

mackworth commented 2 years ago

Haven’t checked the logs yet, but to correlate them, do you know what time you rebooted the Bolt?

magsdev commented 2 years ago

I would say I rebooted around 8 PM CDT last night

mackworth commented 2 years ago

I was able to recreate the problem and have diagnosed. Impressively, here's several bugs involved here, which have been around forever, but are timing dependent, so have never been noticed/reported until now; so thank you!

The base problem is that TiVo is not "de-registering" itself from the network when it reboots (as is required by the spec). Therefore, when it comes back online and announces "I'm here", the network doesn't see that as a change, so doesn't report the "new" device to cTiVo, which would cause it to refresh the Now Playing List. Obviously we can't fix this one. On the other hand, if the network itself becomes unavailable (e.g. your Mac's network connection fails), then the TiVo(s) is/are correctly marked as unavailable, and the link is reestablished upon recovery.

Second is that when cTiVo asks for Now Playing List, if the NPL request fails, then cTiVo doesn't ever ask again, a clear bug. So, why didn't we see this before (as all requests will naturally fail while a TiVo is rebooting)? Because if you use the default timeframe (4 hours or even the old 15 minutes), then the TiVo will probably be back up when the next update request comes through, so everything usually works fine. On the other hand, reducing the time to 1 minute (as you did to speed things up) means there's no chance that the TiVo will be back up again before cTiVo asks, thus the request fails, and cTiVo goes into this erroneous quiet state until you manually refresh. Also as to why we didn't find this, testing for recovery from rebooting is nowadays done with the Reboot TiVo command in cTiVo (less walking!), which, of course, notifies the rest of cTiVo that the TiVo has been rebooted, so it recovers properly.

In addition to the stateless NPL updates, there's also the RPC pipe, which I incorrectly assumed would fail upon a TiVo reboot, triggering a reload with retries until the TiVo comes up. In fact it does fail and recovers properly, but only after the next RPC request, so usually after the successful NPL update, cTiVo would then do an RPC request, realize the pipe was broken and reestablish it. But if the NPL request itself failed (see above), then that RPC request would never happen. So there should be a heartbeat check that sends an innocuous request every few minutes to ensure the pipe is really alive.

So I'd recommend setting the refresh rate to, say, 15 minutes. You might still hit the bug as you found, but the chances are much lower. If you do hit it as you found, the workaround is simple: just Refresh the TiVo after a reboot, but I've got this in the queue for the next release.

magsdev commented 2 years ago

Very interesting, like a domino effect - thanks a lot for the update and the candidate to fix the issue! 😀 Looking forward to try out the next release and feel free let me know if you want me to do a test before the release.

mackworth commented 1 year ago

Finally fixed in 3.6. Beta available now

magsdev commented 1 year ago

Awesome! Thanks a lot - will test tomorrow and hopefully share the good news :)

On Mar 10, 2023, at 16:15, Hugh Mackworth @.***> wrote:

Finally fixed in 3.6. Beta available now

— Reply to this email directly, view it on GitHub https://github.com/mackworth/cTiVo/issues/491#issuecomment-1464484699, or unsubscribe https://github.com/notifications/unsubscribe-auth/AJTO6UOZ33XFNHWCFIJPDK3W3OKX3ANCNFSM5ZHG4VBA. You are receiving this because you authored the thread.