chiark / gitweb /
partial revert of fed6df8
[elogind.git] / src / tmpfiles / tmpfiles.c
index 44a087807e348b77df1c01ddbde8af001db65259..96b1fb4d3f338da40bb0d55d122440cedc8369c8 100644 (file)
@@ -308,6 +308,28 @@ static int dir_is_mount_point(DIR *d, const char *subdir) {
         return r;
 }
 
+static DIR* xopendirat_nomod(int dirfd, const char *path) {
+        DIR *dir;
+
+        dir = xopendirat(dirfd, path, O_NOFOLLOW|O_NOATIME);
+        if (!dir) {
+                log_debug_errno(errno, "Cannot open %sdirectory \"%s\": %m",
+                                dirfd == AT_FDCWD ? "" : "sub", path);
+                if (errno == EPERM) {
+                        dir = xopendirat(dirfd, path, O_NOFOLLOW);
+                        if (!dir)
+                                log_debug_errno(errno, "Cannot open %sdirectory \"%s\": %m",
+                                                dirfd == AT_FDCWD ? "" : "sub", path);
+                }
+        }
+
+        return dir;
+}
+
+static DIR* opendir_nomod(const char *path) {
+        return xopendirat_nomod(AT_FDCWD, path);
+}
+
 static int dir_cleanup(
                 Item *i,
                 const char *p,
@@ -329,8 +351,7 @@ static int dir_cleanup(
                 usec_t age;
                 _cleanup_free_ char *sub_path = NULL;
 
-                if (streq(dent->d_name, ".") ||
-                    streq(dent->d_name, ".."))
+                if (STR_IN_SET(dent->d_name, ".", ".."))
                         continue;
 
                 if (fstatat(dirfd(d), dent->d_name, &s, AT_SYMLINK_NOFOLLOW) < 0) {
@@ -347,18 +368,25 @@ static int dir_cleanup(
                 }
 
                 /* Stay on the same filesystem */
-                if (s.st_dev != rootdev)
+                if (s.st_dev != rootdev) {
+                        log_debug("Ignoring \"%s/%s\": different filesystem.", p, dent->d_name);
                         continue;
+                }
 
                 /* Try to detect bind mounts of the same filesystem instance; they
                  * do not differ in device major/minors. This type of query is not
                  * supported on all kernels or filesystem types though. */
-                if (S_ISDIR(s.st_mode) && dir_is_mount_point(d, dent->d_name) > 0)
+                if (S_ISDIR(s.st_mode) && dir_is_mount_point(d, dent->d_name) > 0) {
+                        log_debug("Ignoring \"%s/%s\": different mount of the same filesystem.",
+                                  p, dent->d_name);
                         continue;
+                }
 
                 /* Do not delete read-only files owned by root */
-                if (s.st_uid == 0 && !(s.st_mode & S_IWUSR))
+                if (s.st_uid == 0 && !(s.st_mode & S_IWUSR)) {
+                        log_debug("Ignoring \"%s/%s\": read-only and owner by root.", p, dent->d_name);
                         continue;
+                }
 
                 sub_path = strjoin(p, "/", dent->d_name, NULL);
                 if (!sub_path) {
@@ -367,31 +395,35 @@ static int dir_cleanup(
                 }
 
                 /* Is there an item configured for this path? */
-                if (hashmap_get(items, sub_path))
+                if (hashmap_get(items, sub_path)) {
+                        log_debug("Ignoring \"%s\": a separate entry exists.", sub_path);
                         continue;
+                }
 
-                if (find_glob(globs, sub_path))
+                if (find_glob(globs, sub_path)) {
+                        log_debug("Ignoring \"%s\": a separate glob exists.", sub_path);
                         continue;
+                }
 
                 if (S_ISDIR(s.st_mode)) {
 
                         if (mountpoint &&
                             streq(dent->d_name, "lost+found") &&
-                            s.st_uid == 0)
+                            s.st_uid == 0) {
+                                log_debug("Ignoring \"%s\".", sub_path);
                                 continue;
+                        }
 
                         if (maxdepth <= 0)
-                                log_warning("Reached max depth on %s.", sub_path);
+                                log_warning("Reached max depth on \"%s\".", sub_path);
                         else {
                                 _cleanup_closedir_ DIR *sub_dir;
                                 int q;
 
-                                sub_dir = xopendirat(dirfd(d), dent->d_name, O_NOFOLLOW|O_NOATIME);
+                                sub_dir = xopendirat_nomod(dirfd(d), dent->d_name);
                                 if (!sub_dir) {
-                                        if (errno != ENOENT) {
-                                                log_error_errno(errno, "opendir(%s/%s) failed: %m", p, dent->d_name);
-                                                r = -errno;
-                                        }
+                                        if (errno != ENOENT)
+                                                r = log_error_errno(errno, "opendir(%s) failed: %m", sub_path);
 
                                         continue;
                                 }
@@ -408,83 +440,128 @@ static int dir_cleanup(
                          * bit already has a meaning for directories,
                          * so we don't want to overload that. */
 
-                        if (keep_this_level)
+                        if (keep_this_level) {
+                                log_debug("Keeping \"%s\".", sub_path);
                                 continue;
+                        }
 
                         /* Ignore ctime, we change it when deleting */
-                        age = MAX(timespec_load(&s.st_mtim),
-                                  timespec_load(&s.st_atim));
-                        if (age >= cutoff)
+                        age = timespec_load(&s.st_mtim);
+                        if (age >= cutoff) {
+                                char a[FORMAT_TIMESTAMP_MAX];
+                                /* Follows spelling in stat(1). */
+                                log_debug("Directory \"%s\": modify time %s is too new.",
+                                          sub_path,
+                                          format_timestamp_us(a, sizeof(a), age));
                                 continue;
+                        }
 
-                        if (i->type != IGNORE_DIRECTORY_PATH || !streq(dent->d_name, p)) {
-                                log_debug("rmdir '%s'", sub_path);
+                        age = timespec_load(&s.st_atim);
+                        if (age >= cutoff) {
+                                char a[FORMAT_TIMESTAMP_MAX];
+                                log_debug("Directory \"%s\": access time %s is too new.",
+                                          sub_path,
+                                          format_timestamp_us(a, sizeof(a), age));
+                                continue;
+                        }
 
-                                if (unlinkat(dirfd(d), dent->d_name, AT_REMOVEDIR) < 0) {
-                                        if (errno != ENOENT && errno != ENOTEMPTY) {
-                                                log_error_errno(errno, "rmdir(%s): %m", sub_path);
-                                                r = -errno;
-                                        }
+                        log_debug("Removing directory \"%s\".", sub_path);
+                        if (unlinkat(dirfd(d), dent->d_name, AT_REMOVEDIR) < 0)
+                                if (errno != ENOENT && errno != ENOTEMPTY) {
+                                        log_error_errno(errno, "rmdir(%s): %m", sub_path);
+                                        r = -errno;
                                 }
-                        }
 
                 } else {
                         /* Skip files for which the sticky bit is
                          * set. These are semantics we define, and are
                          * unknown elsewhere. See XDG_RUNTIME_DIR
                          * specification for details. */
-                        if (s.st_mode & S_ISVTX)
+                        if (s.st_mode & S_ISVTX) {
+                                log_debug("Skipping \"%s\": sticky bit set.", sub_path);
                                 continue;
+                        }
 
-                        if (mountpoint && S_ISREG(s.st_mode)) {
-                                if (streq(dent->d_name, ".journal") &&
-                                    s.st_uid == 0)
-                                        continue;
-
-                                if (streq(dent->d_name, "aquota.user") ||
-                                    streq(dent->d_name, "aquota.group"))
+                        if (mountpoint && S_ISREG(s.st_mode))
+                                if ((streq(dent->d_name, ".journal") && s.st_uid == 0) ||
+                                    streq(dent->d_name, "aquota.user") ||
+                                    streq(dent->d_name, "aquota.group")) {
+                                        log_debug("Skipping \"%s\".", sub_path);
                                         continue;
-                        }
+                                }
 
                         /* Ignore sockets that are listed in /proc/net/unix */
-                        if (S_ISSOCK(s.st_mode) && unix_socket_alive(sub_path))
+                        if (S_ISSOCK(s.st_mode) && unix_socket_alive(sub_path)) {
+                                log_debug("Skipping \"%s\": live socket.", sub_path);
                                 continue;
+                        }
 
                         /* Ignore device nodes */
-                        if (S_ISCHR(s.st_mode) || S_ISBLK(s.st_mode))
+                        if (S_ISCHR(s.st_mode) || S_ISBLK(s.st_mode)) {
+                                log_debug("Skipping \"%s\": a device.", sub_path);
                                 continue;
+                        }
 
                         /* Keep files on this level around if this is
                          * requested */
-                        if (keep_this_level)
+                        if (keep_this_level) {
+                                log_debug("Keeping \"%s\".", sub_path);
                                 continue;
+                        }
 
-                        age = MAX3(timespec_load(&s.st_mtim),
-                                   timespec_load(&s.st_atim),
-                                   timespec_load(&s.st_ctim));
-
-                        if (age >= cutoff)
+                        age = timespec_load(&s.st_mtim);
+                        if (age >= cutoff) {
+                                char a[FORMAT_TIMESTAMP_MAX];
+                                /* Follows spelling in stat(1). */
+                                log_debug("File \"%s\": modify time %s is too new.",
+                                          sub_path,
+                                          format_timestamp_us(a, sizeof(a), age));
                                 continue;
+                        }
 
-                        log_debug("unlink '%s'", sub_path);
+                        age = timespec_load(&s.st_atim);
+                        if (age >= cutoff) {
+                                char a[FORMAT_TIMESTAMP_MAX];
+                                log_debug("File \"%s\": access time %s is too new.",
+                                          sub_path,
+                                          format_timestamp_us(a, sizeof(a), age));
+                                continue;
+                        }
 
-                        if (unlinkat(dirfd(d), dent->d_name, 0) < 0) {
-                                if (errno != ENOENT) {
-                                        log_error_errno(errno, "unlink(%s): %m", sub_path);
-                                        r = -errno;
-                                }
+                        age = timespec_load(&s.st_ctim);
+                        if (age >= cutoff) {
+                                char a[FORMAT_TIMESTAMP_MAX];
+                                log_debug("File \"%s\": change time %s is too new.",
+                                          sub_path,
+                                          format_timestamp_us(a, sizeof(a), age));
+                                continue;
                         }
 
+                        log_debug("unlink \"%s\"", sub_path);
+
+                        if (unlinkat(dirfd(d), dent->d_name, 0) < 0)
+                                if (errno != ENOENT)
+                                        r = log_error_errno(errno, "unlink(%s): %m", sub_path);
+
                         deleted = true;
                 }
         }
 
 finish:
         if (deleted) {
+                usec_t age1, age2;
+                char a[FORMAT_TIMESTAMP_MAX], b[FORMAT_TIMESTAMP_MAX];
+
                 /* Restore original directory timestamps */
                 times[0] = ds->st_atim;
                 times[1] = ds->st_mtim;
 
+                age1 = timespec_load(&ds->st_atim);
+                age2 = timespec_load(&ds->st_mtim);
+                log_debug("Restoring access and modification time on \"%s\": %s, %s",
+                          p,
+                          format_timestamp_us(a, sizeof(a), age1),
+                          format_timestamp_us(b, sizeof(b), age2));
                 if (futimens(dirfd(d), times) < 0)
                         log_error_errno(errno, "utimensat(%s): %m", p);
         }
@@ -516,19 +593,27 @@ static int path_set_perms(Item *i, const char *path) {
                                 m &= ~07000; /* remove sticky/sgid/suid bit, unless directory */
                 }
 
-                if (!st_valid || m != (st.st_mode & 07777)) {
+                if (st_valid && m == (st.st_mode & 07777))
+                        log_debug("\"%s\" has right mode %o", path, st.st_mode);
+                else {
+                        log_debug("chmod \"%s\" to mode %o", path, m);
                         if (chmod(path, m) < 0)
                                 return log_error_errno(errno, "chmod(%s) failed: %m", path);
                 }
         }
 
-        if ((!st_valid || (i->uid != st.st_uid || i->gid != st.st_gid)) &&
-            (i->uid_set || i->gid_set))
+        if ((!st_valid || i->uid != st.st_uid || i->gid != st.st_gid) &&
+            (i->uid_set || i->gid_set)) {
+                log_debug("chown \"%s\" to "UID_FMT"."GID_FMT,
+                          path,
+                          i->uid_set ? i->uid : UID_INVALID,
+                          i->gid_set ? i->gid : GID_INVALID);
                 if (chown(path,
                           i->uid_set ? i->uid : UID_INVALID,
                           i->gid_set ? i->gid : GID_INVALID) < 0)
 
                         return log_error_errno(errno, "chown(%s) failed: %m", path);
+        }
 
         return label_fix(path, false, false);
 }
@@ -584,6 +669,7 @@ static int path_set_xattrs(Item *i, const char *path) {
                 int n;
 
                 n = strlen(*value);
+                log_debug("\"%s\": setting xattr \"%s=%s\"", path, *name, *value);
                 if (lsetxattr(path, *name, *value, n, 0) < 0) {
                         log_error("Setting extended attribute %s=%s on %s failed: %m",
                                   *name, *value, path);
@@ -596,11 +682,12 @@ static int path_set_xattrs(Item *i, const char *path) {
 static int get_acls_from_arg(Item *item) {
 #ifdef HAVE_ACL
         int r;
-        _cleanup_(acl_freep) acl_t a = NULL, d = NULL;
 
         assert(item);
 
-        r = parse_acl(item->argument, &item->acl_access, &item->acl_default);
+        /* If force (= modify) is set, we will not modify the acl
+         * afterwards, so the mask can be added now if necessary. */
+        r = parse_acl(item->argument, &item->acl_access, &item->acl_default, !item->force);
         if (r < 0)
                 log_warning_errno(errno, "Failed to parse ACL \"%s\": %m. Ignoring",
                                   item->argument);
@@ -611,6 +698,45 @@ static int get_acls_from_arg(Item *item) {
         return 0;
 }
 
+static int path_set_acl(const char *path, acl_type_t type, acl_t acl, bool modify) {
+        _cleanup_(acl_freep) acl_t dup = NULL;
+        int r;
+        _cleanup_(acl_free_charpp) char *t = NULL;
+
+        if (modify) {
+                r = acls_for_file(path, type, acl, &dup);
+                if (r < 0)
+                        return r;
+
+                r = calc_acl_mask_if_needed(&dup);
+                if (r < 0)
+                        return r;
+        } else {
+                dup = acl_dup(acl);
+                if (!dup)
+                        return -errno;
+
+                /* the mask was already added earlier if needed */
+        }
+
+        r = add_base_acls_if_needed(&dup, path);
+        if (r < 0)
+                return r;
+
+        t = acl_to_any_text(dup, NULL, ',', TEXT_ABBREVIATE);
+        log_debug("\"%s\": setting %s ACL \"%s\"", path,
+                  type == ACL_TYPE_ACCESS ? "access" : "default",
+                  strna(t));
+
+        r = acl_set_file(path, type, dup);
+        if (r < 0)
+                return log_error_errno(-errno,
+                                       "Setting %s ACL \"%s\" on %s failed: %m",
+                                       type == ACL_TYPE_ACCESS ? "access" : "default",
+                                       strna(t), path);
+        return 0;
+}
+
 static int path_set_acls(Item *item, const char *path) {
 #ifdef HAVE_ACL
         int r;
@@ -619,27 +745,15 @@ static int path_set_acls(Item *item, const char *path) {
         assert(path);
 
         if (item->acl_access) {
-                r = acl_set_file(path, ACL_TYPE_ACCESS, item->acl_access);
-                if (r < 0) {
-                        _cleanup_(acl_free_charpp) char *t;
-
-                        t = acl_to_any_text(item->acl_access, NULL, ',', TEXT_ABBREVIATE);
-                        return log_error_errno(errno,
-                                               "Setting access ACL \"%s\" on %s failed: %m",
-                                               strna(t), path);
-                }
+                r = path_set_acl(path, ACL_TYPE_ACCESS, item->acl_access, item->force);
+                if (r < 0)
+                        return r;
         }
 
         if (item->acl_default) {
-                r = acl_set_file(path, ACL_TYPE_DEFAULT, item->acl_default);
-                if (r < 0) {
-                        _cleanup_(acl_free_charpp) char *t;
-
-                        t = acl_to_any_text(item->acl_default, NULL, ',', TEXT_ABBREVIATE);
-                        return log_error_errno(errno,
-                                               "Setting default ACL \"%s\" on %s failed: %m",
-                                               strna(t), path);
-                }
+                r = path_set_acl(path, ACL_TYPE_DEFAULT, item->acl_default, item->force);
+                if (r < 0)
+                        return r;
         }
 #endif
 
@@ -664,8 +778,10 @@ static int write_one_file(Item *i, const char *path) {
         }
 
         if (fd < 0) {
-                if (i->type == WRITE_FILE && errno == ENOENT)
+                if (i->type == WRITE_FILE && errno == ENOENT) {
+                        log_debug_errno(errno, "Not writing \"%s\": %m", path);
                         return 0;
+                }
 
                 log_error_errno(errno, "Failed to create file %s: %m", path);
                 return -errno;
@@ -673,21 +789,19 @@ static int write_one_file(Item *i, const char *path) {
 
         if (i->argument) {
                 _cleanup_free_ char *unescaped;
-                ssize_t n;
-                size_t l;
+
+                log_debug("%s to \"%s\".",
+                          i->type == CREATE_FILE ? "Appending" : "Writing", path);
 
                 unescaped = cunescape(i->argument);
                 if (!unescaped)
                         return log_oom();
 
-                l = strlen(unescaped);
-                n = write(fd, unescaped, l);
-
-                if (n < 0 || (size_t) n < l) {
-                        log_error("Failed to write file %s: %s", path, n < 0 ? strerror(-n) : "Short write");
-                        return n < 0 ? n : -EIO;
-                }
-        }
+                r = loop_write(fd, unescaped, strlen(unescaped), false);
+                if (r < 0)
+                        return log_error_errno(r, "Failed to write file \"%s\": %m", path);
+        } else
+                log_debug("\"%s\" has been created.", path);
 
         fd = safe_close(fd);
 
@@ -718,7 +832,7 @@ static int item_do_children(Item *i, const char *path, action_t action) {
         /* This returns the first error we run into, but nevertheless
          * tries to go on */
 
-        d = opendir(path);
+        d = opendir_nomod(path);
         if (!d)
                 return errno == ENOENT || errno == ENOTDIR ? 0 : -errno;
 
@@ -736,7 +850,7 @@ static int item_do_children(Item *i, const char *path, action_t action) {
                         break;
                 }
 
-                if (streq(de->d_name, ".") || streq(de->d_name, ".."))
+                if (STR_IN_SET(de->d_name, ".", ".."))
                         continue;
 
                 p = strjoin(path, "/", de->d_name, NULL);
@@ -758,12 +872,18 @@ static int item_do_children(Item *i, const char *path, action_t action) {
 }
 
 static int glob_item(Item *i, action_t action, bool recursive) {
-        _cleanup_globfree_ glob_t g = {};
+        _cleanup_globfree_ glob_t g = {
+                .gl_closedir = (void (*)(void *)) closedir,
+                .gl_readdir = (struct dirent *(*)(void *)) readdir,
+                .gl_opendir = (void *(*)(const char *)) opendir_nomod,
+                .gl_lstat = lstat,
+                .gl_stat = stat,
+        };
         int r = 0, k;
         char **fn;
 
         errno = 0;
-        k = glob(i->path, GLOB_NOSORT|GLOB_BRACE, NULL, &g);
+        k = glob(i->path, GLOB_NOSORT|GLOB_BRACE|GLOB_ALTDIRFUNC, NULL, &g);
         if (k != 0 && k != GLOB_NOMATCH)
                 return log_error_errno(errno ?: EIO, "glob(%s) failed: %m", i->path);
 
@@ -782,12 +902,31 @@ static int glob_item(Item *i, action_t action, bool recursive) {
         return r;
 }
 
+typedef enum {
+        CREATION_NORMAL,
+        CREATION_EXISTING,
+        CREATION_FORCE,
+        _CREATION_MODE_MAX,
+        _CREATION_MODE_INVALID = -1
+} CreationMode;
+
+static const char *creation_mode_verb_table[_CREATION_MODE_MAX] = {
+        [CREATION_NORMAL] = "Created",
+        [CREATION_EXISTING] = "Found existing",
+        [CREATION_FORCE] = "Created replacement",
+};
+
+DEFINE_PRIVATE_STRING_TABLE_LOOKUP_TO_STRING(creation_mode_verb, CreationMode);
+
 static int create_item(Item *i) {
         struct stat st;
         int r = 0;
+        CreationMode creation;
 
         assert(i);
 
+        log_debug("Running create action for entry %c %s", (char) i->type, i->path);
+
         switch (i->type) {
 
         case IGNORE_PATH:
@@ -804,6 +943,7 @@ static int create_item(Item *i) {
                 break;
 
         case COPY_FILES:
+                log_debug("Copying tree \"%s\" to \"%s\".", i->argument, i->path);
                 r = copy_tree(i->argument, i->path, false);
                 if (r < 0) {
                         struct stat a, b;
@@ -843,29 +983,34 @@ static int create_item(Item *i) {
                 RUN_WITH_UMASK(0000)
                         mkdir_parents_label(i->path, 0755);
 
-                if (i->type == CREATE_SUBVOLUME) {
-                        RUN_WITH_UMASK((~i->mode) & 0777)
+                if (i->type == CREATE_SUBVOLUME)
+                        RUN_WITH_UMASK((~i->mode) & 0777) {
                                 r = btrfs_subvol_make(i->path);
-                } else
+                                log_debug_errno(r, "Creating subvolume \"%s\": %m", i->path);
+                        }
+                else
                         r = 0;
 
-                if (IN_SET(i->type, CREATE_DIRECTORY, TRUNCATE_DIRECTORY) || r == -ENOTTY) {
+                if (IN_SET(i->type, CREATE_DIRECTORY, TRUNCATE_DIRECTORY) || r == -ENOTTY)
                         RUN_WITH_UMASK(0000)
                                 r = mkdir_label(i->path, i->mode);
-                }
 
                 if (r < 0) {
                         if (r != -EEXIST)
-                                return log_error_errno(r, "Failed to create directory or subvolume %s: %m", i->path);
+                                return log_error_errno(r, "Failed to create directory or subvolume \"%s\": %m", i->path);
 
                         if (stat(i->path, &st) < 0)
                                 return log_error_errno(errno, "stat(%s) failed: %m", i->path);
 
                         if (!S_ISDIR(st.st_mode)) {
-                                log_debug("%s already exists and is not a directory.", i->path);
+                                log_debug("\"%s\" already exists and is not a directory.", i->path);
                                 return 0;
                         }
-                }
+
+                        creation = CREATION_EXISTING;
+                } else
+                        creation = CREATION_NORMAL;
+                log_debug("%s directory \"%s\".", creation_mode_verb_to_string(creation), i->path);
 
                 r = path_set_perms(i, i->path);
                 if (r < 0)
@@ -900,12 +1045,16 @@ static int create_item(Item *i) {
 
                                         if (r < 0)
                                                 return log_error_errno(r, "Failed to create fifo %s: %m", i->path);
+                                        creation = CREATION_FORCE;
                                 } else {
                                         log_debug("%s is not a fifo.", i->path);
                                         return 0;
                                 }
-                        }
-                }
+                        } else
+                                creation = CREATION_EXISTING;
+                } else
+                        creation = CREATION_NORMAL;
+                log_debug("%s fifo \"%s\".", creation_mode_verb_to_string(creation), i->path);
 
                 r = path_set_perms(i, i->path);
                 if (r < 0)
@@ -935,12 +1084,16 @@ static int create_item(Item *i) {
 
                                         if (r < 0)
                                                 return log_error_errno(r, "symlink(%s, %s) failed: %m", i->argument, i->path);
+                                        creation = CREATION_FORCE;
                                 } else {
-                                        log_debug("%s is not a symlink or does not point to the correct path.", i->path);
+                                        log_debug("\"%s\" is not a symlink or does not point to the correct path.", i->path);
                                         return 0;
                                 }
-                        }
-                }
+                        } else
+                                creation = CREATION_EXISTING;
+                } else
+                        creation = CREATION_NORMAL;
+                log_debug("%s symlink \"%s\".", creation_mode_verb_to_string(creation), i->path);
 
                 break;
 
@@ -990,13 +1143,20 @@ static int create_item(Item *i) {
                                         }
 
                                         if (r < 0)
-                                                return log_error_errno(r, "Failed to create device node %s: %m", i->path);
+                                                return log_error_errno(r, "Failed to create device node \"%s\": %m", i->path);
+                                        creation = CREATION_FORCE;
                                 } else {
                                         log_debug("%s is not a device node.", i->path);
                                         return 0;
                                 }
-                        }
-                }
+                        } else
+                                creation = CREATION_EXISTING;
+                } else
+                        creation = CREATION_NORMAL;
+                log_debug("%s %s device node \"%s\" %u:%u.",
+                          creation_mode_verb_to_string(creation),
+                          i->type == CREATE_BLOCK_DEVICE ? "block" : "char",
+                          i->path, major(i->mode), minor(i->mode));
 
                 r = path_set_perms(i, i->path);
                 if (r < 0)
@@ -1055,27 +1215,6 @@ static int remove_item_instance(Item *i, const char *instance) {
 
         switch (i->type) {
 
-        case CREATE_FILE:
-        case TRUNCATE_FILE:
-        case CREATE_DIRECTORY:
-        case CREATE_SUBVOLUME:
-        case CREATE_FIFO:
-        case CREATE_SYMLINK:
-        case CREATE_BLOCK_DEVICE:
-        case CREATE_CHAR_DEVICE:
-        case IGNORE_PATH:
-        case IGNORE_DIRECTORY_PATH:
-        case ADJUST_MODE:
-        case RELABEL_PATH:
-        case RECURSIVE_RELABEL_PATH:
-        case WRITE_FILE:
-        case COPY_FILES:
-        case SET_XATTR:
-        case RECURSIVE_SET_XATTR:
-        case SET_ACL:
-        case RECURSIVE_SET_ACL:
-                break;
-
         case REMOVE_PATH:
                 if (remove(instance) < 0 && errno != ENOENT)
                         return log_error_errno(errno, "rm(%s): %m", instance);
@@ -1086,11 +1225,15 @@ static int remove_item_instance(Item *i, const char *instance) {
         case RECURSIVE_REMOVE_PATH:
                 /* FIXME: we probably should use dir_cleanup() here
                  * instead of rm_rf() so that 'x' is honoured. */
+                log_debug("rm -rf \"%s\"", instance);
                 r = rm_rf_dangerous(instance, false, i->type == RECURSIVE_REMOVE_PATH, false);
                 if (r < 0 && r != -ENOENT)
                         return log_error_errno(r, "rm_rf(%s): %m", instance);
 
                 break;
+
+        default:
+                assert_not_reached("wut?");
         }
 
         return 0;
@@ -1101,6 +1244,8 @@ static int remove_item(Item *i) {
 
         assert(i);
 
+        log_debug("Running remove action for entry %c %s", (char) i->type, i->path);
+
         switch (i->type) {
 
         case CREATE_FILE:
@@ -1138,8 +1283,8 @@ static int clean_item_instance(Item *i, const char* instance) {
         _cleanup_closedir_ DIR *d = NULL;
         struct stat s, ps;
         bool mountpoint;
-        int r;
         usec_t cutoff, n;
+        char timestamp[FORMAT_TIMESTAMP_MAX];
 
         assert(i);
 
@@ -1152,12 +1297,14 @@ static int clean_item_instance(Item *i, const char* instance) {
 
         cutoff = n - i->age;
 
-        d = opendir(instance);
+        d = opendir_nomod(instance);
         if (!d) {
-                if (errno == ENOENT || errno == ENOTDIR)
+                if (errno == ENOENT || errno == ENOTDIR) {
+                        log_debug_errno(errno, "Directory \"%s\": %m", instance);
                         return 0;
+                }
 
-                log_error_errno(errno, "Failed to open directory %s: %m", i->path);
+                log_error_errno(errno, "Failed to open directory %s: %m", instance);
                 return -errno;
         }
 
@@ -1175,9 +1322,13 @@ static int clean_item_instance(Item *i, const char* instance) {
         mountpoint = s.st_dev != ps.st_dev ||
                      (s.st_dev == ps.st_dev && s.st_ino == ps.st_ino);
 
-        r = dir_cleanup(i, instance, d, &s, cutoff, s.st_dev, mountpoint,
-                        MAX_DEPTH, i->keep_first_level);
-        return r;
+        log_debug("Cleanup threshold for %s \"%s\" is %s",
+                  mountpoint ? "mount point" : "directory",
+                  instance,
+                  format_timestamp_us(timestamp, sizeof(timestamp), cutoff));
+
+        return dir_cleanup(i, instance, d, &s, cutoff, s.st_dev, mountpoint,
+                           MAX_DEPTH, i->keep_first_level);
 }
 
 static int clean_item(Item *i) {
@@ -1185,6 +1336,8 @@ static int clean_item(Item *i) {
 
         assert(i);
 
+        log_debug("Running clean action for entry %c %s", (char) i->type, i->path);
+
         switch (i->type) {
         case CREATE_DIRECTORY:
         case CREATE_SUBVOLUME:
@@ -1316,16 +1469,25 @@ static bool should_include_path(const char *path) {
         char **prefix;
 
         STRV_FOREACH(prefix, arg_exclude_prefixes)
-                if (path_startswith(path, *prefix))
+                if (path_startswith(path, *prefix)) {
+                        log_debug("Entry \"%s\" matches exclude prefix \"%s\", skipping.",
+                                  path, *prefix);
                         return false;
+                }
 
         STRV_FOREACH(prefix, arg_include_prefixes)
-                if (path_startswith(path, *prefix))
+                if (path_startswith(path, *prefix)) {
+                        log_debug("Entry \"%s\" matches include prefix \"%s\".", path, *prefix);
                         return true;
+                }
 
         /* no matches, so we should include this path only if we
          * have no whitelist at all */
-        return strv_length(arg_include_prefixes) == 0;
+        if (strv_length(arg_include_prefixes) == 0)
+                return true;
+
+        log_debug("Entry \"%s\" does not match any include prefix, skipping.", path);
+        return false;
 }
 
 static int parse_line(const char *fname, unsigned line, const char *buffer) {
@@ -1380,8 +1542,11 @@ static int parse_line(const char *fname, unsigned line, const char *buffer) {
                 }
         }
 
-        if (boot && !arg_boot)
+        if (boot && !arg_boot) {
+                log_debug("Ignoring entry %s \"%s\" because --boot is not specified.",
+                          action, path);
                 return 0;
+        }
 
         i.type = action[0];
         i.force = force;
@@ -1487,7 +1652,7 @@ static int parse_line(const char *fname, unsigned line, const char *buffer) {
                 break;
 
         default:
-                log_error("[%s:%u] Unknown command type '%c'.", fname, line, i.type);
+                log_error("[%s:%u] Unknown command type '%c'.", fname, line, (char) i.type);
                 return -EBADMSG;
         }
 
@@ -1607,8 +1772,8 @@ static void help(void) {
                "     --clean                Clean up marked directories\n"
                "     --remove               Remove marked files/directories\n"
                "     --boot                 Execute actions only safe at boot\n"
-               "     --prefix=PATH          Only apply rules that apply to paths with the specified prefix\n"
-               "     --exclude-prefix=PATH  Ignore rules that apply to paths with the specified prefix\n"
+               "     --prefix=PATH          Only apply rules with the specified prefix\n"
+               "     --exclude-prefix=PATH  Ignore rules with the specified prefix\n"
                "     --root=PATH            Operate on an alternate filesystem root\n",
                program_invocation_short_name);
 }
@@ -1719,11 +1884,14 @@ static int read_config_file(const char *fn, bool ignore_enoent) {
 
         r = search_and_fopen_nulstr(fn, "re", arg_root, conf_file_dirs, &f);
         if (r < 0) {
-                if (ignore_enoent && r == -ENOENT)
+                if (ignore_enoent && r == -ENOENT) {
+                        log_debug_errno(r, "Failed to open \"%s\": %m", fn);
                         return 0;
+                }
 
                 return log_error_errno(r, "Failed to open '%s', ignoring: %m", fn);
         }
+        log_debug("Reading config file \"%s\".", fn);
 
         FOREACH_LINE(line, f, break) {
                 char *l;