attester: add RA_PERF performance measurement logging

README-j.md

@@ -807,5 +807,17 @@ optee_remote_attestation --key-hex <BlackKey hex> --pubx-hex <PubX hex> --puby-h
 
 期待される結果: `"ear.status": "affirming"`
 
+## 性能計測ログ (RA_PERF)
+
+アテステーション処理全体の時間と主要イベント(メモリハッシュ、CBOR/COSE
+エンコード、ECDSA/CAAM 署名、ブラックキー処理)ごとの所要時間を、機械可読な
+ログ(`RA_PERF|<layer>|<event>|<duration_us>|key=<keymode>`)として出力でき
+ます。ファームウェア側は `CFG_REMOTE_ATTESTATION_PERF=y` でコンパイルし、
+クライアント側は実行時に `optee_remote_attestation --perf`(データ収集用に
+`--loop N` / `--no-server` も利用可)で有効化します。ログポイント一覧、
+QEMU/i.MX での有効化手順、CAAM ブラックキー使用有無の比較を含む推奨計測
+プロトコルは [docs/performance-measurement-j.md](docs/performance-measurement-j.md)
+を参照してください。
+
 ## 謝辞
 研究は、JST、CREST、JPMJCR21M3 ([Zero Trust IoT プロジェクト](https://zt-iot.nii.ac.jp/)) の支援を受けたものです。

README.md

@@ -868,6 +868,18 @@ optee_remote_attestation --key-hex <BlackKey hex> --pubx-hex <PubX hex> --puby-h
 
 Expected result: `"ear.status": "affirming"`
 
+## Performance Measurement Logging (RA_PERF)
+
+The attestation stack can emit machine-parsable timing logs
+(`RA_PERF|<layer>|<event>|<duration_us>|key=<keymode>`) covering the total
+attestation time and each major event (memory hashing, CBOR/COSE encoding,
+ECDSA/CAAM signing, black-key processing). The firmware side is compiled in
+with `CFG_REMOTE_ATTESTATION_PERF=y`; the client side is enabled at runtime
+with `optee_remote_attestation --perf` (plus `--loop N` / `--no-server` for
+data collection). See [docs/performance-measurement.md](docs/performance-measurement.md)
+for the log-point list, how to enable it on QEMU/i.MX, and the recommended
+measurement protocol including the CAAM black-key on/off comparison.
+
 ## Acknowlegement
 
 This work was supported by JST, CREST Grant Number JPMJCR21M3 ([ZeroTrust IoT Project](https://zt-iot.nii.ac.jp/en/)), Japan.

attester/container-imx/meta-veraison-attestation/recipes-security/optee/optee-os_%.imx.bbappend

@@ -8,6 +8,16 @@ PTA_EXTERNAL_SRC ?= "/attester/pta_remote_attestation"
 # Enable the custom remote_attestation PTA
 EXTRA_OEMAKE:append = " CFG_REMOTE_ATTESTATION_PTA=y"
 
+# Performance measurement logging. Enable from local.conf with:
+#   CFG_REMOTE_ATTESTATION_PERF:pn-optee-os = "y"
+#   CFG_REMOTE_ATTESTATION_PERF:pn-veraison-attestation = "y"
+# CFG_TEE_CORE_LOG_LEVEL must be raised together with the flag because
+# meta-freescale's optee-os-common-fslc-imx.inc forces it to 0 (all core
+# trace compiled out, RA_PERF lines included); this append is parsed after
+# the .inc, so the later assignment wins on the make command line.
+CFG_REMOTE_ATTESTATION_PERF ?= "n"
+EXTRA_OEMAKE:append = "${@' CFG_REMOTE_ATTESTATION_PERF=y CFG_TEE_CORE_LOG_LEVEL=2' if d.getVar('CFG_REMOTE_ATTESTATION_PERF') == 'y' else ''}"
+
 # Copy PTA source to OP-TEE OS source tree before compile
 do_configure:append() {
     # Create PTA directory in OP-TEE OS source
@@ -32,6 +42,8 @@ do_configure:append() {
     cp ${PTA_SRC}/hash.h ${S}/core/pta/remote_attestation/
     cp ${PTA_SRC}/sign.c ${S}/core/pta/remote_attestation/
     cp ${PTA_SRC}/sign.h ${S}/core/pta/remote_attestation/
+    cp ${PTA_SRC}/perf.c ${S}/core/pta/remote_attestation/
+    cp ${PTA_SRC}/perf.h ${S}/core/pta/remote_attestation/
     cp ${PTA_SRC}/base64.c ${S}/core/pta/remote_attestation/
     cp ${PTA_SRC}/base64.h ${S}/core/pta/remote_attestation/
     cp ${PTA_SRC}/ocotp.c ${S}/core/pta/remote_attestation/

attester/container-imx/meta-veraison-attestation/recipes-security/veraison-attestation/veraison-attestation_1.0.bb

@@ -22,6 +22,10 @@ S = "${WORKDIR}/src"
 TA_DEV_KIT_DIR = "${STAGING_INCDIR}/optee/export-user_ta"
 TEEC_EXPORT = "${STAGING_DIR_HOST}${prefix}"
 
+# Performance measurement logging in the TA (set "y" in local.conf, together
+# with the optee-os flag; see optee-os_%.imx.bbappend)
+CFG_REMOTE_ATTESTATION_PERF ?= "n"
+
 # Rust configuration - rust-apiclient FFI library
 CARGO_SRC_DIR = "${S}/host/rust-ffi/coserv-rs"
 CARGO_MANIFEST_PATH = "${S}/host/rust-ffi/coserv-rs/Cargo.toml"
@@ -95,7 +99,8 @@ do_compile() {
     oe_runmake V=1 \
         TA_DEV_KIT_DIR=${TA_DEV_KIT_DIR} \
         CROSS_COMPILE=${HOST_PREFIX} \
-        LIBGCC_LOCATE_CFLAGS="--sysroot=${STAGING_DIR_HOST}"
+        LIBGCC_LOCATE_CFLAGS="--sysroot=${STAGING_DIR_HOST}" \
+        CFG_REMOTE_ATTESTATION_PERF=${CFG_REMOTE_ATTESTATION_PERF}
 
     # Build host application
     cd ${S}/host

attester/pta_remote_attestation/remote_attestation/perf.c

@@ -0,0 +1,66 @@
+#include "perf.h"
+
+#include <inttypes.h>
+#include <trace.h>
+
+#define RA_PERF_MAX_EVENTS 16
+
+struct ra_perf_event {
+    const char *event;
+    const char *keymode;
+    uint64_t ticks;
+};
+
+/*
+ * Simple per-command event buffer. Measurement runs are expected to be
+ * sequential (one attestation client at a time); concurrent PTA invocations
+ * would interleave their events.
+ */
+static struct ra_perf_event ra_perf_events[RA_PERF_MAX_EVENTS];
+static size_t ra_perf_num_events;
+
+void ra_perf_reset(void)
+{
+    ra_perf_num_events = 0;
+}
+
+void ra_perf_record(const char *event, uint64_t start_ticks,
+                    uint64_t end_ticks, const char *keymode)
+{
+    struct ra_perf_event *e = NULL;
+
+    if (ra_perf_num_events >= RA_PERF_MAX_EVENTS)
+        return;
+
+    e = &ra_perf_events[ra_perf_num_events++];
+    e->event = event;
+    e->keymode = keymode;
+    e->ticks = end_ticks - start_ticks;
+}
+
+void ra_perf_flush(void)
+{
+    uint32_t freq = read_cntfrq();
+    uint64_t flush_start = ra_perf_now();
+    size_t i = 0;
+
+    /* Report the counter frequency once so tick math can be verified */
+    IMSG("RA_PERF|pta|cntfrq|%" PRIu32 "|key=-", freq);
+
+    for (i = 0; i < ra_perf_num_events; i++) {
+        struct ra_perf_event *e = &ra_perf_events[i];
+        uint64_t us = e->ticks * 1000000ULL / freq;
+
+        IMSG("RA_PERF|pta|%s|%" PRIu64 "|key=%s", e->event, us, e->keymode);
+    }
+    ra_perf_num_events = 0;
+
+    /*
+     * Console writes are synchronous, so this flush is visible in the
+     * brackets measured by the layers above (TA pta_invoke, host
+     * evidence_get). Report its own cost so it can be subtracted; only
+     * the final line below remains unaccounted for.
+     */
+    IMSG("RA_PERF|pta|perf_flush|%" PRIu64 "|key=-",
+         (ra_perf_now() - flush_start) * 1000000ULL / freq);
+}

attester/pta_remote_attestation/remote_attestation/perf.h

@@ -0,0 +1,74 @@
+/*
+ * Performance measurement logging for the remote attestation PTA.
+ *
+ * Enabled with CFG_REMOTE_ATTESTATION_PERF=y. Durations are taken from the
+ * ARM generic timer (CNTPCT via barrier_read_counter_timer()) and reported
+ * in microseconds as:
+ *
+ *   RA_PERF|pta|<event>|<duration_us>|key=<embedded|plain|black|->
+ *
+ * Events are buffered with ra_perf_record() and emitted in one batch by
+ * ra_perf_flush(). Buffering matters: the secure console UART is synchronous
+ * and slow, so printing between two measured operations would inflate the
+ * later measurements.
+ */
+#ifndef PTA_REMOTE_ATTESTATION_PERF_H
+#define PTA_REMOTE_ATTESTATION_PERF_H
+
+#ifdef CFG_REMOTE_ATTESTATION_PERF
+
+#include <arm.h>
+#include <stddef.h>
+#include <stdint.h>
+
+static inline uint64_t ra_perf_now(void)
+{
+    return barrier_read_counter_timer();
+}
+
+/*
+ * Key-path label used to split measurement runs in the logs:
+ *   embedded = no external key, embedded test key
+ *   plain    = external plain private key (32 bytes)
+ *   black    = external serialized CAAM black key (> 32 bytes)
+ * Note: on i.MX with CFG_NXP_CAAM_ECC_DRV all three paths sign on CAAM
+ * hardware; "black" additionally pays blob decapsulation + CCM key import.
+ */
+static inline const char *ra_perf_keymode(const uint8_t *key, size_t key_len)
+{
+    if (!key || !key_len)
+        return "embedded";
+    return key_len > 32 ? "black" : "plain";
+}
+
+void ra_perf_reset(void);
+void ra_perf_record(const char *event, uint64_t start_ticks,
+                    uint64_t end_ticks, const char *keymode);
+void ra_perf_flush(void);
+
+#define RA_PERF_DECL(v) uint64_t v = 0
+#define RA_PERF_RESET() ra_perf_reset()
+#define RA_PERF_START(v) ((v) = ra_perf_now())
+#define RA_PERF_STOP(v, event, keymode) \
+    ra_perf_record((event), (v), ra_perf_now(), (keymode))
+#define RA_PERF_FLUSH() ra_perf_flush()
+
+#else /* CFG_REMOTE_ATTESTATION_PERF */
+
+#define RA_PERF_DECL(v)
+#define RA_PERF_RESET() \
+    do { \
+    } while (0)
+#define RA_PERF_START(v) \
+    do { \
+    } while (0)
+#define RA_PERF_STOP(v, event, keymode) \
+    do { \
+    } while (0)
+#define RA_PERF_FLUSH() \
+    do { \
+    } while (0)
+
+#endif /* CFG_REMOTE_ATTESTATION_PERF */
+
+#endif /* PTA_REMOTE_ATTESTATION_PERF_H */