patch for UEFI debugging; as-is, makes page faults disappear

uefi-debugging.patch

commit 1347a7d0a5bbd05ae0b57b7fa2e20e7699b3d632
Author: Jessica Hamilton <[email protected]>
Date:   Sat Dec 10 22:34:26 2016 +1300

    debugging: uefi page faults disappear with debug added >_<

diff --git a/build/jam/ArchitectureRules b/build/jam/ArchitectureRules
index 03a6f3b..7346ec1 100644
--- a/build/jam/ArchitectureRules
+++ b/build/jam/ArchitectureRules
@@ -655,7 +655,7 @@ rule ArchitectureSetupWarnings architecture
 	EnableWerror src bin pkgman ;
 	EnableWerror src libs bsd ;
 	EnableWerror src apps ;
-	EnableWerror src kits ;
+#	EnableWerror src kits ;
 	EnableWerror src preferences ;
 	EnableWerror src servers ;
 	EnableWerror src system boot ;
diff --git a/src/kits/app/Roster.cpp b/src/kits/app/Roster.cpp
index 1f0e98f..faa99ed 100644
--- a/src/kits/app/Roster.cpp
+++ b/src/kits/app/Roster.cpp
@@ -54,8 +54,8 @@ using namespace BPrivate;
 
 
 // debugging
-//#define DBG(x) x
-#define DBG(x)
+#define DBG(x) x
+//#define DBG(x)
 #ifdef DEBUG_PRINTF
 #	define OUT DEBUG_PRINTF
 #else
diff --git a/src/system/kernel/debug/user_debugger.cpp b/src/system/kernel/debug/user_debugger.cpp
index fb8fa5f..95a2bb8 100644
--- a/src/system/kernel/debug/user_debugger.cpp
+++ b/src/system/kernel/debug/user_debugger.cpp
@@ -817,6 +817,7 @@ thread_hit_serious_debug_event(debug_debugger_message event,
 		Thread *thread = thread_get_current_thread();
 		dprintf("thread_hit_serious_debug_event(): Failed to install debugger: "
 			"thread: %" B_PRId32 ": %s\n", thread->id, strerror(error));
+		kernel_debugger("userland debugger failed; entering kernel debugger");
 		return error;
 	}
 
diff --git a/src/system/kernel/main.cpp b/src/system/kernel/main.cpp
index f3a0a9b..5b26942 100644
--- a/src/system/kernel/main.cpp
+++ b/src/system/kernel/main.cpp
@@ -128,6 +128,78 @@ _start(kernel_args *bootKernelArgs, int currentCPU)
 		dprintf("Welcome to kernel debugger output!\n");
 		dprintf("Haiku revision: %s\n", get_haiku_revision());
 
