Merge pull request #58 from xtr-dev/dev

Dev

package.json

@@ -1,6 +1,6 @@
 {
   "name": "@xtr-dev/payload-mailing",
-  "version": "0.4.8",
+  "version": "0.4.11",
   "description": "Template-based email system with scheduling and job processing for PayloadCMS",
   "type": "module",
   "main": "dist/index.js",

src/collections/Emails.ts

@@ -1,5 +1,6 @@
 import type { CollectionConfig } from 'payload'
 import { findExistingJobs, ensureEmailJob, updateEmailJobRelationship } from '../utils/jobScheduler.js'
+import { createContextLogger } from '../utils/logger.js'
 
 const Emails: CollectionConfig = {
   slug: 'emails',
@@ -220,7 +221,8 @@ const Emails: CollectionConfig = {
           }
         } catch (error) {
           // Log error but don't throw - we don't want to fail the email operation
-          console.error(`Failed to ensure job for email ${doc.id}:`, error)
+          const logger = createContextLogger(req.payload, 'EMAILS_HOOK')
+          logger.error(`Failed to ensure job for email ${doc.id}:`, error)
         }
       }
     ]

src/jobs/processEmailsTask.ts

@@ -1,5 +1,6 @@
 import type { PayloadRequest, Payload } from 'payload'
 import { processAllEmails } from '../utils/emailProcessor.js'
