Commit 70cb0742 authored by Łukasz Nowak's avatar Łukasz Nowak Committed by Łukasz Nowak

Kedifa Log

/reviewed-on nexedi/kedifa!5
parent 745dfdbc
...@@ -24,6 +24,7 @@ from wsgiref.simple_server import make_server ...@@ -24,6 +24,7 @@ from wsgiref.simple_server import make_server
import caucase.exceptions import caucase.exceptions
import caucase.http import caucase.http
import caucase.utils import caucase.utils
from caucase.http_wsgibase import CleanServerHandler
import datetime import datetime
import json import json
import os import os
...@@ -33,6 +34,8 @@ import sqlite3 ...@@ -33,6 +34,8 @@ import sqlite3
import ssl import ssl
import string import string
import urlparse import urlparse
import logging
import logging.handlers
class UserExists(Exception): class UserExists(Exception):
...@@ -514,11 +517,57 @@ class Reloader(object): ...@@ -514,11 +517,57 @@ class Reloader(object):
# what is actually used when accepting a connection - so the update # what is actually used when accepting a connection - so the update
# is actually successful. # is actually successful.
pass pass
print 'KeDiFa reloaded.' logger.warning('KeDiFa reloaded.')
def http(host, port, pocket, certificate, ca_certificate, crl, pidfile): logger = logging.getLogger('kedifa')
pidfile.write(str(os.getpid()))
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() pidfile.close()
kedifa = Kedifa(pocket, ca_certificate, crl) kedifa = Kedifa(pocket, ca_certificate, crl)
if ':' in host: if ':' in host:
...@@ -527,7 +576,8 @@ def http(host, port, pocket, certificate, ca_certificate, crl, pidfile): ...@@ -527,7 +576,8 @@ def http(host, port, pocket, certificate, ca_certificate, crl, pidfile):
access_format = 'https://%s:%s/' access_format = 'https://%s:%s/'
httpd = make_server( httpd = make_server(
host, port, kedifa, caucase.http.ThreadingWSGIServer, host, port, kedifa, caucase.http.ThreadingWSGIServer,
caucase.http.CaucaseSSLWSGIRequestHandler) KedifaSSLWSGIRequestHandler
)
ssl_context = getSSLContext(certificate.name, ca_certificate.name, crl.name) ssl_context = getSSLContext(certificate.name, ca_certificate.name, crl.name)
httpd.socket = ssl_context.wrap_socket( httpd.socket = ssl_context.wrap_socket(
httpd.socket, httpd.socket,
...@@ -540,7 +590,9 @@ def http(host, port, pocket, certificate, ca_certificate, crl, pidfile): ...@@ -540,7 +590,9 @@ def http(host, port, pocket, certificate, ca_certificate, crl, pidfile):
httpd.server_close() httpd.server_close()
raise 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( reloader = Reloader(
httpd, kedifa, certificate.name, ca_certificate.name, crl.name) httpd, kedifa, certificate.name, ca_certificate.name, crl.name)
......
...@@ -71,10 +71,16 @@ def http(*args): ...@@ -71,10 +71,16 @@ def http(*args):
help='Path to PID file.', help='Path to PID file.',
required=True required=True
) )
parser.add_argument(
'--logfile',
type=str,
help='Path to logfile.',
default='-'
)
parsed = parser.parse_args(args) parsed = parser.parse_args(args)
app.http(parsed.ip, parsed.port, parsed.db, parsed.certificate, 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): def getter(*args):
......
...@@ -225,6 +225,7 @@ class KedifaMixinCaucase(KedifaMixin): ...@@ -225,6 +225,7 @@ class KedifaMixinCaucase(KedifaMixin):
def setUpKedifa(self, ip): def setUpKedifa(self, ip):
self.db = os.path.join(self.testdir, 'pocket.sqlite') self.db = os.path.join(self.testdir, 'pocket.sqlite')
self.pidfile = os.path.join(self.testdir, 'kedifa.pid') self.pidfile = os.path.join(self.testdir, 'kedifa.pid')
self.logfile = os.path.join(self.testdir, 'kedifa.log')
port = findFreeTCPPort(ip) port = findFreeTCPPort(ip)
self.kedifa_runtime = multiprocessing.Process( self.kedifa_runtime = multiprocessing.Process(
target=cli.http, target=cli.http,
...@@ -235,7 +236,8 @@ class KedifaMixinCaucase(KedifaMixin): ...@@ -235,7 +236,8 @@ class KedifaMixinCaucase(KedifaMixin):
'--certificate', self.kedifa_key_pem, '--certificate', self.kedifa_key_pem,
'--ca-certificate', self.ca_crt_pem, '--ca-certificate', self.ca_crt_pem,
'--crl', self.crl, '--crl', self.crl,
'--pidfile', self.pidfile) '--pidfile', self.pidfile,
'--logfile', self.logfile)
) )
self.kedifa_url = 'https://[%s]:%s/' % (ip, port) self.kedifa_url = 'https://[%s]:%s/' % (ip, port)
self.addCleanup(self.kedifa_runtime.terminate) self.addCleanup(self.kedifa_runtime.terminate)
...@@ -255,6 +257,11 @@ class KedifaMixinCaucase(KedifaMixin): ...@@ -255,6 +257,11 @@ class KedifaMixinCaucase(KedifaMixin):
self.fail( self.fail(
'Kedifa not available after %.2fs seconds' % (time.time() - b)) 'Kedifa not available after %.2fs seconds' % (time.time() - b))
expected = 'Kedifa started at %s with pid %s stored in %s' % (
self.kedifa_url, self.kedifa_runtime.pid, self.pidfile)
self.assertAnyLogEntry(expected)
self.assertLastLogEntry('"GET /ping HTTP/1.1" 401 0 "-" "python-requests')
def reserveReference(self, *args, **kwargs): def reserveReference(self, *args, **kwargs):
result = requests.post( result = requests.post(
self.kedifa_url + 'reserve-id', self.kedifa_url + 'reserve-id',
...@@ -300,6 +307,21 @@ class KedifaMixinCaucase(KedifaMixin): ...@@ -300,6 +307,21 @@ class KedifaMixinCaucase(KedifaMixin):
class KedifaIntegrationTest(KedifaMixinCaucase, unittest.TestCase): class KedifaIntegrationTest(KedifaMixinCaucase, unittest.TestCase):
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 _getter_get(self, url, certificate, destination): def _getter_get(self, url, certificate, destination):
cli.getter( cli.getter(
url, url,
...@@ -337,6 +359,15 @@ class KedifaIntegrationTest(KedifaMixinCaucase, unittest.TestCase): ...@@ -337,6 +359,15 @@ class KedifaIntegrationTest(KedifaMixinCaucase, unittest.TestCase):
self._updater_get(url, certificate, destination) self._updater_get(url, certificate, destination)
return 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): def test_GET_root(self):
result = self.requests_get(self.kedifa_url) result = self.requests_get(self.kedifa_url)
# KeDiFa does not support nothing on / so for now it just raises # KeDiFa does not support nothing on / so for now it just raises
...@@ -349,6 +380,15 @@ class KedifaIntegrationTest(KedifaMixinCaucase, unittest.TestCase): ...@@ -349,6 +380,15 @@ class KedifaIntegrationTest(KedifaMixinCaucase, unittest.TestCase):
'Wrong path', 'Wrong path',
result.text result.text
) )
self.assertLastLogEntry('"GET / HTTP/1.1" 400')
# check rotation support
os.rename(self.logfile, self.logfile + '.rotated')
result = self.requests_get(self.kedifa_url)
self.assertEqual(
httplib.BAD_REQUEST,
result.status_code
)
self.assertLastLogEntry('"GET / HTTP/1.1" 400')
def test_GET_not_existing(self): def test_GET_not_existing(self):
result = self.requests_get( result = self.requests_get(
...@@ -361,6 +401,7 @@ class KedifaIntegrationTest(KedifaMixinCaucase, unittest.TestCase): ...@@ -361,6 +401,7 @@ class KedifaIntegrationTest(KedifaMixinCaucase, unittest.TestCase):
'', '',
result.text result.text
) )
self.assertLastLogEntry('"GET /%s HTTP/1.1" 404' % (self.reference,))
def test_GET_existing(self): def test_GET_existing(self):
self.put() self.put()
...@@ -374,6 +415,7 @@ class KedifaIntegrationTest(KedifaMixinCaucase, unittest.TestCase): ...@@ -374,6 +415,7 @@ class KedifaIntegrationTest(KedifaMixinCaucase, unittest.TestCase):
self.pem, self.pem,
result.text result.text
) )
self.assertLastLogEntry('"GET /%s HTTP/1.1" 200' % (self.reference,))
def test_GET_unsigned_identity(self): def test_GET_unsigned_identity(self):
self.put() self.put()
...@@ -851,6 +893,7 @@ class KedifaIntegrationTest(KedifaMixinCaucase, unittest.TestCase): ...@@ -851,6 +893,7 @@ class KedifaIntegrationTest(KedifaMixinCaucase, unittest.TestCase):
result.headers.get('Location', ''), result.headers.get('Location', ''),
r'^/%s/\d+$' % key r'^/%s/\d+$' % key
) )
self.assertLastLogEntry('"PUT /%s?auth=%s HTTP/1.1" 201' % (key, auth))
def test_PUT(self): def test_PUT(self):
self.put() 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