[GH-ISSUE #584] [self-hosted] No verification email sent - no logs #988

Closed
opened 2026-03-14 11:22:47 +03:00 by kerem · 8 comments
Owner

Originally created by @buxm on GitHub (Jan 21, 2024).
Original GitHub issue: https://github.com/anonaddy/anonaddy/issues/584

I'm setting up a self hosted instance on Google Cloud.
Google Cloud doesn't allow outbound port 25. However I configured postfix to use Mailjet as a relay host on port 587 to send outbound emails.
After following the installation instructions, I registered the administrator user.
But then I didn't get the verification email.
Even when I click on "Resend verification email", wait until I see the "A fresh verification link has been sent to your email address." message, no email is received.

I cannot find any log that can help me investigate. Am I missing something? How can I debug this issue?

Addy version: current master branch on Git (I presume v1.0.4).

sudo service supervisor status
● supervisor.service - Supervisor process control system for UNIX
     Loaded: loaded (/lib/systemd/system/supervisor.service; enabled; vendor preset: enabled)
     Active: active (running) since Sun 2024-01-21 14:36:29 UTC; 4h 10min ago
       Docs: http://supervisord.org
   Main PID: 442 (supervisord)
      Tasks: 9 (limit: 2337)
     Memory: 263.6M
        CPU: 1min 9.650s
     CGroup: /system.slice/supervisor.service
             ├─   442 /usr/bin/python3 /usr/bin/supervisord -n -c /etc/supervisor/supervisord.conf
             ├─ 91631 php /var/www/anonaddy/artisan queue:work redis --sleep=3 --tries=3
             ├─ 91632 php /var/www/anonaddy/artisan queue:work redis --sleep=3 --tries=3
             ├─ 91647 php /var/www/anonaddy/artisan queue:work redis --sleep=3 --tries=3
             ├─ 94140 php /var/www/anonaddy/artisan queue:work redis --sleep=3 --tries=3
             ├─103028 php /var/www/anonaddy/artisan queue:work redis --sleep=3 --tries=3
             ├─104579 php /var/www/anonaddy/artisan queue:work redis --sleep=3 --tries=3
             ├─105232 php /var/www/anonaddy/artisan queue:work redis --sleep=3 --tries=3
             └─105911 php /var/www/anonaddy/artisan queue:work redis --sleep=3 --tries=3

Jan 21 18:18:06 mail.addy-test.buxnet.net supervisord[442]: 2024-01-21 18:18:06,881 INFO success: anonaddy_01 entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
Jan 21 18:22:06 mail.addy-test.buxnet.net supervisord[442]: 2024-01-21 18:22:06,338 INFO exited: anonaddy_07 (terminated by SIGKILL; not expected)
Jan 21 18:22:07 mail.addy-test.buxnet.net supervisord[442]: 2024-01-21 18:22:07,346 INFO spawned: 'anonaddy_07' with pid 104579
Jan 21 18:22:08 mail.addy-test.buxnet.net supervisord[442]: 2024-01-21 18:22:08,351 INFO success: anonaddy_07 entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
Jan 21 18:23:37 mail.addy-test.buxnet.net supervisord[442]: 2024-01-21 18:23:37,183 INFO exited: anonaddy_02 (terminated by SIGKILL; not expected)
Jan 21 18:23:38 mail.addy-test.buxnet.net supervisord[442]: 2024-01-21 18:23:38,222 INFO spawned: 'anonaddy_02' with pid 105232
Jan 21 18:23:39 mail.addy-test.buxnet.net supervisord[442]: 2024-01-21 18:23:39,227 INFO success: anonaddy_02 entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
Jan 21 18:25:08 mail.addy-test.buxnet.net supervisord[442]: 2024-01-21 18:25:08,229 INFO exited: anonaddy_05 (terminated by SIGKILL; not expected)
Jan 21 18:25:09 mail.addy-test.buxnet.net supervisord[442]: 2024-01-21 18:25:09,235 INFO spawned: 'anonaddy_05' with pid 105911
Jan 21 18:25:10 mail.addy-test.buxnet.net supervisord[442]: 2024-01-21 18:25:10,240 INFO success: anonaddy_05 entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)

/var/log/mail.log: no log after clicking "Resend verification email"
/var/log/mail.err: no log after clicking "Resend verification email"
/var/log/php8.2-fpm.log: no log after clicking "Resend verification email"
/var/log/nginx/access.log

127.0.0.1 - - [21/Jan/2024:18:21:06 +0000] "POST /email/resend HTTP/1.1" 302 422 "https://addy.example.com/email/verify" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36"
127.0.0.1 - - [21/Jan/2024:18:21:08 +0000] "GET /email/verify HTTP/1.1" 200 416 "https://addy.example.com/email/verify" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36"

/var/log/nginx/error.log: no log after clicking "Resend verification email"
/var/log/supervisor/supervisord.log

