SpirvShader: Add a flag for printing SPIRV execution

src/Pipeline/BUILD.gn

@@ -24,6 +24,7 @@ swiftshader_source_set("Pipeline_headers") {
     "SetupRoutine.hpp",
     "ShaderCore.hpp",
     "SpirvShader.hpp",
+    "SpirvShaderDebug.hpp",
     "VertexProgram.hpp",
     "VertexRoutine.hpp",
   ]

src/Pipeline/ShaderCore.hpp

@@ -544,7 +544,19 @@ struct PrintValue::Ty<sw::Vector4s>
 		return PrintValue::vals(v.x, v.y, v.z, v.w);
 	}
 };
+template<>
+struct PrintValue::Ty<sw::SIMD::Pointer>
+{
+	static std::string fmt(const sw::SIMD::Pointer &v)
+	{
+		return "{" + PrintValue::fmt(v.base) + " +" + PrintValue::fmt(v.offsets()) + "}";
+	}
 
+	static std::vector<rr::Value *> val(const sw::SIMD::Pointer &v)
+	{
+		return PrintValue::vals(v.base, v.offsets());
+	}
+};
 }  // namespace rr
 #endif  // ENABLE_RR_PRINT
 

src/Pipeline/SpirvShader.cpp

@@ -13,6 +13,7 @@
 // limitations under the License.
 
 #include "SpirvShader.hpp"
+#include "SpirvShaderDebug.hpp"
 
 #include "System/Debug.hpp"
 #include "Vulkan/VkPipelineLayout.hpp"
@@ -1597,6 +1598,19 @@ SpirvShader::EmitResult SpirvShader::EmitInstruction(InsnIterator insn, EmitStat
 
 	auto opcode = insn.opcode();
 
+#if SPIRV_SHADER_ENABLE_DBG
+	{
+		auto text = spvtools::spvInstructionBinaryToText(
+		    SPV_ENV_VULKAN_1_1,
+		    insn.wordPointer(0),
+		    insn.wordCount(),
+		    insns.data(),
+		    insns.size(),
+		    SPV_BINARY_TO_TEXT_OPTION_NO_HEADER);
+		SPIRV_SHADER_DBG("{0}", text);
+	}
+#endif  // ENABLE_DBG_MSGS
+
 	switch(opcode)
 	{
 		case spv::OpTypeVoid:
@@ -2148,6 +2162,11 @@ SpirvShader::EmitResult SpirvShader::EmitSelect(InsnIterator insn, EmitState *st
 		dst.move(i, (sel & lhs.Int(i)) | (~sel & rhs.Int(i)));  // TODO: IfThenElse()
 	}
 
+	SPIRV_SHADER_DBG("{0}: {1}", insn.word(2), dst);
+	SPIRV_SHADER_DBG("{0}: {1}", insn.word(3), cond);
+	SPIRV_SHADER_DBG("{0}: {1}", insn.word(4), lhs);
+	SPIRV_SHADER_DBG("{0}: {1}", insn.word(5), rhs);
+
 	return EmitResult::Continue;
 }
 

src/Pipeline/SpirvShader.hpp

@@ -83,13 +83,22 @@ public:
 		delete[] scalar;
 	}
 
-	void move(uint32_t i, RValue<SIMD::Float> &&scalar) { emplace(i, scalar.value); }
-	void move(uint32_t i, RValue<SIMD::Int> &&scalar) { emplace(i, scalar.value); }
-	void move(uint32_t i, RValue<SIMD::UInt> &&scalar) { emplace(i, scalar.value); }
+	// TypeHint is used as a hint for rr::PrintValue::Ty<sw::Intermediate> to
+	// decide the format used to print the intermediate data.
+	enum class TypeHint
+	{
+		Float,
+		Int,
+		UInt
+	};
+
+	void move(uint32_t i, RValue<SIMD::Float> &&scalar) { emplace(i, scalar.value, TypeHint::Float); }
+	void move(uint32_t i, RValue<SIMD::Int> &&scalar) { emplace(i, scalar.value, TypeHint::Int); }
+	void move(uint32_t i, RValue<SIMD::UInt> &&scalar) { emplace(i, scalar.value, TypeHint::UInt); }
 
