fixed async file reads

.gitignore

@@ -1,2 +1,4 @@
 .venv
 __pycache__
+*.pyc
+src/bugis/_version.py

Dockerfile

@@ -4,18 +4,20 @@ RUN --mount=type=cache,target=/var/cache/apk apk update
 RUN --mount=type=cache,target=/var/cache/apk apk add python3 py3-pip graphviz
 
 FROM base AS build
-RUN --mount=type=cache,target=/var/cache/apk apk add musl-dev gcc graphviz-dev
+RUN --mount=type=cache,target=/var/cache/apk apk add musl-dev gcc graphviz-dev git
 RUN adduser -D luser
 USER luser
 WORKDIR /home/luser
-COPY --chown=luser:users ./requirements-dev.txt ./bugis/requirements-dev.txt
-COPY --chown=luser:users ./src ./bugis/src
-COPY --chown=luser:users ./pyproject.toml ./bugis/pyproject.toml
-WORKDIR /home/luser/bugis
+COPY --chown=luser:users ./requirements-dev.txt ./requirements-dev.txt
+COPY --chown=luser:users ./requirements-dev.txt ./requirements-run.txt
+WORKDIR /home/luser/
 RUN python -m venv .venv
 RUN --mount=type=cache,target=/home/luser/.cache/pip,uid=1000,gid=1000 .venv/bin/pip wheel -w /home/luser/wheel -r requirements-dev.txt pygraphviz
 RUN --mount=type=cache,target=/home/luser/.cache/pip,uid=1000,gid=1000 .venv/bin/pip install -r requirements-dev.txt /home/luser/wheel/*.whl
-RUN --mount=type=cache,target=/home/luser/.cache/pip,uid=1000,gid=1000 .venv/bin/python -m build
+COPY --chown=luser:users . /home/luser/bugis
+WORKDIR /home/luser/bugis
+RUN rm -rf .venv dist build
+RUN --mount=type=cache,target=/home/luser/.cache/pip,uid=1000,gid=1000 /home/luser/.venv/bin/python -m build
 
 FROM base AS release
 RUN mkdir /srv/http
@@ -24,7 +26,7 @@ USER bugis
 WORKDIR /var/bugis
 COPY --chown=bugis:users conf/pip.conf ./.pip/pip.conf
 RUN python -m venv .venv
-RUN --mount=type=cache,target=/var/bugis/.cache/pip,uid=1000,gid=1000 --mount=type=bind,ro,source=./requirements-run.txt,target=/requirements-run.txt --mount=type=bind,ro,from=build,source=/home/luser/wheel,target=/wheel .venv/bin/pip install -r /requirements-run.txt /wheel/*.whl
+RUN --mount=type=cache,target=/var/bugis/.cache/pip,uid=1000,gid=1000 --mount=type=bind,ro,from=build,source=/home/luser/bugis/requirements-run.txt,target=/requirements-run.txt --mount=type=bind,ro,from=build,source=/home/luser/wheel,target=/wheel .venv/bin/pip install -r /requirements-run.txt /wheel/*.whl
 RUN --mount=type=cache,target=/var/bugis/.cache/pip,uid=1000,gid=1000 --mount=type=bind,ro,from=build,source=/home/luser/bugis/dist,target=/dist .venv/bin/pip install /dist/*.whl
 VOLUME /srv/http
 WORKDIR /srv/http
@@ -32,7 +34,6 @@ WORKDIR /srv/http
 ENV GRANIAN_HOST=0.0.0.0
 ENV GRANIAN_INTERFACE=asginl
 ENV GRANIAN_LOOP=asyncio
-ENV GRANIAN_LOOP=asyncio
 ENV GRANIAN_LOG_ENABLED=false
 
 ENTRYPOINT ["/var/bugis/.venv/bin/python", "-m", "granian", "bugis.asgi:application"]

pyproject.toml

@@ -58,3 +58,4 @@ exclude = ["scripts", "docs", "test"]
 strict = true
 
 [tool.setuptools_scm]
+version_file = "src/bugis/_version.py"

src/bugis/asgi.py

@@ -13,7 +13,8 @@ with open(logging_configuration_file, 'r') as input_file:
     configure_logging(conf)
 
 
-log = logging.getLogger(__name__)
+log = logging.getLogger('access')
+log.propagate = False
 
 _server = None
 async def application(ctx, receive, send):

src/bugis/async_watchdog.py

@@ -1,4 +1,5 @@
 import asyncio
+import logging
 
 from watchdog.events import FileSystemEventHandler, FileSystemEvent, PatternMatchingEventHandler
 from watchdog.observers import Observer
@@ -8,6 +9,7 @@ from asyncio import Queue, AbstractEventLoop, Future, CancelledError, Task
 from typing import Optional, Callable
 from logging import getLogger
 
+log : logging.Logger = getLogger(__name__)
 
 class Subscription:
     _unsubscribe_callback: Callable[['Subscription'], None]
@@ -21,10 +23,12 @@ class Subscription:
 
     def unsubscribe(self) -> None:
         self._unsubscribe_callback(self)
+        log.debug('Deleted subscription %s', id(self))
 
     async def wait(self, tout: float) -> bool:
         handle = self._loop.call_later(tout, lambda: self._event.cancel())
         try:
+            log.debug('Subscription %s is waiting for an event', id(self))
             await self._event
             return True
         except CancelledError:
@@ -33,6 +37,7 @@ class Subscription:
             handle.cancel()
 
     def notify(self) -> None:
+        log.debug('Subscription %s notified', id(self))
         self._event.set_result(None)
 
     def reset(self) -> None:
@@ -85,7 +90,6 @@ def watch(path: Path, queue: Queue, loop: AbstractEventLoop,
     observer.join()
     loop.call_soon_threadsafe(queue.put_nowait, None)
 
-
 class SubscriptionManager:
     _loop: AbstractEventLoop
     _queue: Queue
@@ -104,6 +108,7 @@ class SubscriptionManager:
             subscriptions_per_path.remove(subscription)
 
         result = Subscription(unsubscribe_callback, self._loop)
+        log.debug('Created subscription %s to path %s', id(result), path)
         subscriptions_per_path.add(result)
         return result
 

src/bugis/default-conf/logging.yaml

@@ -4,8 +4,13 @@ handlers:
   console:
     class : logging.StreamHandler
     formatter: default
+    level   : DEBUG
+    stream  : ext://sys.stderr
+  access:
+    class : logging.StreamHandler
+    formatter: request
     level   : INFO
-    stream  : ext://sys.stdout
+    stream  : ext://sys.stderr
 formatters:
   brief:
     format: '%(message)s'
@@ -13,7 +18,14 @@ formatters:
     format: '{asctime} [{levelname}] ({processName:s}/{threadName:s}) - {name} - {message}'
     style: '{'
     datefmt: '%Y-%m-%d %H:%M:%S'
+  request:
+    format: '{asctime} {client[0]}:{client[1]} HTTP/{http_version} {method} {path}'
+    style: '{'
+    datefmt: '%Y-%m-%d %H:%M:%S'
 loggers:
   root:
     handlers: [console]
+    level: DEBUG
+  access:
+    handlers: [access]
     level: INFO

src/bugis/md2html.py

@@ -2,7 +2,7 @@ import sys
 from os.path import dirname, join, relpath
 from time import time
 from typing import Optional, TYPE_CHECKING
-
+from aiofiles import open as async_open
 import markdown
 
 if TYPE_CHECKING:
@@ -20,21 +20,21 @@ STATIC_CACHE: dict[str, tuple[str, float]] = {}
 MARDOWN_EXTENSIONS = ['extra', 'smarty', 'tables', 'codehilite']
 
 
-def load_from_cache(path) -> tuple[str, float]:
+async def load_from_cache(path) -> tuple[str, float]:
     global STATIC_CACHE
     if path not in STATIC_CACHE:
-        with open(join(dirname(__file__), 'static') + path, 'r') as static_file:
-            STATIC_CACHE[path] = (static_file.read(), time())
+        async with async_open(join(dirname(__file__), 'static') + path, 'r') as static_file:
+            STATIC_CACHE[path] = (await static_file.read(), time())
     return STATIC_CACHE[path]
 
 
-def compile_html(url_path,
+async def compile_html(url_path,
                  mdfile: 'StrOrBytesPath',
                  prefix: Optional['StrOrBytesPath'] = None,
                  extensions: Optional[list[str]] = None,
                  raw: bool = False) -> str:
-    with mdfile and open(mdfile, 'r') or sys.stdin as instream:
-        html = markdown.markdown(instream.read(), extensions=extensions, output_format='html')
+    async with mdfile and async_open(mdfile, 'r') or sys.stdin as instream:
+        html = markdown.markdown(await instream.read(), extensions=extensions, output_format='html')
     if raw:
         doc = html
     else:
@@ -44,5 +44,5 @@ def compile_html(url_path,
         css = f'<link rel="icon" type="image/x-icon" href="{prefix}/markdown.svg">'
         for css_file in ('github-markdown.css', 'pygment.css', 'custom.css'):
             css += f'        <link rel="stylesheet" href="{prefix}/{css_file}">'
-        doc = load_from_cache('/template.html')[0].format(content=html, script=script, css=css)
+        doc = (await load_from_cache('/template.html'))[0].format(content=html, script=script, css=css)
     return doc

src/bugis/server.py

@@ -70,12 +70,12 @@ class Server:
         url_path: 'StrOrBytesPath' = normpath(join('/', relative_path))
         path: 'StrOrBytesPath' = join(self.root_dir, relative_path)
         if url_path in STATIC_RESOURCES:
-            content, mtime = load_from_cache(url_path)
+            content, mtime = await load_from_cache(url_path)
             content = content.encode()
             etag, digest = await self.compute_etag_and_digest(
                 etag,
                 url_path,
-                lambda: AiofilesContextManager(completed_future(AsyncBufferedReader(BytesIO(content), loop=get_running_loop()))),
+                lambda: AiofilesContextManager(completed_future(AsyncBufferedReader(BytesIO(content), loop=get_running_loop(), executor=None))),
                 lambda: completed_future(mtime)
             )
             if etag and etag == digest:
@@ -267,11 +267,11 @@ class Server:
                         raw: bool,
                         digest: str,
                         send) -> list[bytes]:
-        body = compile_html(url_path,
+        body = (await compile_html(url_path,
                             path,
                             self.prefix,
                             MARDOWN_EXTENSIONS,
-                            raw=raw).encode()
+                            raw=raw)).encode()
         await send({
             'type': 'http.response.start',
             'status': 200,