From 647ab47ebfa30bef65b57b666b028b75e511e0f7 Mon Sep 17 00:00:00 2001 From: Shivani Tipnis Date: Thu, 28 May 2020 16:53:11 +0530 Subject: [PATCH] ota: Fix OTA Upgrade error messages and ota service checks handling Fixed message handling for OTA failure if no internet connectivity Fixed config check for ota service support before uploading image --- cli/rmaker_cmd/node.py | 141 ++++++++++++++++++++++++-------------- cli/rmaker_lib/node.py | 28 ++++++-- cli/rmaker_lib/service.py | 43 ++++++------ 3 files changed, 134 insertions(+), 78 deletions(-) diff --git a/cli/rmaker_cmd/node.py b/cli/rmaker_cmd/node.py index c683de9..dc25dbd 100644 --- a/cli/rmaker_cmd/node.py +++ b/cli/rmaker_cmd/node.py @@ -312,22 +312,39 @@ def ota_upgrade(vars=None): status = None response = None service_name = None - service_read_params = None - ota_status = None - status_params = None + service_obj = None + service_config = None node_params = None param_url_to_set = None + curr_session = None while retries > 0: try: # If session is expired then to initialise the new session # internet connection is required. - node_object = node.Node(node_id, session.Session()) - # Upload OTA Firwmare Image - log.info("Creating service object...") - service_obj = service.Service() - status, response = service_obj.upload_ota_image(node_object, img_name, base64_fw_img) - if status: - break + if not curr_session: + curr_session = session.Session() + if not node_object: + node_object = node.Node(node_id, curr_session) + log.info("Creating service object...") + if not service_obj: + service_obj = service.Service() + log.info("Checking service " + service.OTA_SERVICE_TYPE + " in node config...") + print("Checking " + service.OTA_SERVICE_TYPE + " in node config...") + if not service_config and not service_name: + service_config, service_name = service_obj.verify_service_exists(node_object, service.OTA_SERVICE_TYPE) + if not service_config: + log.error(service.OTA_SERVICE_TYPE + " not found.") + break + log.info("Checking service " + service.OTA_SERVICE_TYPE + " in config...Success") + log.debug("Service config received: " + str(service_config) + + " Service name received: " + str(service_name)) + print("Uploading OTA Firmware Image...This may take time...") + log.info("Uploading OTA Firmware Image...This may take time...") + if not status and not response: + # Upload OTA Firwmare Image + status, response = service_obj.upload_ota_image(node_object, img_name, base64_fw_img) + if status: + break except SSLError: log.error(SSLError()) break @@ -347,47 +364,71 @@ def ota_upgrade(vars=None): log.error('Initialising new session...Failed\n') return - if status and 'success' in status: - log.info('Upload OTA Firmware Image Request...Success') - log.debug("Upload OTA Firmware Image Request - Status: " + json.dumps(status) + - " Response: " + json.dumps(response)) - if 'image_url' in response: - param_url_to_set = response["image_url"] - - log.info("Checking service " + service.OTA_SERVICE_TYPE + " in node config...") - service_config, service_name = service_obj.verify_service_exists(node_object, service.OTA_SERVICE_TYPE) - if not service_config: - log.error(service.OTA_SERVICE_TYPE + " not found.") - log.info("Checking service " + service.OTA_SERVICE_TYPE + " in config...Success") - log.debug("Service config received: " + str(service_config) + - " Service name received: " + service_name) - - log.info("Getting service params from node config") - service_read_params, service_write_params = service_obj.get_service_params(service_config) - log.debug("Service params received with read properties: " + str(service_read_params) + - " Service params received with write properties: " + str(service_write_params)) - log.info("Getting node params...") - node_params = node_object.get_node_params() - log.debug("Node params received: " + json.dumps(node_params)) - - ota_start_status = service_obj.start_ota(node_object, node_params, service_name, - service_write_params, param_url_to_set) - log.debug("OTA status received: " + str(ota_start_status)) - if not ota_start_status: - log.error("Failed to start OTA service...Exiting...") - return - - ota_status = service_obj.check_ota_status(node_object, service_name, service_read_params) - if ota_status in [None, False]: - print("\n") - log.error(" Download OTA Firmware Image...Failed.") - elif ota_status is True: - log.info('Download OTA Firmware Image...Success.') - else: + if not status or not 'success' in status: print("\n") - log.error("Download OTA Firmware Image...Failed.") - log.debug('Download OTA Firmware Image...Failed' - 'status: ' + status + ' response: ' + response) + log.error("OTA Upgrade...Failed") + log.debug('OTA Upgrade...Failed ' + 'status: ' + str(status) + ' response: ' + str(response)) + return + + log.info('Upload OTA Firmware Image Request...Success') + log.debug("Upload OTA Firmware Image Request - Status: " + json.dumps(status) + + " Response: " + json.dumps(response)) + + + retries = MAX_HTTP_CONNECTION_RETRIES + ota_start_status = None + node_params = None + service_read_params = None + service_write_params = None + ota_status = None + + while retries > 0: + try: + if 'image_url' in response: + param_url_to_set = response["image_url"] + + if not service_read_params and not service_write_params: + log.info("Getting service params from node config") + service_read_params, service_write_params = service_obj.get_service_params(service_config) + log.debug("Service params received with read properties: " + str(service_read_params) + + " Service params received with write properties: " + str(service_write_params)) + log.info("Getting node params...") + if not node_params: + node_params = node_object.get_node_params() + log.debug("Node params received: " + json.dumps(node_params)) + print("Setting the OTA URL parameter...") + + if not ota_start_status: + ota_start_status = service_obj.start_ota(node_object, node_params, service_name, + service_write_params, param_url_to_set) + log.debug("OTA status received: " + str(ota_start_status)) + if not ota_start_status: + log.error("Failed to start OTA service...Exiting...") + break + print("Getting OTA Status...") + if not ota_status: + ota_status = service_obj.check_ota_status(node_object, service_name, service_read_params) + break + except SSLError: + log.error(SSLError()) + break + except (NetworkError, RequestTimeoutError) as conn_err: + print(conn_err) + log.warn(conn_err) + except Exception as node_init_err: + log.error(node_init_err) + break + time.sleep(5) + retries -= 1 + if retries: + print("Retries left:", retries) + log.info("Retries left: " + str(retries)) + + if ota_status in [None, False]: + log.error("OTA Upgrade...Failed") + log.debug('OTA Upgrade...Failed ' + 'ota_status: ' + str(ota_status)) except KeyError as key_err: log.error("Key Error: " + str(key_err)) except Exception as ota_err: diff --git a/cli/rmaker_lib/node.py b/cli/rmaker_lib/node.py index c8cf327..e21ec82 100644 --- a/cli/rmaker_lib/node.py +++ b/cli/rmaker_lib/node.py @@ -85,6 +85,9 @@ class Node: raise SSLError except requests.exceptions.ConnectionError: raise NetworkError + except Timeout as time_err: + log.debug(time_err) + raise RequestTimeoutError except Exception: raise Exception(response.text) log.info("Received node status successfully.") @@ -118,8 +121,13 @@ class Node: raise SSLError except requests.exceptions.ConnectionError: raise NetworkError - except Exception: - raise Exception(response.text) + except Timeout as time_err: + log.debug(time_err) + raise RequestTimeoutError + except RequestException as get_nodes_config_err: + log.debug(get_nodes_config_err) + raise get_nodes_config_err + log.info("Received node config successfully.") return response.json() @@ -154,8 +162,12 @@ class Node: raise SSLError except requests.exceptions.ConnectionError: raise NetworkError - except Exception: - raise Exception(response.text) + except Timeout as time_err: + log.debug(time_err) + raise RequestTimeoutError + except RequestException as get_nodes_params_err: + log.debug(get_nodes_params_err) + raise get_nodes_params_err response = json.loads(response.text) if 'status' in response and response['status'] == 'failure': @@ -199,8 +211,12 @@ class Node: raise SSLError except requests.exceptions.ConnectionError: raise NetworkError - except Exception: - raise Exception(response.text) + except Timeout as time_err: + log.debug(time_err) + raise RequestTimeoutError + except RequestException as set_nodes_params_err: + log.debug(set_nodes_params_err) + raise set_nodes_params_err log.info("Updated node parameters successfully.") return True diff --git a/cli/rmaker_lib/service.py b/cli/rmaker_lib/service.py index 23b9698..79cc6ad 100644 --- a/cli/rmaker_lib/service.py +++ b/cli/rmaker_lib/service.py @@ -77,8 +77,7 @@ class Service: """ node_config = node_obj.get_node_config() service_config = node_config["services"] - log.debug("Checking " + service_type + " in node config...") - print("Checking " + service_type + " in node config...") + log.debug("Checking " + str(service_type) + " in node config...") for service in service_config: if service["type"] == service_type: return service, service["name"] @@ -104,18 +103,23 @@ class Service: :type: bool,str | None """ ota_status = "" + ota_status_empty_str = "(empty)" log.debug("Received service read params: " + json.dumps(service_read_params)) ota_status_key = service_read_params[OTA_PARAMS['status']] ota_info_key = service_read_params[OTA_PARAMS['info']] - log.debug("OTA Status Key : " + ota_status_key) - log.debug("OTA Info Key : " + ota_info_key) - print("Getting OTA Status...") + log.debug("OTA Status Key : " + str(ota_status_key)) + log.debug("OTA Info Key : " + str(ota_info_key)) while True: curr_status = None curr_info = None time.sleep(8) log.info("Getting node params for OTA status") new_node_params = node_obj.get_node_params() + if service_name not in new_node_params and (curr_status not in [None, ota_status_empty_str]): + log.info("OTA may have completed, check the node to confirm.") + print("OTA may have completed, check the node to confirm.") + ota_status = None + break node_service_params = new_node_params[service_name] for k,v in node_service_params.items(): if ota_status_key and k in ota_status_key and not v: @@ -129,22 +133,22 @@ class Service: elif ota_info_key and k in ota_info_key: curr_info = v - log.debug("Current OTA status: " + curr_status) + log.debug("Current OTA status: " + str(curr_status)) curr_time = time.time() if not curr_status: if not ota_status_key: - print("Node Param of type: " + OTA_PARAMS['status'] + " not found...Exiting...") - log.debug("Node Param of type: " + OTA_PARAMS['status'] + " not found...Exiting...") + print("Node param of type: " + OTA_PARAMS['status'] + " not found... Exiting...") + log.debug("Node param of type: " + OTA_PARAMS['status'] + " not found...Exiting...") ota_status = "" break - curr_status = "(empty)" + curr_status = ota_status_empty_str if not curr_info: if not ota_info_key: - print("Node Param of type: " + OTA_PARAMS['info'] + " not found...Exiting...") - log.debug("Node Param of type: " + OTA_PARAMS['info'] + " not found...Exiting...") + print("Node param of type: " + OTA_PARAMS['info'] + " not found... Exiting...") + log.debug("Node param of type: " + OTA_PARAMS['info'] + " not found...Exiting...") ota_status = "" break - curr_info = "(empty)" + curr_info = ota_status_empty_str timestamp = datetime.datetime.fromtimestamp(curr_time).strftime('%H:%M:%S') log.debug("[{:<6}] {:<3} : {:<3}".format(timestamp, curr_status,curr_info)) print("[{:<8}] {:<3} : {:<3}".format(timestamp, curr_status,curr_info)) @@ -192,11 +196,10 @@ class Service: global start_time start_time = None ota_url_key = service_write_params[OTA_PARAMS['url']] - log.debug("OTA URL Key : " + ota_url_key) - log.debug("Setting new url: " + url_to_set) + log.debug("OTA URL Key : " + str(ota_url_key)) + log.debug("Setting new url: " + str(url_to_set)) params_to_set = {service_name: {ota_url_key: url_to_set}} log.debug("New node params after setting url: " + json.dumps(params_to_set)) - print("Setting the OTA URL parameter...") set_node_status = node_obj.set_node_params(params_to_set) if not set_node_status: return False @@ -230,8 +233,6 @@ class Service: :type: str | None """ socket.setdefaulttimeout(100) - print("Uploading OTA Firmware Image...") - log.info("Uploading OTA Firmware Image...") path = 'user/ota_image' request_payload = { 'image_name': img_name, @@ -241,17 +242,15 @@ class Service: request_url = serverconfig.HOST + path try: log.debug("Uploading OTA Firmware Image Request URL : " + - request_url + - " data: " + - json.dumps(request_payload) + str(request_url) ) response = requests.post(url=request_url, data=json.dumps(request_payload), headers=node.request_header, verify=configmanager.CERT_FILE, - timeout=(5.0, 5.0)) + timeout=(60.0, 60.0)) log.debug("Uploading OTA Firmware Image Status Response : " + - response.text) + str(response.text)) response.raise_for_status() except requests.exceptions.SSLError as ssl_err: log.debug(ssl_err)