Rework most of the logging so that the output is no longer interesting

confluent/auth.py

@@ -68,7 +68,7 @@ def _get_usertenant(name, tenant=False):
     yield tenant
 
 
-def authorize(name, element, tenant=False, access='rw'):
+def authorize(name, element, tenant=False, operation='create'):
     #TODO: actually use the element to ascertain if this user is good enough
     """Determine whether the given authenticated name is authorized.
 
@@ -76,7 +76,7 @@ def authorize(name, element, tenant=False, access='rw'):
     :param element: The path being examined.
     :param tenant: The tenant under which the account exists (defaults to
                     detect from name)
-    :param access: Defaults to 'rw', can check 'ro' access
+    :param operation: Defaults to checking for 'create' level access
 
     returns None if authorization fails or a tuple of the user object
             and the relevant ConfigManager object for the context of the
@@ -88,7 +88,7 @@ def authorize(name, element, tenant=False, access='rw'):
     manager = configmanager.ConfigManager(tenant)
     userobj = manager.get_user(user)
     if userobj:  # returning
-        return (userobj, manager)
+        return (userobj, manager, user, tenant)
     return None
 
 
@@ -104,7 +104,7 @@ def check_user_passphrase(name, passphrase, element=None, tenant=False):
     detected passphrase guessing activity when such activity is detected.
 
     :param name: The login name provided by client
-    :param passhprase: The passphrase provided by client
+    :param passphrase: The passphrase provided by client
     :param element: Optional specification of a particular destination
     :param tenant: Optional explicit indication of tenant (defaults to
                    embedded in name)

confluent/consoleserver.py

@@ -41,7 +41,8 @@ class _ConsoleHandler(object):
         self.node = node
         self.connectstate = 'unconnected'
         self.clientcount = 0
-        self.logger = log.Logger(node, tenant=configmanager.tenant)
+        self.logger = log.Logger(node, console=True,
+                                 tenant=configmanager.tenant)
         self.buffer = bytearray()
         (text, termstate) = self.logger.read_recent_text(8192)
         self.buffer += text

confluent/exceptions.py

@@ -30,3 +30,7 @@ class TargetEndpointUnreachable(ConfluentException):
     # A target system was unavailable.  For example, a BMC
     # was unreachable.  http code 504
     pass
+
+class ForbiddenRequest(ConfluentException):
+    # The client request is not allowed by authorization engine
+    pass

confluent/httpapi.py

@@ -22,6 +22,7 @@ import confluent.auth as auth
 import confluent.config.attributes as attribs
 import confluent.consoleserver as consoleserver
 import confluent.exceptions as exc
+import confluent.log as log
 import confluent.messages
 import confluent.pluginapi as pluginapi
 import confluent.util as util
@@ -35,6 +36,8 @@ import eventlet.wsgi
 #scgi = eventlet.import_patched('flup.server.scgi')
 
 
+auditlog = None
+tracelog = None
 consolesessions = {}
 httpsessions = {}
 opmap = {
@@ -137,7 +140,7 @@ def _get_query_dict(env, reqbody, reqtype):
     return qdict
 
 
-def _authorize_request(env):
+def _authorize_request(env, operation):
     """Grant/Deny access based on data from wsgi env
 
     """
@@ -165,12 +168,27 @@ def _authorize_request(env):
         cookie['confluentsessionid']['secure'] = 1
         cookie['confluentsessionid']['httponly'] = 1
         cookie['confluentsessionid']['path'] = '/'
+    auditmsg = {
+        'user': name,
+        'operation': operation,
+        'target': env['PATH_INFO'],
+    }
+    skiplog = False
+    if '/console/session' in env['PATH_INFO']:
+        skiplog = True
     if authdata:
-        return {'code': 200,
+        authinfo = {'code': 200,
                 'cookie': cookie,
                 'cfgmgr': authdata[1],
-                'username': name,
+                'username': authdata[2],
                 'userdata': authdata[0]}
+        if authdata[3] is not None:
+            auditmsg['tenant'] = authdata[3]
+            authinfo['tenant'] = authdata[3]
+        auditmsg['user'] = authdata[2]
+        if not skiplog:
+            auditlog.log(auditmsg)
+        return authinfo
     else:
         return {'code': 401}
     # TODO(jbjohnso): actually evaluate the request for authorization
@@ -224,7 +242,7 @@ def resourcehandler(env, start_response):
     if 'restexplorerop' in querydict:
         operation = querydict['restexplorerop']
         del querydict['restexplorerop']
-    authorized = _authorize_request(env)
+    authorized = _authorize_request(env, operation)
     if authorized['code'] == 401:
         start_response(
             '401 Authentication Required',
@@ -251,6 +269,14 @@ def resourcehandler(env, start_response):
         prefix, _, _ = env['PATH_INFO'].partition('/console/session')
         _, _, nodename = prefix.rpartition('/')
         if 'session' not in querydict.keys() or not querydict['session']:
+            auditmsg = {
+                'operation': 'start',
+                'target': env['PATH_INFO'],
+                'user': authorized['username'],
+            }
+            if 'tenant' in authorized:
+                auditmsg['tenant'] = authorized['tenant']
+            auditlog.log(auditmsg)
             # Request for new session
             consession = consoleserver.ConsoleSession(
                 node=nodename, configmanager=cfgmgr,
@@ -426,11 +452,16 @@ def serve():
     #but deps are simpler without flup
     #also, the potential for direct http can be handy
     #todo remains unix domain socket for even http
-    eventlet.wsgi.server(eventlet.listen(("", 4005)), resourcehandler)
+    eventlet.wsgi.server(eventlet.listen(("", 4005)), resourcehandler,
+                        log=False, log_output=False, debug=False)
 
 
 class HttpApi(object):
     def start(self):
+        global auditlog
+        global tracelog
+        tracelog = log.Logger('trace')
+        auditlog = log.Logger('audit')
         self.server = eventlet.spawn(serve)
 
 _cleaner = eventlet.spawn(_sessioncleaner)

confluent/log.py

@@ -62,6 +62,8 @@ import collections
 import confluent.config.configmanager as configuration
 import eventlet
 import fcntl
+import json
+import os
 import struct
 import time
 
@@ -76,12 +78,13 @@ import time
 # if that happens, warn to have user increase ulimit for optimal
 # performance
 
+_loggers = {}
 
 class Events(object):
     (
         undefined, clearscreen, clientconnect, clientdisconnect,
-        consoledisconnect, consoleconnect,
-    ) = range(6)
+        consoledisconnect, consoleconnect, stacktrace
+    ) = range(7)
     logstr = {
         2: 'connection by ',
         3: 'disconnection by ',
@@ -98,13 +101,30 @@ class Logger(object):
                      False, events will be formatted like syslog:
                      date: message<CR>
     """
