Skip to content
Permalink
Browse files

server2: rework logging

This patch speeds up log filtering on the frontend, captures early log messages
which were missed until now and adds clickable error messages to the flamingo
top bar when capturing errors or warnings

Signed-off-by: Florian Scherf <f.scherf@pengutronix.de>
  • Loading branch information
fscherf committed Dec 3, 2019
1 parent 16b06e4 commit 48a713780aa600143f799cc9f74cef03c758902f
@@ -25,6 +25,7 @@ parser = gen_default_parser(prog='flamingo-server2')

parser.add_argument('--port', type=int, default=8080)
parser.add_argument('--host', type=str, default='localhost')
parser.add_argument('--log-backlog', type=int, default=2500)
parser.add_argument('--shell', action='store_true')
parser.add_argument('--shell-history', action='store_true')

@@ -42,6 +43,7 @@ log_level = {
}[namespace.log_level]

rpc_logging_handler.set_internal_level(log_level)
rpc_logging_handler.buffer_max_size = namespace.log_backlog

# setup aiohttp app
loop = asyncio.get_event_loop()
@@ -4,17 +4,49 @@
import hashlib
import logging

from flamingo.core.utils.cli import color


class RPCHandler(logging.Handler):
def __init__(self, *args, **kwargs):
super().__init__(*args, **kwargs)

self.buffer = []
self.buffer_max_size = 2500
self.logger = {}

self.rpc = None
self.internal_level = None
self.rpc = None

self._setup(initial=True)

def _setup(self, initial=False):
if initial:
self.logger = {}

self.buffer = []

self.stats = {
'debug': 0,
'info': 0,
'warning': 0,
'error': 0,
'critical': 0,
}

def _notify(self, records=None):
if not self.rpc:
return

records = records or []

self.rpc.worker_pool.run_sync(
self.rpc.notify,
'log',
{
'stats': self.stats,
'logger': self.logger,
'records': records,
},
wait=False,
)

def set_rpc(self, rpc):
self.rpc = rpc
@@ -45,12 +77,23 @@ def handle(self, record):
)

self.buffer.append(record_args)
self.stats[record_args['level']] += 1

# buffer rotation
buffer_size = len(self.buffer)

if buffer_size > self.buffer_max_size:
# update stats
old_records = self.buffer[:buffer_size-self.buffer_max_size]

for old_record_args in old_records:
self.stats[old_record_args['level']] -= 1

# update buffer
self.buffer = self.buffer[buffer_size-self.buffer_max_size:]

# logger hash
# this is necessary for the frontend stylesheet generating
if record_args['name'] not in self.logger:
self.logger[record_args['name']] = 'logger_{}'.format(
hashlib.md5(record_args['name'].encode()).hexdigest())
@@ -59,33 +102,52 @@ def handle(self, record):

