Commit f61d6a95 authored by Łukasz Nowak's avatar Łukasz Nowak

kedifa: Implement logging

Logging is better than just printing out things, as times are added and also
they are much better rotated, with controlled retention.
parent c89c31a5
......@@ -24,6 +24,7 @@ from wsgiref.simple_server import make_server
import caucase.exceptions
import caucase.http
import caucase.utils
from caucase.http_wsgibase import CleanServerHandler
import datetime
import json
import os
......@@ -33,6 +34,8 @@ import sqlite3
import ssl
import string
import urlparse
import logging
import logging.handlers
class UserExists(Exception):
......@@ -510,11 +513,57 @@ class Reloader(object):
# what is actually used when accepting a connection - so the update
# is actually successful.
pass
print 'KeDiFa reloaded.'
logger.warning('KeDiFa reloaded.')
def http(host, port, pocket, certificate, ca_certificate, crl, pidfile):
pidfile.write(str(os.getpid()))
logger = logging.getLogger('kedifa')
def setuplog(logfile):
if logfile == '-':
ch = logging.StreamHandler()
else:
ch = logging.handlers.WatchedFileHandler(logfile)
formatter = logging.Formatter(
'%(asctime)s - %(name)s - %(levelname)s - %(message)s')
ch.setFormatter(formatter)
logger.addHandler(ch)
logger.setLevel(logging.INFO)
class KedifaSSLWSGIRequestHandler(caucase.http.CaucaseSSLWSGIRequestHandler):
def log_message(self, format, *args):
"""
Log an arbitrary message.
Compared to caucase.http.CaucaseSSLWSGIRequestHandler:
- use logger
"""
logger.info(
'%s - %s [%s] %s',
self.client_address[0],
self.remote_user_name,
self.log_date_time_string(),
format % args,
)
def log_exception(self, exc_info):
try:
logger.exception(
'Exception while handling the request:', exc_info=exc_info)
finally:
exc_info = None
CleanServerHandler.log_exception = log_exception
def http(host, port, pocket, certificate, ca_certificate, crl, pidfile,
logfile):
setuplog(logfile)
pid = str(os.getpid())
pidfile.write(pid)
pidfile.close()
kedifa = Kedifa(pocket, ca_certificate, crl)
if ':' in host:
......@@ -523,7 +572,8 @@ def http(host, port, pocket, certificate, ca_certificate, crl, pidfile):
access_format = 'https://%s:%s/'
httpd = make_server(
host, port, kedifa, caucase.http.ThreadingWSGIServer,
caucase.http.CaucaseSSLWSGIRequestHandler)
KedifaSSLWSGIRequestHandler
)
ssl_context = getSSLContext(certificate.name, ca_certificate.name, crl.name)
httpd.socket = ssl_context.wrap_socket(
httpd.socket,
......@@ -536,7 +586,9 @@ def http(host, port, pocket, certificate, ca_certificate, crl, pidfile):
httpd.server_close()
raise
print 'Kedifa started at', access_format % httpd.server_address[:2]
logger.info(
'Kedifa started at %s with pid %s stored in %s',
access_format % httpd.server_address[:2], pid, pidfile.name)
reloader = Reloader(
httpd, kedifa, certificate.name, ca_certificate.name, crl.name)
......
......@@ -71,10 +71,16 @@ def http(*args):
help='Path to PID file.',
required=True
)
parser.add_argument(
'--logfile',
type=str,
help='Path to logfile.',
default='-'
)
parsed = parser.parse_args(args)
app.http(parsed.ip, parsed.port, parsed.db, parsed.certificate,
parsed.ca_certificate, parsed.crl, parsed.pidfile)
parsed.ca_certificate, parsed.crl, parsed.pidfile, parsed.logfile)
def getter(*args):
......
......@@ -213,6 +213,7 @@ class KedifaMixinCaucase(KedifaMixin):
def setUpKedifa(self, ip):
self.db = os.path.join(self.testdir, 'pocket.sqlite')
self.pidfile = os.path.join(self.testdir, 'kedifa.pid')
self.logfile = os.path.join(self.testdir, 'kedifa.log')
port = '16080'
self.kedifa_runtime = multiprocessing.Process(
target=cli.http,
......@@ -223,7 +224,8 @@ class KedifaMixinCaucase(KedifaMixin):
'--certificate', self.kedifa_key_pem,
'--ca-certificate', self.ca_crt_pem,
'--crl', self.crl,
'--pidfile', self.pidfile)
'--pidfile', self.pidfile,
'--logfile', self.logfile)
)
self.kedifa_url = 'https://[%s]:%s/' % (ip, port)
self.addCleanup(self.kedifa_runtime.terminate)
......@@ -241,6 +243,13 @@ class KedifaMixinCaucase(KedifaMixin):
else:
raise
with open(self.logfile) as fh:
log_line_list = fh.readlines()
expected = 'Kedifa started at %s with pid %s stored in %s' % (
self.kedifa_url, self.kedifa_runtime.pid, self.pidfile)
self.assertTrue(expected in log_line_list[0])
self.assertLastLogEntry('"GET /ping HTTP/1.1" 401 0 "-" "python-requests')
def reserveReference(self, *args, **kwargs):
result = requests.post(
self.kedifa_url + 'reserve-id',
......@@ -323,6 +332,15 @@ class KedifaIntegrationTest(KedifaMixinCaucase, unittest.TestCase):
self._updater_get(url, certificate, destination)
return destination
def test_reload_log(self):
with open(self.pidfile) as pidfile:
os.kill(int(pidfile.read()), signal.SIGHUP)
# give some time for KeDiFa to react
time.sleep(1)
self.assertLastLogEntry('WARNING - KeDiFa reloaded.')
def test_GET_root(self):
result = self.requests_get(self.kedifa_url)
# KeDiFa does not support nothing on / so for now it just raises
......@@ -335,6 +353,24 @@ class KedifaIntegrationTest(KedifaMixinCaucase, unittest.TestCase):
'A server error occurred. Please contact the administrator.',
result.text
)
self.assertLastLogEntry('"GET / HTTP/1.1" 500')
self.assertAnyLogEntry('Exception while handling the request:')
self.assertAnyLogEntry('ValueError')
def assertAnyLogEntry(self, entry):
with open(self.logfile) as fh:
log_line_list = fh.readlines()
for log_line in log_line_list:
if entry in log_line:
return
self.fail(
'Entry %r not found in log:\n %s' % (entry, ''.join(log_line_list)))
def assertLastLogEntry(self, entry):
with open(self.logfile) as fh:
last_log_line = fh.readlines()[-1]
self.assertTrue(
entry in last_log_line, '%r not found in %r' % (entry, last_log_line))
def test_GET_not_existing(self):
result = self.requests_get(
......@@ -347,6 +383,7 @@ class KedifaIntegrationTest(KedifaMixinCaucase, unittest.TestCase):
'',
result.text
)
self.assertLastLogEntry('"GET /%s HTTP/1.1" 404' % (self.reference,))
def test_GET_existing(self):
self.put()
......@@ -360,6 +397,7 @@ class KedifaIntegrationTest(KedifaMixinCaucase, unittest.TestCase):
self.pem,
result.text
)
self.assertLastLogEntry('"GET /%s HTTP/1.1" 200' % (self.reference,))
def test_GET_unsigned_identity(self):
self.put()
......@@ -837,6 +875,7 @@ class KedifaIntegrationTest(KedifaMixinCaucase, unittest.TestCase):
result.headers.get('Location', ''),
r'^/%s/\d+$' % key
)
self.assertLastLogEntry('"PUT /%s?auth=%s HTTP/1.1" 201' % (key, auth))
def test_PUT(self):
self.put()
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment