24/05/2019 - DOCKER, PHP, NGINX
If you want to change PHP-FPM and Nginx container log format to JSON while keeping same style, you can use example below.
.
├── docker
│ ├── docker-compose.yml
│ ├── Makefile
│ ├── nginx
│ │ ├── app.conf
│ │ ├── Dockerfile
│ │ └── nginx.conf
│ └── php
│ ├── Dockerfile
│ ├── php.ini
│ └── www.conf
└── index.php
version: "3.4"
services:
wait_php:
build:
context: "./php"
hostname: "wait-php"
volumes:
- "..:/app"
environment:
PS1: "\\u@\\h:\\w\\$$ "
wait_nginx:
build:
context: "./nginx"
hostname: "wait-nginx"
ports:
- "1080:80"
volumes:
- "..:/app"
depends_on:
- "wait_php"
environment:
PS1: "\\u@\\h:\\w\\$$ "
FROM nginx:1.15.8-alpine
WORKDIR /app
COPY app.conf /etc/nginx/conf.d/default.conf
COPY nginx.conf /etc/nginx/nginx.conf
We had to add fastcgi_param HTTP_X_REQUEST_ID $request_id; for PHP-FPM logs.
server {
listen 80 default_server;
server_name localhost;
root /app;
index index.php;
location ~ \.php$ {
try_files $uri =404;
fastcgi_pass wait_php:9000;
fastcgi_split_path_info ^(.+\.php)(/.+)$;
fastcgi_index index.php;
include fastcgi_params;
fastcgi_param SCRIPT_FILENAME $document_root$fastcgi_script_name;
fastcgi_param PATH_INFO $fastcgi_path_info;
fastcgi_param HTTP_X_REQUEST_ID $request_id;
}
}
If you remove error_log off; the PHP related coding errors will be displayed by Nginx container rather than the PHP-FPM container. I like my PHP-FPM container to own its own error so I am keeping it.
user nginx;
worker_processes 1;
error_log /var/log/nginx/error.log warn;
pid /var/run/nginx.pid;
events {
worker_connections 1024;
}
http {
include /etc/nginx/mime.types;
default_type application/octet-stream;
log_format json_combined escape=json
'{'
'"time_local":"$time_iso8601",'
'"client_ip":"$http_x_forwarded_for",'
'"remote_addr":"$remote_addr",'
'"remote_user":"$remote_user",'
'"request":"$request",'
'"status":"$status",'
'"body_bytes_sent":"$body_bytes_sent",'
'"request_time":"$request_time",'
'"http_referrer":"$http_referer",'
'"http_user_agent":"$http_user_agent",'
'"request_id":"$request_id"'
'}';
access_log /var/log/nginx/access.log json_combined;
error_log off;
sendfile on;
keepalive_timeout 65;
include /etc/nginx/conf.d/*.conf;
}
FROM php:7.2.13-fpm-alpine3.8
WORKDIR /app
COPY php.ini /usr/local/etc/php/conf.d/php.override.ini
COPY www.conf /usr/local/etc/php-fpm.d/www.conf
CMD ["php-fpm", "--nodaemonize"]
[PHP]
date.timezone=UTC
log_errors=On
error_reporting=E_ALL & ~E_DEPRECATED & ~E_STRICT
display_errors=Off
max_execution_time=60
memory_limit=256M
You may need to add clear_env=no to see how it changes the logs or if it helps to access more environmental variables.
[global]
daemonize=no
[www]
user=www-data
group=www-data
listen=wait_nginx:9000
pm=dynamic
pm.max_children=40
pm.start_servers=2
pm.min_spare_servers=2
pm.max_spare_servers=4
pm.max_requests=500
access.format='{"time_local":"%{%Y-%m-%dT%H:%M:%S%z}T","client_ip":"%{HTTP_X_FORWARDED_FOR}e","remote_addr":"%R","remote_user":"%u","request":"%m %{REQUEST_URI}e %{SERVER_PROTOCOL}e","status":"%s","body_bytes_sent":"%l","request_time":"%d","http_referrer":"%{HTTP_REFERER}e","http_user_agent":"%{HTTP_USER_AGENT}e","request_id":"%{HTTP_X_REQUEST_ID}e"}'
$ docker ps
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
96d7f6c16904 docker_wait_nginx "nginx -g 'daemon of…" 4 minutes ago Up 4 minutes 0.0.0.0:1080->80/tcp docker_wait_nginx_1
f8d0c3367925 docker_wait_php "docker-php-entrypoi…" 4 minutes ago Up 4 minutes 9000/tcp docker_wait_php_1
The PHP access log format has C, d, e, f, l, m, M, n, o, p, P, q, Q, r, R, s, t, T, u options and they are used with % prefix - e.g. %C. However, e (represents Nginx server fastcgi_param vars and PHP-FPM server $_SERVER vars) and o (represents "header" output) are a bit different so they are used as %{VARIABLE_NAME}e - e.g. %{REQUEST_URI}e. Also the list of Nginx config file variables can be found here.
The PHP default access log format is "%R - %u %t \"%m %r\" %s" and the log output is 172.22.0.3 - 26/May/2019:10:57:14 +0000 "GET /index.php" 200.
For demonstration purposes, if you have used all options in log format, your log would look like below.
access.format = '{"C":"%C","d":"%d","f":"%f","l":"%l","m":"%m","M":"%M","n":"%n","P":"%P","p":"%p","q":"%q","Q":"%Q","r":"%r","R":"%R","s":"%s","T":"%T","t":"%t","u":"%u"}'
$ curl -i 0.0.0.0:1080
{
"C": "0.00", # CPU usage
"d": "5.001", # Request processing duration (5 sec 1 milsec)
"f": "/app/index.php", # Script run
"l": "0", # Content length
"m": "GET", # Method
"M": "2097152", # Memory usage (byte)
"n": "www", # Pool name
"P": "1", # PID (master process)
"p": "6", # PID (child process - pm.start_servers)
"q": "", # Query string
"Q": "", # The '?' character if query string exists
"r": "/index.php", # Script run
"R": "172.22.0.3", # IP of requester (Nginx)
"s": "200", # HTTP status code
"T": "2019-06-12T20:26:05+00:00", # Response time
"t": "2019-06-12T20:26:00+00:00", # Request time
"u": "" # Authenticated/remote user
}
# YOU MUST READ "/usr/local/etc/php-fpm.d/www.conf" file for detailed explanation and better usage of these parameters
wait_php_1 | [26-May-2019 17:49:02] WARNING: [pool www] child 7 said into stderr: "NOTICE: PHP message: PHP Parse error: syntax error, unexpected end of file in /app/index.php on line 4"
wait_php_1 | [26-May-2019 17:49:49] WARNING: [pool www] child 8 said into stderr: "NOTICE: PHP message: PHP Fatal error: Uncaught Error: Class 'Tomato' not found in /app/index.php:5"
wait_php_1 | [26-May-2019 17:49:49] WARNING: [pool www] child 8 said into stderr: "Stack trace:"
wait_php_1 | [26-May-2019 17:49:49] WARNING: [pool www] child 8 said into stderr: "#0 {main}"
wait_php_1 | [26-May-2019 17:49:49] WARNING: [pool www] child 8 said into stderr: " thrown in /app/index.php on line 5"
I did my best to match both log formats in configs but it's up to you to improve it.
# PHP-FPM - wait_php_1
{
"time_local": "2019-06-12T20:26:01+00:00",
"client_ip": "2.28.107.100",
"remote_addr": "172.22.0.3",
"remote_user": "",
"request": "GET / HTTP/1.1",
"status": "200",
"body_bytes_sent": "0",
"request_time": "0.002",
"http_referrer": "-",
"http_user_agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/74.0.3729.169 Safari/537.36",
"request_id": "98bb9fbfb3bc710422d87b22d380a4e6"
}
# Nginx - wait_nginx_1
{
"time_local": "2019-06-12T20:26:00+00:00",
"client_ip": "2.28.107.100",
"remote_addr": "192.168.99.1",
"remote_user": "",
"request": "GET / HTTP/1.1",
"status": "200",
"body_bytes_sent": "2509",
"request_time": "0.004",
"http_referrer": "",
"http_user_agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/74.0.3729.169 Safari/537.36",
"request_id": "98bb9fbfb3bc710422d87b22d380a4e6"
}