From 001103f688940775c1cf2840ddeea65317133b0d Mon Sep 17 00:00:00 2001 From: Jon Froehlich Date: Wed, 1 Jul 2026 12:55:18 -0700 Subject: [PATCH 1/3] Derive log file path from BASE_DIR, degrade gracefully if unwritable (#1283) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The LOGGING 'file' handler hardcoded an absolute, container-specific path (/code/media/debug.log). Django evaluates LOGGING at django.setup(), so on any host lacking that exact directory (e.g. GitHub Actions CI) startup died with FileNotFoundError before a single request or test ran. Derive the path from BASE_DIR instead (still under media/ so it stays reachable via the intentional /logs/ URL per docs/DEPLOYMENT.md), allow an ML_LOG_DIR env override, and fall back to a NullHandler when the log dir can't be created or written so a bad log path never crashes startup. In the container/servers BASE_DIR is /code, so the default still resolves to /code/media/debug.log — no behavior change on prod, test, or local dev. The NullHandler swap in settings_test.py is now belt-and-suspenders rather than the only crash guard. Co-Authored-By: Claude Opus 4.8 (1M context) --- makeabilitylab/settings.py | 36 ++++++++++++++++++++++++++++-------- 1 file changed, 28 insertions(+), 8 deletions(-) diff --git a/makeabilitylab/settings.py b/makeabilitylab/settings.py index b82d0ec8..ee3585bf 100644 --- a/makeabilitylab/settings.py +++ b/makeabilitylab/settings.py @@ -105,6 +105,23 @@ # See: https://docs.djangoproject.com/en/2.0/topics/logging/ # https://lincolnloop.com/blog/django-logging-right-way/ # For the log format, see: https://stackoverflow.com/a/26276689/388117 +# +# Log-file path (issue #1283): this used to be hardcoded to /code/media/debug.log, +# an absolute container-specific path. Django evaluates LOGGING at django.setup(), +# so on any host lacking that exact directory (e.g. GitHub Actions CI) startup died +# with FileNotFoundError before a single request/test ran. Derive the path from +# BASE_DIR instead (still under media/ so it stays reachable via the intentional +# /logs/ URL — see docs/DEPLOYMENT.md), allow an ML_LOG_DIR env override, and if +# the directory can't be created or written, fall back to a NullHandler so a bad +# log path never crashes startup. +LOG_DIR = os.environ.get('ML_LOG_DIR', os.path.join(BASE_DIR, 'media')) +LOG_FILE = os.path.join(LOG_DIR, 'debug.log') +try: + os.makedirs(LOG_DIR, exist_ok=True) + _LOG_TO_FILE = os.access(LOG_DIR, os.W_OK) +except OSError: + _LOG_TO_FILE = False + LOGGING = { 'version': 1, 'disable_existing_loggers': False, @@ -125,20 +142,23 @@ }, }, 'handlers': { + # The file handler writes LOG_FILE (media/debug.log by default), which + # lands in the bind-mounted web root and is intentionally exposed via the + # /logs/ URL per docs/DEPLOYMENT.md (Jason Howe's design — convenient + # remote debugging in exchange for some info disclosure). To shrink that + # exposure in production, we log at INFO when DEBUG is off, but keep + # DEBUG-level file logging in local dev where DEBUG is on and the file + # isn't publicly reachable. If the log dir isn't writable (_LOG_TO_FILE + # is False), degrade to a NullHandler so startup never dies (issue #1283). 'file': { - # The file handler writes /code/media/debug.log, which lands in the - # bind-mounted web root and is intentionally exposed via the /logs/ - # URL per docs/DEPLOYMENT.md (Jason Howe's design — convenient - # remote debugging in exchange for some info disclosure). To shrink - # that exposure in production, we log at INFO when DEBUG is off, - # but keep DEBUG-level file logging in local dev where DEBUG is on - # and the file isn't publicly reachable. 'level': 'DEBUG' if DEBUG else 'INFO', 'class': 'logging.handlers.RotatingFileHandler', - 'filename': '/code/media/debug.log', + 'filename': LOG_FILE, 'maxBytes': 1024*1024*5, # 5 MB 'backupCount': 6, 'formatter': 'verbose', # can switch between verbose and simple + } if _LOG_TO_FILE else { + 'class': 'logging.NullHandler', }, 'console': { 'level': 'DEBUG', From ce9ecf518de3e6e1013592084ee89e8c25fa399c Mon Sep 17 00:00:00 2001 From: Jon Froehlich Date: Wed, 8 Jul 2026 18:01:54 -0700 Subject: [PATCH 2/3] Extract log-dir writability guard into a tested helper (#1283) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Address review feedback on the log-path degradation fix: - Pull the try/except guard out of the LOGGING block into a documented _log_dir_is_writable() helper so it can be unit-tested directly (no settings reload / subprocess needed). - Note the dir-vs-file writability gap in the helper docstring: the check is on the directory, so a writable dir holding a root-owned read-only debug.log could still make RotatingFileHandler raise on open — an accepted edge case, strictly better than the prior unconditional crash. - Add website/tests/test_logging_config.py: a fast SimpleTestCase pinning both the writable (→ file handler) and uncreatable (→ NullHandler) paths. Co-Authored-By: Claude Opus 4.8 (1M context) --- makeabilitylab/settings.py | 25 ++++++++++++++---- website/tests/test_logging_config.py | 39 ++++++++++++++++++++++++++++ 2 files changed, 59 insertions(+), 5 deletions(-) create mode 100644 website/tests/test_logging_config.py diff --git a/makeabilitylab/settings.py b/makeabilitylab/settings.py index ee3585bf..d889d29a 100644 --- a/makeabilitylab/settings.py +++ b/makeabilitylab/settings.py @@ -114,13 +114,28 @@ # /logs/ URL — see docs/DEPLOYMENT.md), allow an ML_LOG_DIR env override, and if # the directory can't be created or written, fall back to a NullHandler so a bad # log path never crashes startup. +def _log_dir_is_writable(log_dir): + """Return True if ``log_dir`` exists (or can be created) and looks writable. + + Used to decide whether the file log handler is active or degrades to a + NullHandler so a bad log path never crashes ``django.setup()`` (issue #1283). + + Note: this checks the *directory*, not the eventual log file. A dir that is + writable but already holds a root-owned, read-only ``debug.log`` would still + let RotatingFileHandler raise on open — an edge case we accept, since it is + strictly better than the previous unconditional crash and matches the real + deploy model (media/ is owned by the app's own user). + """ + try: + os.makedirs(log_dir, exist_ok=True) + return os.access(log_dir, os.W_OK) + except OSError: + return False + + LOG_DIR = os.environ.get('ML_LOG_DIR', os.path.join(BASE_DIR, 'media')) LOG_FILE = os.path.join(LOG_DIR, 'debug.log') -try: - os.makedirs(LOG_DIR, exist_ok=True) - _LOG_TO_FILE = os.access(LOG_DIR, os.W_OK) -except OSError: - _LOG_TO_FILE = False +_LOG_TO_FILE = _log_dir_is_writable(LOG_DIR) LOGGING = { 'version': 1, diff --git a/website/tests/test_logging_config.py b/website/tests/test_logging_config.py new file mode 100644 index 00000000..8161bd47 --- /dev/null +++ b/website/tests/test_logging_config.py @@ -0,0 +1,39 @@ +""" +Regression tests for the log-path degradation guard added in issue #1283. + +The base ``LOGGING`` config used to hardcode ``/code/media/debug.log``. Because +Django evaluates ``LOGGING`` at ``django.setup()``, any host missing that exact +directory (e.g. GitHub Actions CI) crashed with ``FileNotFoundError`` before a +single request or test ran. The fix derives the path from ``BASE_DIR`` and, if +the log directory can't be created or written, degrades the file handler to a +``NullHandler`` so startup never dies. These tests pin that helper's behavior. + +Pure logic, no DB — a fast ``SimpleTestCase``. +""" + +import shutil +import tempfile + +from django.test import SimpleTestCase + +from makeabilitylab.settings import _log_dir_is_writable + + +class LogDirWritabilityTests(SimpleTestCase): + def test_writable_dir_returns_true(self): + """A normal, writable directory keeps the file handler active.""" + tmp = tempfile.mkdtemp() + try: + self.assertTrue(_log_dir_is_writable(tmp)) + finally: + shutil.rmtree(tmp, ignore_errors=True) + + def test_uncreatable_dir_returns_false(self): + """A dir that can't be created degrades to False (→ NullHandler). + + ``/dev/null`` is a file on every POSIX host, so ``os.makedirs`` under it + raises ``NotADirectoryError`` (an ``OSError``) — the helper must swallow + it and report the directory as unusable rather than letting the error + propagate into ``django.setup()``. + """ + self.assertFalse(_log_dir_is_writable('/dev/null/cannot/create')) From ec94c7332b9de75de2edbd04fd61b7ff1ba49cf9 Mon Sep 17 00:00:00 2001 From: Jon Froehlich Date: Tue, 28 Jul 2026 06:33:42 -0700 Subject: [PATCH 3/3] Address code-review findings on the #1283 log-path fix MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Follow-ups to the review of PR #1415. The substantive one: degrading to a NullHandler was completely silent. The 'django' logger has only the 'file' handler and the 'website' logger's console handler is gated by require_debug_true (False in prod), so an unwritable log dir means the server runs blind — and there is no console access on -test or prod to notice it. Surface the degraded state two web-reachable ways: - /version.json gains log_to_file + log_file (scriptable deploy check). - The admin dashboard gains a superuser-only warning callout naming the path that failed. Red-tinted so it doesn't read as another amber tip box; both light and dark variants clear WCAG AA (ratios noted inline). Also from the review: - Rename _log_dir_is_writable -> _ensure_log_dir_writable; the function calls os.makedirs, so a pure-predicate name was misleading. Document the os.access root caveat (the deployed container runs as apache, so the guard still bites). - Extract _file_log_handler() so both branches are testable and the LOGGING literal loses its two-dict inline ternary. LOGGING is evaluated once at import, so the degrade branch was otherwise untestable — settings_test.py swaps the handler before any test runs. - Cross-reference LOG_DIR and MEDIA_ROOT at both sites, and add a test pinning LOG_FILE to MEDIA_ROOT/debug.log — the contract the log's readability rests on. - Document ML_LOG_DIR (previously undocumented) in DEPLOYMENT.md and CLAUDE.md. Correcting a stale premise while here: the /logs/ URL that settings.py and DEPLOYMENT.md cite as the way to read debug.log 404s on BOTH prod and test (verified by curl, 2026-07-28). SSH to the shared filesystem is the reliable path; the docs now say so. The INFO-not-DEBUG conservatism stays, since the file does still live in a web-served tree. Tests: 724 pass. New coverage for the helper's dir creation, both handler branches, the MEDIA_ROOT contract, the version.json fields, and the admin callout (shown to superusers when degraded, hidden otherwise). Co-Authored-By: Claude Opus 5 (1M context) --- CLAUDE.md | 1 + docs/DEPLOYMENT.md | 58 ++++++++++++ makeabilitylab/settings.py | 123 ++++++++++++++++++------- website/context_processors.py | 13 ++- website/templates/admin/index.html | 61 ++++++++++++ website/tests/test_logging_config.py | 121 ++++++++++++++++++++++-- website/tests/test_version_endpoint.py | 22 ++++- website/views/version.py | 21 ++++- 8 files changed, 375 insertions(+), 45 deletions(-) diff --git a/CLAUDE.md b/CLAUDE.md index 67fe2eb1..6c68ed95 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -130,6 +130,7 @@ the existing viewset/serializer pattern and keep `v1` fields additive-only - **Prod/test `config.ini` has only a `[Django]` section — no `[Postgres]` section.** Per `settings.py`, a missing `[Postgres]` section means Django uses the fallback `DATABASES` default (`HOST='db'`) — i.e. the dockerized `db` service of the active compose file. A `[Postgres]` section, if added, would override it. So the DB is the in-stack `db` container in **every** environment (no external Postgres); on the servers that's the `db` service in `docker-compose.yml`. - `DEBUG` resolution order: `DJANGO_ENV=PROD` forces False → `config.ini [Django] DEBUG` → `DJANGO_ENV=DEBUG` forces True → default False. - `TIME_ZONE = 'America/Los_Angeles'`. `ML_WEBSITE_VERSION` in settings is shown in the admin header and used in release tagging. +- **Logging (#1283):** `debug.log` lives at `LOG_DIR/debug.log`, where `LOG_DIR` is `$ML_LOG_DIR` or `/media` (`/code/media` in the container). Keep it inside `MEDIA_ROOT` — the web-served `/logs/debug.log` depends on that. `ML_LOG_DIR` is unset everywhere today; it exists for non-`/code` hosts. If the dir isn't writable the file handler degrades to a `NullHandler` rather than crashing `django.setup()`, and since there's no console on the servers that state surfaces via `/version.json` (`log_to_file`) and a superuser-only callout on the admin dashboard. ### Container startup side effects (`docker-entrypoint.sh`) diff --git a/docs/DEPLOYMENT.md b/docs/DEPLOYMENT.md index fb085d6d..0ed1cf5f 100644 --- a/docs/DEPLOYMENT.md +++ b/docs/DEPLOYMENT.md @@ -188,6 +188,64 @@ email. | `httpd-access.log` | HTTP request logs | On the Docker host — web `/logs/` URL. | | `httpd-error.log` | HTTP error logs | On the Docker host — web `/logs/` URL. | +#### Where `debug.log` is written, and what happens if that fails (#1283) + +The path is derived in `makeabilitylab/settings.py`: + +``` +LOG_DIR = $ML_LOG_DIR, defaulting to /media # /code/media in the container +LOG_FILE = $LOG_DIR/debug.log # /code/media/debug.log +``` + +`LOG_DIR` must stay inside `MEDIA_ROOT`, because that is the directory bind-mounted +out to the shared CSE filesystem — it's what makes `debug.log` readable over SSH at +`/cse/web/research/makelab/www/debug.log` (prod) and `www-test/debug.log` (test). + +> **Note:** `https:///logs/debug.log` **404s on both prod and test** as of +> 2026-07-28 (verified with `curl`; it falls through to Django's custom 404). The +> web-URL rows in the table above are stale. SSH is the reliable path — see +> "Reading `debug.log` over SSH" below. Because the log nonetheless lives in a +> web-served tree, we still log at INFO rather than DEBUG when `DEBUG` is off. + +- **`ML_LOG_DIR`** is an optional environment override for hosts that don't use + `/code`. It is **not set** on prod, test, or local dev, and shouldn't need to + be. If you do set it outside `MEDIA_ROOT`, the web `/logs/` URL stops working. +- **If the log directory can't be created or written**, Django does *not* crash + (it used to: `LOGGING` is evaluated at `django.setup()`, so a bad path killed + startup before a single request). The file handler degrades to a `NullHandler` + instead — meaning the server runs fine but **writes no logs at all**. + +Because a degraded state is otherwise invisible (there is no console access on +these servers), it is surfaced two ways: + +1. **`/version.json`** → `"log_to_file": false` and `"log_file": ""`. +2. **The `/admin/` dashboard** → a warning callout, shown to superusers only. + +### Verifying logging after a deploy + +`log_to_file: true` only means the *directory* was writable at startup, so check +both the flag and that records are actually landing on disk: + +```bash +HOST=https://makeabilitylab-test.cs.washington.edu # or the prod host +curl -s $HOST/version.json | python3 -m json.tool +# expect: "log_to_file": true, "log_file": "/code/media/debug.log", +# and a "git_sha" matching the commit you pushed +``` + +Match `git_sha` — **not `built_at`**, which has shown fresh on a stuck auto-deploy +serving stale code. Then confirm records are really being written (the web `/logs/` +URL 404s, so this has to be SSH): + +```bash +ssh makelab1 # or makelab2 / recycle +ls -l /cse/web/research/makelab/www-test/debug.log # www/ for prod +tail -5 /cse/web/research/makelab/www-test/debug.log # timestamps after the deploy +``` + +The log rotates at 5 MB, so check `debug.log.1` too when hunting a container-start +sequence. + ### Accessing Logs via Web - **Test:** https://makeabilitylab-test.cs.washington.edu/logs/ diff --git a/makeabilitylab/settings.py b/makeabilitylab/settings.py index da90a888..1e6b4e52 100644 --- a/makeabilitylab/settings.py +++ b/makeabilitylab/settings.py @@ -86,8 +86,8 @@ SECURE_PROXY_SSL_HEADER = ('HTTP_X_FORWARDED_PROTO', 'https') # Makeability Lab Global Variables, including Makeability Lab version -ML_WEBSITE_VERSION = "2.31.0" # Keep this updated with each release and also change the short description below -ML_WEBSITE_VERSION_DESCRIPTION = "A project's roster in the public API now reports each person's title over the span of their role (#1435), so someone on a project since 2012 reads as what they are today rather than the title they held back then. Finished stints still read as what that person was at the time." +ML_WEBSITE_VERSION = "2.31.1" # Keep this updated with each release and also change the short description below +ML_WEBSITE_VERSION_DESCRIPTION = "The Django log path is now derived from the project root instead of a hardcoded container path, and an unwritable log directory degrades gracefully instead of killing startup (#1283). Because the servers have no console, /version.json now reports whether file logging is actually live." DATE_MAKEABILITYLAB_FORMED = datetime.date(2012, 1, 1) # Date Makeability Lab was formed MAX_BANNERS = 7 # Maximum number of banners on a page @@ -110,21 +110,39 @@ # an absolute container-specific path. Django evaluates LOGGING at django.setup(), # so on any host lacking that exact directory (e.g. GitHub Actions CI) startup died # with FileNotFoundError before a single request/test ran. Derive the path from -# BASE_DIR instead (still under media/ so it stays reachable via the intentional -# /logs/ URL — see docs/DEPLOYMENT.md), allow an ML_LOG_DIR env override, and if +# BASE_DIR instead (still under media/, the bind-mounted tree, so the file stays +# readable over SSH — see docs/DEPLOYMENT.md), allow an ML_LOG_DIR env override, and if # the directory can't be created or written, fall back to a NullHandler so a bad # log path never crashes startup. -def _log_dir_is_writable(log_dir): - """Return True if ``log_dir`` exists (or can be created) and looks writable. - - Used to decide whether the file log handler is active or degrades to a - NullHandler so a bad log path never crashes ``django.setup()`` (issue #1283). - - Note: this checks the *directory*, not the eventual log file. A dir that is - writable but already holds a root-owned, read-only ``debug.log`` would still - let RotatingFileHandler raise on open — an edge case we accept, since it is - strictly better than the previous unconditional crash and matches the real - deploy model (media/ is owned by the app's own user). +# +# Degrading is silent by default, and that is dangerous here: the 'django' logger +# has only the 'file' handler, and the 'website' logger's console handler is gated +# by require_debug_true (False in prod), so an unwritable log dir means the app runs +# completely blind. We have no console access on the -test or prod servers, so the +# degraded state is surfaced two web-reachable ways instead: the 'log_to_file' field +# on /version.json (website/views/version.py) and a warning callout on the admin +# dashboard (website/templates/admin/index.html). +def _ensure_log_dir_writable(log_dir): + """Create ``log_dir`` if needed and return True if it looks writable. + + Named for the side effect: this *creates* the directory (``os.makedirs``) + rather than merely inspecting it. Used to decide whether the file log handler + is active or degrades to a NullHandler, so a bad log path never crashes + ``django.setup()`` (issue #1283). + + Two known limits, both accepted as strictly better than the previous + unconditional crash: + + 1. This checks the *directory*, not the eventual log file. A dir that is + writable but already holds a root-owned, read-only ``debug.log`` would + still let RotatingFileHandler raise on open. That doesn't match the real + deploy model, where media/ is owned by the app's own user. + 2. ``os.access(dir, os.W_OK)`` returns True for root regardless of the + directory mode, so a mode-555 dir wouldn't be caught when running as root. + The deployed container runs as ``apache`` (UID 48, see Dockerfile), so the + guard is meaningful where it matters; only the root devcontainer bypasses + it. The common failures — missing dir, uncreatable dir, read-only + filesystem — are caught either way. """ try: os.makedirs(log_dir, exist_ok=True) @@ -133,9 +151,49 @@ def _log_dir_is_writable(log_dir): return False +def _file_log_handler(log_file, level, enabled): + """Return the ``LOGGING['handlers']['file']`` config dict. + + When ``enabled`` is False (the log dir isn't writable) this returns a + NullHandler instead, which keeps every logger's ``'file'`` handler reference + valid while never touching disk — so startup degrades instead of dying. + + Split out of the ``LOGGING`` literal so both branches are directly testable; + ``LOGGING`` is evaluated once at import, so a test can't re-derive it. + See ``website/tests/test_logging_config.py``. + """ + if not enabled: + return {'class': 'logging.NullHandler'} + return { + 'level': level, + 'class': 'logging.handlers.RotatingFileHandler', + 'filename': log_file, + 'maxBytes': 1024*1024*5, # 5 MB + 'backupCount': 6, + 'formatter': 'verbose', # can switch between verbose and simple + } + + +# NOTE: this default must stay in sync with MEDIA_ROOT (defined further down as +# os.path.join(BASE_DIR, 'media')) — the web-served /logs/debug.log URL only works +# because the log lives inside the media root. MEDIA_ROOT isn't defined yet here +# (LOGGING has to be built before it), hence the duplicated expression; +# test_default_log_file_is_under_media_root pins the two together. LOG_DIR = os.environ.get('ML_LOG_DIR', os.path.join(BASE_DIR, 'media')) LOG_FILE = os.path.join(LOG_DIR, 'debug.log') -_LOG_TO_FILE = _log_dir_is_writable(LOG_DIR) + +# Uppercase on purpose: Django only exposes uppercase module attributes through +# django.conf.settings, and both the /version.json view and the admin dashboard +# read this to surface a degraded-logging warning. +LOG_TO_FILE = _ensure_log_dir_writable(LOG_DIR) + +if not LOG_TO_FILE: + # Secondary signal only. There is no console access on the -test or prod + # servers, so this print is really for local dev and the emailed buildlog; + # the channels that actually work remotely are /version.json (log_to_file + # field) and the warning callout on the admin dashboard. + print(f"WARNING: log dir {LOG_DIR!r} is not writable — file logging disabled " + f"(NullHandler). Check /version.json 'log_to_file'.") LOGGING = { 'version': 1, @@ -157,24 +215,16 @@ def _log_dir_is_writable(log_dir): }, }, 'handlers': { - # The file handler writes LOG_FILE (media/debug.log by default), which - # lands in the bind-mounted web root and is intentionally exposed via the - # /logs/ URL per docs/DEPLOYMENT.md (Jason Howe's design — convenient - # remote debugging in exchange for some info disclosure). To shrink that - # exposure in production, we log at INFO when DEBUG is off, but keep - # DEBUG-level file logging in local dev where DEBUG is on and the file - # isn't publicly reachable. If the log dir isn't writable (_LOG_TO_FILE - # is False), degrade to a NullHandler so startup never dies (issue #1283). - 'file': { - 'level': 'DEBUG' if DEBUG else 'INFO', - 'class': 'logging.handlers.RotatingFileHandler', - 'filename': LOG_FILE, - 'maxBytes': 1024*1024*5, # 5 MB - 'backupCount': 6, - 'formatter': 'verbose', # can switch between verbose and simple - } if _LOG_TO_FILE else { - 'class': 'logging.NullHandler', - }, + # The file handler writes LOG_FILE (media/debug.log by default), which lands + # in the bind-mounted web root — that's what makes it readable over SSH at + # /cse/web/research/makelab/www[-test]/debug.log. (docs/DEPLOYMENT.md also + # describes a /logs/ URL per Jason Howe's design, but that URL 404s on both + # prod and test as of 2026-07-28.) Since the file still sits in a web-served + # tree, stay conservative: log at INFO when DEBUG is off, but keep DEBUG-level + # file logging in local dev where DEBUG is on and nothing is public. If the + # log dir isn't writable (LOG_TO_FILE is False), degrade to a NullHandler so + # startup never dies (issue #1283). + 'file': _file_log_handler(LOG_FILE, 'DEBUG' if DEBUG else 'INFO', LOG_TO_FILE), 'console': { 'level': 'DEBUG', 'filters': ['require_debug_true'], @@ -401,6 +451,11 @@ def _log_dir_is_writable(log_dir): # The MEDIA_URL is required by Django see and is a URL that handles the media served # from MEDIA_ROOT, used for managing stored files. # See: https://docs.djangoproject.com/en/4.2/ref/settings/#media-url +# +# NOTE: LOG_DIR (defined up with LOGGING, which has to be built before this) hard-codes +# the same expression, because the web-served /logs/debug.log URL only works while the +# log file lives inside the media root. If you move MEDIA_ROOT, move LOG_DIR with it — +# test_default_log_file_is_under_media_root fails loudly if the two ever diverge. MEDIA_ROOT = os.path.join(BASE_DIR, 'media') MEDIA_URL = '/media/' diff --git a/website/context_processors.py b/website/context_processors.py index 64a26216..4579a2ed 100644 --- a/website/context_processors.py +++ b/website/context_processors.py @@ -21,14 +21,21 @@ def admin_version_info(request): """ Make version and debug info available to all templates. - This is used by the admin interface to display the current + This is used by the admin interface to display the current website version in the header and show a debug indicator. - + + LOG_TO_FILE / LOG_FILE (#1283) let the admin dashboard warn when the LOGGING + file handler degraded to a NullHandler — i.e. this server is writing no logs + at all. We have no console access on -test/prod, so the dashboard callout and + the /version.json 'log_to_file' field are the only ways to notice. + Returns: - dict: Context variables for ML_WEBSITE_VERSION and DEBUG. + dict: Context variables for ML_WEBSITE_VERSION, DEBUG, and logging health. """ return { 'ML_WEBSITE_VERSION': settings.ML_WEBSITE_VERSION, 'ML_WEBSITE_VERSION_DESCRIPTION': settings.ML_WEBSITE_VERSION_DESCRIPTION, 'DEBUG': settings.DEBUG, + 'LOG_TO_FILE': settings.LOG_TO_FILE, + 'LOG_FILE': settings.LOG_FILE, } \ No newline at end of file diff --git a/website/templates/admin/index.html b/website/templates/admin/index.html index 096ea9e3..9341d98e 100644 --- a/website/templates/admin/index.html +++ b/website/templates/admin/index.html @@ -9,6 +9,25 @@ {% endif %} +{% comment %} + Degraded-logging warning (#1283). LOGGING's file handler falls back to a + NullHandler when the log directory isn't writable, which would otherwise be + completely silent: the 'django' logger has only that handler, and there is no + console access on the -test or prod servers. Superuser-gated because only the + maintainer can act on it. The scriptable equivalent is /version.json's + 'log_to_file' field. +{% endcomment %} +{% if user.is_superuser and not LOG_TO_FILE %} +
+ + Warning: file logging is disabled. + Django could not write to the log directory, + so log records are being discarded and debug.log will not update. + Expected path: {{ LOG_FILE }}. Check that directory's permissions, + or the ML_LOG_DIR environment variable if it is set. +
+{% endif %} + {% if user.is_superuser %}
@@ -122,6 +141,37 @@ color: #666; } + /* Degraded-logging warning (#1283) — only rendered when logging is dead. + Red-tinted rather than amber so it doesn't read as another .ml-help-text tip. */ + .ml-log-warning { + background-color: #fdecea; + border: 1px solid #f5c6c0; + border-left: 4px solid #b3261e; + padding: 10px 15px; + margin-bottom: 20px; + border-radius: 4px; + font-size: 14px; + } + + .ml-log-warning strong { + color: #a3261d; /* 6.4:1 on #fdecea — WCAG AA */ + } + + .ml-log-warning-icon { + margin-right: 6px; + } + + .ml-log-warning-desc { + color: #5f2c28; /* 9.8:1 on #fdecea — WCAG AA */ + } + + /* Inherit the callout's text color rather than the admin's muted grey, + which doesn't clear AA against these backgrounds (especially in dark mode). */ + .ml-log-warning code { + color: inherit; + background: transparent; + } + @media (prefers-color-scheme: dark) { .ml-data-health { background-color: #25302a; @@ -130,6 +180,17 @@ .ml-data-health-desc { color: #aaa; } + .ml-log-warning { + background-color: #3a201d; + border-color: #5a3430; + border-left-color: #e06c5f; + } + .ml-log-warning strong { + color: #f2a099; /* 7.3:1 on #3a201d — WCAG AA */ + } + .ml-log-warning-desc { + color: #d9b8b4; /* 8.2:1 on #3a201d — WCAG AA */ + } } /* Help text styling within category tables */ diff --git a/website/tests/test_logging_config.py b/website/tests/test_logging_config.py index 8161bd47..59910e70 100644 --- a/website/tests/test_logging_config.py +++ b/website/tests/test_logging_config.py @@ -6,17 +6,33 @@ directory (e.g. GitHub Actions CI) crashed with ``FileNotFoundError`` before a single request or test ran. The fix derives the path from ``BASE_DIR`` and, if the log directory can't be created or written, degrades the file handler to a -``NullHandler`` so startup never dies. These tests pin that helper's behavior. +``NullHandler`` so startup never dies. -Pure logic, no DB — a fast ``SimpleTestCase``. +Degrading silently is its own hazard: the ``django`` logger has only the ``file`` +handler and the ``website`` logger's console handler is gated by +``require_debug_true``, so on a server an unwritable log dir means no logs at all +-- and we have no console access on -test or prod. The degraded state is +therefore surfaced on ``/version.json`` and on the admin dashboard; both are +pinned here and in ``test_version_endpoint.py``. + +Note that ``settings_test.py`` replaces ``LOGGING['handlers']['file']`` with a +``NullHandler`` before any test runs, so the live ``LOGGING`` dict can't be used +to exercise the degrade branch. That's why ``settings.py`` factors the handler +construction into ``_file_log_handler`` -- these tests call it directly. + +Mostly pure logic; the admin-dashboard tests need the DB for a superuser login. """ +import os import shutil import tempfile -from django.test import SimpleTestCase +from django.conf import settings +from django.contrib.auth import get_user_model +from django.test import SimpleTestCase, override_settings -from makeabilitylab.settings import _log_dir_is_writable +from makeabilitylab.settings import _ensure_log_dir_writable, _file_log_handler +from website.tests.base import DatabaseTestCase class LogDirWritabilityTests(SimpleTestCase): @@ -24,7 +40,17 @@ def test_writable_dir_returns_true(self): """A normal, writable directory keeps the file handler active.""" tmp = tempfile.mkdtemp() try: - self.assertTrue(_log_dir_is_writable(tmp)) + self.assertTrue(_ensure_log_dir_writable(tmp)) + finally: + shutil.rmtree(tmp, ignore_errors=True) + + def test_missing_dir_is_created(self): + """The helper creates the directory rather than just inspecting it.""" + tmp = tempfile.mkdtemp() + target = os.path.join(tmp, "nested", "logs") + try: + self.assertTrue(_ensure_log_dir_writable(target)) + self.assertTrue(os.path.isdir(target)) finally: shutil.rmtree(tmp, ignore_errors=True) @@ -35,5 +61,88 @@ def test_uncreatable_dir_returns_false(self): raises ``NotADirectoryError`` (an ``OSError``) — the helper must swallow it and report the directory as unusable rather than letting the error propagate into ``django.setup()``. + + Deliberately not tested: an existing-but-unwritable dir (``chmod 0o500``). + ``os.access`` returns True for root regardless of mode, so such a test + would pass locally and fail in the root devcontainer. """ - self.assertFalse(_log_dir_is_writable('/dev/null/cannot/create')) + self.assertFalse(_ensure_log_dir_writable("/dev/null/cannot/create")) + + +class FileLogHandlerTests(SimpleTestCase): + """Both branches of the builder behind ``LOGGING['handlers']['file']``.""" + + def test_enabled_builds_rotating_file_handler(self): + handler = _file_log_handler("/tmp/probe/debug.log", "INFO", True) + self.assertEqual(handler["class"], "logging.handlers.RotatingFileHandler") + self.assertEqual(handler["filename"], "/tmp/probe/debug.log") + self.assertEqual(handler["level"], "INFO") + self.assertEqual(handler["formatter"], "verbose") + + def test_disabled_degrades_to_nullhandler(self): + handler = _file_log_handler("/tmp/probe/debug.log", "INFO", False) + self.assertEqual(handler, {"class": "logging.NullHandler"}) + # No filename key at all -- nothing for logging.config to try to open. + self.assertNotIn("filename", handler) + + +class LogFileLocationTests(SimpleTestCase): + def test_default_log_file_is_under_media_root(self): + """The log must live inside MEDIA_ROOT or the /logs/ URL breaks. + + ``LOG_DIR`` and ``MEDIA_ROOT`` are computed independently in settings.py + (LOGGING has to be built before MEDIA_ROOT is defined), so this pins them + together: the web-served ``/logs/debug.log`` on -test and prod works only + because the log file sits inside the bind-mounted media root. Skipped when + ``ML_LOG_DIR`` is set, since an explicit override may point elsewhere. + """ + if os.environ.get("ML_LOG_DIR"): + self.skipTest("ML_LOG_DIR override in effect") + self.assertEqual( + settings.LOG_FILE, os.path.join(settings.MEDIA_ROOT, "debug.log") + ) + + +class AdminLoggingWarningTests(DatabaseTestCase): + """The admin dashboard callout that surfaces degraded logging (#1283). + + This callout and the ``/version.json`` field are the only ways to notice a + logging blackout on -test or prod, where we have no console access. + """ + + def setUp(self): + super().setUp() + User = get_user_model() + self.superuser = User.objects.create_superuser( + username="logadmin", email="logadmin@example.com", password="pw-for-test" + ) + self.editor = User.objects.create_user( + username="logeditor", + email="logeditor@example.com", + password="pw-for-test", + is_staff=True, + ) + + @override_settings(LOG_TO_FILE=False, LOG_FILE="/code/media/debug.log") + def test_warning_shown_to_superuser_when_logging_degraded(self): + self.client.force_login(self.superuser) + response = self.client.get("/admin/") + self.assertEqual(response.status_code, 200) + self.assertContains(response, "file logging is disabled") + # The resolved path is what tells you which directory was at fault. + self.assertContains(response, "/code/media/debug.log") + + @override_settings(LOG_TO_FILE=True) + def test_no_warning_when_logging_healthy(self): + self.client.force_login(self.superuser) + response = self.client.get("/admin/") + self.assertEqual(response.status_code, 200) + self.assertNotContains(response, "file logging is disabled") + + @override_settings(LOG_TO_FILE=False) + def test_warning_hidden_from_non_superusers(self): + """Only the maintainer can fix a log-dir problem, so don't alarm editors.""" + self.client.force_login(self.editor) + response = self.client.get("/admin/") + self.assertEqual(response.status_code, 200) + self.assertNotContains(response, "file logging is disabled") diff --git a/website/tests/test_version_endpoint.py b/website/tests/test_version_endpoint.py index 1020d0f2..b3b865f4 100644 --- a/website/tests/test_version_endpoint.py +++ b/website/tests/test_version_endpoint.py @@ -7,7 +7,10 @@ - the JSON shape and that version/description/environment come from settings, - ``Cache-Control: no-store`` (so a proxy can't serve a stale version), - that git_sha/built_at are read from the entrypoint-written build-info file, - and fall back to ``"unknown"`` when the file is absent (e.g. local dev). + and fall back to ``"unknown"`` when the file is absent (e.g. local dev), + - that log_to_file/log_file report logging health (#1283) -- with no console + access on -test or prod, this endpoint is how we confirm a deployed server + is actually writing logs rather than silently discarding them. """ import json @@ -59,6 +62,9 @@ def test_payload_from_settings_and_no_store_header(self): # The live WSGI server's self-reported SERVER_SOFTWARE (#1034); always # present so we can confirm gunicorn vs. the dev runserver in deploys. self.assertIn("server", data) + # Logging health (#1283) -- always present so a deploy check can assert on it. + self.assertIn("log_to_file", data) + self.assertIn("log_file", data) def test_server_reflects_wsgi_server_software(self): # The view reports request.META["SERVER_SOFTWARE"] verbatim; on the real @@ -68,6 +74,20 @@ def test_server_reflects_wsgi_server_software(self): ) self.assertEqual(data["server"], "gunicorn/23.0.0") + @override_settings(LOG_TO_FILE=True, LOG_FILE="/code/media/debug.log") + def test_reports_healthy_logging(self): + data = json.loads(self.client.get("/version/").content) + self.assertTrue(data["log_to_file"]) + self.assertEqual(data["log_file"], "/code/media/debug.log") + + @override_settings(LOG_TO_FILE=False, LOG_FILE="/nope/debug.log") + def test_reports_degraded_logging(self): + """``log_to_file: false`` is the remote signal that a server is logging + nowhere (#1283); ``log_file`` names the directory that failed.""" + data = json.loads(self.client.get("/version/").content) + self.assertFalse(data["log_to_file"]) + self.assertEqual(data["log_file"], "/nope/debug.log") + def test_build_info_missing_falls_back_to_unknown(self): with override_settings(): # Point at a path that doesn't exist. diff --git a/website/views/version.py b/website/views/version.py index 3f0a9de6..c8c75ee2 100644 --- a/website/views/version.py +++ b/website/views/version.py @@ -26,13 +26,27 @@ "environment": "PROD", "git_sha": "02909b0", "built_at": "2026-06-21T18:30:00-07:00", - "server": "gunicorn/23.0.0" + "server": "gunicorn/23.0.0", + "log_to_file": true, + "log_file": "/code/media/debug.log" } The ``server`` field is the WSGI server's self-reported ``SERVER_SOFTWARE`` (``gunicorn/`` vs. Django's ``WSGIServer/ CPython/``), read off the live request -- it's the ground-truth answer to *"is this actually running Gunicorn?"* after the #1034 swap, not an inference from env vars or git_sha. + +``log_to_file`` / ``log_file`` report whether the ``LOGGING`` file handler is live +or degraded to a NullHandler, and which path it resolved to (#1283). We have no +console access on the -test or prod servers, so without this a bad log directory +would silently blackhole every log record with no way to notice: ``log_to_file: +false`` means the app is running blind, and ``log_file`` says which directory was +at fault. Nothing new is disclosed -- the path is derivable from the public repo. + +Note that ``log_to_file: true`` only means the log *directory* was writable at +startup. To confirm records are really landing, tail the file over SSH at +``/cse/web/research/makelab/www[-test]/debug.log`` (the ``/logs/`` URL described in +docs/DEPLOYMENT.md 404s on both servers). """ import json @@ -92,6 +106,11 @@ def version(request, format=None): # WSGI server handling this request: "gunicorn/" under #1034, # "WSGIServer/ CPython/" if the dev runserver is somehow live. "server": request.META.get("SERVER_SOFTWARE", "unknown"), + # Is the LOGGING file handler live, and where does it point (#1283)? False + # means it degraded to a NullHandler and this server is logging nowhere -- + # the only remote way to notice, since we have no console on -test/prod. + "log_to_file": settings.LOG_TO_FILE, + "log_file": settings.LOG_FILE, } response = JsonResponse(payload) response["Cache-Control"] = "no-store"