From 46df967bc7851336d30f9879dcea76502dac70d5 Mon Sep 17 00:00:00 2001 From: tierno Date: Fri, 26 May 2017 13:12:21 +0200 Subject: [PATCH] enhance log message errors when fails at starting Change-Id: I44d8e5f8cc2853ccfb9a55816db9b0eabc935097 Signed-off-by: tierno --- openmanod | 112 ++++++++++++++++++++++++++++--------------------- osm_ro/nfvo.py | 31 ++++++++++---- 2 files changed, 87 insertions(+), 56 deletions(-) diff --git a/openmanod b/openmanod index 0ad7a9e3..e8bd2da4 100755 --- a/openmanod +++ b/openmanod @@ -48,7 +48,7 @@ import osm_ro __author__ = "Alfonso Tierno, Gerardo Garcia, Pablo Montes" __date__ = "$26-aug-2014 11:09:29$" -__version__ = "0.5.12-r522" +__version__ = "0.5.14-r523" version_date = "May 2017" database_version = 20 #expected database schema version @@ -77,27 +77,30 @@ def load_configuration(configuration_file): config = yaml.load(config_str) #Validate configuration file with the config_schema js_v(config, config_schema) - + #Add default values tokens for k,v in default_tokens.items(): if k not in config: config[k]=v return config - + except yaml.YAMLError as e: error_pos = "" if hasattr(e, 'problem_mark'): mark = e.problem_mark error_pos = " at line:{} column:{}".format(mark.line+1, mark.column+1) - raise LoadConfigurationException("Bad YAML format at configuration file '{file}'{pos}".format(file=configuration_file, pos=error_pos) ) + raise LoadConfigurationException("Bad YAML format at configuration file '{file}'{pos}: {message}".format( + file=configuration_file, pos=error_pos, message=e)) except js_e.ValidationError as e: error_pos = "" if e.path: error_pos=" at '" + ":".join(map(str, e.path))+"'" - raise LoadConfigurationException("Invalid field at configuration file '{file}'{pos} {message}".format(file=configuration_file, pos=error_pos, message=str(e)) ) + raise LoadConfigurationException("Invalid field at configuration file '{file}'{pos} {message}".format( + file=configuration_file, pos=error_pos, message=e)) except Exception as e: - raise LoadConfigurationException("Cannot load configuration file '{file}' {message}".format(file=configuration_file, message=str(e) ) ) - + raise LoadConfigurationException("Cannot load configuration file '{file}' {message}".format( + file=configuration_file, message=e)) + def console_port_iterator(): '''this iterator deals with the http_console_ports @@ -117,8 +120,8 @@ def console_port_iterator(): yield port2 port2 += 1 index += 1 - - + + def usage(): print("Usage: ", sys.argv[0], "[options]") print( " -v|--version: prints current version") @@ -131,23 +134,37 @@ def usage(): print( " --log-socket-port PORT: send logs using this port (default: 9022)") print( " --log-file FILE: send logs to this file") return - + + +def set_logging_file(log_file): + try: + file_handler = logging.handlers.RotatingFileHandler(log_file, maxBytes=100e6, backupCount=9, delay=0) + file_handler.setFormatter(log_formatter_simple) + logger.addHandler(file_handler) + # logger.debug("moving logs to '%s'", global_config["log_file"]) + # remove initial stream handler + logging.root.removeHandler(logging.root.handlers[0]) + print ("logging on '{}'".format(log_file)) + except IOError as e: + raise LoadConfigurationException( + "Cannot open logging file '{}': {}. Check folder exist and permissions".format(log_file, e)) + + if __name__=="__main__": - #Configure logging step 1 + # Configure logging step 1 hostname = socket.gethostname() - #streamformat = "%(levelname)s (%(module)s:%(lineno)d) %(message)s" + # streamformat = "%(levelname)s (%(module)s:%(lineno)d) %(message)s" # "%(asctime)s %(name)s %(levelname)s %(filename)s:%(lineno)d %(funcName)s %(process)d: %(message)s" - log_formatter_complete = logging.Formatter( - '%(asctime)s.%(msecs)03d00Z[{host}@openmanod] %(filename)s:%(lineno)s severity:%(levelname)s logger:%(name)s log:%(message)s'.format(host=hostname), - datefmt='%Y-%m-%dT%H:%M:%S', - ) + log_formatter_complete = logging.Formatter('%(asctime)s.%(msecs)03d00Z[{host}@openmanod] %(filename)s:%(lineno)s ' + 'severity:%(levelname)s logger:%(name)s log:%(message)s'.format( + host=hostname), + datefmt='%Y-%m-%dT%H:%M:%S') log_format_simple = "%(asctime)s %(levelname)s %(name)s %(filename)s:%(lineno)s %(message)s" log_formatter_simple = logging.Formatter(log_format_simple, datefmt='%Y-%m-%dT%H:%M:%S') logging.basicConfig(format=log_format_simple, level= logging.DEBUG) logger = logging.getLogger('openmano') logger.setLevel(logging.DEBUG) socket_handler = None - file_handler = None # Read parameters and configuration file httpthread = None try: @@ -160,7 +177,7 @@ if __name__=="__main__": log_file = None log_socket_host = None log_socket_port = None - + for o, a in opts: if o in ("-v", "--version"): print ("openmanod version " + __version__ + ' ' + version_date) @@ -185,6 +202,8 @@ if __name__=="__main__": log_file = a else: assert False, "Unhandled option" + if log_file: + set_logging_file(log_file) global_config = load_configuration(config_file) global_config["version"] = __version__ global_config["version_date"] = version_date @@ -198,12 +217,10 @@ if __name__=="__main__": global_config['log_socket_host'] = log_socket_host if log_socket_port: global_config['log_socket_port'] = log_socket_port - if log_file: - global_config['log_file'] = log_file # if vnf_repository is not None: # global_config['vnf_repository'] = vnf_repository # else: -# if not 'vnf_repository' in global_config: +# if not 'vnf_repository' in global_config: # logger.error( os.getcwd() ) # global_config['vnf_repository'] = os.getcwd()+'/vnfrepo' # #print global_config @@ -214,7 +231,7 @@ if __name__=="__main__": # except Exception as e: # logger.error( "Error '%s'. Ensure the path 'vnf_repository' is properly set at %s",e.args[1], config_file) # exit(-1) - + global_config["console_port_iterator"] = console_port_iterator global_config["console_thread"]={} global_config["console_ports"]={} @@ -222,31 +239,26 @@ if __name__=="__main__": global_config["http_console_host"] = global_config["http_host"] if global_config["http_host"]=="0.0.0.0": global_config["http_console_host"] = socket.gethostname() - - #Configure logging STEP 2 + + # Configure logging STEP 2 if "log_host" in global_config: socket_handler= log_handlers.SocketHandler(global_config["log_socket_host"], global_config["log_socket_port"]) socket_handler.setFormatter(log_formatter_complete) - if global_config.get("log_socket_level") and global_config["log_socket_level"] != global_config["log_level"]: + if global_config.get("log_socket_level") and global_config["log_socket_level"] != global_config["log_level"]: socket_handler.setLevel(global_config["log_socket_level"]) logger.addHandler(socket_handler) - #logger.addHandler(log_handlers.SysLogHandler()) - if "log_file" in global_config: - try: - file_handler= logging.handlers.RotatingFileHandler(global_config["log_file"], maxBytes=100e6, backupCount=9, delay=0) - file_handler.setFormatter(log_formatter_simple) - logger.addHandler(file_handler) - #logger.debug("moving logs to '%s'", global_config["log_file"]) - #remove initial stream handler - logging.root.removeHandler(logging.root.handlers[0]) - print ("logging on '{}'".format(global_config["log_file"])) - except IOError as e: - raise LoadConfigurationException("Cannot open logging file '{}': {}. Check folder exist and permissions".format(global_config["log_file"], str(e)) ) - #logging.basicConfig(level = getattr(logging, global_config.get('log_level',"debug"))) + + # logger.addHandler(log_handlers.SysLogHandler()) + if log_file: + global_config['log_file'] = log_file + elif global_config.get('log_file'): + set_logging_file(global_config['log_file']) + + # logging.basicConfig(level = getattr(logging, global_config.get('log_level',"debug"))) logger.setLevel(getattr(logging, global_config['log_level'])) - logger.critical("Starting openmano server version: '%s %s' command: '%s'", + logger.critical("Starting openmano server version: '%s %s' command: '%s'", __version__, version_date, " ".join(sys.argv)) - + for log_module in ("nfvo", "http", "vim", "db", "console", "ovim"): log_level_module = "log_level_" + log_module log_file_module = "log_file_" + log_module @@ -255,15 +267,18 @@ if __name__=="__main__": logger_module.setLevel(global_config[log_level_module]) if log_file_module in global_config: try: - file_handler= logging.handlers.RotatingFileHandler(global_config[log_file_module], maxBytes=100e6, backupCount=9, delay=0) + file_handler = logging.handlers.RotatingFileHandler(global_config[log_file_module], + maxBytes=100e6, backupCount=9, delay=0) file_handler.setFormatter(log_formatter_simple) logger_module.addHandler(file_handler) except IOError as e: - raise LoadConfigurationException("Cannot open logging file '{}': {}. Check folder exist and permissions".format(global_config[log_file_module], str(e)) ) + raise LoadConfigurationException( + "Cannot open logging file '{}': {}. Check folder exist and permissions".format( + global_config[log_file_module], str(e)) ) global_config["logger_"+log_module] = logger_module #httpserver.logger = global_config["logger_http"] #nfvo.logger = global_config["logger_nfvo"] - + # Initialize DB connection mydb = nfvo_db.nfvo_db(); mydb.connect(global_config['db_host'], global_config['db_user'], global_config['db_passwd'], global_config['db_name']) @@ -284,14 +299,14 @@ if __name__=="__main__": nfvo.global_config=global_config nfvo.start_service(mydb) - + httpthread = httpserver.httpserver(mydb, False, global_config['http_host'], global_config['http_port']) - + httpthread.start() - if 'http_admin_port' in global_config: + if 'http_admin_port' in global_config: httpthreadadmin = httpserver.httpserver(mydb, True, global_config['http_host'], global_config['http_admin_port']) httpthreadadmin.start() - time.sleep(1) + time.sleep(1) logger.info('Waiting for http clients') print('Waiting for http clients') print('openmanod ready') @@ -321,6 +336,9 @@ if __name__=="__main__": except db_base_Exception as e: logger.critical(str(e)) exit(-1) + except nfvo.NfvoException as e: + logger.critical(str(e), exc_info=True) + exit(-1) nfvo.stop_service() if httpthread: httpthread.join(1) diff --git a/osm_ro/nfvo.py b/osm_ro/nfvo.py index 5a29eedf..3e59285b 100644 --- a/osm_ro/nfvo.py +++ b/osm_ro/nfvo.py @@ -128,14 +128,16 @@ def start_service(mydb): #TODO: log_level_of should not be needed. To be modified in ovim 'log_level_of': 'DEBUG' } - ovim = ovim_module.ovim(ovim_configuration) - ovim.start_service() - - from_= 'tenants_datacenters as td join datacenters as d on td.datacenter_id=d.uuid join datacenter_tenants as dt on td.datacenter_tenant_id=dt.uuid' - select_ = ('type','d.config as config','d.uuid as datacenter_id', 'vim_url', 'vim_url_admin', 'd.name as datacenter_name', - 'dt.uuid as datacenter_tenant_id','dt.vim_tenant_name as vim_tenant_name','dt.vim_tenant_id as vim_tenant_id', - 'user','passwd', 'dt.config as dt_config', 'nfvo_tenant_id') try: + ovim = ovim_module.ovim(ovim_configuration) + ovim.start_service() + + from_= 'tenants_datacenters as td join datacenters as d on td.datacenter_id=d.uuid join '\ + 'datacenter_tenants as dt on td.datacenter_tenant_id=dt.uuid' + select_ = ('type', 'd.config as config', 'd.uuid as datacenter_id', 'vim_url', 'vim_url_admin', + 'd.name as datacenter_name', 'dt.uuid as datacenter_tenant_id', + 'dt.vim_tenant_name as vim_tenant_name', 'dt.vim_tenant_id as vim_tenant_id', + 'user', 'passwd', 'dt.config as dt_config', 'nfvo_tenant_id') vims = mydb.get_rows(FROM=from_, SELECT=select_) for vim in vims: extra={'datacenter_tenant_id': vim.get('datacenter_tenant_id'), @@ -172,14 +174,25 @@ def start_service(mydb): config=extra, persistent_info=vim_persistent_info[thread_id] ) except Exception as e: - raise NfvoException("Error at VIM {}; {}: {}".format(vim["type"], type(e).__name__, str(e)), HTTP_Internal_Server_Error) - thread_name = get_non_used_vim_name(vim['datacenter_name'], vim['vim_tenant_id'], vim['vim_tenant_name'], vim['vim_tenant_id']) + raise NfvoException("Error at VIM {}; {}: {}".format(vim["type"], type(e).__name__, e), + HTTP_Internal_Server_Error) + thread_name = get_non_used_vim_name(vim['datacenter_name'], vim['vim_tenant_id'], vim['vim_tenant_name'], + vim['vim_tenant_id']) new_thread = vim_thread.vim_thread(myvim, task_lock, thread_name, vim['datacenter_name'], vim['datacenter_tenant_id'], db=db, db_lock=db_lock, ovim=ovim) new_thread.start() vim_threads["running"][thread_id] = new_thread except db_base_Exception as e: raise NfvoException(str(e) + " at nfvo.get_vim", e.http_code) + except ovim_module.ovimException as e: + message = str(e) + if message[:22] == "DATABASE wrong version": + message = "DATABASE wrong version of lib_osm_openvim {msg} -d{dbname} -u{dbuser} -p{dbpass} {ver}' "\ + "at host {dbhost}".format( + msg=message[22:-3], dbname=global_config["db_ovim_name"], + dbuser=global_config["db_ovim_user"], dbpass=global_config["db_ovim_passwd"], + ver=message[-3:-1], dbhost=global_config["db_ovim_host"]) + raise NfvoException(message, HTTP_Bad_Request) def stop_service(): -- 2.25.1