[PATCH V2] [Wok 0/5] Implement User Request Logger

Changes in V2: * applied review from gingerbase patch * added download option * added crontab for deleting generated downloads * log login/logout requests User requests log is saved by default at log/wok-req.log. The maximum file size is 3 MB and there is rotation with log/wok-req.log.1, which means it will use at most 6 MB of disk space. Suggestions here are appreciated. The log format is JSON, since: * the web user interface will provide a log utility to easily search and filter log results. * there is a download function which generates a log-like text file based on search results. Request log results can be searched using the following parameters: * app: filter by application that received the request (wok, kimchi, etc.) * user: filter by user that performed the request * req: filter by request type: POST, DELETE, PUT. GET requests are not logged. * date: filter by request date in format YYYY-MM-DD * download: generate a log-like text file for download Sample JSON response: dev@u1510:~$ curl -u dev -H "Content-Type: application/json" -H "Accept: application/json" "http://localhost:8010/logs?download=True" -X GET -d '{}' Enter host password for user 'dev': { "records":[ { "app":"wok", "req":"POST", "user":"dev", "time":"14:39:59", "date":"2016-02-25", "message":"User 'dev' logout" }, (...truncated...) { "app":"gingerbase", "req":"POST", "user":"dev", "time":"14:42:31", "date":"2016-02-25", "message":"Host software update" } ], "uri":"/data/logs/tmpbnOzP2.txt" } "uri" value can then be used to download log file: dev@u1510:~$ curl -u dev -H "Content-Type: application/json" -H "Accept: application/json" "http://localhost:8010/data/logs/tmpbnOzP2.txt" -X GET -d '{}' Enter host password for user 'dev': [2016-02-25 14:39:59] POST wok dev: User 'dev' logout [2016-02-25 14:40:13] POST gingerbase dev: Create host debug report 'test' [2016-02-25 14:40:58] PUT gingerbase dev: Update host debug report 'test0' [2016-02-25 14:41:10] DELETE gingerbase dev: Delete host debug report 'test0' [2016-02-25 14:41:55] POST gingerbase dev: Enable host software repository 'archive.canonical.com-wily-partner' [2016-02-25 14:42:06] POST gingerbase dev: Disable host software repository 'archive.canonical.com-wily-partner' [2016-02-25 14:42:31] POST gingerbase dev: Host software update Lucio Correia (5): Add User Request Logger Install cron for cleaning User Request Logs Log user requests Implement User Request Logger API Fix tests Makefile.am | 10 +++ contrib/DEBIAN/control.in | 1 + contrib/Makefile.am | 1 + contrib/cleanlogs.sh | 4 ++ contrib/wok.spec.fedora.in | 2 + contrib/wok.spec.suse.in | 2 + docs/API/logs.md | 27 ++++++++ src/wok/config.py.in | 10 +++ src/wok/control/base.py | 81 ++++++++++++++++++++++-- src/wok/control/logs.py | 43 +++++++++++++ src/wok/i18n.py | 4 +- src/wok/model/logs.py | 31 +++++++++ src/wok/reqlogger.py | 154 +++++++++++++++++++++++++++++++++++++++++++++ src/wok/root.py | 27 ++++++++ src/wok/server.py | 11 ++++ src/wok/utils.py | 12 ++++ src/wokd.in | 4 ++ tests/utils.py | 1 + 18 files changed, 418 insertions(+), 7 deletions(-) create mode 100644 contrib/cleanlogs.sh create mode 100644 docs/API/logs.md create mode 100644 src/wok/control/logs.py create mode 100644 src/wok/model/logs.py create mode 100644 src/wok/reqlogger.py -- 1.9.1

