Changeset 280

Timestamp:

06/25/15 14:27:54 (9 years ago)

Author:

atzm

Message:

• logging support

Location:

etherws/trunk

Files:

• README.rst (modified) (2 diffs)
• etherws.py (modified) (35 diffs)
• logging.ini.sample (added)

etherws/trunk/README.rst

@@ -128 +128 @@
 Advanced Usage
 ==============
+
+Proxy
+-----
+You can create WebSocket tunnels via HTTP proxy.  Proxy server's address and
+port number are specified by generic environment variables: e.g. *$http_proxy*
+
+See https://docs.python.org/library/urllib.html for more information about
+environment variables for the proxy.
+
+Logging
+-------
+etherws uses standard logging library.  You can customize the logger using the
+*fileConfig* described in https://docs.python.org/library/logging.config.html
+
+To run *etherws sw* with the custom logger::
+
+  # etherws sw --logconf /path/to/logging.ini
+
+etherws uses a logger stream named "etherws".  And internally Tornado uses
+some logger streams described in http://www.tornadoweb.org/en/stable/log.html
+
+Note: etherws does not write debug logs even if you simply configure loglevel
+DEBUG, to avoid performance degradation.  To write debug logs, you can
+specify *--debug* option.
 
 Remote Control
@@ -203 +227 @@
 =======
 1.3
+  - logging support
   - http proxy support on client connection
   - fix listport bug on tornado 4.0.x

etherws/trunk/etherws.py

@@ -52 +52 @@
 import operator
 import argparse
-import traceback
+
+import logging
+import logging.config
 
 import tornado
@@ -65 +67 @@
 
 
-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 +102 @@
 
 
-class FDB(DebugMixIn):
+class FDB(object):
     class Entry(object):
         def __init__(self, port, ageout):
@@ -122 +117 @@
             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 +145 @@
 
         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 +167 @@
         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 +176 @@
             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 +191 @@
             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 +230 @@
             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 +260 @@
 
         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 +407 @@
                 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 +427 @@
         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 +436 @@
             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 +443 @@
     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 +498 @@
 
     @property
+    def logger(self):
+        return self._logger
+
+    @property
     def device(self):
         return self._device
@@ -503 +514 @@
         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 +535 @@
                 return
         except:
-            traceback.print_exc()
+            self.logger.exception('caught error while receiving frame')
         self.close()
 
@@ -583 +594 @@
             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 +670 @@
         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 +713 @@
         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 +747 @@
 
 
-class ControlServerHandler(DebugMixIn, BasicAuthMixIn, RequestHandler):
+class ControlServerHandler(BasicAuthMixIn, RequestHandler):
     NAMESPACE = 'etherws.control'
     IFTYPES = {
@@ -744 +755 @@
     }
 
-    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 +770 @@
                 'code':    0 - 32700,
                 'message': 'Parse error',
-                'data':    '%s: %s' % (e.__class__.__name__, str(e)),
+                'data':    '%s: %s' % (type(e).__name__, str(e)),
             })
 
@@ -772 +784 @@
                 'code':    0 - 32600,
                 'message': 'Invalid Request',
-                'data':    '%s: %s' % (e.__class__.__name__, str(e)),
+                'data':    '%s: %s' % (type(e).__name__, str(e)),
             })
 
@@ -784 +796 @@
                 'code':    0 - 32601,
                 'message': 'Method not found',
-                'data':    '%s: %s' % (e.__class__.__name__, str(e)),
+                'data':    '%s: %s' % (type(e).__name__, str(e)),
             })
 
@@ -790 +802 @@
             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 +828 @@
         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 +984 @@
         raise ValueError('Invalid ageout: %s' % args.ageout)
 
+    setrealpath(args, 'logconf')
     setrealpath(args, 'htpasswd', 'sslkey', 'sslcert')
     setrealpath(args, 'ctlhtpasswd', 'ctlsslkey', 'ctlsslcert')
@@ -986 +1000 @@
     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 +1023 @@
                 'switch':   switch,
                 'htpasswd': args.htpasswd,
+                'logger':   logger,
                 'debug':    args.debug,
             }),
@@ -1008 +1030 @@
                 'switch':   switch,
                 'htpasswd': args.ctlhtpasswd,
+                'logger':   logger,
                 'debug':    args.debug,
             }),
@@ -1018 +1041 @@
             'switch':   switch,
             'htpasswd': args.htpasswd,
+            'logger':   logger,
             'debug':    args.debug,
         })])
@@ -1027 +1051 @@
             'switch':   switch,
             'htpasswd': args.ctlhtpasswd,
+            'logger':   logger,
             'debug':    args.debug,
         })])
@@ -1199 +1224 @@
     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 +1353 @@
             'code':    0 - 32603,
             'message': 'Internal error',
-            'data':    '%s: %s' % (e.__class__.__name__, str(e)),
+            'data':    '%s: %s' % (type(e).__name__, str(e)),
         })