Strange file permission errors on lxd ubuntu 20.04

dhpowrhost · May 4, 2020, 11:43am

We use lxd for production. We have had a hard time finding the right base OS. Right now we have containers running on both ubuntu 18.04, Debian 10 and now also 20.04.
All based on zfs datasets.

So far it has been a good experience with lxd 4.0.1 on Ubuntu 20.04. Performance is good and seems pretty stable.

One strange issue however. We use it for webservers with apache and php fpm. We migrated a server offline migration with lxc move from a host using debian 10 to another host using ubuntu 20.04. Apache in the container had no problems running on Debian, but when we moved it to the Ubuntu 20.04 host we started to get file permission errors when starting Apache and PHP.

[04-May-2020 13:22:23] ERROR: Unable to create or open slowlog(/var/www/hest.dk/logs/php-fpm-slow.log): Permission denied (13)
[04-May-2020 13:22:23] ERROR: failed to post process the configuration
[04-May-2020 13:22:23] ERROR: FPM initialization failed

(13)Permission denied: AH00091: apache2: could not open error log file /var/www/hest.dk/logs/apache_errorlog.log.

Migrating the container backup to orign host and apache and php fpm starts on boot with no issues.

This happens on both lxd 4.0.1 and 3.23, but only on Ubuntu 20.04
Cannot be replicated on Debian 10 and Ubuntu 18.04

tomp · May 4, 2020, 1:21pm

Can you show output of ls -la /var/www/hest.dk/logs/ on both the original host and the target host?

You can use lxc copy if you want to avoid having to keep moving the container about.

dhpowrhost · May 4, 2020, 1:39pm

From 20.04 where file permissions is an issue

root@phct-026:~# ls -alh /var/www/hest.dk/logs/
total 19K
drwxrwx--T 2 root    virtual 6 May  4 13:05 .
drwxr-x--- 8 hest_dk virtual 9 May  4 10:30 ..
-rw-r--r-- 1 hest_dk virtual 0 May  4 10:29 apache_accesslog.log
-rw-r--r-- 1 hest_dk virtual 0 May  4 10:29 apache_errorlog.log
-rw------- 1 hest_dk virtual 0 May  4 13:05 filesystem_audit.log
-rw------- 1 hest_dk virtual 0 May  4 10:28 php-fpm-slow.log

And the original Debian 10 server where it works:

root@phct-026:~# ls -alh /var/www/hest.dk/logs/
total 19K
drwxrwx--T 2 root    virtual 6 May  4 13:05 .
drwxr-x--- 8 hest_dk virtual 9 May  4 10:30 ..
-rw-r--r-- 1 hest_dk virtual 0 May  4 10:29 apache_accesslog.log
-rw-r--r-- 1 hest_dk virtual 0 May  4 10:29 apache_errorlog.log
-rw------- 1 hest_dk virtual 0 May  4 13:05 filesystem_audit.log
-rw------- 1 hest_dk virtual 0 May  4 10:28 php-fpm-slow.log

So no difference at all.

tomp · May 4, 2020, 1:46pm

Do you see any apparmor errors in the host’s syslog on 20.04 host?

dhpowrhost · May 4, 2020, 1:55pm

Nope… No errors. We use unconfined right now

stgraber · May 4, 2020, 1:58pm

@dhpowrhost can you show lxc config show --expanded NAME for that container?

If you’re forcing unconfined through raw.lxc, this may actually be the source of the issue.

Unlike what most people think, unconfined isn’t really unconfined, it mostly means you don’t have an apparmor profile or namespace, which also means that any apparmor profile defined on the host which applies based on application path WILL be applied to your processes.

dhpowrhost · May 4, 2020, 2:00pm

architecture: x86_64
config:
  environment.TZ: Europe/Copenhagen
  image.architecture: amd64
  image.description: Debian buster amd64 (20200429_05:24)
  image.os: Debian
  image.release: buster
  image.serial: "20200429_05:24"
  image.type: squashfs
  limits.cpu: "16"
  limits.memory: 65536MB
  raw.lxc: lxc.apparmor.profile = unconfined
  security.syscalls.intercept.mknod: "true"
  volatile.base_image: ca69d602f44982892920977933a60a5075deed0df6896530ff713eb36c7020ac
  volatile.eth0.host_name: vethf214582c
  volatile.eth0.hwaddr: 00:16:3e:3a:4c:16
  volatile.eth1.hwaddr: 00:16:3e:c5:d0:f3
  volatile.idmap.base: "0"
  volatile.idmap.current: '[{"Isuid":true,"Isgid":false,"Hostid":1000000,"Nsid":0,"Maprange":1000000000},{"Isuid":false,"Isgid":true,"Hostid":1000000,"Nsid":0,"Maprange":1000000000}]'
  volatile.idmap.next: '[{"Isuid":true,"Isgid":false,"Hostid":1000000,"Nsid":0,"Maprange":1000000000},{"Isuid":false,"Isgid":true,"Hostid":1000000,"Nsid":0,"Maprange":1000000000}]'
  volatile.last_state.idmap: '[{"Isuid":true,"Isgid":false,"Hostid":1000000,"Nsid":0,"Maprange":1000000000},{"Isuid":false,"Isgid":true,"Hostid":1000000,"Nsid":0,"Maprange":1000000000}]'
  volatile.last_state.power: RUNNING
devices:
  eth0:
    limits.egress: 1000Mbit
    limits.ingress: 1000Mbit
    name: eth0
    nictype: bridged
    parent: br0
    type: nic
  root:
    path: /
    pool: lxd
    type: disk
