From 8d7c0201456b7f9af6e91fea90354f4c3de323fe Mon Sep 17 00:00:00 2001 From: Satoshi Fujii Date: Fri, 22 Oct 2021 12:30:45 +0000 Subject: Fix log rotation issue Writing log to a single file from multiple processes is not supported by python logging. It causes making fragmented log files at log rotation and logs are mixed up. This change is to use different log files for each sub-process to help developers check log for a specific process easily. This change does not affect to pod log (stdout log). Signed-off-by: Satoshi Fujii Issue-ID: DCAEGEN2-2941 Change-Id: If8bcb2308863d1395a2c547d2e7b746301665fb0 --- Changelog.md | 1 + miss_htbt_service/cbs_polling.py | 5 ++-- miss_htbt_service/db_monitoring.py | 4 ++- miss_htbt_service/get_logger.py | 42 ++++++++++++++++++++------------ miss_htbt_service/htbtworker.py | 10 ++++---- miss_htbt_service/misshtbtd.py | 6 ++--- miss_htbt_service/mod/trapd_vnf_table.py | 7 +++--- tests/test_get_logger.py | 36 ++++++++++++++++----------- tests/test_trapd_vnf_table.py | 5 ++-- 9 files changed, 70 insertions(+), 46 deletions(-) diff --git a/Changelog.md b/Changelog.md index db72ea9..5aeff31 100644 --- a/Changelog.md +++ b/Changelog.md @@ -11,6 +11,7 @@ and this project adheres to [Semantic Versioning](http://semver.org/). - [DCAEGEN2-2832] Pod become unready state - [DCAEGEN2-2872] No such file or directory error and stop working - [DCAEGEN2-2940] Microsec timestamp not properly handled +- [DCAEGEN2-2941] Log file fragmented by log rotation - [DCAEGEN2-2944] cbs polling process startup failure diff --git a/miss_htbt_service/cbs_polling.py b/miss_htbt_service/cbs_polling.py index 3832b71..e7bdef1 100644 --- a/miss_htbt_service/cbs_polling.py +++ b/miss_htbt_service/cbs_polling.py @@ -22,7 +22,7 @@ # CBS Polling # Set the hb_common table with state="RECONFIGURATION" periodically # to get the new configuration downloaded - +import logging import sys import os import socket @@ -30,7 +30,7 @@ import time import misshtbtd as db import get_logger -_logger = get_logger.get_logger(__name__) +_logger = logging.getLogger(__name__) def poll_cbs(current_pid: int) -> None: @@ -60,6 +60,7 @@ def poll_cbs(current_pid: int) -> None: def cbs_polling_loop(current_pid: int): + get_logger.configure_logger('cbs_polling') while True: poll_cbs(current_pid) diff --git a/miss_htbt_service/db_monitoring.py b/miss_htbt_service/db_monitoring.py index 32e8edc..a405876 100644 --- a/miss_htbt_service/db_monitoring.py +++ b/miss_htbt_service/db_monitoring.py @@ -24,6 +24,7 @@ # and generates Missing Heartbeat signal for Policy Engine import json +import logging import sys import os import socket @@ -33,7 +34,7 @@ import htbtworker as pm import misshtbtd as db import get_logger -_logger = get_logger.get_logger(__name__) +_logger = logging.getLogger(__name__) def sendControlLoopEvent(CLType, pol_url, policy_version, policy_name, policy_scope, target_type, srcName, epoc_time, @@ -232,6 +233,7 @@ def db_monitoring(current_pid, json_file, user_name, password, ip_address, port_ if __name__ == "__main__": + get_logger.configure_logger('db_monitoring') _logger.info("DBM: DBM Process started") current_pid = sys.argv[1] jsfile = sys.argv[2] diff --git a/miss_htbt_service/get_logger.py b/miss_htbt_service/get_logger.py index c58a945..55286eb 100644 --- a/miss_htbt_service/get_logger.py +++ b/miss_htbt_service/get_logger.py @@ -17,20 +17,32 @@ import logging.handlers -'''Configures the module root logger''' -root = logging.getLogger() -if root.handlers: - del root.handlers[:] -formatter = logging.Formatter('%(asctime)s | %(name)s | %(module)s | %(funcName)s | %(lineno)d | %(levelname)s | %(message)s') -handler = logging.StreamHandler() -handler.setFormatter(formatter) -root.addHandler(handler) -fhandler = logging.handlers.RotatingFileHandler('./hb_logs.txt', maxBytes=(1048576 * 5), backupCount=10) -fhandler.setFormatter(formatter) -root.addHandler(fhandler) -root.setLevel("DEBUG") +LOG_LEVEL = logging.DEBUG +LOG_FORMAT = '%(asctime)s | %(levelname)5s | %(name)s | %(module)s | %(funcName)s | %(lineno)d | %(message)s' +LOG_MAXSIZE = 10485760 * 5 +LOG_BACKUP_COUNT = 10 -def get_logger(module=None): - '''Returns a module-specific logger or global logger if the module is None''' - return root if module is None else root.getChild(module) +def configure_logger(proc_name: str) -> None: + """Configures the module root logger""" + + # Clear handlers + root = logging.getLogger() + if root.handlers: + del root.handlers[:] + + # Add stdout handler + formatter = logging.Formatter(LOG_FORMAT) + handler = logging.StreamHandler() + handler.setFormatter(formatter) + root.addHandler(handler) + + # Add rotating log file handler + if proc_name: + logfile_path = './hb_%s_logs.txt' % proc_name + else: + logfile_path = './hb_logs.txt' + fhandler = logging.handlers.RotatingFileHandler(logfile_path, maxBytes=LOG_MAXSIZE, backupCount=LOG_BACKUP_COUNT) + fhandler.setFormatter(formatter) + root.addHandler(fhandler) + root.setLevel(LOG_LEVEL) diff --git a/miss_htbt_service/htbtworker.py b/miss_htbt_service/htbtworker.py index 6fbda2d..be1b6aa 100644 --- a/miss_htbt_service/htbtworker.py +++ b/miss_htbt_service/htbtworker.py @@ -22,6 +22,7 @@ # Simple Microservice # Tracks Heartbeat messages on input topic in DMaaP # and poppulate the information in postgres DB +import logging import psycopg2 import requests @@ -33,7 +34,7 @@ import time import misshtbtd as db import get_logger -_logger = get_logger.get_logger(__name__) +_logger = logging.getLogger(__name__) def read_json_file(i, prefix="../../tests"): @@ -160,8 +161,7 @@ def process_msg(jsfile, user_name, password, ip_address, port_num, db_name): source_name_key = source_name_count + 1 cl_flag = 0 if source_name_count == 0: # pragma: no cover - msg = "HBT: Insert entry in table_2,source_name_count=0 : ", row - _logger.info(msg) + _logger.info("HBT: Insert entry into vnf_table_2, source_name='%s'", srcname) cur.execute("INSERT INTO vnf_table_2 VALUES(%s,%s,%s,%s,%s)", (eventName, source_name_key, lastepo, srcname, cl_flag)) cur.execute("UPDATE vnf_table_1 SET SOURCE_NAME_COUNT = %s where EVENT_NAME = %s", @@ -190,8 +190,7 @@ def process_msg(jsfile, user_name, password, ip_address, port_num, db_name): _logger.info(msg) if source_name_count == (source_name_key + 1): source_name_key = source_name_count + 1 - msg = "HBT: Insert entry in table_2 : ", row - _logger.info(msg) + _logger.info("HBT: Insert entry into vnf_table_2, source_name='%s'", srcname) cur.execute("INSERT INTO vnf_table_2 VALUES(%s,%s,%s,%s,%s)", (eventName, source_name_key, lastepo, srcname, cl_flag)) cur.execute("UPDATE vnf_table_1 SET SOURCE_NAME_COUNT = %s WHERE EVENT_NAME = %s", @@ -256,6 +255,7 @@ def commit_and_close_db(connection_db): if __name__ == '__main__': + get_logger.configure_logger('htbtworker') jsfile = sys.argv[1] msg = "HBT:HeartBeat thread Created" _logger.info("HBT:HeartBeat thread Created") diff --git a/miss_htbt_service/misshtbtd.py b/miss_htbt_service/misshtbtd.py index 61da9d9..6be2260 100644 --- a/miss_htbt_service/misshtbtd.py +++ b/miss_htbt_service/misshtbtd.py @@ -28,6 +28,7 @@ # # Author Prakash Hosangady(ph553f@att.com) import shutil +import logging import traceback import os import sys @@ -49,6 +50,7 @@ from mod import trapd_settings as tds from mod.trapd_get_cbs_config import get_cbs_config hb_properties_file = path.abspath(path.join(__file__, "../config/hbproperties.yaml")) +_logger = logging.getLogger(__name__) ABSOLUTE_PATH1 = path.abspath(path.join(__file__, "../htbtworker.py")) ABSOLUTE_PATH2 = path.abspath(path.join(__file__, "../db_monitoring.py")) @@ -319,10 +321,8 @@ def create_process(job_list, jsfile, pid_current): return job_list -_logger = get_logger.get_logger(__name__) - - def main(): + get_logger.configure_logger('misshtbtd') pid_current = os.getpid() hc_proc = multiprocessing.Process(target=check_health.start_health_check_server) cbs_polling_proc = multiprocessing.Process(target=cbs_polling.cbs_polling_loop, args=(pid_current,)) diff --git a/miss_htbt_service/mod/trapd_vnf_table.py b/miss_htbt_service/mod/trapd_vnf_table.py index ff738f0..db6bd17 100644 --- a/miss_htbt_service/mod/trapd_vnf_table.py +++ b/miss_htbt_service/mod/trapd_vnf_table.py @@ -25,7 +25,7 @@ """ trapd_vnf_table verifies the successful creation of DB Tables. """ - +import logging import os import yaml import os.path as path @@ -39,8 +39,9 @@ import misshtbtd as db import cbs_polling as cbs prog_name = os.path.basename(__file__) -hb_properties_file = path.abspath(path.join(__file__, "../../config/hbproperties.yaml")) -_logger = get_logger.get_logger(__name__) +hb_properties_file = path.abspath(path.join(__file__, "../../config/hbproperties.yaml")) +_logger = logging.getLogger(__name__) + def hb_properties(): #Read the hbproperties.yaml for postgress and CBS related data diff --git a/tests/test_get_logger.py b/tests/test_get_logger.py index a643e0f..cbef9c6 100644 --- a/tests/test_get_logger.py +++ b/tests/test_get_logger.py @@ -1,5 +1,6 @@ # ============LICENSE_START======================================================= # Copyright (c) 2020 AT&T Intellectual Property. All rights reserved. +# Copyright 2021 Fujitsu Ltd. # ================================================================================ # Licensed under the Apache License, Version 2.0 (the "License"); # you may not use this file except in compliance with the License. @@ -13,23 +14,30 @@ # See the License for the specific language governing permissions and # limitations under the License. # ============LICENSE_END========================================================= +import logging +import os +from pathlib import Path from miss_htbt_service import get_logger -import os +log = logging.getLogger(__name__) + -def test_get_logger(): - try: - os.remove("hb_logs.txt") - except: - pass - log = get_logger.get_logger() +def test_configure_logger(): + expected_log_path = Path('./hb_logs.txt') + if expected_log_path.exists(): + os.remove(expected_log_path) + get_logger.configure_logger('') log.info("hi there") + assert expected_log_path.exists() + os.remove(expected_log_path) -def test_get_logger_node(): - try: - os.remove("hb_logs.txt") - except: - pass - log = get_logger.get_logger("node") - log.info("hi there node") + +def test_configure_logger_with_name(): + expected_log_path = Path('./hb_htbtworker_logs.txt') + if expected_log_path.exists(): + os.remove(expected_log_path) + get_logger.configure_logger('htbtworker') + log.info("hi there") + assert expected_log_path.exists() + os.remove(expected_log_path) diff --git a/tests/test_trapd_vnf_table.py b/tests/test_trapd_vnf_table.py index 2110324..e8ef5d0 100644 --- a/tests/test_trapd_vnf_table.py +++ b/tests/test_trapd_vnf_table.py @@ -23,9 +23,8 @@ """ test_trapd_vnf_table contains test cases related to DB Tables and cbs polling. """ - +import logging import unittest -import get_logger from mod.trapd_vnf_table import ( verify_DB_creation_1, verify_DB_creation_2, verify_DB_creation_hb_common, hb_properties, verify_cbspolling, @@ -34,7 +33,7 @@ from mod.trapd_vnf_table import ( verify_fetch_json_file, verify_misshtbtdmain, verify_dbmonitoring, verify_dbmon_startup) -_logger = get_logger.get_logger(__name__) +_logger = logging.getLogger(__name__) class test_vnf_tables(unittest.TestCase): -- cgit 1.2.3-korg