295 changes: 205 additions & 90 deletions mythtv/bindings/python/MythTV/logging.py
Original file line number Diff line number Diff line change
@@ -1,15 +1,28 @@
# -*- coding: utf-8 -*-
"""Provides managed logging."""

from static import LOGLEVEL
from static import LOGLEVEL, LOGMASK, LOGFACILITY
from exceptions import MythError

from sys import version_info, stdout
import os
import syslog

from sys import version_info, stdout, argv
from datetime import datetime
from thread import allocate_lock
from cStringIO import StringIO
from traceback import format_exc

class MythLog( LOGLEVEL ):
def _donothing(*args, **kwargs):
pass

class DummyLogger( LOGLEVEL, LOGMASK, LOGFACILITY ):
def __init__(self, module=None, db=None): pass
def logTB(self, mask): pass
def log(self, mask, level, message, detail=None): pass
def __call__(self, mask, level, message, detail=None): pass

class MythLog( LOGLEVEL, LOGMASK, LOGFACILITY ):
"""
MythLog(module='pythonbindings', lstr=None, lbit=None, \
db=None) -> logging object
Expand All @@ -24,10 +37,6 @@ class MythLog( LOGLEVEL ):
The logging object is callable, and implements the MythLog.log() method.
"""

LEVEL = LOGLEVEL.IMPORTANT|LOGLEVEL.GENERAL
LOGFILE = stdout
_lock = allocate_lock()

helptext = """Verbose debug levels.
Accepts any combination (separated by comma) of:
Expand Down Expand Up @@ -78,136 +87,242 @@ class MythLog( LOGLEVEL ):
Some debug levels may not apply to this program.
"""

@classmethod
def _initlogger(cls):
cls._initlogger = classmethod(_donothing)
cls._MASK = LOGMASK.GENERAL
cls._LEVEL = LOGLEVEL.INFO
cls._LOGFILE = stdout
cls._logwrite = cls._logfile
cls._QUIET = 0
cls._DBLOG = True
cls._SYSLOG = None
cls._lock = allocate_lock()
args = iter(argv)
args.next()
try:
while True:
arg = args.next()
if arg == '--quiet':
cls._QUIET += 1
elif arg == '--nodblog':
cls._DBLOG = False
elif arg == '--loglevel':
cls._setlevel(args.next())
elif arg == '--verbose':
cls._setmask(args.next())
elif arg == '--logfile':
cls._setfile(args.next())
elif arg == '--logpath':
cls._setfile(os.path.join(args.next(), "{0}.{1}.{2}.log"\
.format(argv[0].rsplit('/', 1)[1],
datetime.now().strftime('%Y%m%d%H%M%S'),
os.getpid())))
elif arg == '--syslog':
cls._setsyslog(args.next())
elif arg == '--':
break

except StopIteration:
pass

def __repr__(self):
return "<%s '%s','%s' at %s>" % \
(str(self.__class__).split("'")[1].split(".")[-1],
self.module, bin(self.LEVEL), hex(id(self)))
self.module, bin(self._MASK), hex(id(self)))

def __init__(self, module='pythonbindings', lstr=None, lbit=None, db=None):
if lstr or lbit:
self._setlevel(lstr, lbit)
def __new__(cls, *args, **kwargs):
# abuse the __new__ constructor to set some immutable class attributes
# before the class is instantiated
cls._initlogger()
return super(MythLog, cls).__new__(cls, *args, **kwargs)

def __init__(self, module='pythonbindings', db=None):
self.module = module
self.db = db

@classmethod
def _setlevel(cls, lstr=None, lbit=None):
def _setlevel(cls, level):
cls._initlogger()
try:
level = int(level)
cls._LEVEL = level
except:
if level not in ('any', 'emerg', 'alert', 'crit', 'err',
'warning', 'info', 'notice', 'debug', 'unknown'):
return
cls._LEVEL = getattr(cls, level.upper())

@classmethod
def _setmask(cls, mask):
"""Manually set loglevel."""
if lstr:
cls.LEVEL = cls._parselevel(lstr)
elif lbit:
cls.LEVEL = lbit
cls._initlogger()
try:
cls._MASK = int(mask)
except:
cls._MASK = cls._parsemask(mask)

@classmethod
def _setfile(cls, filename):
"""Redirect log output to a specific file."""
cls._initlogger()
cls._setfileobject(open(filename, 'w'))