Signed-off-by: Lucio Correia <luciojhc@linux.vnet.ibm.com> --- src/wok/config.py.in | 10 ++++ src/wok/i18n.py | 4 +- src/wok/reqlogger.py | 154 +++++++++++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 167 insertions(+), 1 deletion(-) create mode 100644 src/wok/reqlogger.py diff --git a/src/wok/config.py.in b/src/wok/config.py.in index 40fbcda..afe0f08 100644 --- a/src/wok/config.py.in +++ b/src/wok/config.py.in @@ -60,6 +60,10 @@ FONTS_PATH = { SESSIONSTIMEOUT = 10 # session time out is 10 minutes +def get_log_download_path(): + return os.path.join(paths.state_dir, 'logs') + + def get_object_store(): return os.path.join(paths.state_dir, 'objectstore') @@ -188,6 +192,12 @@ class WokConfig(dict): 'tools.sessions.timeout': SESSIONSTIMEOUT, 'tools.wokauth.on': False }, + '/data/logs': { + 'tools.staticdir.on': True, + 'tools.staticdir.dir': '%s/logs' % paths.state_dir, + 'tools.nocache.on': False, + 'tools.wokauth.on': True, + }, '/base64/jquery.base64.js': { 'tools.staticfile.on': True, 'tools.staticfile.filename': '%s/base64/jquery.base64.js' % diff --git a/src/wok/i18n.py b/src/wok/i18n.py index 82d28d1..e6087f4 100644 --- a/src/wok/i18n.py +++ b/src/wok/i18n.py @@ -37,12 +37,14 @@ messages = { "WOKASYNC0002E": _("Unable to start task due error: %(err)s"), "WOKASYNC0003E": _("Timeout of %(seconds)s seconds expired while running task '%(task)s."), - "WOKAUTH0001E": _("Authentication failed for user '%(username)s'. [Error code: %(code)s]"), "WOKAUTH0002E": _("You are not authorized to access Kimchi"), "WOKAUTH0003E": _("Specify %(item)s to login into Kimchi"), "WOKAUTH0005E": _("Invalid LDAP configuration: %(item)s : %(value)s"), + "WOKLOG0001E": _("Invalid filter parameter. Filter parameters allowed: %(filters)s"), + "WOKLOG0002E": _("Creation of log file failed: %(err)s"), + "WOKOBJST0001E": _("Unable to find %(item)s in datastore"), "WOKUTILS0001E": _("Unable to reach %(url)s. Make sure it is accessible and try again."), diff --git a/src/wok/reqlogger.py b/src/wok/reqlogger.py new file mode 100644 index 0000000..b5b22d8 --- /dev/null +++ b/src/wok/reqlogger.py @@ -0,0 +1,154 @@ +# +# Project Wok +# +# Copyright IBM Corp, 2016 +# +# This library is free software; you can redistribute it and/or +# modify it under the terms of the GNU Lesser General Public +# License as published by the Free Software Foundation; either +# version 2.1 of the License, or (at your option) any later version. +# +# This library is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU +# Lesser General Public License for more details. +# +# You should have received a copy of the GNU Lesser General Public +# License along with this library; if not, write to the Free Software +# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA +# + +import json +import logging +import os.path + +from datetime import datetime +from tempfile import NamedTemporaryFile +from wok.config import get_log_download_path + + +# Log search setup +FILTER_FIELDS = ['app', 'date', 'download', 'req', 'user'] +LOG_DOWNLOAD_URI = "/data/logs/%s" +LOG_FORMAT = "[%(date)s %(time)s] %(req)-6s %(app)-11s %(user)s: %(message)s\n" + +# Log handler setup +MAX_FILE_SIZE = 3072000 +NUM_BACKUP_FILES = 1 +WOK_REQUEST_LOGGER = 'wok_request_logger' + + +class RequestParser(object): + def __init__(self): + logger = logging.getLogger(WOK_REQUEST_LOGGER) + self.baseFile = logger.handlers[0].baseFilename + self.downloadDir = get_log_download_path() + + def generateLogFile(self, records): + """ + Generates a log-format text file with lines for each record specified. + Returns a download URI for the generated file. + """ + try: + # sort records chronologically + sortedList = sorted(records, key=lambda k: k['date'] + k['time']) + + # generate log file + fd = NamedTemporaryFile(mode='w', dir=self.downloadDir, + suffix='.txt', delete=False) + + with fd: + for record in sortedList: + fd.write(LOG_FORMAT % record) + + fd.close() + except IOError as e: + raise OperationFailed("WOKLOG0002E", {'err': str(e)}) + + return LOG_DOWNLOAD_URI % os.path.basename(fd.name) + + def getRecords(self): + records = self.getRecordsFromFile(self.baseFile) + + for count in range(NUM_BACKUP_FILES): + filename = ".".join([self.baseFile, str(count + 1)]) + records.extend(self.getRecordsFromFile(filename)) + + return records + + def getRecordsFromFile(self, filename): + """ + Returns a list of dict, where each dict corresponds to a request + record. + """ + records = [] + + if not os.path.exists(filename): + return [] + + # read records from file + try: + with open(filename) as f: + line = f.readline() + while line != "": + data = line.split(">>>") + if len(data) > 1: + record = json.JSONDecoder().decode(data[0]) + record['message'] = data[1].strip() + records.append(record) + + line = f.readline() + + f. close() + except IOError as e: + raise OperationFailed("WOKLOG0002E", {'err': str(e)}) + + return records + + def getFilteredRecords(self, filter_params): + """ + Returns a dict containing the filtered list of request log entries + (dicts), and an optional uri for downloading results in a text file. + """ + uri = None + results = [] + records = self.getRecords() + + # ignore unrecognized filter options + for key in filter_params.keys(): + if key not in FILTER_FIELDS: + filters = ", ".join(FILTER_FIELDS) + raise InvalidParameter("WOKLOG0001E", {"filters": filters}) + + download = filter_params.pop('download', False) + + # filter records according to parameters + for record in records: + if all(key in record and record[key] == val + for key, val in filter_params.iteritems()): + results.append(record) + + # download option active: generate text file and provide donwload uri + if download and len(results) > 0: + uri = self.generateLogFile(results) + + return {'uri': uri, 'records': results} + + +class RequestRecord(object): + def __init__(self, message, **kwargs): + self.message = message + self.kwargs = kwargs + + # register timestamp + timestamp = datetime.today() + self.kwargs['date'] = timestamp.strftime('%Y-%m-%d') + self.kwargs['time'] = timestamp.strftime('%H:%M:%S') + + def __str__(self): + info = json.JSONEncoder().encode(self.kwargs) + return '%s >>> %s' % (info, self.message) + + def log(self): + reqLogger = logging.getLogger(WOK_REQUEST_LOGGER) + reqLogger.info(self) -- 1.9.1

Signed-off-by: Lucio Correia <luciojhc@linux.vnet.ibm.com> --- Makefile.am | 10 ++++++++++ contrib/DEBIAN/control.in | 1 + contrib/Makefile.am | 1 + contrib/cleanlogs.sh | 4 ++++ contrib/wok.spec.fedora.in | 2 ++ contrib/wok.spec.suse.in | 2 ++ 6 files changed, 20 insertions(+) create mode 100644 contrib/cleanlogs.sh diff --git a/Makefile.am b/Makefile.am index 86d83a0..584c695 100644 --- a/Makefile.am +++ b/Makefile.am @@ -95,6 +95,10 @@ install-deb: install $(DESTDIR)/etc/init/wokd.conf; \ fi $(MKDIR_P) $(DESTDIR)/$(localstatedir)/lib/wok/ + $(MKDIR_P) $(DESTDIR)/$(localstatedir)/lib/wok/logs + $(MKDIR_P) $(DESTDIR)/etc/cron.daily + cp -R $(top_srcdir)/contrib/cleanlogs.sh \ + $(DESTDIR)/etc/cron.daily/wok-cleanlogs $(MKDIR_P) $(DESTDIR)/usr/lib/firewalld/services cp -R $(top_srcdir)/src/firewalld.xml \ $(DESTDIR)/usr/lib/firewalld/services/wokd.xml @@ -146,6 +150,10 @@ install-data-local: $(INSTALL_DATA) src/firewalld.xml $(DESTDIR)/usr/lib/firewalld/services/wokd.xml; \ fi; \ mkdir -p $(DESTDIR)/$(localstatedir)/lib/wok/ + $(MKDIR_P) $(DESTDIR)/$(localstatedir)/lib/wok/logs + $(MKDIR_P) $(DESTDIR)/etc/cron.daily + $(INSTALL_DATA) contrib/cleanlogs.sh $(DESTDIR)/etc/cron.daily/wok-cleanlogs + chmod +x $(DESTDIR)/etc/cron.daily/wok-cleanlogs mkdir -p $(DESTDIR)/$(localstatedir)/log/wok/ touch $(DESTDIR)/$(localstatedir)/log/wok/wok-access.log touch $(DESTDIR)/$(localstatedir)/log/wok/wok-error.log @@ -166,9 +174,11 @@ uninstall-local: if test -d /usr/lib/firewalld/services/; then \ $(RM) $(DESTDIR)/usr/lib/firewalld/services/wokd.xml; \ fi; \ + $(RM) -rf $(DESTDIR)/$(localstatedir)/lib/wok/logs $(RM) -rf $(DESTDIR)/$(localstatedir)/lib/wok $(RM) -rf $(DESTDIR)/$(localstatedir)/log/wok $(RM) -rf $(DESTDIR)/etc/wok + $(RM) $(DESTDIR)/etc/cron.daily/wok-cleanlogs $(RM) $(DESTDIR)/etc/nginx/conf.d/wok.conf $(RM) $(DESTDIR)/etc/logrotate.d/wokd.in $(RM) $(DESTDIR)/etc/logrotate.d/wokd diff --git a/contrib/DEBIAN/control.in b/contrib/DEBIAN/control.in index e585080..bf0e751 100644 --- a/contrib/DEBIAN/control.in +++ b/contrib/DEBIAN/control.in @@ -15,6 +15,7 @@ Depends: python-cherrypy3 (>= 3.2.0), python-psutil (>= 0.6.0), fonts-font-awesome, logrotate, + cron, texlive-fonts-extra Build-Depends: xsltproc, gettext, diff --git a/contrib/Makefile.am b/contrib/Makefile.am index a82ba30..fdc8d2c 100644 --- a/contrib/Makefile.am +++ b/contrib/Makefile.am @@ -30,6 +30,7 @@ EXTRA_DIST = \ wokd-upstart.conf.fedora \ make-deb.sh.in \ wokd.logrotate.in \ + cleanlogs.sh \ $(NULL) make-deb.sh: make-deb.sh.in $(top_builddir)/config.status diff --git a/contrib/cleanlogs.sh b/contrib/cleanlogs.sh new file mode 100644 index 0000000..b916d67 --- /dev/null +++ b/contrib/cleanlogs.sh @@ -0,0 +1,4 @@ +#!/bin/sh + +DIR=/var/lib/wok/logs +[ -d "$DIR" ] && find "$DIR" -mtime +1 -type f -delete diff --git a/contrib/wok.spec.fedora.in b/contrib/wok.spec.fedora.in index 7715e7f..40b247f 100644 --- a/contrib/wok.spec.fedora.in +++ b/contrib/wok.spec.fedora.in @@ -20,6 +20,7 @@ Requires: python-psutil >= 0.6.0 Requires: fontawesome-fonts Requires: open-sans-fonts Requires: logrotate +Requires: crontabs BuildRequires: gettext-devel BuildRequires: libxslt BuildRequires: openssl @@ -114,6 +115,7 @@ rm -rf $RPM_BUILD_ROOT %{_prefix}/share/locale/*/LC_MESSAGES/wok.mo %{_datadir}/wok/ui/ %{_datadir}/wok +%{_sysconfdir}/cron.daily/wok-cleanlogs %{_sysconfdir}/nginx/conf.d/wok.conf.in %{_sysconfdir}/wok/wok.conf %{_sysconfdir}/wok/ diff --git a/contrib/wok.spec.suse.in b/contrib/wok.spec.suse.in index 3d39483..edbf7a0 100644 --- a/contrib/wok.spec.suse.in +++ b/contrib/wok.spec.suse.in @@ -21,6 +21,7 @@ Requires: python-psutil >= 0.6.0 Requires: fontawesome-fonts Requires: google-opensans-fonts Requires: logrotate +Requires: cronie BuildRequires: gettext-tools BuildRequires: libxslt-tools BuildRequires: openssl @@ -91,6 +92,7 @@ rm -rf $RPM_BUILD_ROOT %{_prefix}/share/locale/*/LC_MESSAGES/wok.mo %{_datadir}/wok/ui/ %{_datadir}/wok +%{_sysconfdir}/cron.daily/wok-cleanlogs %{_sysconfdir}/wok/wok.conf %{_sysconfdir}/wok/ %{_sysconfdir}/nginx/conf.d/wok.conf.in -- 1.9.1

Hi Lucio, Instead of setup cron, we can use the cherrypy plugins to execute a task on every time. Please, take a look at http://docs.cherrypy.org/en/latest/pkg/cherrypy.process.html Seems BackgroundTask will fit our needs here: http://docs.cherrypy.org/en/latest/pkg/cherrypy.process.html#cherrypy.proces... We can register the plugin on server start up and let it run on every time you need to check the logs. On 02/25/2016 05:47 PM, Lucio Correia wrote:
Signed-off-by: Lucio Correia <luciojhc@linux.vnet.ibm.com> --- Makefile.am | 10 ++++++++++ contrib/DEBIAN/control.in | 1 + contrib/Makefile.am | 1 + contrib/cleanlogs.sh | 4 ++++ contrib/wok.spec.fedora.in | 2 ++ contrib/wok.spec.suse.in | 2 ++ 6 files changed, 20 insertions(+) create mode 100644 contrib/cleanlogs.sh
diff --git a/Makefile.am b/Makefile.am index 86d83a0..584c695 100644 --- a/Makefile.am +++ b/Makefile.am @@ -95,6 +95,10 @@ install-deb: install $(DESTDIR)/etc/init/wokd.conf; \ fi $(MKDIR_P) $(DESTDIR)/$(localstatedir)/lib/wok/ + $(MKDIR_P) $(DESTDIR)/$(localstatedir)/lib/wok/logs + $(MKDIR_P) $(DESTDIR)/etc/cron.daily + cp -R $(top_srcdir)/contrib/cleanlogs.sh \ + $(DESTDIR)/etc/cron.daily/wok-cleanlogs $(MKDIR_P) $(DESTDIR)/usr/lib/firewalld/services cp -R $(top_srcdir)/src/firewalld.xml \ $(DESTDIR)/usr/lib/firewalld/services/wokd.xml @@ -146,6 +150,10 @@ install-data-local: $(INSTALL_DATA) src/firewalld.xml $(DESTDIR)/usr/lib/firewalld/services/wokd.xml; \ fi; \ mkdir -p $(DESTDIR)/$(localstatedir)/lib/wok/ + $(MKDIR_P) $(DESTDIR)/$(localstatedir)/lib/wok/logs + $(MKDIR_P) $(DESTDIR)/etc/cron.daily + $(INSTALL_DATA) contrib/cleanlogs.sh $(DESTDIR)/etc/cron.daily/wok-cleanlogs + chmod +x $(DESTDIR)/etc/cron.daily/wok-cleanlogs mkdir -p $(DESTDIR)/$(localstatedir)/log/wok/ touch $(DESTDIR)/$(localstatedir)/log/wok/wok-access.log touch $(DESTDIR)/$(localstatedir)/log/wok/wok-error.log @@ -166,9 +174,11 @@ uninstall-local: if test -d /usr/lib/firewalld/services/; then \ $(RM) $(DESTDIR)/usr/lib/firewalld/services/wokd.xml; \ fi; \ + $(RM) -rf $(DESTDIR)/$(localstatedir)/lib/wok/logs $(RM) -rf $(DESTDIR)/$(localstatedir)/lib/wok $(RM) -rf $(DESTDIR)/$(localstatedir)/log/wok $(RM) -rf $(DESTDIR)/etc/wok + $(RM) $(DESTDIR)/etc/cron.daily/wok-cleanlogs $(RM) $(DESTDIR)/etc/nginx/conf.d/wok.conf $(RM) $(DESTDIR)/etc/logrotate.d/wokd.in $(RM) $(DESTDIR)/etc/logrotate.d/wokd diff --git a/contrib/DEBIAN/control.in b/contrib/DEBIAN/control.in index e585080..bf0e751 100644 --- a/contrib/DEBIAN/control.in +++ b/contrib/DEBIAN/control.in @@ -15,6 +15,7 @@ Depends: python-cherrypy3 (>= 3.2.0), python-psutil (>= 0.6.0), fonts-font-awesome, logrotate, + cron, texlive-fonts-extra Build-Depends: xsltproc, gettext, diff --git a/contrib/Makefile.am b/contrib/Makefile.am index a82ba30..fdc8d2c 100644 --- a/contrib/Makefile.am +++ b/contrib/Makefile.am @@ -30,6 +30,7 @@ EXTRA_DIST = \ wokd-upstart.conf.fedora \ make-deb.sh.in \ wokd.logrotate.in \ + cleanlogs.sh \ $(NULL)
make-deb.sh: make-deb.sh.in $(top_builddir)/config.status diff --git a/contrib/cleanlogs.sh b/contrib/cleanlogs.sh new file mode 100644 index 0000000..b916d67 --- /dev/null +++ b/contrib/cleanlogs.sh @@ -0,0 +1,4 @@ +#!/bin/sh + +DIR=/var/lib/wok/logs +[ -d "$DIR" ] && find "$DIR" -mtime +1 -type f -delete diff --git a/contrib/wok.spec.fedora.in b/contrib/wok.spec.fedora.in index 7715e7f..40b247f 100644 --- a/contrib/wok.spec.fedora.in +++ b/contrib/wok.spec.fedora.in @@ -20,6 +20,7 @@ Requires: python-psutil >= 0.6.0 Requires: fontawesome-fonts Requires: open-sans-fonts Requires: logrotate +Requires: crontabs BuildRequires: gettext-devel BuildRequires: libxslt BuildRequires: openssl @@ -114,6 +115,7 @@ rm -rf $RPM_BUILD_ROOT %{_prefix}/share/locale/*/LC_MESSAGES/wok.mo %{_datadir}/wok/ui/ %{_datadir}/wok +%{_sysconfdir}/cron.daily/wok-cleanlogs %{_sysconfdir}/nginx/conf.d/wok.conf.in %{_sysconfdir}/wok/wok.conf %{_sysconfdir}/wok/ diff --git a/contrib/wok.spec.suse.in b/contrib/wok.spec.suse.in index 3d39483..edbf7a0 100644 --- a/contrib/wok.spec.suse.in +++ b/contrib/wok.spec.suse.in @@ -21,6 +21,7 @@ Requires: python-psutil >= 0.6.0 Requires: fontawesome-fonts Requires: google-opensans-fonts Requires: logrotate +Requires: cronie BuildRequires: gettext-tools BuildRequires: libxslt-tools BuildRequires: openssl @@ -91,6 +92,7 @@ rm -rf $RPM_BUILD_ROOT %{_prefix}/share/locale/*/LC_MESSAGES/wok.mo %{_datadir}/wok/ui/ %{_datadir}/wok +%{_sysconfdir}/cron.daily/wok-cleanlogs %{_sysconfdir}/wok/wok.conf %{_sysconfdir}/wok/ %{_sysconfdir}/nginx/conf.d/wok.conf.in

Signed-off-by: Lucio Correia <luciojhc@linux.vnet.ibm.com> --- src/wok/control/base.py | 81 +++++++++++++++++++++++++++++++++++++++++++++---- src/wok/root.py | 27 +++++++++++++++++ src/wok/server.py | 11 +++++++ src/wok/utils.py | 12 ++++++++ src/wokd.in | 4 +++ 5 files changed, 129 insertions(+), 6 deletions(-) diff --git a/src/wok/control/base.py b/src/wok/control/base.py index 363fd60..f44771e 100644 --- a/src/wok/control/base.py +++ b/src/wok/control/base.py @@ -32,6 +32,15 @@ from wok.control.utils import validate_params from wok.exception import InvalidOperation, InvalidParameter from wok.exception import MissingParameter, NotFoundError from wok.exception import OperationFailed, UnauthorizedError, WokException +from wok.reqlogger import RequestRecord +from wok.utils import get_plugin_from_request + + +LOG_DISABLED_METHODS = ['GET'] + +# Default request log messages +COLLECTION_DEFAULT_LOG = "request on collection" +RESOURCE_DEFAULT_LOG = "request on resource" class Resource(object): @@ -58,6 +67,7 @@ class Resource(object): self.model_args = (ident,) self.role_key = None self.admin_methods = [] + self.log_map = {} def _redirect(self, action_result, code=303): uri_params = [] @@ -102,7 +112,8 @@ class Resource(object): def _generate_action_handler_base(self, action_name, render_fn, destructive=False, action_args=None): def wrapper(*args, **kwargs): - validate_method(('POST'), self.role_key, self.admin_methods) + method = 'POST' + validate_method((method), self.role_key, self.admin_methods) try: self.lookup() if not self.is_authorized(): @@ -137,6 +148,17 @@ class Resource(object): raise cherrypy.HTTPError(500, e.message) except WokException, e: raise cherrypy.HTTPError(500, e.message) + finally: + params = {} + if model_args: + params = {'ident': str(model_args[0])} + + RequestRecord( + self.getRequestMessage(method, action_name) % params, + app=get_plugin_from_request(), + req=method, + user=cherrypy.session.get(USER_NAME, 'N/A') + ).log() wrapper.__name__ = action_name wrapper.exposed = True @@ -162,6 +184,18 @@ class Resource(object): raise cherrypy.HTTPError(500, e.message) except InvalidOperation, e: raise cherrypy.HTTPError(400, e.message) + finally: + method = 'DELETE' + params = {} + if self.model_args: + params = {'ident': str(self.model_args[0])} + + RequestRecord( + self.getRequestMessage(method, 'default') % params, + app=get_plugin_from_request(), + req=method, + user=cherrypy.session.get(USER_NAME, 'N/A') + ).log() @cherrypy.expose def index(self, *args, **kargs): @@ -203,14 +237,23 @@ class Resource(object): return user_name in users or len(set(user_groups) & set(groups)) > 0 def update(self, *args, **kargs): + params = parse_request() + try: update = getattr(self.model, model_fn(self, 'update')) except AttributeError: e = InvalidOperation('WOKAPI0003E', {'resource': get_class_name(self)}) raise cherrypy.HTTPError(405, e.message) + finally: + method = 'PUT' + RequestRecord( + self.getRequestMessage(method) % params, + app=get_plugin_from_request(), + req=method, + user=cherrypy.session.get(USER_NAME, 'N/A') + ).log() - params = parse_request() validate_params(params, self, 'update') args = list(self.model_args) + [params] @@ -222,6 +265,13 @@ class Resource(object): def get(self): return wok.template.render(get_class_name(self), self.data) + def getRequestMessage(self, method, action='default'): + """ + Provide customized user activity log message in inherited classes + through log_map attribute. + """ + return self.log_map.get(method, {}).get(action, RESOURCE_DEFAULT_LOG) + @property def data(self): """ @@ -273,6 +323,7 @@ class Collection(object): self.model_args = [] self.role_key = None self.admin_methods = [] + self.log_map = {} def create(self, params, *args): try: @@ -341,18 +392,28 @@ class Collection(object): data = self.filter_data(resources, fields_filter) return wok.template.render(get_class_name(self), data) + def getRequestMessage(self, method): + """ + Provide customized user activity log message in inherited classes + through log_map attribute. + """ + return self.log_map.get(method, {}).get('default', + COLLECTION_DEFAULT_LOG) + @cherrypy.expose def index(self, *args, **kwargs): + params = {} method = validate_method(('GET', 'POST'), self.role_key, self.admin_methods) try: if method == 'GET': - filter_params = cherrypy.request.params - validate_params(filter_params, self, 'get_list') - return self.get(filter_params) + params = cherrypy.request.params + validate_params(params, self, 'get_list') + return self.get(params) elif method == 'POST': - return self.create(parse_request(), *args) + params = parse_request() + return self.create(params, *args) except InvalidOperation, e: raise cherrypy.HTTPError(400, e.message) except InvalidParameter, e: @@ -365,6 +426,14 @@ class Collection(object): raise cherrypy.HTTPError(500, e.message) except WokException, e: raise cherrypy.HTTPError(500, e.message) + finally: + if method not in LOG_DISABLED_METHODS: + RequestRecord( + self.getRequestMessage(method) % params, + app=get_plugin_from_request(), + req=method, + user=cherrypy.session.get(USER_NAME, 'N/A') + ).log() class AsyncCollection(Collection): diff --git a/src/wok/root.py b/src/wok/root.py index 174a9b9..084613f 100644 --- a/src/wok/root.py +++ b/src/wok/root.py @@ -32,8 +32,17 @@ from wok.control import sub_nodes from wok.control.base import Resource from wok.control.utils import parse_request from wok.exception import MissingParameter, OperationFailed +from wok.reqlogger import RequestRecord +from wok.utils import get_plugin_from_request +ROOT_REQUESTS = { + 'POST': { + 'login': "User '%(username)s' login", + 'logout': "User '%(username)s' logout", + }, +} + class Root(Resource): def __init__(self, model, dev_env=False): super(Root, self).__init__(model) @@ -129,6 +138,7 @@ class WokRoot(Root): self.paths = wok_paths self.domain = 'wok' self.messages = messages + self.log_map = ROOT_REQUESTS @cherrypy.expose def login(self, *args): @@ -144,10 +154,27 @@ class WokRoot(Root): user_info = auth.login(username, password) except OperationFailed: raise cherrypy.HTTPError(401) + finally: + method = 'POST' + RequestRecord( + self.getRequestMessage(method, 'login') % params, + app=get_plugin_from_request(), + req=method, + user=cherrypy.session.get(auth.USER_NAME, 'N/A') + ).log() return json.dumps(user_info) @cherrypy.expose def logout(self): + method = 'POST' + params = {'username': cherrypy.session.get(auth.USER_NAME, 'N/A')} + RequestRecord( + self.getRequestMessage(method, 'logout') % params, + app=get_plugin_from_request(), + req=method, + user=params['username'] + ).log() + auth.logout() return '{}' diff --git a/src/wok/server.py b/src/wok/server.py index 75b41d5..e27124e 100644 --- a/src/wok/server.py +++ b/src/wok/server.py @@ -36,6 +36,7 @@ from wok.model import model from wok.proxy import start_proxy, terminate_proxy from wok.root import WokRoot from wok.safewatchedfilehandler import SafeWatchedFileHandler +from wok.reqlogger import MAX_FILE_SIZE, NUM_BACKUP_FILES, WOK_REQUEST_LOGGER from wok.utils import get_enabled_plugins, import_class LOGGING_LEVEL = {"debug": logging.DEBUG, @@ -65,6 +66,7 @@ class Server(object): start_proxy(options) make_dirs = [ + os.path.abspath(config.get_log_download_path()), os.path.dirname(os.path.abspath(options.access_log)), os.path.dirname(os.path.abspath(options.error_log)), os.path.dirname(os.path.abspath(config.get_object_store())) @@ -130,6 +132,15 @@ class Server(object): # Add error log file to cherrypy configuration cherrypy.log.error_log.addHandler(h) + # Request logger setup + h = logging.handlers.RotatingFileHandler(options.req_log, 'a', + maxBytes=MAX_FILE_SIZE, + backupCount=NUM_BACKUP_FILES) + h.setFormatter(logging.Formatter('%(message)s')) + reqLogger = logging.getLogger(WOK_REQUEST_LOGGER) + reqLogger.setLevel(logging.INFO) + reqLogger.addHandler(h) + # only add logrotate if wok is installed if paths.installed: diff --git a/src/wok/utils.py b/src/wok/utils.py index e2f1d8e..7b1aa06 100644 --- a/src/wok/utils.py +++ b/src/wok/utils.py @@ -120,6 +120,18 @@ def get_all_tabs(): return tabs +def get_plugin_from_request(): + """ + Returns name of plugin being requested. If no plugin, returns 'wok'. + """ + script_name = cherrypy.request.script_name + split = script_name.split('/') + if len(split) > 2 and split[1] == 'plugins': + return split[2] + + return 'wok' + + def import_class(class_path): module_name, class_name = class_path.rsplit('.', 1) try: diff --git a/src/wokd.in b/src/wokd.in index 7255d3c..c91f07a 100644 --- a/src/wokd.in +++ b/src/wokd.in @@ -36,6 +36,7 @@ if not config.paths.installed: ACCESS_LOG = "wok-access.log" ERROR_LOG = "wok-error.log" +REQ_LOG = "wok-req.log" def main(options): @@ -76,6 +77,9 @@ def main(options): parser.add_option('--error-log', default=os.path.join(logDir, ERROR_LOG), help="Error log file") + parser.add_option('--req-log', + default=os.path.join(logDir, REQ_LOG), + help="User Request log file") parser.add_option('--environment', default=runningEnv, help="Running environment of wok server") parser.add_option('--test', action='store_true', -- 1.9.1

On 02/25/2016 05:47 PM, Lucio Correia wrote:
Signed-off-by: Lucio Correia <luciojhc@linux.vnet.ibm.com> --- src/wok/control/base.py | 81 +++++++++++++++++++++++++++++++++++++++++++++---- src/wok/root.py | 27 +++++++++++++++++ src/wok/server.py | 11 +++++++ src/wok/utils.py | 12 ++++++++ src/wokd.in | 4 +++ 5 files changed, 129 insertions(+), 6 deletions(-)
diff --git a/src/wok/control/base.py b/src/wok/control/base.py index 363fd60..f44771e 100644 --- a/src/wok/control/base.py +++ b/src/wok/control/base.py @@ -32,6 +32,15 @@ from wok.control.utils import validate_params from wok.exception import InvalidOperation, InvalidParameter from wok.exception import MissingParameter, NotFoundError from wok.exception import OperationFailed, UnauthorizedError, WokException +from wok.reqlogger import RequestRecord +from wok.utils import get_plugin_from_request + + +LOG_DISABLED_METHODS = ['GET'] + +# Default request log messages +COLLECTION_DEFAULT_LOG = "request on collection" +RESOURCE_DEFAULT_LOG = "request on resource"
class Resource(object): @@ -58,6 +67,7 @@ class Resource(object): self.model_args = (ident,) self.role_key = None self.admin_methods = [] + self.log_map = {}
def _redirect(self, action_result, code=303): uri_params = [] @@ -102,7 +112,8 @@ class Resource(object): def _generate_action_handler_base(self, action_name, render_fn, destructive=False, action_args=None): def wrapper(*args, **kwargs): - validate_method(('POST'), self.role_key, self.admin_methods) + method = 'POST' + validate_method((method), self.role_key, self.admin_methods) try: self.lookup() if not self.is_authorized(): @@ -137,6 +148,17 @@ class Resource(object): raise cherrypy.HTTPError(500, e.message) except WokException, e: raise cherrypy.HTTPError(500, e.message) + finally: + params = {} + if model_args: + params = {'ident': str(model_args[0])} + + RequestRecord( + self.getRequestMessage(method, action_name) % params, + app=get_plugin_from_request(), + req=method, + user=cherrypy.session.get(USER_NAME, 'N/A') + ).log()
wrapper.__name__ = action_name wrapper.exposed = True @@ -162,6 +184,18 @@ class Resource(object): raise cherrypy.HTTPError(500, e.message) except InvalidOperation, e: raise cherrypy.HTTPError(400, e.message) + finally: + method = 'DELETE' + params = {} + if self.model_args: + params = {'ident': str(self.model_args[0])} + + RequestRecord( + self.getRequestMessage(method, 'default') % params, + app=get_plugin_from_request(), + req=method, + user=cherrypy.session.get(USER_NAME, 'N/A') + ).log()
@cherrypy.expose def index(self, *args, **kargs): @@ -203,14 +237,23 @@ class Resource(object): return user_name in users or len(set(user_groups) & set(groups)) > 0
def update(self, *args, **kargs): + params = parse_request() + try: update = getattr(self.model, model_fn(self, 'update')) except AttributeError: e = InvalidOperation('WOKAPI0003E', {'resource': get_class_name(self)}) raise cherrypy.HTTPError(405, e.message) + finally: + method = 'PUT' + RequestRecord( + self.getRequestMessage(method) % params, + app=get_plugin_from_request(), + req=method, + user=cherrypy.session.get(USER_NAME, 'N/A') + ).log()
- params = parse_request() validate_params(params, self, 'update')
args = list(self.model_args) + [params] @@ -222,6 +265,13 @@ class Resource(object): def get(self): return wok.template.render(get_class_name(self), self.data)
+ def getRequestMessage(self, method, action='default'): + """ + Provide customized user activity log message in inherited classes + through log_map attribute. + """ + return self.log_map.get(method, {}).get(action, RESOURCE_DEFAULT_LOG) + @property def data(self): """ @@ -273,6 +323,7 @@ class Collection(object): self.model_args = [] self.role_key = None self.admin_methods = [] + self.log_map = {}
def create(self, params, *args): try: @@ -341,18 +392,28 @@ class Collection(object): data = self.filter_data(resources, fields_filter) return wok.template.render(get_class_name(self), data)
+ def getRequestMessage(self, method): + """ + Provide customized user activity log message in inherited classes + through log_map attribute. + """ + return self.log_map.get(method, {}).get('default', + COLLECTION_DEFAULT_LOG) + @cherrypy.expose def index(self, *args, **kwargs): + params = {} method = validate_method(('GET', 'POST'), self.role_key, self.admin_methods)
try: if method == 'GET': - filter_params = cherrypy.request.params - validate_params(filter_params, self, 'get_list') - return self.get(filter_params) + params = cherrypy.request.params + validate_params(params, self, 'get_list') + return self.get(params) elif method == 'POST': - return self.create(parse_request(), *args) + params = parse_request() + return self.create(params, *args) except InvalidOperation, e: raise cherrypy.HTTPError(400, e.message) except InvalidParameter, e: @@ -365,6 +426,14 @@ class Collection(object): raise cherrypy.HTTPError(500, e.message) except WokException, e: raise cherrypy.HTTPError(500, e.message) + finally: + if method not in LOG_DISABLED_METHODS: + RequestRecord( + self.getRequestMessage(method) % params, + app=get_plugin_from_request(), + req=method, + user=cherrypy.session.get(USER_NAME, 'N/A') + ).log()
class AsyncCollection(Collection): diff --git a/src/wok/root.py b/src/wok/root.py index 174a9b9..084613f 100644 --- a/src/wok/root.py +++ b/src/wok/root.py @@ -32,8 +32,17 @@ from wok.control import sub_nodes from wok.control.base import Resource from wok.control.utils import parse_request from wok.exception import MissingParameter, OperationFailed +from wok.reqlogger import RequestRecord +from wok.utils import get_plugin_from_request
+ROOT_REQUESTS = { + 'POST': { + 'login': "User '%(username)s' login", + 'logout': "User '%(username)s' logout", + }, +} + class Root(Resource): def __init__(self, model, dev_env=False): super(Root, self).__init__(model) @@ -129,6 +138,7 @@ class WokRoot(Root): self.paths = wok_paths self.domain = 'wok' self.messages = messages + self.log_map = ROOT_REQUESTS
@cherrypy.expose def login(self, *args): @@ -144,10 +154,27 @@ class WokRoot(Root): user_info = auth.login(username, password) except OperationFailed: raise cherrypy.HTTPError(401) + finally: + method = 'POST' + RequestRecord( + self.getRequestMessage(method, 'login') % params, + app=get_plugin_from_request(), + req=method, + user=cherrypy.session.get(auth.USER_NAME, 'N/A') + ).log()
return json.dumps(user_info)
@cherrypy.expose def logout(self): + method = 'POST' + params = {'username': cherrypy.session.get(auth.USER_NAME, 'N/A')} + RequestRecord( + self.getRequestMessage(method, 'logout') % params, + app=get_plugin_from_request(), + req=method, + user=params['username'] + ).log() + auth.logout() return '{}' diff --git a/src/wok/server.py b/src/wok/server.py index 75b41d5..e27124e 100644 --- a/src/wok/server.py +++ b/src/wok/server.py @@ -36,6 +36,7 @@ from wok.model import model from wok.proxy import start_proxy, terminate_proxy from wok.root import WokRoot from wok.safewatchedfilehandler import SafeWatchedFileHandler +from wok.reqlogger import MAX_FILE_SIZE, NUM_BACKUP_FILES, WOK_REQUEST_LOGGER from wok.utils import get_enabled_plugins, import_class
LOGGING_LEVEL = {"debug": logging.DEBUG, @@ -65,6 +66,7 @@ class Server(object): start_proxy(options)
make_dirs = [ + os.path.abspath(config.get_log_download_path()), os.path.dirname(os.path.abspath(options.access_log)), os.path.dirname(os.path.abspath(options.error_log)), os.path.dirname(os.path.abspath(config.get_object_store())) @@ -130,6 +132,15 @@ class Server(object): # Add error log file to cherrypy configuration cherrypy.log.error_log.addHandler(h)
+ # Request logger setup + h = logging.handlers.RotatingFileHandler(options.req_log, 'a', + maxBytes=MAX_FILE_SIZE, + backupCount=NUM_BACKUP_FILES) + h.setFormatter(logging.Formatter('%(message)s')) + reqLogger = logging.getLogger(WOK_REQUEST_LOGGER) + reqLogger.setLevel(logging.INFO) + reqLogger.addHandler(h) +
There was a recent change on wok to use a thread safe logging (commit 3aad7ba93d0228650af8c95101addd561140cef7) Maybe it will be better to use it in this case too. Ziviani, as you did the patch about the logging, could you advice on that?
# only add logrotate if wok is installed if paths.installed:
diff --git a/src/wok/utils.py b/src/wok/utils.py index e2f1d8e..7b1aa06 100644 --- a/src/wok/utils.py +++ b/src/wok/utils.py @@ -120,6 +120,18 @@ def get_all_tabs(): return tabs
+def get_plugin_from_request(): + """ + Returns name of plugin being requested. If no plugin, returns 'wok'. + """ + script_name = cherrypy.request.script_name + split = script_name.split('/') + if len(split) > 2 and split[1] == 'plugins': + return split[2] + + return 'wok' + + def import_class(class_path): module_name, class_name = class_path.rsplit('.', 1) try: diff --git a/src/wokd.in b/src/wokd.in index 7255d3c..c91f07a 100644 --- a/src/wokd.in +++ b/src/wokd.in @@ -36,6 +36,7 @@ if not config.paths.installed:
ACCESS_LOG = "wok-access.log" ERROR_LOG = "wok-error.log" +REQ_LOG = "wok-req.log"
def main(options): @@ -76,6 +77,9 @@ def main(options): parser.add_option('--error-log', default=os.path.join(logDir, ERROR_LOG), help="Error log file") + parser.add_option('--req-log', + default=os.path.join(logDir, REQ_LOG), + help="User Request log file") parser.add_option('--environment', default=runningEnv, help="Running environment of wok server") parser.add_option('--test', action='store_true',

On 26-02-2016 10:40, Aline Manera wrote:
diff --git a/src/wok/server.py b/src/wok/server.py index 75b41d5..e27124e 100644 --- a/src/wok/server.py +++ b/src/wok/server.py @@ -36,6 +36,7 @@ from wok.model import model from wok.proxy import start_proxy, terminate_proxy from wok.root import WokRoot from wok.safewatchedfilehandler import SafeWatchedFileHandler +from wok.reqlogger import MAX_FILE_SIZE, NUM_BACKUP_FILES, WOK_REQUEST_LOGGER from wok.utils import get_enabled_plugins, import_class
LOGGING_LEVEL = {"debug": logging.DEBUG, @@ -65,6 +66,7 @@ class Server(object): start_proxy(options)
make_dirs = [ + os.path.abspath(config.get_log_download_path()), os.path.dirname(os.path.abspath(options.access_log)), os.path.dirname(os.path.abspath(options.error_log)), os.path.dirname(os.path.abspath(config.get_object_store())) @@ -130,6 +132,15 @@ class Server(object): # Add error log file to cherrypy configuration cherrypy.log.error_log.addHandler(h)
+ # Request logger setup + h = logging.handlers.RotatingFileHandler(options.req_log, 'a', + maxBytes=MAX_FILE_SIZE, + backupCount=NUM_BACKUP_FILES) + h.setFormatter(logging.Formatter('%(message)s')) + reqLogger = logging.getLogger(WOK_REQUEST_LOGGER) + reqLogger.setLevel(logging.INFO) + reqLogger.addHandler(h) +
There was a recent change on wok to use a thread safe logging (commit 3aad7ba93d0228650af8c95101addd561140cef7)
Maybe it will be better to use it in this case too.
Ziviani, as you did the patch about the logging, could you advice on that?
That one uses WatchedFileHandler, not RotatingFileHandler I've used. What can be done is to make a SafeRotatingFileHandler similar to the SafeWatchedFileHandler made by Ziviani. Does it make sense? -- Lucio Correia Software Engineer IBM LTC Brazil

On 26-02-2016 10:40, Aline Manera wrote:
On 02/25/2016 05:47 PM, Lucio Correia wrote:
Signed-off-by: Lucio Correia <luciojhc@linux.vnet.ibm.com> --- src/wok/control/base.py | 81 +++++++++++++++++++++++++++++++++++++++++++++---- src/wok/root.py | 27 +++++++++++++++++ src/wok/server.py | 11 +++++++ src/wok/utils.py | 12 ++++++++ src/wokd.in | 4 +++ 5 files changed, 129 insertions(+), 6 deletions(-)
diff --git a/src/wok/control/base.py b/src/wok/control/base.py index 363fd60..f44771e 100644 --- a/src/wok/control/base.py +++ b/src/wok/control/base.py @@ -32,6 +32,15 @@ from wok.control.utils import validate_params from wok.exception import InvalidOperation, InvalidParameter from wok.exception import MissingParameter, NotFoundError from wok.exception import OperationFailed, UnauthorizedError, WokException +from wok.reqlogger import RequestRecord +from wok.utils import get_plugin_from_request + + +LOG_DISABLED_METHODS = ['GET'] + +# Default request log messages +COLLECTION_DEFAULT_LOG = "request on collection" +RESOURCE_DEFAULT_LOG = "request on resource"
class Resource(object): @@ -58,6 +67,7 @@ class Resource(object): self.model_args = (ident,) self.role_key = None self.admin_methods = [] + self.log_map = {}
def _redirect(self, action_result, code=303): uri_params = [] @@ -102,7 +112,8 @@ class Resource(object): def _generate_action_handler_base(self, action_name, render_fn, destructive=False, action_args=None): def wrapper(*args, **kwargs): - validate_method(('POST'), self.role_key, self.admin_methods) + method = 'POST' + validate_method((method), self.role_key, self.admin_methods) try: self.lookup() if not self.is_authorized(): @@ -137,6 +148,17 @@ class Resource(object): raise cherrypy.HTTPError(500, e.message) except WokException, e: raise cherrypy.HTTPError(500, e.message) + finally: + params = {} + if model_args: + params = {'ident': str(model_args[0])} + + RequestRecord( + self.getRequestMessage(method, action_name) % params, + app=get_plugin_from_request(), + req=method, + user=cherrypy.session.get(USER_NAME, 'N/A') + ).log()
wrapper.__name__ = action_name wrapper.exposed = True @@ -162,6 +184,18 @@ class Resource(object): raise cherrypy.HTTPError(500, e.message) except InvalidOperation, e: raise cherrypy.HTTPError(400, e.message) + finally: + method = 'DELETE' + params = {} + if self.model_args: + params = {'ident': str(self.model_args[0])} + + RequestRecord( + self.getRequestMessage(method, 'default') % params, + app=get_plugin_from_request(), + req=method, + user=cherrypy.session.get(USER_NAME, 'N/A') + ).log()
@cherrypy.expose def index(self, *args, **kargs): @@ -203,14 +237,23 @@ class Resource(object): return user_name in users or len(set(user_groups) & set(groups)) > 0
def update(self, *args, **kargs): + params = parse_request() + try: update = getattr(self.model, model_fn(self, 'update')) except AttributeError: e = InvalidOperation('WOKAPI0003E', {'resource': get_class_name(self)}) raise cherrypy.HTTPError(405, e.message) + finally: + method = 'PUT' + RequestRecord( + self.getRequestMessage(method) % params, + app=get_plugin_from_request(), + req=method, + user=cherrypy.session.get(USER_NAME, 'N/A') + ).log()
- params = parse_request() validate_params(params, self, 'update')
args = list(self.model_args) + [params] @@ -222,6 +265,13 @@ class Resource(object): def get(self): return wok.template.render(get_class_name(self), self.data)
+ def getRequestMessage(self, method, action='default'): + """ + Provide customized user activity log message in inherited classes + through log_map attribute. + """ + return self.log_map.get(method, {}).get(action, RESOURCE_DEFAULT_LOG) + @property def data(self): """ @@ -273,6 +323,7 @@ class Collection(object): self.model_args = [] self.role_key = None self.admin_methods = [] + self.log_map = {}
def create(self, params, *args): try: @@ -341,18 +392,28 @@ class Collection(object): data = self.filter_data(resources, fields_filter) return wok.template.render(get_class_name(self), data)
+ def getRequestMessage(self, method): + """ + Provide customized user activity log message in inherited classes + through log_map attribute. + """ + return self.log_map.get(method, {}).get('default', + COLLECTION_DEFAULT_LOG) + @cherrypy.expose def index(self, *args, **kwargs): + params = {} method = validate_method(('GET', 'POST'), self.role_key, self.admin_methods)
try: if method == 'GET': - filter_params = cherrypy.request.params - validate_params(filter_params, self, 'get_list') - return self.get(filter_params) + params = cherrypy.request.params + validate_params(params, self, 'get_list') + return self.get(params) elif method == 'POST': - return self.create(parse_request(), *args) + params = parse_request() + return self.create(params, *args) except InvalidOperation, e: raise cherrypy.HTTPError(400, e.message) except InvalidParameter, e: @@ -365,6 +426,14 @@ class Collection(object): raise cherrypy.HTTPError(500, e.message) except WokException, e: raise cherrypy.HTTPError(500, e.message) + finally: + if method not in LOG_DISABLED_METHODS: + RequestRecord( + self.getRequestMessage(method) % params, + app=get_plugin_from_request(), + req=method, + user=cherrypy.session.get(USER_NAME, 'N/A') + ).log()
class AsyncCollection(Collection): diff --git a/src/wok/root.py b/src/wok/root.py index 174a9b9..084613f 100644 --- a/src/wok/root.py +++ b/src/wok/root.py @@ -32,8 +32,17 @@ from wok.control import sub_nodes from wok.control.base import Resource from wok.control.utils import parse_request from wok.exception import MissingParameter, OperationFailed +from wok.reqlogger import RequestRecord +from wok.utils import get_plugin_from_request
+ROOT_REQUESTS = { + 'POST': { + 'login': "User '%(username)s' login", + 'logout': "User '%(username)s' logout", + }, +} + class Root(Resource): def __init__(self, model, dev_env=False): super(Root, self).__init__(model) @@ -129,6 +138,7 @@ class WokRoot(Root): self.paths = wok_paths self.domain = 'wok' self.messages = messages + self.log_map = ROOT_REQUESTS
@cherrypy.expose def login(self, *args): @@ -144,10 +154,27 @@ class WokRoot(Root): user_info = auth.login(username, password) except OperationFailed: raise cherrypy.HTTPError(401) + finally: + method = 'POST' + RequestRecord( + self.getRequestMessage(method, 'login') % params, + app=get_plugin_from_request(), + req=method, + user=cherrypy.session.get(auth.USER_NAME, 'N/A') + ).log()
return json.dumps(user_info)
@cherrypy.expose def logout(self): + method = 'POST' + params = {'username': cherrypy.session.get(auth.USER_NAME, 'N/A')} + RequestRecord( + self.getRequestMessage(method, 'logout') % params, + app=get_plugin_from_request(), + req=method, + user=params['username'] + ).log() + auth.logout() return '{}' diff --git a/src/wok/server.py b/src/wok/server.py index 75b41d5..e27124e 100644 --- a/src/wok/server.py +++ b/src/wok/server.py @@ -36,6 +36,7 @@ from wok.model import model from wok.proxy import start_proxy, terminate_proxy from wok.root import WokRoot from wok.safewatchedfilehandler import SafeWatchedFileHandler +from wok.reqlogger import MAX_FILE_SIZE, NUM_BACKUP_FILES, WOK_REQUEST_LOGGER from wok.utils import get_enabled_plugins, import_class
LOGGING_LEVEL = {"debug": logging.DEBUG, @@ -65,6 +66,7 @@ class Server(object): start_proxy(options)
make_dirs = [ + os.path.abspath(config.get_log_download_path()), os.path.dirname(os.path.abspath(options.access_log)), os.path.dirname(os.path.abspath(options.error_log)), os.path.dirname(os.path.abspath(config.get_object_store())) @@ -130,6 +132,15 @@ class Server(object): # Add error log file to cherrypy configuration cherrypy.log.error_log.addHandler(h)
+ # Request logger setup + h = logging.handlers.RotatingFileHandler(options.req_log, 'a', + maxBytes=MAX_FILE_SIZE, + backupCount=NUM_BACKUP_FILES) + h.setFormatter(logging.Formatter('%(message)s')) + reqLogger = logging.getLogger(WOK_REQUEST_LOGGER) + reqLogger.setLevel(logging.INFO) + reqLogger.addHandler(h) +
There was a recent change on wok to use a thread safe logging (commit 3aad7ba93d0228650af8c95101addd561140cef7)
Maybe it will be better to use it in this case too.
Ziviani, as you did the patch about the logging, could you advice on that?
Hello! Only the handler to "options.error_log" is required to use SafeWatchedFileHandler because the web serial console writes to that in a different process. In this case it's not necessary (unless we need to use this req_log in other processes as well.)
# only add logrotate if wok is installed if paths.installed:
diff --git a/src/wok/utils.py b/src/wok/utils.py index e2f1d8e..7b1aa06 100644 --- a/src/wok/utils.py +++ b/src/wok/utils.py @@ -120,6 +120,18 @@ def get_all_tabs(): return tabs
+def get_plugin_from_request(): + """ + Returns name of plugin being requested. If no plugin, returns 'wok'. + """ + script_name = cherrypy.request.script_name + split = script_name.split('/') + if len(split) > 2 and split[1] == 'plugins': + return split[2] + + return 'wok' + + def import_class(class_path): module_name, class_name = class_path.rsplit('.', 1) try: diff --git a/src/wokd.in b/src/wokd.in index 7255d3c..c91f07a 100644 --- a/src/wokd.in +++ b/src/wokd.in @@ -36,6 +36,7 @@ if not config.paths.installed:
ACCESS_LOG = "wok-access.log" ERROR_LOG = "wok-error.log" +REQ_LOG = "wok-req.log"
def main(options): @@ -76,6 +77,9 @@ def main(options): parser.add_option('--error-log', default=os.path.join(logDir, ERROR_LOG), help="Error log file") + parser.add_option('--req-log', + default=os.path.join(logDir, REQ_LOG), + help="User Request log file") parser.add_option('--environment', default=runningEnv, help="Running environment of wok server") parser.add_option('--test', action='store_true',
_______________________________________________ Kimchi-devel mailing list Kimchi-devel@ovirt.org http://lists.ovirt.org/mailman/listinfo/kimchi-devel
-- Jose Ricardo Ziviani ----------------------------- Software Engineer Linux Technology Center - IBM

On 02/25/2016 05:47 PM, Lucio Correia wrote:
Signed-off-by: Lucio Correia <luciojhc@linux.vnet.ibm.com> --- src/wok/control/base.py | 81 +++++++++++++++++++++++++++++++++++++++++++++---- src/wok/root.py | 27 +++++++++++++++++ src/wok/server.py | 11 +++++++ src/wok/utils.py | 12 ++++++++ src/wokd.in | 4 +++ 5 files changed, 129 insertions(+), 6 deletions(-)
diff --git a/src/wok/control/base.py b/src/wok/control/base.py index 363fd60..f44771e 100644 --- a/src/wok/control/base.py +++ b/src/wok/control/base.py @@ -32,6 +32,15 @@ from wok.control.utils import validate_params from wok.exception import InvalidOperation, InvalidParameter from wok.exception import MissingParameter, NotFoundError from wok.exception import OperationFailed, UnauthorizedError, WokException +from wok.reqlogger import RequestRecord +from wok.utils import get_plugin_from_request + + +LOG_DISABLED_METHODS = ['GET'] + +# Default request log messages +COLLECTION_DEFAULT_LOG = "request on collection" +RESOURCE_DEFAULT_LOG = "request on resource"
class Resource(object): @@ -58,6 +67,7 @@ class Resource(object): self.model_args = (ident,) self.role_key = None self.admin_methods = [] + self.log_map = {}
def _redirect(self, action_result, code=303): uri_params = [] @@ -102,7 +112,8 @@ class Resource(object): def _generate_action_handler_base(self, action_name, render_fn, destructive=False, action_args=None): def wrapper(*args, **kwargs): - validate_method(('POST'), self.role_key, self.admin_methods) + method = 'POST' + validate_method((method), self.role_key, self.admin_methods) try: self.lookup() if not self.is_authorized(): @@ -137,6 +148,17 @@ class Resource(object): raise cherrypy.HTTPError(500, e.message) except WokException, e: raise cherrypy.HTTPError(500, e.message) + finally: + params = {} + if model_args: + params = {'ident': str(model_args[0])} + + RequestRecord( + self.getRequestMessage(method, action_name) % params, + app=get_plugin_from_request(), + req=method, + user=cherrypy.session.get(USER_NAME, 'N/A') + ).log()
wrapper.__name__ = action_name wrapper.exposed = True @@ -162,6 +184,18 @@ class Resource(object): raise cherrypy.HTTPError(500, e.message) except InvalidOperation, e: raise cherrypy.HTTPError(400, e.message) + finally: + method = 'DELETE' + params = {} + if self.model_args: + params = {'ident': str(self.model_args[0])} + + RequestRecord( + self.getRequestMessage(method, 'default') % params, + app=get_plugin_from_request(), + req=method, + user=cherrypy.session.get(USER_NAME, 'N/A') + ).log()
@cherrypy.expose def index(self, *args, **kargs): @@ -203,14 +237,23 @@ class Resource(object): return user_name in users or len(set(user_groups) & set(groups)) > 0
def update(self, *args, **kargs): + params = parse_request() + try: update = getattr(self.model, model_fn(self, 'update')) except AttributeError: e = InvalidOperation('WOKAPI0003E', {'resource': get_class_name(self)}) raise cherrypy.HTTPError(405, e.message) + finally: + method = 'PUT' + RequestRecord( + self.getRequestMessage(method) % params, + app=get_plugin_from_request(), + req=method, + user=cherrypy.session.get(USER_NAME, 'N/A') + ).log()
- params = parse_request() validate_params(params, self, 'update')
args = list(self.model_args) + [params] @@ -222,6 +265,13 @@ class Resource(object): def get(self): return wok.template.render(get_class_name(self), self.data)
+ def getRequestMessage(self, method, action='default'): + """ + Provide customized user activity log message in inherited classes + through log_map attribute. + """ + return self.log_map.get(method, {}).get(action, RESOURCE_DEFAULT_LOG) + @property def data(self): """ @@ -273,6 +323,7 @@ class Collection(object): self.model_args = [] self.role_key = None self.admin_methods = [] + self.log_map = {}
def create(self, params, *args): try: @@ -341,18 +392,28 @@ class Collection(object): data = self.filter_data(resources, fields_filter) return wok.template.render(get_class_name(self), data)
+ def getRequestMessage(self, method): + """ + Provide customized user activity log message in inherited classes + through log_map attribute. + """ + return self.log_map.get(method, {}).get('default', + COLLECTION_DEFAULT_LOG) + @cherrypy.expose def index(self, *args, **kwargs): + params = {} method = validate_method(('GET', 'POST'), self.role_key, self.admin_methods)
try: if method == 'GET': - filter_params = cherrypy.request.params - validate_params(filter_params, self, 'get_list') - return self.get(filter_params) + params = cherrypy.request.params + validate_params(params, self, 'get_list') + return self.get(params) elif method == 'POST': - return self.create(parse_request(), *args) + params = parse_request() + return self.create(params, *args) except InvalidOperation, e: raise cherrypy.HTTPError(400, e.message) except InvalidParameter, e: @@ -365,6 +426,14 @@ class Collection(object): raise cherrypy.HTTPError(500, e.message) except WokException, e: raise cherrypy.HTTPError(500, e.message) + finally: + if method not in LOG_DISABLED_METHODS: + RequestRecord( + self.getRequestMessage(method) % params, + app=get_plugin_from_request(), + req=method, + user=cherrypy.session.get(USER_NAME, 'N/A') + ).log()
class AsyncCollection(Collection): diff --git a/src/wok/root.py b/src/wok/root.py index 174a9b9..084613f 100644 --- a/src/wok/root.py +++ b/src/wok/root.py @@ -32,8 +32,17 @@ from wok.control import sub_nodes from wok.control.base import Resource from wok.control.utils import parse_request from wok.exception import MissingParameter, OperationFailed +from wok.reqlogger import RequestRecord +from wok.utils import get_plugin_from_request
+ROOT_REQUESTS = { + 'POST': { + 'login': "User '%(username)s' login", + 'logout': "User '%(username)s' logout", + }, +} + class Root(Resource): def __init__(self, model, dev_env=False): super(Root, self).__init__(model) @@ -129,6 +138,7 @@ class WokRoot(Root): self.paths = wok_paths self.domain = 'wok' self.messages = messages + self.log_map = ROOT_REQUESTS
@cherrypy.expose def login(self, *args): @@ -144,10 +154,27 @@ class WokRoot(Root): user_info = auth.login(username, password) except OperationFailed: raise cherrypy.HTTPError(401) + finally: + method = 'POST' + RequestRecord( + self.getRequestMessage(method, 'login') % params, + app=get_plugin_from_request(), + req=method, + user=cherrypy.session.get(auth.USER_NAME, 'N/A') + ).log()
return json.dumps(user_info)
@cherrypy.expose def logout(self): + method = 'POST' + params = {'username': cherrypy.session.get(auth.USER_NAME, 'N/A')} + RequestRecord( + self.getRequestMessage(method, 'logout') % params, + app=get_plugin_from_request(), + req=method, + user=params['username'] + ).log() + auth.logout() return '{}' diff --git a/src/wok/server.py b/src/wok/server.py index 75b41d5..e27124e 100644 --- a/src/wok/server.py +++ b/src/wok/server.py @@ -36,6 +36,7 @@ from wok.model import model from wok.proxy import start_proxy, terminate_proxy from wok.root import WokRoot from wok.safewatchedfilehandler import SafeWatchedFileHandler +from wok.reqlogger import MAX_FILE_SIZE, NUM_BACKUP_FILES, WOK_REQUEST_LOGGER from wok.utils import get_enabled_plugins, import_class
LOGGING_LEVEL = {"debug": logging.DEBUG, @@ -65,6 +66,7 @@ class Server(object): start_proxy(options)
make_dirs = [ + os.path.abspath(config.get_log_download_path()), os.path.dirname(os.path.abspath(options.access_log)), os.path.dirname(os.path.abspath(options.error_log)), os.path.dirname(os.path.abspath(config.get_object_store())) @@ -130,6 +132,15 @@ class Server(object): # Add error log file to cherrypy configuration cherrypy.log.error_log.addHandler(h)
+ # Request logger setup + h = logging.handlers.RotatingFileHandler(options.req_log, 'a', + maxBytes=MAX_FILE_SIZE, + backupCount=NUM_BACKUP_FILES) + h.setFormatter(logging.Formatter('%(message)s')) + reqLogger = logging.getLogger(WOK_REQUEST_LOGGER) + reqLogger.setLevel(logging.INFO) + reqLogger.addHandler(h) + # only add logrotate if wok is installed if paths.installed:
diff --git a/src/wok/utils.py b/src/wok/utils.py index e2f1d8e..7b1aa06 100644 --- a/src/wok/utils.py +++ b/src/wok/utils.py @@ -120,6 +120,18 @@ def get_all_tabs(): return tabs
+def get_plugin_from_request(): + """ + Returns name of plugin being requested. If no plugin, returns 'wok'. + """ + script_name = cherrypy.request.script_name + split = script_name.split('/') + if len(split) > 2 and split[1] == 'plugins': + return split[2] + + return 'wok' + + def import_class(class_path): module_name, class_name = class_path.rsplit('.', 1) try: diff --git a/src/wokd.in b/src/wokd.in index 7255d3c..c91f07a 100644 --- a/src/wokd.in +++ b/src/wokd.in @@ -36,6 +36,7 @@ if not config.paths.installed:
ACCESS_LOG = "wok-access.log" ERROR_LOG = "wok-error.log" +REQ_LOG = "wok-req.log"
def main(options): @@ -76,6 +77,9 @@ def main(options): parser.add_option('--error-log', default=os.path.join(logDir, ERROR_LOG), help="Error log file")
+ parser.add_option('--req-log', + default=os.path.join(logDir, REQ_LOG), + help="User Request log file")
What is the proposal of this option? I don't think we can let the user change the log file directory as the cherrpy configuration depends on that.
parser.add_option('--environment', default=runningEnv, help="Running environment of wok server") parser.add_option('--test', action='store_true',

On 26-02-2016 10:41, Aline Manera wrote:
diff --git a/src/wokd.in b/src/wokd.in index 7255d3c..c91f07a 100644 --- a/src/wokd.in +++ b/src/wokd.in @@ -36,6 +36,7 @@ if not config.paths.installed:
ACCESS_LOG = "wok-access.log" ERROR_LOG = "wok-error.log" +REQ_LOG = "wok-req.log"
def main(options): @@ -76,6 +77,9 @@ def main(options): parser.add_option('--error-log', default=os.path.join(logDir, ERROR_LOG), help="Error log file")
+ parser.add_option('--req-log', + default=os.path.join(logDir, REQ_LOG), + help="User Request log file")
What is the proposal of this option? I don't think we can let the user change the log file directory as the cherrpy configuration depends on that.
There are two places where files are save. This one is for saving the JSON log, and it's saved in the same directory of the other cherrypy logs, wok-access and wok-error. The option was added to keep the same behaviour of these logs. The temporary logs, for the download functionality, are saved in another directory, which cannot be changed. -- Lucio Correia Software Engineer IBM LTC Brazil

On 02/26/2016 10:47 AM, Lucio Correia wrote:
On 26-02-2016 10:41, Aline Manera wrote:
diff --git a/src/wokd.in b/src/wokd.in index 7255d3c..c91f07a 100644 --- a/src/wokd.in +++ b/src/wokd.in @@ -36,6 +36,7 @@ if not config.paths.installed:
ACCESS_LOG = "wok-access.log" ERROR_LOG = "wok-error.log" +REQ_LOG = "wok-req.log"
def main(options): @@ -76,6 +77,9 @@ def main(options): parser.add_option('--error-log', default=os.path.join(logDir, ERROR_LOG), help="Error log file")
+ parser.add_option('--req-log', + default=os.path.join(logDir, REQ_LOG), + help="User Request log file")
What is the proposal of this option? I don't think we can let the user change the log file directory as the cherrpy configuration depends on that.
There are two places where files are save.
This one is for saving the JSON log, and it's saved in the same directory of the other cherrypy logs, wok-access and wok-error. The option was added to keep the same behaviour of these logs.
The temporary logs, for the download functionality, are saved in another directory, which cannot be changed.
I don't think it is needed We can have only one place to save the log files. Otherwise, it is hard to understand (from an user point of view) the difference between the 2 logs

Signed-off-by: Lucio Correia <luciojhc@linux.vnet.ibm.com> --- docs/API/logs.md | 27 +++++++++++++++++++++++++++ src/wok/control/logs.py | 43 +++++++++++++++++++++++++++++++++++++++++++ src/wok/model/logs.py | 31 +++++++++++++++++++++++++++++++ 3 files changed, 101 insertions(+) create mode 100644 docs/API/logs.md create mode 100644 src/wok/control/logs.py create mode 100644 src/wok/model/logs.py diff --git a/docs/API/logs.md b/docs/API/logs.md new file mode 100644 index 0000000..f808e1a --- /dev/null +++ b/docs/API/logs.md @@ -0,0 +1,27 @@ +## REST API Specification for Logs + +### Collection: Logs + +**URI:** /logs + +**Methods:** + +* **GET**: Retrieve a list of entries from User Request Log + * Parameters: + * app: Filter entries by application that received the request. + Use "wok" or any plugin installed, like "kimchi". + * req: Filter entries by type of request: "DELETE", "POST", "PUT". + "GET" requests are not logged. + * user: Filter entries by user that performed the request. + * date: Filter entries by date of record in the format "YYYY-MM-DD" + * download: Generate text file for download of search results. + +#### Examples +GET /logs?download=True +{'records': [{entry-record1}, {entry-record2}, {entry-record3}, ...], +'uri': "/data/logs/tmpbnOzP2.txt"} + +GET /logs?user=dev&app=ginger +{'records': [{entry-record1}, {entry-record2}, {entry-record3}, ...], +'uri': None} + diff --git a/src/wok/control/logs.py b/src/wok/control/logs.py new file mode 100644 index 0000000..0eb04d7 --- /dev/null +++ b/src/wok/control/logs.py @@ -0,0 +1,43 @@ +# +# Project Wok +# +# Copyright IBM Corp, 2016 +# +# This library is free software; you can redistribute it and/or +# modify it under the terms of the GNU Lesser General Public +# License as published by the Free Software Foundation; either +# version 2.1 of the License, or (at your option) any later version. +# +# This library is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU +# Lesser General Public License for more details. +# +# You should have received a copy of the GNU Lesser General Public +# License along with this library; if not, write to the Free Software +# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA + +import wok.template + +from wok.control.base import SimpleCollection +from wok.control.utils import get_class_name, model_fn +from wok.control.utils import UrlSubNode + + +@UrlSubNode("logs") +class Logs(SimpleCollection): + def __init__(self, model): + super(Logs, self).__init__(model) + self.role_key = 'logs' + self.admin_methods = ['GET'] + + def get(self, filter_params): + res_list = [] + + try: + get_list = getattr(self.model, model_fn(self, 'get_list')) + res_list = get_list(filter_params) + except AttributeError: + pass + + return wok.template.render(get_class_name(self), res_list) diff --git a/src/wok/model/logs.py b/src/wok/model/logs.py new file mode 100644 index 0000000..89a79ab --- /dev/null +++ b/src/wok/model/logs.py @@ -0,0 +1,31 @@ +# +# Project Wok +# +# Copyright IBM Corp, 2016 +# +# This library is free software; you can redistribute it and/or +# modify it under the terms of the GNU Lesser General Public +# License as published by the Free Software Foundation; either +# version 2.1 of the License, or (at your option) any later version. +# +# This library is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU +# Lesser General Public License for more details. +# +# You should have received a copy of the GNU Lesser General Public +# License along with this library; if not, write to the Free Software +# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA + +from wok.reqlogger import RequestParser + + +class LogsModel(object): + def __init__(self, **kargs): + pass + + def get_list(self, filter_params): + if filter_params: + return RequestParser().getFilteredRecords(filter_params) + + return RequestParser().getRecords() -- 1.9.1

Signed-off-by: Lucio Correia <luciojhc@linux.vnet.ibm.com> --- tests/utils.py | 1 + 1 file changed, 1 insertion(+) diff --git a/tests/utils.py b/tests/utils.py index d158ba1..249205d 100644 --- a/tests/utils.py +++ b/tests/utils.py @@ -119,6 +119,7 @@ def run_server(host, port, ssl_port, test_mode, cherrypy_port=None, 'websockets_port': 64667, 'ssl_cert': '', 'ssl_key': '', 'max_body_size': '4*1024', 'test': test_mode, 'access_log': '/dev/null', 'error_log': '/dev/null', + 'req_log': '/dev/null', 'environment': environment, 'log_level': 'debug'})() if model is not None: setattr(args, 'model', model) -- 1.9.1
participants (3)
-
Aline Manera
-
Jose Ricardo Ziviani
-
Lucio Correia