-    def __init__(self, logname, console=True, tenant=None):
+    def __new__(cls, logname, console=False, tenant=None):
+        global _loggers
+        if console:
+            relpath = 'consoles/' + logname
+        else:
+            relpath = logname
+        if relpath in _loggers:
+            return _loggers[relpath]
+        else:
+            return object.__new__(cls)
+
+    def __init__(self, logname, console=False, tenant=None):
+        if hasattr(self, 'initialized'):
+            # we are just a copy of the same object
+            return
+        self.initialized = True
         self.filepath = configuration.get_global("logdirectory")
         if self.filepath is None:
             self.filepath = "/var/log/confluent/"
         self.isconsole = console
         if console:
             self.filepath += "consoles/"
+        if not os.path.isdir(self.filepath):
+            os.makedirs(self.filepath, 448)
         self.textpath = self.filepath + logname
         self.binpath = self.filepath + logname + ".cbl"
         self.writer = None
@@ -204,6 +224,7 @@ class Logger(object):
             raise Exception("Unsupported logdata")
         if ltype is None:
             if type(logdata) == dict:
+                logdata = json.dumps(logdata)
                 ltype = 1
             elif self.isconsole:
                 ltype = 2

confluent/sockapi.py

@@ -24,6 +24,7 @@ import confluent.common.tlvdata as tlvdata
 import confluent.consoleserver as consoleserver
 import confluent.config.configmanager as configmanager
 import confluent.exceptions as exc
+import confluent.log as log
 import confluent.messages
 import confluent.pluginapi as pluginapi
 import eventlet.green.socket as socket
@@ -34,7 +35,10 @@ import os
 import pwd
 import stat
 import struct
+import traceback
 
+tracelog = None
+auditlog = None
 SO_PEERCRED = 17
 
 class ClientConsole(object):
@@ -79,17 +83,25 @@ def sessionhdl(connection, authname, skipauth):
         # element path, that authorization will need to be called
         # per request the user makes
         authdata = auth.check_user_passphrase(authname, passphrase)
-        if authdata is not None:
+        if authdata is None:
+            auditlog.log(
+                {'operation': 'connect', 'user': authname, 'allowed': False})
+        else:
             authenticated = True
             cfm = authdata[1]
     tlvdata.send(connection, {'authpassed': 1})
     request = tlvdata.recv(connection)
     while request is not None:
         try:
-            process_request(connection, request, cfm, authdata, authname)
+            process_request(
+                connection, request, cfm, authdata, authname, skipauth)
+        except exc.ForbiddenRequest as e:
+            tlvdata.send(connection, {'errorcode': 403,
+                                  'error': 'Forbidden'})
+            tlvdata.send(connection, {'_requestdone': 1})
         except:
