I have built a docker image that contains a pre-built application that I cannot add logging statements to. The application makes many HTTP requests as it executes, and I would like to log those requests, and in particular, the time it takes for those responses to be fulfilled. Is there something I add to my docker container, such as a proxy, that would allow me to log response times to all outgoing HTTP requests?
To log outgoing requests, you can set up Nginx as a forward proxy.
To illustrate, I've created this Flask app which makes a request to Google when we hit the / endpoint.
from flask import Flask
import requests
app = Flask(__name__)
@app.route("/")
def hello_world():
r = requests.get('http://www.google.com')
return r.text
and Dockerfile
FROM python:latest
WORKDIR /app
RUN pip install flask requests
COPY hello.py .
CMD flask --app hello run --host=0.0.0.0
We then configure Nginx to listen on port 80 and pass all requests on to the host indicated in the request
log_format upstream_time '$remote_addr - $remote_user [$time_local] '
'"$request" $status $body_bytes_sent '
'"$http_referer" "$http_user_agent" '
'"$upstream_response_time"';
server {
listen 80;
location / {
resolver 8.8.8.8;
proxy_pass http://$http_host$uri$is_args$args;
}
access_log /var/log/nginx/access.log upstream_time;
}
I've added a custom log format that logs the response time from the server we're calling.
We can then orchestrate the 2 containers using Docker Compose like this. Note that we're setting the http_proxy environment variable for the application container. That causes it to pass all outgoing requests to the proxy container instead of calling directly.
version: '3'
services:
app:
build: .
ports:
- 5000:5000
environment:
- http_proxy=http://nginx/
nginx:
image: nginx:latest
volumes:
- ./nginx.conf:/etc/nginx/conf.d/default.conf
Now we can run the containers, make a request and check the log with
docker compose up -d
curl http://localhost:5000/
docker compose logs nginx
At the end of the log messages, you'll see the response time from the server (in the example, it's Google). My log looks like this and shows a response time of 112ms.
172.24.0.3 - - [10/Oct/2023:20:14:46 +0000] "GET http://www.google.com/ HTTP/1.1" 200 8264 "-" "python-requests/2.31.0" "0.112"
If you want to log incoming requests, you can set up Nginx as a reverse proxy.
To create an app to measure, I've used this Dockerfile that creates a template C# web API application that listens on port 80 and responds to requests on /weatherforecast. I've used this since I'm familiar with it and it's easy to set up. You should use your application instead.
FROM mcr.microsoft.com/dotnet/sdk:7.0 AS build
WORKDIR /src
RUN dotnet new webapi -n myapp -o . --no-https
RUN dotnet publish -o /app
FROM mcr.microsoft.com/dotnet/aspnet:7.0
WORKDIR /app
COPY --from=build /app /app
CMD ["dotnet", "myapp.dll"]
We'll orchestrate the application and Nginx using this docker-compose.yml file
version: '3'
services:
myapp:
build: .
nginx:
image: nginx:latest
ports:
- 8000:80
volumes:
- ./nginx.conf:/etc/nginx/conf.d/default.conf
This runs the application ('myapp') and Nginx. Nginx listens on the host's port 8000 and is configured with a file called nginx.conf which looks like this:
log_format upstream_time '$remote_addr - $remote_user [$time_local] '
'"$request" $status $body_bytes_sent '
'"$http_referer" "$http_user_agent" '
'"$upstream_response_time"';
server {
listen 80;
location / {
proxy_pass http://myapp/;
}
access_log /var/log/nginx/access.log upstream_time;
}
In this file we've specified a custom log format for Nginx that includes $upstream_response_time as the last part of the log entries. Nginx is also configured to pass all requests on to the myapp application.
Run it, make a couple of requests and look at the Nginx log using
docker compose up -d
curl http://localhost:8000/weatherforecast
curl http://localhost:8000/weatherforecast
docker compose logs nginx
My output looks like this, with the response times logged as 68 ms and 3 ms for the two requests (the response times are at the end of the log entries)
nginx_1 | 172.22.0.1 - - [07/Oct/2023:09:51:16 +0000] "GET /weatherforecast HTTP/1.1" 200 394 "-" "curl/7.81.0" "0.068"
nginx_1 | 172.22.0.1 - - [07/Oct/2023:09:52:13 +0000] "GET /weatherforecast HTTP/1.1" 200 393 "-" "curl/7.81.0" "0.003"