From fddf2e6968ba849077787fdded6fba62878f3b7c Mon Sep 17 00:00:00 2001 From: Sergi Delgado Segura Date: Thu, 23 Jan 2020 18:13:30 +0100 Subject: [PATCH 1/3] Fixes logger not properly working for cli The Logger was set to use c_logger and f_logger from pisad, so the cli file logs were never created --- common/logger.py | 23 ++++++++++++----------- 1 file changed, 12 insertions(+), 11 deletions(-) diff --git a/common/logger.py b/common/logger.py index ac683c2..b175ebf 100644 --- a/common/logger.py +++ b/common/logger.py @@ -1,8 +1,7 @@ import json +import logging from datetime import datetime -from pisa import f_logger, c_logger - class _StructuredMessage: def __init__(self, message, **kwargs): @@ -22,8 +21,10 @@ class Logger: actor (:obj:`str`): the system actor that is logging the event (e.g. ``Watcher``, ``Cryptographer``, ...). """ - def __init__(self, actor=None): + def __init__(self, log_name_prefix, actor=None): self.actor = actor + self.f_logger = logging.getLogger("{}_file_log".format(log_name_prefix)) + self.c_logger = logging.getLogger("{}_console_log".format(log_name_prefix)) def _add_prefix(self, msg): return msg if self.actor is None else "[{}]: {}".format(self.actor, msg) @@ -54,8 +55,8 @@ class Logger: kwargs: a ``key:value`` collection parameters to be added to the output. """ - f_logger.info(self._create_file_message(msg, **kwargs)) - c_logger.info(self._create_console_message(msg, **kwargs)) + self.f_logger.info(self._create_file_message(msg, **kwargs)) + self.c_logger.info(self._create_console_message(msg, **kwargs)) def debug(self, msg, **kwargs): """ @@ -66,8 +67,8 @@ class Logger: kwargs: a ``key:value`` collection parameters to be added to the output. """ - f_logger.debug(self._create_file_message(msg, **kwargs)) - c_logger.debug(self._create_console_message(msg, **kwargs)) + self.f_logger.debug(self._create_file_message(msg, **kwargs)) + self.c_logger.debug(self._create_console_message(msg, **kwargs)) def error(self, msg, **kwargs): """ @@ -78,8 +79,8 @@ class Logger: kwargs: a ``key:value`` collection parameters to be added to the output. """ - f_logger.error(self._create_file_message(msg, **kwargs)) - c_logger.error(self._create_console_message(msg, **kwargs)) + self.f_logger.error(self._create_file_message(msg, **kwargs)) + self.c_logger.error(self._create_console_message(msg, **kwargs)) def warning(self, msg, **kwargs): """ @@ -90,5 +91,5 @@ class Logger: kwargs: a ``key:value`` collection parameters to be added to the output. """ - f_logger.warning(self._create_file_message(msg, **kwargs)) - c_logger.warning(self._create_console_message(msg, **kwargs)) + self.f_logger.warning(self._create_file_message(msg, **kwargs)) + self.c_logger.warning(self._create_console_message(msg, **kwargs)) From 1f46e6eb26749cf3b633753f257ead414b3cc887 Mon Sep 17 00:00:00 2001 From: Sergi Delgado Segura Date: Thu, 23 Jan 2020 18:14:34 +0100 Subject: [PATCH 2/3] Moves logging setup to common The setup it's identical for cli and pisad --- common/tools.py | 30 ++++++++++++++++++++++++++++++ 1 file changed, 30 insertions(+) diff --git a/common/tools.py b/common/tools.py index 6c2d0c2..ec02451 100644 --- a/common/tools.py +++ b/common/tools.py @@ -1,5 +1,6 @@ import re import os +import logging from common.constants import LOCATOR_LEN_HEX @@ -69,3 +70,32 @@ def extend_paths(base_path, config_fields): config_fields[key]["value"] = base_path + config_fields[key]["value"] return config_fields + + +def setup_logging(log_file_path, log_name_prefix): + if not isinstance(log_file_path, str): + print(log_file_path) + raise ValueError("Wrong log file path.") + + if not isinstance(log_name_prefix, str): + raise ValueError("Wrong log file name.") + + # Create the file logger + f_logger = logging.getLogger("{}_file_log".format(log_name_prefix)) + f_logger.setLevel(logging.INFO) + + fh = logging.FileHandler(log_file_path) + fh.setLevel(logging.INFO) + fh_formatter = logging.Formatter("%(message)s") + fh.setFormatter(fh_formatter) + f_logger.addHandler(fh) + + # Create the console logger + c_logger = logging.getLogger("{}_console_log".format(log_name_prefix)) + c_logger.setLevel(logging.INFO) + + ch = logging.StreamHandler() + ch.setLevel(logging.INFO) + ch_formatter = logging.Formatter("%(message)s.", "%Y-%m-%d %H:%M:%S") + ch.setFormatter(ch_formatter) + c_logger.addHandler(ch) From 6884db9f58abb3d7b827a8e2ea8256f09f11ba86 Mon Sep 17 00:00:00 2001 From: Sergi Delgado Segura Date: Thu, 23 Jan 2020 18:16:25 +0100 Subject: [PATCH 3/3] Updates logger codebase-wise to match the Logger updates Logger instances now specify the logger prefix so the logger can be properly loaded, fixing the issues with the cli file logger --- pisa/api.py | 5 +++-- pisa/block_processor.py | 4 +++- pisa/carrier.py | 3 ++- pisa/chain_monitor.py | 3 ++- pisa/cleaner.py | 4 +++- pisa/db_manager.py | 4 +++- pisa/inspector.py | 4 ++-- pisa/responder.py | 3 ++- pisa/watcher.py | 3 ++- 9 files changed, 22 insertions(+), 11 deletions(-) diff --git a/pisa/api.py b/pisa/api.py index a70ca34..e31d0d2 100644 --- a/pisa/api.py +++ b/pisa/api.py @@ -1,8 +1,9 @@ import os import json +import logging from flask import Flask, request, abort, jsonify -from pisa import HOST, PORT, logging +from pisa import HOST, PORT, LOG_PREFIX from common.logger import Logger from pisa.inspector import Inspector from common.appointment import Appointment @@ -13,7 +14,7 @@ from common.constants import HTTP_OK, HTTP_BAD_REQUEST, HTTP_SERVICE_UNAVAILABLE # ToDo: #5-add-async-to-api app = Flask(__name__) -logger = Logger("API") +logger = Logger(actor="API", log_name_prefix=LOG_PREFIX) class API: diff --git a/pisa/block_processor.py b/pisa/block_processor.py index 1970b42..c5a7dd1 100644 --- a/pisa/block_processor.py +++ b/pisa/block_processor.py @@ -1,8 +1,10 @@ from common.logger import Logger + +from pisa import LOG_PREFIX from pisa.tools import bitcoin_cli from pisa.utils.auth_proxy import JSONRPCException -logger = Logger("BlockProcessor") +logger = Logger(actor="BlockProcessor", log_name_prefix=LOG_PREFIX) class BlockProcessor: diff --git a/pisa/carrier.py b/pisa/carrier.py index 00602e9..dec4ba6 100644 --- a/pisa/carrier.py +++ b/pisa/carrier.py @@ -1,10 +1,11 @@ +from pisa import LOG_PREFIX from pisa.rpc_errors import * from common.logger import Logger from pisa.tools import bitcoin_cli from pisa.utils.auth_proxy import JSONRPCException from pisa.errors import UNKNOWN_JSON_RPC_EXCEPTION, RPC_TX_REORGED_AFTER_BROADCAST -logger = Logger("Carrier") +logger = Logger(actor="Carrier", log_name_prefix=LOG_PREFIX) # FIXME: This class is not fully covered by unit tests diff --git a/pisa/chain_monitor.py b/pisa/chain_monitor.py index 689a223..22ef377 100644 --- a/pisa/chain_monitor.py +++ b/pisa/chain_monitor.py @@ -2,11 +2,12 @@ import zmq import binascii from threading import Thread, Event, Condition +from pisa import LOG_PREFIX from common.logger import Logger from pisa.conf import FEED_PROTOCOL, FEED_ADDR, FEED_PORT, POLLING_DELTA, BLOCK_WINDOW_SIZE from pisa.block_processor import BlockProcessor -logger = Logger("ChainMonitor") +logger = Logger(actor="ChainMonitor", log_name_prefix=LOG_PREFIX) class ChainMonitor: diff --git a/pisa/cleaner.py b/pisa/cleaner.py index d2e6925..777834c 100644 --- a/pisa/cleaner.py +++ b/pisa/cleaner.py @@ -1,6 +1,8 @@ +from pisa import LOG_PREFIX + from common.logger import Logger -logger = Logger("Cleaner") +logger = Logger(actor="Cleaner", log_name_prefix=LOG_PREFIX) class Cleaner: diff --git a/pisa/db_manager.py b/pisa/db_manager.py index 2c693b6..983a26e 100644 --- a/pisa/db_manager.py +++ b/pisa/db_manager.py @@ -1,9 +1,11 @@ import json import plyvel +from pisa import LOG_PREFIX + from common.logger import Logger -logger = Logger("DBManager") +logger = Logger(actor="DBManager", log_name_prefix=LOG_PREFIX) WATCHER_PREFIX = "w" WATCHER_LAST_BLOCK_KEY = "bw" diff --git a/pisa/inspector.py b/pisa/inspector.py index fcc570e..dfdb0a8 100644 --- a/pisa/inspector.py +++ b/pisa/inspector.py @@ -4,12 +4,12 @@ from binascii import unhexlify from common.constants import LOCATOR_LEN_HEX from common.cryptographer import Cryptographer -from pisa import errors +from pisa import errors, LOG_PREFIX from common.logger import Logger from common.appointment import Appointment from pisa.block_processor import BlockProcessor -logger = Logger("Inspector") +logger = Logger(actor="Inspector", log_name_prefix=LOG_PREFIX) # FIXME: The inspector logs the wrong messages sent form the users. A possible attack surface would be to send a really # long field that, even if not accepted by PISA, would be stored in the logs. This is a possible DoS surface diff --git a/pisa/responder.py b/pisa/responder.py index 5d4ac9d..1198553 100644 --- a/pisa/responder.py +++ b/pisa/responder.py @@ -2,6 +2,7 @@ import json from queue import Queue from threading import Thread +from pisa import LOG_PREFIX from common.logger import Logger from pisa.cleaner import Cleaner from pisa.carrier import Carrier @@ -10,7 +11,7 @@ from pisa.block_processor import BlockProcessor CONFIRMATIONS_BEFORE_RETRY = 6 MIN_CONFIRMATIONS = 6 -logger = Logger("Responder") +logger = Logger(actor="Responder", log_name_prefix=LOG_PREFIX) class TransactionTracker: diff --git a/pisa/watcher.py b/pisa/watcher.py index c0e852a..86a5c40 100644 --- a/pisa/watcher.py +++ b/pisa/watcher.py @@ -8,11 +8,12 @@ from common.tools import compute_locator from common.logger import Logger +from pisa import LOG_PREFIX from pisa.cleaner import Cleaner from pisa.responder import Responder from pisa.block_processor import BlockProcessor -logger = Logger("Watcher") +logger = Logger(actor="Watcher", log_name_prefix=LOG_PREFIX) class Watcher: