Index: etherws/trunk/etherws.py
===================================================================
--- etherws/trunk/etherws.py	(revision 278)
+++ etherws/trunk/etherws.py	(revision 280)
@@ -52,5 +52,7 @@
 import operator
 import argparse
-import traceback
+
+import logging
+import logging.config
 
 import tornado
@@ -65,11 +67,4 @@
 
 
-class DebugMixIn(object):
-    def dprintf(self, msg, func=lambda: ()):
-        if self._debug:
-            prefix = '[%s] %s - ' % (time.asctime(), self.__class__.__name__)
-            sys.stderr.write(prefix + (msg % func()))
-
-
 class EthernetFrame(object):
     def __init__(self, data):
@@ -107,5 +102,5 @@
 
 
-class FDB(DebugMixIn):
+class FDB(object):
     class Entry(object):
         def __init__(self, port, ageout):
@@ -122,6 +117,7 @@
             return self.age > self._ageout
 
-    def __init__(self, ageout, debug):
+    def __init__(self, ageout, logger, debug):
         self._ageout = ageout
+        self._logger = logger
         self._debug = debug
         self._table = {}
@@ -149,6 +145,8 @@
 
         self._del_entry(vid, mac)
-        self.dprintf('aged out: port:%d; vid:%d; mac:%s\n',
-                     lambda: (entry.port.number, vid, mac.encode('hex')))
+
+        if self._debug:
+            self._logger.debug('fdb aged out: port:%d; vid:%d; mac:%s',
+                               entry.port.number, vid, mac.encode('hex'))
 
     def each(self):
@@ -169,6 +167,8 @@
         vid = frame.vid
         self._set_entry(vid, mac, port)
-        self.dprintf('learned: port:%d; vid:%d; mac:%s\n',
-                     lambda: (port.number, vid, mac.encode('hex')))
+
+        if self._debug:
+            self._logger.debug('fdb learned: port:%d; vid:%d; mac:%s',
+                               port.number, vid, mac.encode('hex'))
 
     def delete(self, port):
@@ -176,9 +176,11 @@
             if entry.port.number == port.number:
                 self._del_entry(vid, mac)
-                self.dprintf('deleted: port:%d; vid:%d; mac:%s\n',
-                             lambda: (port.number, vid, mac.encode('hex')))
-
-
-class SwitchingHub(DebugMixIn):
+
+                if self._debug:
+                    self._logger.debug('fdb deleted: port:%d; vid:%d; mac:%s',
+                                       port.number, vid, mac.encode('hex'))
+
+
+class SwitchingHub(object):
     class Port(object):
         def __init__(self, number, interface):
@@ -189,6 +191,7 @@
             self.shut = False
 
-    def __init__(self, fdb, debug):
+    def __init__(self, fdb, logger, debug):
         self.fdb = fdb
+        self._logger = logger
         self._debug = debug
         self._table = {}
@@ -227,10 +230,10 @@
             p.tx += 1
 
-        if ports:
-            self.dprintf('sent: port:%s; vid:%d; %s -> %s\n',
-                         lambda: (','.join(str(p.number) for p in ports),
-                                  frame.vid,
-                                  frame.src_mac.encode('hex'),
-                                  frame.dst_mac.encode('hex')))
+        if self._debug and ports:
+            self._logger.debug('sent: port:%s; vid:%d; %s -> %s',
+                               ','.join(str(p.number) for p in ports),
+                               frame.vid,
+                               frame.src_mac.encode('hex'),
+                               frame.dst_mac.encode('hex'))
 
     def receive(self, src_interface, frame):
@@ -257,8 +260,10 @@
 
         except:  # ex. received invalid frame
-            traceback.print_exc()
+            self._logger.exception(
+                'caught error while forwarding frame: port:%d; frame:%s',
+                src_port.number, frame.data.encode('hex'))
 
     def _privattr(self, name):
-        return '_%s_%s_%s' % (self.__class__.__name__, id(self), name)
+        return '_%s_%s_%s' % (type(self).__name__, id(self), name)
 
     def _set_privattr(self, name, obj, value):
@@ -402,17 +407,18 @@
                 return do_execute()
         except:
-            traceback.print_exc()
+            self._logger.exception('caught error while doing authorization')
 
         return auth_required()
 
 
