Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Multiple emails are sent #3632

Closed
nehasri12 opened this issue Dec 27, 2023 · 61 comments
Closed

Multiple emails are sent #3632

nehasri12 opened this issue Dec 27, 2023 · 61 comments

Comments

@nehasri12
Copy link

While sending mail, Job processed successfully once but it also send to Background Process: Queued jobs. From Queued jobs, it is not cleaned automatically, and perform same job again and again (retry) after 90 seconds. Therefore, we received multiple email for 1 job only.

@freescout-helpdesk
Copy link
Contributor

Your FreeScout version?

@nehasri12
Copy link
Author

Your FreeScout version?

1.8.115

@freescout-helpdesk
Copy link
Contributor

Check errors in laravel logs in Manage > Logs > App Logs.

@nehasri12
Copy link
Author

Check errors in laravel logs in Manage > Logs > App Logs.

Events: Error sending email to customer
Error : App\Jobs\SendReplyToCustomer has been attempted too many times or run too long. The job may have previously timed out.; File: /var/www/html/vendor/laravel/framework/src/Illuminate/Queue/Worker.php (394)

@freescout-helpdesk
Copy link
Contributor

Try to manually restart background jobs: https://github.com/freescout-helpdesk/freescout/wiki/Background-Jobs

@nehasri12
Copy link
Author

Try to manually restart background jobs: https://github.com/freescout-helpdesk/freescout/wiki/Background-Jobs
I did the same. but problem was not resolved.

Initially, I was using swiftmail() for mailing and the queued job processed properly. But now I am using sendmail(), and then this problem arises. Whenever, we reply to any email. The mail sent successfully, but it also sent to Background Jobs: Queued Job. Here, number of attempts is increases iteratively after every attempts (retries). and therefore, for every attempts we receive multiple emails.

Here, attempts should be = 0 ( if mail sent successfully) but it is not equal to zero. It is increase by 1. It doesn't receive signal/message that mail sent, so for every retry it receive signal mail not sent and then it retry again and again.

@freescout-helpdesk
Copy link
Contributor

Is there anything in "Manage > Logs > Send Errors" or "Manage > Logs > Outgoing Emails"?

@nehasri12
Copy link
Author

Yes

Is there anything in "Manage > Logs > Send Errors" or "Manage > Logs > Outgoing Emails"?

Outgoing Emails : Accepted for delivery

Send Error :
Events: Error sending email to customer
Error: App\Jobs\SendReplyToCustomer has been attempted too many times or run too long. The job may have previously timed out.; File: /var/www/html/vendor/laravel/framework/src/Illuminate/Queue/Worker.php (394)

@freescout-helpdesk
Copy link
Contributor

Very strange. In the latest version of FreeScout if something happens during mail sending there should be a corresponding error message in some log.

@nehasri12
Copy link
Author

Very strange. In the latest version of FreeScout if something happens during mail sending there should be a corresponding error message in some log.

The logs are generated only after the job is failed after 100 attempts.. do you have any solution where after sending mail the job should be finished or closed..

@freescout-helpdesk
Copy link
Contributor

where after sending mail the job should be finished or closed..

This is how it works (at least for others). You may need to find someone who can investigate it on your server.

https://github.com/freescout-helpdesk/freescout/blob/dist/app/Jobs/SendReplyToCustomer.php#L271

https://github.com/freescout-helpdesk/freescout/wiki/Debugging

@nehasri12
Copy link
Author

where after sending mail the job should be finished or closed..

This is how it works (at least for others). You may need to find someone who can investigate it on your server.

https://github.com/freescout-helpdesk/freescout/blob/dist/app/Jobs/SendReplyToCustomer.php#L271

https://github.com/freescout-helpdesk/freescout/wiki/Debugging

Yet, not found any solution.

PHP version: PHP 8.1.2-1ubuntu2.14
Freescout version: 1.8.117
Database: Mysql (8.0.35-0ubuntu0.22.04.1)

