Merge pull request #29004 from poettering/measure-log

tpm2: whenever we measure, also write a tpm log record

src/boot/pcrphase.c

@@ -241,6 +241,7 @@ static int get_file_system_word(
 
 static int run(int argc, char *argv[]) {
         _cleanup_free_ char *joined = NULL, *word = NULL;
+        Tpm2UserspaceEventType event;
         unsigned target_pcr_nr;
         size_t length;
         int r;
@@ -291,6 +292,7 @@ static int run(int argc, char *argv[]) {
                 }
 
                 target_pcr_nr = TPM2_PCR_SYSTEM_IDENTITY; /* → PCR 15 */
+                event = TPM2_EVENT_FILESYSTEM;
 
         } else if (arg_machine_id) {
                 sd_id128_t mid;
@@ -307,6 +309,7 @@ static int run(int argc, char *argv[]) {
                         return log_oom();
 
                 target_pcr_nr = TPM2_PCR_SYSTEM_IDENTITY; /* → PCR 15 */
+                event = TPM2_EVENT_MACHINE_ID;
 
         } else {
                 if (optind+1 != argc)
@@ -323,6 +326,7 @@ static int run(int argc, char *argv[]) {
                         return log_error_errno(SYNTHETIC_ERRNO(EINVAL), "String to measure cannot be empty, refusing.");
 
                 target_pcr_nr = TPM2_PCR_KERNEL_BOOT; /* → PCR 11 */
+                event = TPM2_EVENT_PHASE;
         }
 
         if (arg_graceful && tpm2_support() != TPM2_SUPPORT_FULL) {
@@ -358,7 +362,7 @@ static int run(int argc, char *argv[]) {
 
         log_debug("Measuring '%s' into PCR index %u, banks %s.", word, target_pcr_nr, joined);
 
-        r = tpm2_extend_bytes(c, arg_banks, target_pcr_nr, word, length, NULL, 0);
+        r = tpm2_extend_bytes(c, arg_banks, target_pcr_nr, word, length, NULL, 0, event, word);
         if (r < 0)
                 return r;
 

src/cryptsetup/cryptsetup.c

@@ -862,7 +862,7 @@ static int measure_volume_key(
         if (!s)
                 return log_oom();
 
-        r = tpm2_extend_bytes(c, l ?: arg_tpm2_measure_banks, arg_tpm2_measure_pcr, s, SIZE_MAX, volume_key, volume_key_size);
+        r = tpm2_extend_bytes(c, l ?: arg_tpm2_measure_banks, arg_tpm2_measure_pcr, s, SIZE_MAX, volume_key, volume_key_size, TPM2_EVENT_VOLUME_KEY, s);
         if (r < 0)
                 return r;
 

src/shared/tpm2-util.c

@@ -1,5 +1,7 @@
 /* SPDX-License-Identifier: LGPL-2.1-or-later */
 
+#include <sys/file.h>
+
 #include "alloc-util.h"
 #include "constants.h"
 #include "cryptsetup-util.h"
@@ -14,10 +16,12 @@
 #include "hexdecoct.h"
 #include "hmac.h"
 #include "initrd-util.h"
+#include "io-util.h"
 #include "lock-util.h"
 #include "log.h"
 #include "logarithm.h"
 #include "memory-util.h"
+#include "mkdir.h"
 #include "nulstr-util.h"
 #include "parse-util.h"
 #include "random-util.h"
@@ -25,6 +29,7 @@
 #include "sort-util.h"
 #include "stat-util.h"
 #include "string-table.h"
+#include "sync-util.h"
 #include "time-util.h"
 #include "tpm2-util.h"
 #include "virt.h"
@@ -4293,6 +4298,159 @@ int tpm2_find_device_auto(
 }
 
 #if HAVE_TPM2
+static const char* tpm2_userspace_event_type_table[_TPM2_USERSPACE_EVENT_TYPE_MAX] = {
+        [TPM2_EVENT_PHASE]      = "phase",
+        [TPM2_EVENT_FILESYSTEM] = "filesystem",
+        [TPM2_EVENT_VOLUME_KEY] = "volume-key",
+        [TPM2_EVENT_MACHINE_ID] = "machine-id",
+};
+
+DEFINE_STRING_TABLE_LOOKUP(tpm2_userspace_event_type, Tpm2UserspaceEventType);
+
+const char *tpm2_userspace_log_path(void) {
+        return secure_getenv("SYSTEMD_MEASURE_LOG_USERSPACE") ?: "/var/log/systemd/tpm2-measure.log";
+}
+
+static int tpm2_userspace_log_open(void) {
+        _cleanup_close_ int fd = -EBADF;
+        struct stat st;
+        const char *e;
+        int r;
+
+        e = tpm2_userspace_log_path();
+        (void) mkdir_parents(e, 0755);
+
+        /* We use access mode 0600 here (even though the measurements should not strictly be confidential),
+         * because we use BSD file locking on it, and if anyone but root can access the file they can also
+         * lock it, which we want to avoid. */
+        fd = open(e, O_CREAT|O_WRONLY|O_CLOEXEC|O_NOCTTY|O_NOFOLLOW, 0600);
+        if (fd < 0)
+                return log_warning_errno(errno, "Failed to open TPM log file '%s' for writing, ignoring: %m", e);
+
+        if (flock(fd, LOCK_EX) < 0)
+                return log_warning_errno(errno, "Failed to lock TPM log file '%s', ignoring: %m", e);
+
+        if (fstat(fd, &st) < 0)
+                return log_warning_errno(errno, "Failed to fstat TPM log file '%s', ignoring: %m", e);
+
+        r = stat_verify_regular(&st);
+        if (r < 0)
+                return log_warning_errno(r, "TPM log file '%s' is not regular, ignoring: %m", e);
+
+        /* We set the sticky bit when we are about to append to the log file. We'll unset it afterwards
+         * again. If we manage to take a lock on a file that has it set we know we didn't write it fully and
+         * it is corrupted. Ideally we'd like to use user xattrs for this, but unfortunately tmpfs (which is
+         * our assumed backend fs) doesn't know user xattrs. */
+        if (st.st_mode & S_ISVTX)
+                return log_warning_errno(SYNTHETIC_ERRNO(ESTALE), "TPM log file '%s' aborted, ignoring.", e);
+
+        if (fchmod(fd, 0600 | S_ISVTX) < 0)
+                return log_warning_errno(errno, "Failed to chmod() TPM log file '%s', ignoring: %m", e);
+
+        return TAKE_FD(fd);
+}
+
+static int tpm2_userspace_log(
+                int fd,
+                unsigned pcr_index,
+                const TPML_DIGEST_VALUES *values,
+                Tpm2UserspaceEventType event_type,
+                const char *description) {
+
+        _cleanup_(json_variant_unrefp) JsonVariant *v = NULL, *array = NULL;
+        _cleanup_free_ char *f = NULL;
+        sd_id128_t boot_id;
+        int r;
+
+        assert(values);
+        assert(values->count > 0);
+
+        /* We maintain a local PCR measurement log. This implements a subset of the TCG Canonical Event Log
+         * Format – the JSON flavour –
+         * (https://trustedcomputinggroup.org/resource/canonical-event-log-format/), but departs in certain
+         * ways from it, specifically:
+         *
+         * - We don't write out a recnum. It's a bit too vaguely defined which means we'd have to read
+         *   through the whole logs (include firmware logs) before knowing what the next value is we should
+         *   use. Hence we simply don't write this out as append-time, and instead expect a consumer to add
+         *   it in when it uses the data.
+         *
+         * - We write this out in RFC 7464 application/json-seq rather than as a JSON array. Writing this as
+         *   JSON array would mean that for each appending we'd have to read the whole log file fully into
+         *   memory before writing it out again. We prefer a strictly append-only write pattern however. (RFC
+         *   7464 is what jq --seq eats.) Conversion into a proper JSON array is trivial.
+         *
+         * It should be possible to convert this format in a relatively straight-forward way into the
+         * official TCG Canonical Event Log Format on read, by simply adding in a few more fields that can be
+         * determined from the full dataset.
+         *
+         * We set the 'content_type' field to "systemd" to make clear this data is generated by us, and
+         * include various interesting fields in the 'content' subobject, including a CLOCK_BOOTTIME
+         * timestamp which can be used to order this measurement against possibly other measurements
+         * independently done by other subsystems on the system.
+         */
+
+        if (fd < 0) /* Apparently tpm2_local_log_open() failed earlier, let's not complain again */
+                return 0;
+
+        for (size_t i = 0; i < values->count; i++) {
+                const EVP_MD *implementation;
+                const char *a;
+
+                assert_se(a = tpm2_hash_alg_to_string(values->digests[i].hashAlg));
+                assert_se(implementation = EVP_get_digestbyname(a));
+
+                r = json_variant_append_arrayb(
+                                &array, JSON_BUILD_OBJECT(
+                                                JSON_BUILD_PAIR_STRING("hashAlg", a),
+                                                JSON_BUILD_PAIR("digest", JSON_BUILD_HEX(&values->digests[i].digest, EVP_MD_size(implementation)))));
+                if (r < 0)
+                        return log_error_errno(r, "Failed to append digest object to JSON array: %m");
+        }
+
+        assert(array);
+
+        r = sd_id128_get_boot(&boot_id);
+        if (r < 0)
+                return log_error_errno(r, "Failed to acquire boot ID: %m");
+
+        r = json_build(&v, JSON_BUILD_OBJECT(
+                                       JSON_BUILD_PAIR("pcr", JSON_BUILD_UNSIGNED(pcr_index)),
+                                       JSON_BUILD_PAIR("digests", JSON_BUILD_VARIANT(array)),
+                                       JSON_BUILD_PAIR("content_type", JSON_BUILD_STRING("systemd")),
+                                       JSON_BUILD_PAIR("content", JSON_BUILD_OBJECT(
+                                                                       JSON_BUILD_PAIR_CONDITION(description, "string", JSON_BUILD_STRING(description)),
+                                                                       JSON_BUILD_PAIR("bootId", JSON_BUILD_ID128(boot_id)),
+                                                                       JSON_BUILD_PAIR("timestamp", JSON_BUILD_UNSIGNED(now(CLOCK_BOOTTIME))),
+                                                                       JSON_BUILD_PAIR_CONDITION(event_type >= 0, "eventType", JSON_BUILD_STRING(tpm2_userspace_event_type_to_string(event_type)))))));
+        if (r < 0)
+                return log_error_errno(r, "Failed to build log record JSON: %m");
+
+        r = json_variant_format(v, JSON_FORMAT_SEQ, &f);
+        if (r < 0)
+                return log_error_errno(r, "Failed to format JSON: %m");
+
+        if (lseek(fd, 0, SEEK_END) == (off_t) -1)
+                return log_error_errno(errno, "Failed to seek to end of JSON log: %m");
+
+        r = loop_write(fd, f, SIZE_MAX, /* do_poll= */ false);
+        if (r < 0)
+                return log_error_errno(r, "Failed to write JSON data to log: %m");
+
+        if (fsync(fd) < 0)
+                return log_error_errno(errno, "Failed to sync JSON data: %m");
+
+        /* Unset S_ISVTX again */
+        if (fchmod(fd, 0600) < 0)
+                return log_warning_errno(errno, "Failed to chmod() TPM log file, ignoring: %m");
+
+        r = fsync_full(fd);
+        if (r < 0)
+                return log_error_errno(r, "Failed to sync JSON log: %m");
+
+        return 1;
+}
+
 int tpm2_extend_bytes(
                 Tpm2Context *c,
                 char **banks,
@@ -4300,9 +4458,12 @@ int tpm2_extend_bytes(
                 const void *data,
                 size_t data_size,
                 const void *secret,
-                size_t secret_size) {
+                size_t secret_size,
+                Tpm2UserspaceEventType event_type,
+                const char *description) {
 
 #if HAVE_OPENSSL
+        _cleanup_close_ int log_fd = -EBADF;
         TPML_DIGEST_VALUES values = {};
         TSS2_RC rc;
 
@@ -4354,6 +4515,10 @@ int tpm2_extend_bytes(
                 values.count++;
         }
 
+        /* Open + lock the log file *before* we start measuring, so that noone else can come between our log
+         * and our measurement and change either */
+        log_fd = tpm2_userspace_log_open();
+
         rc = sym_Esys_PCR_Extend(
                         c->esys_context,
                         ESYS_TR_PCR0 + pcr_index,
@@ -4368,6 +4533,9 @@ int tpm2_extend_bytes(
                                 pcr_index,
                                 sym_Tss2_RC_Decode(rc));
 
+        /* Now, write what we just extended to the log, too. */
+        (void) tpm2_userspace_log(log_fd, pcr_index, &values, event_type, description);
+
         return 0;
 #else /* HAVE_OPENSSL */
         return log_error_errno(SYNTHETIC_ERRNO(EOPNOTSUPP), "OpenSSL support is disabled.");

src/shared/tpm2-util.h

@@ -112,7 +112,21 @@ int tpm2_get_good_pcr_banks(Tpm2Context *c, uint32_t pcr_mask, TPMI_ALG_HASH **r
 int tpm2_get_good_pcr_banks_strv(Tpm2Context *c, uint32_t pcr_mask, char ***ret);
 int tpm2_get_best_pcr_bank(Tpm2Context *c, uint32_t pcr_mask, TPMI_ALG_HASH *ret);
 
-int tpm2_extend_bytes(Tpm2Context *c, char **banks, unsigned pcr_index, const void *data, size_t data_size, const void *secret, size_t secret_size);
+const char *tpm2_userspace_log_path(void);
+
+typedef enum Tpm2UserspaceEventType {
+        TPM2_EVENT_PHASE,
+        TPM2_EVENT_FILESYSTEM,
+        TPM2_EVENT_VOLUME_KEY,
+        TPM2_EVENT_MACHINE_ID,
+        _TPM2_USERSPACE_EVENT_TYPE_MAX,
+        _TPM2_USERSPACE_EVENT_TYPE_INVALID = -EINVAL,
+} Tpm2UserspaceEventType;
+
+const char* tpm2_userspace_event_type_to_string(Tpm2UserspaceEventType type) _const_;
+Tpm2UserspaceEventType tpm2_userspace_event_type_from_string(const char *s) _pure_;
+
+int tpm2_extend_bytes(Tpm2Context *c, char **banks, unsigned pcr_index, const void *data, size_t data_size, const void *secret, size_t secret_size, Tpm2UserspaceEventType event, const char *description);
 
 uint32_t tpm2_tpms_pcr_selection_to_mask(const TPMS_PCR_SELECTION *s);
 void tpm2_tpms_pcr_selection_from_mask(uint32_t mask, TPMI_ALG_HASH hash, TPMS_PCR_SELECTION *ret);

test/units/testsuite-70.sh

@@ -264,6 +264,10 @@ if [[ -x "$SD_PCRPHASE" ]] && tpm_has_pcr sha256 11 && tpm_has_pcr sha256 15; th
 
     rm -f /tmp/oldpcr15 /tmp/newpcr15
 
+    # Check that the event log record was properly written:
+    test "$(jq --seq --slurp '.[0].pcr' < /var/log/systemd/tpm2-measure.log)" == "$(printf '\x1e15')"
+    test "$(jq --seq --slurp --raw-output '.[0].digests[1].digest' < /var/log/systemd/tpm2-measure.log) *stdin" == "$(echo -n "machine-id:994013bf23864ee7992eab39a96dd3bb" | openssl dgst -hex -sha256 -r)"
+
     # And similar for the boot phase measurement into PCR 11
     tpm2_pcrread sha256:11 -Q -o /tmp/oldpcr11
     SYSTEMD_FORCE_MEASURE=1 "$SD_PCRPHASE" foobar
@@ -272,6 +276,12 @@ if [[ -x "$SD_PCRPHASE" ]] && tpm_has_pcr sha256 11 && tpm_has_pcr sha256 15; th
     diff /tmp/newpcr11 \
         <(cat /tmp/oldpcr11 <(echo -n "foobar" | openssl dgst -binary -sha256) | openssl dgst -binary -sha256)
 
+    # Check the event log for the 2nd record
+    jq --seq --slurp < /var/log/systemd/tpm2-measure.log
+
+    test "$(jq --seq --slurp .[1].pcr < /var/log/systemd/tpm2-measure.log)" == "$(printf '\x1e11')"
+    test "$(jq --seq --slurp --raw-output .[1].digests[0].digest < /var/log/systemd/tpm2-measure.log) *stdin" == "$(echo -n "foobar" | openssl dgst -hex -sha256 -r)"
+
     rm -f /tmp/oldpcr11 /tmp/newpcr11
 else
     echo "$SD_PCRPHASE or PCR sysfs files not found, skipping PCR extension test case"