-	void move(uint32_t i, const RValue<SIMD::Float> &scalar) { emplace(i, scalar.value); }
-	void move(uint32_t i, const RValue<SIMD::Int> &scalar) { emplace(i, scalar.value); }
-	void move(uint32_t i, const RValue<SIMD::UInt> &scalar) { emplace(i, scalar.value); }
+	void move(uint32_t i, const RValue<SIMD::Float> &scalar) { emplace(i, scalar.value, TypeHint::Float); }
+	void move(uint32_t i, const RValue<SIMD::Int> &scalar) { emplace(i, scalar.value, TypeHint::Int); }
+	void move(uint32_t i, const RValue<SIMD::UInt> &scalar) { emplace(i, scalar.value, TypeHint::UInt); }
 
 	// Value retrieval functions.
 	RValue<SIMD::Float> Float(uint32_t i) const
@@ -122,14 +131,20 @@ public:
 	const uint32_t componentCount;
 
 private:
-	void emplace(uint32_t i, rr::Value *value)
+	void emplace(uint32_t i, rr::Value *value, TypeHint type)
 	{
 		ASSERT(i < componentCount);
 		ASSERT(scalar[i] == nullptr);
 		scalar[i] = value;
+		RR_PRINT_ONLY(typeHint = type;)
 	}
 
 	rr::Value **const scalar;
+
+#ifdef ENABLE_RR_PRINT
+	friend struct rr::PrintValue::Ty<sw::Intermediate>;
+	TypeHint typeHint = TypeHint::Float;
+#endif  // ENABLE_RR_PRINT
 };
 
 class SpirvShader
@@ -1028,6 +1043,8 @@ private:
 		}
 
 	private:
+		RR_PRINT_ONLY(friend struct rr::PrintValue::Ty<Operand>;)
+
 		// Delegate constructor
 		Operand(const EmitState *state, const Object &object);
 
@@ -1038,6 +1055,8 @@ private:
 		const uint32_t componentCount;
 	};
 
+	RR_PRINT_ONLY(friend struct rr::PrintValue::Ty<Operand>;)
+
 	Type const &getType(Type::ID id) const
 	{
 		auto it = types.find(id);

src/Pipeline/SpirvShaderArithmetic.cpp

@@ -13,6 +13,7 @@
 // limitations under the License.
 
 #include "SpirvShader.hpp"
+#include "SpirvShaderDebug.hpp"
 
 #include "ShaderCore.hpp"
 
@@ -505,6 +506,10 @@ SpirvShader::EmitResult SpirvShader::EmitBinaryOp(InsnIterator insn, EmitState *
 		}
 	}
 
+	SPIRV_SHADER_DBG("{0}: {1}", insn.word(2), dst);
+	SPIRV_SHADER_DBG("{0}: {1}", insn.word(3), lhs);
+	SPIRV_SHADER_DBG("{0}: {1}", insn.word(4), rhs);
+
 	return EmitResult::Continue;
 }
 
@@ -518,6 +523,11 @@ SpirvShader::EmitResult SpirvShader::EmitDot(InsnIterator insn, EmitState *state
 	auto rhs = Operand(this, state, insn.word(4));
 
 	dst.move(0, Dot(lhsType.componentCount, lhs, rhs));
+
+	SPIRV_SHADER_DBG("{0}: {1}", insn.resultId(), dst);
+	SPIRV_SHADER_DBG("{0}: {1}", insn.word(3), lhs);
+	SPIRV_SHADER_DBG("{0}: {1}", insn.word(4), rhs);
+
 	return EmitResult::Continue;
 }
 

src/Pipeline/SpirvShaderControlFlow.cpp

@@ -13,6 +13,7 @@
 // limitations under the License.
 
 #include "SpirvShader.hpp"
+#include "SpirvShaderDebug.hpp"
 
 #include "Reactor/Coroutine.hpp"  // rr::Yield
 
@@ -298,8 +299,10 @@ void SpirvShader::EmitNonLoop(EmitState *state) const
 		for(auto in : block.ins)
 		{
 			auto inMask = GetActiveLaneMaskEdge(state, in, blockId);
+			SPIRV_SHADER_DBG("Block {0} -> {1} mask: {2}", in, blockId, inMask);
 			activeLaneMask |= inMask;
 		}