+		// dump the kernel args
+		dprintf("kernel args:\n");
+		dprintf("  size: %" B_PRIu32 "\n", sKernelArgs.kernel_args_size);
+		dprintf("  version: %" B_PRIu32 "\n", sKernelArgs.version);
+		dprintf("  kernel image (addr): %p\n", sKernelArgs.kernel_image.Pointer());
+		dprintf("  preloaded images (addr): %p\n", sKernelArgs.preloaded_images.Pointer());
+		dprintf("  physical memory ranges:\n");
+		for (unsigned int i = 0; i < sKernelArgs.num_physical_memory_ranges; ++i) {
+			dprintf("    start: 0x%" B_PRIx64 "\n", sKernelArgs.physical_memory_range[i].start);
+			dprintf("     size: 0x%" B_PRIx64 "\n", sKernelArgs.physical_memory_range[i].size);
+		}
+		dprintf("  physical allocated memory ranges:\n");
+		for (unsigned int i = 0; i < sKernelArgs.num_physical_allocated_ranges; ++i) {
+			dprintf("    start: 0x%" B_PRIx64 "\n", sKernelArgs.physical_allocated_range[i].start);
+			dprintf("     size: 0x%" B_PRIx64 "\n", sKernelArgs.physical_allocated_range[i].size);
+		}
+		dprintf("  virtual allocated memory ranges:\n");
+		for (unsigned int i = 0; i < sKernelArgs.num_virtual_allocated_ranges; ++i) {
+			dprintf("    start: 0x%" B_PRIx64 "\n", sKernelArgs.virtual_allocated_range[i].start);
+			dprintf("     size: 0x%" B_PRIx64 "\n", sKernelArgs.virtual_allocated_range[i].size);
+		}
+		dprintf("  kernel args memory ranges:\n");
+		for (unsigned int i = 0; i < sKernelArgs.num_kernel_args_ranges; ++i) {
+			dprintf("    start: 0x%" B_PRIx64 "\n", sKernelArgs.kernel_args_range[i].start);
+			dprintf("     size: 0x%" B_PRIx64 "\n", sKernelArgs.kernel_args_range[i].size);
+		}
+		dprintf("  ignored physical memory: 0x%" B_PRIx64 "\n", sKernelArgs.ignored_physical_memory);
+		dprintf("  total CPUs: %" B_PRIu32 "\n", sKernelArgs.num_cpus);
+		dprintf("  CPU kernel stacks:\n");
+		for (unsigned int i = 0; i < sKernelArgs.num_cpus; ++i) {
+			dprintf("    start: 0x%" B_PRIx64 "\n", sKernelArgs.cpu_kstack[i].start);
+			dprintf("     size: 0x%" B_PRIx64 "\n", sKernelArgs.cpu_kstack[i].size);
+		}
+		dprintf("  boot volume (addr): %p\n", sKernelArgs.boot_volume.Pointer());
+		dprintf("  boot volume size: %" B_PRId32 "\n", sKernelArgs.boot_volume_size);
+		dprintf("  driver settings (addr): %p\n", sKernelArgs.driver_settings.Pointer());
+		dprintf("  framebuffer settings:\n");
+		dprintf("    buffer start: 0x%" B_PRIx64 "\n", sKernelArgs.frame_buffer.physical_buffer.start);
+		dprintf("    buffer size:  0x%" B_PRIx64 "\n", sKernelArgs.frame_buffer.physical_buffer.size);
+		dprintf("    bytes per row: %" B_PRIu32 "\n", sKernelArgs.frame_buffer.bytes_per_row);
+		dprintf("    mode: %" B_PRIu16 "x%" B_PRIu16 "x%" B_PRIu8 "\n", sKernelArgs.frame_buffer.width, sKernelArgs.frame_buffer.height, sKernelArgs.frame_buffer.depth);
+		dprintf("    enabled: %s\n", sKernelArgs.frame_buffer.enabled ? "true" : "false");
+		dprintf("  debug output (addr): %p\n", sKernelArgs.debug_output.Pointer());
+		dprintf("  debug output size: %" B_PRIu32 "\n", sKernelArgs.debug_size);
+		dprintf("  previous debug output (addr) %p\n", sKernelArgs.previous_debug_output.Pointer());
+		dprintf("  previous debug output size: %" B_PRIu32 "\n", sKernelArgs.previous_debug_size);
+		dprintf("  keep debug output buffer: %s\n", sKernelArgs.keep_debug_output_buffer ? "true" : "false");
+		dprintf("arch kernel args:\n");
+		dprintf("  system time cv factor: %" B_PRIu32 "\n", sKernelArgs.arch_args.system_time_cv_factor);
+		dprintf("  cpu clock speed: %" B_PRIu64 "\n", sKernelArgs.arch_args.cpu_clock_speed);
+		dprintf("  page dir (phys): 0x%" B_PRIx32 "\n", sKernelArgs.arch_args.phys_pgdir);
+		dprintf("  page dir (virt): 0x%" B_PRIx64 "\n", sKernelArgs.arch_args.vir_pgdir);
+		dprintf("  number of page tables: %" B_PRIu32 "\n", sKernelArgs.arch_args.num_pgtables);
+		dprintf("  boot page tables:\n");
+		for (int i = 0; i < MAX_BOOT_PTABLES; ++i) {
+			dprintf("    page table: 0x%" B_PRIx32 "\n", sKernelArgs.arch_args.pgtables[i]);
+		}
+		dprintf("  virtual end: 0x%" B_PRIx64 "\n", sKernelArgs.arch_args.virtual_end);
+		dprintf("  page hole: %" B_PRIu64 "\n", sKernelArgs.arch_args.page_hole);
+		dprintf("  apic time cv factor: %" B_PRIu32 "\n", sKernelArgs.arch_args.apic_time_cv_factor);
+		dprintf("  apic (phys): 0x%" B_PRIx32 "\n", sKernelArgs.arch_args.apic_phys);
+		dprintf("  apic (virt): %p\n", sKernelArgs.arch_args.apic.Pointer());
+		dprintf("  ioapic (phys): 0x%" B_PRIx32 "\n", sKernelArgs.arch_args.ioapic_phys);
+		dprintf("  per-cpu apic:\n");
+		for (int i = 0; i < sKernelArgs.num_cpus; ++i) {
+			dprintf("    apic id: %" B_PRIu32 "\n", sKernelArgs.arch_args.cpu_apic_id[i]);
+			dprintf("    apic version: %" B_PRIu32 "\n", sKernelArgs.arch_args.cpu_apic_version[i]);
+		}
+		dprintf("  hpet (phys): 0x%" B_PRIx32 "\n", sKernelArgs.arch_args.hpet_phys);
+		dprintf("  hpet (virt): %p\n", sKernelArgs.arch_args.hpet.Pointer());
+		dprintf("  acpi root: %p\n", sKernelArgs.arch_args.acpi_root.Pointer());
+
 		// init modules
 		TRACE("init CPU\n");
 		cpu_init(&sKernelArgs);