+import { createContextLogger } from '../utils/logger.js'
 
 /**
  * Data passed to the process emails task
@@ -67,7 +68,8 @@ export const scheduleEmailsJob = async (
   delay?: number
 ) => {
   if (!payload.jobs) {
-    console.warn('PayloadCMS jobs not configured - emails will not be processed automatically')
+    const logger = createContextLogger(payload, 'SCHEDULER')
+    logger.warn('PayloadCMS jobs not configured - emails will not be processed automatically')
     return
   }
 
@@ -79,6 +81,7 @@ export const scheduleEmailsJob = async (
       waitUntil: delay ? new Date(Date.now() + delay) : undefined,
     } as any)
   } catch (error) {
-    console.error('Failed to schedule email processing job:', error)
+    const logger = createContextLogger(payload, 'SCHEDULER')
+    logger.error('Failed to schedule email processing job:', error)
   }
 }

src/sendEmail.ts

@@ -2,6 +2,7 @@ import { Payload } from 'payload'
 import { getMailing, renderTemplate, parseAndValidateEmails, sanitizeFromName } from './utils/helpers.js'
 import { BaseEmailDocument } from './types/index.js'
 import { processJobById } from './utils/emailProcessor.js'
+import { createContextLogger } from './utils/logger.js'
 
 // Options for sending emails
 export interface SendEmailOptions<T extends BaseEmailDocument = BaseEmailDocument> {
@@ -137,6 +138,9 @@ export const sendEmail = async <TEmail extends BaseEmailDocument = BaseEmailDocu
 
   // If processImmediately is true, get the job from the relationship and process it now
   if (options.processImmediately) {
+    const logger = createContextLogger(payload, 'IMMEDIATE')
+    logger.debug(`Starting immediate processing for email ${email.id}`)
+
     if (!payload.jobs) {
       throw new Error('PayloadCMS jobs not configured - cannot process email immediately')
     }
@@ -149,6 +153,8 @@ export const sendEmail = async <TEmail extends BaseEmailDocument = BaseEmailDocu
     const startTime = Date.now()
     let jobId: string | undefined
 
+    logger.debug(`Polling for job creation (max ${maxAttempts} attempts, ${maxTotalTime}ms timeout)`)
+
     for (let attempt = 0; attempt < maxAttempts; attempt++) {
       // Check total timeout before continuing
       if (Date.now() - startTime > maxTotalTime) {
@@ -172,17 +178,19 @@ export const sendEmail = async <TEmail extends BaseEmailDocument = BaseEmailDocu
         id: email.id,
       })
 
+      logger.debug(`Attempt ${attempt + 1}/${maxAttempts}: Found ${emailWithJobs.jobs?.length || 0} jobs for email ${email.id}`)
+
       if (emailWithJobs.jobs && emailWithJobs.jobs.length > 0) {
         // Job found! Get the first job ID (should only be one for a new email)
-        jobId = Array.isArray(emailWithJobs.jobs)
+        const firstJob = Array.isArray(emailWithJobs.jobs) ? emailWithJobs.jobs[0] : emailWithJobs.jobs
-          ? String(emailWithJobs.jobs[0])
+        jobId = typeof firstJob === 'string' ? firstJob : String(firstJob.id || firstJob)
-          : String(emailWithJobs.jobs)
+        logger.info(`Found job ID: ${jobId}`)
         break
       }
 
       // Log on later attempts to help with debugging (reduced threshold)
-      if (attempt >= 2) {
+      if (attempt >= 1) {
-        console.log(`Waiting for job creation for email ${email.id}, attempt ${attempt + 1}/${maxAttempts}`)
+        logger.debug(`Waiting for job creation for email ${email.id}, attempt ${attempt + 1}/${maxAttempts}`)
       }
     }
 
@@ -204,9 +212,12 @@ export const sendEmail = async <TEmail extends BaseEmailDocument = BaseEmailDocu
       )
     }
 
+    logger.info(`Starting job execution for job ${jobId}`)
     try {
       await processJobById(payload, jobId)
+      logger.info(`Successfully processed email ${email.id} immediately`)
     } catch (error) {
+      logger.error(`Failed to process email ${email.id} immediately:`, error)
       throw new Error(`Failed to process email ${email.id} immediately: ${String(error)}`)
     }
   }

src/utils/emailProcessor.ts

@@ -1,4 +1,5 @@
 import type { Payload } from 'payload'
+import { createContextLogger } from './logger.js'
 
 /**
  * Processes a single email by ID using the mailing service
@@ -36,20 +37,28 @@ export async function processEmailById(payload: Payload, emailId: string): Promi
  * @returns Promise that resolves when job is processed
  */
 export async function processJobById(payload: Payload, jobId: string): Promise<void> {
+  const logger = createContextLogger(payload, 'PROCESSOR')
+  logger.debug(`Starting processJobById for job ${jobId}`)
+
   if (!payload.jobs) {
     throw new Error('PayloadCMS jobs not configured - cannot process job immediately')
   }
 
   try {
+    logger.debug(`Running job ${jobId} with payload.jobs.run()`)
+
     // Run a specific job by its ID (using where clause to find the job)
-    await payload.jobs.run({
+    const result = await payload.jobs.run({
       where: {
         id: {
           equals: jobId
         }
       }
     })
+
+    logger.info(`Job ${jobId} execution completed`, { result })
   } catch (error) {
+    logger.error(`Job ${jobId} execution failed:`, error)
     throw new Error(`Failed to process job ${jobId}: ${String(error)}`)
   }
 }

src/utils/jobScheduler.ts

@@ -1,4 +1,5 @@
 import type { Payload } from 'payload'
+import { createContextLogger } from './logger.js'
 
 /**
  * Finds existing processing jobs for an email
@@ -47,11 +48,16 @@ export async function ensureEmailJob(
   const mailingContext = (payload as any).mailing
   const queueName = options?.queueName || mailingContext?.config?.queue || 'default'
 
+  const logger = createContextLogger(payload, 'JOB_SCHEDULER')
+  logger.debug(`Ensuring job for email ${normalizedEmailId}`)
+  logger.debug(`Queue: ${queueName}, scheduledAt: ${options?.scheduledAt || 'immediate'}`)
+
   // First, optimistically try to create the job
   // If it fails due to uniqueness constraint, then check for existing jobs
   // This approach minimizes the race condition window
 
   try {
+    logger.debug(`Attempting to create new job for email ${normalizedEmailId}`)
     // Attempt to create job - rely on database constraints for duplicate prevention
     const job = await payload.jobs.queue({
       queue: queueName,
@@ -62,21 +68,32 @@ export async function ensureEmailJob(
       waitUntil: options?.scheduledAt ? new Date(options.scheduledAt) : undefined
     })
 
-    console.log(`Auto-scheduled processing job ${job.id} for email ${normalizedEmailId}`)
+    logger.info(`Auto-scheduled processing job ${job.id} for email ${normalizedEmailId}`)
+    logger.debug(`Job details`, {
+      jobId: job.id,
+      emailId: normalizedEmailId,
+      scheduledAt: options?.scheduledAt || 'immediate',
+      task: 'process-email',
+      queue: queueName
+    })
 
     return {
       jobIds: [job.id],
       created: true
     }
   } catch (createError) {
+    logger.warn(`Job creation failed for email ${normalizedEmailId}: ${String(createError)}`)
+
     // Job creation failed - likely due to duplicate constraint or system issue
 
     // Check if duplicate jobs exist (handles race condition where another process created job)
     const existingJobs = await findExistingJobs(payload, normalizedEmailId)
 
+    logger.debug(`Found ${existingJobs.totalDocs} existing jobs after creation failure`)
+
     if (existingJobs.totalDocs > 0) {
       // Found existing jobs - return them (race condition handled successfully)
-      console.log(`Found existing jobs for email ${normalizedEmailId}: ${existingJobs.docs.map(j => j.id).join(', ')}`)
+      logger.info(`Using existing jobs for email ${normalizedEmailId}: ${existingJobs.docs.map(j => j.id).join(', ')}`)
       return {
         jobIds: existingJobs.docs.map(job => job.id),
         created: false
@@ -92,6 +109,7 @@ export async function ensureEmailJob(
 
     if (isLikelyUniqueConstraint) {
       // This should not happen if our check above worked, but provide a clear error
+      logger.error(`Unique constraint violation but no existing jobs found for email ${normalizedEmailId}`)
       throw new Error(
         `Database uniqueness constraint violation for email ${normalizedEmailId}, but no existing jobs found. ` +
         `This indicates a potential data consistency issue. Original error: ${errorMessage}`
@@ -99,6 +117,7 @@ export async function ensureEmailJob(
     }
 
     // Non-constraint related error
+    logger.error(`Non-constraint job creation error for email ${normalizedEmailId}: ${errorMessage}`)
     throw new Error(`Failed to create job for email ${normalizedEmailId}: ${errorMessage}`)
   }
 }
@@ -134,7 +153,8 @@ export async function updateEmailJobRelationship(
     })
   } catch (error) {
     const normalizedEmailId = String(emailId)
-    console.error(`Failed to update email ${normalizedEmailId} with job relationship:`, error)
+    const logger = createContextLogger(payload, 'JOB_SCHEDULER')
+    logger.error(`Failed to update email ${normalizedEmailId} with job relationship:`, error)
     throw error
   }
 }

src/utils/logger.ts

@@ -0,0 +1,48 @@
+import type { Payload } from 'payload'
+
+let pluginLogger: any = null
+
+/**
+ * Get or create the plugin logger instance
+ * Uses PAYLOAD_MAILING_LOG_LEVEL environment variable to configure log level
+ * Defaults to 'info' if not set
+ */
+export function getPluginLogger(payload: Payload) {
+  if (!pluginLogger && payload.logger) {
+    const logLevel = process.env.PAYLOAD_MAILING_LOG_LEVEL || 'info'
+
+    pluginLogger = payload.logger.child({
+      level: logLevel,
+      plugin: '@xtr-dev/payload-mailing'
+    })
+
+    // Log the configured log level on first initialization
+    pluginLogger.info(`Logger initialized with level: ${logLevel}`)
+  }
+
+  // Fallback to console if logger not available (shouldn't happen in normal operation)
+  if (!pluginLogger) {
+    return {
+      debug: (...args: any[]) => console.log('[MAILING DEBUG]', ...args),
+      info: (...args: any[]) => console.log('[MAILING INFO]', ...args),
+      warn: (...args: any[]) => console.warn('[MAILING WARN]', ...args),
+      error: (...args: any[]) => console.error('[MAILING ERROR]', ...args),
+    }
+  }
+
+  return pluginLogger
+}
+
+/**
+ * Create a context-specific logger for a particular operation
+ */
+export function createContextLogger(payload: Payload, context: string) {
+  const logger = getPluginLogger(payload)
+
+  return {
+    debug: (message: string, ...args: any[]) => logger.debug(`[${context}] ${message}`, ...args),
+    info: (message: string, ...args: any[]) => logger.info(`[${context}] ${message}`, ...args),
+    warn: (message: string, ...args: any[]) => logger.warn(`[${context}] ${message}`, ...args),
+    error: (message: string, ...args: any[]) => logger.error(`[${context}] ${message}`, ...args),
+  }
+}