+		SPIRV_SHADER_DBG("Block {0} mask: {1}", blockId, activeLaneMask);
 		SetActiveLaneMask(activeLaneMask, state);
 	}
 
@@ -312,6 +315,8 @@ void SpirvShader::EmitNonLoop(EmitState *state) const
 			state->pending->push_back(out);
 		}
 	}
+
+	SPIRV_SHADER_DBG("Block {0} done", blockId);
 }
 
 void SpirvShader::EmitLoop(EmitState *state) const
@@ -327,6 +332,8 @@ void SpirvShader::EmitLoop(EmitState *state) const
 		return;  // Already emitted this loop.
 	}
 
+	SPIRV_SHADER_DBG("*** LOOP HEADER ***");
+
 	// Gather all the blocks that make up the loop.
 	std::unordered_set<Block::ID> loopBlocks;
 	loopBlocks.emplace(block.mergeBlock);
@@ -376,6 +383,8 @@ void SpirvShader::EmitLoop(EmitState *state) const
 	Nucleus::createBr(headerBasicBlock);
 	Nucleus::setInsertBlock(headerBasicBlock);
 
+	SPIRV_SHADER_DBG("*** LOOP START (mask: {0}) ***", loopActiveLaneMask);
+
 	// Load the active lane mask.
 	SetActiveLaneMask(loopActiveLaneMask, state);
 
@@ -432,6 +441,8 @@ void SpirvShader::EmitLoop(EmitState *state) const
 		}
 	}
 
+	SPIRV_SHADER_DBG("*** LOOP END (mask: {0}) ***", loopActiveLaneMask);
+
 	// Use the [loop -> merge] active lane masks to update the phi values in
 	// the merge block. We need to do this to handle divergent control flow
 	// in the loop.
@@ -516,6 +527,7 @@ SpirvShader::EmitResult SpirvShader::EmitSwitch(InsnIterator insn, EmitState *st
 
 	auto sel = Operand(this, state, selId);
 	ASSERT_MSG(sel.componentCount == 1, "Selector must be a scalar");
+	SPIRV_SHADER_DBG("switch({0})", sel);
 
 	auto numCases = (block.branchInstruction.wordCount() - 3) / 2;
 
@@ -531,11 +543,13 @@ SpirvShader::EmitResult SpirvShader::EmitSwitch(InsnIterator insn, EmitState *st
 		auto label = block.branchInstruction.word(i * 2 + 3);
 		auto caseBlockId = Block::ID(block.branchInstruction.word(i * 2 + 4));
 		auto caseLabelMatch = CmpEQ(sel.Int(0), SIMD::Int(label));
+		SPIRV_SHADER_DBG("case {0}: {1}", label, caseLabelMatch & state->activeLaneMask());
 		state->addOutputActiveLaneMaskEdge(caseBlockId, caseLabelMatch);
 		defaultLaneMask &= ~caseLabelMatch;
 	}
 
 	auto defaultBlockId = Block::ID(block.branchInstruction.word(2));
+	SPIRV_SHADER_DBG("default: {0}", defaultLaneMask);
 	state->addOutputActiveLaneMaskEdge(defaultBlockId, defaultLaneMask);
 
 	return EmitResult::Terminator;
@@ -654,6 +668,7 @@ void SpirvShader::LoadPhi(InsnIterator insn, EmitState *state) const
 	for(uint32_t i = 0; i < type.componentCount; i++)
 	{
 		dst.move(i, storage[i]);
+		SPIRV_SHADER_DBG("LoadPhi({0}.{1}): {2}", objectId, i, storage[i]);
 	}
 }
 
@@ -683,8 +698,15 @@ void SpirvShader::StorePhi(Block::ID currentBlock, InsnIterator insn, EmitState
 		for(uint32_t i = 0; i < type.componentCount; i++)
 		{
 			storage[i] = As<SIMD::Float>((As<SIMD::Int>(storage[i]) & ~mask) | (in.Int(i) & mask));
+			SPIRV_SHADER_DBG("StorePhi({0}.{1}): [{2} <- {3}] {4}: {5}, mask: {6}",
+			                 objectId, i, currentBlock, blockId, varId, in.UInt(i), mask);
 		}
 	}