ephemeral: false
profiles:
- default
- level1
stateful: false
description: ""

dhpowrhost · May 4, 2020, 2:03pm

Just tried to remove it raw.lxc: lxc.apparmor.profile = unconfined from the profile. No luck

dhpowrhost · May 4, 2020, 6:25pm

@tomp
@stgraber
As a test i also tried to disable apparmor via grub, however the file permission issue persists.

stgraber · May 5, 2020, 12:59am

Can you show:

stat /
stat /var
stat /var/www
stat /var/www/hest.dk
stat /var/www/hest.dk/logs
stat /var/www/hest.dk/logs/php-fpm-slow.log

See if there’s anything odd going on in an intermediate path.

dhpowrhost · May 5, 2020, 6:24am

On the faulty host:

root@phct-026:~# stat /
File: /
Size: 21        	Blocks: 17         IO Block: 1536   directory
Device: 4ah/74d	Inode: 2           Links: 21
Access: (0755/drwxr-xr-x)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 2020-05-04 14:38:17.720409656 +0200
Modify: 2020-05-04 14:43:33.106769066 +0200
Change: 2020-05-04 15:35:36.234276577 +0200
 Birth: -
root@phct-026:~# stat /var
  File: /var
  Size: 15        	Blocks: 17         IO Block: 1024   directory
Device: 4ah/74d	Inode: 22          Links: 13
Access: (0755/drwxr-xr-x)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 2020-05-04 14:39:12.848820475 +0200
Modify: 2020-04-29 13:08:37.232078102 +0200
Change: 2020-05-04 15:35:42.206321709 +0200
 Birth: -
root@phct-026:~# stat /var/www
  File: /var/www
  Size: 5         	Blocks: 1          IO Block: 512    directory
Device: 4ah/74d	Inode: 59584       Links: 5
Access: (0755/drwxr-xr-x)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 2020-05-04 14:39:44.229054669 +0200
Modify: 2020-05-04 10:27:14.623289902 +0200
Change: 2020-05-04 15:35:45.486346497 +0200
 Birth: -
root@phct-026:~# stat /var/www/hest.dk
  File: /var/www/hest.dk
  Size: 9         	Blocks: 17         IO Block: 1024   directory
Device: 4ah/74d	Inode: 89933       Links: 8
Access: (0750/drwxr-x---)  Uid: (999999/ hest_dk)   Gid: (10001/ virtual)
Access: 2020-05-04 14:39:44.233054699 +0200
Modify: 2020-05-04 10:30:02.044032923 +0200
Change: 2020-05-05 06:15:01.816051480 +0200
 Birth: -
root@phct-026:~# stat /var/www/hest.dk/logs
  File: /var/www/hest.dk/logs
  Size: 6         	Blocks: 17         IO Block: 512    directory
Device: 4ah/74d	Inode: 89948       Links: 2
Access: (1770/drwxrwx--T)  Uid: (    0/    root)   Gid: (10001/ virtual)
Access: 2020-05-04 14:39:44.233054699 +0200
Modify: 2020-05-04 13:05:57.033643371 +0200
Change: 2020-05-05 06:15:05.172068760 +0200
 Birth: -
root@phct-026:~# stat /var/www/hest.dk/logs/php-fpm-slow.log 
  File: /var/www/hest.dk/logs/php-fpm-slow.log
  Size: 0         	Blocks: 1          IO Block: 512    regular empty file
Device: 4ah/74d	Inode: 90734       Links: 1
Access: (0600/-rw-------)  Uid: (999999/ hest_dk)   Gid: (10001/ virtual)
Access: 2020-05-04 14:39:44.233054699 +0200
Modify: 2020-05-04 10:28:59.971756727 +0200

tomp · May 5, 2020, 8:02am

What user is apache configured to run as?

Can you also show your apache config part that configures the log files?

dhpowrhost · May 5, 2020, 8:13am

@tomp
The user is www-data which is a part of the virtual group:

root@phct-026:~# cat /etc/group | grep www-data
www-data:x:33:
virtual:x:10001:www-data

Loggin is configured the following way:

    ErrorLog /var/www/${site}/logs/apache_errorlog.log
            LogLevel error

tomp · May 6, 2020, 7:49am

I’m not sure about this, I think I’d need to login to the system to take a look.

dhpowrhost · May 6, 2020, 7:50am

The container or the host?

tomp · May 6, 2020, 7:58am

Both ideally.

stgraber · May 6, 2020, 1:27pm

Ok, so apache runs as www-data and is part of virtual.

Based on:

-rw-r--r-- 1 hest_dk virtual 0 May  4 10:29 apache_accesslog.log
-rw-r--r-- 1 hest_dk virtual 0 May  4 10:29 apache_errorlog.log
-rw------- 1 hest_dk virtual 0 May  4 13:05 filesystem_audit.log
-rw------- 1 hest_dk virtual 0 May  4 10:28 php-fpm-slow.log

That www-data user will only be able to read the apache_* logs, not open them for writing, they need to be 660 or 664 for that, not the current 644.
It’s worse on the other two files as those can only be written to by hest_dk, so apache/php will have no way of doing that.

tomp · May 6, 2020, 1:31pm

Its strange that apache starts OK on the other host though.

dhpowrhost · May 15, 2020, 11:10am

When apache reloads and restarts it uses uid 0, so something is not right here. There is also no problems the default access-log:

root@HOSTNAME:~# ls -alh /var/log/apache2/access.log
-rw-r----- 1 root adm 0 Apr 29 13:08 /var/log/apache2/access.log