AI_Assistant/pcbjam
Watch
1
0
Fork
You've already forked pcbjam
 0
Code Issues Pull requests Projects Releases 4 Packages Wiki Activity Actions 2

diagnostics: configurable --diag logging flags + asyncify setupUIConditions fix

Browse source 
- build-pcbnew.sh: add --diag=<gal,coroutine,ctor,all> -> -DKICAD_DIAG_*,
  off by default (forwarded by docker/build.sh)
- diagnostics.js: emit at console.log level (no longer error/warn); still
  gated by SHIM_DIAGNOSTICS=1
- apply-asyncify.sh: exclude PCB_EDIT_FRAME::setupUIConditions() from
  asyncify instrumentation (V8 cannot run the instrumented huge function
  on the rewound ctor stack -> Chrome startup stall; Firefox unaffected)
- DEBUG.md: reusable WASM/asyncify/browser debugging guide, diagnostic
  flag docs, and a production-build (release + -O2 asyncify) recipe
- tests: standalone coroutine vcall/gl repro probes
- bump kicad + wxwidgets submodules (diagnostic gating / debug cleanup)

Co-Authored-By: Claude Opus 4.7 <noreply@anthropic.com>
This commit is contained in:
Viktor Vaczi 2026-05-27 16:14:03 +02:00
commit 7331619404
10 changed files with 768 additions and 18 deletions
Download patch file Download diff file Expand all files Collapse all files

1
scripts/common/apply-asyncify.sh
View file

@ -45,6 +45,7 @@ StepAP214_Protocol::StepAP214_Protocol()
BRepCheck_ParallelAnalyzer::operator()(int) const
ShapeFix_Wire::FixGap3d(int, bool)
ShapeFix_Wire::FixGap2d(int, bool)
PCB_EDIT_FRAME::setupUIConditions()
REMOVELIST
)

172
scripts/common/shims/diagnostics.js
View file