2024-01-21 18:22:06,338 INFO exited: anonaddy_07 (terminated by SIGKILL; not expected)
2024-01-21 18:22:07,346 INFO spawned: 'anonaddy_07' with pid 104579
2024-01-21 18:22:08,351 INFO success: anonaddy_07 entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-01-21 18:23:37,183 INFO exited: anonaddy_02 (terminated by SIGKILL; not expected)
2024-01-21 18:23:38,222 INFO spawned: 'anonaddy_02' with pid 105232
2024-01-21 18:23:39,227 INFO success: anonaddy_02 entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-01-21 18:25:08,229 INFO exited: anonaddy_05 (terminated by SIGKILL; not expected)
2024-01-21 18:25:09,235 INFO spawned: 'anonaddy_05' with pid 105911
2024-01-21 18:25:10,240 INFO success: anonaddy_05 entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)

/var/log/supervisor/anonaddy_07-stdout---supervisor-5v4ysyfb.log

2024-01-21 18:21:06 App\Notifications\CustomVerifyEmail ............ RUNNING

/var/log/supervisor/anonaddy_02-stdout---supervisor-fl_vnnsu.log

2024-01-21 18:22:37 App\Notifications\CustomVerifyEmail ............ RUNNING

/var/log/supervisor/anonaddy_05-stdout---supervisor-vzctg9t8.log

  2024-01-21 18:24:07 App\Notifications\CustomVerifyEmail ............ RUNNING
  2024-01-21 18:25:07 App\Notifications\CustomVerifyEmail ............ 1m FAIL

/var/www/anonaddy/storage/logs/laravel-2024-01-21.log: no log after clicking "Resend verification email"

Many thanks for any help you can provide.