@classmethod
def _setfileobject(cls, fileobject, close=True):
"""Redirect log output to an opened file pointer."""
if (cls.LOGFILE.fileno() != 1) and close:
cls.LOGFILE.close()
cls.LOGFILE = fileobject
cls._initlogger()
if (cls._LOGFILE.fileno() != 1) and close:
cls._LOGFILE.close()
cls._LOGFILE = fileobject
cls._logwrite = cls._logfile
if cls._SYSLOG:
cls._SYSLOG = None
syslog.closelog()

@classmethod
def _setsyslog(cls, facility=LOGFACILITY.USER):
cls._initlogger()
try:
facility = int(facility)
for fac in dir(LOGFACILITY):
if '_' in fac:
continue
if getattr(LOGFACILITY, fac) == facility:
facility = 'LOG_'+fac
break
else:
raise MythError("Invalid syslog facility")

except ValueError:
if not facility.startswith('LOG_'):
facility = 'LOG_'+facility.upper()
if not hasattr(LOGFACILITY, facility[4:]):
raise MythError("Invalid syslog facility")

cls._SYSLOG = facility
syslog.openlog(argv[0].rsplit('/', 1)[1],
syslog.LOG_NDELAY|syslog.LOG_PID,
getattr(syslog, facility))
cls._logwrite = cls._logsyslog
if cls._LOGFILE:
if cls._LOGFILE.fileno() != 1:
cls._LOGFILE.close()
cls._LOGFILE = None

@classmethod
def _parselevel(cls, lstr=None):
def _parsemask(cls, mstr=None):
bwlist = ( 'important','general','record','playback','channel','osd',
'file','schedule','network','commflag','audio','libav',
'jobqueue','siparser','eit','vbi','database','dsmcc',
'mheg','upnp','socket','xmltv','dvbcam','media','idle',
'channelscan','extra','timestamp')
if lstr:
level = cls.NONE
for l in lstr.split(','):
if mstr:
mask = cls.NONE
for m in mstr.split(','):
try:
if l in ('all','most','none'):
if m in ('all','most','none'):
# set initial bitfield
level = getattr(cls, l.upper())
mask = getattr(cls, m.upper())
elif l in bwlist:
# update bitfield OR
level |= getattr(cls, l.upper())
elif len(l) > 2:
if l[0:2] == 'no':
if l[2:] in bwlist:
mask |= getattr(cls, m.upper())
elif len(m) > 2:
if m[0:2] == 'no':
if m[2:] in bwlist:
# update bitfield NOT
level &= level^getattr(self, l[2:].upper())
mask &= mask^getattr(cls, m[2:].upper())
except AttributeError:
pass
return level
else:
level = []
for l,v in enumerate(bwlist):
if cls.LEVEL&2**l:
level.append(v)
return ','.join(level)

def time(self): return datetime.now().strftime('%Y-%m-%d %H:%M:%S.%f')[:-3]

def _testLevel(self, level):
if level&self.EXTRA:
if not self.LEVEL&self.EXTRA:
return False
return self._testLevel(level&(self.ALL-self.EXTRA))
return mask
else:
return bool(level&self.LEVEL)
cls._initlogger()
mask = []
for m,v in enumerate(bwlist):
if cls._MASK&2**l:
mask.append(v)
return ','.join(mask)

def logTB(self, level):
def time(self): return datetime.now().strftime('%Y-%m-%d %H:%M:%S.%f')

def logTB(self, mask):
"""
MythLog.logTB(level) -> None
MythLog.logTB(mask) -> None
'level' sets the bitwise log level, to be matched against the log
'mask' sets the bitwise log mask, to be matched against the log
filter. If any bits match true, the message will be logged.
This will log the latest traceback.
"""
self.log(level, format_exc())
self.log(mask, self.CRIT, format_exc())

def log(self, level, message, detail=None):
def log(self, mask, level, message, detail=None):
"""
MythLog.log(level, message, detail=None) -> None
MythLog.log(mask, message, detail=None) -> None
'level' sets the bitwise log level, to be matched against the log
'mask' sets the bitwise log mask, to be matched against the log
filter. If any bits match true, the message will be logged.
'message' and 'detail' set the log message content using the format:
<timestamp> <module>: <message>
---- or ----
<timestamp> <module>: <message> -- <detail>
"""
if self._testLevel(level):
buff = StringIO()
buff.write('%s %s: ' % (self.time(), self.module))
if level > self._LEVEL:
return
if not mask&self._MASK:
return
if self._QUIET > 1:
return

with self._lock:
self._logwrite(mask, level, message, detail)
self._logdatabase(mask, level, message, detail)