@ -7,6 +7,9 @@
// observed right up to the faulting point.
(function() {
var modalActive = false;
var glTraceActive = false; // armed at the first main rewind (rewindId===0) below
var glCallSeq = 0;
var glTraceCap = 8000; // safety cap so a non-crashing run can't log forever
var tableLen = function() { return (typeof wasmTable !== "undefined" && wasmTable) ? wasmTable.length : -1; };
var asyncState = function() { return (typeof Asyncify !== "undefined") ? Asyncify.state : "N/A"; };
@ -15,9 +18,9 @@
var __origAsyncCall = _emscripten_async_call;
_emscripten_async_call = function(func, arg, millis) {
var inBounds = func >= 0 && func < tableLen();
console.warn("[DIAG_ASYNC_CALL] func=" + func + " arg=" + arg + " millis=" + millis +
console.log("[DIAG_ASYNC_CALL] func=" + func + " arg=" + arg + " millis=" + millis +
" inBounds=" + inBounds + " modalActive=" + modalActive + " state=" + asyncState());
if (!inBounds) { console.error("[DIAG_ASYNC_CALL] OUT OF BOUNDS at schedule time! func=" + func); console.trace(); }
if (!inBounds) { console.log("[DIAG_ASYNC_CALL] OUT OF BOUNDS at schedule time! func=" + func); console.trace(); }
return __origAsyncCall(func, arg, millis);
};
}
@ -26,7 +29,7 @@
if (typeof Asyncify !== "undefined" && Asyncify.setDataRewindFunc) {
var __origSetRewind = Asyncify.setDataRewindFunc.bind(Asyncify);
Asyncify.setDataRewindFunc = function(ptr, forced) {
console.warn("[DIAG_REWIND_FUNC] ptr=" + ptr + " forced=" + forced + " state=" + Asyncify.state +
console.log("[DIAG_REWIND_FUNC] ptr=" + ptr + " forced=" + forced + " state=" + Asyncify.state +
" modalActive=" + modalActive + " callStack=" + JSON.stringify(Asyncify.exportCallStack));
return __origSetRewind(ptr, forced);
};
@ -36,12 +39,38 @@
// immediately before re-entering wasm, so the last line before the crash names it.
if (typeof Asyncify !== "undefined" && typeof Asyncify.doRewind === "function") {
var __origDoRewind = Asyncify.doRewind.bind(Asyncify);
var heap32 = function () { return (typeof GROWABLE_HEAP_I32 === "function") ? GROWABLE_HEAP_I32() : HEAP32; };
Asyncify.doRewind = function(ptr) {
var rewindId = -1;
try { rewindId = (typeof GROWABLE_HEAP_I32 === "function") ? GROWABLE_HEAP_I32()[((ptr + 8) >> 2)] : HEAP32[((ptr + 8) >> 2)]; } catch (e) {}
console.warn("[DIAG_DOREWIND] ptr=" + ptr + " rewindId=" + rewindId + " state=" + asyncState() +
" modalActive=" + modalActive + " — re-entering wasm now");
return __origDoRewind(ptr);
var H = heap32();
var rd = function (off) { try { return H[((ptr + off) >> 2)]; } catch (e) { return -999; } };
// asyncify_data layout: [ptr+0]=current stack pos (top of saved data),
// [ptr+4]=stack end, [ptr+8]=rewindId. Saved call-index/locals live below [ptr+0].
var curPos = rd(0), stackEnd = rd(4), rewindId = rd(8);
var name = (Asyncify.callStackIdToName && Asyncify.callStackIdToName[rewindId]) || "?";
var usedBytes = curPos - (ptr + 12);
console.log("[DIAG_DOREWIND] ptr=" + ptr + " rewindId=" + rewindId + " (" + name + ")" +
" curPos=" + curPos + " stackEnd=" + stackEnd + " usedBytes=" + usedBytes +
" state=" + asyncState() + " — re-entering wasm now");
// Arm the WebGL tracer exactly at the main rewind (the crash window: the silent V8
// abort happens right after this rewind returns to main, before coroutine #2/first paint).
if (rewindId === 0 && !glTraceActive) {
glTraceActive = true;
console.log("[DIAG_GL] tracing ARMED at main rewind (rewindId=0)");
}
// Dump the saved call-index chain (first words of the buffer) so we can see the
// depth/shape of what the rewind replays at the crash.
try {
var words = [];
var start = ptr + 12;
for (var a = start; a < curPos && a < start + 256; a += 4) words.push(H[(a >> 2)]);
console.log("[DIAG_DOREWIND] saved-data[" + words.length + "w]: " + JSON.stringify(words));
} catch (e) {}
try {
return __origDoRewind(ptr);
} catch (e) {
console.log("[DIAG_DOREWIND] EXCEPTION during rewind: " + e + " | " + (e && e.stack));
throw e;
}
};
}
@ -50,7 +79,7 @@
var __origDynCallVi = dynCall_vi;
dynCall_vi = function(index, a0) {
if (index < 0 || index >= tableLen()) {
console.error("[DIAG_DYNCALL_VI] OUT OF BOUNDS index=" + index + " tableLen=" + tableLen() +
console.log("[DIAG_DYNCALL_VI] OUT OF BOUNDS index=" + index + " tableLen=" + tableLen() +
" modalActive=" + modalActive + " state=" + asyncState());
console.trace();
}
@ -64,16 +93,16 @@
setInterval(function() {
if (Module._endModal && !seen) {
seen = true; modalActive = true;
console.warn("[DIAG_MODAL] modal started, state=" + asyncState());
console.log("[DIAG_MODAL] modal started, state=" + asyncState());
var __origEnd = Module._endModal;
Module._endModal = function(code) {
console.warn("[DIAG_MODAL] EndModal code=" + code + " state=" + asyncState());
console.log("[DIAG_MODAL] EndModal code=" + code + " state=" + asyncState());
modalActive = false;
return __origEnd(code);
};
} else if (!Module._endModal && seen) {
seen = false;
console.warn("[DIAG_MODAL] modal cleanup, state=" + asyncState());
console.log("[DIAG_MODAL] modal cleanup, state=" + asyncState());
}
}, 100);
}
@ -86,11 +115,11 @@
var diagSleepId = 0;
Asyncify.handleSleep = function(startAsync) {
var id = ++diagSleepId;
console.warn("[DIAG_SLEEP] ENTER id=" + id + " state=" + asyncState() +
console.log("[DIAG_SLEEP] ENTER id=" + id + " state=" + asyncState() +
" currData=" + ((typeof Asyncify.currData !== "undefined" && Asyncify.currData) || "null"));
return __diagOrigHandleSleep(function(wakeUp) {
return startAsync(function(result) {
console.warn("[DIAG_SLEEP] WAKE id=" + id + " state=" + asyncState() +
console.log("[DIAG_SLEEP] WAKE id=" + id + " state=" + asyncState() +
" currData=" + ((typeof Asyncify.currData !== "undefined" && Asyncify.currData) || "null"));
return wakeUp(result);
});
@ -98,6 +127,119 @@
};
}
console.warn("[DIAG] Asyncify/fiber/modal diagnostics installed (logging only)");
// 7. WebGL call tracer — pinpoint the exact GL op that crashes Chrome's renderer.
// KiCad runs the GAL on an OffscreenCanvas in the pthread worker (PROXY_TO_PTHREAD +
// OFFSCREENCANVAS_SUPPORT), and this diagnostics code runs in that same worker, so we
// hook getContext where the context is actually created. Each call logs via
// console.error (immediate flush → captured even just before a hard V8 abort), but
// only once glTraceActive is set (at the main rewind), so volume = the crash window.
function wrapGLContext(ctx, kind) {
if (!ctx) return ctx;
try { if (ctx.__diagWrapped) return ctx; ctx.__diagWrapped = true; } catch (e) {}
console.log("[DIAG_GL] context created kind=" + kind);
return new Proxy(ctx, {
get: function(target, prop) {
var val = target[prop];
if (typeof val === "function") {
return function() {
if (glTraceActive && glCallSeq < glTraceCap) {
console.log("[DIAG_GL] #" + (++glCallSeq) + " " + String(prop));
}
return val.apply(target, arguments);
};
}
return val;
}
});
}
function hookGetContext(proto, kind) {
if (!proto || typeof proto.getContext !== "function" || proto.__diagGCHooked) return;
proto.__diagGCHooked = true;
var orig = proto.getContext;
proto.getContext = function(type) {
// Log the ATTEMPT before calling through, so if getContext itself crashes the
// renderer (e.g. a Chrome/ANGLE WebGL-context bug) this is the last line we see.
if (type === "webgl2" || type === "webgl" || type === "experimental-webgl") {
var attrs = "";
try { attrs = JSON.stringify(arguments[1] || {}); } catch (e) {}
console.log("[DIAG_GL] getContext(" + kind + ":" + type + ") attrs=" + attrs + " — calling through now");
}
var ctx = orig.apply(this, arguments);
if (type === "webgl2" || type === "webgl" || type === "experimental-webgl") {
console.log("[DIAG_GL] getContext returned " + (ctx ? "a context" : "NULL"));
try { return wrapGLContext(ctx, kind + ":" + type); } catch (e) { return ctx; }
}
return ctx;
};
}
if (typeof OffscreenCanvas !== "undefined") hookGetContext(OffscreenCanvas.prototype, "offscreen");
if (typeof HTMLCanvasElement !== "undefined") hookGetContext(HTMLCanvasElement.prototype, "html");
// 8. dynCall_ii / dynCall_vi invocation tracer (logging only). The shim routes the
// pthread-entry (ii) and fiber-entry/signal/timer (vi) callbacks through these bound
// instrumented dynCall_<sig>. Wrap them to log each invocation + the function pointer,
// armed at the main rewind (glTraceActive) so volume = the crash window. The LAST line
// before the silent crash names the faulting dispatch + its ptr. Tag thread for context.
var __thr = (typeof ENVIRONMENT_IS_PTHREAD !== "undefined" && ENVIRONMENT_IS_PTHREAD) ? "worker" : "main";
var __fnName = function(ptr) {
try { var f = getWasmTableEntry(ptr); return (f && f.name) ? f.name : "?"; } catch (e) { return "?err"; }
};
try {
if (typeof dynCall_ii === "function") {
var __origDCii = dynCall_ii;
dynCall_ii = function(ptr, a0) {
if (glTraceActive && glCallSeq < glTraceCap)
console.log("[DIAG_DC] " + __thr + " dynCall_ii ptr=" + ptr + " name=" + __fnName(ptr) + " #" + (++glCallSeq));
return __origDCii(ptr, a0);
};
}
} catch (e) {}
try {
if (typeof dynCall_vi === "function") {
var __origDCvi = dynCall_vi;
var __asy = function() {
if (typeof Asyncify === "undefined") return "noAsyncify";
var st = Asyncify.state;
var cd = (Asyncify.currData || 0);
return "state=" + st + " currData=" + cd;
};
dynCall_vi = function(ptr, a0) {
var big = glTraceActive && ptr > 15000; // the rare large-index 'vi' dispatches (incl. the stalling 20078)
if (glTraceActive && glCallSeq < glTraceCap) {
console.log("[DIAG_DC] " + __thr + " dynCall_vi ptr=" + ptr + " name=" + __fnName(ptr) + " arg=" + a0 + " #" + (++glCallSeq));
}
if (big) {
// Asyncify state going IN: if it's non-NORMAL (1=unwinding, 2=rewinding) the
// leftover coroutine state is making the instrumented dispatch misbehave.
console.log("[DIAG_DC_VI] ENTER ptr=" + ptr + " " + __asy());
var r = __origDCvi(ptr, a0);
// If this RETURNED line never appears, the dispatch unwound/stalled and never came back.
console.log("[DIAG_DC_VI] RETURNED ptr=" + ptr + " " + __asy());
return r;
}
return __origDCvi(ptr, a0);
};
}
} catch (e) {}
// 9. Periodic asyncify-state monitor (main thread). After dynCall_vi(20078)=
// setupUIConditions appears to unwind-and-never-rewind, this timer (which still runs
// on the idle event loop) reveals the post-stall Asyncify.state: if it's stuck at
// 1 (UNWINDING) or 2 (REWINDING) with a fixed currData, the app yielded and the
// rewind was never scheduled. Logs only on change + a heartbeat.
if (typeof Asyncify !== "undefined" && __thr === "main") {
var __lastSt = -999, __lastCd = -999, __hb = 0;
setInterval(function() {
var st = Asyncify.state, cd = (Asyncify.currData || 0);
if (st !== __lastSt || cd !== __lastCd) {
console.log("[DIAG_ASTATE] change -> state=" + st + " currData=" + cd);
__lastSt = st; __lastCd = cd;
} else if (st !== 0 && (++__hb % 6 === 0)) {
console.log("[DIAG_ASTATE] STILL state=" + st + " currData=" + cd + " (stuck?)");
}
}, 500);
}
console.log("[DIAG] Asyncify/fiber/modal diagnostics installed (logging only) [" + __thr + "]");
})();
// === End diagnostics ===

30
scripts/kicad/build-pcbnew.sh
View file

@ -41,6 +41,7 @@ NO_CLEAN=1
FULL_CLEAN=0
SKIP_DEPS=1
DEBUG=0
DIAG_LIST=""
while [[ $# -gt 0 ]]; do
case $1 in
--full)
@ -66,6 +67,14 @@ while [[ $# -gt 0 ]]; do
export DEBUG_BUILD
shift
;;
--diag=*)
DIAG_LIST="${1#--diag=}"
shift
;;
--diag)
DIAG_LIST="$2"
shift 2
;;
-j)
export JOBS="$2"
shift 2
@ -80,6 +89,25 @@ while [[ $# -gt 0 ]]; do
esac
done
# Diagnostic preprocessor defines from --diag=<csv> (gal, coroutine, ctor, all).
# These gate the KI_DIAG_* macros in kicad/include/kicad_wasm_diag.h. Output goes
# to stdout ([KICAD_OUT] logs), never errors. Off by default.
DIAG_DEFINES=""
if [ -n "${DIAG_LIST}" ]; then
IFS=',' read -ra _diag_cats <<< "${DIAG_LIST}"
for _cat in "${_diag_cats[@]}"; do
case "${_cat}" in
gal) DIAG_DEFINES="${DIAG_DEFINES} -DKICAD_DIAG_GAL=1" ;;
coroutine) DIAG_DEFINES="${DIAG_DEFINES} -DKICAD_DIAG_COROUTINE=1" ;;
ctor) DIAG_DEFINES="${DIAG_DEFINES} -DKICAD_DIAG_CTOR=1" ;;
all) DIAG_DEFINES="${DIAG_DEFINES} -DKICAD_DIAG_GAL=1 -DKICAD_DIAG_COROUTINE=1 -DKICAD_DIAG_CTOR=1" ;;
"") ;;
*) log_warn "Unknown --diag category: '${_cat}' (valid: gal, coroutine, ctor, all)" ;;
esac
done
log_info "Diagnostic logging enabled:${DIAG_DEFINES}"
fi
log_info "Using ${JOBS} parallel jobs"
# Step 1: Clean build directories
@ -241,7 +269,7 @@ emcmake cmake "${KICAD_DIR}" \
-DCMAKE_MODULE_PATH="${WASM_LAYER}/cmake" \
-DSYSROOT="${SYSROOT}" \
-DCMAKE_POLICY_VERSION_MINIMUM=3.5 \
-DCMAKE_CXX_FLAGS="${EXTRA_FLAGS} -pthread -sUSE_ZLIB=1 -DKICAD_USE_PLATFORM_WASM=1 -I${SYSROOT}/include -I${STUBS_DIR}" \
-DCMAKE_CXX_FLAGS="${EXTRA_FLAGS} -pthread -sUSE_ZLIB=1 -DKICAD_USE_PLATFORM_WASM=1${DIAG_DEFINES} -I${SYSROOT}/include -I${STUBS_DIR}" \
-DCMAKE_C_FLAGS="${EXTRA_FLAGS} -pthread -sUSE_ZLIB=1 -I${SYSROOT}/include -I${STUBS_DIR}" \
-DCMAKE_EXE_LINKER_FLAGS="${LINKER_DEBUG_FLAGS} -pthread -sUSE_ZLIB=1 -sASYNCIFY=1 -sDYNCALLS=1 -sASYNCIFY_STACK_SIZE=65536 -sUSE_PTHREADS=1 -sPTHREAD_POOL_SIZE='navigator.hardwareConcurrency' -sPTHREAD_POOL_SIZE_STRICT=0 -sALLOW_MEMORY_GROWTH=1 -sINITIAL_MEMORY=256MB -sMAXIMUM_MEMORY=4GB -sMAX_WEBGL_VERSION=2 -sEXPORTED_RUNTIME_METHODS=['ccall','cwrap','UTF8ToString','stringToUTF8','lengthBytesUTF8','dynCall'] -sDEFAULT_LIBRARY_FUNCS_TO_INCLUDE=['\$dynCall'] --bind -L${SYSROOT}/lib ${STUBS_BUILD}/libgit2_stub.a ${STUBS_BUILD}/libcurl_stub.a ${STUBS_BUILD}/libpcbnew_scripting_stub.a ${STUBS_BUILD}/libnng_stub.a ${STUBS_BUILD}/pcbnew_embind.o" \
-DCMAKE_PREFIX_PATH="${SYSROOT};${WX_BUILD}" \