diff --git a/docs/logging.md b/docs/logging.md index f24b3f71..0f5f81bb 100644 --- a/docs/logging.md +++ b/docs/logging.md @@ -10,7 +10,9 @@ bitvid ships a frozen logger at `js/utils/logger.js` with two channels: - `logger.dev`: Emits only when `IS_DEV_MODE` is truthy. Use this channel for verbose traces, performance probes, and feature flag experimentation that - should disappear from production consoles. + should disappear from production consoles. The `logger.dev.debug` helper is + available for especially noisy traces that you want to keep isolated to local + development sessions. - `logger.user`: Always available and automatically prefixes output with `[bitvid]`. Use this channel for operator-facing warnings and errors that help diagnose issues in production. @@ -19,7 +21,7 @@ When adding new messages, classify them by the audience: | Scenario | Recommended channel | Notes | | --- | --- | --- | -| Debugging a new feature locally | `logger.dev.info`/`logger.dev.log` | Remove or downgrade before launching if they no longer serve a purpose. | +| Debugging a new feature locally | `logger.dev.debug`/`logger.dev.info` | Remove or downgrade before launching if they no longer serve a purpose. | | Non-fatal recoverable issues users should investigate | `logger.user.warn` | Provide actionable context so operators know what failed. | | Fatal errors that block playback or payments | `logger.user.error` | Escalate with a clear message and include relevant IDs or URLs. | | Metrics or noisy traces that only help during QA | `logger.dev.*` | Wrap expensive logging in conditional checks when possible. | diff --git a/js/feedEngine/stages.js b/js/feedEngine/stages.js index 15ad2e2b..8c845590 100644 --- a/js/feedEngine/stages.js +++ b/js/feedEngine/stages.js @@ -1,8 +1,10 @@ // js/feedEngine/stages.js import { getApplication } from "../applicationContext.js"; +import { IS_DEV_MODE } from "../config.js"; import nostrService from "../services/nostrService.js"; import moderationService from "../services/moderationService.js"; +import logger from "../utils/logger.js"; import { dedupeToNewestByRoot } from "../utils/videoDeduper.js"; import { isPlainObject, toSet } from "./utils.js"; @@ -500,6 +502,17 @@ export function createModerationStage({ metadataModeration.trustedMuteCount = trustedMuteCount; item.metadata.moderation = metadataModeration; + if (IS_DEV_MODE) { + logger.dev.debug("[feedEngine/moderation] metadata.moderation updated", { + stage: stageName, + videoId: videoId || null, + blockAutoplay, + blurThumbnail, + trustedCount, + reportType: normalizedReportType, + }); + } + if (!video.moderation || typeof video.moderation !== "object") { video.moderation = {}; } diff --git a/js/services/moderationService.js b/js/services/moderationService.js index 65258253..05d9f62d 100644 --- a/js/services/moderationService.js +++ b/js/services/moderationService.js @@ -4,6 +4,20 @@ import { accessControl } from "../accessControl.js"; import { userBlocks, USER_BLOCK_EVENTS } from "../userBlocks.js"; import logger from "../utils/logger.js"; +const AUTOPLAY_TRUST_THRESHOLD = 2; +const BLUR_TRUST_THRESHOLD = 3; + +function normalizeUserLogger(candidate) { + if ( + candidate && + typeof candidate === "object" && + typeof candidate.info === "function" + ) { + return candidate; + } + return logger.user; +} + class SimpleEventEmitter { constructor(logHandler = null) { this.listeners = new Map(); @@ -310,9 +324,11 @@ export class ModerationService { logger: log = null, userBlocks: userBlockManager = null, accessControl: accessControlService = null, + userLogger: userChannel = null, } = {}) { this.nostrClient = client; this.log = normalizeLogger(log); + this.userLogger = normalizeUserLogger(userChannel); this.viewerPubkey = ""; this.trustedContacts = new Set(); @@ -350,6 +366,66 @@ export class ModerationService { this.setUserBlocks(userBlockManager); } + setUserLogger(channel) { + this.userLogger = normalizeUserLogger(channel); + } + + logThresholdTransitions({ + eventId = "", + reportType = "", + previousTrusted = 0, + nextTrusted = 0, + } = {}) { + const normalizedEventId = normalizeEventId(eventId); + const normalizedType = normalizeReportType(reportType); + if (!normalizedEventId || !normalizedType) { + return; + } + + const previous = Number.isFinite(previousTrusted) ? previousTrusted : 0; + const next = Number.isFinite(nextTrusted) ? nextTrusted : 0; + + const transitions = []; + + if (AUTOPLAY_TRUST_THRESHOLD > 0) { + const previousMet = previous >= AUTOPLAY_TRUST_THRESHOLD; + const nextMet = next >= AUTOPLAY_TRUST_THRESHOLD; + if (previousMet !== nextMet) { + transitions.push({ + action: nextMet ? "autoplay-block-enabled" : "autoplay-block-cleared", + }); + } + } + + if (BLUR_TRUST_THRESHOLD > 0) { + const previousMet = previous >= BLUR_TRUST_THRESHOLD; + const nextMet = next >= BLUR_TRUST_THRESHOLD; + if (previousMet !== nextMet) { + transitions.push({ + action: nextMet ? "blur-enabled" : "blur-cleared", + }); + } + } + + if (!transitions.length) { + return; + } + + const channel = this.userLogger || logger.user; + for (const entry of transitions) { + try { + channel.info("[moderationService] moderation threshold crossed", { + eventId: normalizedEventId, + reportType: normalizedType, + trustedCount: next, + action: entry.action, + }); + } catch (error) { + logger.user.warn("[moderationService] failed to log threshold transition", error); + } + } + } + setLogger(newLogger) { this.log = normalizeLogger(newLogger); } @@ -1512,11 +1588,29 @@ export class ModerationService { const eventReports = this.reportEvents.get(normalized); if (!eventReports || !eventReports.size) { + const previousSummary = this.reportSummaries.get(normalized); + if (previousSummary && previousSummary.types) { + for (const [type, detail] of Object.entries(previousSummary.types)) { + if (!detail || typeof detail !== "object") { + continue; + } + const previousTrusted = Number.isFinite(detail.trusted) ? detail.trusted : 0; + if (previousTrusted > 0) { + this.logThresholdTransitions({ + eventId: normalized, + reportType: type, + previousTrusted, + nextTrusted: 0, + }); + } + } + } this.reportSummaries.delete(normalized); this.emit("summary", { eventId: normalized, summary: null }); return; } + const previousSummary = this.reportSummaries.get(normalized); const typeStats = new Map(); let totalTrusted = 0; const adminSnapshot = this.getAdminListSnapshot(); @@ -1565,6 +1659,43 @@ export class ModerationService { }; } + if (previousSummary && previousSummary.types) { + const seen = new Set([ + ...Object.keys(previousSummary.types || {}), + ...Object.keys(types), + ]); + for (const type of seen) { + const previousEntry = previousSummary?.types?.[type]; + const nextEntry = types?.[type]; + const previousTrusted = Number.isFinite(previousEntry?.trusted) + ? previousEntry.trusted + : 0; + const nextTrusted = Number.isFinite(nextEntry?.trusted) + ? nextEntry.trusted + : 0; + if (previousTrusted !== nextTrusted) { + this.logThresholdTransitions({ + eventId: normalized, + reportType: type, + previousTrusted, + nextTrusted, + }); + } + } + } else { + for (const [type, stats] of Object.entries(types)) { + const nextTrusted = Number.isFinite(stats?.trusted) ? stats.trusted : 0; + if (nextTrusted > 0) { + this.logThresholdTransitions({ + eventId: normalized, + reportType: type, + previousTrusted: 0, + nextTrusted, + }); + } + } + } + const summary = { eventId: normalized, totalTrusted, diff --git a/js/utils/logger.js b/js/utils/logger.js index a819cd14..53289dfb 100644 --- a/js/utils/logger.js +++ b/js/utils/logger.js @@ -1,6 +1,8 @@ // js/utils/logger.js // Provides frozen logger channels so both modules and inline scripts share // consistent dev-vs-user logging semantics without duplicating feature gates. +// The dev channel now exposes a `debug` helper for high-volume traces that +// should never reach production consoles. import { isDevMode } from "../config.js"; @@ -23,6 +25,7 @@ function createConsoleAdapter() { return { log: NOOP, info: NOOP, + debug: NOOP, warn: NOOP, error: NOOP, }; @@ -33,6 +36,7 @@ function createConsoleAdapter() { return { log: typeof consoleRef.log === "function" ? consoleRef.log.bind(consoleRef) : fallback, info: typeof consoleRef.info === "function" ? consoleRef.info.bind(consoleRef) : fallback, + debug: typeof consoleRef.debug === "function" ? consoleRef.debug.bind(consoleRef) : fallback, warn: typeof consoleRef.warn === "function" ? consoleRef.warn.bind(consoleRef) : fallback, error: typeof consoleRef.error === "function" ? consoleRef.error.bind(consoleRef) : fallback, }; @@ -65,6 +69,10 @@ const devLogger = Object.freeze({ if (!isDevMode) return; consoleAdapter.info(...args); }, + debug: (...args) => { + if (!isDevMode) return; + consoleAdapter.debug(...args); + }, warn: (...args) => { if (!isDevMode) return; consoleAdapter.warn(...args); @@ -136,16 +144,17 @@ function isCompatibleLogger(candidate) { return false; } - const requiredChannels = ["dev", "user"]; - const requiredMethods = ["log", "info", "warn", "error"]; + const channelRequirements = { + dev: ["log", "info", "debug", "warn", "error"], + user: ["log", "info", "warn", "error"], + }; - return requiredChannels.every((channel) => { + return Object.entries(channelRequirements).every(([channel, methods]) => { const obj = candidate[channel]; - return ( - obj && - typeof obj === "object" && - requiredMethods.every((method) => typeof obj[method] === "function") - ); + if (!obj || typeof obj !== "object") { + return false; + } + return methods.every((method) => typeof obj[method] === "function"); }); } diff --git a/tests/moderation-service.test.mjs b/tests/moderation-service.test.mjs index 79d6c546..7610541d 100644 --- a/tests/moderation-service.test.mjs +++ b/tests/moderation-service.test.mjs @@ -22,6 +22,8 @@ if (typeof globalThis.window === "undefined") { globalThis.window = {}; } +const noopUserLogger = { info: () => {} }; + test("trusted report summaries respect personal blocks and admin lists", async (t) => { const previousTools = globalThis.NostrTools; const previousWindowTools = globalThis.window?.NostrTools; @@ -74,6 +76,7 @@ test("trusted report summaries respect personal blocks and admin lists", async ( logger: () => {}, userBlocks: userBlocksMock, accessControl: accessControlMock, + userLogger: noopUserLogger, }); service.trustedContacts = new Set([trustedHex]); @@ -138,7 +141,7 @@ test("user block updates recompute summaries and emit notifications", async (t) } const userBlocks = new FakeUserBlocks(); - const service = new ModerationService({ logger: () => {}, userBlocks }); + const service = new ModerationService({ logger: () => {}, userBlocks, userLogger: noopUserLogger }); service.trustedContacts = new Set([blockedHex, trustedHex]); @@ -220,8 +223,78 @@ test("user block updates recompute summaries and emit notifications", async (t) ); }); +test("moderation thresholds emit logger hooks only when crossing", async (t) => { + const calls = []; + const userLoggerMock = { + info: (...args) => { + calls.push(args); + }, + }; + + const service = new ModerationService({ logger: () => {}, userLogger: userLoggerMock }); + + const eventId = "9".repeat(64); + const reportType = "nudity"; + const trustedReporters = ["a".repeat(64), "b".repeat(64), "c".repeat(64)]; + + service.trustedContacts = new Set(trustedReporters); + + const reports = new Map(); + service.reportEvents.set(eventId, reports); + + const createReporterEntry = (timestamp) => new Map([[reportType, { created_at: timestamp }]]); + + const expectSingleAction = (expectedAction, expectedCount) => { + assert.equal(calls.length, 1); + const [message, detail] = calls[0]; + assert.equal(message, "[moderationService] moderation threshold crossed"); + assert.equal(detail.action, expectedAction); + assert.equal(detail.eventId, eventId); + assert.equal(detail.reportType, reportType); + assert.equal(detail.trustedCount, expectedCount); + calls.length = 0; + }; + + const expectNoAction = () => { + assert.equal(calls.length, 0); + }; + + reports.set(trustedReporters[0], createReporterEntry(100)); + service.recomputeSummaryForEvent(eventId); + expectNoAction(); + + reports.set(trustedReporters[1], createReporterEntry(200)); + service.recomputeSummaryForEvent(eventId); + expectSingleAction("autoplay-block-enabled", 2); + + service.recomputeSummaryForEvent(eventId); + expectNoAction(); + + reports.set(trustedReporters[2], createReporterEntry(300)); + service.recomputeSummaryForEvent(eventId); + expectSingleAction("blur-enabled", 3); + + service.recomputeSummaryForEvent(eventId); + expectNoAction(); + + reports.delete(trustedReporters[2]); + service.recomputeSummaryForEvent(eventId); + expectSingleAction("blur-cleared", 2); + + reports.delete(trustedReporters[1]); + service.recomputeSummaryForEvent(eventId); + expectSingleAction("autoplay-block-cleared", 1); + + reports.delete(trustedReporters[0]); + service.recomputeSummaryForEvent(eventId); + expectNoAction(); + + service.recomputeSummaryForEvent(eventId); + expectNoAction(); +}); + test("trusted mute aggregation tracks F1 mute lists", () => { - const service = new ModerationService({ logger: () => {} }); + const service = new ModerationService({ logger: () => {}, userLogger: noopUserLogger }); const contactA = "a".repeat(64); const contactB = "b".repeat(64); @@ -305,6 +378,7 @@ test("viewer mute list publishes and updates aggregation", async (t) => { const service = new ModerationService({ logger: () => {}, nostrClient, + userLogger: noopUserLogger, }); const previousNostr = globalThis.window.nostr;