From bcc0192c131448a0d428e26523e9b831708c4c9c Mon Sep 17 00:00:00 2001 From: Jordan DeLong Date: Mon, 3 Jun 2013 23:22:26 -0700 Subject: [PATCH] Improve verifier error message marginally (include unit, func) --- hphp/runtime/vm/verifier/check_func.cpp | 96 +++++++++++++------------ hphp/runtime/vm/verifier/check_unit.cpp | 32 +++++---- hphp/runtime/vm/verifier/pretty.cpp | 15 +++- hphp/runtime/vm/verifier/pretty.h | 11 +-- 4 files changed, 92 insertions(+), 62 deletions(-) diff --git a/hphp/runtime/vm/verifier/check_func.cpp b/hphp/runtime/vm/verifier/check_func.cpp index 3616e17ea..3d700587e 100644 --- a/hphp/runtime/vm/verifier/check_func.cpp +++ b/hphp/runtime/vm/verifier/check_func.cpp @@ -65,6 +65,7 @@ class FuncChecker { FuncChecker(const Func* func, bool verbose); bool checkOffsets(); bool checkFlow(); + private: bool checkEdge(Block* b, const State& cur, Block* t); bool checkSuccEdges(Block* b, State* cur); @@ -105,6 +106,13 @@ class FuncChecker { int numLocals() const { return m_func->numLocals(); } int numParams() const { return m_func->numParams(); } const Unit* unit() const { return m_func->unit(); } + + private: + template + void error(const char* fmt, Args&&... args) { + verify_error(unit(), m_func, fmt, std::forward(args)...); + } + private: Arena m_arena; BlockInfo* m_info; // one per block @@ -247,7 +255,7 @@ bool FuncChecker::checkSection(bool is_main, const char* name, Offset base, int32_t len = getImmVector(pc).size(); int64_t limit = base + len - 2; if (limit < switchBase) { - verify_error("Overflow in Switch bounds [%d:%d]\n", + error("Overflow in Switch bounds [%d:%d]\n", base, past); } } else if (*pc == OpSSwitch) { @@ -259,20 +267,20 @@ bool FuncChecker::checkSection(bool is_main, const char* name, Offset base, } if (i.empty()) { if (offset(pc + instrLen(pc)) != past) { - verify_error("Last instruction in %s at %d overflows [%d:%d]\n", + error("Last instruction in %s at %d overflows [%d:%d]\n", name, offset(pc), base, past); ok = false; } if (!isTF(pc)) { - verify_error("Last instruction in %s is not teriminal %d:%s\n", + error("Last instruction in %s is not teriminal %d:%s\n", name, offset(pc), instrToString(pc, unit()).c_str()); ok = false; } else { if (isRet(pc) && !is_main) { - verify_error("Ret* may not appear in %s\n", name); + error("Ret* may not appear in %s\n", name); ok = false; } else if (Op(*pc) == OpUnwind && is_main) { - verify_error("Unwind may not appear in %s\n", name); + error("Unwind may not appear in %s\n", name); ok = false; } } @@ -362,7 +370,7 @@ class ImmVecRange { bool FuncChecker::checkLocal(PC pc, int k) { if (k < 0 || k >= numLocals()) { - verify_error("invalid local variable id %d at Offset %d\n", + error("invalid local variable id %d at Offset %d\n", k, offset(pc)); return false; } @@ -371,7 +379,7 @@ bool FuncChecker::checkLocal(PC pc, int k) { bool FuncChecker::checkString(PC pc, Id id) { if (id < 0 || unsigned(id) >= unit()->numLitstrs()) { - verify_error("invalid string id %d at %d\n", id, offset(pc)); + error("invalid string id %d at %d\n", id, offset(pc)); return false; } return true; @@ -383,7 +391,7 @@ bool FuncChecker::checkString(PC pc, Id id) { */ bool FuncChecker::checkImmediates(const char* name, const Opcode* instr) { if (!isValidOpcode(*instr)) { - verify_error("Invalid opcode %d in section %s at offset %d\n", + error("Invalid opcode %d in section %s at offset %d\n", *instr, name, offset(instr)); return false; } @@ -397,12 +405,12 @@ bool FuncChecker::checkImmediates(const char* name, const Opcode* instr) { ImmVecRange vr(instr); if (vr.size() < 2) { // vector must at least have a LocationCode and 1+ MemberCodes - verify_error("invalid vector size %d at %d\n", + error("invalid vector size %d at %d\n", vr.size(), offset(instr)); return false; } else { if (vr.loc < 0 || vr.loc >= NumLocationCodes) { - verify_error("invalid location code %d in vector at %d\n", + error("invalid location code %d in vector at %d\n", (int)vr.loc, offset(instr)); ok = false; } @@ -410,7 +418,7 @@ bool FuncChecker::checkImmediates(const char* name, const Opcode* instr) { for (; !vr.empty(); vr.popFront()) { MemberCode member = vr.frontMember(); if (member < 0 || member >= NumMemberCodes) { - verify_error("invalid member code %d in vector at %d\n", + error("invalid member code %d in vector at %d\n", (int) member, offset((PC)instr)); ok = false; } @@ -433,7 +441,7 @@ bool FuncChecker::checkImmediates(const char* name, const Opcode* instr) { PC ia_pc = pc; int32_t k = decodeVariableSizeImm(&ia_pc); if (k >= numIters()) { - verify_error("invalid iterator variable id %d at %d\n", + error("invalid iterator variable id %d at %d\n", k, offset((PC)instr)); ok = false; } @@ -449,7 +457,7 @@ bool FuncChecker::checkImmediates(const char* name, const Opcode* instr) { break; case OpVerifyParamType: if (k >= numParams()) { - verify_error("invalid parameter id %d at %d\n", + error("invalid parameter id %d at %d\n", k, offset((PC)instr)); ok = false; } @@ -460,7 +468,7 @@ bool FuncChecker::checkImmediates(const char* name, const Opcode* instr) { case SLA: { // vec of offsets for Switch/SSwitch int len = *(int*)pc; if (len < 1) { - verify_error("invalid length of jump table %d at Offset %d\n", + error("invalid length of jump table %d at Offset %d\n", len, offset(pc)); return false; } @@ -480,7 +488,7 @@ bool FuncChecker::checkImmediates(const char* name, const Opcode* instr) { PC aa_pc = pc; Id id = decodeId(&aa_pc); if (id < 0 || id >= (Id)unit()->numArrays()) { - verify_error("invalid array id %d\n", id); + error("invalid array id %d\n", id); ok = false; } break; @@ -498,14 +506,14 @@ bool FuncChecker::checkImmediates(const char* name, const Opcode* instr) { case OpIncDecL: case OpIncDecN: case OpIncDecG: case OpIncDecS: case OpIncDecM: if (op >= IncDec_invalid) { - verify_error("invalid operation for IncDec*: %d\n", op); + error("invalid operation for IncDec*: %d\n", op); ok = false; } break; case OpSetOpL: case OpSetOpN: case OpSetOpG: case OpSetOpS: case OpSetOpM: if (op >= SetOp_invalid) { - verify_error("invalid operation for SetOp*: %d\n", op); + error("invalid operation for SetOp*: %d\n", op); ok = false; } break; @@ -529,7 +537,7 @@ bool FuncChecker::checkSig(PC pc, int len, const FlavorDesc* args, for (int i = 0; i < len; ++i) { if (args[i] != (FlavorDesc)sig[i] && !((FlavorDesc)sig[i] == CVV && (args[i] == CV || args[i] == VV))) { - verify_error("flavor mismatch at %d, got %s expected %s\n", + error("flavor mismatch at %d, got %s expected %s\n", offset(pc), stkToString(len, args).c_str(), sigToString(len, sig).c_str()); return false; @@ -657,7 +665,7 @@ bool FuncChecker::checkInputs(State* cur, PC pc, Block* b) { bool FuncChecker::checkTerminal(State* cur, PC pc) { if (isRet(pc) || Op(*pc) == OpUnwind) { if (cur->stklen != 0) { - verify_error("stack depth must equal 0 after Ret* and Unwind; got %d\n", + error("stack depth must equal 0 after Ret* and Unwind; got %d\n", cur->stklen); return false; } @@ -667,7 +675,7 @@ bool FuncChecker::checkTerminal(State* cur, PC pc) { bool FuncChecker::checkFpi(State* cur, PC pc, Block* b) { if (cur->fpilen <= 0) { - verify_error("cannot access empty FPI stack\n"); + error("%s", "cannot access empty FPI stack\n"); return false; } bool ok = true; @@ -677,17 +685,17 @@ bool FuncChecker::checkFpi(State* cur, PC pc, Block* b) { int call_params = Op(*pc) == OpFCall ? getImmIva(pc) : 1; int push_params = getImmIva(at(fpi.fpush)); if (call_params != push_params) { - verify_error("FCall* param_count (%d) doesn't match FPush* (%d)\n", + error("FCall* param_count (%d) doesn't match FPush* (%d)\n", call_params, push_params); ok = false; } if (fpi.next != push_params) { - verify_error("wrong # of params were passed; got %d expected %d\n", + error("wrong # of params were passed; got %d expected %d\n", fpi.next, push_params); ok = false; } if (cur->stklen != fpi.stkmin) { - verify_error("FCall didn't consume the proper param count\n"); + error("%s", "FCall didn't consume the proper param count\n"); ok = false; } } else { @@ -695,12 +703,12 @@ bool FuncChecker::checkFpi(State* cur, PC pc, Block* b) { int param_id = getImmIva(pc); int push_params = getImmIva(at(fpi.fpush)); if (param_id >= push_params) { - verify_error("param_id %d out of range [0:%d)\n", param_id, + error("param_id %d out of range [0:%d)\n", param_id, push_params); return false; } if (param_id != fpi.next) { - verify_error("FPass* out of order; got id %d expected %d\n", + error("FPass* out of order; got id %d expected %d\n", param_id, fpi.next); ok = false; } @@ -708,7 +716,7 @@ bool FuncChecker::checkFpi(State* cur, PC pc, Block* b) { // so this check doesn't count the F result of this FPush, but does // count the previous FPush*s. if (cur->stklen != fpi.stkmin + param_id) { - verify_error("Stack depth incorrect after FPush; got %d expected %d\n", + error("Stack depth incorrect after FPush; got %d expected %d\n", cur->stklen, fpi.stkmin + param_id); ok = false; } @@ -726,13 +734,13 @@ bool FuncChecker::checkIter(State* cur, PC pc) { Op(*pc) == OpMIterInit || Op(*pc) == OpMIterInitK || Op(*pc) == OpDecodeCufIter) { if (cur->iters[id]) { - verify_error( + error( "IterInit* or MIterInit* <%d> trying to double-initialize\n", id); ok = false; } } else { if (!cur->iters[id]) { - verify_error("Cannot access un-initialized iter %d\n", id); + error("Cannot access un-initialized iter %d\n", id); ok = false; } if (Op(*pc) == OpIterFree || @@ -797,7 +805,7 @@ bool FuncChecker::checkOutputs(State* cur, PC pc, Block* b) { outs[i] = outputSigs[*pc][i]; if (isFPush(Op(*pc))) { if (cur->fpilen >= maxFpi()) { - verify_error("more FPush* instructions than FPI regions\n"); + error("%s", "more FPush* instructions than FPI regions\n"); return false; } FpiState& fpi = cur->fpi[cur->fpilen]; @@ -973,12 +981,12 @@ bool FuncChecker::checkEmptyStack(const EHEnt& handler, Block* b) { const State& state = m_info[b->id].state_in; if (!state.stk) return true; // ignore unreachable block if (state.stklen != 0) { - verify_error("EH region starts with non-empty stack at B%d\n", + error("EH region starts with non-empty stack at B%d\n", b->id); return false; } if (state.fpilen != 0) { - verify_error("EH region starts with non-empty FPI stack at B%d\n", + error("EH region starts with non-empty FPI stack at B%d\n", b->id); return false; } @@ -1004,7 +1012,7 @@ bool FuncChecker::checkEdge(Block* b, const State& cur, Block *t) { } for (int i = 0, n = cur.stklen; i < n; i++) { if (state.stk[i] != cur.stk[i]) { - verify_error("mismatch on edge B%d->B%d, current %s target %s\n", + error("mismatch on edge B%d->B%d, current %s target %s\n", b->id, t->id, stkToString(n, cur.stk).c_str(), stkToString(n, state.stk).c_str()); return false; @@ -1012,13 +1020,13 @@ bool FuncChecker::checkEdge(Block* b, const State& cur, Block *t) { } // Check FPI stack. if (state.fpilen != cur.fpilen) { - verify_error("FPI stack depth mismatch on edge B%d->B%d, " + error("FPI stack depth mismatch on edge B%d->B%d, " "current %d target %d\n", b->id, t->id, cur.fpilen, state.fpilen); return false; } for (int i = 0, n = cur.fpilen; i < n; i++) { if (state.fpi[i] != cur.fpi[i]) { - verify_error("FPI mismatch on edge B%d->B%d, current %s target %s\n", + error("FPI mismatch on edge B%d->B%d, current %s target %s\n", b->id, t->id, fpiToString(cur.fpi[i]).c_str(), fpiToString(state.fpi[i]).c_str()); return false; @@ -1028,7 +1036,7 @@ bool FuncChecker::checkEdge(Block* b, const State& cur, Block *t) { if (false /* TODO(#1097182): Iterator verification disabled */) { for (int i = 0, n = numIters(); i < n; i++) { if (state.iters[i] != cur.iters[i]) { - verify_error("mismatched iterator state on edge B%d->B%d, " + error("mismatched iterator state on edge B%d->B%d, " "current %s target %s\n", b->id, t->id, iterToString(cur).c_str(), iterToString(state).c_str()); return false; @@ -1040,22 +1048,22 @@ bool FuncChecker::checkEdge(Block* b, const State& cur, Block *t) { void FuncChecker::reportStkUnderflow(Block*, const State& cur, PC pc) { int min = cur.fpilen > 0 ? cur.fpi[cur.fpilen - 1].stkmin : 0; - verify_error("Rule2: Stack underflow at PC %d, min depth %d\n", + error("Rule2: Stack underflow at PC %d, min depth %d\n", offset(pc), min); } void FuncChecker::reportStkOverflow(Block*, const State& cur, PC pc) { - verify_error("Rule2: Stack overflow at PC %d\n", offset(pc)); + error("Rule2: Stack overflow at PC %d\n", offset(pc)); } void FuncChecker::reportStkMismatch(Block* b, Block* t, const State& cur) { const State& st = m_info[t->id].state_in; - verify_error("Rule1: Stack mismatch on edge B%d->B%d; depth %d->%d\n", + error("Rule1: Stack mismatch on edge B%d->B%d; depth %d->%d\n", b->id, t->id, cur.stklen, st.stklen); } void FuncChecker::reportEscapeEdge(Block* b, Block* s) { - verify_error("Edge from B%d to offset %d escapes function\n", + error("Edge from B%d to offset %d escapes function\n", b->id, offset(s->start)); } @@ -1068,12 +1076,12 @@ bool FuncChecker::checkOffset(const char* name, Offset off, Offset past, bool check_instrs) { assert(past >= base); if (off < base || off >= past) { - verify_error("Offset %s %d is outside region %s %d:%d\n", + error("Offset %s %d is outside region %s %d:%d\n", name, off, regionName, base, past); return false; } if (check_instrs && !m_instrs.get(off - m_func->base())) { - verify_error("label %s %d is not on a valid instruction boundary\n", + error("label %s %d is not on a valid instruction boundary\n", name, off); return false; } @@ -1089,18 +1097,18 @@ bool FuncChecker::checkRegion(const char* name, Offset b, Offset p, Offset past, bool check_instrs) { assert(past >= base); if (p < b) { - verify_error("region %s %d:%d has negative length\n", + error("region %s %d:%d has negative length\n", name, b, p); return false; } if (b < base || p > past) { - verify_error("region %s %d:%d is not inside region %s %d:%d\n", + error("region %s %d:%d is not inside region %s %d:%d\n", name, b, p, regionName, base, past); return false; } else if (check_instrs && (!m_instrs.get(b - m_func->base()) || !m_instrs.get(p - m_func->base()))) { - verify_error("region %s %d:%d boundaries are inbetween instructions\n", + error("region %s %d:%d boundaries are inbetween instructions\n", name, b, p); return false; } diff --git a/hphp/runtime/vm/verifier/check_unit.cpp b/hphp/runtime/vm/verifier/check_unit.cpp index 67e07a368..2ab181663 100644 --- a/hphp/runtime/vm/verifier/check_unit.cpp +++ b/hphp/runtime/vm/verifier/check_unit.cpp @@ -29,6 +29,7 @@ class UnitChecker { UnitChecker(const Unit*, bool verbose); ~UnitChecker() {} bool verify(); + private: template bool checkLiteral(size_t, const T*, const char*); bool checkStrings(); @@ -38,6 +39,13 @@ class UnitChecker { bool checkFuncs(); bool checkBytecode(); bool checkMetadata(); + + private: + template + void error(const char* fmt, Args&&... args) { + verify_error(m_unit, nullptr, fmt, std::forward(args)...); + } + private: const Unit* m_unit; bool m_verbose; @@ -45,7 +53,7 @@ class UnitChecker { bool checkUnit(const Unit* unit, bool verbose) { if (verbose) { - verify_error("verifying unit from %s\n", unit->filepath()->data()); + printf("verifying unit from %s\n", unit->filepath()->data()); } return UnitChecker(unit, verbose).verify(); } @@ -80,12 +88,12 @@ bool UnitChecker::checkLiteral(size_t id, const char* what) { bool ok = true; if (!lt) { - verify_error("null %s id %zu in unit %s\n", what, id, + error("null %s id %zu in unit %s\n", what, id, m_unit->md5().toString().c_str()); ok = false; } if (!lt->isStatic()) { - verify_error("non-static %s id %zu in unit %s\n", what, id, + error("non-static %s id %zu in unit %s\n", what, id, m_unit->md5().toString().c_str()); ok = false; } @@ -133,21 +141,21 @@ bool UnitChecker::checkBytecode() { const Func* f = i.popFront(); if (f->past() <= f->base()) { if (!f->isAbstract() || f->past() < f->base()) { - verify_error("func size <= 0 [%d:%d] in unit %s\n", + error("func size <= 0 [%d:%d] in unit %s\n", f->base(), f->past(), m_unit->md5().toString().c_str()); ok = false; continue; } } if (f->base() < 0 || f->past() > m_unit->bclen()) { - verify_error("function region [%d:%d] out of unit %s bounds [%d:%d]\n", + error("function region [%d:%d] out of unit %s bounds [%d:%d]\n", f->base(), f->past(), m_unit->md5().toString().c_str(), 0, m_unit->bclen()); ok = false; continue; } if (funcs.find(f->base()) != funcs.end()) { - verify_error("duplicate function-base at %d in unit %s\n", + error("duplicate function-base at %d in unit %s\n", f->base(), m_unit->md5().toString().c_str()); ok = false; continue; @@ -156,7 +164,7 @@ bool UnitChecker::checkBytecode() { } // iterate funcs in offset order, checking for holes and overlap if (funcs.empty()) { - verify_error("unit %s must have at least one func\n", + error("unit %s must have at least one func\n", m_unit->md5().toString().c_str()); return false; } @@ -164,17 +172,17 @@ bool UnitChecker::checkBytecode() { for (FuncMap::iterator i = funcs.begin(), e = funcs.end(); i != e; ) { const Func* f = (*i).second; ++i; if (f->base() < last_past) { - verify_error("function overlap [%d:%d] in unit %s\n", + error("function overlap [%d:%d] in unit %s\n", f->base(), last_past, m_unit->md5().toString().c_str()); ok = false; } else if (f->base() > last_past) { - verify_error("dead bytecode space [%d:%d] in unit %s\n", + error("dead bytecode space [%d:%d] in unit %s\n", last_past, f->base(), m_unit->md5().toString().c_str()); ok = false; } last_past = f->past(); if (i == e && last_past != m_unit->bclen()) { - verify_error("dead bytecode [%d:%d] at end of unit %s\n", + error("dead bytecode [%d:%d] at end of unit %s\n", last_past, m_unit->bclen(), m_unit->md5().toString().c_str()); ok = false; } @@ -195,7 +203,7 @@ bool UnitChecker::checkFuncs() { if (i.front()->isPseudoMain()) { if (pseudo) { multi = true; - verify_error("unit should have exactly one pseudo-main\n"); + error("%s", "unit should have exactly one pseudo-main\n"); ok = false; } pseudo = i.front(); @@ -204,7 +212,7 @@ bool UnitChecker::checkFuncs() { } if (!multi && m_unit->getMain() != pseudo) { - verify_error("funcs and unit disagree on what is the pseudo-main\n"); + error("%s", "funcs and unit disagree on what is the pseudo-main\n"); ok = false; } diff --git a/hphp/runtime/vm/verifier/pretty.cpp b/hphp/runtime/vm/verifier/pretty.cpp index b384c03a1..af45e5a19 100644 --- a/hphp/runtime/vm/verifier/pretty.cpp +++ b/hphp/runtime/vm/verifier/pretty.cpp @@ -19,6 +19,8 @@ #include #include +#include "folly/Format.h" + #include "hphp/runtime/vm/repo.h" #include "hphp/runtime/vm/verifier/util.h" #include "hphp/runtime/vm/verifier/cfg.h" @@ -143,13 +145,22 @@ void printGml(const Unit* unit) { fclose(file); } -void verify_error(const char* fmt, ...) { +void verify_error(const Unit* unit, + const Func* func, + const char* fmt, + ...) { char buf[1024]; va_list args; va_start(args, fmt); vsnprintf(buf, sizeof buf, fmt, args); va_end(args); - fprintf(stderr, "Verification: %s", buf); + fprintf(stderr, + "Verification Error (unit %s%s): %s", + unit->filepath()->data(), + func != nullptr + ? folly::format(" func {}", func->fullName()->data()).str().c_str() + : "", + buf); } }} // namespace HPHP::VM diff --git a/hphp/runtime/vm/verifier/pretty.h b/hphp/runtime/vm/verifier/pretty.h index 8dae8f976..0fbcd33ca 100644 --- a/hphp/runtime/vm/verifier/pretty.h +++ b/hphp/runtime/vm/verifier/pretty.h @@ -65,11 +65,14 @@ void printGml(const Unit*); /* * Called to indicate a verification error. * - * Currently just prints to stdout, but we might eventually want to + * Currently just prints to stderr, but we might eventually want to * support other ways of reporting the error. + * + * The Func* may be nullptr. */ -void verify_error(const char* fmt, ...) __attribute__((format(printf,1,2))); +void verify_error(const Unit*, const Func*, const char* fmt, ...) + __attribute__((format(printf,3,4))); -}} // HPHP::Verifier +}} -#endif // incl_HPHP_VM_VERIFIER_PRETTY_H +#endif