+
+	for(uint32_t i = 0; i < type.componentCount; i++)
+	{
+		SPIRV_SHADER_DBG("StorePhi({0}.{1}): {2}", objectId, i, As<SIMD::UInt>(storage[i]));
+	}
 }
 
 void SpirvShader::Fence(spv::MemorySemanticsMask semantics) const

src/Pipeline/SpirvShaderDebug.hpp

+// Copyright 2020 The SwiftShader Authors. All Rights Reserved.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//    http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+#ifndef sw_SpirvShaderDebug_hpp
+#define sw_SpirvShaderDebug_hpp
+
+// Enable this to print verbose debug messages as each SPIR-V instructon is
+// executed. Very handy for performing text diffs when the thread count is
+// reduced to 1 and execution is deterministic.
+#define SPIRV_SHADER_ENABLE_DBG 0
+
+#if SPIRV_SHADER_ENABLE_DBG
+#	define SPIRV_SHADER_DBG(fmt, ...) rr::Print(fmt "\n", ##__VA_ARGS__)
+#	include "spirv-tools/libspirv.h"
+namespace spvtools {
+// Function implemented in third_party/SPIRV-Tools/source/disassemble.cpp
+// but with no public header.
+std::string spvInstructionBinaryToText(const spv_target_env env,
+                                       const uint32_t *inst_binary,
+                                       const size_t inst_word_count,
+                                       const uint32_t *binary,
+                                       const size_t word_count,
+                                       const uint32_t options);
+
+}  // namespace spvtools
+#else
+#	define SPIRV_SHADER_DBG(...)
+#endif  // SPIRV_SHADER_ENABLE_DBG
+
+#ifdef ENABLE_RR_PRINT
+namespace rr {
+template<>
+struct PrintValue::Ty<sw::SpirvShader::Object::ID>
+{
+	static inline std::string fmt(sw::SpirvShader::Object::ID v) { return "Object<" + std::to_string(v.value()) + ">"; }
+	static inline std::vector<Value *> val(sw::SpirvShader::Object::ID v) { return {}; }
+};
+template<>
+struct PrintValue::Ty<sw::SpirvShader::Type::ID>
+{
+	static inline std::string fmt(sw::SpirvShader::Type::ID v) { return "Type<" + std::to_string(v.value()) + ">"; }
+	static inline std::vector<Value *> val(sw::SpirvShader::Type::ID v) { return {}; }
+};
+template<>
+struct PrintValue::Ty<sw::SpirvShader::Block::ID>
+{
+	static inline std::string fmt(sw::SpirvShader::Block::ID v) { return "Block<" + std::to_string(v.value()) + ">"; }
+	static inline std::vector<Value *> val(sw::SpirvShader::Block::ID v) { return {}; }
+};
+
+template<>
+struct PrintValue::Ty<sw::Intermediate>
+{
+	static inline std::string fmt(const sw::Intermediate &v, uint32_t i)
+	{
+		switch(v.typeHint)
+		{
+			case sw::Intermediate::TypeHint::Float:
+				return PrintValue::Ty<sw::SIMD::Float>::fmt(v.Float(i));
+			case sw::Intermediate::TypeHint::Int:
+				return PrintValue::Ty<sw::SIMD::Int>::fmt(v.Int(i));
+			case sw::Intermediate::TypeHint::UInt:
+				return PrintValue::Ty<sw::SIMD::UInt>::fmt(v.UInt(i));
+		}
+		return "";
+	}
+
+	static inline std::vector<Value *> val(const sw::Intermediate &v, uint32_t i)
+	{
+		switch(v.typeHint)
+		{
+			case sw::Intermediate::TypeHint::Float:
+				return PrintValue::Ty<sw::SIMD::Float>::val(v.Float(i));
+			case sw::Intermediate::TypeHint::Int:
+				return PrintValue::Ty<sw::SIMD::Int>::val(v.Int(i));
+			case sw::Intermediate::TypeHint::UInt:
+				return PrintValue::Ty<sw::SIMD::UInt>::val(v.UInt(i));
+		}
+		return {};
+	}
+
+	static inline std::string fmt(const sw::Intermediate &v)
+	{
+		if(v.componentCount == 1)
+		{
+			return fmt(v, 0);
+		}
+
+		std::string out = "[";
+		for(uint32_t i = 0; i < v.componentCount; i++)
+		{
+			if(i > 0) { out += ", "; }
+			out += std::to_string(i) + ": ";
+			out += fmt(v, i);
+		}
+		return out + "]";
+	}
+
+	static inline std::vector<Value *> val(const sw::Intermediate &v)
+	{
+		std::vector<Value *> out;
+		for(uint32_t i = 0; i < v.componentCount; i++)
+		{
+			auto vals = val(v, i);
+			out.insert(out.end(), vals.begin(), vals.end());
+		}
+		return out;
+	}
+};
+
+template<>
+struct PrintValue::Ty<sw::SpirvShader::Operand>
+{
+	static inline std::string fmt(const sw::SpirvShader::Operand &v)
+	{
+		return (v.intermediate != nullptr) ? PrintValue::Ty<sw::Intermediate>::fmt(*v.intermediate) : PrintValue::Ty<sw::SIMD::UInt>::fmt(v.UInt(0));
+	}
+
+	static inline std::vector<Value *> val(const sw::SpirvShader::Operand &v)
+	{
+		return (v.intermediate != nullptr) ? PrintValue::Ty<sw::Intermediate>::val(*v.intermediate) : PrintValue::Ty<sw::SIMD::UInt>::val(v.UInt(0));
+	}
+};
+}  // namespace rr
+#endif  // ENABLE_RR_PRINT
+
+#endif  // sw_SpirvShaderDebug_hpp

