vk: associate more logs with modules

ref/vk/vk_framectl.c

@@ -11,7 +11,6 @@
 #include "vk_staging.h"
 #include "vk_commandpool.h"
 #include "vk_combuf.h"
-#include "vk_logs.h"
 
 #include "profiler.h"
 #include "r_speeds.h"

ref/vk/vk_light.c

@@ -156,7 +156,7 @@ static struct {
 
 } g_lights_bsp = {0};
 
-static void loadRadData( const model_t *map, const char *fmt, ... ) {
+static qboolean loadRadData( const model_t *map, const char *fmt, ... ) {
 	fs_offset_t size;
 	char *data;
 	byte *buffer;
@@ -170,8 +170,8 @@ static void loadRadData( const model_t *map, const char *fmt, ... ) {
 	buffer = gEngine.fsapi->LoadFile( filename, &size, false);
 
 	if (!buffer) {
-		WARN("Couldn't load RAD data from file %s, the map will be completely black", filename);
-		return;
+		DEBUG("Couldn't load RAD data from file %s", filename);
+		return false;
 	}
 
 	DEBUG("Loading RAD data from file %s", filename);
@@ -277,6 +277,7 @@ static void loadRadData( const model_t *map, const char *fmt, ... ) {
 	}
 
 	Mem_Free(buffer);
+	return true;
 }
 
 static void leafAccumPrepare( void ) {
@@ -919,8 +920,10 @@ void RT_LightsLoadBegin( const struct model_s *map ) {
 			name_len -= 4;
 
 		memset(g_lights_.map.emissive_textures, 0, sizeof(g_lights_.map.emissive_textures));
-		loadRadData( map, "maps/lights.rad" );
-		loadRadData( map, "%.*s.rad", name_len, map->name );
+		const qboolean loaded = loadRadData( map, "maps/lights.rad" ) | loadRadData( map, "%.*s.rad", name_len, map->name );
+		if (!loaded) {
+			ERR("No RAD files loaded. The map will be completely black");
+		}
 	}
 
 	// Clear static lights counts

ref/vk/vk_logs.c

@@ -7,13 +7,15 @@ static const struct log_pair_t {
 	const char *name;
 	uint32_t bit;
 } g_log_module_pairs[] = {
-	{"vk", LogModule_Vulkan},
+	{"misc", LogModule_Misc},
 	{"tex", LogModule_Textures},
 	{"brush", LogModule_Brush},
 	{"light", LogModule_Lights},
 	{"studio", LogModule_Studio},
 	{"patch", LogModule_Patch},
 	{"mat", LogModule_Material},
+	{"meat", LogModule_Meatpipe},
+	{"rt", LogModule_RT},
 };
 
 void VK_LogsReadCvar(void) {

ref/vk/vk_logs.h

@@ -3,13 +3,15 @@
 #include "vk_common.h"
 
 enum {
-	LogModule_Vulkan = (1<<0),
+	LogModule_Misc = (1<<0),
 	LogModule_Textures = (1<<1),
 	LogModule_Brush = (1<<2),
 	LogModule_Lights = (1<<3),
 	LogModule_Studio = (1<<4),
 	LogModule_Patch = (1<<5),
 	LogModule_Material = (1<<6),
+	LogModule_Meatpipe = (1<<7),
+	LogModule_RT = (1<<8),
 };
 
 extern uint32_t g_log_debug_bits;

ref/vk/vk_meatpipe.c

@@ -5,6 +5,9 @@
 
 #include "ray_pass.h"
 #include "vk_common.h"
+#include "vk_logs.h"
+
+#define LOG_MODULE LogModule_Meatpipe
 
 #define MIN(a,b) ((a)<(b)?(a):(b))
 
@@ -47,13 +50,13 @@ const void* curReadPtr(cursor_t *cur, int size) {
 
 #define CUR_ERROR(errmsg, ...) \
 	if (ctx->cur.error) { \
-		gEngine.Con_Printf(S_ERROR "(off=%d left=%d) " errmsg "\n", ctx->cur.off, (ctx->cur.size - ctx->cur.off), ##__VA_ARGS__); \
+		ERR("(off=%d left=%d) " errmsg "", ctx->cur.off, (ctx->cur.size - ctx->cur.off), ##__VA_ARGS__); \
 		goto finalize; \
 	}
 
 #define CUR_ERROR_RETURN(retval, errmsg, ...) \
 	if (ctx->cur.error) { \
-		gEngine.Con_Printf(S_ERROR "(off=%d left=%d) " errmsg "\n", ctx->cur.off, (ctx->cur.size - ctx->cur.off), ##__VA_ARGS__); \
+		ERR("(off=%d left=%d) " errmsg "", ctx->cur.off, (ctx->cur.size - ctx->cur.off), ##__VA_ARGS__); \
 		return retval; \
 	}
 
@@ -103,7 +106,7 @@ static struct ray_pass_s *pipelineLoadCompute(load_context_t *ctx, int i, const
 	const uint32_t shader_comp = READ_U32_RETURN(NULL, "Couldn't read comp shader for %d %s", i, name);
 
 	if (shader_comp >= ctx->shaders_count) {
-		gEngine.Con_Printf(S_ERROR "Pipeline %s shader index out of bounds %d (count %d)\n", name, shader_comp, ctx->shaders_count);
+		ERR("Pipeline %s shader index out of bounds %d (count %d)", name, shader_comp, ctx->shaders_count);
 		return NULL;
 	}
 
@@ -171,7 +174,7 @@ static qboolean readBindings(load_context_t *ctx, VkDescriptorSetLayoutBinding *
 	const int count = READ_U32("Coulnd't read bindings count");
 
 	if (count > MAX_BINDINGS) {
-		gEngine.Con_Printf(S_ERROR "Too many binding (%d), max: %d\n", count, MAX_BINDINGS);
+		ERR("Too many binding (%d), max: %d", count, MAX_BINDINGS);
 		goto finalize;
 	}
 
@@ -183,7 +186,7 @@ static qboolean readBindings(load_context_t *ctx, VkDescriptorSetLayoutBinding *
 		const uint32_t stages = READ_U32("Couldn't read stages for binding %d", i);
 
 		if (res_index >= ctx->meatpipe.resources_count) {
-			gEngine.Con_Printf(S_ERROR "Resource %d is out of bound %d for binding %d", res_index, ctx->meatpipe.resources_count, i);
+			ERR("Resource %d is out of bound %d for binding %d", res_index, ctx->meatpipe.resources_count, i);
 			goto finalize;
 		}
 
@@ -200,7 +203,7 @@ static qboolean readBindings(load_context_t *ctx, VkDescriptorSetLayoutBinding *
 			write_from = i;
 
 		if (!write && write_from >= 0) {
-			gEngine.Con_Printf(S_ERROR "Unsorted non-write binding found at %d(%s), writable started at %d\n",
+			ERR("Unsorted non-write binding found at %d(%s), writable started at %d",
 				i, res->name, write_from);
 			goto finalize;
 		}
@@ -223,7 +226,7 @@ static qboolean readBindings(load_context_t *ctx, VkDescriptorSetLayoutBinding *
 		if (create)
 			res->flags |= MEATPIPE_RES_CREATE;
 
-		gEngine.Con_Reportf("Binding %d: %s ds=%d b=%d s=%08x res=%d type=%d write=%d\n",
+		DEBUG("Binding %d: %s ds=%d b=%d s=%08x res=%d type=%d write=%d",
 			i, name, descriptor_set, binding, stages, res_index, res->descriptor_type, write);
 	}
 
@@ -254,10 +257,10 @@ static qboolean readAndCreatePass(load_context_t *ctx, int i) {
 	char name[64];
 	READ_STR(name, "Couldn't read pipeline %d name", i);
 
-	gEngine.Con_Reportf("%d: loading pipeline %s\n", i, name);
+	DEBUG("%d: loading pipeline %s", i, name);
 
 	if (!readBindings(ctx, bindings, pass)) {
-		gEngine.Con_Printf(S_ERROR "Couldn't read bindings for pipeline %s\n", name);
+		ERR("Couldn't read bindings for pipeline %s", name);
 		return false;
 	}
 
@@ -275,7 +278,7 @@ static qboolean readAndCreatePass(load_context_t *ctx, int i) {
 			pass->pass = pipelineLoadRT(ctx, i, name, &layout);
 			break;
 		default:
-			gEngine.Con_Printf(S_ERROR "Unexpected pipeline type %d\n", type);
+			ERR("Unexpected pipeline type %d", type);
 	}
 
 	if (pass->pass)
@@ -307,7 +310,7 @@ static qboolean readResources(load_context_t *ctx) {
 			res->prev_frame_index_plus_1 = READ_U32("Couldn't read resource %d:%s previous frame index", i, res->name);
 		}
 
-		gEngine.Con_Reportf("Resource %d:%s = %08x is_image=%d image_format=%08x count=%d\n",
+		DEBUG("Resource %d:%s = %08x is_image=%d image_format=%08x count=%d",
 			i, res->name, res->descriptor_type, is_image, res->image_format, res->count);
 	}
 
@@ -329,11 +332,11 @@ static qboolean readAndLoadShaders(load_context_t *ctx) {
 		const void *src = READ_PTR(size, "Couldn't read shader %s data", name);
 
 		if (VK_NULL_HANDLE == (ctx->shaders[i] = R_VkShaderLoadFromMem(src, size, name))) {
-			gEngine.Con_Printf(S_ERROR "Failed to load shader %d:%s\n", i, name);
+			ERR("Failed to load shader %d:%s", i, name);
 			goto finalize;
 		}
 
-		gEngine.Con_Reportf("%d: Shader loaded %s\n", i, name);
+		DEBUG("%d: Shader loaded %s", i, name);
 	}
 
 	return true;
@@ -347,7 +350,7 @@ vk_meatpipe_t* R_VkMeatpipeCreateFromFile(const char *filename) {
 	byte* const buf = gEngine.fsapi->LoadFile(filename, &size, false);
 
 	if (!buf) {
-		gEngine.Con_Printf(S_ERROR "Couldn't read \"%s\"\n", filename);
+		ERR("Couldn't read \"%s\"", filename);
 		return NULL;
 	}
 
@@ -363,7 +366,7 @@ vk_meatpipe_t* R_VkMeatpipeCreateFromFile(const char *filename) {
 		const uint32_t magic = READ_U32("Couldn't read magic");
 
 		if (magic != k_meatpipe_magic) {
-			gEngine.Con_Printf(S_ERROR "Meatpipe magic invalid for \"%s\": got %08x expected %08x\n", filename, magic, k_meatpipe_magic);
+			ERR("Meatpipe magic invalid for \"%s\": got %08x expected %08x", filename, magic, k_meatpipe_magic);
 			goto finalize;
 		}
 	}
@@ -391,6 +394,8 @@ vk_meatpipe_t* R_VkMeatpipeCreateFromFile(const char *filename) {
 	memcpy(ret, &ctx->meatpipe, sizeof(*ret));
 	ctx->meatpipe.resources = NULL;
 
+	INFO("Loaded meatpipe %s with %d passes and %d resources", filename, ret->passes_count, ret->resources_count);
+
 finalize:
 	for (int i = 0; i < ctx->shaders_count; ++i) {
 		if (ctx->shaders[i] == VK_NULL_HANDLE)

ref/vk/vk_ray_accel.c

@@ -9,12 +9,11 @@
 #include "vk_math.h"
 #include "vk_geometry.h"
 #include "vk_render.h"
+#include "vk_logs.h"
 
 #include "xash3d_mathlib.h"
 
-#ifndef ARRAYSIZE
-#define ARRAYSIZE(p)	(sizeof(p)/sizeof(p[0]))
-#endif // #ifndef ARRAYSIZE
+#define LOG_MODULE LogModule_RT
 
 #define MODULE_NAME "accel"
 
@@ -81,7 +80,7 @@ static VkAccelerationStructureKHR createAccel(const char *name, VkAccelerationSt
 	const alo_block_t block = aloPoolAllocate(g_accel.accels_buffer_alloc, size, /*TODO why? align=*/256);
 
 	if (block.offset == ALO_ALLOC_FAILED) {
-		gEngine.Con_Printf(S_ERROR "Failed to allocated %u bytes for blas \"%s\"\n", size, name);
+		ERR("Failed to allocated %u bytes for blas \"%s\"", size, name);
 		return VK_NULL_HANDLE;
 	}
 
@@ -123,13 +122,13 @@ static qboolean buildAccel(VkBuffer geometry_buffer, VkAccelerationStructureBuil
 			VK_PIPELINE_STAGE_TRANSFER_BIT,
 			//VK_PIPELINE_STAGE_ACCELERATION_STRUCTURE_BUILD_BIT_KHR,
 			VK_PIPELINE_STAGE_ACCELERATION_STRUCTURE_BUILD_BIT_KHR | VK_PIPELINE_STAGE_RAY_TRACING_SHADER_BIT_KHR,
-			0, 0, NULL, ARRAYSIZE(bmb), bmb, 0, NULL);
+			0, 0, NULL, COUNTOF(bmb), bmb, 0, NULL);
 	}
 
-	//gEngine.Con_Reportf("sratch offset = %d, req=%d\n", g_accel.frame.scratch_offset, scratch_buffer_size);
+	//gEngine.Con_Reportf("sratch offset = %d, req=%d", g_accel.frame.scratch_offset, scratch_buffer_size);
 
 	if (MAX_SCRATCH_BUFFER < g_accel.frame.scratch_offset + scratch_buffer_size) {
-		gEngine.Con_Printf(S_ERROR "Scratch buffer overflow: left %u bytes, but need %u\n",
+		ERR("Scratch buffer overflow: left %u bytes, but need %u",
 			MAX_SCRATCH_BUFFER - g_accel.frame.scratch_offset,
 			scratch_buffer_size);
 		return false;
@@ -141,7 +140,7 @@ static qboolean buildAccel(VkBuffer geometry_buffer, VkAccelerationStructureBuil
 	g_accel.frame.scratch_offset += scratch_buffer_size;
 	g_accel.frame.scratch_offset = ALIGN_UP(g_accel.frame.scratch_offset, vk_core.physical_device.properties_accel.minAccelerationStructureScratchOffsetAlignment);
 
-	//gEngine.Con_Reportf("AS=%p, n_geoms=%u, scratch: %#x %d %#x\n", *args->p_accel, args->n_geoms, scratch_offset_initial, scratch_buffer_size, scratch_offset_initial + scratch_buffer_size);
+	//gEngine.Con_Reportf("AS=%p, n_geoms=%u, scratch: %#x %d %#x", *args->p_accel, args->n_geoms, scratch_offset_initial, scratch_buffer_size, scratch_offset_initial + scratch_buffer_size);
 
 	g_accel.stats.accels_built++;
 
@@ -188,7 +187,7 @@ qboolean createOrUpdateAccelerationStructure(vk_combuf_t *combuf, const as_build
 		if (args->inout_size)
 			*args->inout_size = build_size.accelerationStructureSize;
 
-		// gEngine.Con_Reportf("AS=%p, n_geoms=%u, build: %#x %d %#x\n", *args->p_accel, args->n_geoms, buffer_offset, asci.size, buffer_offset + asci.size);
+		// gEngine.Con_Reportf("AS=%p, n_geoms=%u, build: %#x %d %#x", *args->p_accel, args->n_geoms, buffer_offset, asci.size, buffer_offset + asci.size);
 	}
 
 	// If not enough data for building, just create
@@ -343,7 +342,7 @@ vk_resource_t RT_VkAccelPrepareTlas(vk_combuf_t *combuf) {
 		vkCmdPipelineBarrier(combuf->cmdbuf,
 			VK_PIPELINE_STAGE_ACCELERATION_STRUCTURE_BUILD_BIT_KHR,
 			VK_PIPELINE_STAGE_RAY_TRACING_SHADER_BIT_KHR | VK_PIPELINE_STAGE_COMPUTE_SHADER_BIT,
-			0, 0, NULL, ARRAYSIZE(bmb), bmb, 0, NULL);
+			0, 0, NULL, COUNTOF(bmb), bmb, 0, NULL);
 	}
 
 	return (vk_resource_t){
@@ -490,14 +489,14 @@ qboolean RT_BlasPreallocate(struct rt_blas_s* blas, rt_blas_preallocate_t args)
 	};
 
 	const VkAccelerationStructureBuildSizesInfoKHR build_size = getAccelSizes(&build_info, max_prim_counts);
-	gEngine.Con_Reportf("geoms=%d max_prims=%d max_vertex=%d => blas=%dKiB\n",
+	DEBUG("geoms=%d max_prims=%d max_vertex=%d => blas=%dKiB",
 		args.max_geometries, args.max_prims_per_geometry, args.max_vertex_per_geometry, (int)build_size.accelerationStructureSize / 1024);
 
 	qboolean retval = false;
 
 	blas->blas = createAccel(blas->debug_name, VK_ACCELERATION_STRUCTURE_TYPE_BOTTOM_LEVEL_KHR, build_size.accelerationStructureSize);
 	if (!blas->blas) {
-		gEngine.Con_Printf(S_ERROR "Couldn't preallocate blas %s\n", blas->debug_name);
+		ERR("Couldn't preallocate blas %s", blas->debug_name);
 		goto finalize;
 	}
 
@@ -609,15 +608,15 @@ qboolean RT_BlasBuild(struct rt_blas_s *blas, const struct vk_render_geometry_s
 	if (!blas->blas) {
 		blas->blas = createAccel(blas->debug_name, VK_ACCELERATION_STRUCTURE_TYPE_BOTTOM_LEVEL_KHR, build_size.accelerationStructureSize);
 		if (!blas->blas) {
-			gEngine.Con_Printf(S_ERROR "Couldn't create vk accel\n");
+			ERR("Couldn't create vk accel");
 			goto finalize;
 		}
 
 		blas->blas_size = build_size.accelerationStructureSize;
 		blas->max_geoms = build_info.geometryCount;
 	} else {
 		if (blas->blas_size < build_size.accelerationStructureSize) {
-			gEngine.Con_Printf(S_ERROR "Fast dynamic BLAS %s size exceeded (need %dKiB, have %dKiB, geoms = %d)\n", blas->debug_name,
+			ERR("Fast dynamic BLAS %s size exceeded (need %dKiB, have %dKiB, geoms = %d)", blas->debug_name,
 				(int)build_size.accelerationStructureSize / 1024,
 				blas->blas_size / 1024,
 				geoms_count
@@ -629,7 +628,7 @@ qboolean RT_BlasBuild(struct rt_blas_s *blas, const struct vk_render_geometry_s
 	// Build
 	build_info.dstAccelerationStructure = blas->blas;
 	if (!buildAccel(geometry_buffer, &build_info, is_update ? build_size.updateScratchSize : build_size.buildScratchSize, build_ranges)) {
-		gEngine.Con_Printf(S_ERROR "Couldn't build BLAS %s\n", blas->debug_name);
+		ERR("Couldn't build BLAS %s", blas->debug_name);
 		goto finalize;
 	}
 

ref/vk/vk_rmain.c

@@ -112,17 +112,11 @@ static void R_InitSkyClouds( struct mip_s *mt, struct texture_s *tx, qboolean cu
 
 extern void GL_SubdivideSurface( msurface_t *fa );
 
-
-static void Mod_LoadAliasModel( model_t *mod, const void *buffer, qboolean *loaded )
-{
-	PRINT_NOT_IMPLEMENTED_ARGS("(%p, %s), %p, %d", mod, mod->name, buffer, *loaded);
-}
-
 static qboolean Mod_ProcessRenderData( model_t *mod, qboolean create, const byte *buffer )
 {
 	qboolean loaded = true;
 
-	gEngine.Con_Reportf("%s(%s, create=%d)\n", __FUNCTION__, mod->name, create);
+	//gEngine.Con_Reportf("%s(%s, create=%d)\n", __FUNCTION__, mod->name, create);
 
 	// TODO does this ever happen?
 	if (!create && mod->type == mod_brush)
@@ -141,7 +135,7 @@ static qboolean Mod_ProcessRenderData( model_t *mod, qboolean create, const byte
 				Mod_LoadSpriteModel( mod, buffer, &loaded, mod->numtexinfo );
 				break;
 			case mod_alias:
-				Mod_LoadAliasModel( mod, buffer, &loaded );
+				// TODO what ARE mod_alias? We just don't know.
 				break;
 			case mod_brush:
 				// This call happens before we get R_NewMap, which frees all current buffers