diff --git a/bitelab/__init__.py b/bitelab/__init__.py index ee7ef77..dcac91c 100644 --- a/bitelab/__init__.py +++ b/bitelab/__init__.py @@ -58,6 +58,7 @@ import sqlite3 import subprocess import sys import tempfile +import time import ucl import unittest import urllib @@ -73,6 +74,26 @@ def new_parse_socket_addr(domain, addr): tcp_server.parse_socket_addr = new_parse_socket_addr +async def log_event(tag, board=None, user=None, extra={}): + info = extra.copy() + info['event'] = tag + + if board is not None: + info['board_name'] = board.name + else: + info.pop('board_name', None) + + if user is not None: + info['user'] = user + else: + info.pop('user', None) + + t = time.time() + info['date'] = time.strftime('%Y-%m-%dT%H:%M:%S', time.gmtime(t)) + \ + '.%03dZ' % (int((t * 1000) % 1000),) + + logging.info(json.dumps(info)) + class EtherIface(DefROAttribute): defattrname = 'eiface' @@ -411,6 +432,8 @@ async def reserve_board(board_id_or_class, await brd.activate() + await log_event('reserve', user=user, board=brd) + await brd.update() return brd @@ -423,6 +446,9 @@ async def release_board(board_id, user: str = Depends(lookup_user), brd = brdmgr.boards[board_id] async with brd.lock: + # XXX - how to handle a release error? + await log_event('release', user=user, board=brd) + try: brduser = await data.BoardStatus.objects.get(board=board_id) if user != brduser.user: @@ -660,11 +686,12 @@ class TestBiteLab(unittest.IsolatedAsyncioTestCase): # and that the error got logged le.assert_called_with('release script failure: board: \'cora-1\', ret: 1, stderr: b\'error\'') + @patch('bitelab.log_event') @patch('bitelab.BoardImpl.deactivate') @patch('bitelab.BoardImpl.activate') @patch('asyncio.create_subprocess_exec') @patch('bitelab.snmp.snmpget') - async def test_board_reserve_release(self, sg, cse, biact, bideact): + async def test_board_reserve_release(self, sg, cse, biact, bideact, le): # that when releasing a board that is not yet reserved res = await self.client.post('/board/cora-1/release', auth=BiteAuth('anotherlongapikey')) @@ -737,6 +764,10 @@ class TestBiteLab(unittest.IsolatedAsyncioTestCase): # and that the board was activated biact.assert_called() + # and that log_event was called properly + le.assert_called_with('reserve', user='foo', + board=self.brdmgr.boards['cora-1']) + # that another user reserving the board res = await self.client.post('/board/cora-1/reserve', auth=BiteAuth('anotherlongapikey')) @@ -781,6 +812,10 @@ class TestBiteLab(unittest.IsolatedAsyncioTestCase): } self.assertEqual(res.json(), info) + # and that log_event was called properly + le.assert_called_with('release', user='foo', + board=self.brdmgr.boards['cora-1']) + env = os.environ.copy() env['ip'] = brdinfo['attrs']['ip'] env['iface'] = brdinfo['attrs']['iface'] @@ -950,6 +985,49 @@ class TestBoardImpl(unittest.IsolatedAsyncioTestCase): opt.deactivate.assert_called_with(brd) +class TestLogEvent(unittest.IsolatedAsyncioTestCase): + @patch('time.time') + @patch('logging.info') + async def test_log_event(self, li, tt): + tag = 'eslkjdf' + user = 'weoijsdfkj' + brdname = 'woied' + extra = dict(something=2323, someelse='asdlfkj') + brd = BoardImpl(brdname, {}, []) + + tt.return_value = 1607650392.384 + + await log_event(tag, user=user, board=brd, extra=extra) + + res = dict(event=tag, board_name=brdname, user=user, + date='2020-12-11T01:33:12.384Z', **extra) + + # that log_event logs the correct data + self.assertEqual(len(li.call_args[0]), 1) + + # that the logged data can be parsed as json, and results + # in the correct object + self.assertEqual(json.loads(li.call_args[0][0]), res) + + tt.return_value = 1607650393.289 + + # that log_event handles no board/user + await log_event(tag) + + res = json.dumps(dict(event=tag, + date='2020-12-11T01:33:13.289Z')) + + li.assert_called_with(res) + + # that log_event doesn't allow board/user from extra + await log_event(tag, extra=dict(board_name='sldkfj', + user='sod')) + + res = json.dumps(dict(event=tag, + date='2020-12-11T01:33:13.289Z')) + + li.assert_called_with(res) + class TestAttrs(unittest.IsolatedAsyncioTestCase): @patch('asyncio.create_subprocess_exec') async def test_serialconsole(self, cse): diff --git a/bitelab/testing.py b/bitelab/testing.py index 22b9b04..84cb45a 100644 --- a/bitelab/testing.py +++ b/bitelab/testing.py @@ -30,5 +30,5 @@ from .snmp import TestSNMPPower, TestSNMPWrapper from .data import TestDatabase -from . import TestBiteLab, TestUnhashLRU, TestAttrs, TestBoardImpl +from . import TestBiteLab, TestUnhashLRU, TestAttrs, TestBoardImpl, TestLogEvent from .__main__ import TestClient