diff --git a/src/system/libroot/os/image.cpp b/src/system/libroot/os/image.cpp
index b59a6d4..c2b50dc 100644
--- a/src/system/libroot/os/image.cpp
+++ b/src/system/libroot/os/image.cpp
@@ -8,6 +8,7 @@
 
 #include <stdlib.h>
 #include <string.h>
+#include <syslog.h>
 
 #include <algorithm>
 #include <new>
@@ -16,6 +17,7 @@
 
 #include <AutoDeleter.h>
 
+#include <debug.h>
 #include <libroot_private.h>
 #include <runtime_loader.h>
 #include <syscalls.h>
@@ -210,15 +212,22 @@ load_image(int32 argCount, const char **args, const char **environ)
 	if (argCount < 1 || environ == NULL)
 		return B_BAD_VALUE;
 
+	debug_printf("load_image:\n");
+	debug_printf("__gRuntimeLoader address: %p\n", __gRuntimeLoader);
+
 	// test validity of executable + support for scripts
 	{
+		debug_printf("calling __test_executable\n");
 		status_t status = __test_executable(args[0], invoker);
+		debug_printf("done\n");
 		if (status < B_OK)
 			return status;
 
 		if (invoker[0]) {
+			debug_printf("calling __parse_invoke_line\n");
 			status = __parse_invoke_line(invoker, &newArgs,
 				(char * const **)&args, &argCount, args[0]);
+			debug_printf("done\n");
 			if (status < B_OK)
 				return status;
 		}
@@ -230,18 +239,23 @@ load_image(int32 argCount, const char **args, const char **environ)
 
 	char** flatArgs = NULL;
 	size_t flatArgsSize;
+	debug_printf("calling __flatten_process_args\n");
 	status_t status = __flatten_process_args(args, argCount, environ,
 		&envCount, args[0], &flatArgs, &flatArgsSize);
+	debug_printf("done\n");
 
 	if (status == B_OK) {
+		debug_printf("calling _kern_load_image\n");
 		thread = _kern_load_image(flatArgs, flatArgsSize, argCount, envCount,
 			B_NORMAL_PRIORITY, B_WAIT_TILL_LOADED, -1, 0);
+		debug_printf("done\n");
 
 		free(flatArgs);
 	} else
 		thread = status;
 
 	free(newArgs);
+	debug_printf("leaving load_image\n");
 	return thread;
 }
 
@@ -252,6 +266,7 @@ load_add_on(char const *name)
 	if (name == NULL)
 		return B_BAD_VALUE;
 
+	debug_printf("=> load_add_on\n");
 	return __gRuntimeLoader->load_add_on(name, 0);
 }
 
@@ -259,6 +274,7 @@ load_add_on(char const *name)
 status_t
 unload_add_on(image_id id)
 {
+	debug_printf("=> unload_add_on\n");
 	return __gRuntimeLoader->unload_add_on(id);
 }
 
@@ -267,6 +283,7 @@ status_t
 get_image_symbol(image_id id, char const *symbolName, int32 symbolType,
 	void **_location)
 {
+	debug_printf("=> get_image_symbol\n");
 	return __gRuntimeLoader->get_image_symbol(id, symbolName, symbolType,
 		false, NULL, _location);
 }
@@ -276,6 +293,7 @@ status_t
 get_image_symbol_etc(image_id id, char const *symbolName, int32 symbolType,
 	bool recursive, image_id *_inImage, void **_location)
 {
+	debug_printf("=> get_image_symbol_etc\n");
 	return __gRuntimeLoader->get_image_symbol(id, symbolName, symbolType,
 		recursive, _inImage, _location);
 }