Well, we are facing this issue since 2 weeks. All the Emails are sent mutiple times to receivers. Usually, when we send any email to customer or do reply to customer, email sent succesfully but also it is sent in system background jobs queued:jonb. Here it send repetedly to customer for 100 retries and then it send to failed queued:job.

Back ground jobs:
sendtoreply

But , there is no log in outgoing emails: ( 9th jan 2024 log is empty)
image

Laravel log also has no entries to this emails.

Queue-jobs.log is :
app log

Send Error log: App\jobs\sendreplytocustomer has been attempted too many times or run too long.
senderror log

I also increased the retry_time, debug kernel.php and SystemController.php, but nothing worked.

Kindly provide useful solution.

@nehasri12 nehasri12 changed the title Queued jobs aren't cleaned automatically. Multiple Emails sends ##Queued jobs aren't cleaned automatically. Jan 9, 2024
@freescout-helpdesk
Copy link
Contributor

Make sure your console PHP is able to write to /storage/logs directory.

@nehasri12
Copy link
Author

Make sure your console PHP is able to write to /storage/logs directory.

logs are working.

@cymuc
Copy link

cymuc commented Jan 18, 2024

Today, we encountered a recurring issue with our system configuration. Specifically, we are running PHP version 7.4 alongside Freescout version 1.8.117. The problem arose when an email was inexplicably sent around 30 times to a single recipient, causing a bottleneck in the job queue and hindering the execution of other tasks.

The outgoing mail.log of Freescout did not reference this email duplication issue, but upon investigation, we identified the incident in the mail.log of the Postfix SMTP server.

We manually removed the problematic job from the queue, subsequently allowing the seamless execution of the remaining tasks in the queue. We had that exact problem twice.

When trying to run the job queue manually with a "hanging job" it times out.

Logs are working as expected, and we get proper messages for that in the systems log.

@freescout-helpdesk
Copy link
Contributor

@cymuc What the time interval between sent emails? Do you have CC or BCC in those emails?

@cymuc
Copy link

cymuc commented Jan 19, 2024

The time interval is 2 minutes because that is the time interval in the cron job.

It was a mail forwarding job with an attachment. No CC or BCC. But there were other mail forwarding jobs with attachments that worked just fine after that.

It looks like it is doing part of the job, but then after the email is sent, something hangs and times out. The process is then killed and no sending is reported anywhere. The failed attempts were reported to the database.

@freescout-helpdesk
Copy link
Contributor

The time interval is 2 minutes because that is the time interval in the cron job.

The thing is that emails to customers are being sent by the queue:work job which is constantly running in the background. Try to set the standard 1 minute interval for the cron job.

@cymuc
Copy link

cymuc commented Jan 19, 2024

The job would still hang. Even if I try to run the job in the console. It would also not go to the second job. It has nothing to do with the interval.

@freescout-helpdesk
Copy link
Contributor

freescout-helpdesk commented Jan 19, 2024

Are you all using Docker?

Do you have smtp_queue_id field in send_logs table?

Do you have "IMAP Folder To Save Outgoing Replies" value set in mailbox "Fetching Emails"? If yes try to remove it.

@iantearle
Copy link

Agreed, #3706 is a duplicate of this.
You requested the full error message:

