Hello everyone!

We have been investing plenty of personal time and energy for many years to share our knowledge with you all. However, we now need your help to keep this blog running. All you have to do is just click one of the adverts on the site, otherwise it will sadly be taken down due to hosting etc. costs. Thank you.

If you want to change PHP-FPM and Nginx container log format to JSON while keeping same style, you can use example below.


Structure


.
├── docker
│   ├── docker-compose.yml
│   ├── Makefile
│   ├── nginx
│   │   ├── app.conf
│   │   ├── Dockerfile
│   │   └── nginx.conf
│   └── php
│   ├── Dockerfile
│   ├── php.ini
│   └── www.conf
└── index.php

Files


docker/docker-compose.yml


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\\$$ "

docker/nginx/Dockerfile


FROM nginx:1.15.8-alpine

WORKDIR /app

COPY app.conf /etc/nginx/conf.d/default.conf
COPY nginx.conf /etc/nginx/nginx.conf

docker/nginx/app.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;
}
}

docker/nginx/nginx.conf


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;
}

docker/php/Dockerfile


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"]

docker/php/php.ini


[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

docker/php/www.conf


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


$ 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

Configuration information


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

Tests


PHP-FPM error log


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"

Access logs


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"
}