diff --git a/backend/src/routes/auth.ts b/backend/src/routes/auth.ts index 9f50e4d..7a031cc 100644 --- a/backend/src/routes/auth.ts +++ b/backend/src/routes/auth.ts @@ -247,7 +247,7 @@ export async function authRoutes(app: FastifyInstance) { }) .returning(); - app.log.info(`User registered: ${username}`); + app.log.info(`[Auth] Account registered: username=${newUser.username}, userId=${newUser.id}`); return reply.status(201).send({ ok: true, @@ -376,7 +376,7 @@ export async function authRoutes(app: FastifyInstance) { { expiresIn: `${refreshTtlDays}d`, key: app.config.refreshSecret } ); - app.log.info(`User logged in: ${username} (rememberMe: ${rememberMe})`); + app.log.info(`[Auth] Login succeeded: username=${user.username}, userId=${user.id}, rememberMe=${rememberMe}`); // Cookie options: with maxAge for "remember me", without for session cookie const accessCookieOptions = rememberMe @@ -807,7 +807,7 @@ export async function authRoutes(app: FastifyInstance) { // Delete user - cascade delete handles all related data await db.delete(users).where(eq(users.id, authUser.id)); - app.log.info(`User deleted account: ${authUser.username} (ID: ${authUser.id})`); + app.log.info(`[Auth] Account deleted: username=${authUser.username}, userId=${authUser.id}`); // Clear auth cookies return reply diff --git a/backend/src/routes/oidc.ts b/backend/src/routes/oidc.ts index f84faa3..c3d7865 100644 --- a/backend/src/routes/oidc.ts +++ b/backend/src/routes/oidc.ts @@ -238,7 +238,7 @@ export async function oidcRoutes(app: FastifyInstance) { // Set cookies (use app's centralized cookie options) request.log.debug( - `[OIDC] Setting cookies for user ${user.username}, NODE_ENV=${env.NODE_ENV}, secure=${app.config.cookieOptions.secure}` + `[OIDC] Setting auth cookies for username=${user.username}, userId=${user.id}, NODE_ENV=${env.NODE_ENV}, secure=${app.config.cookieOptions.secure}` ); setAuthCookies(app, reply, accessToken, refreshToken); diff --git a/backend/src/routes/planner.ts b/backend/src/routes/planner.ts index b36f553..a0561b1 100644 --- a/backend/src/routes/planner.ts +++ b/backend/src/routes/planner.ts @@ -40,13 +40,6 @@ function escapeHtml(text: string): string { return text.replace(/[&<>"']/g, (char) => htmlEscapes[char] || char); } -function maskEmail(email: string): string { - const [localPart, domain] = email.split("@"); - if (!domain) return "invalid-email"; - if (localPart.length <= 2) return `${localPart[0] ?? "*"}*@${domain}`; - return `${localPart.slice(0, 2)}***@${domain}`; -} - type MailDeliveryInfo = { accepted?: unknown; rejected?: unknown; @@ -256,10 +249,7 @@ export async function plannerRoutes(app: FastifyInstance) { }, async (request, reply) => { const { email, from, until, rows, language: bodyLanguage } = request.body; - request.log.info( - { hasEmail: Boolean(email), rowCount: rows?.length ?? 0 }, - "[Planner] Demand notification request received" - ); + request.log.info({ email, rowCount: rows?.length ?? 0 }, "[Planner] Demand notification request received"); if (!rows || rows.length === 0) { return reply.status(400).send({ error: "Missing planner data" }); @@ -277,6 +267,7 @@ export async function plannerRoutes(app: FastifyInstance) { request.log.warn("[Planner] Demand notification skipped: no active medications in request"); return reply.status(400).send({ error: "No active medications to notify" }); } + const activeMedicationNames = activeRows.map((row) => row.medicationName); const userSettings = await loadUserSettings(userId); const notificationSettings = { @@ -291,6 +282,8 @@ export async function plannerRoutes(app: FastifyInstance) { pushEnabled: notificationSettings.shoutrrrEnabled, hasPushUrl: Boolean(notificationSettings.shoutrrrUrl), activeRowCount: activeRows.length, + recipientEmail: email, + medications: activeMedicationNames, }, "[Planner] Demand notification channel state" ); @@ -377,13 +370,14 @@ ${getFooterPlain(language)}`; request.log.info( { + userId, hasSmtpHost: Boolean(smtpHost), hasSmtpUser: Boolean(smtpUser), hasSmtpPass: Boolean(smtpPass), smtpPort, smtpSecure, hasSmtpFrom: Boolean(smtpFrom), - to: maskEmail(email), + recipientEmail: email, }, "[Planner] Demand email path selected" ); @@ -494,7 +488,7 @@ ${getFooterPlain(language)}`; }, }); - request.log.info({ to: maskEmail(email) }, "[Planner] Sending demand email"); + request.log.info({ userId, recipientEmail: email }, "[Planner] Sending demand email"); const mailResult = await transporter.sendMail({ from: smtpFrom, @@ -509,19 +503,23 @@ ${getFooterPlain(language)}`; throw new Error(deliveryError); } - request.log.info({ to: maskEmail(email), messageId: mailResult.messageId }, "[Planner] Demand email sent"); + request.log.info( + { userId, recipientEmail: email, messageId: mailResult.messageId }, + "[Planner] Demand email sent" + ); results.email = true; } catch (error) { - request.log.error({ error, to: maskEmail(email) }, "[Planner] Demand email failed"); + request.log.error({ userId, recipientEmail: email, error }, "[Planner] Demand email failed"); const errorMessage = error instanceof Error ? error.message : "Unknown error"; results.errors.push(`Email: ${errorMessage}`); } } else { request.log.warn( { + userId, hasSmtpHost: Boolean(smtpHost), hasSmtpUser: Boolean(smtpUser), - to: maskEmail(email), + recipientEmail: email, }, "[Planner] Demand email skipped: SMTP not configured" ); @@ -612,7 +610,7 @@ ${getFooterPlain(language)}`; async (request, reply) => { const { email, lowStock } = request.body; request.log.info( - { hasEmail: Boolean(email), lowStockCount: lowStock?.length ?? 0 }, + { email, lowStockCount: lowStock?.length ?? 0 }, "[ReminderManual] Stock reminder request received" ); @@ -641,6 +639,7 @@ ${getFooterPlain(language)}`; request.log.warn("[ReminderManual] Stock reminder skipped: no active medications after filtering"); return reply.status(400).send({ error: "No active medications to notify" }); } + const filteredMedicationNames = filteredLowStock.map((item) => item.name); const userSettings = await loadUserSettings(userId); const notificationSettings = { @@ -655,6 +654,8 @@ ${getFooterPlain(language)}`; pushEnabled: notificationSettings.shoutrrrEnabled, hasPushUrl: Boolean(notificationSettings.shoutrrrUrl), filteredLowStockCount: filteredLowStock.length, + recipientEmail: email, + medications: filteredMedicationNames, }, "[ReminderManual] Stock reminder channel state" ); @@ -731,13 +732,14 @@ ${getFooterPlain(language)}`; request.log.info( { + userId, hasSmtpHost: Boolean(smtpHost), hasSmtpUser: Boolean(smtpUser), hasSmtpPass: Boolean(smtpPass), smtpPort, smtpSecure, hasSmtpFrom: Boolean(smtpFrom), - to: maskEmail(email), + recipientEmail: email, }, "[ReminderManual] Stock email path selected" ); @@ -855,7 +857,7 @@ ${getFooterPlain(language)}`; }, }); - request.log.info({ to: maskEmail(email) }, "[ReminderManual] Sending stock reminder email"); + request.log.info({ userId, recipientEmail: email }, "[ReminderManual] Sending stock reminder email"); const mailResult = await transporter.sendMail({ from: smtpFrom, @@ -871,21 +873,22 @@ ${getFooterPlain(language)}`; } request.log.info( - { to: maskEmail(email), messageId: mailResult.messageId }, + { userId, recipientEmail: email, messageId: mailResult.messageId }, "[ReminderManual] Stock reminder email sent" ); results.email = true; } catch (error) { - request.log.error({ error, to: maskEmail(email) }, "[ReminderManual] Stock reminder email failed"); + request.log.error({ userId, recipientEmail: email, error }, "[ReminderManual] Stock reminder email failed"); const errorMessage = error instanceof Error ? error.message : "Unknown error"; results.errors.push(`Email: ${errorMessage}`); } } else { request.log.warn( { + userId, hasSmtpHost: Boolean(smtpHost), hasSmtpUser: Boolean(smtpUser), - to: maskEmail(email), + recipientEmail: email, }, "[ReminderManual] Stock reminder email skipped: SMTP not configured" ); @@ -983,7 +986,7 @@ ${getFooterPlain(language)}`; async (request, reply) => { const { email, prescriptionLow } = request.body; request.log.info( - { hasEmail: Boolean(email), prescriptionCount: prescriptionLow?.length ?? 0 }, + { email, prescriptionCount: prescriptionLow?.length ?? 0 }, "[ReminderManual] Prescription reminder request received" ); @@ -1002,10 +1005,23 @@ ${getFooterPlain(language)}`; request.log.warn("[ReminderManual] Prescription reminder skipped: no active medications after filtering"); return reply.status(400).send({ error: "No active medications to notify" }); } + const filteredMedicationNames = filteredPrescriptionLow.map((item) => item.name); const userSettings = await loadUserSettings(userId); const language = (userSettings.language as Language) || "en"; const tr = getTranslations(language); + request.log.info( + { + userId, + emailEnabled: userSettings.emailEnabled, + pushEnabled: userSettings.shoutrrrEnabled, + hasPushUrl: Boolean(userSettings.shoutrrrUrl), + prescriptionCount: filteredPrescriptionLow.length, + recipientEmail: email, + medications: filteredMedicationNames, + }, + "[ReminderManual] Prescription reminder channel state" + ); const emptyRx = filteredPrescriptionLow.filter((item) => item.remainingRefills <= 0); const lowRx = filteredPrescriptionLow.filter((item) => item.remainingRefills > 0); @@ -1039,13 +1055,14 @@ ${getFooterPlain(language)}`; request.log.info( { + userId, hasSmtpHost: Boolean(smtpHost), hasSmtpUser: Boolean(smtpUser), hasSmtpPass: Boolean(smtpPass), smtpPort, smtpSecure, hasSmtpFrom: Boolean(smtpFrom), - to: maskEmail(email), + recipientEmail: email, }, "[ReminderManual] Prescription email path selected" ); @@ -1133,7 +1150,7 @@ ${getFooterPlain(language)}`; `; - request.log.info({ to: maskEmail(email) }, "[ReminderManual] Sending prescription reminder email"); + request.log.info({ userId, recipientEmail: email }, "[ReminderManual] Sending prescription reminder email"); const mailResult = await transporter.sendMail({ from: smtpFrom, @@ -1149,21 +1166,25 @@ ${getFooterPlain(language)}`; } request.log.info( - { to: maskEmail(email), messageId: mailResult.messageId }, + { userId, recipientEmail: email, messageId: mailResult.messageId }, "[ReminderManual] Prescription reminder email sent" ); results.email = true; } catch (error) { - request.log.error({ error, to: maskEmail(email) }, "[ReminderManual] Prescription reminder email failed"); + request.log.error( + { userId, recipientEmail: email, error }, + "[ReminderManual] Prescription reminder email failed" + ); const errorMessage = error instanceof Error ? error.message : "Unknown error"; results.errors.push(`Email: ${errorMessage}`); } } else { request.log.warn( { + userId, hasSmtpHost: Boolean(smtpHost), hasSmtpUser: Boolean(smtpUser), - to: maskEmail(email), + recipientEmail: email, }, "[ReminderManual] Prescription reminder email skipped: SMTP not configured" ); diff --git a/backend/src/routes/settings.ts b/backend/src/routes/settings.ts index b3303aa..99d7a6b 100644 --- a/backend/src/routes/settings.ts +++ b/backend/src/routes/settings.ts @@ -97,13 +97,6 @@ const settingsErrorSchema = { }, }; -function maskEmail(email: string): string { - const [localPart, domain] = email.split("@"); - if (!domain) return "invalid-email"; - if (localPart.length <= 2) return `${localPart[0] ?? "*"}*@${domain}`; - return `${localPart.slice(0, 2)}***@${domain}`; -} - type MailDeliveryInfo = { accepted?: unknown; rejected?: unknown; @@ -668,7 +661,7 @@ export async function settingsRoutes(app: FastifyInstance) { request.log.info( { - to: maskEmail(email), + to: email, hasSmtpHost: Boolean(smtpHost), hasSmtpUser: Boolean(smtpUser), hasSmtpPass: Boolean(smtpPass), @@ -681,7 +674,7 @@ export async function settingsRoutes(app: FastifyInstance) { if (!smtpHost || !smtpUser) { request.log.warn( - { to: maskEmail(email), hasSmtpHost: Boolean(smtpHost), hasSmtpUser: Boolean(smtpUser) }, + { to: email, hasSmtpHost: Boolean(smtpHost), hasSmtpUser: Boolean(smtpUser) }, "[Settings] Test email skipped: SMTP not configured" ); return reply.status(400).send({ error: "SMTP not configured" }); @@ -698,7 +691,7 @@ export async function settingsRoutes(app: FastifyInstance) { }, }); - request.log.info({ to: maskEmail(email) }, "[Settings] Sending test email"); + request.log.info({ to: email }, "[Settings] Sending test email"); const mailResult = await transporter.sendMail({ from: smtpFrom, @@ -721,11 +714,11 @@ export async function settingsRoutes(app: FastifyInstance) { throw new Error(deliveryError); } - request.log.info({ to: maskEmail(email), messageId: mailResult.messageId }, "[Settings] Test email sent"); + request.log.info({ to: email, messageId: mailResult.messageId }, "[Settings] Test email sent"); return reply.send({ success: true, message: "Test email sent successfully" }); } catch (error) { - request.log.error({ error, to: maskEmail(email) }, "[Settings] Test email failed"); + request.log.error({ to: email, error }, "[Settings] Test email failed"); const failure = classifyTestEmailFailure(error); return reply.status(failure.status).send({ error: failure.message, code: failure.code }); } diff --git a/backend/src/services/intake-reminder-scheduler.ts b/backend/src/services/intake-reminder-scheduler.ts index d782e55..e2bbabf 100644 --- a/backend/src/services/intake-reminder-scheduler.ts +++ b/backend/src/services/intake-reminder-scheduler.ts @@ -91,19 +91,25 @@ function buildDoseIdForIntake(intake: UpcomingIntake & { medicationId: number; b return `${intake.medicationId}-${intake.blisterIndex}-${dateOnlyMs}`; } -async function resolveSchedulerUserDisplayName(userId: number): Promise { - const [userRow] = await db.select({ username: users.username }).from(users).where(eq(users.id, userId)).limit(1); - return userRow?.username?.trim() || `unknown-user-${userId}`; +async function getUsernameForLog(userId: number): Promise { + const user = await db.select({ username: users.username }).from(users).where(eq(users.id, userId)); + const username = user[0]?.username?.trim(); + return username && username.length > 0 ? username : `unknown-user-${userId}`; } -function formatIntakeDescriptor( - definitionIndex: number, - medicationName: string, - medicationId: number, - intake: { every: number; usage: number; start: string; intakeRemindersEnabled: boolean; takenBy: string | null } -): string { - const takenByPart = intake.takenBy ? `, takenBy=${intake.takenBy}` : ""; - return `Intake #${definitionIndex + 1} (index=${definitionIndex}, medication=${medicationName}, medicationId=${medicationId}, start=${intake.start}, every=${intake.every}d, usage=${intake.usage}, reminderEnabled=${intake.intakeRemindersEnabled}${takenByPart})`; +function formatIntakeLog(intake: { + medName: string; + medicationId: number; + blisterIndex: number; + intakeTime: Date; + intakeTimeStr: string; + usage: number; + doseUnit?: string; + takenBy?: string | null; +}): string { + const takenBy = intake.takenBy ? intake.takenBy : "none"; + const doseUnit = intake.doseUnit ?? "mg"; + return `${intake.medName} (medId=${intake.medicationId}, intakeIndex=${intake.blisterIndex}, time=${intake.intakeTime.toISOString()}, localTime=${intake.intakeTimeStr}, usage=${intake.usage} ${doseUnit}, takenBy=${takenBy})`; } async function autoMarkDueIntakesAsTaken( @@ -114,6 +120,9 @@ async function autoMarkDueIntakesAsTaken( logger: ServiceLogger ): Promise { if (settings.stockCalculationMode !== "automatic") { + logger.debug( + `[IntakeReminder] Auto-mark disabled for userId=${settings.userId} because stockCalculationMode=${settings.stockCalculationMode}` + ); return 0; } @@ -214,6 +223,19 @@ async function autoMarkDueIntakesAsTaken( dismissed: false, }); + logger.info( + `[IntakeReminder] Auto-marked intake for userId=${settings.userId}: ${formatIntakeLog({ + medName: intake.medName, + medicationId: intake.medicationId, + blisterIndex: intake.blisterIndex, + intakeTime: intake.intakeTime, + intakeTimeStr: intake.intakeTimeStr, + usage: intake.usage, + doseUnit: intake.doseUnit, + takenBy: intake.takenBy, + })}` + ); + existingDoseIds.add(doseId); trackedDoses.push({ id: 0, @@ -229,8 +251,10 @@ async function autoMarkDueIntakesAsTaken( } } - if (inserted > 0) { - logger.info(`[IntakeReminder] Auto-marked ${inserted} due intake dose(s) as taken`); + if (inserted === 0) { + logger.debug(`[IntakeReminder] Auto-mark completed for userId=${settings.userId}: no due intakes`); + } else { + logger.info(`[IntakeReminder] Auto-mark completed for userId=${settings.userId}: inserted=${inserted}`); } return inserted; @@ -417,55 +441,70 @@ async function checkAndSendIntakeReminders(logger: ServiceLogger): Promise // Get all user settings to iterate over each user const allUserSettings = await getAllUserSettings(); + logger.debug(`[IntakeReminder] Scheduler cycle loaded user settings count=${allUserSettings.length}`); if (allUserSettings.length === 0) { logger.debug(`[IntakeReminder] No users with settings found`); return; // No users with settings } - logger.debug(`[IntakeReminder] Evaluating ${allUserSettings.length} intake profile(s) for auto-marking`); - for (const userSettings of allUserSettings) { await checkAndSendIntakeRemindersForUser(userSettings, logger); } + + logger.debug(`[IntakeReminder] Scheduler cycle finished`); } export async function checkAndSendIntakeRemindersForUser( settings: UserSettings & { userId: number }, logger: ServiceLogger ): Promise { + const username = await getUsernameForLog(settings.userId); + logger.info( + `[IntakeReminder] Evaluating intake reminders for user=${username} (userId=${settings.userId}, emailEnabled=${settings.emailEnabled}, pushEnabled=${settings.shoutrrrEnabled}, skipTaken=${settings.skipRemindersForTakenDoses}, repeat=${settings.repeatRemindersEnabled}, mode=${settings.stockCalculationMode})` + ); + const language = settings.language; const tr = getTranslations(language); - const schedulerUserName = await resolveSchedulerUserDisplayName(settings.userId); - - logger.debug(`[IntakeReminder] Evaluating intake reminder profile for user '${schedulerUserName}'`); const rows = await db .select() .from(medications) - .where(eq(medications.userId, settings.userId)) - .orderBy(medications.id); + .where(and(eq(medications.userId, settings.userId), eq(medications.isObsolete, false))); + + const activeRows = rows.filter((med) => med.isObsolete !== true).sort((left, right) => left.id - right.id); const locale = getDateLocale(language); const tz = getTimezone(); - await autoMarkDueIntakesAsTaken(settings, rows, locale, tz, logger); + const autoMarkedCount = await autoMarkDueIntakesAsTaken(settings, activeRows, locale, tz, logger); + if (autoMarkedCount > 0) { + logger.info( + `[IntakeReminder] Auto-mark summary for user=${username} (userId=${settings.userId}): autoMarkedCount=${autoMarkedCount}` + ); + } + + if (settings.stockCalculationMode === "automatic" && settings.skipRemindersForTakenDoses) { + logger.info( + `[IntakeReminder] Reminder sending skipped for user=${username} (userId=${settings.userId}) because stockCalculationMode=automatic and skipRemindersForTakenDoses=true` + ); + return; + } // Check if any intake reminder notifications are enabled (granular check) const emailEnabled = settings.emailEnabled && settings.notificationEmail && settings.emailIntakeReminders; const shoutrrrEnabled = settings.shoutrrrEnabled && settings.shoutrrrUrl && settings.shoutrrrIntakeReminders; if (!emailEnabled && !shoutrrrEnabled) { + logger.debug( + `[IntakeReminder] Notification sending disabled for user=${username} (userId=${settings.userId}): both email and push intake reminders are off` + ); return; // No intake reminder notifications enabled for this user } - logger.debug( - `[IntakeReminder] Notifications enabled for current scheduler context (email:${emailEnabled}, shoutrrr:${shoutrrrEnabled})` - ); - // Build medication entries that have at least one reminder-enabled intake. // Intake-level reminders are the single source of truth. - const reminderEntries = rows + const reminderEntries = activeRows .map((med) => { const intakes = parseIntakesJson( med.intakesJson, @@ -478,42 +517,32 @@ export async function checkAndSendIntakeRemindersForUser( .filter((entry) => entry.intakesWithReminders.length > 0); if (reminderEntries.length === 0) { - logger.debug("[IntakeReminder] No medications have reminders enabled for current scheduler context"); + logger.debug( + `[IntakeReminder] No reminder-enabled intake definitions for user=${username} (userId=${settings.userId})` + ); return; // No medications have reminders enabled for this user } - logger.debug(`[IntakeReminder] Found ${reminderEntries.length} medications with reminders`); - const state = loadIntakeReminderState(); const allUpcoming: (UpcomingIntake & { medicationId: number; blisterIndex: number })[] = []; let scheduledIntakesTodayCount = 0; // Get start and end of today in user's timezone (for filtering today's doses only) const now = new Date(); - const checkMinuteStart = new Date(Math.floor(now.getTime() / 60000) * 60000); - const checkMinuteEnd = new Date(checkMinuteStart.getTime() + 60000); const todayStart = new Date(now.toLocaleString("en-US", { timeZone: tz })); todayStart.setHours(0, 0, 0, 0); const todayEnd = new Date(now.toLocaleString("en-US", { timeZone: tz })); todayEnd.setHours(23, 59, 59, 999); - logger.debug(`[IntakeReminder] Today range: ${todayStart.toISOString()} to ${todayEnd.toISOString()}`); - // Find intakes: upcoming ones in reminder window + past ones for repeat reminders for (const { med, intakes, intakesWithReminders } of reminderEntries) { // Medication-level takenBy (for fallback/display purposes) const medicationTakenBy = parseTakenByJson(med.takenByJson); const medDisplayName = med.name || med.genericName || ""; - logger.debug( - `[IntakeReminder] Processing medication '${medDisplayName}' (id=${med.id}) with ${intakes.length} intake definition(s)` - ); - // Process each intake separately to track blisterIndex intakesWithReminders.forEach((intake, _blisterIndex) => { const actualIndex = intakes.indexOf(intake); // Get the actual index in original array - const intakeDescriptor = formatIntakeDescriptor(actualIndex, medDisplayName, med.id, intake); - logger.debug(`[IntakeReminder] ${intakeDescriptor}`); const todaysIntakesForThisDefinition = getTodaysIntakes( medDisplayName, @@ -540,12 +569,6 @@ export async function checkAndSendIntakeRemindersForUser( med.id, med.doseUnit ?? "mg" ); - logger.debug( - `[IntakeReminder] ${intakeDescriptor} -> ${upcomingIntakes.length} intake(s) currently due for advance reminder (default ${REMINDER_MINUTES_BEFORE} min before intake, with catch-up while intake is still in the future)` - ); - logger.debug( - `[IntakeReminder] ${intakeDescriptor} -> ${todaysIntakesForThisDefinition.length} scheduled intake(s) today (independent of reminder window)` - ); // Add upcoming intakes for first reminders allUpcoming.push( @@ -558,15 +581,9 @@ export async function checkAndSendIntakeRemindersForUser( // If repeat reminders enabled, also check for missed intakes (past the intake time) if (settings.repeatRemindersEnabled) { - logger.debug( - `[IntakeReminder] ${intakeDescriptor} -> ${todaysIntakesForThisDefinition.length} candidate intake(s) for repeat reminders` - ); const missedIntakes = todaysIntakesForThisDefinition.filter( (todayIntake) => todayIntake.intakeTime.getTime() < now.getTime() ); - logger.debug( - `[IntakeReminder] ${intakeDescriptor} -> ${missedIntakes.length} missed intake(s) (past intake time)` - ); // Add missed intakes for repeat reminders (only if not already in upcoming list) const upcomingTimes = new Set(upcomingIntakes.map((i) => i.intakeTime.getTime())); @@ -583,16 +600,17 @@ export async function checkAndSendIntakeRemindersForUser( }); } - logger.debug(`[IntakeReminder] Total scheduled intakes for today: ${scheduledIntakesTodayCount}`); - logger.debug(`[IntakeReminder] Total reminder candidates in current check: ${allUpcoming.length}`); - if (allUpcoming.length === 0) { logger.debug( - `[IntakeReminder] No reminder due in this check window (minute=${checkMinuteStart.toISOString()}..${checkMinuteEnd.toISOString()}, advanceLead=${REMINDER_MINUTES_BEFORE}m, plus catch-up while intake is still future)` + `[IntakeReminder] No upcoming intakes in reminder window for user=${username} (userId=${settings.userId}, scheduledToday=${scheduledIntakesTodayCount})` ); return; // No upcoming intakes for today } + logger.info( + `[IntakeReminder] Candidate intakes for user=${username} (userId=${settings.userId}): scheduledToday=${scheduledIntakesTodayCount}, candidates=${allUpcoming.length}` + ); + // Determine which doses need reminders (new or repeated) const nowMs = Date.now(); const maxReminders = settings.maxNaggingReminders ?? 5; @@ -620,9 +638,6 @@ export async function checkAndSendIntakeRemindersForUser( // Recently missed — scheduler likely recovered from sleep/restart. // Send a catch-up reminder (counts as first nagging reminder). remindersToSend.push({ ...intake, currentSendCount: 1, maxReminders, isAdvanceReminder: false }); - logger.info( - `[IntakeReminder] Catch-up reminder for recently missed intake (${Math.round(minutesSinceIntake)} min ago)` - ); } else { // Long ago — seed state without notification (user likely already noticed) state.reminders[key] = { @@ -631,14 +646,10 @@ export async function checkAndSendIntakeRemindersForUser( sendCount: 0, advanceSent: false, }; - logger.debug( - `[IntakeReminder] Seeding state for old past intake (no notification — ${Math.round(minutesSinceIntake)} min ago)` - ); } } else { // Upcoming - this is advance reminder (no counter) remindersToSend.push({ ...intake, currentSendCount: 0, maxReminders, isAdvanceReminder: true }); - logger.debug("[IntakeReminder] Advance reminder candidate added"); } } else if (settings.repeatRemindersEnabled && isIntakePast) { // Intake time passed - check if we need to send nagging reminder @@ -650,23 +661,41 @@ export async function checkAndSendIntakeRemindersForUser( const currentNaggingCount = existingEntry.sendCount; if (currentNaggingCount >= maxReminders) { - // Max nagging reminders reached - stop - logger.debug(`[IntakeReminder] Max nagging (${maxReminders}) reached for intake reminder key`); } else if (timeSinceLastReminder >= intervalMs) { const nextSendCount = currentNaggingCount + 1; remindersToSend.push({ ...intake, currentSendCount: nextSendCount, maxReminders, isAdvanceReminder: false }); - logger.debug(`[IntakeReminder] Nagging reminder candidate added (${nextSendCount}/${maxReminders})`); } } // Else: Already sent and either repeats disabled or intake not yet past - skip } if (remindersToSend.length === 0) { + logger.debug( + `[IntakeReminder] No reminders to send for user=${username} (userId=${settings.userId}) after state/repeat evaluation` + ); return; // All reminders already sent and no repeats needed } + logger.info( + `[IntakeReminder] Reminders selected for user=${username} (userId=${settings.userId}): count=${remindersToSend.length} :: ${remindersToSend + .map((intake) => + formatIntakeLog({ + medName: intake.medName, + medicationId: intake.medicationId, + blisterIndex: intake.blisterIndex, + intakeTime: intake.intakeTime, + intakeTimeStr: intake.intakeTimeStr, + usage: intake.usage, + doseUnit: intake.doseUnit, + takenBy: intake.takenBy, + }) + ) + .join(" | ")}` + ); + // If skipRemindersForTakenDoses is enabled, filter out doses that were already taken today if (settings.skipRemindersForTakenDoses) { + const beforeFilterCount = remindersToSend.length; // Query doses marked as taken today (takenAt is timestamp, stored as seconds since epoch) const takenToday = await db .select() @@ -692,29 +721,30 @@ export async function checkAndSendIntakeRemindersForUser( // For person-specific intake, check if that person has taken it const doseId = `${intake.medicationId}-${intake.blisterIndex}-${dateOnlyMs}-${intake.takenBy}`; const isTaken = takenDoseIds.has(doseId); - if (isTaken) { - logger.debug("[IntakeReminder] Skipping reminder candidate - dose already taken"); - } return !isTaken; } else { // For non-person-specific intakes const doseId = `${intake.medicationId}-${intake.blisterIndex}-${dateOnlyMs}`; const isTaken = takenDoseIds.has(doseId); - if (isTaken) { - logger.debug("[IntakeReminder] Skipping reminder candidate - dose already taken"); - } return !isTaken; } }); + const filteredOutCount = beforeFilterCount - remindersToSend.length; + if (filteredOutCount > 0) { + logger.info( + `[IntakeReminder] Removed reminders for already taken doses for user=${username} (userId=${settings.userId}): removed=${filteredOutCount}, remaining=${remindersToSend.length}` + ); + } + if (remindersToSend.length === 0) { - logger.debug("[IntakeReminder] All doses taken, skipping reminders"); + logger.info( + `[IntakeReminder] All candidate reminders already taken for user=${username} (userId=${settings.userId}); nothing to send` + ); return; } } - logger.info(`[IntakeReminder] Sending reminder for ${remindersToSend.length} intakes...`); - // Determine if this is a repeat reminder: // - Any intake already has a state entry AND is past (repeat after first reminder) // - OR intake is past even without state entry (missed the 15-min window) @@ -744,10 +774,14 @@ export async function checkAndSendIntakeRemindersForUser( hasNaggingReminder ? maxReminderCount : undefined ); emailSuccess = result.success; - if (result.success) { - logger.info("[IntakeReminder] Email sent successfully"); + if (!result.success) { + logger.error( + `[IntakeReminder] Email delivery failed for user=${username} (userId=${settings.userId}): ${result.error}` + ); } else { - logger.error(`[IntakeReminder] Failed to send email: ${result.error}`); + logger.info( + `[IntakeReminder] Email delivered for user=${username} (userId=${settings.userId}, recipient=${settings.notificationEmail}, reminders=${remindersToSend.length}, messageId=${result.messageId ?? "n/a"})` + ); } } @@ -810,10 +844,14 @@ export async function checkAndSendIntakeRemindersForUser( const result = await sendShoutrrrNotification(settings.shoutrrrUrl!, title, message); shoutrrrSuccess = result.success; - if (result.success) { - logger.info("[IntakeReminder] Push notification sent successfully"); + if (!result.success) { + logger.error( + `[IntakeReminder] Push delivery failed for user=${username} (userId=${settings.userId}): ${result.error}` + ); } else { - logger.error(`[IntakeReminder] Failed to send push: ${result.error}`); + logger.info( + `[IntakeReminder] Push delivered for user=${username} (userId=${settings.userId}, reminders=${remindersToSend.length})` + ); } } @@ -880,6 +918,13 @@ export async function checkAndSendIntakeRemindersForUser( const medName = firstReminder?.medName; const takenBy = firstReminder?.takenBy || undefined; await updateUserReminderSentTime(settings.userId, "intake", channel, medName, takenBy); + logger.info( + `[IntakeReminder] Reminder state persisted for user=${username} (userId=${settings.userId}, channel=${channel}, reminders=${remindersToSend.length}, firstMed=${medName ?? "n/a"}, firstTakenBy=${takenBy ?? "none"})` + ); + } else { + logger.info( + `[IntakeReminder] No reminder channel succeeded for user=${username} (userId=${settings.userId}, remindersAttempted=${remindersToSend.length})` + ); } } diff --git a/backend/src/test/intake-reminder-scheduler.test.ts b/backend/src/test/intake-reminder-scheduler.test.ts index fe516b4..05b868d 100644 --- a/backend/src/test/intake-reminder-scheduler.test.ts +++ b/backend/src/test/intake-reminder-scheduler.test.ts @@ -18,6 +18,14 @@ function createLogger() { }; } +function mockSelectWhere(result: T) { + return { + from: () => ({ + where: async () => result, + }), + } as never; +} + describe("checkAndSendIntakeRemindersForUser", () => { const mockedDb = vi.mocked(db); let originalTz: string | undefined; @@ -45,73 +53,43 @@ describe("checkAndSendIntakeRemindersForUser", () => { const insertMock = vi.mocked(mockedDb.insert); selectMock - .mockImplementationOnce( - () => - ({ - from: () => ({ - where: () => ({ - limit: async () => [{ username: "auto-user" }], - }), - }), - }) as never + .mockImplementationOnce(() => mockSelectWhere([{ username: "test-user" }])) + .mockImplementationOnce(() => + mockSelectWhere([ + { + id: 7, + userId: 11, + name: "Vitamin D", + genericName: null, + takenByJson: null, + packageType: "blister", + medicationForm: "tablet", + packCount: 1, + blistersPerPack: 1, + pillsPerBlister: 10, + looseTablets: 0, + stockAdjustment: 0, + pillWeightMg: null, + doseUnit: "mg", + isObsolete: false, + intakeRemindersEnabled: false, + intakesJson: JSON.stringify([ + { + usage: 1, + every: 1, + start: "2026-01-05T08:00:00.000Z", + takenBy: null, + intakeRemindersEnabled: false, + }, + ]), + usageJson: "[]", + everyJson: "[]", + startJson: "[]", + }, + ]) ) - .mockImplementationOnce( - () => - ({ - from: () => ({ - where: () => ({ - orderBy: async () => [ - { - id: 7, - userId: 11, - name: "Vitamin D", - genericName: null, - takenByJson: null, - packageType: "blister", - medicationForm: "tablet", - packCount: 1, - blistersPerPack: 1, - pillsPerBlister: 10, - looseTablets: 0, - stockAdjustment: 0, - pillWeightMg: null, - doseUnit: "mg", - isObsolete: false, - intakeRemindersEnabled: false, - intakesJson: JSON.stringify([ - { - usage: 1, - every: 1, - start: "2026-01-05T08:00:00.000Z", - takenBy: null, - intakeRemindersEnabled: false, - }, - ]), - usageJson: "[]", - everyJson: "[]", - startJson: "[]", - }, - ], - }), - }), - }) as never - ) - .mockImplementationOnce( - () => - ({ - from: () => ({ - where: async () => [], - }), - }) as never - ) - .mockImplementationOnce( - () => - ({ - from: () => ({ - where: async () => [], - }), - }) as never - ); + .mockImplementationOnce(() => mockSelectWhere([])) + .mockImplementationOnce(() => mockSelectWhere([])); insertMock.mockImplementation( () => @@ -148,7 +126,7 @@ describe("checkAndSendIntakeRemindersForUser", () => { takenSource: "automatic", dismissed: false, }); - expect(logger.info).toHaveBeenCalledWith("[IntakeReminder] Auto-marked 1 due intake dose(s) as taken"); + expect(logger.info).toHaveBeenCalledWith("[IntakeReminder] Auto-mark completed for userId=11: inserted=1"); }); it("does not auto-mark due intakes when current stock is empty", async () => { @@ -157,73 +135,43 @@ describe("checkAndSendIntakeRemindersForUser", () => { const insertMock = vi.mocked(mockedDb.insert); selectMock - .mockImplementationOnce( - () => - ({ - from: () => ({ - where: () => ({ - limit: async () => [{ username: "auto-user" }], - }), - }), - }) as never + .mockImplementationOnce(() => mockSelectWhere([{ username: "test-user" }])) + .mockImplementationOnce(() => + mockSelectWhere([ + { + id: 7, + userId: 11, + name: "Vitamin D", + genericName: null, + takenByJson: null, + packageType: "blister", + medicationForm: "tablet", + packCount: 0, + blistersPerPack: 1, + pillsPerBlister: 10, + looseTablets: 0, + stockAdjustment: 0, + pillWeightMg: null, + doseUnit: "mg", + isObsolete: false, + intakeRemindersEnabled: false, + intakesJson: JSON.stringify([ + { + usage: 1, + every: 1, + start: "2026-01-05T08:00:00.000Z", + takenBy: null, + intakeRemindersEnabled: false, + }, + ]), + usageJson: "[]", + everyJson: "[]", + startJson: "[]", + }, + ]) ) - .mockImplementationOnce( - () => - ({ - from: () => ({ - where: () => ({ - orderBy: async () => [ - { - id: 7, - userId: 11, - name: "Vitamin D", - genericName: null, - takenByJson: null, - packageType: "blister", - medicationForm: "tablet", - packCount: 0, - blistersPerPack: 1, - pillsPerBlister: 10, - looseTablets: 0, - stockAdjustment: 0, - pillWeightMg: null, - doseUnit: "mg", - isObsolete: false, - intakeRemindersEnabled: false, - intakesJson: JSON.stringify([ - { - usage: 1, - every: 1, - start: "2026-01-05T08:00:00.000Z", - takenBy: null, - intakeRemindersEnabled: false, - }, - ]), - usageJson: "[]", - everyJson: "[]", - startJson: "[]", - }, - ], - }), - }), - }) as never - ) - .mockImplementationOnce( - () => - ({ - from: () => ({ - where: async () => [], - }), - }) as never - ) - .mockImplementationOnce( - () => - ({ - from: () => ({ - where: async () => [], - }), - }) as never - ); + .mockImplementationOnce(() => mockSelectWhere([])) + .mockImplementationOnce(() => mockSelectWhere([])); insertMock.mockImplementation( () => @@ -255,4 +203,81 @@ describe("checkAndSendIntakeRemindersForUser", () => { expect(insertedRows).toHaveLength(0); expect(logger.info).not.toHaveBeenCalledWith("[IntakeReminder] Auto-marked 1 due intake dose(s) as taken"); }); + + it("suppresses intake notifications entirely when automatic mode and skip-taken reminders are both enabled", async () => { + const insertedRows: Array> = []; + const selectMock = vi.mocked(mockedDb.select); + const insertMock = vi.mocked(mockedDb.insert); + + selectMock + .mockImplementationOnce(() => mockSelectWhere([{ username: "test-user" }])) + .mockImplementationOnce(() => + mockSelectWhere([ + { + id: 7, + userId: 11, + name: "Vitamin D", + genericName: null, + takenByJson: null, + packageType: "blister", + medicationForm: "tablet", + packCount: 1, + blistersPerPack: 1, + pillsPerBlister: 10, + looseTablets: 0, + stockAdjustment: 0, + pillWeightMg: null, + doseUnit: "mg", + isObsolete: false, + intakeRemindersEnabled: true, + intakesJson: JSON.stringify([ + { + usage: 1, + every: 1, + start: "2026-01-05T08:00:00.000Z", + takenBy: null, + intakeRemindersEnabled: true, + }, + ]), + usageJson: "[]", + everyJson: "[]", + startJson: "[]", + }, + ]) + ) + .mockImplementationOnce(() => mockSelectWhere([])) + .mockImplementationOnce(() => mockSelectWhere([])); + + insertMock.mockImplementation( + () => + ({ + values: async (row: Record) => { + insertedRows.push(row); + }, + }) as never + ); + + const logger = createLogger(); + + await checkAndSendIntakeRemindersForUser( + { + userId: 11, + language: "en", + stockCalculationMode: "automatic", + skipRemindersForTakenDoses: true, + emailEnabled: true, + notificationEmail: "user@example.com", + emailIntakeReminders: true, + shoutrrrEnabled: false, + shoutrrrUrl: null, + shoutrrrIntakeReminders: false, + repeatRemindersEnabled: false, + } as never, + logger as never + ); + + expect(insertedRows).toHaveLength(1); + expect(logger.info).not.toHaveBeenCalledWith("[IntakeReminder] Sending reminder for 1 intakes..."); + expect(logger.error).not.toHaveBeenCalled(); + }); }); diff --git a/frontend/src/i18n/de.json b/frontend/src/i18n/de.json index cd5cf51..eafc1c7 100644 --- a/frontend/src/i18n/de.json +++ b/frontend/src/i18n/de.json @@ -314,7 +314,7 @@ "prescriptionReminders": "Rezept-Erinnerungen", "enableHint": "Aktiviere mindestens einen Kanal, um Benachrichtigungen zu erhalten.", "skipTakenDoses": "Keine Erinnerungen für genommene Dosen", - "skipTakenDosesTooltip": "Sende keine Einnahme-Erinnerungen für Dosen, die heute bereits als genommen markiert wurden", + "skipTakenDosesTooltip": "Sende keine Einnahme-Erinnerungen für Dosen, die heute bereits als genommen markiert wurden. Wenn diese Option und die automatische Einnahme gleichzeitig aktiviert sind, werden gar keine Einnahme-Erinnerungen mehr gesendet.", "repeatReminders": "Wiederholte Erinnerungen für verpasste Dosen", "repeatRemindersTooltip": "Sende automatisch wiederholte Erinnerungen für Dosen, die noch nicht als genommen markiert wurden", "reminderInterval": "Erinnerungsintervall (Minuten)", diff --git a/frontend/src/i18n/en.json b/frontend/src/i18n/en.json index 003e1aa..d93827a 100644 --- a/frontend/src/i18n/en.json +++ b/frontend/src/i18n/en.json @@ -314,7 +314,7 @@ "prescriptionReminders": "Prescription Reminders", "enableHint": "Enable at least one channel below to receive notifications.", "skipTakenDoses": "Skip reminders for taken doses", - "skipTakenDosesTooltip": "Don't send intake reminders for doses that have already been marked as taken today", + "skipTakenDosesTooltip": "Don't send intake reminders for doses that have already been marked as taken today. If this option and automatic intake are both enabled, no intake reminders will be sent.", "repeatReminders": "Repeat reminders for missed doses", "repeatRemindersTooltip": "Automatically send repeated reminders for doses that haven't been marked as taken", "reminderInterval": "Reminder interval (minutes)",