search

docusealco / docuseal

Open source DocuSign alternative. Create, fill, and sign digital documents ✍️
https://www.docuseal.co
GNU Affero General Public License v3.0
5.7k stars 378 forks source link

inconsistent sending of mails #161

Closed hknobbe closed 7 months ago

hknobbe commented 7 months ago

Hi!

I've noticed a inconsistency in the sending of emails. The logs show the following errors:

I, [2023-12-14T09:39:23.807400 #1]  INFO -- : [f7295912-f22a-4cb1-be21-ff0b246827a0] [ActiveJob] Enqueued ActiveStorage::AnalyzeJob (Job ID: 03f0caf6-c04a-4662-a5b9-6e3a9a797a05) to Async(default) with arguments: #<GlobalID:0x00007f4b1f01da08 @uri=#<URI::GID gid://docu-seal/ActiveStorage::Blob/66>>

I, [2023-12-14T09:39:23.814195 #1]  INFO -- : [f7295912-f22a-4cb1-be21-ff0b246827a0] {"method":"POST","path":"/api/attachments","format":"json","controller":"Api::AttachmentsController","action":"create","status":200,"allocations":4376,"duration":1913.56,"view":0.26,"db":20.17,"fwd":"77.167.120.118"}

I, [2023-12-14T09:39:23.816289 #1]  INFO -- : [ActiveJob] [ActiveStorage::AnalyzeJob] [03f0caf6-c04a-4662-a5b9-6e3a9a797a05] Performing ActiveStorage::AnalyzeJob (Job ID: 03f0caf6-c04a-4662-a5b9-6e3a9a797a05) from Async(default) enqueued at 2023-12-14T09:39:23Z with arguments: #<GlobalID:0x00007f4b1f02edd0 @uri=#<URI::GID gid://docu-seal/ActiveStorage::Blob/66>>

I, [2023-12-14T09:39:23.928243 #1]  INFO -- : [9d2e4949-0b2e-466d-bef6-d1a7984b3af6] [ActiveJob] Enqueued ProcessSubmitterCompletionJob (Job ID: 73cefa03-d78a-4458-ab7d-d4a3ade9a45c) to Async(default) with arguments: #<GlobalID:0x00007f4b1f683140 @uri=#<URI::GID gid://docu-seal/Submitter/13>>

I, [2023-12-14T09:39:23.930331 #1]  INFO -- : [9d2e4949-0b2e-466d-bef6-d1a7984b3af6] {"method":"PUT","path":"/s/yX8pkxJmwNguhm","format":"*/*","controller":"SubmitFormController","action":"update","status":200,"allocations":4466,"duration":25.2,"view":0.0,"db":7.01,"fwd":"77.167.120.118"}

I, [2023-12-14T09:39:23.972681 #1]  INFO -- : [ActiveJob] [ProcessSubmitterCompletionJob] [73cefa03-d78a-4458-ab7d-d4a3ade9a45c] Performing ProcessSubmitterCompletionJob (Job ID: 73cefa03-d78a-4458-ab7d-d4a3ade9a45c) from Async(default) enqueued at 2023-12-14T09:39:23Z with arguments: #<GlobalID:0x00007f4b2744ff60 @uri=#<URI::GID gid://docu-seal/Submitter/13>>

I, [2023-12-14T09:39:24.345865 #1]  INFO -- : [ActiveJob] [ActiveStorage::AnalyzeJob] [03f0caf6-c04a-4662-a5b9-6e3a9a797a05] Performed ActiveStorage::AnalyzeJob (Job ID: 03f0caf6-c04a-4662-a5b9-6e3a9a797a05) from Async(default) in 537.74ms

I, [2023-12-14T09:39:30.652502 #1]  INFO -- : [ActiveJob] [ProcessSubmitterCompletionJob] [73cefa03-d78a-4458-ab7d-d4a3ade9a45c] Enqueued ActionMailer::MailDeliveryJob (Job ID: 4e614c17-9bab-482c-b2ab-b2248440815f) to Async(default) with arguments: "SubmitterMailer", "completed_email", "deliver_now!", {:args=>[#<GlobalID:0x00007f4b1dc3a1d0 @uri=#<URI::GID gid://docu-seal/Submitter/13>>, #<GlobalID:0x00007f4b1dc39d48 @uri=#<URI::GID gid://docu-seal/User/1>>, {:bcc=>nil}]}

I, [2023-12-14T09:39:30.654312 #1]  INFO -- : [ActiveJob] [ProcessSubmitterCompletionJob] [73cefa03-d78a-4458-ab7d-d4a3ade9a45c] Enqueued ActionMailer::MailDeliveryJob (Job ID: cde60081-55ba-42ca-beb0-d0c61ebf424a) to Async(default) with arguments: "SubmitterMailer", "documents_copy_email", "deliver_now!", {:args=>[#<GlobalID:0x00007f4b1dc360a8 @uri=#<URI::GID gid://docu-seal/Submitter/13>>, {:to=>"\"Hexxxxxxxbbe\" <hexxxxxxxxn@xxxxxxxx.nl>, \"Hxxxxxxxn\" <hkxxxxxxe@xxxxxx.com>"}]}

I, [2023-12-14T09:39:30.659319 #1]  INFO -- : [ActiveJob] [ActionMailer::MailDeliveryJob] [cde60081-55ba-42ca-beb0-d0c61ebf424a] Performing ActionMailer::MailDeliveryJob (Job ID: cde60081-55ba-42ca-beb0-d0c61ebf424a) from Async(default) enqueued at 2023-12-14T09:39:30Z with arguments: "SubmitterMailer", "documents_copy_email", "deliver_now!", {:args=>[#<GlobalID:0x00007f4b1dc4be80 @uri=#<URI::GID gid://docu-seal/Submitter/13>>, {:to=>"\"Hexxxxxxxxbe\" <henk-jaxxxxxxxxxxxes.nl>, \"Hexxxxxan\" <hknxxxxxxxxxxom>"}]}

I, [2023-12-14T09:39:30.660188 #1]  INFO -- : [ActiveJob] [ActionMailer::MailDeliveryJob] [4e614c17-9bab-482c-b2ab-b2248440815f] Performing ActionMailer::MailDeliveryJob (Job ID: 4e614c17-9bab-482c-b2ab-b2248440815f) from Async(default) enqueued at 2023-12-14T09:39:30Z with arguments: "SubmitterMailer", "completed_email", "deliver_now!", {:args=>[#<GlobalID:0x00007f4b1dc4a4e0 @uri=#<URI::GID gid://docu-seal/Submitter/13>>, #<GlobalID:0x00007f4b1dc4a058 @uri=#<URI::GID gid://docu-seal/User/1>>, {:bcc=>nil}]}

I, [2023-12-14T09:39:30.671133 #1]  INFO -- : [ActiveJob] [ProcessSubmitterCompletionJob] [73cefa03-d78a-4458-ab7d-d4a3ade9a45c] Performed ProcessSubmitterCompletionJob (Job ID: 73cefa03-d78a-4458-ab7d-d4a3ade9a45c) from Async(default) in 6742.25ms

E, [2023-12-14T09:39:37.632007 #1] ERROR -- : [ActiveJob] [ActionMailer::MailDeliveryJob] [4e614c17-9bab-482c-b2ab-b2248440815f] Error performing ActionMailer::MailDeliveryJob (Job ID: 4e614c17-9bab-482c-b2ab-b2248440815f) from Async(default) in 6978.91ms: Net::ReadTimeout (Net::ReadTimeout with #<Socket:(closed)>):

/usr/local/lib/ruby/3.2.0/net/protocol.rb:229:in `rbuf_fill'

/usr/local/lib/ruby/3.2.0/net/protocol.rb:199:in `readuntil'

/usr/local/lib/ruby/3.2.0/net/protocol.rb:209:in `readline'

/usr/local/lib/ruby/gems/3.2.0/gems/net-smtp-0.3.3/lib/net/smtp.rb:1057:in `recv_response'

/usr/local/lib/ruby/gems/3.2.0/gems/net-smtp-0.3.3/lib/net/smtp.rb:1019:in `block in data'

/usr/local/lib/ruby/gems/3.2.0/gems/net-smtp-0.3.3/lib/net/smtp.rb:1067:in `critical'

/usr/local/lib/ruby/gems/3.2.0/gems/net-smtp-0.3.3/lib/net/smtp.rb:1005:in `data'

/usr/local/lib/ruby/gems/3.2.0/gems/net-smtp-0.3.3/lib/net/smtp.rb:768:in `block in send_message'

/usr/local/lib/ruby/gems/3.2.0/gems/net-smtp-0.3.3/lib/net/smtp.rb:962:in `rcptto_list'

/usr/local/lib/ruby/gems/3.2.0/gems/net-smtp-0.3.3/lib/net/smtp.rb:768:in `send_message'

/usr/local/bundle/gems/mail-2.8.1/lib/mail/network/delivery_methods/smtp_connection.rb:53:in `deliver!'

/usr/local/bundle/gems/mail-2.8.1/lib/mail/network/delivery_methods/smtp.rb:101:in `block in deliver!'

/usr/local/lib/ruby/gems/3.2.0/gems/net-smtp-0.3.3/lib/net/smtp.rb:612:in `start'

/usr/local/bundle/gems/mail-2.8.1/lib/mail/network/delivery_methods/smtp.rb:109:in `start_smtp_session'

/usr/local/bundle/gems/mail-2.8.1/lib/mail/network/delivery_methods/smtp.rb:100:in `deliver!'

/usr/local/bundle/gems/mail-2.8.1/lib/mail/message.rb:269:in `deliver!'

/usr/local/bundle/gems/actionmailer-7.0.7/lib/action_mailer/message_delivery.rb:109:in `block in deliver_now!'

/usr/local/bundle/gems/actionmailer-7.0.7/lib/action_mailer/rescuable.rb:19:in `handle_exceptions'

/usr/local/bundle/gems/actionmailer-7.0.7/lib/action_mailer/message_delivery.rb:108:in `deliver_now!'

/usr/local/bundle/gems/actionmailer-7.0.7/lib/action_mailer/mail_delivery_job.rb:23:in `perform'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/execution.rb:65:in `block in _perform_job'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/callbacks.rb:118:in `block in run_callbacks'

/usr/local/bundle/gems/i18n-1.14.1/lib/i18n.rb:322:in `with_locale'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/translation.rb:9:in `block (2 levels) in <module:Translation>'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/callbacks.rb:127:in `instance_exec'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/callbacks.rb:127:in `block in run_callbacks'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/core_ext/time/zones.rb:65:in `use_zone'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/timezones.rb:9:in `block (2 levels) in <module:Timezones>'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/callbacks.rb:127:in `instance_exec'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/callbacks.rb:127:in `block in run_callbacks'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/callbacks.rb:138:in `run_callbacks'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/execution.rb:64:in `_perform_job'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/instrumentation.rb:20:in `_perform_job'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/execution.rb:52:in `perform_now'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/instrumentation.rb:14:in `block in perform_now'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/instrumentation.rb:25:in `block in instrument'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/notifications.rb:206:in `block in instrument'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/notifications/instrumenter.rb:24:in `instrument'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/notifications.rb:206:in `instrument'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/instrumentation.rb:35:in `instrument'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/instrumentation.rb:14:in `perform_now'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/logging.rb:18:in `block in perform_now'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/tagged_logging.rb:99:in `block in tagged'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/tagged_logging.rb:37:in `tagged'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/tagged_logging.rb:99:in `tagged'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/logging.rb:25:in `tag_logger'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/logging.rb:18:in `perform_now'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/execution.rb:30:in `block in execute'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/callbacks.rb:118:in `block in run_callbacks'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/railtie.rb:54:in `block (4 levels) in <class:Railtie>'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/execution_wrapper.rb:92:in `wrap'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/reloader.rb:72:in `block in wrap'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/execution_wrapper.rb:92:in `wrap'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/reloader.rb:71:in `wrap'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/railtie.rb:53:in `block (3 levels) in <class:Railtie>'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/callbacks.rb:127:in `instance_exec'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/callbacks.rb:127:in `block in run_callbacks'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/callbacks.rb:138:in `run_callbacks'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/execution.rb:28:in `execute'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/queue_adapters/async_adapter.rb:70:in `perform'

/usr/local/bundle/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:352:in `run_task'

/usr/local/bundle/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:343:in `block (3 levels) in create_worker'

/usr/local/bundle/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:334:in `loop'

/usr/local/bundle/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:334:in `block (2 levels) in create_worker'

/usr/local/bundle/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:333:in `catch'

/usr/local/bundle/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:333:in `block in create_worker'

E, [2023-12-14T09:39:38.056723 #1] ERROR -- : [ActiveJob] [ActionMailer::MailDeliveryJob] [cde60081-55ba-42ca-beb0-d0c61ebf424a] Error performing ActionMailer::MailDeliveryJob (Job ID: cde60081-55ba-42ca-beb0-d0c61ebf424a) from Async(default) in 7401.47ms: Net::ReadTimeout (Net::ReadTimeout with #<Socket:(closed)>):

/usr/local/lib/ruby/3.2.0/net/protocol.rb:229:in `rbuf_fill'

/usr/local/lib/ruby/3.2.0/net/protocol.rb:199:in `readuntil'

/usr/local/lib/ruby/3.2.0/net/protocol.rb:209:in `readline'

/usr/local/lib/ruby/gems/3.2.0/gems/net-smtp-0.3.3/lib/net/smtp.rb:1057:in `recv_response'

/usr/local/lib/ruby/gems/3.2.0/gems/net-smtp-0.3.3/lib/net/smtp.rb:1019:in `block in data'

/usr/local/lib/ruby/gems/3.2.0/gems/net-smtp-0.3.3/lib/net/smtp.rb:1067:in `critical'

/usr/local/lib/ruby/gems/3.2.0/gems/net-smtp-0.3.3/lib/net/smtp.rb:1005:in `data'

/usr/local/lib/ruby/gems/3.2.0/gems/net-smtp-0.3.3/lib/net/smtp.rb:768:in `block in send_message'

/usr/local/lib/ruby/gems/3.2.0/gems/net-smtp-0.3.3/lib/net/smtp.rb:962:in `rcptto_list'

/usr/local/lib/ruby/gems/3.2.0/gems/net-smtp-0.3.3/lib/net/smtp.rb:768:in `send_message'

/usr/local/bundle/gems/mail-2.8.1/lib/mail/network/delivery_methods/smtp_connection.rb:53:in `deliver!'

/usr/local/bundle/gems/mail-2.8.1/lib/mail/network/delivery_methods/smtp.rb:101:in `block in deliver!'

/usr/local/lib/ruby/gems/3.2.0/gems/net-smtp-0.3.3/lib/net/smtp.rb:612:in `start'

/usr/local/bundle/gems/mail-2.8.1/lib/mail/network/delivery_methods/smtp.rb:109:in `start_smtp_session'

/usr/local/bundle/gems/mail-2.8.1/lib/mail/network/delivery_methods/smtp.rb:100:in `deliver!'

/usr/local/bundle/gems/mail-2.8.1/lib/mail/message.rb:269:in `deliver!'

/usr/local/bundle/gems/actionmailer-7.0.7/lib/action_mailer/message_delivery.rb:109:in `block in deliver_now!'

/usr/local/bundle/gems/actionmailer-7.0.7/lib/action_mailer/rescuable.rb:19:in `handle_exceptions'

/usr/local/bundle/gems/actionmailer-7.0.7/lib/action_mailer/message_delivery.rb:108:in `deliver_now!'

/usr/local/bundle/gems/actionmailer-7.0.7/lib/action_mailer/mail_delivery_job.rb:23:in `perform'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/execution.rb:65:in `block in _perform_job'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/callbacks.rb:118:in `block in run_callbacks'

/usr/local/bundle/gems/i18n-1.14.1/lib/i18n.rb:322:in `with_locale'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/translation.rb:9:in `block (2 levels) in <module:Translation>'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/callbacks.rb:127:in `instance_exec'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/callbacks.rb:127:in `block in run_callbacks'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/core_ext/time/zones.rb:65:in `use_zone'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/timezones.rb:9:in `block (2 levels) in <module:Timezones>'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/callbacks.rb:127:in `instance_exec'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/callbacks.rb:127:in `block in run_callbacks'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/callbacks.rb:138:in `run_callbacks'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/execution.rb:64:in `_perform_job'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/instrumentation.rb:20:in `_perform_job'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/execution.rb:52:in `perform_now'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/instrumentation.rb:14:in `block in perform_now'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/instrumentation.rb:25:in `block in instrument'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/notifications.rb:206:in `block in instrument'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/notifications/instrumenter.rb:24:in `instrument'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/notifications.rb:206:in `instrument'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/instrumentation.rb:35:in `instrument'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/instrumentation.rb:14:in `perform_now'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/logging.rb:18:in `block in perform_now'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/tagged_logging.rb:99:in `block in tagged'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/tagged_logging.rb:37:in `tagged'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/tagged_logging.rb:99:in `tagged'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/logging.rb:25:in `tag_logger'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/logging.rb:18:in `perform_now'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/execution.rb:30:in `block in execute'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/callbacks.rb:118:in `block in run_callbacks'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/railtie.rb:54:in `block (4 levels) in <class:Railtie>'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/execution_wrapper.rb:92:in `wrap'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/reloader.rb:72:in `block in wrap'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/execution_wrapper.rb:92:in `wrap'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/reloader.rb:71:in `wrap'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/railtie.rb:53:in `block (3 levels) in <class:Railtie>'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/callbacks.rb:127:in `instance_exec'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/callbacks.rb:127:in `block in run_callbacks'

/usr/local/bundle/gems/activesupport-7.0.7/lib/active_support/callbacks.rb:138:in `run_callbacks'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/execution.rb:28:in `execute'

/usr/local/bundle/gems/activejob-7.0.7/lib/active_job/queue_adapters/async_adapter.rb:70:in `perform'

Sometimes the mails just send fine, othertimes they don't. I'm using Resend (https://resend.com) as provider.

Might be a problem at their side but I don't have any issues like this with other projects that I'm using them for.

omohokcoj commented 7 months ago

@hknobbe that looks like a network error on their side, we might try to add retires but the error is not related to DocuSeal so closing the issue