Debugging strange EACCES (Permission denied) permission error

I have a symlink to a world-readable file that a c program is being unable to read. redshift is supposed to pick up configuration from $HOME/.config/redshift/redsihft.conf automatically, but it wasn’t. I tried tracing system calls to understand what files are being tried:

debian-x1-7th][redshift-1.12][130]$ strace -fe trace=file redshift          
execve("/usr/bin/redshift", ["redshift"], 0x7ffd2d3c2680 /* 78 vars */) = 0
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libdrm.so.2", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libwayland-client.so.0", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libxcb.so.1", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libxcb-randr.so.0", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libX11.so.6", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libXxf86vm.so.1", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libgio-2.0.so.0", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libgobject-2.0.so.0", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libglib-2.0.so.0", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libm.so.6", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libpthread.so.0", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libffi.so.7", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libXau.so.6", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libXdmcp.so.6", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libdl.so.2", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libXext.so.6", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libgmodule-2.0.so.0", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libz.so.1", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libmount.so.1", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libselinux.so.1", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libresolv.so.2", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libpcre.so.3", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libbsd.so.0", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libblkid.so.1", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libpcre2-8.so.0", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libmd.so.0", O_RDONLY|O_CLOEXEC) = 3
statfs("/sys/fs/selinux", 0x7ffc678ee320) = -1 ENOENT (No such file or directory)
statfs("/selinux", 0x7ffc678ee320)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/proc/filesystems", O_RDONLY|O_CLOEXEC) = 3
access("/etc/selinux/config", F_OK)     = 0
openat(AT_FDCWD, "/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/home/ealfonso/.config/redshift/redshift.conf", O_RDONLY) = -1 EACCES (Permission denied)
openat(AT_FDCWD, "/home/ealfonso/.config/redshift.conf", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/nsswitch.conf", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libnss_files.so.2", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/etc/passwd", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/home/ealfonso/.config/redshift/redshift.conf", O_RDONLY) = -1 EACCES (Permission denied)
openat(AT_FDCWD, "/home/ealfonso/.config/redshift.conf", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/redshift.conf", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/locale.alias", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/usr/share/locale/en_US.UTF-8/LC_MESSAGES/redshift.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/en_US.utf8/LC_MESSAGES/redshift.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/en_US/LC_MESSAGES/redshift.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/en.UTF-8/LC_MESSAGES/redshift.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/en.utf8/LC_MESSAGES/redshift.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/en/LC_MESSAGES/redshift.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
Trying location provider `geoclue2'...
Using provider `geoclue2'.
strace: Process 78213 attached
Could not connect to wayland display, exiting.
Failed to start adjustment method wayland.
Trying next method...
[pid 78212] access("/home/ealfonso/.Xauthority", R_OK) = 0
[pid 78212] openat(AT_FDCWD, "/home/ealfonso/.Xauthority", O_RDONLY) = 6
strace: Process 78214 attached
[pid 78213] openat(AT_FDCWD, "/usr/share/locale/en_US.UTF-8/LC_MESSAGES/glib20.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
[pid 78213] openat(AT_FDCWD, "/usr/share/locale/en_US.utf8/LC_MESSAGES/glib20.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
[pid 78213] openat(AT_FDCWD, "/usr/share/locale/en_US/LC_MESSAGES/glib20.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
[pid 78213] openat(AT_FDCWD, "/usr/share/locale/en.UTF-8/LC_MESSAGES/glib20.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
[pid 78213] openat(AT_FDCWD, "/usr/share/locale/en.utf8/LC_MESSAGES/glib20.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
[pid 78213] openat(AT_FDCWD, "/usr/share/locale/en/LC_MESSAGES/glib20.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
Using method `randr'.
Waiting for initial location to become available...
strace: Process 78215 attached
strace: Process 78216 attached
[pid 78215] +++ exited with 0 +++    

`

The line that surprises me is this permission denied:

openat(AT_FDCWD, "/home/ealfonso/.config/redshift/redshift.conf", O_RDONLY) = -1 EACCES (Permission denied)

Suggesting that the process is being denied opening /home/ealfonso/.config/redshift/redshift.conf. This is strange because the file is supposed to be world-readable. All the parent directories are owner-executable, including the symlink target:

[debian-x1-7th][redshift-1.12][1]$ ls -l /home/ealfonso/.config/redshift/redshift.conf
lrwxrwxrwx 1 ealfonso ealfonso 47 Jul 21 15:47 /home/ealfonso/.config/redshift/redshift.conf -> /home/ealfonso/git/dotfiles/inits/redshift.conf
█[debian-x1-7th][redshift-1.12][0]$ ls -l /home/ealfonso/git/dotfiles/inits/redshift.conf
-rw-r--r-- 1 ealfonso ealfonso 138 Jul 21 15:32 /home/ealfonso/git/dotfiles/inits/redshift.conf
█[debian-x1-7th][redshift-1.12][0]$ ls -ld ~/.config/
drwx------ 29 ealfonso ealfonso 4096 Jul 21 15:47 /home/ealfonso/.config/
█[debian-x1-7th][redshift-1.12][0]$ ls -ld ~/
drwxr-xr-x 56 ealfonso ealfonso 4096 Jul 21 16:10 /home/ealfonso/
█[debian-x1-7th][redshift-1.12][0]$ ls -ld /home/
drwxr-xr-x 3 root root 4096 Apr 27 17:10 /home/
█[debian-x1-7th][redshift-1.12][0]$ 
█[debian-x1-7th][redshift-1.12][0]$ ls -ld /home/ealfonso/git/dotfiles/inits/
drwxr-xr-x 8 ealfonso ealfonso 4096 Jul 21 15:32 /home/ealfonso/git/dotfiles/inits/

I tried compiling redshift from source and adding some debug logs, and surprisingly I was not able to reproduce the error:

█[debian-x1-7th][redshift-1.12][130]$ strace -f -e trace=file ./src/redshift
execve("./src/redshift", ["./src/redshift"], 0x7ffc655cd728 /* 78 vars */) = 0
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libwayland-client.so.0", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libxcb.so.1", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libxcb-randr.so.0", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libgio-2.0.so.0", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libgobject-2.0.so.0", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libglib-2.0.so.0", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libm.so.6", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libpthread.so.0", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libffi.so.7", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libXau.so.6", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libXdmcp.so.6", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libgmodule-2.0.so.0", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libz.so.1", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libdl.so.2", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libmount.so.1", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libselinux.so.1", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libresolv.so.2", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libpcre.so.3", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libbsd.so.0", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libblkid.so.1", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libpcre2-8.so.0", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libmd.so.0", O_RDONLY|O_CLOEXEC) = 3
statfs("/sys/fs/selinux", 0x7fff8353fa80) = -1 ENOENT (No such file or directory)
statfs("/selinux", 0x7fff8353fa80)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/proc/filesystems", O_RDONLY|O_CLOEXEC) = 3
access("/etc/selinux/config", F_OK)     = 0
openat(AT_FDCWD, "/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3
DDEBUG 7w6d: cp /home/ealfonso/.config/redshift/redshift.conf
openat(AT_FDCWD, "/home/ealfonso/.config/redshift/redshift.conf", O_RDONLY) = 3
DDEBUG TRACE (config-ini.c) nlbc ()
DDEBUG wo2r: value randr
DDEBUG iwyt: m->name wayland
DDEBUG iwyt: m->name randr
access("/home/ealfonso/.Xauthority", R_OK) = 0
openat(AT_FDCWD, "/home/ealfonso/.Xauthority", O_RDONLY) = 4
openat(AT_FDCWD, "/usr/share/locale/locale.alias", O_RDONLY|O_CLOEXEC) = 4
openat(AT_FDCWD, "/usr/local/share/locale/en_US.UTF-8/LC_MESSAGES/redshift.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/local/share/locale/en_US.utf8/LC_MESSAGES/redshift.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/local/share/locale/en_US/LC_MESSAGES/redshift.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/local/share/locale/en.UTF-8/LC_MESSAGES/redshift.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/local/share/locale/en.utf8/LC_MESSAGES/redshift.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/local/share/locale/en/LC_MESSAGES/redshift.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
Waiting for initial location to become available...
Location: 28.56 N, 81.21 E
openat(AT_FDCWD, "/home/ealfonso/.config/redshift/hooks", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = -1 ENOENT (No such file or directory)
^Cstrace: Process 78851 detached

█[debian-x1-7th][redshift-1.12][130]$ 
    

In particular:

DDEBUG 7w6d: cp /home/ealfonso/.config/redshift/redshift.conf
openat(AT_FDCWD, "/home/ealfonso/.config/redshift/redshift.conf", O_RDONLY) = 3

The file is opened successfully and the correct configuration is loaded.

How can I further debug this strange error?

For context, I am on debian 11 using redshift 1.12, but this is intended as a general question of how to debug these system calls.

Shortly after posting the question, I looked into the files packaged as part of redshift and noticed an apparmor file with contents including:

#include <tunables/global>
/usr/bin/redshift {
  #include <abstractions/base>
  #include <abstractions/nameservice>
  #include <abstractions/dbus-strict>
  #include <abstractions/wayland>
  #include <abstractions/X>

  dbus send
       bus=system
       path=/org/freedesktop/GeoClue2/Client/[0-9]*,

  dbus receive
       bus=system
       path=/org/freedesktop/GeoClue2/Manager,

  # Allow but log any other dbus activity
  audit dbus bus=system,

  owner @{HOME}/.config/redshift.conf r,
  owner /run/user/*/redshift-shared-* rw,

  # Site-specific additions and overrides. See local/README for details.
  #include <local/usr.bin.redshift>
}

From the source, the ~/.config/redshift.conf is referred to as the "formerly used" fall-back path:

if (f == NULL && (env = getenv("XDG_CONFIG_HOME")) != NULL &&
            env[0] != '') {
            snprintf(cp, sizeof(cp),
                     "%s/redshift/redshift.conf", env);
            f = fopen(cp, "r");
            if (f == NULL) {
                /* Fall back to formerly used path. */
                snprintf(cp, sizeof(cp),
                         "%s/redshift.conf", env);
                f = fopen(cp, "r");
            }
        }

But after adding the line owner @{HOME}/.config/redshift/redshift.conf r to this config and the file was still denied.

Asked By: user84207

||

If there’s a file that all programs running with the same privileges can’t access, it’s because of file permissions. If there’s a file that some programs can access and others can’t, it’s because of their security context.

How to debug: look for something in the kernel logs. The location and content of the log file depends on which security framework is involved and how your distribution configures it. Look for a file under /var/log (possibly in a subdirectory) that gets modified when the access fails. Spoiler: it’s AppArmor, the logs are in /var/log/syslog and look like this:

Jul 21 20:55:00 darkstar kernel: [1234.567] audit: type=1400 audit(1234.567:89): apparmor="DENIED" operation="open" profile="/usr/bin/redshift" name="/home/ealfonso/.config/redshift/redshift.conf" pid=2345 comm="redshift" requested_mask="r" denied_mask="r" fsuid=1000 ouid=1000

Debian’s redshift package comes with an AppArmor profile which prevents /usr/bin/redshift from accessing arbitrary files under home directories. (The profile does not apply to executables called redshift located in directories other than /usr/bin.) The profile is located in /etc/apparmor.d/usr.bin.redshift and it denies access to files under /home apart from

   owner @{HOME}/.config/redshift.conf r,

Since your configuration file is a symbolic link that points outside the permitted area, redshift can’t follow the link.

One solution is to give /usr/bin/redshift broader permissions. You can add custom lines in /etc/apparmor.d/local/usr.bin.redshift. I think the following line should work for you:

  owner @{HOME}/git/dotfiles/inits/redshift.conf

Then run service apparmor reload to reload the AppArmor configuration.

Alternatively, make the usual location a copy of your git-managed file, rather than a symbolic link to it.