multiline = False
if '\n' in message:
def _logfile(self, mask, level, message, detail):
if self._QUIET and (self._LOGFILE == stdout):
return

buff = StringIO()
buff.write("{0} {3} [{1}] {2} "\
.format(self.time(), os.getpid(), self.module,
['!','A','C','E','W','N','I','D'][level]))

multiline = False
if '\n' in message:
multiline = True
elif detail:
if '\n' in detail:
multiline = True
elif detail:
if '\n' in detail:
multiline = True

if multiline:
for line in message.split('\n'):
buff.write('\n %s' % line)
if detail:
for line in detail.split('\n'):
buff.write('\n %s' % line)
else:
buff.write(message)
if detail:
buff.write(' -- %s' % detail)

buff.write('\n')

with self._lock:
self.LOGFILE.write(buff.getvalue())
self.LOGFILE.flush()

# if (dblevel is not None) and (self.db is not None):
# c = self.db.cursor(self.log)
# c.execute("""INSERT INTO mythlog (module, priority, logdate,
# host, message, details)
# VALUES (%s, %s, %s, %s, %s, %s)""",
# (self.module, dblevel, now(),
# self.host, message, detail))
# c.close()

def __call__(self, level, message, detail=None):
self.log(level, message, detail)

if multiline:
for line in message.split('\n'):
buff.write('\n %s' % line)
if detail:
for line in detail.split('\n'):
buff.write('\n %s' % line)
else:
buff.write(message)
if detail:
buff.write(' -- %s' % detail)

buff.write('\n')

self._LOGFILE.write(buff.getvalue())
self._LOGFILE.flush()

def _logsyslog(self, mask, level, message, detail):
syslog.syslog(level,
message + (' -- {0}'.format(detail) if detail else ''))

def _logdatabase(self, mask, level, message, detail):
if self.db and self._DBLOG:
with self.db.cursor(DummyLogger()) as cursor:
cursor.execute("""INSERT INTO logging
(host, application, pid, thread,
msgtime, level, message)
VALUES (?, ?, ?, ?, ?, ?, ?)""",
(self.db.gethostname(), argv[0].rsplit('/', 1)[1],
os.getpid(), self.module, self.time(), level,
message + (' -- {0}'.format(detail) if detail else '')))

def __call__(self, mask, level, message, detail=None):
self.log(mask, level, message, detail)
4 changes: 1 addition & 3 deletions mythtv/bindings/python/MythTV/methodheap.py
Original file line number Diff line number Diff line change
Expand Up @@ -393,7 +393,7 @@ def _neweventconn(self):
def eventMonitor(self, event=None):
if event is None:
return re.compile('BACKEND_MESSAGE')
self.log(MythLog.ALL-MythLog.EXTRA, event)
self.log(MythLog.ALL, MythLog.INFO, event)

class MythSystemEvent( BECache ):
class systemeventhandler( object ):
Expand Down Expand Up @@ -611,15 +611,13 @@ def getScreenShot(self):
class MythDB( DBCache ):
__doc__ = DBCache.__doc__+"""
obj.searchRecorded() - return a list of matching Recorded objects
obj.getRecorded() - return a single matching Recorded object
obj.searchOldRecorded() - return a list of matching
OldRecorded objects
obj.searchJobs() - return a list of matching Job objects
obj.searchGuide() - return a list of matching Guide objects
obj.searchRecord() - return a list of matching Record rules
obj.getFrontends() - return a list of available Frontends
obj.getFrontend() - return a single Frontend object
obj.getChannels() - return a list of all channels
"""