Allowed memory size of 268435456 bytes exhausted (tried to allocate 134217736 bytes) {"exception":"[object] (Symfony\\Component\\Debug\\Exception\\FatalErrorException(code: 1): Allowed memory size of 268435456 bytes exhausted (tried to allocate 134217736 bytes) at /www/html/overrides/webklex/php-imap/src/Connection/Protocols/ImapProtocol.php:275)
[stacktrace] #0 {main} "} 

I have that every minute since the initial email got sent - in this case 21 times over 21 minutes. (the first time this occurred, we had a report of 84 emails getting sent out).

As per other issue, we are running in Docker.

@iantearle
Copy link

Incidentally, each time this has happened theres been a log entry at the start of the day some hours before:

The process has been signaled with signal "15". {"exception":"[object] (Symfony\\Component\\Process\\Exception\\RuntimeException(code: 0): The process has been signaled with signal \"15\". at /www/html/overrides/symfony/process/Process.php:434)

[stacktrace]
#0 /www/html/overrides/symfony/process/Process.php(212): Symfony\\Component\\Process\\Process->wait()
#1 /www/html/vendor/laravel/framework/src/Illuminate/Console/Scheduling/Event.php(201): Symfony\\Component\\Process\\Process->run()
#2 /www/html/vendor/laravel/framework/src/Illuminate/Console/Scheduling/Event.php(176): Illuminate\\Console\\Scheduling\\Event->runCommandInForeground(Object(Illuminate\\Foundation\\Application))
#3 /www/html/vendor/laravel/framework/src/Illuminate/Console/Scheduling/ScheduleRunCommand.php(59): Illuminate\\Console\\Scheduling\\Event->run(Object(Illuminate\\Foundation\\Application))
#4 [internal function]: Illuminate\\Console\\Scheduling\\ScheduleRunCommand->handle()
#5 /www/html/overrides/laravel/framework/src/Illuminate/Container/BoundMethod.php(28): call_user_func_array(Array, Array)
#6 /www/html/overrides/laravel/framework/src/Illuminate/Container/BoundMethod.php(87): Illuminate\\Container\\BoundMethod::Illuminate\\Container\\{closure}()
#7 /www/html/overrides/laravel/framework/src/Illuminate/Container/BoundMethod.php(27): Illuminate\\Container\\BoundMethod::callBoundMethod(Object(Illuminate\\Foundation\\Application), Array, Object(Closure))
#8 /www/html/overrides/laravel/framework/src/Illuminate/Container/Container.php(549): Illuminate\\Container\\BoundMethod::call(Object(Illuminate\\Foundation\\Application), Array, Array, NULL)
#9 /www/html/vendor/laravel/framework/src/Illuminate/Console/Command.php(183): Illuminate\\Container\\Container->call(Array)
#10 /www/html/vendor/symfony/console/Command/Command.php(255): Illuminate\\Console\\Command->execute(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Illuminate\\Console\\OutputStyle))
#11 /www/html/vendor/laravel/framework/src/Illuminate/Console/Command.php(169): Symfony\\Component\\Console\\Command\\Command->run(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Illuminate\\Console\\OutputStyle))
#12 /www/html/vendor/symfony/console/Application.php(992): Illuminate\\Console\\Command->run(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))
#13 /www/html/vendor/symfony/console/Application.php(255): Symfony\\Component\\Console\\Application->doRunCommand(Object(Illuminate\\Console\\Scheduling\\ScheduleRunCommand), Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))
#14 /www/html/vendor/symfony/console/Application.php(148): Symfony\\Component\\Console\\Application->doRun(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))
#15 /www/html/vendor/laravel/framework/src/Illuminate/Console/Application.php(88): Symfony\\Component\\Console\\Application->run(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))
#16 /www/html/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(121): Illuminate\\Console\\Application->run(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))
#17 /www/html/artisan(60): Illuminate\\Foundation\\Console\\Kernel->handle(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))
#18 {main}
"}
              

May or may not be relevant.

@cymuc
Copy link

cymuc commented Jan 19, 2024

In my case, it is not running on docker. There is no error message in the logs since the process was killed. There is also no sent log in Freescout, but I can see it in the outgoing message in the postfix mail.log. The allowed memory for php-cli which is relevant for the cron job is memory_limit = -1.

@freescout-helpdesk
Copy link
Contributor

freescout-helpdesk commented Jan 19, 2024

What about other questions? #3632 (comment)

@cymuc
Copy link

cymuc commented Jan 19, 2024

Do you have smtp_queue_id field in send_logs table?
There is no send Log ID, just the outgoing email in the postfix mail.log.
Do you have "IMAP Folder To Save Outgoing Replies" value set in mailbox "Fetching Emails"? If yes try to remove it.
Yes, we had that in the configuration and removed it after the incident, because I have seen another ticket mentioning that as a potential problem.

We had that incident twice in about 6 months.

@freescout-helpdesk
Copy link
Contributor

We had that incident twice in about 6 months.

And since when and how often does it happen for others? It may help us to identify the commit which could have brought the issue.

@cymuc
Copy link

cymuc commented Jan 19, 2024

We had it for the first time on January 4th and then again on January 18th. And the problem disappears when we delete the hanging job from the database job table.

@freescout-helpdesk
Copy link
Contributor

  1. Update FreeScout to the latest version.
  2. Replace /app/Jobs/SendReplyToCustomer.php with SendReplyToCustomer.zip
  3. Clear cache https://github.com/freescout-helpdesk/freescout/wiki/Clearing-the-Cache
  4. Wait for the issue to happen and send us lines from "Manage > Logs > App Logs" (laravel-...log) starting with [SendReplyToCustomer] #your_conversation_number.

@freescout-helpdesk
Copy link
Contributor

@bekre10 #3632 (comment)

@freescout-helpdesk freescout-helpdesk changed the title Multiple Emails sends ##Queued jobs aren't cleaned automatically. Multiple emails are sent Jan 26, 2024
@Leopere
Copy link

Leopere commented Jan 28, 2024

I'm also running into this while using a private email server using IMAP and SMTP settings that seem to be verified.

@iantearle
Copy link

iantearle commented Jan 29, 2024

I have just added the logging file - so hopefully I shall have more to report on when next we start sending multiple emails. This is getting critical now.
I have noticed a pattern of exhausted memory on the same day (though it could be hours after when the emails start getting multiplied)

Allowed memory size of 268435456 bytes exhausted (tried to allocate 134217736 bytes) {"exception":"[object] (Symfony\\Component\\Debug\\Exception\\FatalErrorException(code: 1): Allowed memory size of 268435456 bytes exhausted (tried to allocate 134217736 bytes) at /www/html/overrides/webklex/php-imap/src/Connection/Protocols/ImapProtocol.php:275)

[Stacktrace]
#0 {main}
"}```

@iantearle
Copy link

image
Also, when this last happened one of our users noticed this in console.

@iantearle
Copy link

Interestingly, the email thread that caused the issue today was responded to, and the following logs generated post the updated logging file provided. Looks like it caused an issue saving to the sent Imap folder (we're sending via AWS SES).


error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 29
-- | -- | -- | --
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 28
error | production | 2024-01-29 14:33:15 | [Fellowship Support » Connection Settings » Fetching Emails » IMAP Folder To Save Outgoing Replies] Could not save outgoing reply to the IMAP folder: Error: fread(): SSL: Connection reset by peer; File: /www/html/overrides/webklex/php-imap/src/Connection/Protocols/ImapProtocol.php (108)
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 24
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 22.4
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 22.3 envelope_str:67661
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 22.2
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 22.1
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 22
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 21
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 20
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 19
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 18
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 17
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 16
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 15
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 14
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 6 (last_smtp_queue_id: )
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 5
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 4
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 3
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 2
error | production | 2024-01-29 14:33:15 | [SendReplyToCustomer] #260 - 1


@bekre10
Copy link

bekre10 commented Jan 29, 2024

I've disabled saving sent emails to the IMAP folder and it still happens intermittently.
We are using AWS SES as well.
--- Update: I was wrong, the incident occurred for a mailbox which still saved to the IMAP folder. I have disabled it and will monitor it.

@freescout-helpdesk
Copy link
Contributor

This log #3632 (comment) does not show that the SendReplyToCustomer job actually got stuck.

We need a log for the SendReplyToCustomer job that got stuck.

@nehasri12
Copy link
Author

What about other questions? #3632 (comment)

while checking AWS logs found the issue as

Jan 10 10:00:01 ip- sm-msp-queue[1751844]: My unqualified host name (ip-) unknown; sleeping for retry
Jan 10 10:01:01 ip-sm-msp-queue[1751844]: unable to qualify my own domain name (ip-) -- using short name

updated configuration provided in following link..

https://linuxconfig.org/sendmail-unqualified-hostname-unknown-sleeping-for-retry-unqualified-hostname

the issue is resolved now.. but it may be different for different users.

@iantearle
Copy link

Curious, where did you find the logs in AWS? I've been hunting for them for a while.

@nehasri12
Copy link
Author

Curious, where did you find the logs in AWS? I've been hunting for them for a while.

Logs created by the application server are stored locally on individual instances. We retrieved them by using the environment management console.

@freescout-helpdesk
Copy link
Contributor

nehasri12 Thanks for the info. So in your case do you have "IMAP Folder To Save Outgoing Replies" option set for the mailbox?

@bekre10
Copy link

bekre10 commented Jan 31, 2024

I have disabled "IMAP Folder to Save Outgoing Replies" and it just happened again to a customer who received over 600 duplicate mails. They were not amused :(

@iantearle
Copy link

I have disabled "IMAP Folder to Save Outgoing Replies" and it just happened again to a customer who received over 600 duplicate mails. They were not amused :(

Did you clear cache after doing so? I did the same thing, in fact I added it in again a day later, clearing cache each time and I'm not seeing even the memory exhausted errors I was seeing - so far no dupes

@bekre10
Copy link

bekre10 commented Jan 31, 2024

I have disabled "IMAP Folder to Save Outgoing Replies" and it just happened again to a customer who received over 600 duplicate mails. They were not amused :(

Did you clear cache after doing so? I did the same thing, in fact I added it in again a day later, clearing cache each time and I'm not seeing even the memory exhausted errors I was seeing - so far no dupes

I have cleared the cache before it happened again and after I disabled the IMAP folder for outgoing mails.

Are those affected all using M365 and AWS SES?

@iantearle
Copy link

Are those affected all using M365 and AWS SES?

Yes in my case.

@nehasri12
Copy link
Author

nehasri12 Thanks for the info. So in your case do you have "IMAP Folder To Save Outgoing Replies" option set for the mailbox?

Yes.

@cymuc
Copy link

cymuc commented Jan 31, 2024

Are those affected all using M365 and AWS SES?

Not in our case. It is a self-hosted Exchange Server and Hosted Ubuntu the Intranet using Hyper-V.

@bekre10
Copy link

bekre10 commented Jan 31, 2024

Are those affected all using M365 and AWS SES?

Not in our case. It is a self-hosted Exchange Server and Hosted Ubuntu the Intranet using Hyper-V.

And you aren't using AWS SES to send out emails, are you?

@cymuc
Copy link

cymuc commented Jan 31, 2024

And you aren't using AWS SES to send out emails, are you?

No. We are using a local postfix with Smarthost.

@phanousk
Copy link

phanousk commented Jan 31, 2024

And you aren't using AWS SES to send out emails, are you?

No. We are using a local postfix with Smarthost.

I am using SMTP with M365. And have set "IMAP Folder To Save Outgoing Replies".

@freescout-helpdesk
Copy link
Contributor

We still have not received requested logs:
#3632 (comment)
#3632 (comment)

@Leopere
Copy link

Leopere commented Feb 1, 2024

I myself am having a hard time capturing a where this happens consistently. I'm not even sure if its the same problem so maybe I'll step out.

@freescout-helpdesk
Copy link
Contributor

If someone can reproduce it consistently and can provide access to your FreeScout, please email at [email protected]

@bekre10
Copy link

bekre10 commented Feb 1, 2024

If someone can reproduce it consistently and can provide access to your FreeScout, please email at [email protected]

I wouldn't mind giving access if it helps to find the cause. However, it happens intermittently, sometimes not for a week and then a few times in a row.

@freescout-helpdesk
Copy link
Contributor

freescout-helpdesk commented Feb 1, 2024

We've made some adjustments. You can wait for it to be released or copy 2 following files to your FreeScout, clear cache and see how it goes:

https://github.com/freescout-helpdesk/freescout/blob/master/app/Thread.php
https://github.com/freescout-helpdesk/freescout/blob/master/app/Jobs/SendReplyToCustomer.php

Don't forget to update FreeScout to the latest version first.

@bekre10
Copy link

bekre10 commented Feb 1, 2024

If I replace the Thread.php file I get the screen as per screenshot, even after restarting the Server.
The SendReplyToCustomer.php is not causing any issue.
IMG_6141

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

7 participants