SpirvShader: Add a flag for printing SPIRV execution The ENABLE_DBG_MSGS flag controls printing of verbose debug messages to stdout as each SPIR-V instruction is executed. This is very handy for performing text diffs when the thread count is reduced to 1 and execution is deterministic. Bug: b/140287657 Change-Id: I3b62f0f9f3017087cf7f2786e1c30497cfa05a20 Reviewed-on: https://swiftshader-review.googlesource.com/c/SwiftShader/+/31488 Tested-by: Ben Clayton <bclayton@google.com> Reviewed-by: Nicolas Capens <nicolascapens@google.com>
diff --git a/src/Pipeline/BUILD.gn b/src/Pipeline/BUILD.gn index b85cf6a..998cb47 100644 --- a/src/Pipeline/BUILD.gn +++ b/src/Pipeline/BUILD.gn
@@ -24,6 +24,7 @@ "SetupRoutine.hpp", "ShaderCore.hpp", "SpirvShader.hpp", + "SpirvShaderDebug.hpp", "VertexProgram.hpp", "VertexRoutine.hpp", ]
diff --git a/src/Pipeline/ShaderCore.hpp b/src/Pipeline/ShaderCore.hpp index bbd4c2a..2b705cb 100644 --- a/src/Pipeline/ShaderCore.hpp +++ b/src/Pipeline/ShaderCore.hpp
@@ -544,7 +544,19 @@ 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
diff --git a/src/Pipeline/SpirvShader.cpp b/src/Pipeline/SpirvShader.cpp index 9a9ccd3..70d97bb 100644 --- a/src/Pipeline/SpirvShader.cpp +++ b/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 @@ 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 @@ 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; }
diff --git a/src/Pipeline/SpirvShader.hpp b/src/Pipeline/SpirvShader.hpp index 7df782e..b395ca2 100644 --- a/src/Pipeline/SpirvShader.hpp +++ b/src/Pipeline/SpirvShader.hpp
@@ -83,13 +83,22 @@ 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, 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, 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, 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 @@ 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: + RR_PRINT_ONLY(friend struct rr::PrintValue::Ty<Operand>;) + // Delegate constructor Operand(const EmitState *state, const Object &object); @@ -1038,6 +1055,8 @@ 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);
diff --git a/src/Pipeline/SpirvShaderArithmetic.cpp b/src/Pipeline/SpirvShaderArithmetic.cpp index 59c499b..e730505 100644 --- a/src/Pipeline/SpirvShaderArithmetic.cpp +++ b/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 @@ } } + 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 @@ 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; }
diff --git a/src/Pipeline/SpirvShaderControlFlow.cpp b/src/Pipeline/SpirvShaderControlFlow.cpp index 80cf455..8261b14 100644 --- a/src/Pipeline/SpirvShaderControlFlow.cpp +++ b/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 @@ 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 @@ state->pending->push_back(out); } } + + SPIRV_SHADER_DBG("Block {0} done", blockId); } void SpirvShader::EmitLoop(EmitState *state) const @@ -327,6 +332,8 @@ 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 @@ 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 @@ } } + 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 @@ 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 @@ 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 @@ 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 @@ 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
diff --git a/src/Pipeline/SpirvShaderDebug.hpp b/src/Pipeline/SpirvShaderDebug.hpp new file mode 100644 index 0000000..1cf3ce6 --- /dev/null +++ b/src/Pipeline/SpirvShaderDebug.hpp
@@ -0,0 +1,138 @@ +// 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
diff --git a/src/Pipeline/SpirvShaderMemory.cpp b/src/Pipeline/SpirvShaderMemory.cpp index 8407166..cbed2de 100644 --- a/src/Pipeline/SpirvShaderMemory.cpp +++ b/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 @@ 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 @@ 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); }
diff --git a/src/Reactor/Print.hpp b/src/Reactor/Print.hpp index ca70465..163af82 100644 --- a/src/Reactor/Print.hpp +++ b/src/Reactor/Print.hpp
@@ -35,6 +35,7 @@ // * 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 @@ return buf; } -public: const std::string format; const std::vector<Value *> values; @@ -456,6 +456,9 @@ } // namespace rr +# define RR_PRINT_ONLY(x) x +#else +# define RR_PRINT_ONLY(x) #endif // ENABLE_RR_PRINT #endif // rr_Print_hpp