Originally created by @buxm on GitHub (Jan 21, 2024). Original GitHub issue: https://github.com/anonaddy/anonaddy/issues/584 I'm setting up a self hosted instance on Google Cloud. Google Cloud doesn't allow outbound port 25. However I configured postfix to use Mailjet as a relay host on port 587 to send outbound emails. After following the installation instructions, I registered the administrator user. But then I didn't get the verification email. Even when I click on "Resend verification email", wait until I see the "A fresh verification link has been sent to your email address." message, no email is received. I cannot find any log that can help me investigate. Am I missing something? How can I debug this issue? Addy version: current master branch on Git (I presume v1.0.4). ``` sudo service supervisor status ● supervisor.service - Supervisor process control system for UNIX Loaded: loaded (/lib/systemd/system/supervisor.service; enabled; vendor preset: enabled) Active: active (running) since Sun 2024-01-21 14:36:29 UTC; 4h 10min ago Docs: http://supervisord.org Main PID: 442 (supervisord) Tasks: 9 (limit: 2337) Memory: 263.6M CPU: 1min 9.650s CGroup: /system.slice/supervisor.service ├─ 442 /usr/bin/python3 /usr/bin/supervisord -n -c /etc/supervisor/supervisord.conf ├─ 91631 php /var/www/anonaddy/artisan queue:work redis --sleep=3 --tries=3 ├─ 91632 php /var/www/anonaddy/artisan queue:work redis --sleep=3 --tries=3 ├─ 91647 php /var/www/anonaddy/artisan queue:work redis --sleep=3 --tries=3 ├─ 94140 php /var/www/anonaddy/artisan queue:work redis --sleep=3 --tries=3 ├─103028 php /var/www/anonaddy/artisan queue:work redis --sleep=3 --tries=3 ├─104579 php /var/www/anonaddy/artisan queue:work redis --sleep=3 --tries=3 ├─105232 php /var/www/anonaddy/artisan queue:work redis --sleep=3 --tries=3 └─105911 php /var/www/anonaddy/artisan queue:work redis --sleep=3 --tries=3 Jan 21 18:18:06 mail.addy-test.buxnet.net supervisord[442]: 2024-01-21 18:18:06,881 INFO success: anonaddy_01 entered RUNNING state, process has stayed up for > than 1 seconds (startsecs) Jan 21 18:22:06 mail.addy-test.buxnet.net supervisord[442]: 2024-01-21 18:22:06,338 INFO exited: anonaddy_07 (terminated by SIGKILL; not expected) Jan 21 18:22:07 mail.addy-test.buxnet.net supervisord[442]: 2024-01-21 18:22:07,346 INFO spawned: 'anonaddy_07' with pid 104579 Jan 21 18:22:08 mail.addy-test.buxnet.net supervisord[442]: 2024-01-21 18:22:08,351 INFO success: anonaddy_07 entered RUNNING state, process has stayed up for > than 1 seconds (startsecs) Jan 21 18:23:37 mail.addy-test.buxnet.net supervisord[442]: 2024-01-21 18:23:37,183 INFO exited: anonaddy_02 (terminated by SIGKILL; not expected) Jan 21 18:23:38 mail.addy-test.buxnet.net supervisord[442]: 2024-01-21 18:23:38,222 INFO spawned: 'anonaddy_02' with pid 105232 Jan 21 18:23:39 mail.addy-test.buxnet.net supervisord[442]: 2024-01-21 18:23:39,227 INFO success: anonaddy_02 entered RUNNING state, process has stayed up for > than 1 seconds (startsecs) Jan 21 18:25:08 mail.addy-test.buxnet.net supervisord[442]: 2024-01-21 18:25:08,229 INFO exited: anonaddy_05 (terminated by SIGKILL; not expected) Jan 21 18:25:09 mail.addy-test.buxnet.net supervisord[442]: 2024-01-21 18:25:09,235 INFO spawned: 'anonaddy_05' with pid 105911 Jan 21 18:25:10 mail.addy-test.buxnet.net supervisord[442]: 2024-01-21 18:25:10,240 INFO success: anonaddy_05 entered RUNNING state, process has stayed up for > than 1 seconds (startsecs) ``` `/var/log/mail.log`: no log after clicking "Resend verification email" `/var/log/mail.err`: no log after clicking "Resend verification email" `/var/log/php8.2-fpm.log`: no log after clicking "Resend verification email" `/var/log/nginx/access.log` ``` 127.0.0.1 - - [21/Jan/2024:18:21:06 +0000] "POST /email/resend HTTP/1.1" 302 422 "https://addy.example.com/email/verify" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" 127.0.0.1 - - [21/Jan/2024:18:21:08 +0000] "GET /email/verify HTTP/1.1" 200 416 "https://addy.example.com/email/verify" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" ``` `/var/log/nginx/error.log`: no log after clicking "Resend verification email" `/var/log/supervisor/supervisord.log` ``` 2024-01-21 18:22:06,338 INFO exited: anonaddy_07 (terminated by SIGKILL; not expected) 2024-01-21 18:22:07,346 INFO spawned: 'anonaddy_07' with pid 104579 2024-01-21 18:22:08,351 INFO success: anonaddy_07 entered RUNNING state, process has stayed up for > than 1 seconds (startsecs) 2024-01-21 18:23:37,183 INFO exited: anonaddy_02 (terminated by SIGKILL; not expected) 2024-01-21 18:23:38,222 INFO spawned: 'anonaddy_02' with pid 105232 2024-01-21 18:23:39,227 INFO success: anonaddy_02 entered RUNNING state, process has stayed up for > than 1 seconds (startsecs) 2024-01-21 18:25:08,229 INFO exited: anonaddy_05 (terminated by SIGKILL; not expected) 2024-01-21 18:25:09,235 INFO spawned: 'anonaddy_05' with pid 105911 2024-01-21 18:25:10,240 INFO success: anonaddy_05 entered RUNNING state, process has stayed up for > than 1 seconds (startsecs) ``` `/var/log/supervisor/anonaddy_07-stdout---supervisor-5v4ysyfb.log` ``` 2024-01-21 18:21:06 App\Notifications\CustomVerifyEmail ............ RUNNING ``` `/var/log/supervisor/anonaddy_02-stdout---supervisor-fl_vnnsu.log` ``` 2024-01-21 18:22:37 App\Notifications\CustomVerifyEmail ............ RUNNING ``` `/var/log/supervisor/anonaddy_05-stdout---supervisor-vzctg9t8.log` ``` 2024-01-21 18:24:07 App\Notifications\CustomVerifyEmail ............ RUNNING 2024-01-21 18:25:07 App\Notifications\CustomVerifyEmail ............ 1m FAIL ``` `/var/www/anonaddy/storage/logs/laravel-2024-01-21.log`: no log after clicking "Resend verification email" Many thanks for any help you can provide.
kerem closed this issue 2026-03-14 11:22:52 +03:00
Author
Owner

@willbrowningme commented on GitHub (Jan 22, 2024):

Is port 587 open on the server?

<!-- gh-comment-id:1904357425 --> @willbrowningme commented on GitHub (Jan 22, 2024): Is port 587 open on the server?
Author
Owner

@buxm commented on GitHub (Jan 22, 2024):

Yes, I can successfully netcat the Mailjet server on port 587 from the machine where I installed Addy.io.

<!-- gh-comment-id:1904379044 --> @buxm commented on GitHub (Jan 22, 2024): Yes, I can successfully netcat the Mailjet server on port 587 from the machine where I installed Addy.io.
Author
Owner

@willbrowningme commented on GitHub (Jan 22, 2024):

The only thing I can think is that it must be related to the Postfix Mailjet config. If you remove all of the Mailjet config and set it back to default are any errors then shown?

<!-- gh-comment-id:1904524794 --> @willbrowningme commented on GitHub (Jan 22, 2024): The only thing I can think is that it must be related to the Postfix Mailjet config. If you remove all of the Mailjet config and set it back to default are any errors then shown?
Author
Owner

@buxm commented on GitHub (Jan 22, 2024):

