n8n-io/n8n

GMail Trigger : Fetching duplicate emails again

Alexandero89 opened this issue · 5 comments

Alexandero89 commented

Bug Description

Hello all,

My Gmail trigger is firing multiple times for the same email.

It seems it was a problem before #5510 #9424 and is one again.

Every time the Gmailtrigger fired it processed the last available emails.
Sometimes it processed the same email up to 5 times.
And i could finally find the reason for that.

In the GmailTrigger especially the function nextPollPossibleDuplicates

n8n/packages/nodes-base/nodes/Google/Gmail/GmailTrigger.node.ts

Lines 360 to 368 in ab9faf1

const nextPollPossibleDuplicates = (responseData as IDataObject[]).reduce(
(duplicates, { json }) => {
const emailDate = getEmailDateAsSeconds(json as IDataObject);
return emailDate === lastEmailDate
? duplicates.concat((json as IDataObject).id as string)
: duplicates;
},
Array.from(emailsWithInvalidDate),
);

It checks if the email has the same timestamp as lastEmailDate. If so it adds it to the list of possible duplicates for the next run.

But if the poll from gmail gives back an array of emails every email that has not the identical timestamp as lastEmailDate slips through the logic of this filter although it is a duplicate.
Lets say we get an array of 2 emails from google and responseData is [{id:"email1"}, {id: "email2"}].
email1 has timestamp 1724052900 and email2 has timestamp 1724052800.
The function lastEmailDate

n8n/packages/nodes-base/nodes/Google/Gmail/GmailTrigger.node.ts

Lines 355 to 358 in ab9faf1

const lastEmailDate = (responseData as IDataObject[]).reduce((lastDate, { json }) => {
const emailDate = getEmailDateAsSeconds(json as IDataObject);
return emailDate > lastDate ? emailDate : lastDate;
}, 0);

sets the lastEmailDate to 1724052900. Then email1 gets added to the nextPollPossibleDuplicates list because it has the same timestamp as lastEmailDate, but not email2.

So if next time we pull data from gmail again and we get the same two emails (because no new email arrived), email1 is recognised as duplicate, but not email2.
Email2 will then be processed by the workflow everytime the trigger runs.
It only stops until a new mail arrives and we get new data from the gmail poll.

My thoughts:

I dont really understand why there is even a need for a duplicateemail list?
Why is there not just a reduce function to delete all emails from responsedata which have a smaller timestamp than nodeStaticData.lastTimeChecked ?
I mean nodeStaticData.lastTimeChecked gives us the exact timestamp every mail up to this time was polled and processed.
So we can be kind of sure that every mail that arrives with a timestamp before nodeStaticData.lastTimeChecked is a duplicate.

I added some logger to find the error. Here are the logs if they help you.

Click to see the log

