particle-os/debian-koji
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

clean up hub logging a bit

Browse source
This commit is contained in:
Mike McLean 2009-06-03 17:22:21 -04:00
parent 3210c55576
commit 487ccdb2e3
4 changed files with 72 additions and 44 deletions
Download patch file Download diff file Expand all files Collapse all files

7
hub/kojihub.py
View file

@ -31,12 +31,10 @@ import koji.policy
import datetime import datetime
import errno import errno
import logging import logging
import logging.handlers
import fcntl import fcntl
import fnmatch import fnmatch
from koji.util import md5_constructor from koji.util import md5_constructor
import os import os
import pgdb
import random import random
import re import re
import rpm import rpm
@ -49,12 +47,15 @@ import types
import xmlrpclib import xmlrpclib
from koji.context import context from koji.context import context
logger = logging.getLogger('koji.hub')
def log_error(msg): def log_error(msg):
if hasattr(context,'req'): if hasattr(context,'req'):
context.req.log_error(msg) context.req.log_error(msg)
else: else:
sys.stderr.write(msg + "\n") sys.stderr.write(msg + "\n")
logging.getLogger('koji.hub').error(msg) logger.error(msg)
class Task(object): class Task(object):

70
hub/kojixmlrpc.py
View file

@ -21,6 +21,7 @@
# Mike McLean <mikem@redhat.com> # Mike McLean <mikem@redhat.com>
from ConfigParser import ConfigParser from ConfigParser import ConfigParser
import logging
import sys import sys
import time import time
import traceback import traceback
@ -234,11 +235,9 @@ class ModXMLRPCRequestHandler(object):
sys.stderr.flush() sys.stderr.flush()
response = dumps(Fault(faultCode, faultString)) response = dumps(Fault(faultCode, faultString))
if _opt_bool(context.opts, 'KojiDebug'): logger.debug("Returning %d bytes after %f seconds\n", len(response),
sys.stderr.write("Returning %d bytes after %f seconds\n" % time.time() - start)
(len(response),time.time() - start))
sys.stderr.flush()
return response return response
def _dispatch(self,method,params): def _dispatch(self,method,params):
@ -262,21 +261,20 @@ class ModXMLRPCRequestHandler(object):
params,opts = koji.decode_args(*params) params,opts = koji.decode_args(*params)
if _opt_bool(context.opts, 'KojiDebug'): if _opt_bool(context.opts, 'KojiDebug'):
sys.stderr.write("Handling method %s for session %s (#%s)\n" \ logger.debug("Handling method %s for session %s (#%s)",
% (method, context.session.id, context.session.callnum)) method, context.session.id, context.session.callnum)
if method != 'uploadFile': if method != 'uploadFile':
sys.stderr.write("Params: %s\n" % pprint.pformat(params)) logger.debug("Params: %s\n", pprint.pformat(params))
sys.stderr.write("Opts: %s\n" % pprint.pformat(opts)) logger.debug("Opts: %s\n", pprint.pformat(opts))
start = time.time() start = time.time()
ret = func(*params,**opts) ret = func(*params,**opts)
if _opt_bool(context.opts, 'KojiDebug'): if _opt_bool(context.opts, 'KojiDebug'):
sys.stderr.write("Completed method %s for session %s (#%s): %f seconds\n" logger.debug("Completed method %s for session %s (#%s): %f seconds",
% (method, context.session.id, context.session.callnum, method, context.session.id, context.session.callnum,
time.time()-start)) time.time()-start)
sys.stderr.flush()
return ret return ret
def multiCall(self, calls): def multiCall(self, calls):
@ -439,15 +437,14 @@ def load_plugins(opts):
return return
tracker = koji.plugin.PluginTracker(path=opts['PluginPath'].split(':')) tracker = koji.plugin.PluginTracker(path=opts['PluginPath'].split(':'))
for name in opts['Plugins'].split(): for name in opts['Plugins'].split():
sys.stderr.write('Loading plugin: %s\n' % name) logger.info('Loading plugin: %s\n', name)
try: try:
tracker.load(name) tracker.load(name)
except Exception: except Exception:
sys.stderr.write(''.join(traceback.format_exception(*sys.exc_info()))) logger.error(''.join(traceback.format_exception(*sys.exc_info())))
#make this non-fatal, but set ServerOffline #make this non-fatal, but set ServerOffline
opts['ServerOffline'] = True opts['ServerOffline'] = True
opts['OfflineMessage'] = 'configuration error' opts['OfflineMessage'] = 'configuration error'
sys.stderr.flush()
return tracker return tracker
_default_policies = { _default_policies = {
@ -493,6 +490,40 @@ def get_policy(opts, plugins):
return policy return policy
class HubFormatter(logging.Formatter):
"""Support some koji specific fields in the format string"""
def format(self, record):
record.method = getattr(context, 'method', None)
if hasattr(context, 'session'):
record.user_id = context.session.user_id
record.session_id = context.session.id
record.callnum = context.session.callnum
record.user_name = context.session.user_data.get('name')
else:
record.user_id = None
record.session_id = None
record.callnum = None
record.user_name = None
return logging.Formatter.format(self, record)
def setup_logging(opts):
#TODO - more robust config
global logger
logger = logging.getLogger("koji")
if opts.get('KojiDebug'):
logger.setLevel(logging.DEBUG)
else:
logger.setLevel(logging.INFO)
#for now, just stderr logging (stderr goes to httpd logs)
#koji.add_stderr_logger("koji")
handler = logging.StreamHandler()
handler.setFormatter(HubFormatter('%(asctime)s [%(levelname)s] (%(method)s, %(user_name)s) %(name)s: %(message)s'))
handler.setLevel(logging.DEBUG)
logger.addHandler(handler)
# #
# mod_python handler # mod_python handler
# #
@ -506,6 +537,7 @@ def handler(req, profiling=False):
if firstcall: if firstcall:
firstcall = False firstcall = False
opts = load_config(req) opts = load_config(req)
setup_logging(opts)
plugins = load_plugins(opts) plugins = load_plugins(opts)
registry = get_registry(opts, plugins) registry = get_registry(opts, plugins)
policy = get_policy(opts, plugins) policy = get_policy(opts, plugins)
@ -543,7 +575,7 @@ def handler(req, profiling=False):
password = opts.get("DBPass",None), password = opts.get("DBPass",None),
host = opts.get("DBHost", None)) host = opts.get("DBHost", None))
try: try:
context.cnx = koji.db.connect(_opt_bool(opts, 'KojiDebug')) context.cnx = koji.db.connect()
except Exception: except Exception:
offline_reply(req, msg="database outage") offline_reply(req, msg="database outage")
return apache.OK return apache.OK

