diff --git a/Script/CastorScript.py b/Script/CastorScript.py index 6bcea59ecdc33a2c0796f1d9bb5fc9bee9586ebe..e1c6dd843906ba7b8e8f657ad953688a3fa9f078 100644 --- a/Script/CastorScript.py +++ b/Script/CastorScript.py @@ -8,22 +8,17 @@ import sys import os import datetime import signal -import logging -import logging.handlers import importlib #Imports of script -from cs.Tools.utils import set_log_level, formatter, enable_file_logging from cs.Threads.ManagerThread import ManagerThread from cs.Threads.CopyThread import CopyThread from cs.Threads.DeleteThread import DeleteThread from cs.Threads.CheckThread import CheckThread from cs.Threads.DdmMonitoringThread import DdmMonitoringThread -import cs.Tools.Conf as Conf +import cs.Tools.ConfigParser as ConfigParser import cs.Tools.Constants as Constants - -#From cm_setup Script -import mailinglogger +import cs.Tools.LogConfig as LogConfig ##### Global flag for exit ##### exitFlag = 0 @@ -31,7 +26,7 @@ exitFlag = 0 ##### Get Configuration ##### if len(sys.argv) >= 2: try: - config = Conf.Conf(sys.argv[1]) + config = ConfigParser.ConfigHolder(sys.argv[1]) except Exception as ex: print 'Configuration file parsing failed because:', ex sys.exit(1) @@ -44,14 +39,6 @@ else: ### writeable os.umask(0002) -##### Set ERS Variables ##### -os.environ["TDAQ_PARTITION"] = config.partition -os.environ["TDAQ_APPLICATION_NAME"] = "CastorScript" -os.environ["TDAQ_ERS_ERROR"] = config.ers_error -os.environ["TDAQ_ERS_INFO"] = config.ers_info -os.environ["TDAQ_ERS_WARNING"] = config.ers_warning -os.environ["TDAQ_ERS_DEBUG"] = config.ers_debug - ##### Set event ##### event = threading.Event() @@ -79,52 +66,29 @@ if config.DdmMonitoringEnabled: def main(conf): - ##### Set root Logger ##### - logging.basicConfig(level=logging.DEBUG, - format='%(asctime)s %(levelname)-8s %(message)s', - datefmt='%a, %d %b %Y %H:%M:%S', - filename= '/dev/null',filemode='w') + # Root should only log to mail or ERS, but initializes root logger if no none set + LogConfig.disable_root_logging_to_stdout() - ##### Add email handler ##### + ##### enable mail logging ##### if conf.mailList: - # by default max email sending rate is 10 per hour - mail_handler = mailinglogger.MailingLogger(conf.mailSender, - conf.mailList, subject='CastorScript message', - mailhost='localhost') - - mail_handler.setFormatter(formatter) - set_log_level(conf.mailLevel, mail_handler) - logging.getLogger('').addHandler(mail_handler) + LogConfig.enable_mail_logging(conf) # end if - # get logger to files, (Will also log to ERS, when enabled) - logger = enable_file_logging("main","mainLog.out", conf.LogDir, conf.LogLevel) + # Get main logger, (Will also log to ERS and mail, when enabled) + logger = LogConfig.enable_file_logging("main","mainLog.out", conf.LogDir, conf.LogLevel) ##### Setup ERS ##### if conf.ERSenabled: - try: - import ers - # Instantiating an IPCPartition has some side effect: initializing IPC Core stuff - from ispy import IPCPartition #pylint: disable=no-name-in-module - IPCPartition = IPCPartition() - ers_handler = ers.LoggingHandler() - set_log_level(conf.ERSLogLevel, ers_handler) - logging.getLogger().addHandler(ers_handler) - logger.info("CastorScript is now logging to partition '%s'", - conf.partition) - except Exception as ex: - logger.error("CastorScript could not create ERS, reason is '%s'", - str(ex)) - - ##### Start looking for the partition ##### - if conf.ERSenabled: - check = CheckThread(conf, event, ers_handler) + ers_handler = LogConfig.enable_ers_logging(config) + if ers_handler is not None: + ##### Start looking for the partition ##### + check = CheckThread(conf, event, ers_handler) ##### Create db file logger ##### - dblogger = enable_file_logging("Database","DatabaseLog.out",conf.LogDir,conf.LogLevel) + dblogger = LogConfig.enable_file_logging("Database","DatabaseLog.out",conf.LogDir,conf.LogLevel) #### Extend the PYTHON_PATH #### @@ -201,7 +165,7 @@ def main(conf): copy.start() if delete is not None: delete.start() - if conf.ERSenabled: + if conf.ERSenabled and check is not None: check.start() logger.info('Manager, Copy, Delete and Check Threads started') if conf.DdmMonitoringEnabled: diff --git a/Script/TestSuite_UnitTests.py b/Script/TestSuite_UnitTests.py index b8e2b5e50433dc4718ac15cfd2a37a3824f9d544..64c6a824326fb6138de67b1a2b82a6ad1d02d428 100644 --- a/Script/TestSuite_UnitTests.py +++ b/Script/TestSuite_UnitTests.py @@ -1,10 +1,14 @@ import unittest from UnitTests import BaseFileNameParser_Test +from UnitTests import LogConfig_Test +from UnitTests import ConfigParser_Test suite = unittest.TestSuite() loader = unittest.TestLoader() suite.addTests(loader.loadTestsFromModule(BaseFileNameParser_Test)) +suite.addTests(loader.loadTestsFromModule(LogConfig_Test)) +suite.addTests(loader.loadTestsFromModule(ConfigParser_Test)) runner = unittest.TextTestRunner(verbosity=3) print("\n==============================================================") diff --git a/Script/UnitTests/BaseFileNameParser_Test.py b/Script/UnitTests/BaseFileNameParser_Test.py index 5db26e92d358e0ed9ab277f3c72ca9bf27c0fe77..19e9a971ae7da2416581854cccb715c4a9c47c73 100644 --- a/Script/UnitTests/BaseFileNameParser_Test.py +++ b/Script/UnitTests/BaseFileNameParser_Test.py @@ -3,7 +3,7 @@ import unittest if __name__ == '__main__': import sys from os.path import dirname, abspath, join - # add /../../CastorScript/Script to path so imports keeps working + # add /../CastorScript/Script to path so imports keeps working SCRIPT_DIR = abspath(join(dirname(__file__), '..')) sys.path.append(SCRIPT_DIR) diff --git a/Script/UnitTests/ConfigParser_Test.py b/Script/UnitTests/ConfigParser_Test.py new file mode 100644 index 0000000000000000000000000000000000000000..7f4fea4635beffd3096d1cb897f027369496b202 --- /dev/null +++ b/Script/UnitTests/ConfigParser_Test.py @@ -0,0 +1,29 @@ +import unittest +#import mock +import os + +if __name__ == '__main__': + import sys + from os.path import dirname, abspath, join + # add CastorScript/Script to path so imports keeps working + SCRIPT_DIR = abspath(join(dirname(__file__), '..')) + sys.path.append(SCRIPT_DIR) + +from cs.Tools.ConfigParser import ConfigHolder + +class TestConfigHolder(unittest.TestCase): + + @classmethod + def setUpClass(self): + self.thisDir = os.path.dirname(__file__) + self.templateName = "template.cfg" + self.cfgTemplate = os.path.abspath(os.path.join(self.thisDir, "../../Configs/" + self.templateName)) + + def test_it_should_save_config_file_name(self): + cfg = ConfigHolder(self.cfgTemplate) + self.assertEquals(self.templateName, cfg.FileName) + + +if __name__ == '__main__': + unittest.main() + diff --git a/Script/UnitTests/LogConfig_Test.py b/Script/UnitTests/LogConfig_Test.py new file mode 100644 index 0000000000000000000000000000000000000000..69a7db4b93db4080b06f08ea9e6caa6667198791 --- /dev/null +++ b/Script/UnitTests/LogConfig_Test.py @@ -0,0 +1,125 @@ +import unittest +import mock +from mock import patch, call, ANY +import socket +import os + +if __name__ == '__main__': + import sys + from os.path import dirname, abspath, join + ## add CastorScript/Script to path so imports keeps working + SCRIPT_DIR = abspath(join(dirname(__file__), '..')) + sys.path.append(SCRIPT_DIR) + +import cs.Tools.LogConfig as LogConfig +from cs.Tools.ConfigParser import ConfigHolder + +# As a developer, i would like to add a +# new LogBook for my module "myModule" so that I can log messages + +# As developers, we would like to configure the build-in logging feature of python +# So that it works with the ERS / MTS system at the ATLAS experiment + +class TestLogConfig(unittest.TestCase): + + def setUp(self): + # We define what we want the TDAQ_APPLICATION_NAME should be + # We want it to be unique to the host and configuration filename + self.app_name = "CastorScript-{}-forSpecialUseCase".format(socket.gethostname()) + self.simple_app_name = "CastorScript-{}".format(socket.gethostname()) + ## the ConfigHolder object is mocked. We expect it to be properly configured. + self.mock_cfg = mock.create_autospec(ConfigHolder) + + ## ConfigHolder will parse the filename of the config, to a FileName property. + # We specify an ERS-specific configuration in a file and give it a name. + self.mock_cfg.configure_mock(FileName="Conf-forSpecialUseCase.cfg", + partition="initial", + ers_error="mts", + ers_info="mts", + ers_warning="mts", + ers_debug="mts", + ERSLogLevel="debug", + mailSender="anyone@cern.ch", + mailList=["noone@dkcern.ch"], + mailLevel="debug") + +class TestMakeTDAQAppName(TestLogConfig): + + def test_it_should_create_config_specific_name(self): + + # We see that "myLog" has the defined name. + self.assertEqual(self.app_name, LogConfig.make_tdaq_app_name(self.mock_cfg)) + + def test_it_should_create_simple_name(self): + self.mock_cfg.configure_mock(FileName="Conf.cfg") + # We see that "myLog" has the defined name. + self.assertEqual(self.simple_app_name, LogConfig.make_tdaq_app_name(self.mock_cfg)) + + self.mock_cfg.configure_mock(FileName="Config.cfg") + self.assertEqual(self.simple_app_name, LogConfig.make_tdaq_app_name(self.mock_cfg)) + +class TestSetEnvironment(TestLogConfig): + + @patch.dict('os.environ', {'TDAQ_PARTITION': 'NotSet', + 'TDAQ_APPLICATION_NAME':"NotSet", + 'TDAQ_ERS_ERROR': "NotSet", + 'TDAQ_ERS_INFO':'NotSet', + 'TDAQ_ERS_WARNING':'NotSet', + 'TDAQ_ERS_DEBUG':'NotSet'}) + def test_env_should_be_set_as_configured(self): + + ## For the test, we need to create instance again but in the patched context, + ## for the os.environ patch to work + # We create the LogBook with a ConfigHolder object. + LogConfig.set_environment(self.mock_cfg, self.app_name) + + ## + def wasNotSetError(param, expected, actual): + return "%s was not set to: %s but: %s" % ( param, expected, actual ) + + # We check the environment variables. + # We see they have been set, according to our configuration. + self.assertEqual(self.app_name, os.environ['TDAQ_APPLICATION_NAME'], msg=wasNotSetError("TDAQ_APPLICATION_NAME", self.app_name, os.environ['TDAQ_APPLICATION_NAME'])) + + self.assertEqual("initial", os.environ['TDAQ_PARTITION'], msg=wasNotSetError("TDAQ_PARTITION", "initial", os.environ['TDAQ_PARTITION'])) + + self.assertEqual("mts", os.environ['TDAQ_ERS_ERROR'],msg=wasNotSetError("TDAQ_ERS_ERROR", "mts", os.environ['TDAQ_ERS_ERROR'])) + + self.assertEqual("mts", os.environ['TDAQ_ERS_INFO'],msg=wasNotSetError("TDAQ_ERS_INFO", "mts", os.environ['TDAQ_ERS_INFO'])) + + self.assertEqual("mts", os.environ['TDAQ_ERS_WARNING'],msg=wasNotSetError("TDAQ_ERS_WARNING", "mts", os.environ['TDAQ_ERS_WARNING'])) + + self.assertEqual("mts", os.environ['TDAQ_ERS_DEBUG'],msg=wasNotSetError("TDAQ_ERS_DEBUG", "mts", os.environ['TDAQ_ERS_DEBUG'])) + + +class TestEnableERSLogging(TestLogConfig): + + @patch('logging.getLogger') + def test_it_should_request_root_logger(self, mock_getLogger): + + LogConfig.enable_ers_logging(self.mock_cfg) + + # We see that the the root logger gets requested + CALLS = [call(), ANY] + mock_getLogger.assert_has_calls(CALLS, any_order=True) + + @patch('ers.LoggingHandler') + @patch('logging.Logger.addHandler') + def test_it_should_add_an_ERS_handler(self, mock_addHandler, mock_ers_logginghandler): + LogConfig.enable_ers_logging(self.mock_cfg) + mock_addHandler.assert_called_with(mock_ers_logginghandler()) + +class TestEnableMailLogging(TestLogConfig): + + @patch('logging.getLogger') + def test_it_should_request_root_logger(self, mock_getLogger): + + LogConfig.enable_mail_logging(self.mock_cfg) + + # We see that the the root logger gets requested + CALLS = [call(),] + mock_getLogger.assert_has_calls(CALLS, any_order=True) + +if __name__ == "__main__": + unittest.main() + diff --git a/Script/cs/Threads/CheckThread.py b/Script/cs/Threads/CheckThread.py index 30b396c1bd4bb681e8a1017cee61657f0fe34e70..7befd090af9dc0fe438fbdff60a064d6fb6a46fb 100644 --- a/Script/cs/Threads/CheckThread.py +++ b/Script/cs/Threads/CheckThread.py @@ -3,7 +3,8 @@ ##### Thread checking constantly the state of the partition ##### import threading import logging -from cs.Tools.utils import thread_id_string, enable_file_logging +from cs.Tools.utils import thread_id_string +from cs.Tools.LogConfig import enable_file_logging class CheckThread(threading.Thread): diff --git a/Script/cs/Threads/CopyThread.py b/Script/cs/Threads/CopyThread.py index 26c12bd1cf617ec07cb328e07b2babb83a5d0fbd..57a1d4d6f2aecff25b053e9c46d8e4ba248382b1 100644 --- a/Script/cs/Threads/CopyThread.py +++ b/Script/cs/Threads/CopyThread.py @@ -7,7 +7,8 @@ import Queue import uuid import errno import cs.Tools.Constants as Constants -from cs.Tools.utils import thread_id_string,adler32,get_bw, enable_file_logging +from cs.Tools.utils import thread_id_string,adler32,get_bw +from cs.Tools.LogConfig import enable_file_logging class CopyThread(threading.Thread): diff --git a/Script/cs/Threads/DdmMonitoringThread.py b/Script/cs/Threads/DdmMonitoringThread.py index 6217e5c1b807c1de5f8e2d1918b196a3da71083c..78e3c5fe0565fc09ec5dd955e35fd6990076f932 100644 --- a/Script/cs/Threads/DdmMonitoringThread.py +++ b/Script/cs/Threads/DdmMonitoringThread.py @@ -5,7 +5,8 @@ import json import Queue import time -from cs.Tools.utils import thread_id_string, enable_file_logging +from cs.Tools.utils import thread_id_string +from cs.Tools.LogConfig import enable_file_logging class DdmMonitoringThread(threading.Thread): diff --git a/Script/cs/Threads/DeleteThread.py b/Script/cs/Threads/DeleteThread.py index 8f4acd8e51d40639e2c34fa06b788cf04f089696..a488b69ca8816d73dc9fd28d3a50e745ff81740c 100644 --- a/Script/cs/Threads/DeleteThread.py +++ b/Script/cs/Threads/DeleteThread.py @@ -8,7 +8,8 @@ from time import time import operator from itertools import imap, chain import cs.Tools.Constants as Constants -from cs.Tools.utils import thread_id_string, enable_file_logging +from cs.Tools.utils import thread_id_string +from cs.Tools.LogConfig import enable_file_logging class DeleteThread(threading.Thread): diff --git a/Script/cs/Threads/ManagerThread.py b/Script/cs/Threads/ManagerThread.py index df3893341c56d51a5b442f44e088ff0f2061a9c2..d149afc887b934af8f65bff340e0d2f082dee426 100644 --- a/Script/cs/Threads/ManagerThread.py +++ b/Script/cs/Threads/ManagerThread.py @@ -13,7 +13,8 @@ import math import cs.Tools.Constants as Constants import errno import re -from cs.Tools.utils import thread_id_string, enable_file_logging +from cs.Tools.utils import thread_id_string +from cs.Tools.LogConfig import enable_file_logging from itertools import chain class ManagerThread(threading.Thread): diff --git a/Script/cs/Tools/Conf.py b/Script/cs/Tools/ConfigParser.py similarity index 99% rename from Script/cs/Tools/Conf.py rename to Script/cs/Tools/ConfigParser.py index 0e7fd2716ce2cd9648b94802c7cabc9fa3330aac..59a285ae48476085d878a1521f818a1f79b50480 100644 --- a/Script/cs/Tools/Conf.py +++ b/Script/cs/Tools/ConfigParser.py @@ -3,6 +3,7 @@ from cs.Tools.Libraries.config import Config import importlib from collections import namedtuple import re +import os class REWrap(object): ### @@ -40,11 +41,13 @@ class DrivenPool(namedtuple('DrivenPool', ['targetdir','stagehost','pool','proje REWrap(application), REWrap(directory)) -class Conf: +class ConfigHolder: def __init__(self, cfgfile): - cfg = Config(file(cfgfile)) + self.FileName = os.path.split(cfgfile)[1] + + cfg = Config(cfgfile) ########## Common parameters ########## diff --git a/Script/cs/Tools/LogConfig.py b/Script/cs/Tools/LogConfig.py new file mode 100644 index 0000000000000000000000000000000000000000..52c7f357747838f5a4047013020b9a584752198c --- /dev/null +++ b/Script/cs/Tools/LogConfig.py @@ -0,0 +1,100 @@ +import socket +import os +import logging +#From cm_setup Script +import mailinglogger + +def enable_ers_logging(config): + + tdaq_app_name = make_tdaq_app_name(config) + + set_environment(config, tdaq_app_name) + + try: + import ers + # Instantiating an IPCPartition has some side effect: initializing IPC Core stuff + from ispy import IPCPartition #pylint: disable=no-name-in-module + IPCPartition = IPCPartition() + ers_handler = ers.LoggingHandler() + set_log_level(config.ERSLogLevel, ers_handler) + logging.getLogger().addHandler(ers_handler) + logging.getLogger("main").info("CastorScript is now logging to partition '%s'", + config.partition) + except Exception as ex: + logging.getLogger("main").error("CastorScript could not create ERS, reason is '%s'", str(ex)) + + if ers_handler is not None: + return ers_handler + +def make_tdaq_app_name(config): + hostname = socket.gethostname() + cleanFileName = config.FileName.replace("Config", "",1).replace("Conf","",1).replace(".cfg","",1).replace("-","").replace("_","") + if len(cleanFileName) is 0: + return "CastorScript-{}".format(hostname) + return "CastorScript-{}-{}".format(hostname, cleanFileName) + +def set_environment(config, tdaq_app_name): + ##### Set ERS Variables ##### + os.environ["TDAQ_APPLICATION_NAME"] = tdaq_app_name + + os.environ["TDAQ_PARTITION"] = config.partition + os.environ["TDAQ_ERS_ERROR"] = config.ers_error + os.environ["TDAQ_ERS_INFO"] = config.ers_info + os.environ["TDAQ_ERS_WARNING"] = config.ers_warning + os.environ["TDAQ_ERS_DEBUG"] = config.ers_debug + + +def disable_root_logging_to_stdout(): + ##### Set root Logging to file: NULL ##### + logging.basicConfig(level=logging.DEBUG, + format='%(asctime)s %(levelname)-8s %(message)s', + datefmt='%a, %d %b %Y %H:%M:%S', + filename= '/dev/null',filemode='w') + +def enable_mail_logging(config): + # by default max email sending rate is 10 per hour + mail_handler = mailinglogger.MailingLogger(config.mailSender, + config.mailList, subject='CastorScript message', + mailhost='localhost') + + mail_handler.setFormatter(formatter) + set_log_level(config.mailLevel, mail_handler) + logging.getLogger().addHandler(mail_handler) + + +#### Set Log severity level ##### +def set_log_level(level, logger): + + level = level.upper() + + levelmap = {'DEBUG':logging.DEBUG, + 'INFO':logging.INFO, + 'WARNING':logging.WARNING, + 'ERROR':logging.ERROR, + 'CRITICAL':logging.CRITICAL} + + logger.setLevel(levelmap[level]) + +formatter = logging.Formatter('%(asctime)s %(levelname)-8s [%(filename)s:%(lineno)d] %(message)s') + +def enable_file_logging(loggerName, fileName, filePath, logLevel): + """Enables file logging to a file with fileName at filePath. + It will make a logger with loggerName as identifier, at the specified loglevel, + + It will afterwards be retrievable with the use of logging.getLogger(loggerName), from any thread as long as it is in the same process. + + Filename should formatted like this: name + Log.out + + returns a reference to a properly configured logger""" + + ##### Setup FileHandler for Logger ##### + logFilePath = os.path.join(str(filePath),fileName) + fileHandler = logging.FileHandler(logFilePath,'w') + fileHandler.setFormatter(formatter) + + ##### Set LogLevel for filehandler ##### + set_log_level(logLevel, fileHandler) + logger = logging.getLogger(loggerName) + logger.addHandler(fileHandler) + + return logger \ No newline at end of file diff --git a/Script/cs/Tools/utils.py b/Script/cs/Tools/utils.py index baf304eda6df0580a811c7a1856694a00df4eef8..d74f4ad9b9831ff38d38578de9badd7a047126fe 100644 --- a/Script/cs/Tools/utils.py +++ b/Script/cs/Tools/utils.py @@ -1,48 +1,8 @@ -import logging import zlib import ctypes import time import datetime -import os - -#### Set Log severity level ##### -def set_log_level(level, logger): - - level = level.upper() - - levelmap = {'DEBUG':logging.DEBUG, - 'INFO':logging.INFO, - 'WARNING':logging.WARNING, - 'ERROR':logging.ERROR, - 'CRITICAL':logging.CRITICAL} - - logger.setLevel(levelmap[level]) - -formatter = logging.Formatter('%(asctime)s %(levelname)-8s [%(filename)s:%(lineno)d] %(message)s') - -def enable_file_logging(loggerName, fileName, filePath, logLevel): - """Enables file logging to a file with fileName at filePath. - It will make a logger with loggerName as identifier, at the specified loglevel, - - It will afterwards be retrievable with the use of logging.getLogger(loggerName), from any thread as long as it is in the same process. - - Filename should formatted like this: name + Log.out - - returns a reference to a properly configured logger""" - - ##### Setup FileHandler for Logger ##### - logFilePath = os.path.join(str(filePath),fileName) - fileHandler = logging.FileHandler(logFilePath,'w') - fileHandler.setFormatter(formatter) - - ##### Set LogLevel for filehandler ##### - set_log_level(logLevel, fileHandler) - logger = logging.getLogger(loggerName) - logger.addHandler(fileHandler) - - return logger - def gettid(): #This is linux specific ... diff --git a/run_pylint.sh b/run_pylint.sh index 3d93fc577eaefddeea503c6d3a23b178383e2d45..4a6b44c0ec6948680f7587bb16511751305af143 100755 --- a/run_pylint.sh +++ b/run_pylint.sh @@ -5,4 +5,7 @@ then source /afs/cern.ch/atlas/project/tdaq/cmake/cmake_tdaq/bin/cm_setup.sh nightly fi -/cvmfs/sft.cern.ch/lcg/views/$TDAQ_LCG_RELEASE/$CMTCONFIG/bin/pylint $(find Script/ -name '*.py' -a -not -name config.py) \ No newline at end of file +/cvmfs/sft.cern.ch/lcg/views/$TDAQ_LCG_RELEASE/$CMTCONFIG/bin/pylint $(find Script/ -name '*.py' -a -not -name config.py) + +#if nightly is down, you can just use the locally installed pylint (imports will produce errors) +#pylint $(find Script/ -name '*.py' -a -not -name config.py) \ No newline at end of file