diff --git a/Utils/CameraControl.py b/Utils/CameraControl.py index 894dcb9e6..ce5b7fed3 100644 --- a/Utils/CameraControl.py +++ b/Utils/CameraControl.py @@ -61,6 +61,7 @@ import ipaddress as ip import binascii import socket +import time import argparse import json import pprint @@ -633,6 +634,43 @@ def manageCloudConnection(cam, opts): log.info('Enabled %s', info['NatEnable']) +def waitForCameraOnline(camera_ip, timeout=240, settle=8): + """Wait for a camera to answer on the DVRIP port again after a reboot. + + Used to settle whether a firmware upgrade actually took: the upgrade + protocol does not reliably confirm itself, so the real test is that the + camera boots and its application starts serving again. + + Port 34567 is a good liveness check specifically because it is served by the + application, not the bootloader -- when the application is dead the camera + answers on 12901 instead and 34567 stays shut. + + Arguments: + camera_ip: [str] Address of the camera. + + Keyword arguments: + timeout: [int] Seconds to wait for it to return. 240 by default. + settle: [int] Seconds to wait before polling, so we do not catch the + camera still up on the old firmware. 8 by default. + + Return: + [bool] True if the camera answered again within the timeout. + """ + sleep(settle) + + deadline = time.time() + timeout + while time.time() < deadline: + try: + s = socket.create_connection((camera_ip, 34567), timeout=3) + s.close() + return True + + except OSError: + sleep(3) + + return False + + def upgradeFirmware(cam, firmware_path, skip_confirm=False): """Upgrade the camera firmware via the DVRIP protocol. @@ -720,36 +758,100 @@ def progress_callback(*args, **kwargs): log.info("Starting firmware upgrade...") log.info("Uploading firmware to camera...") + # Stop dvrip's keep-alive timer for the duration of the transfer. + # + # login() starts a threading.Timer that re-sends a KeepAlive every 20 s on + # the SAME socket the firmware upload uses. A transfer takes far longer than + # that, so the timer fires mid-upload, writes a KeepAlive into the middle of + # the binary stream and then tries to JSON-decode whatever comes back -- + # firmware packets start with 0xFF, which surfaces as + # UnicodeDecodeError: 'utf-8' codec can't decode byte 0xff + # from a background thread. + # + # The noise is the lesser problem. The thread also consumes replies the + # upload loop is waiting for, which can swallow the camera's own completion + # response -- including the Ret 515 confirmation. Whether it lands at a bad + # moment depends on file size and camera timing, which is why upgrade + # results looked erratic between runs. + # + # There is nothing to keep alive during an upgrade: the camera reboots at + # the end and the session goes with it. + if getattr(cam, 'alive', None) is not None: + try: + cam.alive.cancel() + log.info("Paused the keep-alive timer for the transfer.") + except Exception as e: + log.warning("Could not stop the keep-alive timer: %s", e) + try: result = cam.upgrade(firmware_path, packetsize=0x8000, vprint=progress_callback) - if result is None: - log.info("Firmware upload completed.") - log.info("Camera is now applying the update and will reboot automatically.") - log.info("Please wait for the camera to come back online (this may take several minutes).") - return True - elif isinstance(result, dict): + # cam.upgrade() ends in one of two ways and they do NOT mean the same + # thing: + # + # dict with Ret 515 - the camera explicitly confirmed the upgrade + # None - the connection ended with no confirmation + # + # None happens both when the camera reboots before it gets round to + # sending 515 (which is fine) and when it drops the transfer partway + # (which is not). Treating None as success is why upgrade results looked + # inconsistent: a flash that was never confirmed reported exactly the + # same as one that was. So None is treated as "unconfirmed" and settled + # by waiting for the camera to come back. + # + # Note the progress lines printed during the transfer are not a reliable + # status either -- dvrip's completion loop prints a stale variable, so + # the Ret values scrolling past can repeat or show a value the camera + # never sent. + confirmed = False + + if isinstance(result, dict): ret_code = result.get('Ret', -1) if ret_code == 515: - log.info("Firmware upgrade successful!") - log.info("Camera will reboot automatically.") - return True + log.info("Camera confirmed the upgrade (Ret 515).") + confirmed = True elif ret_code in [512, 513, 514]: error_msgs = { 512: "Upgrade not started", 513: "Data errors during transfer", 514: "Upgrade failed" } - log.error("Firmware upgrade failed: %s (code %d)", - error_msgs.get(ret_code, "Unknown error"), ret_code) + log.error("Firmware upgrade FAILED: %s (code %d)", + error_msgs.get(ret_code, "Unknown error"), ret_code) + log.error("The camera kept its existing firmware.") return False else: - log.warning("Upgrade returned unexpected code: %d", ret_code) + log.error("Upgrade returned unexpected code %d - treating as failed.", + ret_code) return False - else: - log.warning("Unexpected upgrade result: %s", result) + + elif result is not None: + log.error("Unexpected upgrade result: %s", result) return False + else: + log.warning("Transfer ended without a confirmation from the camera.") + log.warning("That is normal if it rebooted early, but it has to be verified.") + + # Either way, the camera is the authority on whether this worked. + log.info("Waiting for the camera to come back online...") + back = waitForCameraOnline(cam.ip) + + if back: + if confirmed: + log.info("Firmware upgrade successful - camera confirmed it and is back online.") + else: + log.info("Camera is back online after the upgrade.") + log.info("The upgrade was not confirmed over the wire, so check the " + "build with GetDeviceInformation before relying on it.") + log.info("Remember: push 'SwitchMode init' now. Config stored on the " + "camera is not replaced by the new image's defaults.") + return True + + log.error("Camera did not come back online within the timeout.") + log.error("Do not power-cycle it yet - it may still be writing flash.") + return False + except Exception as e: log.error("Firmware upgrade failed with exception: %s", e) return False diff --git a/requirements.txt b/requirements.txt index 2318ed1d4..4ca07822c 100644 --- a/requirements.txt +++ b/requirements.txt @@ -22,7 +22,7 @@ astropy>=2.0.3 imreg_dft @ git+https://github.com/matejak/imreg_dft@master configparser==4.0.2 imageio>=2.31 -python-dvr>=0.0.1 ; python_version >='3.6' +python-dvr @ git+https://github.com/OpenIPC/python-dvr@master ; python_version >='3.6' pyqtgraph>=0.12,<0.13 ; python_version >='3.6' pyyaml; python_version>='3.6' tflite-runtime; python_version >= '3.6' and python_version < '3.12' and sys_platform != 'darwin'