-class ServerHandler(DebugMixIn, BasicAuthMixIn, WebSocketHandler):
+class ServerHandler(BasicAuthMixIn, WebSocketHandler):
     IFTYPE = 'server'
     IFOP_ALLOWED = False
 
-    def __init__(self, app, req, switch, htpasswd, debug):
+    def __init__(self, app, req, switch, htpasswd, logger, debug):
         super(ServerHandler, self).__init__(app, req)
         self._switch = switch
         self._htpasswd = htpasswd
+        self._logger = logger
         self._debug = debug
 
@@ -421,7 +427,7 @@
         conn = self.request.connection
         if hasattr(conn, 'address'):
-            return ':'.join(str(e) for e in conn.address)
+            return ':'.join(str(e) for e in conn.address[:2])
         if hasattr(conn, 'context'):
-            return ':'.join(str(e) for e in conn.context.address)
+            return ':'.join(str(e) for e in conn.context.address[:2])
         return str(conn)
 
@@ -430,5 +436,5 @@
             return self._switch.register_port(self)
         finally:
-            self.dprintf('connected: %s\n', lambda: self.request.remote_ip)
+            self._logger.info('connected: %s', self.request.remote_ip)
 
     def on_message(self, message):
@@ -437,15 +443,16 @@
     def on_close(self):
         self._switch.unregister_port(self)
-        self.dprintf('disconnected: %s\n', lambda: self.request.remote_ip)
-
-
-class BaseClientHandler(DebugMixIn):
+        self._logger.info('disconnected: %s', self.request.remote_ip)
+
+
+class BaseClientHandler(object):
     IFTYPE = 'baseclient'
     IFOP_ALLOWED = False
 
-    def __init__(self, ioloop, switch, target, debug, *args, **kwargs):
+    def __init__(self, ioloop, switch, target, logger, debug, *args, **kwargs):
         self._ioloop = ioloop
         self._switch = switch
         self._target = target
+        self._logger = logger
         self._debug = debug
         self._args = args
@@ -491,4 +498,8 @@
 
     @property
+    def logger(self):
+        return self._logger
+
+    @property
     def device(self):
         return self._device
@@ -503,5 +514,5 @@
         self.leave_switch()
         self.unregister_device()
-        self.dprintf('disconnected: %s\n', lambda: self.target)
+        self.logger.info('disconnected: %s', self.target)
 
     def register_device(self, device):
@@ -524,5 +535,5 @@
                 return
         except:
-            traceback.print_exc()
+            self.logger.exception('caught error while receiving frame')
         self.close()
 
@@ -583,5 +594,5 @@
             socket.PF_PACKET, socket.SOCK_RAW, socket.htons(self.ETH_P_ALL)))
         self.device.bind((self.target, self.ETH_P_ALL))
-        self.dprintf('connected: %s\n', lambda: self.target)
+        self.logger.info('connected: %s', self.target)
         return self.join_switch()
 
@@ -659,5 +670,5 @@
         self.register_device(TunTapDevice(self.target, IFF_TAP | IFF_NO_PI))
         self.device.up()
-        self.dprintf('connected: %s\n', lambda: self.target)
+        self.logger.info('connected: %s', self.target)
         return self.join_switch()
 
@@ -702,5 +713,5 @@
         self.register_device(websocket.WebSocket(sslopt=self._sslopt))
         self.device.connect(self.target, **self._options)
-        self.dprintf('connected: %s\n', lambda: self.target)
+        self.logger.info('connected: %s', self.target)
         return self.join_switch()
 
@@ -736,5 +747,5 @@
 
 
-class ControlServerHandler(DebugMixIn, BasicAuthMixIn, RequestHandler):
+class ControlServerHandler(BasicAuthMixIn, RequestHandler):
     NAMESPACE = 'etherws.control'
     IFTYPES = {
@@ -744,9 +755,10 @@
     }
 
-    def __init__(self, app, req, ioloop, switch, htpasswd, debug):
+    def __init__(self, app, req, ioloop, switch, htpasswd, logger, debug):
         super(ControlServerHandler, self).__init__(app, req)
         self._ioloop = ioloop
         self._switch = switch
         self._htpasswd = htpasswd