n8n-1 | 2024-08-19T07:36:56.007Z | error | "{ comment: 'Starting poll function', file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:36:56.007Z | error | "{ Lasttimechecked: 1724052792, file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:36:56.007Z | error | "{ comment: "Time now '1724053016'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:36:56.007Z | error | "{ comment: "Startdate '1724052792'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:36:56.007Z | error | "{ comment: "Enddate '1724053016'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:36:56.007Z | error | "{ comment: 'Options ', options: {}, file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:36:56.008Z | error | "{ comment: 'Filters ', filters: { labelIds: [ 'Label_2641557787588889810' ], receivedAfter: 1724052792 }, file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:36:56.192Z | error | "{ comment: 'Responsedata ', responseData: [ { id: '1916990b5e5b8bb2', threadId: '1916990b5e5b8bb2' }, { id: '1916990a6644fbd3', threadId: '1916990a6644fbd3' }, { id: '191698dffa7d2f00', threadId: '191698dffa7d2f00' } ], file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:36:57.051Z | error | "{ emailid: '1916990b5e5b8bb2', comment: "Email date '1724052963'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:36:57.051Z | error | "{ comment: "Lastemaildate '1724052963'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:36:57.051Z | error | "{ emailid: '1916990a6644fbd3', comment: "Email date '1724052961'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:36:57.051Z | error | "{ comment: "Lastemaildate '1724052963'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:36:57.052Z | error | "{ emailid: '191698dffa7d2f00', comment: "Email date '1724052791'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:36:57.052Z | error | "{ comment: "Lastemaildate '1724052963'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:36:57.052Z | error | "{ emailid: '1916990b5e5b8bb2', comment: "Email date '1724052963'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:36:57.052Z | error | "{ emailid: '1916990a6644fbd3', comment: "Email date '1724052961'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:36:57.052Z | error | "{ emailid: '191698dffa7d2f00', comment: "Email date '1724052791'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:36:57.052Z | error | "{ comment: 'Possible duplicates not empty ', possibleDuplicates: [ '191698dffa7d2f00' ], file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:36:57.054Z | error | "{ comment: 'Filtered response data ', responseData: [ { json: [Object], binary: undefined }, { json: [Object], binary: undefined } ], file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:36:57.054Z | error | "{ comment: "Nextpollpossibleduplicates '1916990b5e5b8bb2'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:36:57.055Z | error | "{ comment: "Setting lastemaildate '1724052963'", file: 'LoggerProxy.js', function: 'exports.error'}"

#########################################################################################################################################

n8n-1 | 2024-08-19T07:37:56.007Z | error | "{ comment: 'Starting poll function', file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:37:56.007Z | error | "{ Lasttimechecked: 1724052963, file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:37:56.007Z | error | "{ comment: "Time now '1724053076'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:37:56.007Z | error | "{ comment: "Startdate '1724052963'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:37:56.007Z | error | "{ comment: "Enddate '1724053076'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:37:56.008Z | error | "{ comment: 'Options ', options: {}, file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:37:56.008Z | error | "{ comment: 'Filters ', filters: { labelIds: [ 'Label_2641557787588889810' ], receivedAfter: 1724052963 }, file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:37:56.202Z | error | "{ comment: 'Responsedata ', responseData: [ { id: '1916990b5e5b8bb2', threadId: '1916990b5e5b8bb2' }, { id: '1916990a6644fbd3', threadId: '1916990a6644fbd3' } ], file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:37:56.958Z | debug | Wait tracker resuming execution 1947 "{ executionId: '1947', file: 'WaitTracker.js', function: 'startExecution'}"
n8n-1 | 2024-08-19T07:37:57.026Z | error | "{ emailid: '1916990b5e5b8bb2', comment: "Email date '1724052963'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:37:57.026Z | error | "{ comment: "Lastemaildate '1724052963'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:37:57.026Z | error | "{ emailid: '1916990a6644fbd3', comment: "Email date '1724052961'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:37:57.027Z | error | "{ comment: "Lastemaildate '1724052963'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:37:57.027Z | error | "{ emailid: '1916990b5e5b8bb2', comment: "Email date '1724052963'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:37:57.027Z | error | "{ emailid: '1916990a6644fbd3', comment: "Email date '1724052961'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:37:57.027Z | error | "{ comment: 'Possible duplicates not empty ', possibleDuplicates: [ '1916990b5e5b8bb2' ], file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:37:57.028Z | error | "{ comment: 'Filtered response data ', responseData: [ { json: [Object], binary: undefined } ], file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:37:57.028Z | error | "{ comment: "Nextpollpossibleduplicates '1916990b5e5b8bb2'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:37:57.028Z | error | "{ comment: "Setting lastemaildate '1724052963'", file: 'LoggerProxy.js', function: 'exports.error'}"

#########################################################################################################################################

n8n-1 | 2024-08-19T07:38:56.006Z | error | "{ comment: 'Starting poll function', file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:38:56.006Z | error | "{ Lasttimechecked: 1724052963, file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:38:56.007Z | error | "{ comment: "Time now '1724053136'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:38:56.007Z | error | "{ comment: "Startdate '1724052963'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:38:56.007Z | error | "{ comment: "Enddate '1724053136'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:38:56.007Z | error | "{ comment: 'Options ', options: {}, file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:38:56.007Z | error | "{ comment: 'Filters ', filters: { labelIds: [ 'Label_2641557787588889810' ], receivedAfter: 1724052963 }, file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:38:56.231Z | error | "{ comment: 'Responsedata ', responseData: [ { id: '1916990b5e5b8bb2', threadId: '1916990b5e5b8bb2' }, { id: '1916990a6644fbd3', threadId: '1916990a6644fbd3' } ], file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:38:56.830Z | error | "{ emailid: '1916990b5e5b8bb2', comment: "Email date '1724052963'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:38:56.830Z | error | "{ comment: "Lastemaildate '1724052963'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:38:56.831Z | error | "{ emailid: '1916990a6644fbd3', comment: "Email date '1724052961'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:38:56.831Z | error | "{ comment: "Lastemaildate '1724052963'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:38:56.831Z | error | "{ emailid: '1916990b5e5b8bb2', comment: "Email date '1724052963'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:38:56.831Z | error | "{ emailid: '1916990a6644fbd3', comment: "Email date '1724052961'", file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:38:56.831Z | error | "{ comment: 'Possible duplicates not empty ', possibleDuplicates: [ '1916990b5e5b8bb2' ], file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:38:56.832Z | error | "{ comment: 'Filtered response data ', responseData: [ { json: [Object], binary: undefined } ], file: 'LoggerProxy.js', function: 'exports.error'}"
n8n-1 | 2024-08-19T07:38:56.832Z | error | "{ comment: "Nextpollpossibleduplicates '1916990b5e5b8bb2'", file: 'LoggerProxy.js', function: 'exports.error'}"

To Reproduce

  1. Set up docker compose with version 1.54.02
  2. Add workflow with gmail trigger

Expected behavior

Every email from gmail should be polled/processed once

Operating System

docker compose

n8n Version

1.45.2

Node.js Version

docker compose

Database

SQLite (default)

Execution mode

main (default)

Joffcom commented

Hey @Alexandero89,

We have created an internal ticket to look into this which we will be tracking as "GHC-174"

Alexandero89 commented

Nice.

just FYI @Joffcom:
Had a typo with a timestamp in my logs. Just changed that

Joffcom commented

@Alexandero89 no worries, Oddly I noticed this issue a couple of weeks back and forgot to create an internal ticket so this perfect.

Alexandero89 commented

A simple change did the trick for me:
Change Line 363 in

n8n/packages/nodes-base/nodes/Google/Gmail/GmailTrigger.node.ts

Lines 360 to 368 in ab9faf1

const nextPollPossibleDuplicates = (responseData as IDataObject[]).reduce(
(duplicates, { json }) => {
const emailDate = getEmailDateAsSeconds(json as IDataObject);
return emailDate === lastEmailDate
? duplicates.concat((json as IDataObject).id as string)
: duplicates;
},
Array.from(emailsWithInvalidDate),
);

to "<=".

Although i think it would still be better to replace this duplicate list thing at all.

Joffcom commented

@Alexandero89 we are currently working on an internal dedupe mechanism which will likely be a better option for this kind of trigger in the future although using message IDs or date in theory should work it is a bit of a strange one.

  • 👍1