Apache fails accessing log files (container crashes)

[liarco]

Hi everyone,
I'm having an issue with the following setup:

• ubuntu 18.04
• docker 18.09
• latest php7.2-apache image (honestly I'm using the official WordPress image based on the PHP one, but I think the error is not related to WP)
• the image is running as an arbitrary user (I'm following the guidelines about this)

It used to work perfectly (and it still does on machines that are not running the latest version), but at some point something must have changed and now the container boots, runs every task before starting apache, then it fires this error (before crashing):

(13)Permission denied: AH00091: apache2: could not open error log file /var/log/apache2/error.log.
AH00015: Unable to open logs

No other error is fired before this...

I tried moving the log dir with APACHE_LOG_DIR: /tmp/apache2/logs and it works (as a ugly hack), but unfortunately symlinks to /dev/std* are not working because I think that they're created at build time (here are the lines in the Dockerfile).

Is this my fault or what?

Thank you for your time!

[bascht]

@liarco I think you tripped into the fix for #743. See: https://github.com/docker-library/docs/tree/master/php#running-as-an-arbitrary-user

[tianon]

Oh boo -- are the log file symlinks being created with weird permissions or something?

Can you provide a more explicit example command for reproducing the issue?

[liarco]

Thank you for your replies, here is the docker-compose configuration (original):

version: '3'

services:
  wordpress:
    image: wordpress:latest
    user: $APACHE_RUN_USER:$APACHE_RUN_GROUP
    restart: always
    expose:
      - 80
    networks:
      - private
      - nginx-proxy
    depends_on:
      - db
    environment:
      APACHE_RUN_USER: '#$APACHE_RUN_USER'
      APACHE_RUN_GROUP: '#$APACHE_RUN_GROUP'
      VIRTUAL_HOST: ${VIRTUAL_HOST}
      WORDPRESS_DB_HOST: db:3306
      WORDPRESS_DB_PASSWORD:
      WORDPRESS_DEBUG: 1
    sysctls:
      net.ipv4.ip_unprivileged_port_start: '0' # Allow non-root user to bind to port 80
    tmpfs: /run/apache2:uid=$APACHE_RUN_USER # Fix custom user permissions
    volumes:
      - ./docker_data/wordpress:/var/www/html
      - ./plugins:/var/www/html/wp-content/plugins
      - ./themes:/var/www/html/wp-content/themes

...

I'm doing some tests following the hints found on the links from @bascht and here is what I found:

• my kernel is 4.15.0, so I removed any APACHE_ constant and the tmpfs: directive. The result is:

AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 192.168.160.4. Set the 'ServerName' directive globally to suppress this message
(13)Permission denied: AH00091: apache2: could not open error log file /var/log/apache2/error.log.
AH00015: Unable to open logs

The container crashes...

• next I tried to remove the user: directive and added back the APACHE_ constants:

[Fri Nov 23 17:09:52.530343 2018] [core:notice] [pid 1] AH00094: Command line: 'apache2 -D FOREGROUND'
[Fri Nov 23 17:09:52.532120 2018] [unixd:alert] [pid 98] AH02155: getpwuid: couldn't determine user name from uid 1000, you probably need to modify the User directive
[Fri Nov 23 17:09:52.533057 2018] [unixd:alert] [pid 100] AH02155: getpwuid: couldn't determine user name from uid 1000, you probably need to modify the User directive
[Fri Nov 23 17:09:52.533973 2018] [unixd:alert] [pid 101] AH02155: getpwuid: couldn't determine user name from uid 1000, you probably need to modify the User directive
[Fri Nov 23 17:09:52.534910 2018] [unixd:alert] [pid 97] AH02155: getpwuid: couldn't determine user name from uid 1000, you probably need to modify the User directive
[Fri Nov 23 17:09:52.535601 2018] [unixd:alert] [pid 99] AH02155: getpwuid: couldn't determine user name from uid 1000, you probably need to modify the User directive

The webserver runs, but PHP doesn't have write permissions on the html folder.

• next I added the ugly fix APACHE_LOG_DIR: /tmp/apache2/logs:

AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 192.168.224.4. Set the 'ServerName' directive globally to suppress this message

This log is perfectly fine (am I right?), the server runs and write permissions work as intended

It seems like I need both the user: directive and the APACHE_ constants to have write access, but that breaks logs permissions...

Here is a ls of the logs folder without the APACHE_LOG_DIR hack:

$ docker exec -it -u root project_wordpress_1 ls -lah /var/log/apache2
total 8.0K
drwxrwxrwt 1 www-data www-data 4.0K Nov 16 02:06 .
drwxr-xr-x 1 root     root     4.0K Nov 16 02:06 ..
lrwxrwxrwx 1 root     root       11 Nov 16 02:06 access.log -> /dev/stdout
lrwxrwxrwx 1 root     root       11 Nov 16 02:06 error.log -> /dev/stderr
lrwxrwxrwx 1 root     root       11 Nov 16 02:06 other_vhosts_access.log -> /dev/stdout

I hope this can help you, please ask me for any further information!

Thank you for your help.

[bascht]

@liarco I think user: $APACHE_RUN_USER:$APACHE_RUN_GROUP might be the culprit. We ran into the same issue with our setup. From what I can tell you are using Docker on Linux?

[liarco]

@bascht that's right! I use my code in a hybrid team (MacOS / Ubuntu) with deployment on Linux (mainly Ubuntu).

On MacOS, Docker handles file permissions in a different way, so I never run into problems... but on linux I had to deal with custom UIDs/GIDs to fix permissions on local folders mounted as volumes.

[bascht]

@liarco Yip, same with us. Mixed macOS / Linux workstations and without specifying a user: we would end up with root-owned files in our working directory.

I don't see any way around this though. The chown / chmod fix will allow running apache as an arbitrary user – https://github.com/docker-library/php/pull/745/files#diff-7dd25658243fe99c8fbeecd29c63876eR73 but from what I reckon, the APACHE_RUN_USER is only the user apache will spawn processes with. The parent process is still running as root, no?

We used to work around this by supplying volumes for the run and var dirs:

Still, kinda ugly.

[wglambert]

/var/log/apache2 needs proper permissions, as a workaround you can mount it from your host with an appropriate chown or chmod. I just did a chown 1000:1000 apache2
The APACHE_RUN_USER variable requires the user: <uid>:<gid> set as well, or it will error with chown: invalid user: '#1000:www-data'. I haven't had to set the APACHE_RUN_GROUP variable

version: '3'

services:
  wordpress:
    image: wordpress:latest
    user: 1000:1000
    restart: always
    ports:
      - 80:80
    environment:
      APACHE_RUN_USER: '#1000'
      WORDPRESS_DB_USER: exampleuser
      WORDPRESS_DB_HOST: db
      WORDPRESS_DB_PASSWORD: examplepass
      WORDPRESS_DB_NAME: exampledb
      WORDPRESS_DEBUG: 1
    sysctls:
      net.ipv4.ip_unprivileged_port_start: '0' # Allow non-root user to bind to port 80
    volumes:
      - ./apache2:/var/log/apache2

  db:
    image: mysql:5.7
    restart: always
    environment:
      MYSQL_DATABASE: exampledb
      MYSQL_USER: exampleuser
      MYSQL_PASSWORD: examplepass
      MYSQL_RANDOM_ROOT_PASSWORD: '1'

After doing the wordpress setup the container is listening on port 80

$ docker ps
CONTAINER ID        IMAGE               COMMAND                  CREATED             STATUS              PORTS                 NAMES
b9610749a8f9        mysql:5.7           "docker-entrypoint.s…"   29 seconds ago      Up 26 seconds       3306/tcp, 33060/tcp   php-754_db_1
dff5852dc086        wordpress:latest    "docker-entrypoint.s…"   29 seconds ago      Up 18 seconds       0.0.0.0:80->80/tcp    php-754_wordpress_1
$ curl localhost:80
<!DOCTYPE html>
<html lang="en-US" class="no-js no-svg">
<head>
<meta charset="UTF-8">
<meta name="viewport" content="width=device-width, initial-scale=1">
<link rel="profile" href="http://gmpg.org/xfn/11">

<script>(function(html){html.className = html.className.replace(/\bno-js\b/,'js')})(document.documentElement);</script>
<title>title &#8211; Just another WordPress site</title>

And in the container apache2 is running as the arbitrary user, which has an invalid name as there isn't a corresponding entry in the /etc/passwd file

$ docker exec -it php-754_wordpress_1 bash
I have no name!@ede033de6ec3:/var/www/html$ ps aux
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
1000         1  0.0  1.0 390012 30804 ?        Ss   21:52   0:00 apache2 -DF
1000       218  0.0  1.3 469684 42580 ?        S    21:52   0:00 apache2 -DF
1000       219  0.0  1.1 467636 34788 ?        S    21:52   0:00 apache2 -DF
1000       220  0.0  0.2 390044  7748 ?        S    21:52   0:00 apache2 -DF
1000       221  0.0  0.2 390044  7748 ?        S    21:52   0:00 apache2 -DF
1000       222  0.0  0.2 390044  7748 ?        S    21:52   0:00 apache2 -DF
1000       223  0.0  0.2 390044  7748 ?        S    21:53   0:00 apache2 -DF
1000       226  0.0  0.1  18144  3140 pts/0    Ss   21:56   0:00 bash
1000       234  0.5  0.0  36640  2780 pts/0    R+   22:01   0:00 ps aux

There is also an error generated by tar on startup, however it seems to not cause any problems and wordpress is successfully copied to /var/www/html/.
However if your container is not set to restart:always it will remain stopped due to this error.

$ docker-compose up -d
$ docker logs php-754_wordpress_1
WordPress not found in /var/www/html - copying now...
tar: .: Cannot utime: Operation not permitted
tar: .: Cannot change mode to rwxr-xr-t: Operation not permitted
tar: Exiting with failure status due to previous errors

Warning: mysqli::__construct(): (HY000/2002): Connection refused in Standard input code on line 22

MySQL Connection Error: (2002) Connection refused
. . .

$ docker exec -it php-754_wordpress_1 bash
I have no name!@4cd5d6dc51e7:/var/www/html$ ls -alh
total 204K
drwxrwxrwt  5 www-data www-data 4.0K Nov 26 22:21 .
drwxr-xr-x  4 root     root     4.0K Nov 16 02:06 ..
-rw-r--r--  1     1000     1000  418 Sep 25  2013 index.php
-rw-r--r--  1     1000     1000  20K Jan  6  2018 license.txt
-rw-r--r--  1     1000     1000 7.3K Mar 18  2018 readme.html
-rw-r--r--  1     1000     1000 5.4K May  1  2018 wp-activate.php
drwxr-xr-x  9     1000     1000 4.0K Aug  2 20:39 wp-admin
-rw-r--r--  1     1000     1000  364 Dec 19  2015 wp-blog-header.php
-rw-r--r--  1     1000     1000 1.9K May  2  2018 wp-comments-post.php
-rw-r--r--  1     1000     1000 2.7K Nov 26 22:21 wp-config-sample.php
-rw-r--r--  1     1000     1000 3.1K Nov 26 22:21 wp-config.php
drwxr-xr-x  4     1000     1000 4.0K Nov 26 22:24 wp-content
-rw-r--r--  1     1000     1000 3.6K Aug 20  2017 wp-cron.php
drwxr-xr-x 18     1000     1000  12K Aug  2 20:39 wp-includes
-rw-r--r--  1     1000     1000 2.4K Nov 21  2016 wp-links-opml.php
-rw-r--r--  1     1000     1000 3.3K Aug 22  2017 wp-load.php
-rw-r--r--  1     1000     1000  37K Jul 16 14:14 wp-login.php
-rw-r--r--  1     1000     1000 7.9K Jan 11  2017 wp-mail.php
-rw-r--r--  1     1000     1000  16K Oct  4  2017 wp-settings.php
-rw-r--r--  1     1000     1000  30K Apr 29  2018 wp-signup.php
-rw-r--r--  1     1000     1000 4.6K Oct 23  2017 wp-trackback.php
-rw-r--r--  1     1000     1000 3.0K Aug 31  2016 xmlrpc.php

[liarco]

@wglambert I confirm that the workaround works since I also tried it before landing on the APACHE_LOG_DIR: /tmp/apache2/logs trick. Then I decided to keep the folder inside the container because, with docker-compose, I can be sure that logs are automatically cleared on each restart instead of being persisted on the local filesystem... but I understand this is far from optimal.

I still can't find a better solution... :(

[tianon]

Definitely a bug, definitely introduced by #745 (apologies!)

Simplest reproducer:

$ docker run -it --rm -u 1000:1000 --sysctl net.ipv4.ip_unprivileged_port_start=0 php:apache

Working on a fix now.

[tianon]

Also, just to clear things up -- user: and the APACHE_RUN_xxx environment variables should be considered exclusive. The latter are to inform Apache of which user it should try to step down from root to, and the former tells Docker which user to step down to before even running Apache (which would thus prevent Apache from stepping down -- and it will simply log a warning and ignore your parameters directly).

It looks like wordpress also has a bug with chown where it tries to use APACHE_RUN_USER directly which doesn't work with the #xxx format which we should likely look to fix separately (unrelatedly).

[tianon]

Fix PR: #755