From 7a8e2582b69b8c02fa57f5cf656a5abce0de79cc Mon Sep 17 00:00:00 2001
From: Andreas Battaglia <Andreas.Battaglia@cern.ch>
Date: Thu, 3 Jul 2008 17:14:20 +0000
Subject: [PATCH] * Logging system sends e-mail messages of desired severity
level to responsibles * Database logging severity level can now be change run
time
---
Script/{main.py => CastorScript.py} | 59 ++++++++++++++++++-----------
Script/Conf.py | 9 +++++
Script/CopyThread.py | 16 ++++----
Script/Database.py | 28 +++++++++++++-
Script/DeleteThread.py | 16 ++++----
Script/ManagerThread.py | 2 +
6 files changed, 91 insertions(+), 39 deletions(-)
rename Script/{main.py => CastorScript.py} (77%)
diff --git a/Script/main.py b/Script/CastorScript.py
similarity index 77%
rename from Script/main.py
rename to Script/CastorScript.py
index 4b492d1..05f95f9 100755
--- a/Script/main.py
+++ b/Script/CastorScript.py
@@ -12,7 +12,7 @@ from time import sleep
import threading
import sys
import signal
-import logging
+import logging, logging.handlers
##### Global flags for update and exit signals #####
@@ -22,14 +22,6 @@ confFlag = 0
##### Get Configuration #####
conf = Conf.Conf()
-##### Set Logger for main thread #####
-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')
-mainLog = logging.FileHandler(conf.LogDir + '/mainLog.out','w')
-formatter = logging.Formatter('%(asctime)s %(levelname)-8s [%(file)s:%(line)s] %(message)s')
-mainLog.setFormatter(formatter)
-logger = logging.getLogger('main')
-
##### Set event #####
event = threading.Event()
@@ -49,9 +41,29 @@ delete = DeleteThread(conf,event,dbLock,DeleteQueue,ClearQueue)
def main(conf):
- #### Set Logger for main thread #####
+ ##### 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')
+ formatter = logging.Formatter('%(asctime)s %(levelname)-8s [%(file)s:%(line)s] %(message)s')
+
+ ##### Add email handler #####
+ mailFlag = False
+ if len(conf.mailList)!=0:
+ mailFlag = True
+ # if we want sender to be the username, do: import getpass, getpass.getuser()
+ email = logging.handlers.SMTPHandler('localhost',conf.mailSender,conf.mailList,'CastorScript message')
+ email.setFormatter(formatter)
+ mailLevel = conf.mailLevel
+ setLogLevel(mailLevel,email)
+ logging.getLogger('').addHandler(email)
+ # end if
+
+ ##### Set root Logger for main thread #####
+ mainLog = logging.FileHandler(conf.LogDir + '/mainLog.out','w')
+ mainLog.setFormatter(formatter)
+ logger = logging.getLogger('main')
LogLevel = conf.LogLevel
- setLogLevel(LogLevel)
+ setLogLevel(LogLevel,mainLog)
logger.addHandler(mainLog)
##### Set update and exit signal handlers #####
@@ -65,7 +77,7 @@ def main(conf):
db = 0
logInfo = {'file':logger.findCaller()[0],'line':logger.findCaller()[1]}
logger.info('Check for connection to Metadata Database',extra = logInfo)
- db = checkDB(db)
+ db = checkDB(db,logger)
DBTimeout = conf.DBTimeout
##### Start the threads #####
@@ -73,25 +85,28 @@ def main(conf):
copy.start()
delete.start()
logInfo = {'file':logger.findCaller()[0],'line':logger.findCaller()[1]}
- logger.info('Manager,Copy and Delete Threads started',extra = logInfo)
+ logger.info('Manager,Copy and Delete Threads started',extra = logInfo)
##### Every DBTimeout check if connection to Oracle database is still good #####
while not exitFlag:
#signal.pause()
logInfo = {'file':logger.findCaller()[0],'line':logger.findCaller()[1]}
logger.info('Check for connection to Metadata Database',extra = logInfo)
- db = checkDB(db)
+ db = checkDB(db,logger)
event.wait(DBTimeout)
##### If update signal, update configuration #####
if confFlag:
reload(Conf)
conf = Conf.Conf()
DBTimeout = conf.DBTimeout
+ mailLevel = conf.mailLevel
LogLevel = conf.LogLevel
manager.managerConf(conf)
copy.copyConf(conf)
delete.deleteConf(conf)
- setLogLevel(LogLevel)
+ db.dbConf(conf)
+ if mailFlag: setLogLevel(mailLevel,email)
+ setLogLevel(LogLevel,mainLog)
confFlag = 0
logInfo = {'file':logger.findCaller()[0],'line':logger.findCaller()[1]}
logger.info('Configuration updated',extra = logInfo)
@@ -130,7 +145,7 @@ def Exit(signum,frame):
event.set()
-def checkDB(db):
+def checkDB(db,logger):
dbFlag = copy.getDBFlag() and delete.getDBFlag()
if not dbFlag: db = 0
if not db:
@@ -169,13 +184,13 @@ def checkDB(db):
#### Set Log severity level #####
-def setLogLevel(LogLevel):
+def setLogLevel(LogLevel,Log):
level = LogLevel.upper()
- if level == 'DEBUG': mainLog.setLevel(logging.DEBUG)
- elif level == 'INFO': mainLog.setLevel(logging.INFO)
- elif level == 'WARNING': mainLog.setLevel(logging.WARNING)
- elif level == 'ERROR': mainLog.setLevel(logging.ERROR)
- elif level == 'CRITICAL': mainLog.setLevel(logging.CRITICAL)
+ if level == 'DEBUG': Log.setLevel(logging.DEBUG)
+ elif level == 'INFO': Log.setLevel(logging.INFO)
+ elif level == 'WARNING': Log.setLevel(logging.WARNING)
+ elif level == 'ERROR': Log.setLevel(logging.ERROR)
+ elif level == 'CRITICAL': Log.setLevel(logging.CRITICAL)
# end setLogLevel()
diff --git a/Script/Conf.py b/Script/Conf.py
index b992935..4aebde9 100755
--- a/Script/Conf.py
+++ b/Script/Conf.py
@@ -14,6 +14,15 @@ class Conf:
# Log severity level (DEBUG,INFO,WARNING,ERROR,CRITICAL)
self.LogLevel = 'debug'
+ # Email list which will receive error messages (list of strings)
+ self.mailList = []
+
+ # Email Log severity level (DEBUG,INFO,WARNING,ERROR,CRITICAL)
+ self.mailLevel = 'debug'
+
+ # Email sender
+ self.mailSender = 'andreas.battaglia@cern.ch'
+
########## METADATA DATABASE ##########
diff --git a/Script/CopyThread.py b/Script/CopyThread.py
index 0265316..3bec6d8 100755
--- a/Script/CopyThread.py
+++ b/Script/CopyThread.py
@@ -50,15 +50,15 @@ class CopyThread(threading.Thread):
##### Set Logger Level #####
self.setLogLevel()
-
+
while(1):
##### When time to exit, do not take new files to be copied, but finish ongoing copy processes #####
if (self.exitFlag and len(self.CopyList)==0): break
self.logInfo = {'file':self.logger.findCaller()[0],'line':self.logger.findCaller()[1]}
- self.logger.debug('Size of CopyQueue: ' + str(self.CopyQueue.qsize()) + '\n\t\t\t\t\t\t Size of DeleteQueue: '
- + str(self.DeleteQueue.qsize()) + '\n\t\t\t\t\t\t Size of ClearQueue: ' + str(self.ClearQueue.qsize()),extra = self.logInfo)
+ self.logger.debug('Size of CopyQueue: ' + str(self.CopyQueue.qsize()) + ', Size of DeleteQueue: '
+ + str(self.DeleteQueue.qsize()) + ', Size of ClearQueue: ' + str(self.ClearQueue.qsize()),extra = self.logInfo)
##### Launch n = maxCopy of parallel rfcp processes #####
self.logInfo = {'file':self.logger.findCaller()[0],'line':self.logger.findCaller()[1]}
@@ -124,7 +124,8 @@ class CopyThread(threading.Thread):
self.event.wait(self.CopyTimeout)
# end while
-
+ self.logInfo = {'file':self.logger.findCaller()[0],'line':self.logger.findCaller()[1]}
+ self.logger.info('CopyThread exited',extra = self.logInfo)
# end def run()
@@ -176,10 +177,12 @@ class CopyThread(threading.Thread):
#SFO_filesize = os.path.getsize(DataFile)
nsls = Popen(['nsls', '-l',CastorFile], stdout = PIPE, stderr = STDOUT, env= castorEnv)
+ w = nsls.wait()
+ nslsOut = nsls.stdout.read()
Castor_filesize = 0
- if nsls.wait()==0: Castor_filesize = long(filter(lambda x: x!='',nsls.stdout.read().split(' '))[4])
+ if w==0: Castor_filesize = long(filter(lambda x: x!='',nslsOut.split(' '))[4])
self.logInfo = {'file':self.logger.findCaller()[0],'line':self.logger.findCaller()[1]}
- self.logger.debug(nsls.stdout.read(),extra = self.logInfo)
+ self.logger.debug(nslsOut,extra = self.logInfo)
# end if
if SFO_filesize == Castor_filesize:
@@ -196,7 +199,6 @@ class CopyThread(threading.Thread):
self.logger.info('Update Metadata database',extra = self.logInfo)
self.dbLock.acquire()
self.dbFlag = self.db.Transfer(DataFile,CastorFile)
- ## PASS THE LOGGER
self.dbLock.release()
else:
self.logInfo = {'file':self.logger.findCaller()[0],'line':self.logger.findCaller()[1]}
diff --git a/Script/Database.py b/Script/Database.py
index cf4ce51..2ef64a4 100755
--- a/Script/Database.py
+++ b/Script/Database.py
@@ -77,7 +77,7 @@ class Database:
try:
self.filedeletion(sfofile)
return True
- except:
+ except (InterfaceError,DatabaseError):
self.logInfo = {'file':self.logger.findCaller()[0],'line':self.logger.findCaller()[1]}
self.logger.error(str(sys.exc_info()),extra = self.logInfo)
self.logger.error(str(sys.exc_type),extra = self.logInfo)
@@ -85,6 +85,14 @@ class Database:
self.logger.error(str(self.db.lastOp()),extra = self.logInfo)
self.logger.error(str(self.db.getLastKeys()),extra = self.logInfo)
return False
+ except:
+ self.logInfo = {'file':self.logger.findCaller()[0],'line':self.logger.findCaller()[1]}
+ self.logger.error(str(sys.exc_info()),extra = self.logInfo)
+ self.logger.error(str(sys.exc_type),extra = self.logInfo)
+ self.logger.error(str(sys.exc_value),extra = self.logInfo)
+ self.logger.error(str(self.db.lastOp()),extra = self.logInfo)
+ self.logger.error(str(self.db.getLastKeys()),extra = self.logInfo)
+ return True
def Transfer(self,sfofile,castorfile):
@@ -101,7 +109,7 @@ class Database:
return True
- except:
+ except (InterfaceError,DatabaseError):
self.logInfo = {'file':self.logger.findCaller()[0],'line':self.logger.findCaller()[1]}
self.logger.error(str(sys.exc_info()),extra = self.logInfo)
self.logger.error(str(sys.exc_type),extra = self.logInfo)
@@ -109,6 +117,15 @@ class Database:
self.logger.error(str(self.db.lastOp()),extra = self.logInfo)
self.logger.error(str(self.db.getLastKeys()),extra = self.logInfo)
return False
+
+ except:
+ self.logInfo = {'file':self.logger.findCaller()[0],'line':self.logger.findCaller()[1]}
+ self.logger.error(str(sys.exc_info()),extra = self.logInfo)
+ self.logger.error(str(sys.exc_type),extra = self.logInfo)
+ self.logger.error(str(sys.exc_value),extra = self.logInfo)
+ self.logger.error(str(self.db.lastOp()),extra = self.logInfo)
+ self.logger.error(str(self.db.getLastKeys()),extra = self.logInfo)
+ return True
def filedeletion(self,sfofile):
@@ -248,3 +265,10 @@ class Database:
elif level == 'WARNING': self.dbLog.setLevel(logging.WARNING)
elif level == 'ERROR': self.dbLog.setLevel(logging.ERROR)
elif level == 'CRITICAL': self.dbLog.setLevel(logging.CRITICAL)
+
+ def dbConf(self,conf):
+ self.logInfo = {'file':self.logger.findCaller()[0],'line':self.logger.findCaller()[1]}
+ self.logger.info('Update log level',extra = self.logInfo)
+ self.conf = conf
+ self.LogLevel = self.conf.LogLevel
+ self.setLogLevel(self.LogLevel)
diff --git a/Script/DeleteThread.py b/Script/DeleteThread.py
index f5ca5d4..ca3cbdc 100755
--- a/Script/DeleteThread.py
+++ b/Script/DeleteThread.py
@@ -113,7 +113,6 @@ class DeleteThread(threading.Thread):
self.logger.info('Update Metadata database',extra = self.logInfo)
self.dbLock.acquire()
self.dbFlag = self.db.Deletion(deletefile[0])
- ## PASS THE LOGGER
self.dbLock.release()
else:
self.logInfo = {'file':self.logger.findCaller()[0],'line':self.logger.findCaller()[1]}
@@ -134,7 +133,7 @@ class DeleteThread(threading.Thread):
# block until room is available in the queue ?????
self.event.wait(self.DeleteTimeout)
self.logInfo = {'file':self.logger.findCaller()[0],'line':self.logger.findCaller()[1]}
- self.logger.warning('File ' + deletefile[0] + ' too recent: delete it later',extra = self.logInfo)
+ self.logger.info('File ' + deletefile[0] + ' too recent: delete it later',extra = self.logInfo)
continue
##### Check the SFO lock, if required #####
@@ -185,7 +184,6 @@ class DeleteThread(threading.Thread):
self.logInfo = {'file':self.logger.findCaller()[0],'line':self.logger.findCaller()[1]}
self.logger.info('Update Metadata database',extra = self.logInfo)
self.dbFlag = self.db.Deletion(deletefile[0])
- ## PASS THE LOGGER
self.dbLock.release()
else:
self.logInfo = {'file':self.logger.findCaller()[0],'line':self.logger.findCaller()[1]}
@@ -217,12 +215,13 @@ class DeleteThread(threading.Thread):
self.logInfo = {'file':self.logger.findCaller()[0],'line':self.logger.findCaller()[1]}
self.logger.debug('Time to check if file has been migrated',extra = self.logInfo)
Castor_file = copyDir + deletefile[0][deletefile[0].rindex('/'):]
- nsls = Popen(['nsls', '-l',Castor_file], stdout = PIPE, stderr = self.logFile, env= castorEnv)
+ nsls = Popen(['nsls', '-l',Castor_file], stdout = PIPE, stderr = STDOUT, env= castorEnv)
nsls.wait()
+ nslsOut = nsls.stdout.read()
self.logInfo = {'file':self.logger.findCaller()[0],'line':self.logger.findCaller()[1]}
- self.logger.debug(nsls.stdout.read(),extra = self.logInfo)
- isMig = 'm' in nsls.communicate()[0].split(' ')[0]
- #isMig = nsls.communicate()[0].split(' ')[0].startswith('m')
+ self.logger.debug(nslsOut,extra = self.logInfo)
+ isMig = 'm' in nslsOut.split(' ')[0]
+ #isMig = nslsOut.split(' ')[0].startswith('m')
if isMig:
@@ -241,7 +240,6 @@ class DeleteThread(threading.Thread):
self.logInfo = {'file':self.logger.findCaller()[0],'line':self.logger.findCaller()[1]}
self.logger.info('Update Metadata database',extra = self.logInfo)
self.dbFlag = self.db.Deletion(deletefile[0])
- ## PASS THE LOGGER
self.dbLock.release()
else:
self.logInfo = {'file':self.logger.findCaller()[0],'line':self.logger.findCaller()[1]}
@@ -263,6 +261,8 @@ class DeleteThread(threading.Thread):
self.event.wait(self.DeleteTimeout)
# end while
+ self.logInfo = {'file':self.logger.findCaller()[0],'line':self.logger.findCaller()[1]}
+ self.logger.info('DeleteThread exited',extra = self.logInfo)
# end def run()
diff --git a/Script/ManagerThread.py b/Script/ManagerThread.py
index 830cbe0..a93e80c 100755
--- a/Script/ManagerThread.py
+++ b/Script/ManagerThread.py
@@ -179,6 +179,8 @@ class ManagerThread(threading.Thread):
self.updateDates()
# end while
+ self.logInfo = {'file':self.logger.findCaller()[0],'line':self.logger.findCaller()[1]}
+ self.logger.info('ManagerThread exited',extra = self.logInfo)
# end def run()
--
GitLab