From 3e1485dd055bbf34a1356044f0c4685ce669fa2b Mon Sep 17 00:00:00 2001 From: Heitor Matsui Date: Thu, 22 Feb 2024 17:26:36 -0300 Subject: [PATCH] Improve logging for deploy python scripts This commit improves logging during "deploy start" by: 1. Creating a function on upgrade_utils to configure logging 2. Replacing basic log configuration with the function from previous item 3. Configuring software/utilities/migrate.py module to effectively log in a file 4. Suppressing meaningless SQL commands output generated during databases migration Test Plan PASS: run deploy start/upload, verify the logs from the scripts are created as expected Story: 2010676 Task: 49620 Depends-on: https://review.opendev.org/c/starlingx/update/+/910262 Signed-off-by: Heitor Matsui Change-Id: Ib78bdcd1dd98b0f221985a429b6e9eeddeba837b --- software/scripts/prep-data-migration | 10 +++++----- software/scripts/sync-controllers-feed | 6 +++--- software/scripts/upgrade_utils.py | 15 ++++++++++++++- software/scripts/usm_load_import | 5 +++-- software/software/utilities/migrate.py | 24 ++++++++++++++---------- 5 files changed, 39 insertions(+), 21 deletions(-) diff --git a/software/scripts/prep-data-migration b/software/scripts/prep-data-migration index 1f093e84..25c08e44 100644 --- a/software/scripts/prep-data-migration +++ b/software/scripts/prep-data-migration @@ -3,7 +3,7 @@ # # vim: tabstop=4 shiftwidth=4 softtabstop=4 # -# Copyright (c) 2023 Wind River Systems, Inc. +# Copyright (c) 2023-2024 Wind River Systems, Inc. # # SPDX-License-Identifier: Apache-2.0 # @@ -260,7 +260,7 @@ def main(sys_argv): data_migration = DataMigration(rootdir, from_release, to_release, keystone_config) - LOG.info("Running data migration from %s to %s" % (from_release, to_release)) + LOG.info("Running data migration preparation from %s to %s" % (from_release, to_release)) try: # export postgres databases @@ -285,14 +285,14 @@ def main(sys_argv): # Export /etc directory to $rootdir/etc data_migration.export_etc() - LOG.info("Data migration completed successfully.") + LOG.info("Data migration preparation completed successfully.") except Exception as e: - LOG.exception("Data migration failed.") + LOG.exception("Data migration preparation failed.") return 1 return 0 if __name__ == "__main__": - LOG.basicConfig(filename='/var/log/prep-data-migration.log', level=LOG.INFO) + upgrade_utils.configure_logging("/var/log/software.log", log_level=LOG.INFO) sys.exit(main(sys.argv)) diff --git a/software/scripts/sync-controllers-feed b/software/scripts/sync-controllers-feed index c5a89f9e..376c6f64 100644 --- a/software/scripts/sync-controllers-feed +++ b/software/scripts/sync-controllers-feed @@ -3,7 +3,7 @@ # # vim: tabstop=4 shiftwidth=4 softtabstop=4 # -# Copyright (c) 2023 Wind River Systems, Inc. +# Copyright (c) 2023-2024 Wind River Systems, Inc. # # SPDX-License-Identifier: Apache-2.0 # @@ -60,7 +60,7 @@ def main(sys_argv): _, system_mode = upgrade_utils.get_system_info(sysinv_client) simplex = (system_mode == SYSTEM_MODE_SIMPLEX) if simplex: - print("System mode is simplex. Skipping sync controllers feed.. ") + LOG.info("System mode is simplex. Skipping sync controllers feed.. ") return 0 except ImportError: @@ -88,5 +88,5 @@ def main(sys_argv): if __name__ == "__main__": - LOG.basicConfig(filename='/var/log/software.log', level=LOG.INFO) + upgrade_utils.configure_logging('/var/log/software.log', log_level=LOG.INFO) sys.exit(main(sys.argv)) diff --git a/software/scripts/upgrade_utils.py b/software/scripts/upgrade_utils.py index 5d95b31c..e6f4bb7c 100644 --- a/software/scripts/upgrade_utils.py +++ b/software/scripts/upgrade_utils.py @@ -1,12 +1,15 @@ # -# Copyright (c) 2023 Wind River Systems, Inc. +# Copyright (c) 2023-2024 Wind River Systems, Inc. # # SPDX-License-Identifier: Apache-2.0 # # This is an utility module used by standalone USM upgrade scripts # that runs on the FROM-side context but using TO-side code base # +import logging +import os import re +import sys from keystoneauth1 import exceptions from keystoneauth1 import identity @@ -128,3 +131,13 @@ def get_system_info(sysinv_client): """ system_info = sysinv_client.isystem.list()[0] return system_info.system_type, system_info.system_mode + + +def configure_logging(filename, log_level=logging.INFO): + my_exec = os.path.basename(sys.argv[0]) + + log_format = ('%(asctime)s: ' + my_exec + '[%(process)s]: ' + '%(filename)s(%(lineno)s): %(levelname)s: %(message)s') + log_datefmt = "%FT%T" + + logging.basicConfig(filename=filename, format=log_format, level=log_level, datefmt=log_datefmt) diff --git a/software/scripts/usm_load_import b/software/scripts/usm_load_import index fce6283d..d9a6419c 100644 --- a/software/scripts/usm_load_import +++ b/software/scripts/usm_load_import @@ -3,7 +3,7 @@ # # vim: tabstop=4 shiftwidth=4 softtabstop=4 # -# Copyright (c) 2023 Wind River Systems, Inc. +# Copyright (c) 2023-2024 Wind River Systems, Inc. # # SPDX-License-Identifier: Apache-2.0 # @@ -21,6 +21,7 @@ import os import shutil import sys +import upgrade_utils AVAILABLE_DIR = "/opt/software/metadata/available" FEED_OSTREE_BASE_DIR = "/var/www/pages/feed" @@ -199,5 +200,5 @@ def main(): if __name__ == "__main__": - LOG.basicConfig(filename='/var/log/usm-load-import.log', level=LOG.INFO) + upgrade_utils.configure_logging('/var/log/software.log', log_level=LOG.INFO) sys.exit(main()) diff --git a/software/software/utilities/migrate.py b/software/software/utilities/migrate.py index 067acbf7..e6e734f3 100644 --- a/software/software/utilities/migrate.py +++ b/software/software/utilities/migrate.py @@ -1,5 +1,5 @@ # -# Copyright (c) 2023 Wind River Systems, Inc. +# Copyright (c) 2023-2024 Wind River Systems, Inc. # # SPDX-License-Identifier: Apache-2.0 # @@ -7,6 +7,7 @@ import argparse import glob import json +import logging import os from pathlib import Path import psycopg2 @@ -16,14 +17,12 @@ import sys import subprocess import yaml - -from oslo_log import log - from software.utilities import constants import software.utilities.utils as utils sout = sys.stdout +devnull = subprocess.DEVNULL def get_postgres_bin(): @@ -38,12 +37,18 @@ def get_postgres_bin(): POSTGRES_BIN = get_postgres_bin() -LOG = log.getLogger(__name__) POSTGRES_PATH = '/var/lib/postgresql' POSTGRES_DATA_DIR = os.path.join(POSTGRES_PATH, constants.SW_VERSION) DB_CONNECTION_FORMAT = "connection=postgresql://%s:%s@127.0.0.1:%s/%s\n" DB_BARBICAN_CONNECTION_FORMAT = "postgresql://%s:%s@127.0.0.1:%s/%s" +# Configure logging +LOG = logging.getLogger(__name__) +log_format = ('%(asctime)s: ' + __name__ + '[%(process)s]: ' + '%(filename)s(%(lineno)s): %(levelname)s: %(message)s') +log_datefmt = "%FT%T" +logging.basicConfig(filename="/var/log/software.log", format=log_format, level=logging.INFO, datefmt=log_datefmt) + def migrate_keyring_data(from_release, to_release): """Migrates keyring data. """ @@ -252,11 +257,11 @@ def import_databases(target_port, from_path=None): try: postgres_config_path = os.path.join( from_dir, 'postgres.postgreSql.config') - # Do postgres schema import (suppress stderr due to noise) + # Do postgres schema import subprocess.check_call(['sudo -u postgres psql --port=%s -f ' % target_port + postgres_config_path + ' postgres'], shell=True, - stdout=sout, + stdout=devnull, stderr=sout) except subprocess.CalledProcessError: LOG.exception("Failed to import schemas.") @@ -267,7 +272,7 @@ def import_databases(target_port, from_path=None): # Do postgres data import for data in glob.glob(from_dir + '/*.*Sql.data'): db_elem = data.split('/')[-1].split('.')[0] - LOG.info("importing {}".format(db_elem)) + LOG.info("Importing %s" % db_elem) import_commands.append((db_elem, "sudo -u postgres psql --port=%s -f " % target_port + data + " " + db_elem)) @@ -301,8 +306,7 @@ def import_databases(target_port, from_path=None): try: print("Importing %s" % cmd[0]) LOG.info("Executing import command: %s" % cmd[1]) - subprocess.check_call([cmd[1]], - shell=True, stdout=sout) + subprocess.check_call([cmd[1]], shell=True, stdout=devnull, stderr=sout) except subprocess.CalledProcessError as ex: LOG.exception("Failed to execute command: '%s' during upgrade "