Merge pull request #21502 from keszybz/os-release-debugging

Additional debugging info to make release-extension easier to introspect

7 files changed, 68 insertions, 53 deletions

diff --git a/src/basic/os-util.c b/src/basic/os-util.c
index 2a218ad145..69ea39345a 100644
--- a/src/basic/os-util.c
+++ b/src/basic/os-util.c
@@ -72,6 +72,8 @@ int open_extension_release(const char *root, const char *extension, char **ret_p
                 r = chase_symlinks(extension_full_path, root, CHASE_PREFIX_ROOT,
                                    ret_path ? &q : NULL,
                                    ret_fd ? &fd : NULL);
+                log_full_errno_zerook(LOG_DEBUG, MIN(r, 0), "Checking for %s: %m", extension_full_path);
+
                 /* Cannot find the expected extension-release file? The image filename might have been
                  * mangled on deployment, so fallback to checking for any file in the extension-release.d
                  * directory, and return the first one with a user.extension-release xattr instead.
@@ -84,7 +86,7 @@ int open_extension_release(const char *root, const char *extension, char **ret_p
                         r = chase_symlinks_and_opendir("/usr/lib/extension-release.d/", root, CHASE_PREFIX_ROOT,
                                                        &extension_release_dir_path, &extension_release_dir);
                         if (r < 0)
-                                return r;
+                                return log_debug_errno(r, "Cannot open %s/usr/lib/extension-release.d/, ignoring: %m", root);
 
                         r = -ENOENT;
                         struct dirent *de;
@@ -98,8 +100,11 @@ int open_extension_release(const char *root, const char *extension, char **ret_p
                                 if (!image_name)
                                         continue;
 
-                                if (!image_name_is_valid(image_name))
+                                if (!image_name_is_valid(image_name)) {
+                                        log_debug("%s/%s is not a valid extension-release file name, ignoring.",
+                                                  extension_release_dir_path, de->d_name);
                                         continue;
+                                }
 
                                 /* We already chased the directory, and checked that
                                  * this is a real file, so we shouldn't fail to open it. */
@@ -113,30 +118,38 @@ int open_extension_release(const char *root, const char *extension, char **ret_p
                                                                de->d_name);
 
                                 /* Really ensure it is a regular file after we open it. */
-                                if (fd_verify_regular(extension_release_fd) < 0)
+                                if (fd_verify_regular(extension_release_fd) < 0) {
+                                        log_debug("%s/%s is not a regular file, ignoring.", extension_release_dir_path, de->d_name);
                                         continue;
+                                }
 
                                 /* No xattr or cannot parse it? Then skip this. */
                                 _cleanup_free_ char *extension_release_xattr = NULL;
                                 k = fgetxattr_malloc(extension_release_fd, "user.extension-release.strict", &extension_release_xattr);
                                 if (k < 0 && !ERRNO_IS_NOT_SUPPORTED(k) && k != -ENODATA)
                                         log_debug_errno(k,
-                                                        "Failed to read 'user.extension-release.strict' extended attribute from extension-release file %s/%s: %m",
-                                                        extension_release_dir_path,
-                                                        de->d_name);
-                                if (k < 0)
+                                                        "%s/%s: Failed to read 'user.extension-release.strict' extended attribute from file: %m",
+                                                        extension_release_dir_path, de->d_name);
+                                if (k < 0) {
+                                        log_debug("%s/%s does not have user.extension-release.strict xattr, ignoring.", extension_release_dir_path, de->d_name);
                                         continue;
+                                }
 
                                 /* Explicitly set to request strict matching? Skip it. */
                                 k = parse_boolean(extension_release_xattr);
                                 if (k < 0)
                                         log_debug_errno(k,
-                                                        "Failed to parse 'user.extension-release.strict' extended attribute value from extension-release file %s/%s: %m",
-                                                        extension_release_dir_path,
-                                                        de->d_name);
-                                if (k < 0 || k > 0)
+                                                        "%s/%s: Failed to parse 'user.extension-release.strict' extended attribute from file: %m",
+                                                        extension_release_dir_path, de->d_name);
+                                else if (k > 0)
+                                        log_debug("%s/%s: 'user.extension-release.strict' attribute is true, ignoring file.",
+                                                  extension_release_dir_path, de->d_name);
+                                if (k != 0)
                                         continue;
 
+                                log_debug("%s/%s: 'user.extension-release.strict' attribute is false…",
+                                          extension_release_dir_path, de->d_name);
+
                                 /* We already found what we were looking for, but there's another candidate?
                                  * We treat this as an error, as we want to enforce that there are no ambiguities
                                  * in case we are in the fallback path.*/
