Add basic backend support for a system log (#10492)

Everything logged with "warning" or "error" is stored and exposed via
the HTTP API, that can be used by the frontend.

homeassistant/bootstrap.py

@@ -30,8 +30,8 @@ ERROR_LOG_FILENAME = 'home-assistant.log'
 DATA_LOGGING = 'logging'
 
 FIRST_INIT_COMPONENT = set((
-    'recorder', 'mqtt', 'mqtt_eventstream', 'logger', 'introduction',
-    'frontend', 'history'))
+    'system_log', 'recorder', 'mqtt', 'mqtt_eventstream', 'logger',
+    'introduction', 'frontend', 'history'))
 
 
 def from_config_dict(config: Dict[str, Any],

homeassistant/components/frontend/__init__.py

@@ -26,7 +26,7 @@ from homeassistant.loader import bind_hass
 REQUIREMENTS = ['home-assistant-frontend==20171111.0']
 
 DOMAIN = 'frontend'
-DEPENDENCIES = ['api', 'websocket_api', 'http']
+DEPENDENCIES = ['api', 'websocket_api', 'http', 'system_log']
 
 URL_PANEL_COMPONENT_FP = '/frontend/panels/{}-{}.html'
 

homeassistant/components/system_log/__init__.py

@@ -0,0 +1,145 @@
+"""
+Support for system log.
+
+For more details about this platform, please refer to the documentation at
+https://home-assistant.io/components/system_log/
+"""
+import os
+import re
+import asyncio
+import logging
+import traceback
+from io import StringIO
+from collections import deque
+
+import voluptuous as vol
+
+from homeassistant.config import load_yaml_config_file
+import homeassistant.helpers.config_validation as cv
+from homeassistant.components.http import HomeAssistantView
+
+DOMAIN = 'system_log'
+DEPENDENCIES = ['http']
+SERVICE_CLEAR = 'clear'
+
+CONF_MAX_ENTRIES = 'max_entries'
+
+DEFAULT_MAX_ENTRIES = 50
+
+DATA_SYSTEM_LOG = 'system_log'
+
+CONFIG_SCHEMA = vol.Schema({
+    DOMAIN: vol.Schema({
+        vol.Optional(CONF_MAX_ENTRIES,
+                     default=DEFAULT_MAX_ENTRIES): cv.positive_int,
+    }),
+}, extra=vol.ALLOW_EXTRA)
+
+SERVICE_CLEAR_SCHEMA = vol.Schema({})
+
+
+class LogErrorHandler(logging.Handler):
+    """Log handler for error messages."""
+
+    def __init__(self, maxlen):
+        """Initialize a new LogErrorHandler."""
+        super().__init__()
+        self.records = deque(maxlen=maxlen)
+
+    def emit(self, record):
+        """Save error and warning logs.
+
+        Everyhing logged with error or warning is saved in local buffer. A
+        default upper limit is set to 50 (older entries are discarded) but can
+        be changed if neeeded.
+        """
+        if record.levelno >= logging.WARN:
+            self.records.appendleft(record)
+
+
+@asyncio.coroutine
+def async_setup(hass, config):
+    """Set up the logger component."""
+    conf = config.get(DOMAIN)
+
+    if conf is None:
+        conf = CONFIG_SCHEMA({DOMAIN: {}})[DOMAIN]
+
+    handler = LogErrorHandler(conf.get(CONF_MAX_ENTRIES))
+    logging.getLogger().addHandler(handler)
+
+    hass.http.register_view(AllErrorsView(handler))
+    yield from hass.components.frontend.async_register_built_in_panel(
+        'system-log', 'system_log', 'mdi:monitor')
+
+    @asyncio.coroutine
+    def async_service_handler(service):
+        """Handle logger services."""
+        # Only one service so far
+        handler.records.clear()
+
+    descriptions = yield from hass.async_add_job(
+        load_yaml_config_file, os.path.join(
+            os.path.dirname(__file__), 'services.yaml'))
+
+    hass.services.async_register(
+        DOMAIN, SERVICE_CLEAR, async_service_handler,
+        descriptions[DOMAIN].get(SERVICE_CLEAR),
+        schema=SERVICE_CLEAR_SCHEMA)
+
+    return True
+
+
+def _figure_out_source(record):
+    # If a stack trace exists, extract filenames from the entire call stack.
+    # The other case is when a regular "log" is made (without an attached
+    # exception). In that case, just use the file where the log was made from.
+    if record.exc_info:
+        stack = [x[0] for x in traceback.extract_tb(record.exc_info[2])]
+    else:
+        stack = [record.pathname]
+
+    # Iterate through the stack call (in reverse) and find the last call from
+    # a file in HA. Try to figure out where error happened.
+    for pathname in reversed(stack):
+
+        # Try to match with a file within HA
+        match = re.match(r'.*/homeassistant/(.*)', pathname)
+        if match:
+            return match.group(1)
+
+    # Ok, we don't know what this is
+    return 'unknown'
+
+
+def _exception_as_string(exc_info):
+    buf = StringIO()
+    if exc_info:
+        traceback.print_exception(*exc_info, file=buf)
+    return buf.getvalue()
+
+
+def _convert(record):
+    return {
+        'timestamp': record.created,
+        'level': record.levelname,
+        'message': record.getMessage(),
+        'exception': _exception_as_string(record.exc_info),
+        'source': _figure_out_source(record),
+        }
+
+
+class AllErrorsView(HomeAssistantView):
+    """Get all logged errors and warnings."""
+
+    url = "/api/error/all"
+    name = "api:error:all"
+
+    def __init__(self, handler):
+        """Initialize a new AllErrorsView."""
+        self.handler = handler
+
+    @asyncio.coroutine
+    def get(self, request):
+        """Get all errors and warnings."""
+        return self.json([_convert(x) for x in self.handler.records])

homeassistant/components/system_log/services.yaml

@@ -0,0 +1,3 @@
+system_log:
+  clear:
+    description: Clear all log entries.

tests/components/test_system_log.py

@@ -0,0 +1,112 @@
+"""Test system log component."""
+import asyncio
+import logging
+import pytest
+
+from homeassistant.bootstrap import async_setup_component
+from homeassistant.components import system_log
+
+_LOGGER = logging.getLogger('test_logger')
+
+
+@pytest.fixture(autouse=True)
+@asyncio.coroutine
+def setup_test_case(hass):
+    """Setup system_log component before test case."""
+    config = {'system_log': {'max_entries': 2}}
+    yield from async_setup_component(hass, system_log.DOMAIN, config)
+
+
+@asyncio.coroutine
+def get_error_log(hass, test_client, expected_count):
+    """Fetch all entries from system_log via the API."""
+    client = yield from test_client(hass.http.app)
+    resp = yield from client.get('/api/error/all')
+    assert resp.status == 200
+
+    data = yield from resp.json()
+    assert len(data) == expected_count
+    return data
+
+
+def _generate_and_log_exception(exception, log):
+    try:
+        raise Exception(exception)
+    except:  # pylint: disable=bare-except
+        _LOGGER.exception(log)
+
+
+def assert_log(log, exception, message, level):
+    """Assert that specified values are in a specific log entry."""
+    assert exception in log['exception']
+    assert message == log['message']
+    assert level == log['level']
+    assert log['source'] == 'unknown'  # always unkown in tests
+    assert 'timestamp' in log
+
+
+@asyncio.coroutine
+def test_normal_logs(hass, test_client):
+    """Test that debug and info are not logged."""
+    _LOGGER.debug('debug')
+    _LOGGER.info('info')
+
+    # Assert done by get_error_log
+    yield from get_error_log(hass, test_client, 0)
+
+
+@asyncio.coroutine
+def test_exception(hass, test_client):
+    """Test that exceptions are logged and retrieved correctly."""
+    _generate_and_log_exception('exception message', 'log message')
+    log = (yield from get_error_log(hass, test_client, 1))[0]
+    assert_log(log, 'exception message', 'log message', 'ERROR')
+
+
+@asyncio.coroutine
+def test_warning(hass, test_client):
+    """Test that warning are logged and retrieved correctly."""
+    _LOGGER.warning('warning message')
+    log = (yield from get_error_log(hass, test_client, 1))[0]
+    assert_log(log, '', 'warning message', 'WARNING')
+
+
+@asyncio.coroutine
+def test_error(hass, test_client):
+    """Test that errors are logged and retrieved correctly."""
+    _LOGGER.error('error message')
+    log = (yield from get_error_log(hass, test_client, 1))[0]
+    assert_log(log, '', 'error message', 'ERROR')
+
+
+@asyncio.coroutine
+def test_critical(hass, test_client):
+    """Test that critical are logged and retrieved correctly."""
+    _LOGGER.critical('critical message')
+    log = (yield from get_error_log(hass, test_client, 1))[0]
+    assert_log(log, '', 'critical message', 'CRITICAL')
+
+
+@asyncio.coroutine
+def test_remove_older_logs(hass, test_client):
+    """Test that older logs are rotated out."""
+    _LOGGER.error('error message 1')
+    _LOGGER.error('error message 2')
+    _LOGGER.error('error message 3')
+    log = yield from get_error_log(hass, test_client, 2)
+    assert_log(log[0], '', 'error message 3', 'ERROR')
+    assert_log(log[1], '', 'error message 2', 'ERROR')
+
+
+@asyncio.coroutine
+def test_clear_logs(hass, test_client):
+    """Test that the log can be cleared via a service call."""
+    _LOGGER.error('error message')
+
+    hass.async_add_job(
+        hass.services.async_call(
+            system_log.DOMAIN, system_log.SERVICE_CLEAR, {}))
+    yield from hass.async_block_till_done()
+
+    # Assert done by get_error_log
+    yield from get_error_log(hass, test_client, 0)