diff --git a/homeassistant/components/system_log/__init__.py b/homeassistant/components/system_log/__init__.py index 6505107d034..60f707b1e33 100644 --- a/homeassistant/components/system_log/__init__.py +++ b/homeassistant/components/system_log/__init__.py @@ -14,6 +14,7 @@ from collections import deque import voluptuous as vol +from homeassistant import __path__ as HOMEASSISTANT_PATH from homeassistant.config import load_yaml_config_file import homeassistant.helpers.config_validation as cv from homeassistant.components.http import HomeAssistantView @@ -54,7 +55,14 @@ class LogErrorHandler(logging.Handler): be changed if neeeded. """ if record.levelno >= logging.WARN: - self.records.appendleft(record) + stack = [] + if not record.exc_info: + try: + stack = [f for f, _, _, _ in traceback.extract_stack()] + except ValueError: + # On Python 3.4 under py.test getting the stack might fail. + pass + self.records.appendleft([record, stack]) @asyncio.coroutine @@ -88,26 +96,41 @@ def async_setup(hass, config): return True -def _figure_out_source(record): +def _figure_out_source(record, call_stack, hass): + paths = [HOMEASSISTANT_PATH[0], hass.config.config_dir] + try: + # If netdisco is installed check its path too. + from netdisco import __path__ as netdisco_path + paths.append(netdisco_path[0]) + except ImportError: + pass # 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] + index = -1 + for i, frame in enumerate(call_stack): + if frame == record.pathname: + index = i + break + if index == -1: + # For some reason we couldn't find pathname in the stack. + stack = [record.pathname] + else: + stack = call_stack[0:index+1] # 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) + match = re.match(r'(?:{})/(.*)'.format('|'.join(paths)), pathname) if match: return match.group(1) - # Ok, we don't know what this is - return 'unknown' + return record.pathname def _exception_as_string(exc_info): @@ -117,13 +140,13 @@ def _exception_as_string(exc_info): return buf.getvalue() -def _convert(record): +def _convert(record, call_stack, hass): return { 'timestamp': record.created, 'level': record.levelname, 'message': record.getMessage(), 'exception': _exception_as_string(record.exc_info), - 'source': _figure_out_source(record), + 'source': _figure_out_source(record, call_stack, hass), } @@ -140,4 +163,5 @@ class AllErrorsView(HomeAssistantView): @asyncio.coroutine def get(self, request): """Get all errors and warnings.""" - return self.json([_convert(x) for x in self.handler.records]) + return self.json([_convert(x[0], x[1], request.app['hass']) + for x in self.handler.records]) diff --git a/tests/components/test_system_log.py b/tests/components/test_system_log.py index b86c768fb42..0f61986cf47 100644 --- a/tests/components/test_system_log.py +++ b/tests/components/test_system_log.py @@ -5,6 +5,7 @@ import pytest from homeassistant.bootstrap import async_setup_component from homeassistant.components import system_log +from unittest.mock import MagicMock, patch _LOGGER = logging.getLogger('test_logger') @@ -41,10 +42,14 @@ def assert_log(log, exception, message, level): 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 +def get_frame(name): + """Get log stack frame.""" + return (name, None, None, None) + + @asyncio.coroutine def test_normal_logs(hass, test_client): """Test that debug and info are not logged.""" @@ -110,3 +115,61 @@ def test_clear_logs(hass, test_client): # Assert done by get_error_log yield from get_error_log(hass, test_client, 0) + + +@asyncio.coroutine +def test_unknown_path(hass, test_client): + """Test error logged from unknown path.""" + _LOGGER.findCaller = MagicMock( + return_value=('unknown_path', 0, None, None)) + _LOGGER.error('error message') + log = (yield from get_error_log(hass, test_client, 1))[0] + assert log['source'] == 'unknown_path' + + +def log_error_from_test_path(path): + """Log error while mocking the path.""" + call_path = 'internal_path.py' + with patch.object( + _LOGGER, + 'findCaller', + MagicMock(return_value=(call_path, 0, None, None))): + with patch('traceback.extract_stack', + MagicMock(return_value=[ + get_frame('main_path/main.py'), + get_frame(path), + get_frame(call_path), + get_frame('venv_path/logging/log.py')])): + _LOGGER.error('error message') + + +@asyncio.coroutine +def test_homeassistant_path(hass, test_client): + """Test error logged from homeassistant path.""" + log_error_from_test_path('venv_path/homeassistant/component/component.py') + + with patch('homeassistant.components.system_log.HOMEASSISTANT_PATH', + new=['venv_path/homeassistant']): + log = (yield from get_error_log(hass, test_client, 1))[0] + assert log['source'] == 'component/component.py' + + +@asyncio.coroutine +def test_config_path(hass, test_client): + """Test error logged from config path.""" + log_error_from_test_path('config/custom_component/test.py') + + with patch.object(hass.config, 'config_dir', new='config'): + log = (yield from get_error_log(hass, test_client, 1))[0] + assert log['source'] == 'custom_component/test.py' + + +@asyncio.coroutine +def test_netdisco_path(hass, test_client): + """Test error logged from netdisco path.""" + log_error_from_test_path('venv_path/netdisco/disco_component.py') + + with patch.dict('sys.modules', + netdisco=MagicMock(__path__=['venv_path/netdisco'])): + log = (yield from get_error_log(hass, test_client, 1))[0] + assert log['source'] == 'disco_component.py'