diag(#7): env-gated per-relay transport instrumentation

Add NSEC_BUNKER_DEBUG_TRANSPORT=1 opt-in logging that emits REQUEST_IN
on inbound NIP-46 RPCs, RESPONSE_SENT around NDKNostrRpc.sendResponse,
and PUBLISHED / PUBLISH_FAILED per-relay on the bunker's pool. Surfaces
the diagnostic signal NDKNostrRpc itself discards: sendResponse calls
`event.publish(this.relaySet)` and throws away the Set<NDKRelay> it
returns, so silent outbox-drops and wrong-kind responses are invisible
without hooking the pool's per-relay events directly.

Validated against the local bunker via the lnbits-side admin spike
harness (~/dev/lnbits/misc-aio/bunker_admin_spike.py): the instrumentation
made the 9-step harness reveal a wrong-kind error response path (separate
fix in the next commit) that had been masquerading as an NDK echo issue
for a week. With the env flag unset the daemon stays as quiet as before.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
This commit is contained in:
Padreug 2026-05-27 16:56:27 +02:00
commit 8caf856ab2

View file

@ -111,8 +111,28 @@ class AdminInterface {
return;
}
this.ndk.pool.on('relay:connect', () => console.log('✅ nsecBunker Admin Interface ready'));
const debugTransport = process.env.NSEC_BUNKER_DEBUG_TRANSPORT === '1';
// Per-relay publish-status logging for diagnosing aiolabs/nsecbunkerd#7.
// NDKNostrRpc.sendResponse calls event.publish() and discards the
// returned Set<NDKRelay>, so a silent outbox-drop is invisible without
// hooking the underlying per-relay events. Gated by env flag so
// production deployments stay quiet.
const attachRelayLogging = (relay: any) => {
relay.on('published', (event: NDKEvent) => {
console.log(`📤 PUBLISHED relay=${relay.url} kind=${event.kind} id=${event.id?.slice(0,8)}`);
});
relay.on('publish:failed', (event: NDKEvent, err: any) => {
console.log(`❌ PUBLISH_FAILED relay=${relay.url} kind=${event.kind} id=${event.id?.slice(0,8)} err=${err?.message ?? err}`);
});
};
this.ndk.pool.on('relay:connect', (relay: any) => {
console.log('✅ nsecBunker Admin Interface ready');
if (debugTransport) attachRelayLogging(relay);
});
this.ndk.pool.on('relay:disconnect', () => console.log('❌ admin disconnected'));
this.ndk.connect(2500).then(() => {
// connect for whitelisted admins
this.rpc.subscribe({
@ -120,7 +140,33 @@ class AdminInterface {
"#p": [this.signerUser!.pubkey]
});
this.rpc.on('request', (req) => this.handleRequest(req));
// Attach per-relay logging to relays that connected before our
// 'relay:connect' listener was registered above (NDK can connect
// synchronously inside .connect() under some paths).
if (debugTransport) {
this.ndk.pool.relays.forEach((relay: any) => attachRelayLogging(relay));
// Wrap sendResponse to log id + kind + elapsed time so we
// can correlate REQUEST_IN → RESPONSE_SENT → PUBLISHED.
const originalSendResponse = this.rpc.sendResponse.bind(this.rpc);
this.rpc.sendResponse = async (id: string, remotePubkey: string, result: string, kind?: number, error?: string) => {
const start = Date.now();
try {
await originalSendResponse(id, remotePubkey, result, kind, error);
console.log(`📨 RESPONSE_SENT id=${id} remote=${remotePubkey.slice(0,8)} kind=${kind ?? NDKKind.NostrConnect} elapsed=${Date.now()-start}ms`);
} catch (e: any) {
console.log(`❌ RESPONSE_SEND_FAILED id=${id} remote=${remotePubkey.slice(0,8)} kind=${kind ?? NDKKind.NostrConnect} err=${e?.message ?? e}`);
throw e;
}
};
}
this.rpc.on('request', (req) => {
if (debugTransport) {
console.log(`📥 REQUEST_IN method=${req.method} id=${req.id} from=${req.pubkey?.slice(0,8)} kind=${req.event?.kind}`);
}
this.handleRequest(req);
});
// pingOrDie disabled — NDK 2.8.1 outbox model doesn't echo
// self-published events back through subscriptions on