src/Pipeline/SpirvShaderMemory.cpp

@@ -13,6 +13,7 @@
 // limitations under the License.
 
 #include "SpirvShader.hpp"
+#include "SpirvShaderDebug.hpp"
 
 #include "ShaderCore.hpp"
 
@@ -63,6 +64,8 @@ SpirvShader::EmitResult SpirvShader::EmitLoad(InsnIterator insn, EmitState *stat
 		dst.move(el.index, p.Load<SIMD::Float>(robustness, state->activeLaneMask(), atomic, memoryOrder));
 	});
 
+	SPIRV_SHADER_DBG("Load(atomic: {0}, order: {1}, ptr: {2}, val: {3}, mask: {4})", atomic, int(memoryOrder), ptr, dst, state->activeLaneMask());
+
 	return EmitResult::Continue;
 }
 
@@ -105,6 +108,8 @@ void SpirvShader::Store(Object::ID pointerId, const Operand &value, bool atomic,
 		mask = mask & state->storesAndAtomicsMask();
 	}
 
+	SPIRV_SHADER_DBG("Store(atomic: {0}, order: {1}, ptr: {2}, val: {3}, mask: {4}", atomic, int(memoryOrder), ptr, value, mask);
+
 	VisitMemoryObject(pointerId, [&](const MemoryElement &el) {
 		auto p = ptr + el.offset;
 		if(interleavedByLane) { p = InterleaveByLane(p); }

src/Reactor/Print.hpp

@@ -35,6 +35,7 @@ namespace rr {
 //   * Static arrays in the form T[N] where T can be any of the above.
 class PrintValue
 {
+public:
 	// Ty is a template that can be specialized for printing type T.
 	// Each specialization must expose:
 	//  * A 'static std::string fmt(const T& v)' method that provides the
@@ -83,7 +84,6 @@ class PrintValue
 		return buf;
 	}
 
-public:
 	const std::string format;
 	const std::vector<Value *> values;
 
@@ -456,6 +456,9 @@ static_assert(3 == RR_COUNT_ARGUMENTS(a, b, c), "RR_COUNT_ARGUMENTS broken");
 
 }  // namespace rr
 
+#	define RR_PRINT_ONLY(x) x
+#else
+#	define RR_PRINT_ONLY(x)
 #endif  // ENABLE_RR_PRINT
 
 #endif  // rr_Print_hpp