I've just tried to remove everything regarding relayhost and sasl from /etc/postfix/main.cf.
The result is the same as before: no verification email, no meaningful log, apart from:
/var/log/supervisor/anonaddy_05-stdout---supervisor-g3_ti7ze.log

  2024-01-22 21:07:41 App\Notifications\CustomVerifyEmail ............ RUNNING
  2024-01-22 21:09:14 App\Notifications\CustomVerifyEmail ............ RUNNING
  2024-01-22 21:10:15 App\Notifications\CustomVerifyEmail ............ 1m FAIL

Maybe for some reason Postfix wasn't trying to use Mailjet as a relay host even before... but I would expect some log line of at least attempting to send the email somehow....
I've also edited Postfix's master.cf putting smtp -v and smtpd -v everywhere in place of smtpd and smtp in the "command+args" column. But no logs for the outgoing email.
However I do get verbose logs in /var/log/mail.log when someone from the outside world (maybe bots or spammers) attempts to connect to my Postfix on port 25.

I presume there is actually no other log file that I should be checking....

<!-- gh-comment-id:1904845438 --> @buxm commented on GitHub (Jan 22, 2024): I've just tried to remove everything regarding relayhost and sasl from /etc/postfix/main.cf. The result is the same as before: no verification email, no meaningful log, apart from: /var/log/supervisor/anonaddy_05-stdout---supervisor-g3_ti7ze.log ``` 2024-01-22 21:07:41 App\Notifications\CustomVerifyEmail ............ RUNNING 2024-01-22 21:09:14 App\Notifications\CustomVerifyEmail ............ RUNNING 2024-01-22 21:10:15 App\Notifications\CustomVerifyEmail ............ 1m FAIL ``` Maybe for some reason Postfix wasn't trying to use Mailjet as a relay host even before... but I would expect some log line of at least attempting to send the email somehow.... I've also edited Postfix's master.cf putting `smtp -v` and `smtpd -v` everywhere in place of `smtpd` and `smtp` in the "command+args" column. But no logs for the outgoing email. However I do get verbose logs in /var/log/mail.log when someone from the outside world (maybe bots or spammers) attempts to connect to my Postfix on port 25. I presume there is actually no other log file that I should be checking....
Author
Owner

@willbrowningme commented on GitHub (Jan 24, 2024):

If you look at the database are there any jobs listed in the failed_jobs table for those App\Notifications\CustomVerifyEmail failures?

<!-- gh-comment-id:1908049433 --> @willbrowningme commented on GitHub (Jan 24, 2024): If you look at the database are there any jobs listed in the `failed_jobs` table for those `App\Notifications\CustomVerifyEmail` failures?
Author
Owner

@buxm commented on GitHub (Jan 24, 2024):

Thank you for pointing me to this.
I've got 6 rows in the failed_jobs table.
They all contain pretty much the same stuff.
failed_at refers to attempts to send emails both when postfix was configured to use Mailjet as relayhost and when it was configured to send out directly.
Other columns contain:
connection=redis
queue=default
payload={"uuid":"265af6d5-8338-4b77-bd15-c4e61db7512b","timeout":null,"id":"hkJQtzwj7UyS3UHE7sjLQU0wLQRNxtsu","backoff":null,"displayName":"App\\Notifications\\CustomVerifyEmail","maxTries":null,"failOnTimeout":false,"maxExceptions":null,"retryUntil":null,"job":"Illuminate\\Queue\\CallQueuedHandler@call","data":{"command":"eyJpdiI6IkMwRytqTVUvL3E3bVczSjdQejhuc0E9PSIsInZhbHVlIjoiNTBSRzA5L2ZzZjJveU9vZVhCcjRZQXJpSzJndDJ1TXo3SXM2RG1YSlhacFhnWEkwazhhNjZ2YVNwY1Y4L2MzTGRKb0g3TDBmUmFQdFZJQStkdGlYb291NHdqL1pTWW0rWDRzU21CbmVjVGdQWGY1bjFQM28vTTNRRW13WnR5ajB4Nm5VMjNqQXZHaU5xSDFOQzBJWjJ1ekVYRVFWUlNtOXR1ejFSMkRqMnRaai9BeFYyaE1rTFFSNUxMb0FaM2lERHdaVnAvQUE3UDNTVk1pTzRBZi9uRkNsT0c4RjRFN0hxdnA5aWd2VjVYeDFHSkpVZWpMSFBiMHQvYjRJK0xZSDdUaExrS0hWQVFlM2pJRnAweXYvS3VVVkxTV0EwajB0YmdibUxCZjA5VTNrK2dZOVNrTkdJa2FVMXJjYUhyVndxWk91YkdYc3lyT21MUk1NQVMzWXZtaU5UTXhZdUZFcm5UaUZpQXdENjh1TjFtNWNaNUQxbjcwcStQaUcvbDNVS3dVTzh6eG5mRFlMa3B5amw0dnlQb21zbjg3TnJFdVVnSXBuSTd6bkVXcVcydjBIWFhaMjNsRndHbG5UaDVGdW1wbzhqejJuSVZTY1c1Q2dyeGQvSEo1OUxCVkgxRFNvNkdlRGhFVUFwVWpiOEthWHBKcWhZY0drb05VTk9EUlpTalBOMlFCSU1uemloVDNMTVlSZ2pMcDlxYWIwVGZTWFVNTmhnNDczNC9TS0ZhbXp0Y3VhYUhnOFF0RmdNSGpxa3RWcXdIdUlGMlpwQk5rakFMNFA4dmh6Y2VsQVpTTVlrRlhYdHpYaG5CTVFBbjFLM3JZN09zdVBmNUFNL2prclJGTCtOc3ZQQjB6UUR3UjR6aE0xU2U0bytxcHh5WVVPSjlLUlEvcC8yQkhjcjVKVDlmeW1QMGtZL3hGQUgzSVlUUVNUR3ZUSDk4UTVMY2c4ZzVRTS9nPT0iLCJtYWMiOiI3ZDdjY2ZmNDVkMTNkZWY2ZTliMGE2ODhhMGY1YzY1NzA1YWNkOGQ1MmM1Y2I2MDc5ZTRjNGU3OTIyOTIzZjk1IiwidGFnIjoiIn0=","commandName":"Illuminate\\Notifications\\SendQueuedNotifications"},"attempts":2}
or something similar with different ids.

