From f41e1a7b1f705209affe151ef466636456f9a5fa Mon Sep 17 00:00:00 2001 From: Hans-Kristian Arntzen Date: Mon, 3 Jul 2023 17:54:40 +0200 Subject: [PATCH 1/3] vkd3d: Flush debug log after sensitive crashes. We really need to make sure we get everything in the log. The important information might be hidden in the buffer. Especially relevant for indirect trace debug where we need buffered logs to keep FPS above fractional values. Signed-off-by: Hans-Kristian Arntzen --- include/private/vkd3d_debug.h | 1 + libs/vkd3d-common/debug.c | 36 ++++++++++++++++++++++++++++++----- libs/vkd3d/breadcrumbs.c | 1 + libs/vkd3d/debug_ring.c | 1 + 4 files changed, 34 insertions(+), 5 deletions(-) diff --git a/include/private/vkd3d_debug.h b/include/private/vkd3d_debug.h index 4010d04b96..70a7e05517 100644 --- a/include/private/vkd3d_debug.h +++ b/include/private/vkd3d_debug.h @@ -69,6 +69,7 @@ enum vkd3d_dbg_level vkd3d_dbg_get_level(enum vkd3d_dbg_channel channel); void vkd3d_dbg_printf(enum vkd3d_dbg_channel channel, enum vkd3d_dbg_level level, const char *function, const char *fmt, ...) VKD3D_PRINTF_FUNC(4, 5); +void vkd3d_dbg_flush(void); const char *vkd3d_dbg_sprintf(const char *fmt, ...) VKD3D_PRINTF_FUNC(1, 2); const char *vkd3d_dbg_vsprintf(const char *fmt, va_list args); diff --git a/libs/vkd3d-common/debug.c b/libs/vkd3d-common/debug.c index 23e84537b8..68c61388bc 100644 --- a/libs/vkd3d-common/debug.c +++ b/libs/vkd3d-common/debug.c @@ -146,9 +146,35 @@ enum vkd3d_dbg_level vkd3d_dbg_get_level(enum vkd3d_dbg_channel channel) return vkd3d_dbg_level[channel]; } +static spinlock_t vkd3d_debug_buffer_spin; + +void vkd3d_dbg_flush(void) +{ + if (vkd3d_dbg_buffer.buffer) + { + spinlock_acquire(&vkd3d_debug_buffer_spin); + if (vkd3d_dbg_buffer.offset) + { + if (vkd3d_log_file) + { + fwrite(vkd3d_dbg_buffer.buffer, 1, vkd3d_dbg_buffer.offset, vkd3d_log_file); + } + else + { + /* Binary vs text matters on Win32. + * Don't bother trying to be clever here reopening stdio files as O_BINARY, etc. */ + fputs(vkd3d_dbg_buffer.buffer, stderr); + } + + vkd3d_dbg_buffer.offset = 0; + fflush(vkd3d_log_file ? vkd3d_log_file : stderr); + } + spinlock_release(&vkd3d_debug_buffer_spin); + } +} + void vkd3d_dbg_printf(enum vkd3d_dbg_channel channel, enum vkd3d_dbg_level level, const char *function, const char *fmt, ...) { - static spinlock_t spin; unsigned int tid; FILE *log_file; va_list args; @@ -175,7 +201,7 @@ void vkd3d_dbg_printf(enum vkd3d_dbg_channel channel, enum vkd3d_dbg_level level local_buffer_count = vsnprintf(local_buffer, sizeof(local_buffer), fmt, args); required_count = prefix_buffer_count + local_buffer_count; - spinlock_acquire(&spin); + spinlock_acquire(&vkd3d_debug_buffer_spin); if (vkd3d_dbg_buffer.offset + required_count > vkd3d_dbg_buffer.size) { if (vkd3d_log_file) @@ -206,7 +232,7 @@ void vkd3d_dbg_printf(enum vkd3d_dbg_channel channel, enum vkd3d_dbg_level level fputs(prefix_buffer, log_file); fputs(local_buffer, log_file); } - spinlock_release(&spin); + spinlock_release(&vkd3d_debug_buffer_spin); } #ifdef _WIN32 else if (wine_log_output) @@ -228,10 +254,10 @@ void vkd3d_dbg_printf(enum vkd3d_dbg_channel channel, enum vkd3d_dbg_level level #endif else { - spinlock_acquire(&spin); + spinlock_acquire(&vkd3d_debug_buffer_spin); fprintf(log_file, "%04x:%s:%s: ", tid, debug_level_names[level], function); vfprintf(log_file, fmt, args); - spinlock_release(&spin); + spinlock_release(&vkd3d_debug_buffer_spin); fflush(log_file); } va_end(args); diff --git a/libs/vkd3d/breadcrumbs.c b/libs/vkd3d/breadcrumbs.c index 4b44a8a0d4..0afae23a24 100644 --- a/libs/vkd3d/breadcrumbs.c +++ b/libs/vkd3d/breadcrumbs.c @@ -598,6 +598,7 @@ void vkd3d_breadcrumb_tracer_report_device_lost(struct vkd3d_breadcrumb_tracer * } ERR("Done analyzing breadcrumbs ...\n"); + vkd3d_dbg_flush(); pthread_mutex_unlock(&global_report_lock); } diff --git a/libs/vkd3d/debug_ring.c b/libs/vkd3d/debug_ring.c index d09bdef74f..d78a964aa0 100644 --- a/libs/vkd3d/debug_ring.c +++ b/libs/vkd3d/debug_ring.c @@ -350,6 +350,7 @@ void *vkd3d_shader_debug_ring_thread_main(void *arg) } } INFO("Done fishing for clues ...\n"); + vkd3d_dbg_flush(); } return NULL; From 07d8c2d2cc699d73701d6521dc6e7782f8041a3a Mon Sep 17 00:00:00 2001 From: Hans-Kristian Arntzen Date: Thu, 13 Jul 2023 16:09:07 +0200 Subject: [PATCH 2/3] vkd3d: Use sysmem for breadcrumb + debug ring on NV. Signed-off-by: Hans-Kristian Arntzen --- libs/vkd3d/debug_ring.c | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/libs/vkd3d/debug_ring.c b/libs/vkd3d/debug_ring.c index d78a964aa0..56ca7da962 100644 --- a/libs/vkd3d/debug_ring.c +++ b/libs/vkd3d/debug_ring.c @@ -438,7 +438,17 @@ HRESULT vkd3d_shader_debug_ring_init(struct vkd3d_shader_debug_ring *ring, * We use coherent in the debug_channel.h header, but not necessarily guaranteed to be coherent with * host reads, so make extra sure. */ if (device->device_info.device_coherent_memory_features_amd.deviceCoherentMemory) + { memory_props |= VK_MEMORY_PROPERTY_DEVICE_UNCACHED_BIT_AMD | VK_MEMORY_PROPERTY_DEVICE_COHERENT_BIT_AMD; + } + else if (device->device_info.vulkan_1_2_properties.driverID == VK_DRIVER_ID_NVIDIA_PROPRIETARY) + { + /* Writes to sysmem seem to be coherent, but not ReBAR. Very slow, but hey, + * we're desperate when we're doing breadcrumb + debug ring! */ + memory_props = VK_MEMORY_PROPERTY_HOST_VISIBLE_BIT | + VK_MEMORY_PROPERTY_HOST_CACHED_BIT | + VK_MEMORY_PROPERTY_HOST_COHERENT_BIT; + } } if (FAILED(vkd3d_allocate_internal_buffer_memory(device, ring->device_atomic_buffer, From 088dbf56815ae230a4420935936aa98dd12f3d9e Mon Sep 17 00:00:00 2001 From: Hans-Kristian Arntzen Date: Thu, 13 Jul 2023 16:42:23 +0200 Subject: [PATCH 3/3] debug: Ensure that MSG_UNIFORM is completed before we unblock wave. Signed-off-by: Hans-Kristian Arntzen --- include/shader-debug/debug_channel.h | 12 ++++++++++++ 1 file changed, 12 insertions(+) diff --git a/include/shader-debug/debug_channel.h b/include/shader-debug/debug_channel.h index aa54fa76fe..9b21263fa5 100644 --- a/include/shader-debug/debug_channel.h +++ b/include/shader-debug/debug_channel.h @@ -267,72 +267,84 @@ void DEBUG_CHANNEL_MSG_UNIFORM(uint v0) { if (DEBUG_CHANNEL_ELECT()) DEBUG_CHANNEL_MSG(v0); + subgroupBarrier(); } void DEBUG_CHANNEL_MSG_UNIFORM(uint v0, uint v1) { if (DEBUG_CHANNEL_ELECT()) DEBUG_CHANNEL_MSG(v0, v1); + subgroupBarrier(); } void DEBUG_CHANNEL_MSG_UNIFORM(uint v0, uint v1, uint v2) { if (DEBUG_CHANNEL_ELECT()) DEBUG_CHANNEL_MSG(v0, v1, v2); + subgroupBarrier(); } void DEBUG_CHANNEL_MSG_UNIFORM(uint v0, uint v1, uint v2, uint v3) { if (DEBUG_CHANNEL_ELECT()) DEBUG_CHANNEL_MSG(v0, v1, v2, v3); + subgroupBarrier(); } void DEBUG_CHANNEL_MSG_UNIFORM(int v0) { if (DEBUG_CHANNEL_ELECT()) DEBUG_CHANNEL_MSG(v0); + subgroupBarrier(); } void DEBUG_CHANNEL_MSG_UNIFORM(int v0, int v1) { if (DEBUG_CHANNEL_ELECT()) DEBUG_CHANNEL_MSG(v0, v1); + subgroupBarrier(); } void DEBUG_CHANNEL_MSG_UNIFORM(int v0, int v1, int v2) { if (DEBUG_CHANNEL_ELECT()) DEBUG_CHANNEL_MSG(v0, v1, v2); + subgroupBarrier(); } void DEBUG_CHANNEL_MSG_UNIFORM(int v0, int v1, int v2, int v3) { if (DEBUG_CHANNEL_ELECT()) DEBUG_CHANNEL_MSG(v0, v1, v2, v3); + subgroupBarrier(); } void DEBUG_CHANNEL_MSG_UNIFORM(float v0) { if (DEBUG_CHANNEL_ELECT()) DEBUG_CHANNEL_MSG(v0); + subgroupBarrier(); } void DEBUG_CHANNEL_MSG_UNIFORM(float v0, float v1) { if (DEBUG_CHANNEL_ELECT()) DEBUG_CHANNEL_MSG(v0, v1); + subgroupBarrier(); } void DEBUG_CHANNEL_MSG_UNIFORM(float v0, float v1, float v2) { if (DEBUG_CHANNEL_ELECT()) DEBUG_CHANNEL_MSG(v0, v1, v2); + subgroupBarrier(); } void DEBUG_CHANNEL_MSG_UNIFORM(float v0, float v1, float v2, float v3) { if (DEBUG_CHANNEL_ELECT()) DEBUG_CHANNEL_MSG(v0, v1, v2, v3); + subgroupBarrier(); } #endif