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