-            import traceback
-            traceback.print_exc()
+            tracelog.log(traceback.format_exc(), ltype=log.DataTypes.event,
+                event=log.Events.stacktrace)
             tlvdata.send(connection, {'errorcode': 500,
                                   'error': 'Unexpected error'})
             tlvdata.send(connection, {'_requestdone': 1})
@@ -104,53 +116,69 @@ def send_response(responses, connection):
     tlvdata.send(connection, {'_requestdone': 1})
 
 
-def process_request(connection, request, cfm, authdata, authname):
+def process_request(connection, request, cfm, authdata, authname, skipauth):
     #TODO(jbjohnso): authorize each request
-    if type(request) == dict:
-        operation = request['operation']
-        path = request['path']
-        params = request.get('parameters', None)
-        hdlr = None
-        try:
-            if operation == 'start':
-                elems = path.split('/')
-                if elems[3] != "console":
-                    raise exc.InvalidArgumentException()
-                node = elems[2]
-                ccons = ClientConsole(connection)
-                consession = consoleserver.ConsoleSession(
-                    node=node, configmanager=cfm, username=authname,
-                    datacallback=ccons.sendall)
-                if consession is None:
-                    raise Exception("TODO")
-                tlvdata.send(connection, {'started': 1})
-                ccons.startsending()
-                while consession is not None:
-                    data = tlvdata.recv(connection)
-                    if type(data) == dict:
-                        if data['operation'] == 'stop':
-                            consession.destroy()
-                            return
-                        elif data['operation'] == 'break':
-                            consession.send_break()
-                            continue
-                        else:
-                            raise Exception("TODO")
-                    if not data:
+    if not isinstance(request, dict):
+        raise ValueError
+    operation = request['operation']
+    path = request['path']
+    params = request.get('parameters', None)
+    hdlr = None
+    if not skipauth:
+        authdata = auth.authorize(authdata[2], path, authdata[3], operation)
+        auditmsg = {
+            'operation': operation,
+            'user': authdata[2],
+            'target': path,
+        }
+        if authdata[3] is not None:
+            auditmsg['tenant'] = authdata[3]
+        if authdata is None:
+            auditmsg['allowed'] = False
+            auditlog.log(auditmsg)
+            raise exc.ForbiddenRequest()
+        auditmsg['allowed'] = True
+        auditlog.log(auditmsg)
+    try:
+        if operation == 'start':
+            elems = path.split('/')
+            if elems[3] != "console":
+                raise exc.InvalidArgumentException()
+            node = elems[2]
+            ccons = ClientConsole(connection)
+            consession = consoleserver.ConsoleSession(
+                node=node, configmanager=cfm, username=authname,
+                datacallback=ccons.sendall)
+            if consession is None:
+                raise Exception("TODO")
+            tlvdata.send(connection, {'started': 1})
+            ccons.startsending()
+            while consession is not None:
+                data = tlvdata.recv(connection)
+                if type(data) == dict:
+                    if data['operation'] == 'stop':
                         consession.destroy()
                         return
-                    consession.write(data)
-            else:
-                hdlr = pluginapi.handle_path(path, operation, cfm, params)
-        except exc.NotFoundException:
-            tlvdata.send(connection, {"errorcode": 404,
-                                 "error": "Target not found"})
-            tlvdata.send(connection, {"_requestdone": 1})
-        except exc.InvalidArgumentException:
-            tlvdata.send(connection, {"errorcode": 400,
-                                 "error": "Bad Request"})
-            tlvdata.send(connection, {"_requestdone": 1})
-        send_response(hdlr, connection)
+                    elif data['operation'] == 'break':
+                        consession.send_break()
+                        continue
+                    else:
+                        raise Exception("TODO")
+                if not data:
+                    consession.destroy()
+                    return
+                consession.write(data)
+        else:
+            hdlr = pluginapi.handle_path(path, operation, cfm, params)
+    except exc.NotFoundException:
+        tlvdata.send(connection, {"errorcode": 404,
+                             "error": "Target not found"})
+        tlvdata.send(connection, {"_requestdone": 1})
+    except exc.InvalidArgumentException:
+        tlvdata.send(connection, {"errorcode": 400,
+                             "error": "Bad Request"})
+        tlvdata.send(connection, {"_requestdone": 1})
+    send_response(hdlr, connection)
     return
 
 
@@ -209,5 +237,9 @@ def _unixdomainhandler():
 
 class SockApi(object):
     def start(self):
+        global auditlog
+        global tracelog
+        tracelog = log.Logger('trace')
+        auditlog = log.Logger('audit')
         self.tlsserver = eventlet.spawn(_tlshandler)
         self.unixdomainserver = eventlet.spawn(_unixdomainhandler)