exception=Illuminate\Queue\TimeoutExceededException: App\Notifications\CustomVerifyEmail has timed out. in /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/TimeoutExceededException.php:15 Stack trace: #0 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(796): Illuminate\Queue\TimeoutExceededException::forJob() #1 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(217): Illuminate\Queue\Worker->timeoutExceededException() #2 /var/www/anonaddy/vendor/symfony/mailer/Transport/Smtp/Stream/SocketStream.php(154): Illuminate\Queue\Worker->Illuminate\Queue\{closure}() #3 [internal function]: Symfony\Component\Mailer\Transport\Smtp\Stream\SocketStream->Symfony\Component\Mailer\Transport\Smtp\Stream\{closure}() #4 /var/www/anonaddy/vendor/symfony/mailer/Transport/Smtp/Stream/SocketStream.php(157): stream_socket_client() #5 /var/www/anonaddy/vendor/symfony/mailer/Transport/Smtp/SmtpTransport.php(275): Symfony\Component\Mailer\Transport\Smtp\Stream\SocketStream->initialize() #6 /var/www/anonaddy/vendor/symfony/mailer/Transport/Smtp/SmtpTransport.php(213): Symfony\Component\Mailer\Transport\Smtp\SmtpTransport->start() #7 /var/www/anonaddy/vendor/symfony/mailer/Transport/AbstractTransport.php(69): Symfony\Component\Mailer\Transport\Smtp\SmtpTransport->doSend() #8 /var/www/anonaddy/vendor/symfony/mailer/Transport/Smtp/SmtpTransport.php(137): Symfony\Component\Mailer\Transport\AbstractTransport->send() #9 /var/www/anonaddy/app/CustomMailDriver/CustomMailer.php(185): Symfony\Component\Mailer\Transport\Smtp\SmtpTransport->send() #10 /var/www/anonaddy/app/CustomMailDriver/CustomMailer.php(136): App\CustomMailDriver\CustomMailer->sendSymfonyMessage() #11 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Notifications/Channels/MailChannel.php(66): App\CustomMailDriver\CustomMailer->send() #12 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Notifications/NotificationSender.php(148): Illuminate\Notifications\Channels\MailChannel->send() #13 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Notifications/NotificationSender.php(106): Illuminate\Notifications\NotificationSender->sendToNotifiable() #14 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Support/Traits/Localizable.php(19): Illuminate\Notifications\NotificationSender->Illuminate\Notifications\{closure}() #15 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Notifications/NotificationSender.php(101): Illuminate\Notifications\NotificationSender->withLocale() #16 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Notifications/ChannelManager.php(54): Illuminate\Notifications\NotificationSender->sendNow() #17 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Notifications/SendQueuedNotifications.php(119): Illuminate\Notifications\ChannelManager->sendNow() #18 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(36): Illuminate\Notifications\SendQueuedNotifications->handle() #19 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Container/Util.php(41): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}() #20 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(93): Illuminate\Container\Util::unwrapIfClosure() #21 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(35): Illuminate\Container\BoundMethod::callBoundMethod() #22 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Container/Container.php(662): Illuminate\Container\BoundMethod::call() #23 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(128): Illuminate\Container\Container->call() #24 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(144): Illuminate\Bus\Dispatcher->Illuminate\Bus\{closure}() #25 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(119): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}() #26 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(132): Illuminate\Pipeline\Pipeline->then() #27 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(123): Illuminate\Bus\Dispatcher->dispatchNow() #28 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(144): Illuminate\Queue\CallQueuedHandler->Illuminate\Queue\{closure}() #29 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(119): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}() #30 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(122): Illuminate\Pipeline\Pipeline->then() #31 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(70): Illuminate\Queue\CallQueuedHandler->dispatchThroughMiddleware() #32 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/Jobs/Job.php(102): Illuminate\Queue\CallQueuedHandler->call() #33 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(439): Illuminate\Queue\Jobs\Job->fire() #34 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(389): Illuminate\Queue\Worker->process() #35 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(176): Illuminate\Queue\Worker->runJob() #36 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(137): Illuminate\Queue\Worker->daemon() #37 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(120): Illuminate\Queue\Console\WorkCommand->runWorker() #38 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(36): Illuminate\Queue\Console\WorkCommand->handle() #39 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Container/Util.php(41): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}() #40 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(93): Illuminate\Container\Util::unwrapIfClosure() #41 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(35): Illuminate\Container\BoundMethod::callBoundMethod() #42 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Container/Container.php(662): Illuminate\Container\BoundMethod::call() #43 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Console/Command.php(211): Illuminate\Container\Container->call() #44 /var/www/anonaddy/vendor/symfony/console/Command/Command.php(326): Illuminate\Console\Command->execute() #45 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Console/Command.php(180): Symfony\Component\Console\Command\Command->run() #46 /var/www/anonaddy/vendor/symfony/console/Application.php(1096): Illuminate\Console\Command->run() #47 /var/www/anonaddy/vendor/symfony/console/Application.php(324): Symfony\Component\Console\Application->doRunCommand() #48 /var/www/anonaddy/vendor/symfony/console/Application.php(175): Symfony\Component\Console\Application->doRun() #49 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(201): Symfony\Component\Console\Application->run() #50 /var/www/anonaddy/artisan(35): Illuminate\Foundation\Console\Kernel->handle() #51 {main}

