[Erp5-report] r13828 - /erp5/trunk/utils/oood/
nobody at svn.erp5.org
nobody at svn.erp5.org
Fri Mar 30 18:28:41 CEST 2007
Author: bartek
Date: Fri Mar 30 18:28:37 2007
New Revision: 13828
URL: http://svn.erp5.org?rev=13828&view=rev
Log:
added many logging instruction for debugging
Added:
erp5/trunk/utils/oood/logger.py
Modified:
erp5/trunk/utils/oood/config.py
erp5/trunk/utils/oood/factory.py
erp5/trunk/utils/oood/mimemapper.py
erp5/trunk/utils/oood/pool.py
erp5/trunk/utils/oood/runserw.py
erp5/trunk/utils/oood/serw.py
erp5/trunk/utils/oood/start.py
erp5/trunk/utils/oood/worker.py
Modified: erp5/trunk/utils/oood/config.py
URL: http://svn.erp5.org/erp5/trunk/utils/oood/config.py?rev=13828&r1=13827&r2=13828&view=diff
==============================================================================
--- erp5/trunk/utils/oood/config.py (original)
+++ erp5/trunk/utils/oood/config.py Fri Mar 30 18:28:37 2007
@@ -27,6 +27,8 @@
#
##############################################################################
+import logging
+
###################################################################
# System config
###################################################################
@@ -37,6 +39,7 @@
log_file = '/var/log/oood/oood.log' # Complete absolute path to the log file
debug_mode = False
+log_level = logging.DEBUG
###################################################################
Modified: erp5/trunk/utils/oood/factory.py
URL: http://svn.erp5.org/erp5/trunk/utils/oood/factory.py?rev=13828&r1=13827&r2=13828&view=diff
==============================================================================
--- erp5/trunk/utils/oood/factory.py (original)
+++ erp5/trunk/utils/oood/factory.py Fri Mar 30 18:28:37 2007
@@ -32,6 +32,7 @@
import config
import lib
+from logger import Log
sys.path.append(config.uno_path)
import uno
@@ -49,11 +50,14 @@
"""
Create a context, bind it to next instance of OO using calculated port number.
"""
+ Log.warning('[factory] building worker for %d' % i)
instance_port = config.pool_port_range_start + i
ctx = self.resolver.resolve("uno:socket,host=%s,port=%d;urp;StarOffice.ComponentContext" % (config.pool_host, instance_port))
smgr = ctx.ServiceManager
desktop = smgr.createInstanceWithContext("com.sun.star.frame.Desktop", ctx)
- return worker.Worker(i, desktop, pool)
+ w = worker.Worker(i, desktop, pool)
+ Log.info('[factory] worker for %d created' % i)
+ return w
builder = WorkerFactory()
Added: erp5/trunk/utils/oood/logger.py
URL: http://svn.erp5.org/erp5/trunk/utils/oood/logger.py?rev=13828&view=auto
==============================================================================
--- erp5/trunk/utils/oood/logger.py (added)
+++ erp5/trunk/utils/oood/logger.py Fri Mar 30 18:28:37 2007
@@ -1,0 +1,41 @@
+
+import logging
+import sys
+import threading
+import traceback
+sys.path.append('/etc/oood')
+import config
+
+
+logging.basicConfig(level=config.log_level,
+ format='%(asctime)s %(levelname)-8s %(message)s',
+ datefmt='%Y/%m/%d %H:%M:%S',
+ filename=config.log_file,
+ filemode='a')
+
+
+class mylog(object):
+
+ funcs = ('debug', 'info', 'warning', 'error', 'critical', 'exception')
+
+ def __init__(self):
+ def mkFunc(f):
+ logfunc = getattr(logging, f)
+ def _func(msg, *a, **kw):
+ thread_name = threading.currentThread().getName()
+ msg = '<%s> %s' %(thread_name, msg)
+ logfunc(msg, *a, **kw)
+ return _func
+ for f in self.funcs:
+ setattr(self, f, mkFunc(f))
+
+ def logException(self, e, tb):
+ Log.error(str(e))
+ Log.error(''.join(traceback.format_tb(tb)))
+
+Log = mylog()
+
+
+if __name__=='__main__':
+ Log.warning('bleble')
+ Log.critical('iiiiiii')
Modified: erp5/trunk/utils/oood/mimemapper.py
URL: http://svn.erp5.org/erp5/trunk/utils/oood/mimemapper.py?rev=13828&r1=13827&r2=13828&view=diff
==============================================================================
--- erp5/trunk/utils/oood/mimemapper.py (original)
+++ erp5/trunk/utils/oood/mimemapper.py Fri Mar 30 18:28:37 2007
@@ -31,6 +31,7 @@
import sys
sys.path.append('/etc/oood')
import config
+from logger import Log
sys.path.append(config.uno_path)
import uno
from com.sun.star.beans import PropertyValue
Modified: erp5/trunk/utils/oood/pool.py
URL: http://svn.erp5.org/erp5/trunk/utils/oood/pool.py?rev=13828&r1=13827&r2=13828&view=diff
==============================================================================
--- erp5/trunk/utils/oood/pool.py (original)
+++ erp5/trunk/utils/oood/pool.py Fri Mar 30 18:28:37 2007
@@ -37,6 +37,7 @@
import factory
import lib
import start
+from logger import Log
class Pool(object):
"""
@@ -83,12 +84,14 @@
"""
w = None
self.acquire() # wait untill something is free
+ Log.info('[pool] getting worker from ' + str(self.inst))
for idx in range(self.total):
candidate = self.inst[idx]
if not candidate.busy and not candidate.dead:
w = self.inst[idx]
break
if w is None: # means semaphore is out of sync with pool - this signals a serious problem
+ Log.info('[pool] no worker availabie')
raise lib.WorkerNotAvailable('sorry')
w.setBusy()
self.timers[idx] = threading.Timer(config.instance_timeout, self.rebuild(idx))
@@ -107,7 +110,7 @@
in the pool with the new one
"""
print 'That takes too long !'
- lib.log('Instance %s not responding - restart it' % i, 3)
+ Log.warning('[pool] Instance %s not responding - restart it' % i)
start.killInstance(i)
self._killWorker(i)
start.startInstance(i)
@@ -128,6 +131,8 @@
but we have to mark it, otherwise it may hang around for a while, complete the job and release semaphore
which would cause serious problem
"""
+ w = self.inst[i]
+ Log.warning('[pool] killing %s idx %d, busy? %d, dead? %d' % (str(w), w.idx, w.busy, w.dead))
self.inst[i].dead = True
pool = Pool()
Modified: erp5/trunk/utils/oood/runserw.py
URL: http://svn.erp5.org/erp5/trunk/utils/oood/runserw.py?rev=13828&r1=13827&r2=13828&view=diff
==============================================================================
--- erp5/trunk/utils/oood/runserw.py (original)
+++ erp5/trunk/utils/oood/runserw.py Fri Mar 30 18:28:37 2007
@@ -29,6 +29,8 @@
##############################################################################
import getopt, sys, os, signal, lib
+import logging
+from logger import Log
@@ -105,13 +107,13 @@
lock_file_path = os.path.join(config.run_dir, 'server_pid.lock')
# Get the server process id which is written in the lock file.
if not os.path.exists(lock_file_path):
- lib.log("Server - Can't stop server: it was not running !", 1)
+ Log.info("Server - Can't stop server: it was not running !")
sys.exit(1)
lock_file = open(lock_file_path, 'r')
server_pid = int(lock_file.read())
lock_file.close()
os.kill(server_pid, signal.SIGTERM)
- lib.log("Server - Stopped properly", 0)
+ Log.info("Server - Stopped properly")
sys.exit(0)
@@ -126,7 +128,7 @@
Remove the lock file and exit cleanly.
"""
import config
- lib.log("Server - Remove lock file and stop server", 0)
+ Log.info("Server - Remove lock file and stop server")
lock_file_path = os.path.join(config.run_dir, 'server_pid.lock')
if os.path.exists(lock_file_path):
os.remove(lock_file_path)
@@ -136,11 +138,11 @@
"""
Catch signal to stop the server
"""
- lib.log("Server - Stopped by signal %s" % signum, 0)
+ Log.info("Server - Stopped by signal %s" % signum)
cleanAndExit()
if debug:
- lib.log("Server - Started in debug mode", 1)
+ Log.info("Server - Started in debug mode")
# Some signals signify a stop request
signal.signal(signal.SIGINT, signalHandler)
@@ -149,13 +151,13 @@
# Create a lock file to not run more than one server and to save the pid
lock_file_path = os.path.join(config.run_dir, 'server_pid.lock')
if os.path.exists(lock_file_path):
- lib.log("Server - Can't start a new server: another one is already started or the previous server wasn't properly stopped", 2)
+ Log.info("Server - Can't start a new server: another one is already started or the previous server wasn't properly stopped")
sys.exit(1)
lock_file = open(lock_file_path, 'w')
server_pid = os.getpid()
lock_file.write(str(server_pid))
lock_file.close()
- lib.log("Server - Started as process %s" % server_pid, 0)
+ Log.info("Server - Started as process %s" % server_pid)
# Start the server core
proc = Procesor()
@@ -171,7 +173,7 @@
# Run the server forever
ser = MySerw((config.server_host, config.server_port), allow_none = True)
ser.register_instance(proc)
- lib.log("Server - Will serve indefinitely until you kill or interrupt it...", 0)
+ Log.info("Server - Will serve indefinitely until you kill or interrupt it...")
ser.serve_forever()
# Clean up and exit
@@ -180,4 +182,4 @@
# Exit on general error
usage()
- sys.exit(1)
+ sys.exit(1)
Modified: erp5/trunk/utils/oood/serw.py
URL: http://svn.erp5.org/erp5/trunk/utils/oood/serw.py?rev=13828&r1=13827&r2=13828&view=diff
==============================================================================
--- erp5/trunk/utils/oood/serw.py (original)
+++ erp5/trunk/utils/oood/serw.py Fri Mar 30 18:28:37 2007
@@ -51,6 +51,7 @@
import config
import lib
+from logger import Log
import pool
from com.sun.star.uno import RuntimeException as unoRuntimeException
@@ -122,14 +123,16 @@
get list of allowed target formats from worker
different interface (no file), so we don't wrap it
"""
+ Log.info('[serw] getting target list for %s' % mimetype)
id, w = pool.pool.getWorker()
+ try:
+ Log.info('[serw] got worker nr %d' % w.idx)
+ except AttributeError:
+ Log.error('[serw] worker is %s' % str(w))
try:
return w.getAllowedTargetItemList(mimetype)
finally:
w.setFree()
-
- # backwards compatibility with old versions of ERP5OOo
- getAllowedTargets = getAllowedTargetItemList
def _pre(self,kw):
"""
@@ -156,12 +159,12 @@
any = False
pth = os.path.join(config.oood_home, 'tmp', os.path.basename(filename))
for f in glob.glob(pth + '*'):
- lib.log('removing %s' % f)
+ #lib.log('removing %s' % f)
if not config.debug_mode:
os.remove(self._mkName(f))
any = True
if not any:
- lib.log('no file beginning with %s' % filename, 1)
+ Lib.warning('no file beginning with %s' % filename, 1)
def _post(self, w, kw):
"""
@@ -188,16 +191,20 @@
def _run(*args):
def _process(kw):
print 'running', func.__name__
+ Log.info('[serw] running %s' % func.__name__)
res = func(w, kw) # XXX am I sure it is threadsafe?
if kw.get('newfilename') is None:
+ Log.warning('[serw] no data received back from func')
# we return empty data
kw['data'] = ''
else:
+ Log.info('[serw] returning %s' % kw.get('newfilename'))
try: # we can do it only if the argument is a string
tozip = kw.get('extension').startswith('html') # if html, we pack the output files
except AttributeError:
tozip = False
if tozip:
+ Log.info('[serw] zipping result')
#first delete the original
fname = kw['filename']
fullname = self._mkName(fname)
@@ -223,24 +230,29 @@
w = None # initialize worker variable
try:
try:
+ Log.info('[serw] doing "pre" for %s' % funcname)
id, w = self._pre(kw)
return _process(kw)
except unoRuntimeException:
print "unoRuntimeException in " + str(id)
+ Log.error("[serw] unoRuntimeException in " + str(id))
id, w = self._pre(kw)
return _process(kw)
except Exception, e:
- print e
- traceback.print_tb(sys.exc_info()[2])
+ tb = sys.exc_info()[2]
+ Log.logException(e, tb)
raise e
finally:
try:
if w is not None:
# do cleanup only if worker has been created
+ Log.info('[serw] doing "post" for %s' % funcname)
self._post(w, kw)
+ else:
+ Log.debug('[serw] w was none')
except Exception, e:
- print e
- traceback.print_tb(sys.exc_info()[2])
+ tb = sys.exc_info()[2]
+ Log.logException(e, tb)
raise e
func = getattr(self, funcname)
return _run
Modified: erp5/trunk/utils/oood/start.py
URL: http://svn.erp5.org/erp5/trunk/utils/oood/start.py?rev=13828&r1=13827&r2=13828&view=diff
==============================================================================
--- erp5/trunk/utils/oood/start.py (original)
+++ erp5/trunk/utils/oood/start.py Fri Mar 30 18:28:37 2007
@@ -28,7 +28,9 @@
#
##############################################################################
-import os, sys
+import logging
+import os
+import sys
# Add oood home (= current path) as a place to look for import
# XXX Is this magical things make oood_home parameter useless in oood config file ?
sys.path.append(os.path.abspath(os.getcwd()))
@@ -38,7 +40,9 @@
import getopt, time, glob
from commands import getstatusoutput, getoutput
# ood python libs
-import lib, config
+import config
+import lib
+from logger import Log
@@ -53,19 +57,19 @@
"""
-def _l(msg, instance_id, level):
+def _l(msg, instance_id, level=0):
"""
This method put instance related messages in the log
"""
LOG_HEAD = "Instance #%s - " % instance_id
- lib.log('%s%s' % (LOG_HEAD, msg), level)
+ Log.info('%s%s' % (LOG_HEAD, msg))
def startInstance(i, on_top=False):
"""
We spawn a new process and record its pid to be able to kill it if necessary.
"""
- _l("Starting...", i, 0)
+ _l("Starting...", i)
instance_port = config.pool_port_range_start + i
BIN = "soffice"
cmd = '%s/%s' % (config.uno_path, BIN)
@@ -92,14 +96,14 @@
, new_context
]
pid = os.spawnlpe(os.P_NOWAIT, cmd, *args_and_env)
- _l("Listening at %s:%s" % (config.pool_host, instance_port), i, 0)
+ _l("Listening at %s:%s" % (config.pool_host, instance_port), i)
pidfile = os.path.join(config.run_dir, 'instance_%d.pid' % i)
open(pidfile, 'w').write(str(pid))
- _l("Started as process %s" % pid, i, 0)
+ _l("Started as process %s" % pid, i)
def killInstance(i):
- _l("Kill requested", i, 1)
+ _l("Kill requested", i)
pid_file_path = os.path.join(config.run_dir, 'instance_%s.pid' % i)
if os.path.exists(pid_file_path):
pid_file = open(pid_file_path, 'r')
@@ -112,38 +116,38 @@
if pid.find('%s' % instance_master_pid) != -1:
instance_pid_list.append(int(pid.strip().split(' ')[0]))
if len(instance_pid_list) > 0:
- _l("Is still running and span on several processes: %s" % ', '.join([str(x) for x in instance_pid_list]), i, 0)
+ _l("Is still running and span on several processes: %s" % ', '.join([str(x) for x in instance_pid_list]), i)
# Kill all instance processes
for pid in instance_pid_list:
- _l("Killing process %s..." % pid, i, 1)
+ _l("Killing process %s..." % pid, i)
os.kill(pid, 9)
- _l("Killed", i, 0)
+ _l("Killed", i)
else:
- _l("Was not properly shutdown", i, 0)
+ _l("Was not properly shutdown", i)
os.remove(pid_file_path)
- _l("Cleaned", i, 0)
+ _l("Cleaned", i)
else:
- _l("Didn't exist, so no need to kill", i, 0)
+ _l("Didn't exist, so no need to kill", i)
def initPool(on_top=False):
"""
This mehod initialize the pool: it kill all previous OOo instances (if any) and re-populate the pool.
"""
- lib.log("Pool - Initialize: populate the pool with %s instances" % config.pool_size, 0)
+ Log.info("Pool - Initialize: populate the pool with %s instances" % config.pool_size)
flushPool()
for i in range(config.pool_size):
startInstance(i, on_top)
- lib.log("Pool - Wait %s seconds to let the instance #%s start" % (config.instance_load_time, i), 0)
+ Log.info("Pool - Wait %s seconds to let the instance #%s start" % (config.instance_load_time, i))
time.sleep(config.instance_load_time)
- lib.log("Pool - Initialized: %s instances started" % config.pool_size, 0)
+ Log.info("Pool - Initialized: %s instances started" % config.pool_size)
def flushPool():
"""
This method flush the pool: it kill all OOo instances to empty the pool.
"""
- lib.log("Pool - Flush requested: kill all instances", 1)
+ Log.info("Pool - Flush requested: kill all instances")
# pool_size can change dynamiccaly, so clear every running OOo intance
max_pool_size = config.pool_size
for pid_file in glob.glob('%s*' % config.run_dir):
@@ -155,7 +159,7 @@
max_pool_size = old_pool_size
for i in range(max_pool_size):
killInstance(i)
- lib.log("Pool - Flushed: all instances killed", 0)
+ Log.info("Pool - Flushed: all instances killed")
def startVirtualFrameBuffer():
@@ -173,7 +177,7 @@
(os.stat(xorg_socket).st_uid != int(getoutput("id -u %s" % OOOD_USER_NAME)) or \
os.stat(xorg_socket).st_gid != int(getoutput("id -g %s" % OOOD_USER_NAME))):
msg = "Pool - Can't start Virtual Frame Buffer because '%s' is not owned by %s" % (xorg_socket, OOOD_USER_NAME)
- lib.log(msg, 3)
+ Log.warning(msg)
print msg
sys.exit(1)
# Start the new virtual display server
@@ -181,8 +185,8 @@
, VIRTUAL_SCREEN
, config.run_dir
))
- lib.log("Pool - Virtual frame buffer started", 0)
- lib.log("Pool - To see the virtual display, run 'xwud -in %sXvfb_screen%s'" % (config.run_dir, VIRTUAL_SCREEN))
+ Log.info("Pool - Virtual frame buffer started")
+ Log.info("Pool - To see the virtual display, run 'xwud -in %sXvfb_screen%s'" % (config.run_dir, VIRTUAL_SCREEN))
def killVirtualFrameBuffer():
@@ -199,7 +203,7 @@
os.kill(pid, 9)
killed = True
if killed:
- lib.log("Pool - Virtual frame buffer killed", 0)
+ Log.info("Pool - Virtual frame buffer killed")
def showPoolStatus():
Modified: erp5/trunk/utils/oood/worker.py
URL: http://svn.erp5.org/erp5/trunk/utils/oood/worker.py?rev=13828&r1=13827&r2=13828&view=diff
==============================================================================
--- erp5/trunk/utils/oood/worker.py (original)
+++ erp5/trunk/utils/oood/worker.py Fri Mar 30 18:28:37 2007
@@ -40,6 +40,7 @@
import lib
from mimemapper import mimemapper
+from logger import Log
def caseUp(s):
"""
@@ -91,6 +92,7 @@
self._generateFuncs()
def setBusy(self):
+ Log.info('[worker] setting busy %s idx %d, busy? %d, dead? %d' % (str(self), self.idx, self.busy, self.dead))
self.busy = True
def setFree(self):
@@ -101,6 +103,7 @@
but hasn't been removed by garbage collector
We have to check because otherwise it will release the semaphore and make it out of sync with the pool
"""
+ Log.info('[worker] setting free %s idx %d, busy? %d, dead? %d' % (str(self), self.idx, self.busy, self.dead))
if not self.dead:
self.busy = False
self.pool.release(self.idx)
@@ -186,9 +189,16 @@
def _run(*args, **kwargs):
"""
if anything goes wrong, we reset the worker
+ and log exception
"""
try:
- res = func(*args, **kwargs)
+ try:
+ res = func(*args, **kwargs)
+ except Exception, e:
+ ex = str(e)
+ tb = sys.exc_info()[2]
+ Log.logException(ex, tb)
+ raise
finally:
self._reset()
return res
@@ -199,20 +209,27 @@
"""
reset all worker's properties
"""
+ Log.info('[worker] resetting worker %d' % self.idx)
try:
self.doc.close(True)
- except:
- pass
+ except Exception, e:
+ # we log exception but do not reraise
+ ex = str(e)
+ tb = sys.exc_info()[2]
+ Log.logException(ex, tb)
for atr in ('fileUrl','doc','dinfo','metadata','destUrl'):
setattr(self,atr,None)
def _loadFile(self,fname):
+ Log.info('[worker] trying to load %s' % fname)
self.fileUrl = absolutize(self.cwd,systemPathToFileUrl(fname))
try:
self.doc = self.desktop.loadComponentFromURL(self.fileUrl,'_blank',0,self.inProps)
except IllegalArgumentException:
+ Log.error('[worker] ' + fname + ' could not be loaded into OpenOffice')
raise lib.NotLoaded(fname + ' could not be loaded into OpenOffice')
if not self.doc:
+ Log.error('[worker] ' + fname + ' was loaded into OpenOffice')
raise lib.NotLoaded(self.fileUrl)
def _saveFile(self):
@@ -330,9 +347,6 @@
except KeyError:
return []
- # backwards compatibility with old versions of ERP5OOo
- getAllowedTargets = getAllowedTargetItemList
-
if __name__ == '__main__':
print caseDown('Reference')
#w = Worker(None)
More information about the Erp5-report
mailing list