# print record to stdout
if self.internal_level and record.levelno >= self.internal_level:
print('{}:{}:{}'.format(
record_args['level'],
color_args = {}

message = '{}:{}:{}'.format(
record_args['level'].upper(),
record_args['name'],
record_args['message'],
))

# send rpc notification
if self.rpc:
self.rpc.worker_pool.run_sync(
self.rpc.notify,
'log',
{
'logger': self.logger,
'records': [record_args],
},
wait=False,
)

if record.levelname == 'DEBUG':
color_args = {
'color': 'green',
}

elif record.levelname == 'WARNING':
color_args = {
'color': 'yellow',
}

elif record.levelname == 'ERROR':
color_args = {
'color': 'red',
'style': 'bright',
}

elif record.levelname == 'CRITICAL':
color_args = {
'color': 'white',
'background': 'red',
'style': 'bright',
}

print(color(message, **color_args))

self._notify(records=[record_args])

async def setup_log(self, request):
request.subscriptions.add('log')

return {
'stats': self.stats,
'logger': self.logger,
'records': self.buffer,
}

async def clear_log(self, request):
self.buffer = []
self._setup(initial=False)
self._notify()

return True
@@ -3,6 +3,7 @@
import logging
import types
import code
import json
import os

from aiohttp.web import FileResponse, Response
@@ -74,6 +75,9 @@ def __init__(self, app, settings, rpc_logging_handler, loop=None,
# setup aiohttp
app.router.add_route('*', '/_flamingo/rpc/', self.rpc)

app.router.add_route(
'*', '/_flamingo/settings.js', self.frontend_settings)

app.router.add_route(
'*', '/_flamingo/static/{path_info:.*}', self.static)

@@ -174,6 +178,17 @@ def unlock(self):
return

# views ###################################################################
@no_cache()
async def frontend_settings(self, request):
settings = {
'log_buffer_max_size': self.rpc_logging_handler.buffer_max_size,
}

settings_string = "var server_settings = JSON.parse('{}');".format(
json.dumps(settings))

return Response(text=settings_string)

@no_cache()
async def static(self, request):
await self.await_unlock()
@@ -10,6 +10,15 @@
<div id="main-grid">
<div id="top">
<span id="logo" on-click="toggle_overlay">Flamingo</span>
{{#if log.stats.critical > 0}}
<span id="critical-errors" on-click="@.fire('log_show', 'critical')">{{log.stats.critical}} Critical Error{{#if log.stats.critical > 1}}s{{/if}}</span>
{{/if}}
{{#if log.stats.error > 0}}
<span id="errors" on-click="@.fire('log_show', 'error')">{{log.stats.error}} Error{{#if log.stats.error > 1}}s{{/if}}</span>
{{/if}}
{{#if log.stats.warning > 0}}
<span id="warnings" on-click="@.fire('log_show', 'warning')">{{log.stats.warning}} Warning{{#if log.stats.warning > 1}}s{{/if}}</span>
{{/if}}
</div>
<div id="overlay"{{#if connected && !settings.overlay.open}} style="display: none;"{{/if}}>
<div id="status">{{#if connected }}Connected{{else}}Reconnecting{{#dots}}{{.}}{{/}}{{/if}}</div>
@@ -109,6 +118,7 @@
</div>
</div>
</script>
<script src="/_flamingo/settings.js"></script>
<script src="/_flamingo/static/lib/js.cookie-2.2.1.min.js"></script>
<script src="/_flamingo/static/lib/ractive.min.js"></script>
<script src="/_flamingo/static/lib/rpc.js"></script>
@@ -78,10 +78,7 @@ rpc.DEBUG = false;

ractive.on('clear_log', function(event) {
rpc.call('clear_log', undefined, function(data) {
ractive.set('log', {
logger: [],
records: [],
});
ractive.set('log.records', []);
});
});

@@ -315,6 +312,38 @@ function log_scroll_to_bottom() {
document.querySelector('.log .records .scroll-anchor').scrollIntoView();
}

function log_show(level) {
var records = ractive.get('log.records');

var settings = {
level: {
debug: false,
info: false,
warning: false,
error: false,
critical: false,
},
logger: {},
};

settings.level[level] = true;

for(var index in records) {
var record = records[index];

if(record.level == level) {
settings.logger[record.name] = true;
}
}

ractive.set('settings.log', settings);

ractive.set('settings.overlay', {
open: true,
tab: 'log',
});
}

ractive.observe('settings.log', function(settings) {
generate_logging_stylesheet(settings);
});
@@ -326,6 +355,9 @@ ractive.on({
log_scroll_to_bottom: function() {
log_scroll_to_bottom();
},
log_show: function(event, level) {
log_show(level);
},
});

// Connection Handling --------------------------------------------------------
@@ -372,8 +404,11 @@ rpc.on('open', function(rpc) {
log.logger = data.logger;
add_logger(data.logger);

log.stats = data.stats;
log.records = log.records.concat(data.records);
log.records = log.records.slice(-2500);

log.records = log.records.slice(
server_settings.log_buffer_max_size * -1);

ractive.set('log', log);
};
@@ -32,12 +32,6 @@ body {
padding: 0.25em 0.2em;
}

#main-grid #top #logo {
font-weight: bold;
cursor: pointer;
user-select: none;
}

#main-grid iframe {
grid-column-start: 1;
grid-column-end: 1;
@@ -49,6 +43,31 @@ body {
width: 100%;
}

/* TOP BAR ----------------------------------------------------------------- */
#main-grid #top span {
margin-right: 0.5em;
cursor: pointer;
user-select: none;
}

#main-grid #top span#logo {
font-weight: bold;
}

#main-grid #top span#critical-errors {
background-color: red;
color: white;
font-weight: bold;
}

#main-grid #top span#errors {
color: red;
}

#main-grid #top span#warnings {
color: yellow;
}

/* OVERLAY ----------------------------------------------------------------- */
#overlay {
grid-column-start: 1;

0 comments on commit 48a7137

Please sign in to comment.
You can’t perform that action at this time.