From the looks of it, it seems that the php script cannot even connect to the local postfix to send an email. Maybe I've got something wrong in the Postfix config, so that it blocks local connections. I'll try and have a look later.

<!-- gh-comment-id:1908179280 --> @buxm commented on GitHub (Jan 24, 2024): Thank you for pointing me to this. I've got 6 rows in the `failed_jobs` table. They all contain pretty much the same stuff. `failed_at` refers to attempts to send emails both when postfix was configured to use Mailjet as relayhost and when it was configured to send out directly. Other columns contain: `connection`=`redis` `queue`=`default` `payload`=`{"uuid":"265af6d5-8338-4b77-bd15-c4e61db7512b","timeout":null,"id":"hkJQtzwj7UyS3UHE7sjLQU0wLQRNxtsu","backoff":null,"displayName":"App\\Notifications\\CustomVerifyEmail","maxTries":null,"failOnTimeout":false,"maxExceptions":null,"retryUntil":null,"job":"Illuminate\\Queue\\CallQueuedHandler@call","data":{"command":"eyJpdiI6IkMwRytqTVUvL3E3bVczSjdQejhuc0E9PSIsInZhbHVlIjoiNTBSRzA5L2ZzZjJveU9vZVhCcjRZQXJpSzJndDJ1TXo3SXM2RG1YSlhacFhnWEkwazhhNjZ2YVNwY1Y4L2MzTGRKb0g3TDBmUmFQdFZJQStkdGlYb291NHdqL1pTWW0rWDRzU21CbmVjVGdQWGY1bjFQM28vTTNRRW13WnR5ajB4Nm5VMjNqQXZHaU5xSDFOQzBJWjJ1ekVYRVFWUlNtOXR1ejFSMkRqMnRaai9BeFYyaE1rTFFSNUxMb0FaM2lERHdaVnAvQUE3UDNTVk1pTzRBZi9uRkNsT0c4RjRFN0hxdnA5aWd2VjVYeDFHSkpVZWpMSFBiMHQvYjRJK0xZSDdUaExrS0hWQVFlM2pJRnAweXYvS3VVVkxTV0EwajB0YmdibUxCZjA5VTNrK2dZOVNrTkdJa2FVMXJjYUhyVndxWk91YkdYc3lyT21MUk1NQVMzWXZtaU5UTXhZdUZFcm5UaUZpQXdENjh1TjFtNWNaNUQxbjcwcStQaUcvbDNVS3dVTzh6eG5mRFlMa3B5amw0dnlQb21zbjg3TnJFdVVnSXBuSTd6bkVXcVcydjBIWFhaMjNsRndHbG5UaDVGdW1wbzhqejJuSVZTY1c1Q2dyeGQvSEo1OUxCVkgxRFNvNkdlRGhFVUFwVWpiOEthWHBKcWhZY0drb05VTk9EUlpTalBOMlFCSU1uemloVDNMTVlSZ2pMcDlxYWIwVGZTWFVNTmhnNDczNC9TS0ZhbXp0Y3VhYUhnOFF0RmdNSGpxa3RWcXdIdUlGMlpwQk5rakFMNFA4dmh6Y2VsQVpTTVlrRlhYdHpYaG5CTVFBbjFLM3JZN09zdVBmNUFNL2prclJGTCtOc3ZQQjB6UUR3UjR6aE0xU2U0bytxcHh5WVVPSjlLUlEvcC8yQkhjcjVKVDlmeW1QMGtZL3hGQUgzSVlUUVNUR3ZUSDk4UTVMY2c4ZzVRTS9nPT0iLCJtYWMiOiI3ZDdjY2ZmNDVkMTNkZWY2ZTliMGE2ODhhMGY1YzY1NzA1YWNkOGQ1MmM1Y2I2MDc5ZTRjNGU3OTIyOTIzZjk1IiwidGFnIjoiIn0=","commandName":"Illuminate\\Notifications\\SendQueuedNotifications"},"attempts":2}` or something similar with different ids. `exception`=`Illuminate\Queue\TimeoutExceededException: App\Notifications\CustomVerifyEmail has timed out. in /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/TimeoutExceededException.php:15 Stack trace: #0 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(796): Illuminate\Queue\TimeoutExceededException::forJob() #1 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(217): Illuminate\Queue\Worker->timeoutExceededException() #2 /var/www/anonaddy/vendor/symfony/mailer/Transport/Smtp/Stream/SocketStream.php(154): Illuminate\Queue\Worker->Illuminate\Queue\{closure}() #3 [internal function]: Symfony\Component\Mailer\Transport\Smtp\Stream\SocketStream->Symfony\Component\Mailer\Transport\Smtp\Stream\{closure}() #4 /var/www/anonaddy/vendor/symfony/mailer/Transport/Smtp/Stream/SocketStream.php(157): stream_socket_client() #5 /var/www/anonaddy/vendor/symfony/mailer/Transport/Smtp/SmtpTransport.php(275): Symfony\Component\Mailer\Transport\Smtp\Stream\SocketStream->initialize() #6 /var/www/anonaddy/vendor/symfony/mailer/Transport/Smtp/SmtpTransport.php(213): Symfony\Component\Mailer\Transport\Smtp\SmtpTransport->start() #7 /var/www/anonaddy/vendor/symfony/mailer/Transport/AbstractTransport.php(69): Symfony\Component\Mailer\Transport\Smtp\SmtpTransport->doSend() #8 /var/www/anonaddy/vendor/symfony/mailer/Transport/Smtp/SmtpTransport.php(137): Symfony\Component\Mailer\Transport\AbstractTransport->send() #9 /var/www/anonaddy/app/CustomMailDriver/CustomMailer.php(185): Symfony\Component\Mailer\Transport\Smtp\SmtpTransport->send() #10 /var/www/anonaddy/app/CustomMailDriver/CustomMailer.php(136): App\CustomMailDriver\CustomMailer->sendSymfonyMessage() #11 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Notifications/Channels/MailChannel.php(66): App\CustomMailDriver\CustomMailer->send() #12 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Notifications/NotificationSender.php(148): Illuminate\Notifications\Channels\MailChannel->send() #13 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Notifications/NotificationSender.php(106): Illuminate\Notifications\NotificationSender->sendToNotifiable() #14 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Support/Traits/Localizable.php(19): Illuminate\Notifications\NotificationSender->Illuminate\Notifications\{closure}() #15 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Notifications/NotificationSender.php(101): Illuminate\Notifications\NotificationSender->withLocale() #16 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Notifications/ChannelManager.php(54): Illuminate\Notifications\NotificationSender->sendNow() #17 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Notifications/SendQueuedNotifications.php(119): Illuminate\Notifications\ChannelManager->sendNow() #18 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(36): Illuminate\Notifications\SendQueuedNotifications->handle() #19 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Container/Util.php(41): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}() #20 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(93): Illuminate\Container\Util::unwrapIfClosure() #21 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(35): Illuminate\Container\BoundMethod::callBoundMethod() #22 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Container/Container.php(662): Illuminate\Container\BoundMethod::call() #23 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(128): Illuminate\Container\Container->call() #24 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(144): Illuminate\Bus\Dispatcher->Illuminate\Bus\{closure}() #25 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(119): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}() #26 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(132): Illuminate\Pipeline\Pipeline->then() #27 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(123): Illuminate\Bus\Dispatcher->dispatchNow() #28 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(144): Illuminate\Queue\CallQueuedHandler->Illuminate\Queue\{closure}() #29 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(119): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}() #30 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(122): Illuminate\Pipeline\Pipeline->then() #31 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(70): Illuminate\Queue\CallQueuedHandler->dispatchThroughMiddleware() #32 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/Jobs/Job.php(102): Illuminate\Queue\CallQueuedHandler->call() #33 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(439): Illuminate\Queue\Jobs\Job->fire() #34 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(389): Illuminate\Queue\Worker->process() #35 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(176): Illuminate\Queue\Worker->runJob() #36 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(137): Illuminate\Queue\Worker->daemon() #37 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(120): Illuminate\Queue\Console\WorkCommand->runWorker() #38 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(36): Illuminate\Queue\Console\WorkCommand->handle() #39 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Container/Util.php(41): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}() #40 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(93): Illuminate\Container\Util::unwrapIfClosure() #41 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(35): Illuminate\Container\BoundMethod::callBoundMethod() #42 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Container/Container.php(662): Illuminate\Container\BoundMethod::call() #43 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Console/Command.php(211): Illuminate\Container\Container->call() #44 /var/www/anonaddy/vendor/symfony/console/Command/Command.php(326): Illuminate\Console\Command->execute() #45 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Console/Command.php(180): Symfony\Component\Console\Command\Command->run() #46 /var/www/anonaddy/vendor/symfony/console/Application.php(1096): Illuminate\Console\Command->run() #47 /var/www/anonaddy/vendor/symfony/console/Application.php(324): Symfony\Component\Console\Application->doRunCommand() #48 /var/www/anonaddy/vendor/symfony/console/Application.php(175): Symfony\Component\Console\Application->doRun() #49 /var/www/anonaddy/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(201): Symfony\Component\Console\Application->run() #50 /var/www/anonaddy/artisan(35): Illuminate\Foundation\Console\Kernel->handle() #51 {main}` From the looks of it, it seems that the php script cannot even connect to the local postfix to send an email. Maybe I've got something wrong in the Postfix config, so that it blocks local connections. I'll try and have a look later.
Author
Owner

