Mailbox Checks Overlapped

A mailbox import logged "success" with no ticket

Fixed in the release after 3.9.0 · Reported in #183 by @jaiintunesscm · Module: Tickets (mailboxes)

---

The short version

A mailbox's processing log sometimes showed an import like this:

{ "step": "import", "result": "success", "ticket_id": null, "is_new_ticket": false }

Nothing was lost. Every one of these was an email that had already been imported - by another check of the same mailbox a moment earlier - so its ticket already existed. The log just called a skipped duplicate a success, with no ticket, and counted it as saved.

The cause was every open ticket inbox checking the mailboxes for itself. With five analysts in Tickets, each mailbox was checked about five times a minute, and now and then two checks ran at the same moment and both picked up the same unread email. The same overlap could, in the worst case, turn one email into two tickets.

Now only one check of a mailbox runs at a time, the inboxes share one automatic check a minute between them, and an email that was already imported is logged as Already imported, with the ticket it went to.

What was wrong

• Every inbox polled every mailbox. tickets/index.php checks each active mailbox when the inbox opens and every 60 seconds after that, each on its own timer. Nothing stopped two checks of the same mailbox overlapping.
• The duplicate check said false, and false was read as success. saveEmailToDatabase() returns early when the email's message id is already stored. It returned false; the caller wrote an import: success step with ticket_id null, counted the email as saved, and logged the row as Imported.
• Two checks looking before either had saved would both create a ticket. The duplicate check and the insert are separate steps with no lock between them.

The fix

• One check per mailbox at a time. The check takes a database lock for the mailbox (GET_LOCK, named per database and mailbox, released when the request ends). A second check that overlaps stands down with "skipped": "busy" and does nothing.
• The inboxes share one automatic check a minute. The inbox's timed polls are sent as automatic. An automatic poll stands down ("skipped": "recent") if any check of that mailbox finished in the last 50 seconds - so five open inboxes mean one check a minute, not five. Clicking the mail icon, or Check in Tickets → Settings → Mailboxes, always checks.
• A stand-down changes nothing. The mailbox's last-checked time and last error stay exactly as they were.
• An honest log for duplicates. An email already in the database comes back as already imported with its ticket. The step reads "result": "already_imported" with the ticket id, it is not counted as saved, and the mailbox's activity list shows it with a grey Already imported badge. The action after importing (delete, move or mark as read) still runs, so an email left behind because that action failed last time is tidied away rather than coming back on every check.

📁 Files changed

	File	Change
🟦	api/tickets/check_mailbox_email.php	The lock, the 50-second stand-down for automatic polls, already imported instead of false
🟦	tickets/index.php	The timed polls say they are automatic
🟦	tickets/settings/index.php	Already imported badge in the mailbox activity list
🟩	tests/mailbox-check-overlap.php	The test below

How it was verified

php tests/mailbox-check-overlap.php creates a throwaway mailbox pointing at a closed local port, so no real mailbox is read, and calls the real endpoint over HTTP:

• while the test holds the mailbox's lock, a check stands down as busy, saves nothing and leaves last-checked alone;
• an automatic poll 10 seconds after a check stands down as recent; a manual check at the same moment still runs; an automatic poll 70 seconds after a check runs;
• an email already in the database comes back as already imported, naming its ticket, and nothing new is saved.

The control that matters: against the code before the fix, 8 of the 15 checks fail. With the fix, all 15 pass.

On the install the fix was built on, the mailbox activity log already held 13 rows of exactly this shape, from one afternoon; each was a repeat of an email imported with a ticket a moment earlier.

What this means for you

Nothing to do after upgrading. If your logs hold success rows with no ticket from before the fix, they are duplicates of an earlier import of the same email - search the mailbox's activity for the same sender and subject to find the ticket.

Still to come: mail collection from a scheduled task, so mail arrives even when nobody has the inbox open, with the inboxes' own checks standing down while the scheduled task is running. See Background job health - design (#182).

Related pages

• Mail collection - Developer Guide - the whole path, and its timing
• Mailbox authentication · Basic IMAP mailboxes
• Bugs resolved