2
koji/auth.py
View file

@ -44,6 +44,8 @@ class Session(object):
self.master = None self.master = None
self.key = None self.key = None
self.user_id = None self.user_id = None
self.hostip = None
self.user_data = {}
self.message = '' self.message = ''
self.exclusive = False self.exclusive = False
self.lockerror = None self.lockerror = None

37
koji/db.py
View file

@ -21,6 +21,7 @@
# Mike McLean <mikem@redhat.com> # Mike McLean <mikem@redhat.com>
import logging
import sys import sys
import pgdb import pgdb
import time import time
@ -41,9 +42,8 @@ _DBopts = None
_DBconn = context.ThreadLocal() _DBconn = context.ThreadLocal()
class DBWrapper: class DBWrapper:
def __init__(self, cnx, debug=False): def __init__(self, cnx):
self.cnx = cnx self.cnx = cnx
self.debug = debug
def __getattr__(self, key): def __getattr__(self, key):
if not self.cnx: if not self.cnx:
@ -53,7 +53,7 @@ class DBWrapper:
def cursor(self, *args, **kw): def cursor(self, *args, **kw):
if not self.cnx: if not self.cnx:
raise StandardError, 'connection is closed' raise StandardError, 'connection is closed'
return CursorWrapper(self.cnx.cursor(*args, **kw),self.debug) return CursorWrapper(self.cnx.cursor(*args, **kw))
def close(self): def close(self):
# Rollback any uncommitted changes and clear the connection so # Rollback any uncommitted changes and clear the connection so
@ -67,21 +67,17 @@ class DBWrapper:
class CursorWrapper: class CursorWrapper:
def __init__(self, cursor, debug=False): def __init__(self, cursor):
self.cursor = cursor self.cursor = cursor
self.debug = debug self.logger = logging.getLogger('koji.db')
def __getattr__(self, key): def __getattr__(self, key):
return getattr(self.cursor, key) return getattr(self.cursor, key)
def _timed_call(self, method, args, kwargs): def _timed_call(self, method, args, kwargs):
if self.debug: start = time.time()
start = time.time()
ret = getattr(self.cursor,method)(*args,**kwargs) ret = getattr(self.cursor,method)(*args,**kwargs)
if self.debug: self.logger.debug("%s operation completed in %.4f seconds", method, time.time() - start)
sys.stderr.write("%s operation completed in %.4f seconds\n" %
(method, time.time() - start))
sys.stderr.flush()
return ret return ret
def fetchone(self,*args,**kwargs): def fetchone(self,*args,**kwargs):
@ -91,16 +87,13 @@ class CursorWrapper:
return self._timed_call('fetchall',args,kwargs) return self._timed_call('fetchall',args,kwargs)
def execute(self, operation, parameters=()): def execute(self, operation, parameters=()):
if self.debug: debug = self.logger.isEnabledFor(logging.DEBUG)
sys.stderr.write(_quoteparams(operation,parameters)) if debug:
sys.stderr.write("\n") self.logger.debug(_quoteparams(operation,parameters))
sys.stderr.flush()
start = time.time() start = time.time()
ret = self.cursor.execute(operation, parameters) ret = self.cursor.execute(operation, parameters)
if self.debug: if debug:
sys.stderr.write("Execute operation completed in %.4f seconds\n" % self.logger.debug("Execute operation completed in %.4f seconds\n", time.time() - start)
(time.time() - start))
sys.stderr.flush()
return ret return ret
@ -117,7 +110,7 @@ def setDBopts(**opts):
def getDBopts(): def getDBopts():
return _DBopts return _DBopts
def connect(debug=False): def connect():
global _DBconn global _DBconn
if hasattr(_DBconn, 'conn'): if hasattr(_DBconn, 'conn'):
# Make sure the previous transaction has been # Make sure the previous transaction has been
@ -132,7 +125,7 @@ def connect(debug=False):
# BEGIN will be a harmless no-op, though there may be a warning. # BEGIN will be a harmless no-op, though there may be a warning.
conn.cursor().execute('BEGIN') conn.cursor().execute('BEGIN')
conn.rollback() conn.rollback()
return DBWrapper(conn, debug) return DBWrapper(conn)
except pgdb.Error: except pgdb.Error:
del _DBconn.conn del _DBconn.conn
#create a fresh connection #create a fresh connection
@ -144,7 +137,7 @@ def connect(debug=False):
# return conn # return conn
_DBconn.conn = conn _DBconn.conn = conn
return DBWrapper(conn, debug) return DBWrapper(conn)
if __name__ == "__main__": if __name__ == "__main__":
setDBopts( database = "test", user = "test") setDBopts( database = "test", user = "test")