@willbrowningme commented on GitHub (Jan 25, 2024):

Yes symfony mailer cannot connect via SMTP which is causing it to timeout, you'll have to find out why that is to resolve it. I'm closing this as it doesn't look like an issue with addy.io itself.

<!-- gh-comment-id:1909746289 --> @willbrowningme commented on GitHub (Jan 25, 2024): Yes symfony mailer cannot connect via SMTP which is causing it to timeout, you'll have to find out why that is to resolve it. I'm closing this as it doesn't look like an issue with addy.io itself.
Author
Owner

@buxm commented on GitHub (Jan 29, 2024):

I found out that my server on Google Cloud resolves its hostname (e.g. mail.example.com) to its public IP address, not its private or localhost one. This likely causes routing issues so essentially you cannot connect to mail.example.com from the server itself.
So I had to set MAIL_HOST=localhost in the Addy.io .env file and also remove the variables MAIL_ENCRYPTION and MAIL_VERIFY_PEER to avoid using TLS on the connection to localhost which would fail the validation of the certificate's FQDN.
Alternatively I could have added 127.0.0.1 mail.example.com in my /etc/hosts file, but I preferred touching as few configuration files as possible in my setup process.
Now emails get correctly sent through Mailjet as a relayhost.

As a feedback for Addy.io, I found it a bit difficult to debug issues due to logs being scattered in multiple places.
What I collected so far is:

  • /var/log/mail.log: Postfix logs
  • /var/log/mail.err: Postfix errors - but not sure when it is used
  • /var/log/php8.2-fpm.log: PHP logs
  • /var/log/nginx/access.log: log of HTTP requests
  • /var/log/nginx/error.log: NGINX errors
  • /var/log/supervisor/*.log: Supervisor logs - other logs generated by PHP code
  • /var/www/anonaddy/storage/logs/laravel*.log: PHP app logs
  • failed_jobs table on DB: error logs generated by failed jobs (presumably those run by crontab)
  • maybe also failed_deliveries table on DB

Maybe a documented list of places to look for relevant logs, and ideally what they contain, would help in such instances.

Anyway thank you so much @willbrowningme for pointing me to the right place! :-)

<!-- gh-comment-id:1914891493 --> @buxm commented on GitHub (Jan 29, 2024): I found out that my server on Google Cloud resolves its hostname (e.g. `mail.example.com`) to its _public_ IP address, not its private or localhost one. This likely causes routing issues so essentially you cannot connect to `mail.example.com` from the server itself. So I had to set `MAIL_HOST=localhost` in the Addy.io `.env` file and also remove the variables `MAIL_ENCRYPTION` and `MAIL_VERIFY_PEER` to avoid using TLS on the connection to localhost which would fail the validation of the certificate's FQDN. Alternatively I could have added `127.0.0.1 mail.example.com` in my `/etc/hosts` file, but I preferred touching as few configuration files as possible in my setup process. Now emails get correctly sent through Mailjet as a relayhost. As a feedback for Addy.io, I found it a bit difficult to debug issues due to logs being scattered in multiple places. What I collected so far is: - `/var/log/mail.log`: Postfix logs - `/var/log/mail.err`: Postfix errors - but not sure when it is used - `/var/log/php8.2-fpm.log`: PHP logs - `/var/log/nginx/access.log`: log of HTTP requests - `/var/log/nginx/error.log`: NGINX errors - `/var/log/supervisor/*.log`: Supervisor logs - other logs generated by PHP code - `/var/www/anonaddy/storage/logs/laravel*.log`: PHP app logs - `failed_jobs` table on DB: error logs generated by failed jobs (presumably those run by crontab) - maybe also `failed_deliveries` table on DB Maybe a documented list of places to look for relevant logs, and ideally what they contain, would help in such instances. Anyway thank you so much @willbrowningme for pointing me to the right place! :-)
Sign in to join this conversation.
No labels
bug
pull-request
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
starred/anonaddy#988
No description provided.