Blob Blame History Raw
From fc4368fed53837e00d303600d8b628cb0392b629 Mon Sep 17 00:00:00 2001
From: Peter Jones <pjones@redhat.com>
Date: Thu, 23 Jul 2020 20:29:52 -0400
Subject: [PATCH 60/62] Improve debug output some

Signed-off-by: Peter Jones <pjones@redhat.com>
Upstream: pr#213
---
 errlog.c          |  26 ++++++-
 shim.c            |  36 ++++++++--
 include/console.h |   3 +
 include/hexdump.h | 172 ++++++++++++++++++++++++++++------------------
 shim.h            |   5 +-
 5 files changed, 164 insertions(+), 78 deletions(-)

diff --git a/errlog.c b/errlog.c
index 6669c800233..08f7a82a6b2 100644
--- a/errlog.c
+++ b/errlog.c
@@ -3,12 +3,28 @@
  * Copyright 2017 Peter Jones <pjones@redhat.com>
  */
 #include "shim.h"
+#include "hexdump.h"
 
 static CHAR16 **errs = NULL;
 static UINTN nerrs = 0;
 
 EFI_STATUS
-VLogError(const char *file, int line, const char *func, CHAR16 *fmt, va_list args)
+vdprint_(const CHAR16 *fmt, const char *file, int line, const char *func, va_list args)
+{
+	va_list args2;
+	EFI_STATUS efi_status = EFI_SUCCESS;
+
+	if (verbose) {
+		va_copy(args2, args);
+		console_print(L"%a:%d:%a() ", file, line, func);
+		efi_status = VPrint(fmt, args2);
+		va_end(args2);
+	}
+	return efi_status;
+}
+
+EFI_STATUS
+VLogError(const char *file, int line, const char *func, const CHAR16 *fmt, va_list args)
 {
 	va_list args2;
 	CHAR16 **newerrs;
@@ -35,7 +51,7 @@ VLogError(const char *file, int line, const char *func, CHAR16 *fmt, va_list arg
 }
 
 EFI_STATUS
-LogError_(const char *file, int line, const char *func, CHAR16 *fmt, ...)
+LogError_(const char *file, int line, const char *func, const CHAR16 *fmt, ...)
 {
 	va_list args;
 	EFI_STATUS efi_status;
@@ -47,6 +63,12 @@ LogError_(const char *file, int line, const char *func, CHAR16 *fmt, ...)
 	return efi_status;
 }
 
+VOID
+LogHexdump_(const char *file, int line, const char *func, const void *data, size_t sz)
+{
+	hexdumpat(file, line, func, data, sz, 0);
+}
+
 VOID
 PrintErrors(VOID)
 {
diff --git a/shim.c b/shim.c
index d10a1ba1cac..9248642bd57 100644
--- a/shim.c
+++ b/shim.c
@@ -34,6 +34,7 @@
  */
 
 #include "shim.h"
+#include "hexdump.h"
 #if defined(ENABLE_SHIM_CERT)
 #include "shim_cert.h"
 #endif /* defined(ENABLE_SHIM_CERT) */
@@ -373,12 +374,18 @@ static BOOLEAN verify_x509(UINT8 *Cert, UINTN CertSize)
 	 * and 64KB. For convenience, assume the number of value bytes
 	 * is 2, i.e. the second byte is 0x82.
 	 */
-	if (Cert[0] != 0x30 || Cert[1] != 0x82)
+	if (Cert[0] != 0x30 || Cert[1] != 0x82) {
+		dprint(L"cert[0:1] is [%02x%02x], should be [%02x%02x]\n",
+		       Cert[0], Cert[1], 0x30, 0x82);
 		return FALSE;
+	}
 
 	length = Cert[2]<<8 | Cert[3];
-	if (length != (CertSize - 4))
+	if (length != (CertSize - 4)) {
+		dprint(L"Cert length is %ld, expecting %ld\n",
+		       length, CertSize);
 		return FALSE;
+	}
 
 	return TRUE;
 }
@@ -426,19 +433,23 @@ static CHECK_STATUS check_db_cert_in_ram(EFI_SIGNATURE_LIST *CertList,
 	EFI_SIGNATURE_DATA *Cert;
 	UINTN CertSize;
 	BOOLEAN IsFound = FALSE;
+	int i = 0;
 
 	while ((dbsize > 0) && (dbsize >= CertList->SignatureListSize)) {
 		if (CompareGuid (&CertList->SignatureType, &EFI_CERT_TYPE_X509_GUID) == 0) {
 			Cert = (EFI_SIGNATURE_DATA *) ((UINT8 *) CertList + sizeof (EFI_SIGNATURE_LIST) + CertList->SignatureHeaderSize);
 			CertSize = CertList->SignatureSize - sizeof(EFI_GUID);
+			dprint(L"trying to verify cert %d (%s)\n", i++, dbname);
 			if (verify_x509(Cert->SignatureData, CertSize)) {
 				if (verify_eku(Cert->SignatureData, CertSize)) {
+					drain_openssl_errors();
 					IsFound = AuthenticodeVerify (data->CertData,
 								      data->Hdr.dwLength - sizeof(data->Hdr),
 								      Cert->SignatureData,
 								      CertSize,
 								      hash, SHA256_DIGEST_SIZE);
 					if (IsFound) {
+						dprint(L"AuthenticodeVerify() succeeded: %d\n", IsFound);
 						tpm_measure_variable(dbname, guid, CertSize, Cert->SignatureData);
 						drain_openssl_errors();
 						return DATA_FOUND;
@@ -447,7 +458,9 @@ static CHECK_STATUS check_db_cert_in_ram(EFI_SIGNATURE_LIST *CertList,
 					}
 				}
 			} else if (verbose) {
-				console_notify(L"Not a DER encoding x.509 Certificate");
+				console_print(L"Not a DER encoded x.509 Certificate");
+				dprint(L"cert:\n");
+				dhexdumpat(Cert->SignatureData, CertSize, 0);
 			}
 		}
 
@@ -641,7 +654,7 @@ static EFI_STATUS check_whitelist (WIN_CERTIFICATE_EFI_PKCS *cert,
 			verification_method = VERIFIED_BY_CERT;
 			update_verification_method(VERIFIED_BY_CERT);
 			return EFI_SUCCESS;
-		} else {
+		} else if (cert) {
 			LogError(L"check_db_cert(db, sha256hash) != DATA_FOUND\n");
 		}
 	}
@@ -666,7 +679,7 @@ static EFI_STATUS check_whitelist (WIN_CERTIFICATE_EFI_PKCS *cert,
 		verification_method = VERIFIED_BY_CERT;
 		update_verification_method(VERIFIED_BY_CERT);
 		return EFI_SUCCESS;
-	} else {
+	} else if (cert) {
 		LogError(L"check_db_cert(vendor_db, sha256hash) != DATA_FOUND\n");
 	}
 #endif
@@ -685,7 +698,7 @@ static EFI_STATUS check_whitelist (WIN_CERTIFICATE_EFI_PKCS *cert,
 		verification_method = VERIFIED_BY_CERT;
 		update_verification_method(VERIFIED_BY_CERT);
 		return EFI_SUCCESS;
-	} else {
+	} else if (cert) {
 		LogError(L"check_db_cert(MokList, sha256hash) != DATA_FOUND\n");
 	}
 
@@ -993,6 +1006,11 @@ static EFI_STATUS generate_hash (char *data, unsigned int datasize_in,
 		goto done;
 	}
 
+	dprint(L"sha1 authenticode hash:\n");
+	dhexdumpat(sha1hash, SHA1_DIGEST_SIZE, 0);
+	dprint(L"sha256 authenticode hash:\n");
+	dhexdumpat(sha256hash, SHA256_DIGEST_SIZE, 0);
+
 done:
 	if (SectionHeader)
 		FreePool(SectionHeader);
@@ -1155,6 +1173,7 @@ static EFI_STATUS verify_buffer (char *data, int datasize,
 	if (EFI_ERROR(ret_efi_status)) {
 		dprint(L"check_whitelist: %r\n", ret_efi_status);
 		if (ret_efi_status != EFI_NOT_FOUND) {
+			dprint(L"check_whitelist(): %r\n", ret_efi_status);
 			PrintErrors();
 			ClearErrors();
 			crypterr(ret_efi_status);
@@ -1803,6 +1822,7 @@ static EFI_STATUS load_image (EFI_LOADED_IMAGE *li, void **data,
 
 	device = li->DeviceHandle;
 
+	dprint(L"attempting to load %s\n", PathName);
 	/*
 	 * Open the device
 	 */
@@ -2778,6 +2798,10 @@ efi_main (EFI_HANDLE passed_image_handle, EFI_SYSTEM_TABLE *passed_systab)
 	 */
 	InitializeLib(image_handle, systab);
 
+	dprint(L"vendor_authorized:0x%08lx vendor_authorized_size:%lu\n",
+		      __FILE__, __LINE__, __func__, vendor_authorized, vendor_authorized_size);
+	dprint(L"vendor_deauthorized:0x%08lx vendor_deauthorized_size:%lu\n",
+		      __FILE__, __LINE__, __func__, vendor_deauthorized, vendor_deauthorized_size);
 	init_openssl();
 
 	/*
diff --git a/include/console.h b/include/console.h
index 810bf13a1f1..ac6fdf61d18 100644
--- a/include/console.h
+++ b/include/console.h
@@ -85,6 +85,9 @@ extern UINT32 verbose;
 		__dprint_ret;							\
 	})
 #define dprint(fmt, ...) dprint_(L"%a:%d:%a() " fmt, __FILE__, __LINE__, __func__, ##__VA_ARGS__)
+extern EFI_STATUS
+vdprint_(const CHAR16 *fmt, const char *file, int line, const char *func, va_list args);
+#define vdprint(fmt, ...) vdprint_(fmt, __FILE__, __LINE__, __func__, ##__VA_ARGS__)
 
 extern EFI_STATUS print_crypto_errors(EFI_STATUS rc, char *file, const char *func, int line);
 #define crypterr(rc) print_crypto_errors((rc), __FILE__, __func__, __LINE__)
diff --git a/include/hexdump.h b/include/hexdump.h
index d337b571d8d..f3f3ac284a3 100644
--- a/include/hexdump.h
+++ b/include/hexdump.h
@@ -1,104 +1,140 @@
 #ifndef STATIC_HEXDUMP_H
 #define STATIC_HEXDUMP_H
 
-static int
-__attribute__((__unused__))
-isprint(char c)
-{
-	if (c < 0x20)
-		return 0;
-	if (c > 0x7e)
-		return 0;
-	return 1;
-}
+#include <stdint.h>
 
-static UINTN
-__attribute__((__unused__))
-format_hex(UINT8 *data, UINTN size, CHAR16 *buf)
+static inline unsigned long UNUSED
+prepare_hex(const void *data, size_t size, char *buf, int position)
 {
-	UINTN sz = (UINTN)data % 16;
-	CHAR16 hexchars[] = L"0123456789abcdef";
+	char hexchars[] = "0123456789abcdef";
 	int offset = 0;
-	UINTN i;
-	UINTN j;
+	unsigned long i;
+	unsigned long j;
+	unsigned long ret;
 
-	for (i = 0; i < sz; i++) {
-		buf[offset++] = L' ';
-		buf[offset++] = L' ';
-		buf[offset++] = L' ';
+	unsigned long before = (position % 16);
+	unsigned long after = (before+size >= 16) ? 0 : 16 - (before+size);
+
+	for (i = 0; i < before; i++) {
+		buf[offset++] = 'X';
+		buf[offset++] = 'X';
+		buf[offset++] = ' ';
 		if (i == 7)
-			buf[offset++] = L' ';
+			buf[offset++] = ' ';
 	}
-	for (j = sz; j < 16 && j < size; j++) {
-		UINT8 d = data[j-sz];
+	for (j = 0; j < 16 - after - before; j++) {
+		uint8_t d = ((uint8_t *)data)[j];
 		buf[offset++] = hexchars[(d & 0xf0) >> 4];
 		buf[offset++] = hexchars[(d & 0x0f)];
-		if (j != 15)
-			buf[offset++] = L' ';
-		if (j == 7)
-			buf[offset++] = L' ';
+		if (i+j != 15)
+			buf[offset++] = ' ';
+		if (i+j == 7)
+			buf[offset++] = ' ';
 	}
-	for (i = j; i < 16; i++) {
-		buf[offset++] = L' ';
-		buf[offset++] = L' ';
-		if (i != 15)
-			buf[offset++] = L' ';
-		if (i == 7)
-			buf[offset++] = L' ';
+	ret = 16 - after - before;
+	j += i;
+	for (i = 0; i < after; i++) {
+		buf[offset++] = 'X';
+		buf[offset++] = 'X';
+		if (i+j != 15)
+			buf[offset++] = ' ';
+		if (i+j == 7)
+			buf[offset++] = ' ';
 	}
-	buf[offset] = L'\0';
-	return j - sz;
+	buf[offset] = '\0';
+	return ret;
 }
 
-static void
-__attribute__((__unused__))
-format_text(UINT8 *data, UINTN size, CHAR16 *buf)
+#define isprint(c) ((c) >= 0x20 && (c) <= 0x7e)
+
+static inline void UNUSED
+prepare_text(const void *data, size_t size, char *buf, int position)
 {
-	UINTN sz = (UINTN)data % 16;
 	int offset = 0;
-	UINTN i;
-	UINTN j;
+	unsigned long i;
+	unsigned long j;
 
-	for (i = 0; i < sz; i++)
-		buf[offset++] = L' ';
-	buf[offset++] = L'|';
-	for (j = sz; j < 16 && j < size; j++) {
-		if (isprint(data[j-sz]))
-			buf[offset++] = data[j-sz];
+	unsigned long before = position % 16;
+	unsigned long after = (before+size > 16) ? 0 : 16 - (before+size);
+
+	if (size == 0) {
+		buf[0] = '\0';
+		return;
+	}
+	for (i = 0; i < before; i++)
+		buf[offset++] = 'X';
+	buf[offset++] = '|';
+	for (j = 0; j < 16 - after - before; j++) {
+		if (isprint(((uint8_t *)data)[j]))
+			buf[offset++] = ((uint8_t *)data)[j];
 		else
-			buf[offset++] = L'.';
+			buf[offset++] = '.';
 	}
-	buf[offset++] = L'|';
-	for (i = j; i < 16; i++)
-		buf[offset++] = L' ';
-	buf[offset] = L'\0';
+	buf[offset++] = size > 0 ? '|' : 'X';
+	buf[offset] = '\0';
 }
 
-static void
-__attribute__((__unused__))
-hexdump(UINT8 *data, UINTN size)
+/*
+ * variadic hexdump formatted
+ * think of it as: printf("%s%s\n", vformat(fmt, ap), hexdump(data,size));
+ */
+static inline void UNUSED
+vhexdumpf(const char *file, int line, const char *func, const CHAR16 * const fmt, const void *data, unsigned long size, size_t at, va_list ap)
 {
-	UINTN display_offset = (UINTN)data & 0xffffffff;
-	UINTN offset = 0;
-	//console_print(L"hexdump: data=0x%016x size=0x%x\n", data, size);
+	unsigned long display_offset = at;
+	unsigned long offset = 0;
 
 	while (offset < size) {
-		CHAR16 hexbuf[49];
-		CHAR16 txtbuf[19];
-		UINTN sz;
+		char hexbuf[49];
+		char txtbuf[19];
+		unsigned long sz;
 
-		sz = format_hex(data+offset, size-offset, hexbuf);
+		sz = prepare_hex(data+offset, size-offset, hexbuf,
+				 (unsigned long)data+offset);
 		if (sz == 0)
 			return;
-		msleep(200000);
 
-		format_text(data+offset, size-offset, txtbuf);
-		console_print(L"%08x  %s  %s\n", display_offset, hexbuf, txtbuf);
-		msleep(200000);
+		prepare_text(data+offset, size-offset, txtbuf,
+			     (unsigned long)data+offset);
+		if (fmt && fmt[0] != 0)
+			vdprint_(fmt, file, line, func, ap);
+		dprint_(L"%a:%d:%a() %08lx  %a  %a\n", file, line, func, display_offset, hexbuf, txtbuf);
 
 		display_offset += sz;
 		offset += sz;
 	}
 }
 
+/*
+ * hexdump formatted
+ * think of it as: printf("%s%s", format(fmt, ...), hexdump(data,size)[lineN]);
+ */
+static inline void UNUSED
+hexdumpf(const char *file, int line, const char *func, const CHAR16 * const fmt, const void *data, unsigned long size, size_t at, ...)
+{
+	va_list ap;
+
+	va_start(ap, at);
+	vhexdumpf(file, line, func, fmt, data, size, at, ap);
+	va_end(ap);
+}
+
+static inline void UNUSED
+hexdump(const char *file, int line, const char *func, const void *data, unsigned long size)
+{
+	hexdumpf(file, line, func, L"", data, size, (intptr_t)data);
+}
+
+static inline void UNUSED
+hexdumpat(const char *file, int line, const char *func, const void *data, unsigned long size, size_t at)
+{
+	hexdumpf(file, line, func, L"", data, size, at);
+}
+
+#define LogHexdump(data, sz) LogHexdump_(__FILE__, __LINE__, __func__, data, sz)
+#define dhexdump(data, sz) hexdump(__FILE__, __LINE__, __func__, data, sz)
+#define dhexdumpat(data, sz, at) hexdumpat(__FILE__, __LINE__, __func__, data, sz, at)
+#define dhexdumpf(fmt, data, sz, at, ...) hexdumpf(__FILE__, __LINE__, __func__, fmt, data, sz, at, ##__VA_ARGS__)
+
 #endif /* STATIC_HEXDUMP_H */
+// vim:fenc=utf-8:tw=75:noet
diff --git a/shim.h b/shim.h
index c1d7e7c7197..0b3ad4f2d20 100644
--- a/shim.h
+++ b/shim.h
@@ -182,8 +182,9 @@ typedef struct _SHIM_LOCK {
 
 extern EFI_STATUS shim_init(void);
 extern void shim_fini(void);
-extern EFI_STATUS LogError_(const char *file, int line, const char *func, CHAR16 *fmt, ...);
-extern EFI_STATUS VLogError(const char *file, int line, const char *func, CHAR16 *fmt, va_list args);
+extern EFI_STATUS LogError_(const char *file, int line, const char *func, const CHAR16 *fmt, ...);
+extern EFI_STATUS VLogError(const char *file, int line, const char *func, const CHAR16 *fmt, va_list args);
+extern VOID LogHexdump_(const char *file, int line, const char *func, const void *data, size_t sz);
 extern VOID PrintErrors(VOID);
 extern VOID ClearErrors(VOID);
 extern EFI_STATUS start_image(EFI_HANDLE image_handle, CHAR16 *ImagePath);
-- 
2.26.2