Debugging And Testing Production Issues
Popping a few layers off the stack of things we’re working on: we have nice wait-for helpers; what were we using them for? Oh yes, waiting to be logged in. And why was that? Ah yes, we had just built a way of pre-authenticating a user. Let’s see how that works against our staging server and Docker.
The Proof Is in the Pudding: Using Docker to Catch Final Bugs
Remember the deployment checklist from [chapter_18_second_deploy]? Let’s see if it can’t come in useful today!
First, we rebuild and start our Docker container locally, on port 8888:
$ docker build -t superlists . && docker run \
-p 8888:8888 \
--mount type=bind,source="$PWD/src/db.sqlite3",target=/src/db.sqlite3 \
-e DJANGO_SECRET_KEY=sekrit \
-e DJANGO_ALLOWED_HOST=localhost \
-it superlists
[...]
=> => naming to docker.io/library/superlists [...]
[2025-01-27 22:37:02 +0000] [7] [INFO] Starting gunicorn 22.0.0
[2025-01-27 22:37:02 +0000] [7] [INFO] Listening at: http://0.0.0.0:8888 (7)
[2025-01-27 22:37:02 +0000] [7] [INFO] Using worker: sync
[2025-01-27 22:37:02 +0000] [8] [INFO] Booting worker with pid: 8
And now let’s do an FT run:
$ TEST_SERVER=localhost:8888 python src/manage.py test functional_tests [...] selenium.common.exceptions.NoSuchElementException: Message: Unable to locate element: #id_logout; [...] [...] AssertionError: 'Check your email' not found in 'Server Error (500)' [...] FAILED (failures=1, errors=1)
We can’t log in—either with the real email system or with our pre-authenticated session. Looks like our nice new authentication system is crashing when we run it in Docker.
Let’s practice a bit of production debugging!
Inspecting the Docker Container Logs
When Django fails with a 500 or "Unhandled Exception" and DEBUG is off, it doesn’t print the tracebacks to your web browser. But it will send them to your logs instead.
If you switch to the terminal that’s running your Docker image, you should see the traceback printed out in there:
Internal Server Error: /accounts/send_login_email
Traceback (most recent call last):
[...]
File "/src/accounts/views.py", line 16, in send_login_email
send_mail(
~~~^
"Your login link for Superlists",
^^^^^^^^^^^
...<2 lines>...
[email],
^^^^
)
^
[...]
self.connection.sendmail(
~~~~~~~~^
from_email, recipients, message.as_bytes(linesep="\r\n")
^^^^^^^^^^^^^^^^^^^^
)
^
File "/usr/local/lib/python3.13/smtplib.py", line 876, in sendmail
raise SMTPSenderRefused(code, resp, from_addr)
smtplib.SMTPSenderRefused: (530, b'5.7.0 Authentication Required. [...]
That looks like a pretty good clue to what’s going on.
Sure enough! Good to know our local Docker setup can repro the error on the server.
Another Environment Variable In Docker
So, Gmail is refusing to let us send emails, is it? Now why might that be? "Authentication Required" you say? Oh woops, we haven’t told the server what our password is!
As you might remember from earlier chapters,
our settings.py expects to get the email server password from an environment variable
named EMAIL_PASSWORD:
EMAIL_HOST_PASSWORD = os.environ.get("EMAIL_PASSWORD")Let’s add this new environment variable to our local Docker container run
command:
First, set your email password in your terminal if you need to:
$ echo $EMAIL_PASSWORD # if that's empty, let's set it: $ export EMAIL_PASSWORD="yoursekritpasswordhere"
Now let’s pass that env var through to our docker container using one more -e flag,
this one fishing the env var out of the shell we’re in:
$ docker build -t superlists . && docker run \
-p 8888:8888 \
--mount type=bind,source="$PWD/src/db.sqlite3",target=/src/db.sqlite3 \
-e DJANGO_SECRET_KEY=sekrit \
-e DJANGO_ALLOWED_HOST=localhost \
-e EMAIL_PASSWORD \
-it superlists
If you use -e without an =something argument,
it sets the env var inside Docker to the same value set in the current shell.
It’s like saying -e EMAIL_PASSWORD=$EMAIL_PASSWORD
|
And now we can rerun our FT again.
We’ll narrow it down to just the test_login test since that’s the main one that has a problem:
$ TEST_SERVER=localhost:8888 python src/manage.py test functional_tests.test_login
[...]
ERROR: test_login_using_magic_link
(functional_tests.test_login.LoginTest.test_login_using_magic_link)
---------------------------------------------------------------------
Traceback (most recent call last):
File "...goat-book/src/functional_tests/test_login.py", line 32, in
test_login_using_magic_link
email = mail.outbox.pop()
IndexError: pop from empty list
Well, not a pass, but the tests do get a little further.
It looks like our server can now send emails
(if you check the docker logs, you’ll see there are no more errors)
But our FT is saying it can’t see any emails appearing in mail.outbox.
mail.outbox Won’t Work Outside Django’s Test Environment
The reason is that mail.outbox is a local, in-memory variable in Django,
so that’s only going to work when our tests and our server are running in the same process,
like they do with unit tests or with LiveServerTestCase FTs.
When we run against another process, be it Docker or an actual server,
we can’t access the same mail.outbox variable.
We need another technique if we want to actually inspect the emails that the server sends, in our tests against Docker (or later, against the staging server).
Deciding How to Test "Real" Email Sending
This is a point at which we have to explore some tradeoffs. There are a few different ways we could test this:
-
We could build a "real" end-to-end test, and have our tests log in to an email server, and retrieve the email from there. That’s what I did in the first and second editions of this book.
-
You can use a service like Mailinator or Mailsac, which gives you an email account to send to, and some APIs for checking what mail has been delivered.
-
We can use an alternative, fake email backend, whereby Django will save the emails to a file on disk for example, and we can inspect them there.
-
We could give up on testing email on the server. If we have a minimal smoke test that the server can send emails, then we don’t need to test that they are actually delivered.
But let’s lay out some of the pros and cons:
Strategy |
Pros |
Cons |
End-to-end with POP3 |
Maximally realistic, tests the whole system |
Slow, fiddly, unreliable |
Email testing service eg Mailinator/Mailsac |
As realistic as real POP3, with better APIs for testing |
Slow, possibly expensive. Plus I don’t want to endorse any particular commercial provider ;-) |
File-based fake email backend |
Faster, more reliable, no network calls, tests end-to-end (albeit with fake components) |
Still Fiddly, requires managing db & filesystem side-effects |
Give up on testing email on the server/Docker |
Fast, simple |
Less confidence that things work "for real" |
This is a common problem in testing integration with external systems, how far should we go? How realistic should we make our tests?
In this case, I’m going to suggest we go for the last option, which is not to test email sending on the server or in Docker.
Email itself is a well-understood protocol (reader, it’s been around since before I was born, and that’s a while ago now) and Django has supported sending email for more than a decade, so I think we can afford to say, in this case, that the costs of building testing tools for email outweigh the benefits.
I’m going to suggest we stick to using mail.outbox when we’re running local tests,
and we configure our FTs to just check that Docker (or, later, the staging server)
seems to be able to send email (in the sense of "not crashing")
and we can skip the bit where we check the email contents in our FT.
Remember, we also have unit tests for the email content!
| I explore some of the difficulties involved in getting these kinds of tests to work in [appendix_fts_for_external_dependencies], so go check that out if this feels like a bit of a cop-out! |
Here’s where we can put an early return in the FT:
# A message appears telling her an email has been sent
self.wait_for(
lambda: self.assertIn(
"Check your email",
self.browser.find_element(By.CSS_SELECTOR, "body").text,
)
)
if self.test_server:
# Testing real email sending from the server is not worth it.
return
# She checks her email and finds a message
email = mail.outbox.pop()This test will still fail if you don’t set EMAIL_PASSWORD to a valid value
in Docker or on the server, so that’s good enough for now.
Here’s how we populate the .test_server attribute:
class FunctionalTest(StaticLiveServerTestCase):
def setUp(self):
self.browser = webdriver.Firefox()
self.test_server = os.environ.get("TEST_SERVER") (1)
if self.test_server:
self.live_server_url = "http://" + self.test_server| 1 | We upgrade test_server to being an attribute on the test object,
so we can access it in various places in our tests.
We’ll see this come in useful later too! |
And you can confirm that the FT will fail if you don’t set EMAIL_PASSWORD in Docker.
Now let’s see if we can get our FTs to pass against the server:
Setting Secret Environment Variables on the Server
Just as in [chapter_11_server_prep], the place we set environment variables on the server is in the superlists.env file.
Let’s add it to the template first:
DJANGO_DEBUG_FALSE=1
DJANGO_SECRET_KEY={{ secret_key }}
DJANGO_ALLOWED_HOST={{ host }}
EMAIL_PASSWORD={{ email_password }}And now we add the line to the ansible deploy playbook that looks up EMAIL_PASSWORD in our local environment:
- name: Ensure .env file exists
ansible.builtin.template:
src: env.j2
dest: ~/superlists.env
force: true # update file if contents changed
vars:
host: "{{ inventory_hostname }}"
secret_key: "{{ lookup('password', '/dev/null length=32 chars=ascii_letters') }}"
email_password: "{{ lookup('env', 'EMAIL_PASSWORD') }}" (1)| 1 | We use another call to lookup(),
this one with the env parameter,
which is equivalent to os.environ.get() in Python. |
Moving on to the next failure
Now if we rerun our full set of FTs, we can move on to the next failure:
$ TEST_SERVER=localhost:8888 python src/manage.py test functional_tests
Now we can rerun our full FT suite and get to the next failure: our attempt to create pre-authenticated sessions doesn’t work, so the "My Lists" test fails:
$ TEST_SERVER=staging.ottg.co.uk python src/manage.py test functional_tests
[...]
ERROR: test_logged_in_users_lists_are_saved_as_my_lists
(functional_tests.test_my_lists.MyListsTest.test_logged_in_users_lists_are_saved_as_my_lists)
----------------------------------------------------------------------
Traceback (most recent call last):
File "...goat-book/src/functional_tests/test_my_lists.py", line 36, in
test_logged_in_users_lists_are_saved_as_my_lists
self.wait_to_be_logged_in(email)
~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^
[...]
selenium.common.exceptions.NoSuchElementException: Message: Unable to locate
element: #id_logout; [...]
[...]
---------------------------------------------------------------------
Ran 8 tests in 30.087s
FAILED (errors=1)
It fails because our test utility function create_pre_authenticated_session()
only acts on the local database.
Let’s find out how our tests can manage the database on the server.
A Django Management Command to Create Sessions
We need a way to make changes to the database inside Docker, or on the server. Essentially we want to run some code outside the context of the tests (and the test database) and in the context of the server and its database.
When trying to build a standalone script that works with Django
(i.e., can talk to the database and so on),
there are some fiddly issues you need to get right,
like setting the DJANGO_SETTINGS_MODULE environment variable,
and setting sys.path correctly.
Instead of messing about with all that, Django lets you create your own
"management commands" (commands you can run with python manage.py), which
will do all that path mangling for you. They live in a folder called
management/commands inside your apps:
$ mkdir -p src/functional_tests/management/commands $ touch src/functional_tests/management/__init__.py $ touch src/functional_tests/management/commands/__init__.py
The boilerplate in a management command is a class that inherits from
django.core.management.BaseCommand, and that defines a method called
handle:
from django.conf import settings
from django.contrib.auth import BACKEND_SESSION_KEY, SESSION_KEY, get_user_model
from django.contrib.sessions.backends.db import SessionStore
from django.core.management.base import BaseCommand
User = get_user_model()
class Command(BaseCommand):
def add_arguments(self, parser):
parser.add_argument("email")
def handle(self, *args, **options):
session_key = create_pre_authenticated_session(options["email"])
self.stdout.write(session_key)
def create_pre_authenticated_session(email):
user = User.objects.create(email=email)
session = SessionStore()
session[SESSION_KEY] = user.pk
session[BACKEND_SESSION_KEY] = settings.AUTHENTICATION_BACKENDS[0]
session.save()
return session.session_keyWe’ve taken the code for create_pre_authenticated_session from
test_my_lists.py. handle will pick up an email address from the parser,
and then return the session key that we’ll want to add to our browser cookies,
and the management command prints it out at the command line. Try it out:
$ python src/manage.py create_session [email protected] Unknown command: 'create_session'. Did you mean clearsessions?
One more step: we need to add functional_tests to our settings.py
for it to recognise it as a real app that might have management commands as
well as tests:
+++ b/superlists/settings.py
@@ -42,6 +42,7 @@ INSTALLED_APPS = [
"lists",
"accounts",
+ "functional_tests",
]Now it works:
$ python src/manage.py create_session [email protected] qnslckvp2aga7tm6xuivyb0ob1akzzwl
If you see an error saying the auth_user table is missing,
you may need to run manage.py migrate.
In case that doesn’t work, delete the db.sqlite3 file
and run migrate again, to get a clean slate.
|
Getting the FT to Run the Management Command on the Server
Next we need to adjust test_my_lists so that it runs the local function
when we’re on the local server,
and make it run the management command on the staging server if we’re on that:
from django.conf import settings
from .base import FunctionalTest
from .container_commands import create_session_on_server
from .management.commands.create_session import create_pre_authenticated_session
class MyListsTest(FunctionalTest):
def create_pre_authenticated_session(self, email):
if self.test_server:
session_key = create_session_on_server(self.test_server, email)
else:
session_key = create_pre_authenticated_session(email)
## to set a cookie we need to first visit the domain.
## 404 pages load the quickest!
self.browser.get(self.live_server_url + "/404_no_such_url/")
self.browser.add_cookie(
dict(
name=settings.SESSION_COOKIE_NAME,
value=session_key,
path="/",
)
)
[...]Running Commands Using Docker Exec and (optionally) SSH
You may remember docker exec from [chapter_09_docker], it lets us run
commands inside a running Docker container.
That’s fine for when we’re running against the local Docker,
but when we’re against the server, we need to SSH in first.
There’s a bit of plumbing here, but I’ve tried to break things down into small chunks:
import subprocess
USER = "elspeth"
def create_session_on_server(host, email):
return _exec_in_container(
host, ["/venv/bin/python", "/src/manage.py", "create_session", email] (1)
)
def _exec_in_container(host, commands):
if "localhost" in host: (2)
return _exec_in_container_locally(commands)
else:
return _exec_in_container_on_server(host, commands)
def _exec_in_container_locally(commands):
print(f"Running {commands} on inside local docker container")
return _run_commands(["docker", "exec", _get_container_id()] + commands) (3)
def _exec_in_container_on_server(host, commands):
print(f"Running {commands!r} on {host} inside docker container")
return _run_commands(
["ssh", f"{USER}@{host}", "docker", "exec", "superlists"] + commands (4)
)
def _get_container_id():
return subprocess.check_output( (5)
["docker", "ps", "-q", "--filter", "ancestor=superlists"] (3)
).strip()
def _run_commands(commands):
process = subprocess.run( (5)
commands,
stdout=subprocess.PIPE,
stderr=subprocess.STDOUT,
check=False,
)
result = process.stdout.decode()
if process.returncode != 0:
raise Exception(result)
print(f"Result: {result!r}")
return result.strip()| 1 | We invoke our management command with the path to the virtualenv python,
the create_session command name, and pass in the email we want to create a session for |
| 2 | We dispatch to two slightly different ways of running a command inside a container, with the assumption that a host that’s on "localhost" is a local Docker container, and the others are on the staging server. |
| 3 | To run a command on the local Docker container, we’re going to use docker exec,
and we have a little extra hop first to get the correct container ID. |
| 4 | To run a command on the Docker container that’s on the staging server,
we still use docker exec, but we do it inside an SSH session.
In this case we don’t need the container ID, because the container is always named "superlists'. |
| 5 | Finally we use Python’s subprocess module to actually run a command.
You can see a couple of different ways of running it here,
which differ based on how we’re handing errors and output;
the details don’t matter too much. |
Recap: Creating Sessions Locally Versus Staging
Does that all make sense? Perhaps a little ascii-art diagram will help:
Locally:
+-----------------------------------+ +-------------------------------------+ | MyListsTest | --> | .management.commands.create_session | | .create_pre_authenticated_session | | .create_pre_authenticated_session | | (locally) | | (locally) | +-----------------------------------+ +-------------------------------------+
Against Docker locally:
+-----------------------------------+ +-------------------------------------+
| MyListsTest | | .management.commands.create_session |
| .create_pre_authenticated_session | | .create_pre_authenticated_session |
| (locally) | | (in Docker) |
+-----------------------------------+ +-------------------------------------+
| ^
v |
+----------------------------+ +-------------+ +----------------------------+
| server_tools | --> | docker exec | --> | ./manage.py create_session |
| .create_session_on_server | +-------------+ | (in Docker) |
| (locally) | +----------------------------+
+----------------------------+
Against Docker locally:
+-----------------------------------+ +-------------------------------------+
| MyListsTest | | .management.commands.create_session |
| .create_pre_authenticated_session | | .create_pre_authenticated_session |
| (locally) | | (on server) |
+-----------------------------------+ +-------------------------------------+
| ^
v |
+----------------------------+ +-----+ +-------------+ +------------------------------+
| server_tools | --> | ssh | -> | docker exec | --> | ./manage.py create_session |
| .create_session_on_server | +-----+ +-------------+ | (on server) |
| (locally) | +------------------------------+
+----------------------------+
Testing the Management Command
In any case, let’s see if it works. First, locally, to check that we didn’t break anything:
$ python src/manage.py test functional_tests.test_my_lists [...] OK
Next, against Docker. Rebuild first:
$ docker build -t superlists . && docker run \
-p 8888:8888 \
--mount type=bind,source="$PWD/src/db.sqlite3",target=/src/db.sqlite3 \
-e DJANGO_SECRET_KEY=sekrit \
-e DJANGO_ALLOWED_HOST=localhost \
-e EMAIL_PASSWORD \
-it superlists
And then we run the FT that uses our fixture, against Docker:
$ TEST_SERVER=localhost:8888 python src/manage.py test functional_tests.test_my_lists [...] OK
And now against the server. First, re-deploy to make sure our
$ pass:quotes[ansible-playbook --user=elspeth -i staging.ottg.co.uk, infra/deploy-playbook.yaml.yaml -vv]
And now we run the test:
$ TEST_SERVER=staging.ottg.co.uk python src/manage.py test \ functional_tests.test_my_lists Found 1 test(s). Creating test database for alias 'default'... System check identified no issues (0 silenced). Running '/venv/bin/python /src/manage.py create_session [email protected]' on staging.ottg.co.uk inside docker container Result: '7n032ogf179t2e7z3olv9ct7b3d4dmas\n' . --------------------------------------------------------------------- Ran 1 test in 4.515s OK Destroying test database for alias 'default'...
Looking good! We can rerun all the tests to make sure…
$ TEST_SERVER=staging.ottg.co.uk python src/manage.py test functional_tests [...] [[email protected]] run: ~/sites/staging.ottg.co.uk/.venv/bin/python [...] Ran 8 tests in 89.494s OK
Hooray!
Test Database Cleanup
One more thing to be aware of: now that we’re running against a real database, we don’t get cleanup for free any more. If you try running the tests twice—locally or against Docker, you’ll run into this error:
$ TEST_SERVER=localhost:8888 python src/manage.py test functional_tests.test_my_lists [...] django.db.utils.IntegrityError: UNIQUE constraint failed: accounts_user.email
It’s because the user we created the first time we ran the tests is still in the database. When we’re running against Django’s test database, Django cleans up for us. Let’s try and emulate that when we’re running against a real database:
def reset_database(host):
return _exec_in_container(
host, ["/venv/bin/python", "/src/manage.py", "flush", "--noinput"]
)And let’s add the call to reset_database() in our base test setUp() method:
from .container_commands import reset_database (1)
[...]
class FunctionalTest(StaticLiveServerTestCase):
def setUp(self):
self.browser = webdriver.Firefox()
self.test_server = os.environ.get("TEST_SERVER")
if self.test_server:
self.live_server_url = "http://" + self.test_server
reset_database(self.test_server)If you try to run your tests again, you’ll find they pass happily.
$ TEST_SERVER=localhost:8888 python src/manage.py test functional_tests.test_my_lists [...] OK
Wrap-Up
Actually getting your new code up and running on a server always tends to flush out some last-minute bugs and unexpected issues. We had to do a bit of work to get through them, but we’ve ended up with several useful things as a result.
We now have a lovely generic wait decorator which will be a nice Pythonic
helper for our FTs from now on. We have test fixtures that work both
locally and on the server, including the ability to test "real" email
integration. And we’ve got some more robust logging configuration.
But before we can deploy our actual live site, we’d better actually give the users what they wanted—the next chapter describes how to give them the ability to save their lists on a "My Lists" page.
Comments