diff --git a/src/dissect/dissect.c b/src/dissect/dissect.c
index 753d4aefd7..a9632a3f16 100644
--- a/src/dissect/dissect.c
+++ b/src/dissect/dissect.c
@@ -433,7 +433,7 @@ static int action_dissect(DissectedImage *m, LoopDevice *d) {
         if (arg_json_format_flags & JSON_FORMAT_OFF)
                 putc('\n', stdout);
 
-        r = dissected_image_acquire_metadata(m);
+        r = dissected_image_acquire_metadata(m, 0);
         if (r == -ENXIO)
                 return log_error_errno(r, "No root partition discovered.");
         if (r == -EUCLEAN)
diff --git a/src/shared/discover-image.c b/src/shared/discover-image.c
index 60833cec45..9c07cda8ee 100644
--- a/src/shared/discover-image.c
+++ b/src/shared/discover-image.c
@@ -1216,7 +1216,9 @@ int image_read_metadata(Image *i) {
                 if (r < 0)
                         return r;
 
-                r = dissected_image_acquire_metadata(m);
+                r = dissected_image_acquire_metadata(m,
+                                                     DISSECT_IMAGE_VALIDATE_OS |
+                                                     DISSECT_IMAGE_VALIDATE_OS_EXT);
                 if (r < 0)
                         return r;
 
diff --git a/src/shared/dissect-image.c b/src/shared/dissect-image.c
index 06d0319f75..685c5225d5 100644
--- a/src/shared/dissect-image.c
+++ b/src/shared/dissect-image.c
@@ -3009,7 +3009,7 @@ int dissected_image_load_verity_sig_partition(
         return 1;
 }
 
-int dissected_image_acquire_metadata(DissectedImage *m) {
+int dissected_image_acquire_metadata(DissectedImage *m, DissectImageFlags extra_flags) {
 
         enum {
                 META_HOSTNAME,
@@ -3026,7 +3026,7 @@ int dissected_image_acquire_metadata(DissectedImage *m) {
                 [META_MACHINE_ID]        = "/etc/machine-id\0",
                 [META_MACHINE_INFO]      = "/etc/machine-info\0",
                 [META_OS_RELEASE]        = ("/etc/os-release\0"
-                                           "/usr/lib/os-release\0"),
+                                            "/usr/lib/os-release\0"),
                 [META_EXTENSION_RELEASE] = "extension-release\0",    /* Used only for logging. */
                 [META_HAS_INIT_SYSTEM]   = "has-init-system\0",      /* ditto */
         };
@@ -3079,17 +3079,13 @@ int dissected_image_acquire_metadata(DissectedImage *m) {
                                 t,
                                 UID_INVALID,
                                 UID_INVALID,
-                                DISSECT_IMAGE_READ_ONLY|
-                                DISSECT_IMAGE_MOUNT_ROOT_ONLY|
-                                DISSECT_IMAGE_VALIDATE_OS|
-                                DISSECT_IMAGE_VALIDATE_OS_EXT|
+                                extra_flags |
+                                DISSECT_IMAGE_READ_ONLY |
+                                DISSECT_IMAGE_MOUNT_ROOT_ONLY |
                                 DISSECT_IMAGE_USR_NO_ROOT);
                 if (r < 0) {
-                        /* Let parent know the error */
-                        (void) write(error_pipe[1], &r, sizeof(r));
-
                         log_debug_errno(r, "Failed to mount dissected image: %m");
-                        _exit(EXIT_FAILURE);
+                        goto inner_fail;
                 }
 
                 for (unsigned k = 0; k < _META_MAX; k++) {
@@ -3168,6 +3164,7 @@ int dissected_image_acquire_metadata(DissectedImage *m) {
                 _exit(EXIT_SUCCESS);
 
         inner_fail:
+                /* Let parent know the error */
                 (void) write(error_pipe[1], &r, sizeof(r));
                 _exit(EXIT_FAILURE);
         }
@@ -3193,7 +3190,7 @@ int dissected_image_acquire_metadata(DissectedImage *m) {
                 case META_HOSTNAME:
                         r = read_etc_hostname_stream(f, &hostname);
                         if (r < 0)
-                                log_debug_errno(r, "Failed to read /etc/hostname: %m");
+                                log_debug_errno(r, "Failed to read /etc/hostname of image: %m");
 
                         break;
 
@@ -3202,17 +3199,17 @@ int dissected_image_acquire_metadata(DissectedImage *m) {
 
                         r = read_line(f, LONG_LINE_MAX, &line);
                         if (r < 0)
-                                log_debug_errno(r, "Failed to read /etc/machine-id: %m");
+                                log_debug_errno(r, "Failed to read /etc/machine-id of image: %m");
                         else if (r == 33) {
                                 r = sd_id128_from_string(line, &machine_id);
                                 if (r < 0)
                                         log_debug_errno(r, "Image contains invalid /etc/machine-id: %s", line);
                         } else if (r == 0)
-                                log_debug("/etc/machine-id file is empty.");
+                                log_debug("/etc/machine-id file of image is empty.");
                         else if (streq(line, "uninitialized"))
-                                log_debug("/etc/machine-id file is uninitialized (likely aborted first boot).");
+                                log_debug("/etc/machine-id file of image is uninitialized (likely aborted first boot).");
                         else
-                                log_debug("/etc/machine-id has unexpected length %i.", r);
+                                log_debug("/etc/machine-id file of image has unexpected length %i.", r);
 
                         break;
                 }
@@ -3220,21 +3217,21 @@ int dissected_image_acquire_metadata(DissectedImage *m) {
                 case META_MACHINE_INFO:
                         r = load_env_file_pairs(f, "machine-info", &machine_info);
                         if (r < 0)
-                                log_debug_errno(r, "Failed to read /etc/machine-info: %m");
+                                log_debug_errno(r, "Failed to read /etc/machine-info of image: %m");
 
                         break;
 
                 case META_OS_RELEASE:
                         r = load_env_file_pairs(f, "os-release", &os_release);
                         if (r < 0)
-                                log_debug_errno(r, "Failed to read OS release file: %m");
+                                log_debug_errno(r, "Failed to read OS release file of image: %m");
 
                         break;
 
                 case META_EXTENSION_RELEASE:
                         r = load_env_file_pairs(f, "extension-release", &extension_release);
                         if (r < 0)
-                                log_debug_errno(r, "Failed to read extension release file: %m");
+                                log_debug_errno(r, "Failed to read extension release file of image: %m");
 
                         break;
 
@@ -3312,29 +3309,32 @@ int dissect_image_and_warn(
                 return log_error_errno(r, "Dissecting images is not supported, compiled without blkid support.");
 
         case -ENOPKG:
-                return log_error_errno(r, "Couldn't identify a suitable partition table or file system in '%s'.", name);
+                return log_error_errno(r, "%s: Couldn't identify a suitable partition table or file system.", name);
+
+        case -ENOMEDIUM:
+                return log_error_errno(r, "%s: The image does not pass validation.", name);
 
         case -EADDRNOTAVAIL:
-                return log_error_errno(r, "No root partition for specified root hash found in '%s'.", name);
+                return log_error_errno(r, "%s: No root partition for specified root hash found.", name);
 
         case -ENOTUNIQ:
-                return log_error_errno(r, "Multiple suitable root partitions found in image '%s'.", name);
+                return log_error_errno(r, "%s: Multiple suitable root partitions found in image.", name);
 
         case -ENXIO:
-                return log_error_errno(r, "No suitable root partition found in image '%s'.", name);
+                return log_error_errno(r, "%s: No suitable root partition found in image.", name);
 
         case -EPROTONOSUPPORT:
                 return log_error_errno(r, "Device '%s' is loopback block device with partition scanning turned off, please turn it on.", name);
 
+        case -ENOTBLK:
+                return log_error_errno(r, "%s: Image is not a block device.", name);
+
         case -EBADR:
                 return log_error_errno(r,
                                        "Combining partitioned images (such as '%s') with external Verity data (such as '%s') not supported. "
                                        "(Consider setting $SYSTEMD_DISSECT_VERITY_SIDECAR=0 to disable automatic discovery of external Verity data.)",
                                        name, strna(verity ? verity->data_path : NULL));
 
-        case -ENOTBLK:
-                return log_error_errno(r, "Specified image '%s' is not a block device.", name);
-
         default:
                 if (r < 0)
                         return log_error_errno(r, "Failed to dissect image '%s': %m", name);
diff --git a/src/shared/dissect-image.h b/src/shared/dissect-image.h
index 8ad26bc45b..48a9e0b4f9 100644
--- a/src/shared/dissect-image.h
+++ b/src/shared/dissect-image.h
@@ -208,7 +208,7 @@ int dissected_image_decrypt_interactively(DissectedImage *m, const char *passphr
 int dissected_image_mount(DissectedImage *m, const char *dest, uid_t uid_shift, uid_t uid_range, DissectImageFlags flags);
 int dissected_image_mount_and_warn(DissectedImage *m, const char *where, uid_t uid_shift, uid_t uid_range, DissectImageFlags flags);
 
-int dissected_image_acquire_metadata(DissectedImage *m);
+int dissected_image_acquire_metadata(DissectedImage *m, DissectImageFlags extra_flags);
 
 DecryptedImage* decrypted_image_unref(DecryptedImage *p);
 DEFINE_TRIVIAL_CLEANUP_FUNC(DecryptedImage*, decrypted_image_unref);
diff --git a/src/shared/format-table.c b/src/shared/format-table.c
index 3fe426863d..b95680b365 100644
--- a/src/shared/format-table.c
+++ b/src/shared/format-table.c
@@ -1708,7 +1708,7 @@ static const char *table_data_format(Table *t, TableData *d, bool avoid_uppercas
         }
 
         case TABLE_UID: {
-                _cleanup_free_ char *p = NULL;
+                char *p;
 
                 if (!uid_is_valid(d->uid))
                         return "n/a";
@@ -1716,14 +1716,14 @@ static const char *table_data_format(Table *t, TableData *d, bool avoid_uppercas
                 p = new(char, DECIMAL_STR_WIDTH(d->uid) + 1);
                 if (!p)
                         return NULL;
-
                 sprintf(p, UID_FMT, d->uid);
-                d->formatted = TAKE_PTR(p);
+
+                d->formatted = p;
                 break;
         }
 
         case TABLE_GID: {
-                _cleanup_free_ char *p = NULL;
+                char *p;
 
                 if (!gid_is_valid(d->gid))
                         return "n/a";
@@ -1731,14 +1731,14 @@ static const char *table_data_format(Table *t, TableData *d, bool avoid_uppercas
                 p = new(char, DECIMAL_STR_WIDTH(d->gid) + 1);
                 if (!p)
                         return NULL;
-
                 sprintf(p, GID_FMT, d->gid);
-                d->formatted = TAKE_PTR(p);
+
+                d->formatted = p;
                 break;
         }
 
         case TABLE_PID: {
-                _cleanup_free_ char *p = NULL;
+                char *p;
 
                 if (!pid_is_valid(d->pid))
                         return "n/a";
@@ -1746,15 +1746,15 @@ static const char *table_data_format(Table *t, TableData *d, bool avoid_uppercas
                 p = new(char, DECIMAL_STR_WIDTH(d->pid) + 1);
                 if (!p)
                         return NULL;
-
                 sprintf(p, PID_FMT, d->pid);
-                d->formatted = TAKE_PTR(p);
+
+                d->formatted = p;
                 break;
         }
 
         case TABLE_SIGNAL: {
-                _cleanup_free_ char *p = NULL;
                 const char *suffix;
+                char *p;
 
                 suffix = signal_to_string(d->int_val);
                 if (!suffix)
@@ -1764,12 +1764,12 @@ static const char *table_data_format(Table *t, TableData *d, bool avoid_uppercas
                 if (!p)
                         return NULL;
 
-                d->formatted = TAKE_PTR(p);
+                d->formatted = p;
                 break;
         }
 
         case TABLE_MODE: {
-                _cleanup_free_ char *p = NULL;
+                char *p;
 
                 if (d->mode == MODE_INVALID)
                         return "n/a";
@@ -1779,7 +1779,7 @@ static const char *table_data_format(Table *t, TableData *d, bool avoid_uppercas
                         return NULL;
 
                 sprintf(p, "%04o", d->mode & 07777);
-                d->formatted = TAKE_PTR(p);
+                d->formatted = p;
                 break;
         }
 
diff --git a/src/test/test-pretty-print.c b/src/test/test-pretty-print.c
index 4620d39bb6..17d21ed109 100644
--- a/src/test/test-pretty-print.c
+++ b/src/test/test-pretty-print.c
@@ -34,7 +34,7 @@ static void test_cat_files(void) {
 static void test_red_green_cross_check_mark(void) {
         bool b = false;
 
-        printf("yeah: <%s>\n", GREEN_CHECK_MARK());
+        printf("yea: <%s>\n", GREEN_CHECK_MARK());
         printf("nay: <%s>\n", RED_CROSS_MARK());
 
         printf("%s → %s → %s → %s\n",