chore: add diagnostic logs to imap email fetch pipeline (#15187)

Adds lifecycle log lines across the IMAP email fetch pipeline so we can
trace where a fetch run spends time or silently stops. Some IMAP inboxes
showed increasingly sparse fetch runs in production without matching
errors; existing logs did not cover job start, lock acquisition,
connection setup, or early-exit paths.

## What changed

- `Inboxes::FetchImapEmailInboxesJob`: log when a fetch job is enqueued
per inbox (temporary instrumentation).
- `Inboxes::FetchImapEmailsJob`: log job start, skip reason on early
return, lock attempt/acquisition, fetched count, processing completion,
job completion, and unexpected errors.
- `Imap::BaseFetchEmailService`: log successful IMAP connection and the
start of each header batch fetch.

All lines share the `[IMAP::FETCH_EMAIL_SERVICE]` tag for searchability.
No behavior changes.

---------

Co-authored-by: Sony Mathew <sony@chatwoot.com>

app/jobs/inboxes/fetch_imap_email_inboxes_job.rb

@@ -5,7 +5,10 @@ class Inboxes::FetchImapEmailInboxesJob < ApplicationJob
   def perform
     email_inboxes = Inbox.where(channel_type: 'Channel::Email')
     email_inboxes.find_each(batch_size: 100) do |inbox|
-      ::Inboxes::FetchImapEmailsJob.perform_later(inbox.channel) if should_fetch_emails?(inbox)
+      next unless should_fetch_emails?(inbox)
+
+      Rails.logger.info "[IMAP::FETCH_EMAIL_SERVICE] Enqueuing fetch job for inbox #{inbox.id}"
+      ::Inboxes::FetchImapEmailsJob.perform_later(inbox.channel)
     end
   end
 

app/jobs/inboxes/fetch_imap_emails_job.rb

@@ -4,13 +4,11 @@ class Inboxes::FetchImapEmailsJob < MutexApplicationJob
   queue_as :scheduled_jobs
 
   def perform(channel, interval = 1)
-    return unless should_fetch_email?(channel)
+    Rails.logger.info "[IMAP::FETCH_EMAIL_SERVICE] Job started for inbox #{channel.inbox.id}"
 
-    key = format(::Redis::Alfred::EMAIL_MESSAGE_MUTEX, inbox_id: channel.inbox.id)
+    return log_skipped_fetch(channel) unless should_fetch_email?(channel)
 
-    with_lock(key, 5.minutes) do
-      process_email_for_channel(channel, interval)
-    end
+    fetch_mails_with_lock(channel, interval)
   rescue *ExceptionList::IMAP_EXCEPTIONS => e
     Rails.logger.error "Authorization error for email channel - #{channel.inbox.id} : #{e.message}"
   rescue IOError, OpenSSL::SSL::SSLError, Net::IMAP::NoResponseError, Net::IMAP::BadResponseError, Net::IMAP::InvalidResponseError,
@@ -19,7 +17,7 @@ class Inboxes::FetchImapEmailsJob < MutexApplicationJob
   rescue LockAcquisitionError
     Rails.logger.error "Lock failed for #{channel.inbox.id}"
   rescue StandardError => e
-    ChatwootExceptionTracker.new(e, account: channel.account).capture_exception
+    handle_unexpected_error(e, channel)
   end
 
   private
@@ -28,6 +26,36 @@ class Inboxes::FetchImapEmailsJob < MutexApplicationJob
     channel.imap_enabled? && !channel.reauthorization_required?
   end
 
+  def handle_unexpected_error(error, channel)
+    Rails.logger.error "[IMAP::FETCH_EMAIL_SERVICE] Unexpected error for inbox #{channel.inbox.id} : #{error.class} - #{error.message}"
+    ChatwootExceptionTracker.new(error, account: channel.account).capture_exception
+  end
+
+  def fetch_mails_with_lock(channel, interval)
+    inbox_id = channel.inbox.id
+    key = format(::Redis::Alfred::EMAIL_MESSAGE_MUTEX, inbox_id: inbox_id)
+    success = false
+    started_at = Process.clock_gettime(Process::CLOCK_MONOTONIC)
+
+    Rails.logger.info "[IMAP::FETCH_EMAIL_SERVICE] Attempting lock for inbox #{inbox_id}"
+    with_lock(key, 5.minutes) do
+      Rails.logger.info "[IMAP::FETCH_EMAIL_SERVICE] Lock acquired for inbox #{inbox_id}"
+      success = process_email_for_channel(channel, interval)
+    end
+
+    duration = (Process.clock_gettime(Process::CLOCK_MONOTONIC) - started_at).round(1)
+    if success
+      Rails.logger.info "[IMAP::FETCH_EMAIL_SERVICE] Job completed for inbox #{inbox_id} in #{duration}s"
+    else
+      Rails.logger.error "[IMAP::FETCH_EMAIL_SERVICE] Job completed with authorization error for inbox #{inbox_id} in #{duration}s"
+    end
+  end
+
+  def log_skipped_fetch(channel)
+    Rails.logger.info "[IMAP::FETCH_EMAIL_SERVICE] Skipping fetch for #{channel.inbox.id} : " \
+                      "imap_enabled: #{channel.imap_enabled?}, reauthorization_required: #{channel.reauthorization_required?}"
+  end
+
   def process_email_for_channel(channel, interval)
     inbound_emails = if channel.microsoft?
                        Imap::MicrosoftFetchEmailService.new(channel: channel, interval: interval).perform
@@ -37,12 +65,18 @@ class Inboxes::FetchImapEmailsJob < MutexApplicationJob
                        Imap::FetchEmailService.new(channel: channel, interval: interval).perform
                      end
 
+    Rails.logger.info "[IMAP::FETCH_EMAIL_SERVICE] Fetched #{inbound_emails.length} new emails for inbox #{channel.inbox.id}"
+
     inbound_emails.each do |inbound_mail|
       process_mail(inbound_mail, channel)
     end
+
+    Rails.logger.info "[IMAP::FETCH_EMAIL_SERVICE] Finished processing fetched emails for inbox #{channel.inbox.id}"
+    true
   rescue OAuth2::Error => e
-    Rails.logger.error "Error for email channel - #{channel.inbox.id} : #{e.message}"
+    Rails.logger.error "[IMAP::FETCH_EMAIL_SERVICE] OAuth error for inbox #{channel.inbox.id} : #{e.message}"
     channel.authorization_error!
+    false
   end
 
   def should_skip_email?(message_id)

app/services/imap/base_fetch_email_service.rb

@@ -98,6 +98,7 @@ class Imap::BaseFetchEmailService
 
   def append_message_ids_for_batch(batch, message_ids_with_seq)
     # Fetch only message-id only without mail body or contents.
+    Rails.logger.info "[IMAP::FETCH_EMAIL_SERVICE] Starting header batch of #{batch.length} for #{channel.email}"
     batch_message_ids = imap_client.fetch(batch, 'BODY.PEEK[HEADER]')
     Rails.logger.info "[IMAP::FETCH_EMAIL_SERVICE] Fetching the batch for #{channel.email}. Found #{batch_message_ids&.length} messages."
 
@@ -140,6 +141,7 @@ class Imap::BaseFetchEmailService
     Imap::Authentication.authenticate!(imap, authentication_type, channel.imap_login, imap_password)
 
     imap.select('INBOX')
+    Rails.logger.info "[IMAP::FETCH_EMAIL_SERVICE] IMAP connection established for #{channel.email}"
     imap
   end