just-containers / s6-overlay

s6 overlay for containers (includes execline, s6-linux-utils & a custom init)
Other
3.73k stars 212 forks source link

Strange behaviour with logs v3 #593

Closed dzirg44 closed 1 month ago

dzirg44 commented 1 month ago

I use Fedora 40 as a host machine, and podman version 5.1.2 as a container runner ARG S6_OVERLAY_VERSION=3.2.0.0 Base image container is: FROM docker.io/library/ubuntu:22.04 as base my nginx log configuration is

    access_log /dev/stdout main;
    error_log /dev/stderr;

I build a container image with nginx and php-fpm and have the next structure.

s6-rc.d

```sh └── s6-rc.d ├── nginx-log │ ├── consumer-for │ ├── dependencies.d │ │ ├── base │ │ └── nginx-log-prepare │ ├── pipeline-name │ ├── run │ └── type ├── nginx-log-prepare │ ├── dependencies.d │ │ └── base │ ├── type │ └── up ├── nginx-service │ ├── dependencies │ ├── dependencies.d │ │ ├── base │ │ ├── nginx-log │ │ └── php-fpm │ ├── producer-for │ ├── run │ └── type ├── php-fpm │ ├── dependencies.d │ │ └── base │ ├── run │ └── type └── user └── contents.d ├── nginx-pipeline ├── nginx-service └── php-fpm ```

All services start well without any issues.

s6-rc.d/nginx-log-prepare/up

```shell if { mkdir -p /var/log/nginx-service } if { chown nobody:nogroup /var/log/nginx-service } chmod 02755 /var/log/nginx-service ```

s6-rc.d/nginx-log/run

```shell #!/bin/sh exec logutil-service /var/log/nginx-service ```

consumer-for and producer-for have correct values ( nginx-service and nginx-log )

If in the file s6-rc.d/nginx-service/run I have

#!/command/execlineb -P
nginx -g "daemon off;"

In the docker console log I see

Container Log Execlineb

```shell app_1 | s6-rc: info: service s6rc-fdholder: starting app_1 | s6-rc: info: service s6rc-oneshot-runner: starting app_1 | s6-rc: info: service s6rc-oneshot-runner successfully started app_1 | s6-rc: info: service fix-attrs: starting app_1 | s6-rc: info: service s6rc-fdholder successfully started app_1 | s6-rc: info: service fix-attrs successfully started app_1 | s6-rc: info: service legacy-cont-init: starting app_1 | s6-rc: info: service legacy-cont-init successfully started app_1 | s6-rc: info: service nginx-log-prepare: starting app_1 | s6-rc: info: service php-fpm: starting app_1 | s6-rc: info: service php-fpm successfully started app_1 | s6-rc: info: service nginx-log-prepare successfully started app_1 | s6-rc: info: service nginx-log: starting app_1 | s6-rc: info: service nginx-log successfully started app_1 | s6-rc: info: service nginx-service: starting app_1 | s6-rc: info: service nginx-service successfully started app_1 | s6-rc: info: service legacy-services: starting app_1 | s6-rc: info: service legacy-services successfully started app_1 | 2024/08/13 16:44:16 [crit] 91#91: *1 connect() to unix:/var/lib/php-fpm/app.com.sock failed (2: No such file or directory) while connecting to upstream, client: 10.89.2.53, server: _, request: "GET / HTTP/2.0", upstream: "fastcgi://unix:/var/lib/php-fpm/app.com.sock:", host: "127.0.0.1:8443" ```

and in the container

/var/log/nginx-service/current

```shell 024-08-13 16:44:16.115314140 10.89.2.53 - - [13/Aug/2024:16:44:16 +0000] "GET / HTTP/2.0" 502 150 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:128.0) Gecko/20100101 Firefox/128.0" "-" ```

When I change the file to

#!/command/execlineb -P
fdmove -c 2 1
nginx -g "daemon off;"

I have everything in /var/log/nginx-service/current

/var/log/nginx-service/current

```shell 2024-08-13 17:18:25.695696491 2024/08/13 17:18:25 [crit] 91#91: *1 connect() to unix:/var/lib/php-fpm/app.com.sock failed (2: No such file or directory) while connecting to upstream, client: 10.89.2.54, server: _, request: "GET / HTTP/2.0", upstream: "fastcgi://unix:/var/lib/php-fpm/app.com.sock:", host: "127.0.0.1:8443" 2024-08-13 17:18:25.695871209 10.89.2.54 - - [13/Aug/2024:17:18:25 +0000] "GET / HTTP/2.0" 502 150 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:128.0) Gecko/20100101 Firefox/128.0" "-" ```

but nothing appears in the container console log.

The same thing for the

#!/bin/sh
exec 2>&1
exec nginx -g "daemon off;"

How can I debug the issue ? Thank you.

skarnet commented 1 month ago

fdmove -c 2 1, just like exec 2>&1, means "what you would send to stderr will now be sent to stdout instead". That is what is happening, and your nginx-log service picks up what your nginx-service service sends to its stdout, which means both access_log and error_log. Things are working as intended.

If you want error_log to fall through to the container console log, just delete the fdmove -c 2 1 line.

dzirg44 commented 1 month ago

@skarnet Thank you for the clarifications, I though that using service loggers is mandatory, also this issue helped me to understand it better. https://github.com/just-containers/s6-overlay/issues/70 So if somebody wants to see logs just in container console - delete all loggers and use fdmove -c 2 1 or exec 2>&1 and everything will be fine. But anyway I have a question when these loggers can be useful ? I though that via these loggers I can add a prefix to the log outputs, like [nginx]-2024/08/14 or [php-fpm]-2024/08/14 , but it seems that they serve for another purposes.

skarnet commented 1 month ago

Yeah, you can delete all the logger definitions if you don't want any loggers. Don't forget to remove producer-for files in your main service definitions as well.

Dedicated loggers are generally a good idea: it's easier to check and process logs of a single service when they're not mixed with logs from everywhere else. Also, s6-log (the program that is run by logutil-service) is designed to make sure you don't lose any log lines, and to automatically rotate log files after a certain size so you don't risk running out of disk space. These are generally things that users want. But they're by no means mandatory! If you prefer to let all your logs fall through to the container's output, you can do so.

You can also use logging services to process log lines before letting them fall through to the container's output: logging services just read their stdin and whatever they write to their stdout or stderr will go to the container's output, it's just that s6-log generally doesn't write anything. But if you replace all your logging scripts by cat, nothing will be logged to /var/log, everything will go to the container's output as if you had no logging service at all.

If you want to write a prefix to all your logs before sending them to the container's output, keep your logging services, but try replacing the logging run scripts with this:

#!/command/execlineb -P
s6-format-filter "%1 %s" myprefix

Note that myprefix is a fixed string, you won't be able to change the date on the fly; but it's a simple utility that comes with s6-overlay. If you want to do more powerful log processing in a logging service, you can - just make sure your processors write their output to their stdout, and you'll see it on the container's stdout.

dzirg44 commented 1 month ago

@skarnet Thank you very much for such a great explanation! This information was so helpful !! Shall I close it as resolved?

skarnet commented 1 month ago

I can do it, thanks 😉