[debug] Add verbosity to narrow down Windows and alpine test failures

Author: droe

qemu/target/arm/pauth_helper.c

@@ -495,11 +495,17 @@ uint64_t HELPER(xpacd)(CPUARMState *env, uint64_t a)
 
 uint64_t _uc_pauth_sign(CPUARMState *env, uint64_t ptr, uint64_t diversifier, uint32_t sctlr_bit, ARMPACKey *key, bool data)
 {
+    printf("----- reached _uc_pauth_sign\n"); fflush(stdout);
     int el = arm_current_el(env);
+    printf("----- after obtaining el=%d\n", el); fflush(stdout);
     if (!pauth_key_enabled(env, el, sctlr_bit)) {
+        printf("----- key not enabled\n"); fflush(stdout);
         return ptr;
     } else {
-        return pauth_addpac(env, ptr, diversifier, key, data);
+        printf("----- key enabled\n"); fflush(stdout);
+        uint64_t res = pauth_addpac(env, ptr, diversifier, key, data);
+        printf("----- returned from pauth_addpac\n"); fflush(stdout);
+        return res;
     }
 }
 

qemu/target/arm/unicorn_aarch64.c

@@ -457,11 +457,19 @@ bool _uc_pauth_auth(CPUARMState *env, uint64_t ptr, uint64_t diversifier, uint32
 
 static uc_err arm64_pauth_sign(struct uc_struct *uc, uint64_t ptr, int key, uint64_t diversifier, uint64_t *signed_ptr)
 {
+    printf("---- reached arm64_pauth_sign\n"); fflush(stdout);
+    printf("arm64_pauth_sign: signed_ptr=%p\n", signed_ptr); fflush(stdout);
     CPUArchState *env = uc->cpu->env_ptr;
+    printf("---- obtained env ptr\n"); fflush(stdout);
     switch (key) {
-        case UC_ARM64_PAUTH_KEY_IA:
-            *signed_ptr = _uc_pauth_sign(env, ptr, diversifier, SCTLR_EnIA, &env->keys.apia, false);
+        case UC_ARM64_PAUTH_KEY_IA: {
+            printf("---- before calling _uc_pauth_sign\n"); fflush(stdout);
+            uint64_t res = _uc_pauth_sign(env, ptr, diversifier, SCTLR_EnIA, &env->keys.apia, false);
+            printf("---- after calling _uc_pauth_sign\n"); fflush(stdout);
+            *signed_ptr = res;
+            printf("---- after storing result\n"); fflush(stdout);
             break;
+        }
         case UC_ARM64_PAUTH_KEY_IB:
             *signed_ptr = _uc_pauth_sign(env, ptr, diversifier, SCTLR_EnIB, &env->keys.apib, false);
             break;

tests/unit/test_arm64.c

@@ -740,6 +740,11 @@ static bool test_arm64_pauth_cp_reg_update(uc_engine *uc, const uint32_t cpregid
     return (((reg.val & setmask) == setmask) && ((reg.val & clearmask) == 0));
 }
 
+#define DEBUG_CHECKPOINT(msg) { \
+    printf("--- " msg "\n");    \
+    fflush(stdout);             \
+}
+
 static void test_arm64_pauth_check_cpu_feat(uc_engine *uc)
 {
     // Check the CPU actually supports any form of PAuth, i.e. any APA or API
@@ -886,9 +891,14 @@ static void test_arm64_pauth_ctl(void)
     OK(uc_ctl_set_cpu_model(uc, UC_CPU_ARM64_MAX));
     OK(uc_mem_map(uc, code_start, code_len, UC_PROT_ALL));
 
+    printf("\n");
+    DEBUG_CHECKPOINT("uc created");
+
     test_arm64_pauth_check_cpu_feat(uc);
     test_arm64_pauth_setup(uc);
 
+    DEBUG_CHECKPOINT("setup complete");
+
     // Verify that paciza and uc_ctl_pauth_sign() result in the same signed
     // pointer.
 
@@ -900,35 +910,58 @@ static void test_arm64_pauth_ctl(void)
     TEST_CHECK(signed_pointer_paciza != some_unsigned_pointer);
     TEST_CHECK((signed_pointer_paciza & pac_mask) != 0);
 
+    DEBUG_CHECKPOINT("paciza done");
+
     uint64_t signed_pointer = 0;
+    printf("test_arm64_pauth: ptr=0x%016"PRIx64" key=%d diversifier=0x%016"PRIx64" signed_ptr=%p\n", some_unsigned_pointer, UC_ARM64_PAUTH_KEY_IA, 0ULL, &signed_pointer); fflush(stdout);
     OK(uc_ctl_pauth_sign(uc, some_unsigned_pointer, UC_ARM64_PAUTH_KEY_IA, 0, &signed_pointer));
     TEST_CHECK(signed_pointer == signed_pointer_paciza);
 
+    DEBUG_CHECKPOINT("uc_ctl_pauth_sign() returned");
+
     // Verify that stripping the PAC results in the original pointer.
 
     uint64_t stripped_pointer = 0;
     OK(uc_ctl_pauth_strip(uc, signed_pointer, UC_ARM64_PAUTH_KEY_IA, &stripped_pointer));
     TEST_CHECK(stripped_pointer == some_unsigned_pointer);
 
+    DEBUG_CHECKPOINT("uc_ctl_pauth_strip() returned");
+
     // Verify that authenticating works as expected.
 
     bool valid = true;
     OK(uc_ctl_pauth_auth(uc, some_unsigned_pointer, UC_ARM64_PAUTH_KEY_IA, 0, &valid));
     TEST_CHECK(!valid); // unsigned pointer
+
+    DEBUG_CHECKPOINT("uc_ctl_pauth_auth() returned once");
+
     valid = false;
     OK(uc_ctl_pauth_auth(uc, signed_pointer, UC_ARM64_PAUTH_KEY_IA, 0, &valid));
     TEST_CHECK(valid);  // signed pointer
+
+    DEBUG_CHECKPOINT("uc_ctl_pauth_auth() returned twice");
+
     valid = true;
     OK(uc_ctl_pauth_auth(uc, signed_pointer, UC_ARM64_PAUTH_KEY_IA, 1337, &valid));
     TEST_CHECK(!valid); // wrong diversifier
+
+    DEBUG_CHECKPOINT("uc_ctl_pauth_auth() returned thrice");
+
     valid = true;
     OK(uc_ctl_pauth_auth(uc, signed_pointer, UC_ARM64_PAUTH_KEY_IB, 0, &valid));
     TEST_CHECK(!valid); // wrong but enabled key
+
+    DEBUG_CHECKPOINT("uc_ctl_pauth_auth() returned four times");
+
     valid = true;
     OK(uc_ctl_pauth_auth(uc, signed_pointer, UC_ARM64_PAUTH_KEY_DA, 0, &valid));
     TEST_CHECK(!valid); // disabled but same value key
 
+    DEBUG_CHECKPOINT("uc_ctl_pauth_auth() returned five times");
+
     OK(uc_close(uc));
+
+    DEBUG_CHECKPOINT("uc closed");
 }
 
 TEST_LIST = {{"test_arm64_until", test_arm64_until},

uc.c

@@ -2987,6 +2987,7 @@ uc_err uc_ctl(uc_engine *uc, uc_control_type control, ...)
             uint64_t diversifier = va_arg(args, uint64_t);
             uint64_t *signed_ptr = va_arg(args, uint64_t *);
             if (uc->pauth_sign != NULL) {
+                printf("uc_ctl: ptr=0x%016"PRIx64" key=%d diversifier=0x%016"PRIx64" signed_ptr=%p\n", ptr, key, diversifier, signed_ptr); fflush(stdout);
                 err = uc->pauth_sign(uc, ptr, key, diversifier, signed_ptr);
             } else {
                 err = UC_ERR_ARG;