Skip to content

Commit 618a10c

Browse files
authored
Merge pull request #1415 from makeabilitylab/1283-derive-log-path-from-base-dir
Derive log file path from BASE_DIR, degrade gracefully if unwritable (#1283)
2 parents a0241fd + ec94c73 commit 618a10c

8 files changed

Lines changed: 426 additions & 22 deletions

File tree

CLAUDE.md

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -130,6 +130,7 @@ the existing viewset/serializer pattern and keep `v1` fields additive-only
130130
- **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`.
131131
- `DEBUG` resolution order: `DJANGO_ENV=PROD` forces False → `config.ini [Django] DEBUG``DJANGO_ENV=DEBUG` forces True → default False.
132132
- `TIME_ZONE = 'America/Los_Angeles'`. `ML_WEBSITE_VERSION` in settings is shown in the admin header and used in release tagging.
133+
- **Logging (#1283):** `debug.log` lives at `LOG_DIR/debug.log`, where `LOG_DIR` is `$ML_LOG_DIR` or `<BASE_DIR>/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.
133134

134135
### Container startup side effects (`docker-entrypoint.sh`)
135136

docs/DEPLOYMENT.md

Lines changed: 58 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -188,6 +188,64 @@ email.
188188
| `httpd-access.log` | HTTP request logs | On the Docker host — web `/logs/` URL. |
189189
| `httpd-error.log` | HTTP error logs | On the Docker host — web `/logs/` URL. |
190190

191+
#### Where `debug.log` is written, and what happens if that fails (#1283)
192+
193+
The path is derived in `makeabilitylab/settings.py`:
194+
195+
```
196+
LOG_DIR = $ML_LOG_DIR, defaulting to <BASE_DIR>/media # /code/media in the container
197+
LOG_FILE = $LOG_DIR/debug.log # /code/media/debug.log
198+
```
199+
200+
`LOG_DIR` must stay inside `MEDIA_ROOT`, because that is the directory bind-mounted
201+
out to the shared CSE filesystem — it's what makes `debug.log` readable over SSH at
202+
`/cse/web/research/makelab/www/debug.log` (prod) and `www-test/debug.log` (test).
203+
204+
> **Note:** `https://<host>/logs/debug.log` **404s on both prod and test** as of
205+
> 2026-07-28 (verified with `curl`; it falls through to Django's custom 404). The
206+
> web-URL rows in the table above are stale. SSH is the reliable path — see
207+
> "Reading `debug.log` over SSH" below. Because the log nonetheless lives in a
208+
> web-served tree, we still log at INFO rather than DEBUG when `DEBUG` is off.
209+
210+
- **`ML_LOG_DIR`** is an optional environment override for hosts that don't use
211+
`/code`. It is **not set** on prod, test, or local dev, and shouldn't need to
212+
be. If you do set it outside `MEDIA_ROOT`, the web `/logs/` URL stops working.
213+
- **If the log directory can't be created or written**, Django does *not* crash
214+
(it used to: `LOGGING` is evaluated at `django.setup()`, so a bad path killed
215+
startup before a single request). The file handler degrades to a `NullHandler`
216+
instead — meaning the server runs fine but **writes no logs at all**.
217+
218+
Because a degraded state is otherwise invisible (there is no console access on
219+
these servers), it is surfaced two ways:
220+
221+
1. **`/version.json`**`"log_to_file": false` and `"log_file": "<path that failed>"`.
222+
2. **The `/admin/` dashboard** → a warning callout, shown to superusers only.
223+
224+
### Verifying logging after a deploy
225+
226+
`log_to_file: true` only means the *directory* was writable at startup, so check
227+
both the flag and that records are actually landing on disk:
228+
229+
```bash
230+
HOST=https://makeabilitylab-test.cs.washington.edu # or the prod host
231+
curl -s $HOST/version.json | python3 -m json.tool
232+
# expect: "log_to_file": true, "log_file": "/code/media/debug.log",
233+
# and a "git_sha" matching the commit you pushed
234+
```
235+
236+
Match `git_sha`**not `built_at`**, which has shown fresh on a stuck auto-deploy
237+
serving stale code. Then confirm records are really being written (the web `/logs/`
238+
URL 404s, so this has to be SSH):
239+
240+
```bash
241+
ssh makelab1 # or makelab2 / recycle
242+
ls -l /cse/web/research/makelab/www-test/debug.log # www/ for prod
243+
tail -5 /cse/web/research/makelab/www-test/debug.log # timestamps after the deploy
244+
```
245+
246+
The log rotates at 5 MB, so check `debug.log.1` too when hunting a container-start
247+
sequence.
248+
191249
### Accessing Logs via Web
192250

193251
- **Test:** https://makeabilitylab-test.cs.washington.edu/logs/

makeabilitylab/settings.py

Lines changed: 107 additions & 17 deletions
Original file line numberDiff line numberDiff line change
@@ -86,8 +86,8 @@
8686
SECURE_PROXY_SSL_HEADER = ('HTTP_X_FORWARDED_PROTO', 'https')
8787

8888
# Makeability Lab Global Variables, including Makeability Lab version
89-
ML_WEBSITE_VERSION = "2.31.0" # Keep this updated with each release and also change the short description below
90-
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."
89+
ML_WEBSITE_VERSION = "2.31.1" # Keep this updated with each release and also change the short description below
90+
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."
9191
DATE_MAKEABILITYLAB_FORMED = datetime.date(2012, 1, 1) # Date Makeability Lab was formed
9292
MAX_BANNERS = 7 # Maximum number of banners on a page
9393

@@ -105,6 +105,96 @@
105105
# See: https://docs.djangoproject.com/en/2.0/topics/logging/
106106
# https://lincolnloop.com/blog/django-logging-right-way/
107107
# For the log format, see: https://stackoverflow.com/a/26276689/388117
108+
#
109+
# Log-file path (issue #1283): this used to be hardcoded to /code/media/debug.log,
110+
# an absolute container-specific path. Django evaluates LOGGING at django.setup(),
111+
# so on any host lacking that exact directory (e.g. GitHub Actions CI) startup died
112+
# with FileNotFoundError before a single request/test ran. Derive the path from
113+
# BASE_DIR instead (still under media/, the bind-mounted tree, so the file stays
114+
# readable over SSH — see docs/DEPLOYMENT.md), allow an ML_LOG_DIR env override, and if
115+
# the directory can't be created or written, fall back to a NullHandler so a bad
116+
# log path never crashes startup.
117+
#
118+
# Degrading is silent by default, and that is dangerous here: the 'django' logger
119+
# has only the 'file' handler, and the 'website' logger's console handler is gated
120+
# by require_debug_true (False in prod), so an unwritable log dir means the app runs
121+
# completely blind. We have no console access on the -test or prod servers, so the
122+
# degraded state is surfaced two web-reachable ways instead: the 'log_to_file' field
123+
# on /version.json (website/views/version.py) and a warning callout on the admin
124+
# dashboard (website/templates/admin/index.html).
125+
def _ensure_log_dir_writable(log_dir):
126+
"""Create ``log_dir`` if needed and return True if it looks writable.
127+
128+
Named for the side effect: this *creates* the directory (``os.makedirs``)
129+
rather than merely inspecting it. Used to decide whether the file log handler
130+
is active or degrades to a NullHandler, so a bad log path never crashes
131+
``django.setup()`` (issue #1283).
132+
133+
Two known limits, both accepted as strictly better than the previous
134+
unconditional crash:
135+
136+
1. This checks the *directory*, not the eventual log file. A dir that is
137+
writable but already holds a root-owned, read-only ``debug.log`` would
138+
still let RotatingFileHandler raise on open. That doesn't match the real
139+
deploy model, where media/ is owned by the app's own user.
140+
2. ``os.access(dir, os.W_OK)`` returns True for root regardless of the
141+
directory mode, so a mode-555 dir wouldn't be caught when running as root.
142+
The deployed container runs as ``apache`` (UID 48, see Dockerfile), so the
143+
guard is meaningful where it matters; only the root devcontainer bypasses
144+
it. The common failures — missing dir, uncreatable dir, read-only
145+
filesystem — are caught either way.
146+
"""
147+
try:
148+
os.makedirs(log_dir, exist_ok=True)
149+
return os.access(log_dir, os.W_OK)
150+
except OSError:
151+
return False
152+
153+
154+
def _file_log_handler(log_file, level, enabled):
155+
"""Return the ``LOGGING['handlers']['file']`` config dict.
156+
157+
When ``enabled`` is False (the log dir isn't writable) this returns a
158+
NullHandler instead, which keeps every logger's ``'file'`` handler reference
159+
valid while never touching disk — so startup degrades instead of dying.
160+
161+
Split out of the ``LOGGING`` literal so both branches are directly testable;
162+
``LOGGING`` is evaluated once at import, so a test can't re-derive it.
163+
See ``website/tests/test_logging_config.py``.
164+
"""
165+
if not enabled:
166+
return {'class': 'logging.NullHandler'}
167+
return {
168+
'level': level,
169+
'class': 'logging.handlers.RotatingFileHandler',
170+
'filename': log_file,
171+
'maxBytes': 1024*1024*5, # 5 MB
172+
'backupCount': 6,
173+
'formatter': 'verbose', # can switch between verbose and simple
174+
}
175+
176+
177+
# NOTE: this default must stay in sync with MEDIA_ROOT (defined further down as
178+
# os.path.join(BASE_DIR, 'media')) — the web-served /logs/debug.log URL only works
179+
# because the log lives inside the media root. MEDIA_ROOT isn't defined yet here
180+
# (LOGGING has to be built before it), hence the duplicated expression;
181+
# test_default_log_file_is_under_media_root pins the two together.
182+
LOG_DIR = os.environ.get('ML_LOG_DIR', os.path.join(BASE_DIR, 'media'))
183+
LOG_FILE = os.path.join(LOG_DIR, 'debug.log')
184+
185+
# Uppercase on purpose: Django only exposes uppercase module attributes through
186+
# django.conf.settings, and both the /version.json view and the admin dashboard
187+
# read this to surface a degraded-logging warning.
188+
LOG_TO_FILE = _ensure_log_dir_writable(LOG_DIR)
189+
190+
if not LOG_TO_FILE:
191+
# Secondary signal only. There is no console access on the -test or prod
192+
# servers, so this print is really for local dev and the emailed buildlog;
193+
# the channels that actually work remotely are /version.json (log_to_file
194+
# field) and the warning callout on the admin dashboard.
195+
print(f"WARNING: log dir {LOG_DIR!r} is not writable — file logging disabled "
196+
f"(NullHandler). Check /version.json 'log_to_file'.")
197+
108198
LOGGING = {
109199
'version': 1,
110200
'disable_existing_loggers': False,
@@ -125,21 +215,16 @@
125215
},
126216
},
127217
'handlers': {
128-
'file': {
129-
# The file handler writes /code/media/debug.log, which lands in the
130-
# bind-mounted web root and is intentionally exposed via the /logs/
131-
# URL per docs/DEPLOYMENT.md (Jason Howe's design — convenient
132-
# remote debugging in exchange for some info disclosure). To shrink
133-
# that exposure in production, we log at INFO when DEBUG is off,
134-
# but keep DEBUG-level file logging in local dev where DEBUG is on
135-
# and the file isn't publicly reachable.
136-
'level': 'DEBUG' if DEBUG else 'INFO',
137-
'class': 'logging.handlers.RotatingFileHandler',
138-
'filename': '/code/media/debug.log',
139-
'maxBytes': 1024*1024*5, # 5 MB
140-
'backupCount': 6,
141-
'formatter': 'verbose', # can switch between verbose and simple
142-
},
218+
# The file handler writes LOG_FILE (media/debug.log by default), which lands
219+
# in the bind-mounted web root — that's what makes it readable over SSH at
220+
# /cse/web/research/makelab/www[-test]/debug.log. (docs/DEPLOYMENT.md also
221+
# describes a /logs/ URL per Jason Howe's design, but that URL 404s on both
222+
# prod and test as of 2026-07-28.) Since the file still sits in a web-served
223+
# tree, stay conservative: log at INFO when DEBUG is off, but keep DEBUG-level
224+
# file logging in local dev where DEBUG is on and nothing is public. If the
225+
# log dir isn't writable (LOG_TO_FILE is False), degrade to a NullHandler so
226+
# startup never dies (issue #1283).
227+
'file': _file_log_handler(LOG_FILE, 'DEBUG' if DEBUG else 'INFO', LOG_TO_FILE),
143228
'console': {
144229
'level': 'DEBUG',
145230
'filters': ['require_debug_true'],
@@ -366,6 +451,11 @@
366451
# The MEDIA_URL is required by Django see and is a URL that handles the media served
367452
# from MEDIA_ROOT, used for managing stored files.
368453
# See: https://docs.djangoproject.com/en/4.2/ref/settings/#media-url
454+
#
455+
# NOTE: LOG_DIR (defined up with LOGGING, which has to be built before this) hard-codes
456+
# the same expression, because the web-served /logs/debug.log URL only works while the
457+
# log file lives inside the media root. If you move MEDIA_ROOT, move LOG_DIR with it —
458+
# test_default_log_file_is_under_media_root fails loudly if the two ever diverge.
369459
MEDIA_ROOT = os.path.join(BASE_DIR, 'media')
370460
MEDIA_URL = '/media/'
371461

website/context_processors.py

Lines changed: 10 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -21,14 +21,21 @@ def admin_version_info(request):
2121
"""
2222
Make version and debug info available to all templates.
2323
24-
This is used by the admin interface to display the current
24+
This is used by the admin interface to display the current
2525
website version in the header and show a debug indicator.
26-
26+
27+
LOG_TO_FILE / LOG_FILE (#1283) let the admin dashboard warn when the LOGGING
28+
file handler degraded to a NullHandler — i.e. this server is writing no logs
29+
at all. We have no console access on -test/prod, so the dashboard callout and
30+
the /version.json 'log_to_file' field are the only ways to notice.
31+
2732
Returns:
28-
dict: Context variables for ML_WEBSITE_VERSION and DEBUG.
33+
dict: Context variables for ML_WEBSITE_VERSION, DEBUG, and logging health.
2934
"""
3035
return {
3136
'ML_WEBSITE_VERSION': settings.ML_WEBSITE_VERSION,
3237
'ML_WEBSITE_VERSION_DESCRIPTION': settings.ML_WEBSITE_VERSION_DESCRIPTION,
3338
'DEBUG': settings.DEBUG,
39+
'LOG_TO_FILE': settings.LOG_TO_FILE,
40+
'LOG_FILE': settings.LOG_FILE,
3441
}

website/templates/admin/index.html

Lines changed: 61 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,25 @@
99
{% endif %}
1010
</div>
1111

12+
{% comment %}
13+
Degraded-logging warning (#1283). LOGGING's file handler falls back to a
14+
NullHandler when the log directory isn't writable, which would otherwise be
15+
completely silent: the 'django' logger has only that handler, and there is no
16+
console access on the -test or prod servers. Superuser-gated because only the
17+
maintainer can act on it. The scriptable equivalent is /version.json's
18+
'log_to_file' field.
19+
{% endcomment %}
20+
{% if user.is_superuser and not LOG_TO_FILE %}
21+
<div class="ml-log-warning">
22+
<span class="ml-log-warning-icon" aria-hidden="true">⚠️</span>
23+
<strong>Warning: file logging is disabled.</strong>
24+
<span class="ml-log-warning-desc">Django could not write to the log directory,
25+
so log records are being discarded and <code>debug.log</code> will not update.
26+
Expected path: <code>{{ LOG_FILE }}</code>. Check that directory's permissions,
27+
or the <code>ML_LOG_DIR</code> environment variable if it is set.</span>
28+
</div>
29+
{% endif %}
30+
1231
{% if user.is_superuser %}
1332
<div class="ml-data-health">
1433
<span class="ml-data-health-icon" aria-hidden="true">🩺</span>
@@ -122,6 +141,37 @@
122141
color: #666;
123142
}
124143

144+
/* Degraded-logging warning (#1283) — only rendered when logging is dead.
145+
Red-tinted rather than amber so it doesn't read as another .ml-help-text tip. */
146+
.ml-log-warning {
147+
background-color: #fdecea;
148+
border: 1px solid #f5c6c0;
149+
border-left: 4px solid #b3261e;
150+
padding: 10px 15px;
151+
margin-bottom: 20px;
152+
border-radius: 4px;
153+
font-size: 14px;
154+
}
155+
156+
.ml-log-warning strong {
157+
color: #a3261d; /* 6.4:1 on #fdecea — WCAG AA */
158+
}
159+
160+
.ml-log-warning-icon {
161+
margin-right: 6px;
162+
}
163+
164+
.ml-log-warning-desc {
165+
color: #5f2c28; /* 9.8:1 on #fdecea — WCAG AA */
166+
}
167+
168+
/* Inherit the callout's text color rather than the admin's muted <code> grey,
169+
which doesn't clear AA against these backgrounds (especially in dark mode). */
170+
.ml-log-warning code {
171+
color: inherit;
172+
background: transparent;
173+
}
174+
125175
@media (prefers-color-scheme: dark) {
126176
.ml-data-health {
127177
background-color: #25302a;
@@ -130,6 +180,17 @@
130180
.ml-data-health-desc {
131181
color: #aaa;
132182
}
183+
.ml-log-warning {
184+
background-color: #3a201d;
185+
border-color: #5a3430;
186+
border-left-color: #e06c5f;
187+
}
188+
.ml-log-warning strong {
189+
color: #f2a099; /* 7.3:1 on #3a201d — WCAG AA */
190+
}
191+
.ml-log-warning-desc {
192+
color: #d9b8b4; /* 8.2:1 on #3a201d — WCAG AA */
193+
}
133194
}
134195

135196
/* Help text styling within category tables */

0 commit comments

Comments
 (0)