+        self._logger = logger
         self._debug = debug
 
@@ -758,5 +770,5 @@
                 'code':    0 - 32700,
                 'message': 'Parse error',
-                'data':    '%s: %s' % (e.__class__.__name__, str(e)),
+                'data':    '%s: %s' % (type(e).__name__, str(e)),
             })
 
@@ -772,5 +784,5 @@
                 'code':    0 - 32600,
                 'message': 'Invalid Request',
-                'data':    '%s: %s' % (e.__class__.__name__, str(e)),
+                'data':    '%s: %s' % (type(e).__name__, str(e)),
             })
 
@@ -784,5 +796,5 @@
                 'code':    0 - 32601,
                 'message': 'Method not found',
-                'data':    '%s: %s' % (e.__class__.__name__, str(e)),
+                'data':    '%s: %s' % (type(e).__name__, str(e)),
             })
 
@@ -790,9 +802,9 @@
             return self._jsonrpc_response(id_=id_, result=handler(params))
         except Exception as e:
-            traceback.print_exc()
+            self._logger.exception('caught error while processing request')
             return self._jsonrpc_response(id_=id_, error={
                 'code':    0 - 32602,
                 'message': 'Invalid params',
-                'data':     '%s: %s' % (e.__class__.__name__, str(e)),
+                'data':     '%s: %s' % (type(e).__name__, str(e)),
             })
 
@@ -816,5 +828,6 @@
         opt = getattr(self, '_optparse_' + type_)(params.get('options', {}))
         cls = self.IFTYPES[type_]
-        interface = cls(self._ioloop, self._switch, target, self._debug, **opt)
+        interface = cls(self._ioloop, self._switch, target,
+                        self._logger, self._debug, **opt)
         portnum = interface.open()
         return {'entries': [self._portstat(self._switch.get_port(portnum))]}
@@ -971,4 +984,5 @@
         raise ValueError('Invalid ageout: %s' % args.ageout)
 
+    setrealpath(args, 'logconf')
     setrealpath(args, 'htpasswd', 'sslkey', 'sslcert')
     setrealpath(args, 'ctlhtpasswd', 'ctlsslkey', 'ctlsslcert')
@@ -986,7 +1000,14 @@
     sethtpasswd(args, 'ctlhtpasswd')
 
+    if args.logconf:
+        logging.config.fileConfig(args.logconf)
+        logger = logging.getLogger('etherws')
+    else:
+        logger = logging.getLogger('etherws')
+        logger.setLevel(logging.DEBUG if args.debug else logging.INFO)
+
     ioloop = IOLoop.instance()
-    fdb = FDB(args.ageout, args.debug)
-    switch = SwitchingHub(fdb, args.debug)
+    fdb = FDB(args.ageout, logger, args.debug)
+    switch = SwitchingHub(fdb, logger, args.debug)
 
     if args.port == args.ctlport and args.host == args.ctlhost:
@@ -1002,4 +1023,5 @@
                 'switch':   switch,
                 'htpasswd': args.htpasswd,
+                'logger':   logger,
                 'debug':    args.debug,
             }),
@@ -1008,4 +1030,5 @@
                 'switch':   switch,
                 'htpasswd': args.ctlhtpasswd,
+                'logger':   logger,
                 'debug':    args.debug,
             }),
@@ -1018,4 +1041,5 @@
             'switch':   switch,
             'htpasswd': args.htpasswd,
+            'logger':   logger,
             'debug':    args.debug,
         })])
@@ -1027,4 +1051,5 @@
             'switch':   switch,
             'htpasswd': args.ctlhtpasswd,
+            'logger':   logger,
             'debug':    args.debug,
         })])
@@ -1199,4 +1224,6 @@
     parser_sw.add_argument('--debug', action='store_true', default=False,
                            help='run as debug mode')
+    parser_sw.add_argument('--logconf',
+                           help='path to logging config')
     parser_sw.add_argument('--foreground', action='store_true', default=False,
                            help='run as foreground mode')
@@ -1326,5 +1353,5 @@
             'code':    0 - 32603,
             'message': 'Internal error',
-            'data':    '%s: %s' % (e.__class__.__name__, str(e)),
+            'data':    '%s: %s' % (type(e).__name__, str(e)),
         })
 
