I've been working on deploying various Django apps to Azure App Service this week and have run into a few issues since I'm customizing the app configuration quite a bit. Both as a reminder for myself and a resource for others, I figured I'd write up my tips for debugging Django app deployments and App Service.
After you finish deploying, first visit the app URL to see if it loads. If it does, amazing! If it doesn't, here are steps you can take to figure out what went wrong.
Check the deployment logs
Select Deployment Center from the side navigation menu, then select Logs. You should see a timestamped list of recent deploys:
Check whether the status of the most recent deploy is "Success (Active)" or "Failed". If it's success, the deployment logs might still reveal issues, and if it's failed, the logs should certainly reveal the issue.
Click the commit ID to open the logs for the most recent deploy. First scroll down to see if any errors or warnings are reported at the end. This is what you'll hopefully see if all went well:
Now scroll back up to find the timestamp with the label "Running oryx build". Oryx is the open source tool that builds apps for App Service, Functions, and other platforms, across all the supported MS languages. Click the Show logs link next to that label. That will pop open detailed logs at the bottom. Scroll down.
Here's what a successful Oryx build looks like for a Django application:
Command: oryx build /tmp/zipdeploy/extracted -o /home/site/wwwroot --platform python --platform-version 3.10 -p virtualenv_name=antenv --log-file /tmp/build-debug.log -i /tmp/8dad4af021551b0 --compress-destination-dir | tee /tmp/oryx-build.log
Operation performed by Microsoft Oryx, https://github.com/Microsoft/Oryx
You can report issues at https://github.com/Microsoft/Oryx/issues
Oryx Version: 0.2.20220825.1, Commit: 24032445dbf7bf6ef068688f1b123a7144453b7f, ReleaseTagName: 20220825.1
Build Operation ID: |BrSlkWT7Cgo=.afae917a_
Repository Commit : 0aed8982-e84a-4573-9ed8-82d46e9056c4
Detecting platforms...
Detected following platforms:
python: 3.10.8
Using intermediate directory '/tmp/8dad4af021551b0'.
Copying files to the intermediate directory...
Done in 0 sec(s).
Source directory : /tmp/8dad4af021551b0
Destination directory: /home/site/wwwroot
Python Version: /tmp/oryx/platforms/python/3.10.8/bin/python3.10
Creating directory for command manifest file if it does not exist
Removing existing manifest file
Python Virtual Environment: antenv
Creating virtual environment...
Activating virtual environment...
Running pip install...
[21:49:24+0000] Collecting Django==4.1.1
[21:49:24+0000] Using cached Django-4.1.1-py3-none-any.whl (8.1 MB)
[21:49:25+0000] Collecting psycopg2
[21:49:25+0000] Using cached psycopg2-2.9.5-cp310-cp310-linux_x86_64.whl
[21:49:25+0000] Collecting python-dotenv
[21:49:25+0000] Using cached python_dotenv-0.21.0-py3-none-any.whl (18 kB)
[21:49:25+0000] Collecting whitenoise[brotli]
[21:49:25+0000] Using cached whitenoise-6.2.0-py3-none-any.whl (19 kB)
[21:49:25+0000] Collecting asgiref<4,>=3.5.2
[21:49:26+0000] Using cached asgiref-3.5.2-py3-none-any.whl (22 kB)
[21:49:26+0000] Collecting sqlparse>=0.2.2
[21:49:26+0000] Using cached sqlparse-0.4.3-py3-none-any.whl (42 kB)
[21:49:26+0000] Collecting Brotli
[21:49:26+0000] Using cached Brotli-1.0.9-cp310-cp310-manylinux_2_5_x86_64.manylinux1_x86_64.manylinux_2_12_x86_64.manylinux2010_x86_64.whl (2.7 MB)
[21:49:27+0000] Installing collected packages: Brotli, whitenoise, sqlparse, python-dotenv, psycopg2, asgiref, Django
[21:49:38+0000] Successfully installed Brotli-1.0.9 Django-4.1.1 asgiref-3.5.2 psycopg2-2.9.5 python-dotenv-0.21.0 sqlparse-0.4.3 whitenoise-6.2.0
[notice] A new release of pip available: 22.2.2 -> 22.3.1
[notice] To update, run: pip install --upgrade pip
Content in source directory is a Django app
Running collectstatic...
132 static files copied to '/tmp/8dad4af021551b0/staticfiles', 643 post-processed.
Done in 21 sec(s).
Not a vso image, so not writing build commands
Preparing output...
Copying files to destination directory '/tmp/_preCompressedDestinationDir'...
Done in 22 sec(s).
Compressing content of directory '/tmp/_preCompressedDestinationDir'...
Copied the compressed output to '/home/site/wwwroot'
Removing existing manifest file
Creating a manifest file...
Manifest file created.
Copying .ostype to manifest output directory.
Done in 103 sec(s).
Look for these important steps in the Oryx build:
Detected following platforms: python: 3.10.8
That should match your runtime in the App Service configuration.Running pip install...
That should install all the requirements in your requirements.txt - if it didn't find your requirements.txt, then you won't see the packages installed.Content in source directory is a Django app
This message means that Oryx detected your app is a Django app, based on the presence of Django in requirements.txt, and will now run the next step.Running collectstatic...This step is running `manage.py collectstatic`, a necessary step for most Django apps. It can be disabled via theDISABLE_COLLECTSTATICenvironment variable if desired.
If you see all those steps in the Oryx build, then that's a good sign that the build went well, and you can move on to checking the App Service logs.
Check the log stream
Under the Monitoring section of the side nav, select Log stream. Scroll to the timestamp corresponding to your most recent deploy.
The logs should start with pulling Docker images:
Here are the full logs for a Django app successfully starting in an App Service container:
2023-01-04T18:20:46.723Z INFO - 3.10_20221128.12.tuxprod Pulling from appsvc/python
2023-01-04T18:20:46.731Z INFO - Digest: sha256:03576ed3edbc1bd69db8826f2cb5bbbdcfd483da4dab4f51f5050972491afef3
2023-01-04T18:20:46.733Z INFO - Status: Image is up to date for mcr.microsoft.com/appsvc/python:3.10_20221128.12.tuxprod
2023-01-04T18:20:46.760Z INFO - Pull Image successful, Time taken: 0 Minutes and 0 Seconds
2023-01-04T18:20:47.273Z INFO - Starting container for site
2023-01-04T18:20:47.285Z INFO - docker run -d --expose=8000 --name djangocc-vssonnwxjqvw2-app-service_2_4555c318 -e WEBSITE_SITE_NAME=djangocc-vssonnwxjqvw2-app-service -e WEBSITE_AUTH_ENABLED=False -e PORT=8000 -e WEBSITE_ROLE_INSTANCE_ID=0 -e WEBSITE_HOSTNAME=djangocc-vssonnwxjqvw2-app-service.azurewebsites.net -e WEBSITE_INSTANCE_ID=37c77572be775c3da9e718e75bdd3dcd6c69246656e6f77972070ce4bfef6455 -e HTTP_LOGGING_ENABLED=1 -e WEBSITE_USE_DIAGNOSTIC_SERVER=True appsvc/python:3.10_20221128.12.tuxprod python manage.py migrate && gunicorn --workers 2 --threads 4 --timeout 60 --access-logfile '-' --error-logfile '-' --bind=0.0.0.0:8000 --chdir=/home/site/wwwroot config.wsgi
2023-01-04T18:21:01.494Z INFO - Initiating warmup request to container djangocc-vssonnwxjqvw2-app-service_2_4555c318_msiProxy for site djangocc-vssonnwxjqvw2-app-service
2023-01-04T18:21:01.524Z INFO - Container djangocc-vssonnwxjqvw2-app-service_2_4555c318_msiProxy for site djangocc-vssonnwxjqvw2-app-service initialized successfully and is ready to serve requests.
2023-01-04T18:21:01.531Z INFO - Initiating warmup request to container djangocc-vssonnwxjqvw2-app-service_2_4555c318 for site djangocc-vssonnwxjqvw2-app-service
2023-01-04T18:21:17.476Z INFO - Waiting for response to warmup request for container djangocc-vssonnwxjqvw2-app-service_2_4555c318. Elapsed time = 16.0211255 sec
2023-01-04T18:21:33.263Z INFO - Waiting for response to warmup request for container djangocc-vssonnwxjqvw2-app-service_2_4555c318. Elapsed time = 31.8082536 sec
2023-01-04T18:21:37.548Z INFO - Container djangocc-vssonnwxjqvw2-app-service_2_4555c318 for site djangocc-vssonnwxjqvw2-app-service initialized successfully and is ready to serve requests.
2023-01-04T18:21:00.181237975Z _____
2023-01-04T18:21:00.181266077Z / _ \ __________ _________ ____
2023-01-04T18:21:00.181271277Z / /_\ \\___ / | \_ __ \_/ __ \
2023-01-04T18:21:00.181274977Z / | \/ /| | /| | \/\ ___/
2023-01-04T18:21:00.181278277Z \____|__ /_____ \____/ |__| \___ >
2023-01-04T18:21:00.181281678Z \/ \/ \/
2023-01-04T18:21:00.181284978Z A P P S E R V I C E O N L I N U X
2023-01-04T18:21:00.181288278Z
2023-01-04T18:21:00.181291278Z Documentation: http://aka.ms/webapp-linux
2023-01-04T18:21:00.181294478Z Python 3.10.4
2023-01-04T18:21:00.181297678Z Note: Any data outside '/home' is not persisted
2023-01-04T18:21:01.465437465Z Starting OpenBSD Secure Shell server: sshd.
2023-01-04T18:21:01.683907061Z Site's appCommandLine: python manage.py migrate && gunicorn --workers 2 --threads 4 --timeout 60 --access-logfile '-' --error-logfile '-' --bind=0.0.0.0:8000 --chdir=/home/site/wwwroot config.wsgi
2023-01-04T18:21:02.113255325Z Starting periodic command scheduler: cron.
2023-01-04T18:21:02.115641859Z Launching oryx with: create-script -appPath /home/site/wwwroot -output /opt/startup/startup.sh -virtualEnvName antenv -defaultApp /opt/defaultsite -userStartupCommand 'python manage.py migrate && gunicorn --workers 2 --threads 4 --timeout 60 --access-logfile '-' --error-logfile '-' --bind=0.0.0.0:8000 --chdir=/home/site/wwwroot config.wsgi'
2023-01-04T18:21:02.513265532Z Found build manifest file at '/home/site/wwwroot/oryx-manifest.toml'. Deserializing it...
2023-01-04T18:21:02.518158007Z Build Operation ID: |83xYwqpdGr0=.fe7a9527_
2023-01-04T18:21:02.519884905Z Oryx Version: 0.2.20220825.1, Commit: 24032445dbf7bf6ef068688f1b123a7144453b7f, ReleaseTagName: 20220825.1
2023-01-04T18:21:02.520450236Z Output is compressed. Extracting it...
2023-01-04T18:21:02.533109549Z Extracting '/home/site/wwwroot/output.tar.gz' to directory '/tmp/8daee7f6ddb01b5'...
2023-01-04T18:21:22.545602410Z App path is set to '/tmp/8daee7f6ddb01b5'
2023-01-04T18:21:22.611376378Z Writing output script to '/opt/startup/startup.sh'
2023-01-04T18:21:24.124335826Z Using packages from virtual environment antenv located at /tmp/8daee7f6ddb01b5/antenv.
2023-01-04T18:21:24.125478895Z Updated PYTHONPATH to '/opt/startup/app_logs:/tmp/8daee7f6ddb01b5/antenv/lib/python3.10/site-packages'
2023-01-04T18:21:31.321664095Z Operations to perform:
2023-01-04T18:21:31.321750300Z Apply all migrations: account, admin, auth, contenttypes, sessions, sites, socialaccount, users
2023-01-04T18:21:31.321758001Z Running migrations:
2023-01-04T18:21:31.321762401Z No migrations to apply.
2023-01-04T18:21:33.977904663Z [2023-01-04 18:21:33 +0000] [80] [INFO] Starting gunicorn 20.1.0
2023-01-04T18:21:33.986985797Z [2023-01-04 18:21:33 +0000] [80] [INFO] Listening at: http://0.0.0.0:8000 (80)
2023-01-04T18:21:33.987019399Z [2023-01-04 18:21:33 +0000] [80] [INFO] Using worker: gthread
2023-01-04T18:21:34.016193616Z [2023-01-04 18:21:34 +0000] [81] [INFO] Booting worker with pid: 81
2023-01-04T18:21:34.093535167Z [2023-01-04 18:21:34 +0000] [82] [INFO] Booting worker with pid: 82
2023-01-04T18:30:36.727907506Z djangocc-vssonnwxjqvw2-app-service : [200ef84a-9498-4d8b-8023-11edbfe8251f] Incoming request on /healthcheck?api-version=2021-08-01
2023-01-04T18:30:36.740159926Z djangocc-vssonnwxjqvw2-app-service : [200ef84a-9498-4d8b-8023-11edbfe8251f] Request to TokenService: Endpoint 169.254.129.14:8081, Port 8081, Path /healthcheck, Query ?api-version=2021-08-01, Method GET, UserAgent HealthCheck/1.0
2023-01-04T18:30:37.201139217Z djangocc-vssonnwxjqvw2-app-service : [200ef84a-9498-4d8b-8023-11edbfe8251f] Returning response for Site , Endpoint 169.254.129.14:8081, Port 8081, Path /healthcheck, Method GET, Result = 200
A few notable logs:
2023-01-04T18:21:01.683907061Z Site's appCommandLine: python manage.py migrate && gunicorn --workers 2 --threads 4 --timeout 60 --access-logfile '-' --error-logfile '-' --bind=0.0.0.0:8000 --chdir=/home/site/wwwroot config.wsgi
This log shows up because my app overrides the app's startup command (`appCommandLine` in a Bicep file). If your app doesn't override the startup command, then Oryx will generate a startup script for you that calls `gunicorn` to start the server. The default startup script does not callmanage.py migrate, so that's why my app overrides it.2023-01-04T18:21:31.321758001Z Running migrations:
That proves that the container did indeed all `manage.py migrate` from my custom startup script.2023-01-04T18:21:33.977904663Z [2023-01-04 18:21:33 +0000] [80] [INFO] Starting gunicorn 20.1.0
That's the start of the gunicorn server serving the Django app. After it starts, the logs should show HTTP requests.
If you aren't seeing the full logs, it's possible that your deploy happened too long ago and the portal has deleted some logs. In that case, open the Log stream and do another deploy, and you should see the full logs.
Alternatively, you can download the full logs from the Kudu interface. Select Advanced Tools from the side nav:
When the Kudu website loads, find the Current Docker Logs link and select Download as zip next to it:
In the downloaded zip file, find the filename that starts with the most recent date and ends with "_default_docker.log":
Open that file to see the full logs, with the most recent logs at the bottom.
No comments:
Post a Comment