/proc/self — указатель на PID вызывающего процесса: $ ls -l /proc/self lrwxrwxrwx 1 root root 0 Feb 12 11:28 /proc/self -> 3037773
тут 3037773 — это PID процесса с /usr/bin/ls
Проверяем свой tty (т.к. в под подключались через -t — Allocate a pseudo-tty):
bash-5.0$ tty
/dev/pts/0
Значит всё, что шлётся в дескриптор /dev/stdout отправляется на /proc/self/fd/1, а тот, в свою очередь, на /dev/pts/0, который является нашей консолью, а не отправляется в STDOUT контейнера Docker и, соответственно, не попадает к демону Docker, который сложил бы лог на хост-машину.
Значит, при подключении к поду с tty — все каналы направляются в него:
root@test-env-deploy-5db5ff4d89-wwkdq:/# ls -l /proc/self/fd
By default, docker logs or docker service logs shows the command’s output just as it would appear if you ran the command interactively in a terminal. UNIX and Linux commands typically open three I/O streams when they run, called STDIN, STDOUT, and STDERR.
…
The official nginx image creates a symbolic link from /var/log/nginx/access.log to /dev/stdout, and creates another symbolic link from /var/log/nginx/error.log to /dev/stderr, overwriting the log files and causing logs to be sent to the relevant special device instead. See the Dockerfile.
The official httpd driver changes the httpd application’s configuration to write its normal output directly to /proc/self/fd/1 (which is STDOUT) and its errors to /proc/self/fd/2 (which is STDERR). See the Dockerfile.
Проверим дексрипторы процессов в нашем контейнере.
PID 1, supervisor который запускает NGINX и PHP-FPM:
С помощью lsof проверяем ID, который передаётся в pipe:
/app $ lsof | grep 21337244
8 /usr/sbin/php-fpm7 pipe:[21337244]
11 /usr/sbin/php-fpm7 pipe:[21337244]
PID 11 — наш воркер, а PID 8:
/app $ ps aux | grep 8
8 nobody 0:00 {php-fpm7} php-fpm: master process (/etc/php7/php-fpm.conf)
Наш мастер-процесс.
Значит, catch_workers_output просто открыл pipe между воркером FPM, и его мастер-процессом: данные из воркера теперь отправляются в мастер-процесс, а от него, в свою очередь, в:
И уже его данные Docker json-file лог-драйвер перехватывает и выводит нам в kubectl logs.
Проверим — запишем что-то в дескриптор FPM-воркера:
/app $ echo fpm-out > /proc/11/fd/1
/app $ echo fpm-err > /proc/11/fd/2
Логи пода:
kk -n bttrm-application-dev-ns logs -f bttrm-application-dev-deploy-d88598f78-r7xsw
...
2020-02-17 14:13:47,991 INFO success: nginx entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2020-02-17 14:13:47,991 INFO success: php-fpm entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
[17-Feb-2020 14:17:45] WARNING: [pool www] child 11 said into stdout: "fpm-out"
[17-Feb-2020 14:17:50] WARNING: [pool www] child 11 said into stderr: "fpm-err"
Думал добавить какую-то ошибку, что бы увидеть реальные ошибки — но не пришлось, «поломалось» само:
kk -n bttrm-application-dev-ns logs -f bttrm-application-dev-deploy-d88598f78-r7xsw
...
2020-02-17 14:13:47,991 INFO success: nginx entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2020-02-17 14:13:47,991 INFO success: php-fpm entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
[17-Feb-2020 14:17:45] WARNING: [pool www] child 11 said into stdout: "fpm-out"
[17-Feb-2020 14:17:50] WARNING: [pool www] child 11 said into stderr: "fpm-err"
[17-Feb-2020 14:20:15] WARNING: [pool www] child 11 said into stderr: "[2020-02-17 16:20:15] dev.ERROR: unserialize(): Error at offset 0 of 40 bytes {"exception":"[object] (ErrorException(code: 0): unserialize(): Error at offset 0 of 40 bytes at /app/vendor/laravel/framework/src/Illuminate/Encryption/Encrypter.php:149)"
[17-Feb-2020 14:20:15] WARNING: [pool www] child 11 said into stderr: "[stacktrace]"
[17-Feb-2020 14:20:15] WARNING: [pool www] child 11 said into stderr: "#0 /app/vendor/sentry/sentry/src/ErrorHandler.php(379): Illuminate\\Foundation\\Bootstrap\\HandleExceptions->handleError(8, 'unserialize(): ...', '/app/vendor/lar...', 149, Array)"
[17-Feb-2020 14:20:15] WARNING: [pool www] child 11 said into stderr: "#1 [internal function]: Sentry\\ErrorHandler->handleError(8, 'unserialize(): ...', '/app/vendor/lar...', 149, Array)"
[17-Feb-2020 14:20:15] WARNING: [pool www] child 11 said into stderr: "#2 /app/vendor/laravel/framework/src/Illuminate/Encryption/Encrypter.php(149): unserialize('***...')"
[17-Feb-2020 14:20:15] WARNING: [pool www] child 11 said into stderr: "#3 /app/vendor/laravel/framework/src/Illuminate/Cookie/Middleware/EncryptCookies.php(95): Illuminate\\Encryption\\Encrypter->decrypt(Array)"
[17-Feb-2020 14:20:15] WARNING: [pool www] child 11 said into stderr: "#4 /app/vendor/laravel/framework/src/Illuminate/Cookie/Middleware/EncryptCookies.php(76): Illuminate\\Cookie\\Middleware\\EncryptCookies->decryptCookie('***...')"