diff options
| -rw-r--r-- | fietsboek/actions.py | 2 | ||||
| -rw-r--r-- | fietsboek/log.py | 39 | ||||
| -rw-r--r-- | tests/assets/no_climbs.gpx.gz | bin | 0 -> 916 bytes | |||
| -rw-r--r-- | tests/assets/two_climbs.gpx.gz | bin | 0 -> 3149 bytes | |||
| -rw-r--r-- | tests/playwright/test_climbs.py | 67 |
5 files changed, 105 insertions, 3 deletions
diff --git a/fietsboek/actions.py b/fietsboek/actions.py index ae98856..3bca6a2 100644 --- a/fietsboek/actions.py +++ b/fietsboek/actions.py @@ -373,7 +373,7 @@ def extract_climbs_background(request: Request, track_id: int): except sqlalchemy.exc.IntegrityError: LOGGER.info("SQL IntegrityError -- did we lose the track while extracting climbs?") request.redis.delete(f"bg-tasks:track-{track_id}") - LOGGER.debug("Climb extraction done") + LOGGER.debug("Climb extraction done for track %d", track_id) Thread(name=f"climbs-{track_id}", target=_extract_climbs).start() diff --git a/fietsboek/log.py b/fietsboek/log.py index e4d3ed9..d3dd811 100644 --- a/fietsboek/log.py +++ b/fietsboek/log.py @@ -1,6 +1,7 @@ """Logging-related utilities.""" import collections +import datetime import logging from dataclasses import asdict, dataclass @@ -33,8 +34,10 @@ class RingBuffer(logging.Handler): self.buffer: collections.deque = collections.deque(maxlen=maxlen) def emit(self, record): + dt = datetime.datetime.fromtimestamp(record.created).astimezone(datetime.UTC) + millis = int(dt.microsecond / 1000) line = LogLine( - time=record.asctime, + time=f"{dt:%F %T},{millis:03}", name=record.name, level=record.levelno, level_name=record.levelname, @@ -45,9 +48,41 @@ class RingBuffer(logging.Handler): self.buffer.append(line) +class NameLevelFilter(logging.Filter): + """Filters log records by level, but only if the name matches.""" + + # pylint: disable=too-few-public-methods + + def __init__(self, name, level): + super().__init__() + self.level = level + self.name = name + + def filter(self, record): + return not record.name.startswith(self.name) or record.levelno >= self.level + + HANDLER = RingBuffer(5000) def install(): """Install the in-memory log handler to the root logger.""" - logging.getLogger().addHandler(HANDLER) + # We want the in-memory buffer to contain all log entries of any level, + # regardless of what the configuration says. This is useful to show them on + # the admin site, and required for the tests. + # + # In order to achieve that, we do a little dance here: We try to figure out + # what the level of the wanted fietsboek logger is, then we set it to DEBUG + # so we catch everything. Since we don't know how the handler setup of the + # user is, we then go and add a filter to replicate the level filtering. + # This avoids that we set levels on handlers, which might interfere with + # other loggers. + my_name = __name__.split(".", maxsplit=1)[0] + fietslog = logging.getLogger(my_name) + root = logging.getLogger() + filty = NameLevelFilter(my_name, fietslog.level) + for handler in root.handlers: + handler.addFilter(filty) + + fietslog.setLevel(logging.DEBUG) + fietslog.addHandler(HANDLER) diff --git a/tests/assets/no_climbs.gpx.gz b/tests/assets/no_climbs.gpx.gz Binary files differnew file mode 100644 index 0000000..f2a3b72 --- /dev/null +++ b/tests/assets/no_climbs.gpx.gz diff --git a/tests/assets/two_climbs.gpx.gz b/tests/assets/two_climbs.gpx.gz Binary files differnew file mode 100644 index 0000000..e352f4c --- /dev/null +++ b/tests/assets/two_climbs.gpx.gz diff --git a/tests/playwright/test_climbs.py b/tests/playwright/test_climbs.py new file mode 100644 index 0000000..3c57345 --- /dev/null +++ b/tests/playwright/test_climbs.py @@ -0,0 +1,67 @@ +import datetime +import re +import time +from pathlib import Path + +from playwright.sync_api import Page, expect + +from testutils import extract_and_upload +from fietsboek import models +from fietsboek.log import HANDLER + + +def wait_for_log( + message: str, + timeout: datetime.timedelta = datetime.timedelta(seconds=10), +): + """Waits for the given log message to appear in the logs.""" + pattern = re.compile(message) + start = datetime.datetime.now(datetime.UTC) + while True: + if any(pattern.search(m.message) is not None for m in HANDLER.buffer): + return + time.sleep(0.5) + if datetime.datetime.now(datetime.UTC) - start > timeout: + raise RuntimeError(f"Timeout waiting for log {message!r}") + + +def upload_and_wait(playwright_helper, filename: str, tmp_path: Path) -> int: + """Upload the track (via the web UI) and wait for the background tasks to + finish. + + Returns the track's ID. + """ + page: Page = playwright_helper.page + + playwright_helper.login() + + page.goto("/") + page.get_by_text("Upload").click() + + extract_and_upload(page, filename, tmp_path) + + page.locator(".btn", has_text="Upload").click() + new_track_id = int(page.url.rsplit("/", 1)[1]) + expect(page.locator(".favourite-star")).to_be_visible() + wait_for_log(f"Climb extraction done for track {new_track_id}$") + return new_track_id + + +def test_no_climbs(playwright_helper, tmp_path, dbaccess): + track_id = upload_and_wait(playwright_helper, "no_climbs.gpx.gz", tmp_path) + track = dbaccess.get(models.Track, track_id) + assert len(track.climbs) == 0 + + +def test_two_climbs(page: Page, playwright_helper, tmp_path, dbaccess): + track_id = upload_and_wait(playwright_helper, "two_climbs.gpx.gz", tmp_path) + track = dbaccess.get(models.Track, track_id) + assert len(track.climbs) == 2 + + page.goto(f"/track/{track_id}") + expect(page.locator(".climb-preview").nth(0)).to_be_visible() + expect(page.locator(".climb-details").nth(0)).to_contain_text("2.84 km") + expect(page.locator(".climb-details").nth(0)).to_contain_text("5.36 %") + expect(page.locator(".climb-preview").nth(1)).to_be_visible() + expect(page.locator(".climb-details").nth(1)).to_contain_text("1.29 km") + expect(page.locator(".climb-details").nth(1)).to_contain_text("5.58 %") |