@@ -285,6 +303,7 @@ status_t
 get_nth_image_symbol(image_id id, int32 num, char *nameBuffer, int32 *_nameLength,
 	int32 *_symbolType, void **_location)
 {
+	debug_printf("=> get_nth_image_symbol\n");
 	return __gRuntimeLoader->get_nth_image_symbol(id, num, nameBuffer, _nameLength, _symbolType, _location);
 }
 
@@ -292,6 +311,7 @@ get_nth_image_symbol(image_id id, int32 num, char *nameBuffer, int32 *_nameLengt
 status_t
 _get_image_info(image_id id, image_info *info, size_t infoSize)
 {
+	debug_printf("called _kern_get_image_info\n");
 	return _kern_get_image_info(id, info, infoSize);
 }
 
@@ -299,6 +319,7 @@ _get_image_info(image_id id, image_info *info, size_t infoSize)
 status_t
 _get_next_image_info(team_id team, int32 *cookie, image_info *info, size_t infoSize)
 {
+	debug_printf("called _kern_get_next_image_info\n");
 	return _kern_get_next_image_info(team, cookie, info, infoSize);
 }
 
@@ -306,6 +327,7 @@ _get_next_image_info(team_id team, int32 *cookie, image_info *info, size_t infoS
 void
 clear_caches(void *address, size_t length, uint32 flags)
 {
+	debug_printf("called _kern_clear_caches\n");
 	_kern_clear_caches(address, length, flags);
 }
 
@@ -397,6 +419,7 @@ __parse_invoke_line(char *invoker, char ***_newArgs,
 status_t
 __get_next_image_dependency(image_id id, uint32 *cookie, const char **_name)
 {
+	debug_printf("=> __get_next_image_dependency\n");
 	return __gRuntimeLoader->get_next_image_dependency(id, cookie, _name);
 }
 
@@ -404,6 +427,9 @@ __get_next_image_dependency(image_id id, uint32 *cookie, const char **_name)
 status_t
 __test_executable(const char *path, char *invoker)
 {
+	debug_printf("=> __test_executable\n");
+	debug_printf("__gRuntimeLoader @ %p\n", __gRuntimeLoader);
+	debug_printf("__gRuntimeLoader->test_executable @ %p\n", __gRuntimeLoader->test_executable);
 	return __gRuntimeLoader->test_executable(path, invoker);
 }
 
diff --git a/src/system/runtime_loader/arch/x86_64/arch_relocate.cpp b/src/system/runtime_loader/arch/x86_64/arch_relocate.cpp
index fda4c27..24e81d9 100644
--- a/src/system/runtime_loader/arch/x86_64/arch_relocate.cpp
+++ b/src/system/runtime_loader/arch/x86_64/arch_relocate.cpp
@@ -30,8 +30,8 @@ relocate_rela(image_t* rootImage, image_t* image, Elf64_Rela* rel,
 			status_t status = resolve_symbol(rootImage, image, sym, cache,
 				&symAddr, &symbolImage);
 			if (status != B_OK) {
-				TRACE(("resolve symbol \"%s\" returned: %" B_PRId32 "\n",
-					SYMNAME(image, sym), status));
+				KTRACE("resolve symbol \"%s\" returned: %" B_PRId32 "\n",
+					SYMNAME(image, sym), status);
 				printf("resolve symbol \"%s\" returned: %" B_PRId32 "\n",
 					SYMNAME(image, sym), status);
 				return status;
@@ -66,7 +66,7 @@ relocate_rela(image_t* rootImage, image_t* image, Elf64_Rela* rel,
 				relocValue = symAddr;
 				break;
 			default:
-				TRACE(("unhandled relocation type %d\n", type));
+				KTRACE("unhandled relocation type %d\n", type);
 				return B_BAD_DATA;
 		}
 
diff --git a/src/system/runtime_loader/elf.cpp b/src/system/runtime_loader/elf.cpp
index 03b8bd1..bdfdef2 100644
--- a/src/system/runtime_loader/elf.cpp
+++ b/src/system/runtime_loader/elf.cpp
@@ -238,6 +238,7 @@ relocate_dependencies(image_t *image)
 static void
 init_dependencies(image_t *image, bool initHead)
 {
+	dprintf("enter init_dependencies\n");
 	image_t **initList;
 	ssize_t count, i;
 
@@ -251,11 +252,11 @@ init_dependencies(image_t *image, bool initHead)
 		initList[--count] = NULL;
 	}
 
-	TRACE(("%ld: init dependencies\n", find_thread(NULL)));
+	KTRACE("%d: init dependencies\n", find_thread(NULL));
 	for (i = 0; i < count; i++) {
 		image = initList[i];
 
-		TRACE(("%ld:  init: %s\n", find_thread(NULL), image->name));
+		KTRACE("%d:  init: %s\n", find_thread(NULL), image->name);
 
 		if (image->preinit_array) {
 			uint count_preinit = image->preinit_array_len / sizeof(addr_t);
@@ -272,9 +273,12 @@ init_dependencies(image_t *image, bool initHead)
 				((init_term_function)image->init_array[j])(image->id);
 		}
 
+		dprintf("&gRuntimeLoader @ %p\n", &gRuntimeLoader);
+		dprintf("test_executable @ %p\n", gRuntimeLoader.test_executable);
+
 		image_event(image, IMAGE_EVENT_INITIALIZED);
 	}
-	TRACE(("%ld:  init done.\n", find_thread(NULL)));
+	KTRACE("%d:  init done.\n", find_thread(NULL));
 
 	free(initList);
 }
@@ -285,12 +289,18 @@ inject_runtime_loader_api(image_t* rootImage)
 {
 	// We patch any exported __gRuntimeLoader symbols to point to our private
 	// API.
+	dprintf("runtime_loader: inject API\n");
 	image_t* image;
 	void* _export;
 	if (find_symbol_breadth_first(rootImage,
 			SymbolLookupInfo("__gRuntimeLoader", B_SYMBOL_TYPE_DATA), &image,
 			&_export) == B_OK) {
+		dprintf("found __gRuntimeLoader symbol @ %p\n", _export);
+		dprintf("&gRuntimeLoader = %p\n", &gRuntimeLoader);
+		dprintf("address of test_executable: %p\n", gRuntimeLoader.test_executable);
 		*(void**)_export = &gRuntimeLoader;
+	} else {
+		dprintf("couldn't find the runtime_loader API\n");
 	}
 }
 
@@ -1027,11 +1037,11 @@ terminate_program(void)
 		update_image_ids();
 	}
 
-	TRACE(("%ld: terminate dependencies\n", find_thread(NULL)));
+	KTRACE("%d: terminate dependencies\n", find_thread(NULL));
 	for (i = count; i-- > 0;) {
 		image_t *image = termList[i];
 
-		TRACE(("%ld:  term: %s\n", find_thread(NULL), image->name));
+		KTRACE("%d:  term: %s\n", find_thread(NULL), image->name);
 
 		image_event(image, IMAGE_EVENT_UNINITIALIZING);
 
@@ -1046,7 +1056,7 @@ terminate_program(void)
 
 		image_event(image, IMAGE_EVENT_UNLOADING);
 	}
-	TRACE(("%ld:  term done.\n", find_thread(NULL)));
+	KTRACE("%d:  term done.\n", find_thread(NULL));
 
 	free(termList);
 }
diff --git a/src/system/runtime_loader/runtime_loader.cpp b/src/system/runtime_loader/runtime_loader.cpp
index 6b31845..abfa75f 100644
--- a/src/system/runtime_loader/runtime_loader.cpp
+++ b/src/system/runtime_loader/runtime_loader.cpp
@@ -212,7 +212,7 @@ try_open_executable(const char *dir, int dirLength, const char *name,
 		strcpy(path + dirLength + 1, name);
 	}
 
-	TRACE(("runtime_loader: try_open_container(): %s\n", path));
+	KTRACE("runtime_loader: try_open_container(): %s\n", path);
 
 	// Test if the target is a symbolic link, and correct the path in this case
 
@@ -251,8 +251,8 @@ search_executable_in_path_list(const char *name, const char *pathList,
 	const char *pathListEnd = pathList + pathListLen;
 	status_t status = B_ENTRY_NOT_FOUND;
 
-	TRACE(("runtime_loader: search_container_in_path_list() %s in %.*s\n", name,
-		pathListLen, pathList));
+	KTRACE("runtime_loader: search_container_in_path_list() %s in %.*s\n", name,
+		pathListLen, pathList);
 
 	while (pathListLen > 0) {
 		const char *pathEnd = pathList;
diff --git a/src/system/runtime_loader/runtime_loader_private.h b/src/system/runtime_loader/runtime_loader_private.h
index be40233..94a808f 100644
--- a/src/system/runtime_loader/runtime_loader_private.h
+++ b/src/system/runtime_loader/runtime_loader_private.h
@@ -24,6 +24,8 @@
 #endif
 
 
+#undef RUNTIME_LOADER_TRACING
+#define RUNTIME_LOADER_TRACING 1
 #if RUNTIME_LOADER_TRACING
 #	define KTRACE(x...)	ktrace_printf(x)
 #else