Expand Down
9 changes: 5 additions & 4 deletions mythtv/bindings/python/MythTV/mythproto.py
Original file line number Diff line number Diff line change
Expand Up @@ -296,7 +296,8 @@ def ftopen(file, mode, forceremote=False, nooverwrite=False, db=None, \
path = sg.dirname+filename.rsplit('/',1)[0]
if not os.access(path, os.F_OK):
os.makedirs(path)
log(log.FILE, 'Opening local file (w)', sg.dirname+filename)
log(log.FILE, log.INFO, 'Opening local file (w)',
sg.dirname+filename)
return open(sg.dirname+filename, mode)

# fallback to remote write
Expand All @@ -310,8 +311,8 @@ def ftopen(file, mode, forceremote=False, nooverwrite=False, db=None, \
sg = findfile(filename, sgroup, db)
if sg is not None:
# file found, open local
log(log.FILE, 'Opening local file (r)',
sg.dirname+filename)
log(log.FILE, log.INFO, 'Opening local file (r)',
sg.dirname+filename)
return open(sg.dirname+filename, mode)
else:
# file not found, open remote
Expand Down Expand Up @@ -988,7 +989,7 @@ def formatJob(self, cmd):
cmd = cmd.replace('%%%sISO%%' % tag, t.isoformat())
cmd = cmd.replace('%%%sISOUTC%%' % tag, \
(t+timedelta(0,altzone)).isoformat())
cmd = cmd.replace('%VERBOSELEVEL%', MythLog._parselevel())
cmd = cmd.replace('%VERBOSELEVEL%', MythLog._parsemask())
cmd = cmd.replace('%RECID%', str(self.recordid))

path = FileOps(self.hostname, db=self._db).fileExists(\
Expand Down
107 changes: 63 additions & 44 deletions mythtv/bindings/python/MythTV/static.py
Original file line number Diff line number Diff line change
Expand Up @@ -4,7 +4,7 @@
Contains any static and global variables for MythTV Python Bindings
"""

OWN_VERSION = (0,25,-1,2)
OWN_VERSION = (0,25,-1,3)
SCHEMA_VERSION = 1283
NVSCHEMA_VERSION = 1007
MUSICSCHEMA_VERSION = 1018
Expand Down Expand Up @@ -147,50 +147,69 @@ class JOBSTATUS( object ):
ERRORED = 0x0130
CANCELLED = 0x0140

class LOGMASK( object ):
ALL = 0b111111111111111111111111111
MOST = 0b011111111110111111111111111
NONE = 0b000000000000000000000000000

GENERAL = 0b000000000000000000000000001
RECORD = 0b000000000000000000000000010
PLAYBACK = 0b000000000000000000000000100
CHANNEL = 0b000000000000000000000001000
OSD = 0b000000000000000000000010000
FILE = 0b000000000000000000000100000
SCHEDULE = 0b000000000000000000001000000
NETWORK = 0b000000000000000000010000000
COMMFLAG = 0b000000000000000000100000000
AUDIO = 0b000000000000000001000000000
LIBAV = 0b000000000000000010000000000
JOBQUEUE = 0b000000000000000100000000000
SIPARSER = 0b000000000000001000000000000
EIT = 0b000000000000010000000000000
VBI = 0b000000000000100000000000000
DATABASE = 0b000000000001000000000000000
DSMCC = 0b000000000010000000000000000
MHEG = 0b000000000100000000000000000
UPNP = 0b000000001000000000000000000
SOCKET = 0b000000010000000000000000000
XMLTV = 0b000000100000000000000000000
DVBCAM = 0b000001000000000000000000000
MEDIA = 0b000010000000000000000000000
IDLE = 0b000100000000000000000000000
CHANNELSCAN = 0b001000000000000000000000000
SYSTEM = 0b010000000000000000000000000
TIMESTAMP = 0b100000000000000000000000000

class LOGLEVEL( object ):
ALL = int('11111111111111111111111111111', 2)
MOST = int('00111111111101111111111111111', 2)
NONE = int('00000000000000000000000000000', 2)

IMPORTANT = int('00000000000000000000000000001', 2)
GENERAL = int('00000000000000000000000000010', 2)
RECORD = int('00000000000000000000000000100', 2)
PLAYBACK = int('00000000000000000000000001000', 2)
CHANNEL = int('00000000000000000000000010000', 2)
OSD = int('00000000000000000000000100000', 2)
FILE = int('00000000000000000000001000000', 2)
SCHEDULE = int('00000000000000000000010000000', 2)
NETWORK = int('00000000000000000000100000000', 2)
COMMFLAG = int('00000000000000000001000000000', 2)
AUDIO = int('00000000000000000010000000000', 2)
LIBAV = int('00000000000000000100000000000', 2)
JOBQUEUE = int('00000000000000001000000000000', 2)
SIPARSER = int('00000000000000010000000000000', 2)
EIT = int('00000000000000100000000000000', 2)
VBI = int('00000000000001000000000000000', 2)
DATABASE = int('00000000000010000000000000000', 2)
DSMCC = int('00000000000100000000000000000', 2)
MHEG = int('00000000001000000000000000000', 2)
UPNP = int('00000000010000000000000000000', 2)
SOCKET = int('00000000100000000000000000000', 2)
XMLTV = int('00000001000000000000000000000', 2)
DVBCAM = int('00000010000000000000000000000', 2)
MEDIA = int('00000100000000000000000000000', 2)
IDLE = int('00001000000000000000000000000', 2)
CHANNELSCAN = int('00010000000000000000000000000', 2)
SYSTEM = int('00100000000000000000000000000', 2)
EXTRA = int('01000000000000000000000000000', 2)
TIMESTAMP = int('10000000000000000000000000000', 2)

DBALL = 8
DBDEBUG = 7
DBINFO = 6
DBNOTICE = 5
DBWARNING = 4
DBERROR = 3
DBCRITICAL = 2
DBALERT = 1
DBEMERGENCY = 0
ANY = -1
EMERG = 0
ALERT = 1
CRIT = 2
ERR = 3
WARNING = 4
NOTICE = 5
INFO = 6
DEBUG = 7
UNKNOWN = 8

class LOGFACILITY( object ):
KERN = 1
USER = 2
MAIL = 3
DAEMON = 4
AUTH = 5
LPR = 6
NEWS = 7
UUCP = 8
CRON = 9
LOCAL0 = 10
LOCAL1 = 11
LOCAL2 = 12
LOCAL3 = 13
LOCAL4 = 14
LOCAL5 = 15
LOCAL6 = 16
LOCAL7 = 17

class ERRCODES( object ):
GENERIC = 0
Expand Down
8 changes: 4 additions & 4 deletions mythtv/bindings/python/MythTV/system.py
Original file line number Diff line number Diff line change
Expand Up @@ -32,9 +32,9 @@ def system(cls, command, db=None):
s = cls(path, db=db)
res = s._runcmd(command)
if len(res):
s.log(MythLog.SYSTEM|MythLog.EXTRA, '---- Output ----', res)
s.log(MythLog.SYSTEM, MythLog.DEBUG, '---- Output ----', res)
if len(s.stderr):
s.log(MythLog.SYSTEM|MythLog.EXTRA,
s.log(MythLog.SYSTEM, MythLog.DEBUG,
'---- Error ----', s.stderr)
return 0
except (MythDBError,MythFileError):
Expand Down Expand Up @@ -116,12 +116,12 @@ def command(self, *args):
return self._runcmd('%s %s' % (self.path, arg))

def _runshell(self, cmd):
self.log(MythLog.SYSTEM, 'Running external command', cmd)
self.log(MythLog.SYSTEM, MythLog.INFO, 'Running external command', cmd)
fd = Popen(cmd, stdout=-1, stderr=-1, shell=True)
return self._runshared(fd, cmd)

def _runnative(self, cmd):
self.log(MythLog.SYSTEM, 'Running external command', cmd)
self.log(MythLog.SYSTEM, MythLog.INFO, 'Running external command', cmd)
args = shlex.split(cmd)
fd = Popen(args, stdout=-1, stderr=-1)
return self._runshared(fd, cmd)
Expand Down
10 changes: 5 additions & 5 deletions mythtv/bindings/python/MythTV/utility.py
Original file line number Diff line number Diff line change
Expand Up @@ -44,21 +44,21 @@ def run(self):
while True:

newschema = getattr(self, 'up%d' % schema)()
self.log(MythLog.DATABASE,
self.log(MythLog.GENERAL, MythLog.INFO,
'successfully updated from %d to %d' %\
(schema, newschema))
schema = newschema
self.db.settings.NULL[self._schema_name] = schema

except AttributeError, e:
self.log(MythLog.DATABASE|MythLog.IMPORTANT,
self.log(MythLog.GENERAL, MythLog.CRIT,
'failed at %d' % schema, 'no handler method')
raise MythDBError('Schema update failed, '
"SchemaUpdate has no function 'up%s'" % schema)

except StopIteration:
if schema != origschema:
self.log(MythLog.DATABASE,
self.log(MythLog.GENERAL, MythLog.NOTICE,
'%s update complete' % self._schema_name)
pass

Expand Down Expand Up @@ -646,14 +646,14 @@ def recvheader(self, flags=0, deadline=None):
"""
size = int(self.dlrecv(8, flags, deadline))
data = self.dlrecv(size, flags, deadline)
self.log(MythLog.SOCKET|MythLog.NETWORK, \
self.log(MythLog.SOCKET|MythLog.NETWORK, MythLog.DEBUG, \
'read <-- %d' % size, data)
return data

def sendheader(self, data, flags=0):
"""Send data, prepending the length in the first 8 bytes."""
try:
self.log(MythLog.SOCKET|MythLog.NETWORK, \
self.log(MythLog.SOCKET|MythLog.NETWORK, MythLog.DEBUG, \
'write --> %d' % len(data), data)
data = '%-8d%s' % (len(data), data)
self.send(data, flags)
Expand Down