Comments (21)
adamcooke
commented on May 27, 2024
Have you looked in your MySQL log? You may find that something like your max_allowed_packet_size is too low.
This doesn't seem like a bug with Postal. As I said in the other issue, if you can provide me with some reproduction steps and I could be sure this was a bug in Postal, I might be able to find time to investigate but, right now, there is not enough to go on.
from postal.
RickoT
commented on May 27, 2024
Here is my MySQL Config. I do not have a max_allowed_packet_size in my config so I am assuming it's default. I have had this postal instance running for almost 3 years now so I am not sure what would have made it start failing suddently.
innodb_buffer_pool_size=100M
max_allowed_packet=1024M
net_read_timeout=3600
net_write_timeout=3600
from postal.
RickoT
commented on May 27, 2024
So I updated my cnf file as below
[mariadb]
innodb_buffer_pool_size=100M
max_allowed_packet=1024M
net_read_timeout=3600
net_write_timeout=3600
innodb_flush_method=littlesync
innodb_use_native_aio=OFF
log_bin=ON
It took longer, but still happened, do you have a recommendation for the max_allowed_packet_size parameter? I mean it's a 1GB, that seems pretty high to me?
from postal.
RickoT
commented on May 27, 2024
Hey @adamcooke. This is still an issue, please let me know how I can help provide you with more information.
Basically once the Postal SMTP container starts, it appears to work for a few sends, but then fails again with the error I posted above. I have 13 other sites and services that this MySQL container services with no issues. the Postal SMTP container is the only one that fails. There has to be something I can look into to help resolve this.
Thanks
~Rick
from postal.
adamcooke
commented on May 27, 2024
Anything in your MySQL server log?
from postal.
RickoT
commented on May 27, 2024
I've attached the MariaDB and Postal-SMTP container logs... nothing that stands out to me, but I can increase the verbosity of the logs if you think it would be helpful
MariaDB Logs.txt
Postal-SMTP Logs.txt
from postal.
RickoT
commented on May 27, 2024
Also, here is my cnf file for MariaDB
[mariadb]
innodb_buffer_pool_size=100M
max_allowed_packet=1024M
net_read_timeout=3600
net_write_timeout=3600
innodb_flush_method=littlesync
innodb_use_native_aio=OFF
log_bin=ON
from postal.
RickoT
commented on May 27, 2024
So I went ahead and turned on anything I could see for logs and there is still nothing more verbose than what I've provided for you from the MySQL side, the postal output is the same as above.
There is definitely some kind of timeout occuring somewhere, but in the last instance the MySQL log didn't even show the disconnect statements from above
from postal.
chrisdeeming
commented on May 27, 2024
@adamcooke we seem to be experiencing a similar issue
This is a new issue for us. Wasn't occurring in 2.1.4. Running 2.2.2 currently.
from postal.
adamcooke
commented on May 27, 2024
@adamcooke we seem to be experiencing a similar issue
This is a new issue for us. Wasn't occurring in 2.1.4. Running 2.2.2 currently.
I deleted the screenshot of the generic error page from your reply. Do you have anything useful from your logs?
from postal.
adamcooke
commented on May 27, 2024
I will try and reproduce this but have been unsuccessful so far. Without being able to poke around the database server, I can't do much debugging.
If anyone else sees this, the following would be useful.
- What database (MySQL or mariadb) engine you're using.
- what version you're using.
- Whether it's on the same host as Postal or not
- extracts from both database and postal logs showing the connection errors
- the output from "show full processlist" for your postal database user
- how long after starting postal did the issue happen
- what postal process exhibited error
- does the issue only appear in one process, if so, a the others working and not reporting errors in the logs? If not, log extracts from the other processes too.
- what was happening at the time the error arose
- the maximum number of connections allowed by your mysql server
- the version of postal you are running
- your postal config (with identifiable and secret values changed)
- anything else which might be of use!
from postal.
RickoT
commented on May 27, 2024
- What database (MySQL or mariadb) engine you're using.
- MariaDB
- what version you're using.
- 11.2.2
- Whether it's on the same host as Postal or not
- MariaDB is running in a docker container
- extracts from both database and postal logs showing the connection errors
- Provided above
- the output from "show full processlist" for your postal database user
- Non potal user and databases are obfuscated
+-------+-----------------+------------------+-----------------+---------+------+----------+-----------------------+----------+
| Id | User | Host | db | Command | Time | State | Info | Progress |
+-------+-----------------+------------------+-----------------+---------+------+----------+-----------------------+----------+
| 7 | rdt-postal-user | 10.0.0.176:59580 | rdt-postal | Sleep | 1 | | NULL | 0.000 |
| 8 | rdt-postal-user | 10.0.0.176:50174 | rdt-postal | Sleep | 14 | | NULL | 0.000 |
| 9 | rdt-postal-user | 10.0.0.176:50190 | rdt-postal | Sleep | 48 | | NULL | 0.000 |
| 10 | rdt-postal-user | 10.0.0.176:50196 | rdt-postal | Sleep | 10 | | NULL | 0.000 |
| 11 | rdt-postal-user | 10.0.0.176:50210 | rdt-postal | Sleep | 10 | | NULL | 0.000 |
| 13 | xx-xxx-user | 10.0.0.176:56008 | xx-xxxxxxxxxxxx | Sleep | 2 | | NULL | 0.000 |
| 14 | xx-xxx-user | 10.0.0.176:56010 | xx-xxxxxxxxxxxx | Sleep | 2 | | NULL | 0.000 |
| 21 | rdt-postal-user | 10.0.0.176:53340 | rdt-postal | Sleep | 70 | | NULL | 0.000 |
| 47951 | rdt-postal-user | 10.0.0.176:51128 | NULL | Sleep | 5223 | | NULL | 0.000 |
| 49482 | rdt-postal-user | 10.0.0.176:51968 | NULL | Sleep | 1623 | | NULL | 0.000 |
| 50278 | rdt-postal-user | 10.0.0.176:49754 | rdt-postal | Sleep | 48 | | NULL | 0.000 |
| 50279 | rdt-postal-user | 10.0.0.176:49756 | NULL | Sleep | 48 | | NULL | 0.000 |
| 50296 | xxxxxx | localhost | NULL | Query | 0 | starting | show full processlist | 0.000 |
+-------+-----------------+------------------+-----------------+---------+------+----------+-----------------------+----------+
- how long after starting postal did the issue happen
- It varies sometimes within 10 minutes, sometimes 30
- what postal process exhibited error
- Only the Postal SMTP process seems to be impacted
- does the issue only appear in one process, if so, a the others working and not reporting errors in the logs? If not, log extracts from the other processes too.
- See below for more logs
- what was happening at the time the error arose]
- Sending a test email
- the maximum number of connections allowed by your mysql server
- 151
- the version of postal you are running
- 2.2.2
- your postal config (with identifiable and secret values changed)
general:
# This can be changed to allow messages to be sent from multiple IP addresses
use_ip_pools: false
web:
# The host that the management interface will be available on
host: mta.xx.xx
# The protocol that requests to the management interface should happen on
protocol: http
web_server:
# Specify configuration for the Postal web server
bind_address: 0.0.0.0
port: 5000
smtp_server:
# Specify configuration to the Postal SMTP server
# port: 25
port: 25
tls_enabled: true
tls_certificate_path: /certs/fullchain.pem
tls_private_key_path: /certs/privkey.pem
tls_ciphers:
ssl_version: TLSv1_2
proxy_protocol: false
log_connect: true
strip_received_headers: false
max_message_size: 14
logging:
# Specify options for the logging
stdout: true
main_db:
# Specify the connection details for your MySQL database
host: mysql
username: xx-xx-xx
password: xx
database: xx-xx
message_db:
# Specify the connection details for your MySQL server that will be house the
# message databases for mail servers.
host: mysql
username: xx-xx-xx
password: xx
prefix: xx-xx
rabbitmq:
# Specify connection details for your RabbitMQ server
host: postal-rabbitmq:5672
username: xx
password: xx
vhost: xx
dns:
mx_records:
- mta.xx.xx
smtp_server_hostname: mta.xx.xx
spf_include: mta.xx.xx
return_path: mta.xx.xx
route_domain: mta.xx.xx
track_domain: track.xx.xx
smtp:
host: 127.0.0.1
port: 2525
username: # Complete when Postal is running and you can
rails:
secret_key: << Removed >>
- anything else which might be of use!
- I noticed that the Postal-Worker and Postal-Requeuer containers hard fail and exit ( I have scaling on so docker spawns a new one automatically)
- I also noticed that sometimes, the postal processes recover and are able to reconnect if given a few seconds after failing
- For example: I noticed the SMTP failed, at the same time the web also failed, but if I let it sit for a minute it all started working again -- Afterwords I noticed that there wer emore NULL db connections from postal processes (see below)
MariaDB [(none)]> show processlist;
+-------+-----------------+------------------+-----------------+---------+------+----------+------------------+----------+
| Id | User | Host | db | Command | Time | State | Info | Progress |
+-------+-----------------+------------------+-----------------+---------+------+----------+------------------+----------+
| 7 | rdt-postal-user | 10.0.0.176:59580 | rdt-postal | Sleep | 1 | | NULL | 0.000 |
| 8 | rdt-postal-user | 10.0.0.176:50174 | rdt-postal | Sleep | 7 | | NULL | 0.000 |
| 9 | rdt-postal-user | 10.0.0.176:50190 | rdt-postal | Sleep | 42 | | NULL | 0.000 |
| 10 | rdt-postal-user | 10.0.0.176:50196 | rdt-postal | Sleep | 102 | | NULL | 0.000 |
| 11 | rdt-postal-user | 10.0.0.176:50210 | rdt-postal | Sleep | 42 | | NULL | 0.000 |
| 13 | xx-xx-xxxxx | 10.0.0.176:56008 | xx-xxxxxxxxxxxx | Sleep | 0 | | NULL | 0.000 |
| 14 | xx-xx-xxxxx | 10.0.0.176:56010 | xx-xxxxxxxxxxxx | Sleep | 0 | | NULL | 0.000 |
| 21 | rdt-postal-user | 10.0.0.176:53340 | rdt-postal | Sleep | 102 | | NULL | 0.000 |
| 47951 | rdt-postal-user | 10.0.0.176:51128 | NULL | Sleep | 6995 | | NULL | 0.000 |
| 49482 | rdt-postal-user | 10.0.0.176:51968 | NULL | Sleep | 3395 | | NULL | 0.000 |
| 50278 | rdt-postal-user | 10.0.0.176:49754 | rdt-postal | Sleep | 1820 | | NULL | 0.000 |
| 50279 | rdt-postal-user | 10.0.0.176:49756 | NULL | Sleep | 1820 | | NULL | 0.000 |
| 50296 | xxxxxxxx | localhost | NULL | Sleep | 1532 | | NULL | 0.000 |
| 50397 | rdt-postal-user | 10.0.0.176:60390 | NULL | Sleep | 1595 | | NULL | 0.000 |
| 50952 | rdt-postal-user | 10.0.0.176:40754 | rdt-postal | Sleep | 288 | | NULL | 0.000 |
| 50971 | rdt-postal-user | 10.0.0.176:55060 | NULL | Sleep | 290 | | NULL | 0.000 |
| 51032 | rdt-postal-user | 10.0.0.176:53904 | rdt-postal | Sleep | 224 | | NULL | 0.000 |
| 51051 | rdt-postal-user | 10.0.0.176:52950 | NULL | Sleep | 224 | | NULL | 0.000 |
| 51082 | rdt-postal-user | 10.0.0.176:41154 | NULL | Sleep | 222 | | NULL | 0.000 |
| 51114 | xxxxxxxx | localhost | NULL | Query | 0 | starting | show processlist | 0.000 |
+-------+-----------------+------------------+-----------------+---------+------+----------+------------------+----------+
20 rows in set (0.000 sec)
Postal Web
[9] [2024-02-10T18:04:33.371] INFO -- : Started GET "/org/xxx" for 10.255.0.2 at 2024-02-10 18:04:33 +0000
[9] [2024-02-10T18:04:33.372] INFO -- : Processing by ServersController#index as HTML
[9] [2024-02-10T18:04:33.372] INFO -- : Parameters: {"org_permalink"=>"xxx"}
[9] [2024-02-10T18:04:33.417] INFO -- : Rendered servers/index.html.haml within layouts/application (Duration: 1.5ms | Allocations: 748)
[9] [2024-02-10T18:04:33.417] INFO -- : Rendered layout layouts/application.html.haml (Duration: 1.7ms | Allocations: 787)
[9] [2024-02-10T18:04:33.418] INFO -- : Completed 500 Internal Server Error in 46ms (ActiveRecord: 36.8ms | Allocations: 2483)
[9] [2024-02-10T18:04:33.420] FATAL -- :
ActionView::Template::Error (MySQL server has gone away):
26: = link_to [organization, server], :class => 'largeList__link' do
27: %span.largeList__rightLabel.label{:class => "label--serverStatus-#{server.status.underscore}"}= t("server_statuses.#{server.status.underscore}")
28: %p= server.name
29: %p.largeList__subText #{number_with_precision server.message_rate, :precision => 2} messages/minute
30: .js-searchable__empty.is-hidden
31: .noData.noData--clean
32: %p.noData__title No servers were found...
lib/postal/message_db/database.rb:327:in `query_on_connection'
lib/postal/message_db/database.rb:319:in `block in query'
lib/postal/message_db/connection_pool.rb:16:in `use'
lib/postal/message_db/database.rb:350:in `with_mysql'
lib/postal/message_db/database.rb:318:in `query'
lib/postal/message_db/live_stats.rb:34:in `total'
app/models/server.rb:133:in `message_rate'
app/views/servers/index.html.haml:29
app/views/servers/index.html.haml:26
app/views/servers/index.html.haml:24:in `each'
app/views/servers/index.html.haml:24
lib/postal/tracking_middleware.rb:12:in `call'
Postal Worker
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] Mysql2::Error::ConnectionError: Lost connection to MySQL server during query
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:151:in `_query'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:151:in `block in query'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:150:in `handle_interrupt'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:150:in `query'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /opt/postal/app/lib/postal/message_db/database.rb:327:in `query_on_connection'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /opt/postal/app/lib/postal/message_db/database.rb:319:in `block in query'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /opt/postal/app/lib/postal/message_db/connection_pool.rb:16:in `use'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /opt/postal/app/lib/postal/message_db/database.rb:350:in `with_mysql'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /opt/postal/app/lib/postal/message_db/database.rb:318:in `query'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /opt/postal/app/lib/postal/message_db/database.rb:174:in `select'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /opt/postal/app/lib/postal/message_db/message.rb:10:in `find_one'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /opt/postal/app/lib/postal/message_db/database.rb:44:in `message'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /opt/postal/app/app/models/concerns/has_message.rb:8:in `message'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /opt/postal/app/app/jobs/unqueue_message_job.rb:10:in `perform'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /opt/postal/app/lib/postal/worker.rb:64:in `receive_job'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /opt/postal/app/lib/postal/worker.rb:96:in `block in join_queue'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /usr/local/bundle/gems/bunny-2.20.3/lib/bunny/consumer.rb:56:in `call'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /usr/local/bundle/gems/bunny-2.20.3/lib/bunny/channel.rb:1842:in `block in handle_frameset'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /usr/local/bundle/gems/bunny-2.20.3/lib/bunny/consumer_work_pool.rb:108:in `block (2 levels) in run_loop'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /usr/local/bundle/gems/bunny-2.20.3/lib/bunny/consumer_work_pool.rb:103:in `loop'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /usr/local/bundle/gems/bunny-2.20.3/lib/bunny/consumer_work_pool.rb:103:in `block in run_loop'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /usr/local/bundle/gems/bunny-2.20.3/lib/bunny/consumer_work_pool.rb:102:in `catch'
[9] [2024-02-10T17:41:14.852] WARN -- : [TIZ3WYBH9G] /usr/local/bundle/gems/bunny-2.20.3/lib/bunny/consumer_work_pool.rb:102:in `run_loop'
Postal Worker when it recreateas a new process
/usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:151:in `_query': Lost connection to MySQL server during query (Mysql2::Error::ConnectionError)
from /usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:151:in `block in query'
from /usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:150:in `handle_interrupt'
from /usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:150:in `query'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:206:in `block (2 levels) in execute'
from /usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/dependencies/interlock.rb:48:in `block in permit_concurrent_loads'
from /usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'
from /usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/dependencies/interlock.rb:47:in `permit_concurrent_loads'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:205:in `block in execute'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_adapter.rb:696:in `block (2 levels) in log'
from /usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
from /usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
from /usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
from /usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
from /usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_adapter.rb:695:in `block in log'
from /usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_adapter.rb:687:in `log'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:204:in `execute'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/mysql/database_statements.rb:52:in `execute'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:215:in `execute_and_free'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/mysql/database_statements.rb:57:in `exec_query'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/database_statements.rb:532:in `select'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/database_statements.rb:69:in `select_all'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/query_cache.rb:103:in `select_all'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/mysql/database_statements.rb:12:in `select_all'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/querying.rb:47:in `find_by_sql'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:843:in `block in exec_queries'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:861:in `skip_query_cache_if_necessary'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:828:in `exec_queries'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:631:in `load'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:249:in `records'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:244:in `to_ary'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation/finder_methods.rb:553:in `find_nth_with_limit'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation/finder_methods.rb:538:in `find_nth'
from /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation/finder_methods.rb:122:in `first'
from /opt/postal/app/lib/postal/worker.rb:140:in `block in manage_ip_queues'
from /opt/postal/app/lib/postal/worker.rb:133:in `each'
from /opt/postal/app/lib/postal/worker.rb:133:in `manage_ip_queues'
from /opt/postal/app/lib/postal/worker.rb:42:in `block in work'
from /opt/postal/app/lib/postal/worker.rb:27:in `loop'
from /opt/postal/app/lib/postal/worker.rb:27:in `work'
from script/worker.rb:3:in `<main>'
Postal Requeuer
8] [2024-02-09T02:56:49.917] INFO -- : Running message requeuer...
rake aborted!
ActiveRecord::StatementInvalid: Mysql2::Error::ConnectionError: Lost connection to MySQL server during query
/usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:151:in `_query'
/usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:151:in `block in query'
/usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:150:in `handle_interrupt'
/usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:150:in `query'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:206:in `block (2 levels) in execute'
/usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/dependencies/interlock.rb:48:in `block in permit_concurrent_loads'
/usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'
/usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/dependencies/interlock.rb:47:in `permit_concurrent_loads'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:205:in `block in execute'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_adapter.rb:696:in `block (2 levels) in log'
/usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
/usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
/usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
/usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
/usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_adapter.rb:695:in `block in log'
/usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_adapter.rb:687:in `log'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:204:in `execute'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/mysql/database_statements.rb:52:in `execute'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:215:in `execute_and_free'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/mysql/database_statements.rb:57:in `exec_query'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/database_statements.rb:532:in `select'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/database_statements.rb:69:in `select_all'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/query_cache.rb:103:in `select_all'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/mysql/database_statements.rb:12:in `select_all'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/querying.rb:47:in `find_by_sql'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:843:in `block in exec_queries'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:861:in `skip_query_cache_if_necessary'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:828:in `exec_queries'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:631:in `load'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:249:in `records'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation/delegation.rb:88:in `each'
/opt/postal/app/app/models/queued_message.rb:121:in `requeue_all'
/opt/postal/app/lib/postal/message_requeuer.rb:11:in `block in run'
/opt/postal/app/lib/postal/message_requeuer.rb:9:in `loop'
/opt/postal/app/lib/postal/message_requeuer.rb:9:in `run'
/opt/postal/app/lib/tasks/postal.rake:20:in `block (2 levels) in <top (required)>'
/usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/rake.rb:24:in `execute'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/cli/exec.rb:58:in `load'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/cli/exec.rb:58:in `kernel_load'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/cli/exec.rb:23:in `run'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/cli.rb:492:in `exec'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/vendor/thor/lib/thor.rb:392:in `dispatch'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/cli.rb:34:in `dispatch'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/vendor/thor/lib/thor/base.rb:485:in `start'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/cli.rb:28:in `start'
/usr/local/bundle/gems/bundler-2.4.9/exe/bundle:45:in `block in <top (required)>'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/friendly_errors.rb:117:in `with_friendly_errors'
/usr/local/bundle/gems/bundler-2.4.9/exe/bundle:33:in `<top (required)>'
/opt/postal/app/bin/bundle:108:in `load'
/opt/postal/app/bin/bundle:108:in `<main>'
Caused by:
Mysql2::Error::ConnectionError: Lost connection to MySQL server during query
/usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:151:in `_query'
/usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:151:in `block in query'
/usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:150:in `handle_interrupt'
/usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:150:in `query'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:206:in `block (2 levels) in execute'
/usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/dependencies/interlock.rb:48:in `block in permit_concurrent_loads'
/usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'
/usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/dependencies/interlock.rb:47:in `permit_concurrent_loads'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:205:in `block in execute'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_adapter.rb:696:in `block (2 levels) in log'
/usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
/usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
/usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
/usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
/usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_adapter.rb:695:in `block in log'
/usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_adapter.rb:687:in `log'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:204:in `execute'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/mysql/database_statements.rb:52:in `execute'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:215:in `execute_and_free'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/mysql/database_statements.rb:57:in `exec_query'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/database_statements.rb:532:in `select'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/database_statements.rb:69:in `select_all'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/query_cache.rb:103:in `select_all'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/mysql/database_statements.rb:12:in `select_all'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/querying.rb:47:in `find_by_sql'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:843:in `block in exec_queries'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:861:in `skip_query_cache_if_necessary'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:828:in `exec_queries'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:631:in `load'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:249:in `records'
/usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation/delegation.rb:88:in `each'
/opt/postal/app/app/models/queued_message.rb:121:in `requeue_all'
/opt/postal/app/lib/postal/message_requeuer.rb:11:in `block in run'
/opt/postal/app/lib/postal/message_requeuer.rb:9:in `loop'
/opt/postal/app/lib/postal/message_requeuer.rb:9:in `run'
/opt/postal/app/lib/tasks/postal.rake:20:in `block (2 levels) in <top (required)>'
/usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/rake.rb:24:in `execute'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/cli/exec.rb:58:in `load'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/cli/exec.rb:58:in `kernel_load'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/cli/exec.rb:23:in `run'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/cli.rb:492:in `exec'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/vendor/thor/lib/thor.rb:392:in `dispatch'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/cli.rb:34:in `dispatch'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/vendor/thor/lib/thor/base.rb:485:in `start'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/cli.rb:28:in `start'
/usr/local/bundle/gems/bundler-2.4.9/exe/bundle:45:in `block in <top (required)>'
/usr/local/bundle/gems/bundler-2.4.9/lib/bundler/friendly_errors.rb:117:in `with_friendly_errors'
/usr/local/bundle/gems/bundler-2.4.9/exe/bundle:33:in `<top (required)>'
/opt/postal/app/bin/bundle:108:in `load'
/opt/postal/app/bin/bundle:108:in `<main>'
Tasks: TOP => postal:requeuer
(See full trace by running task with --trace)
Rabbit MQ -- Log is full of this
024-02-09 03:44:11.059312+00:00 [info] <0.1639.0> accepting AMQP connection <0.1639.0> (10.0.0.176:34994 -> 10.0.0.142:5672)
2024-02-09 03:44:11.061607+00:00 [info] <0.1639.0> connection <0.1639.0> (10.0.0.176:34994 -> 10.0.0.142:5672): user 'postal' authenticated and granted access to vhost 'postal'
2024-02-09 05:08:11.412867+00:00 [warning] <0.1639.0> closing AMQP connection <0.1639.0> (10.0.0.176:34994 -> 10.0.0.142:5672, vhost: 'postal', user: 'postal'):
2024-02-09 05:08:11.412867+00:00 [warning] <0.1639.0> client unexpectedly closed TCP connection
Postal-Cron -- Log is full of this
[9] [2024-02-10T18:00:53.001] INFO -- : Triggering 'every-1-minutes'
[9] [2024-02-10T18:00:53.002] INFO -- : Finished 'every-1-minutes' duration_ms=1 error=nil
from postal.
catphish
commented on May 27, 2024
@RickoT Thank you for the detailed logs. The two usual causes for mysql/mariadb connections being randomly terminates are:
max_allowed_packetbeing too small. This causes mysql to kill a connection when a large query is sent (ie a large email is delivered).wait_timeoutis too low. This causes mysql to kill a connection if it is idle for too long.
I see in your configuration, max_allowed_packet is set to 1GB so this is likely not the issue.
I do not see a value for wait_timeout so this would be the next thing to check. Please could you try setting this to a dramatically larger value? The default is 28800 (8 hours) but I usually set this to its maximum value of 31536000 (1 year).
Postal will only use as many connections as are needed but will leave unused connections idle in between, so this value may be an issue.
The Ruby mysql client library remove the ability to automatically reconnect when these disconnections occur, so these errors will be more noticeable in recent versions. I hope in some cases we can re-implement automatic conneciton retry, but changing the limits in mariadb should help a lot.
from postal.
RickoT
commented on May 27, 2024
@catphish absolutely, happy to help... here are my timeout variables. Which ones would you like me to set?
MariaDB [(none)]> show variables like "%timeout%";
+---------------------------------------+----------+
| Variable_name | Value |
+---------------------------------------+----------+
| connect_timeout | 10 |
| deadlock_timeout_long | 50000000 |
| deadlock_timeout_short | 10000 |
| delayed_insert_timeout | 300 |
| idle_readonly_transaction_timeout | 0 |
| idle_transaction_timeout | 0 |
| idle_write_transaction_timeout | 0 |
| innodb_flush_log_at_timeout | 1 |
| innodb_lock_wait_timeout | 50 |
| innodb_rollback_on_timeout | OFF |
| interactive_timeout | 28800 |
| lock_wait_timeout | 86400 |
| net_read_timeout | 3600 |
| net_write_timeout | 3600 |
| rpl_semi_sync_master_timeout | 10000 |
| rpl_semi_sync_slave_kill_conn_timeout | 5 |
| slave_net_timeout | 60 |
| thread_pool_idle_timeout | 60 |
| wait_timeout | 28800 |
+---------------------------------------+----------+
19 rows in set (0.002 sec)
from postal.
nikhileshjain
commented on May 27, 2024
I do not see a value for wait_timeout so this would be the next thing to check. Please could you try setting this to a dramatically larger value? The default is
28800(8 hours) but I usually set this to its maximum value of31536000(1 year).
Hi @RickoT, was the issue resolved after changing the wait_timeout variable from 28800 (8 hours) to its maximum value of 31536000 (1 year), as suggested by the previous reply?
from postal.
catphish
commented on May 27, 2024
Which ones would you like me to set?
Please set wait_timeout = 31536000
from postal.
RickoT
commented on May 27, 2024
Ok, I've made the change.... took me a bit to realize when I check that interactively that the variable is coming from interactive_wait_timeout instead of wait_timeout, but my global is now what you've asked and I will monitor
from postal.
RickoT
commented on May 27, 2024
MariaDB output
2024-02-11 20:45:04 161 [Warning] Aborted connection 161 to db: 'unconnected' user: 'rdt-postal-user' host: '10.0.0.138' (Got an error reading communication packets)
2024-02-11 21:46:14 1505 [Warning] Aborted connection 1505 to db: 'unconnected' user: 'rdt-postal-user' host: '10.0.0.138' (Got an error reading communication packets)
2024-02-11 22:45:13 2929 [Warning] Aborted connection 2929 to db: 'unconnected' user: 'rdt-postal-user' host: '10.0.0.138' (Got an error reading communication packets)
2024-02-11 23:46:23 3660 [Warning] Aborted connection 3660 to db: 'unconnected' user: 'rdt-postal-user' host: '10.0.0.138' (Got an error reading communication packets)
Postal-Worker Output
9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] Mysql2::Error::ConnectionError: Lost connection to MySQL server during query
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:151:in `_query'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:151:in `block in query'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:150:in `handle_interrupt'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:150:in `query'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /opt/postal/app/lib/postal/message_db/database.rb:327:in `query_on_connection'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /opt/postal/app/lib/postal/message_db/database.rb:319:in `block in query'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /opt/postal/app/lib/postal/message_db/connection_pool.rb:16:in `use'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /opt/postal/app/lib/postal/message_db/database.rb:350:in `with_mysql'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /opt/postal/app/lib/postal/message_db/database.rb:318:in `query'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /opt/postal/app/lib/postal/message_db/database.rb:174:in `select'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /opt/postal/app/lib/postal/message_db/message.rb:16:in `find'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /opt/postal/app/lib/postal/message_db/database.rb:51:in `messages'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /opt/postal/app/app/jobs/expire_held_messages_job.rb:5:in `block in perform'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation/delegation.rb:88:in `each'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation/delegation.rb:88:in `each'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /opt/postal/app/app/jobs/expire_held_messages_job.rb:4:in `perform'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /opt/postal/app/lib/postal/worker.rb:64:in `receive_job'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /opt/postal/app/lib/postal/worker.rb:96:in `block in join_queue'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /usr/local/bundle/gems/bunny-2.20.3/lib/bunny/consumer.rb:56:in `call'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /usr/local/bundle/gems/bunny-2.20.3/lib/bunny/channel.rb:1842:in `block in handle_frameset'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /usr/local/bundle/gems/bunny-2.20.3/lib/bunny/consumer_work_pool.rb:108:in `block (2 levels) in run_loop'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /usr/local/bundle/gems/bunny-2.20.3/lib/bunny/consumer_work_pool.rb:103:in `loop'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /usr/local/bundle/gems/bunny-2.20.3/lib/bunny/consumer_work_pool.rb:103:in `block in run_loop'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /usr/local/bundle/gems/bunny-2.20.3/lib/bunny/consumer_work_pool.rb:102:in `catch'
[9] [2024-02-12T00:15:00.078] WARN -- : [IBWA7XWYMV] /usr/local/bundle/gems/bunny-2.20.3/lib/bunny/consumer_work_pool.rb:102:in `run_loop'
Postal SMTP
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] An error occurred while processing data from a client.
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] ActiveRecord::StatementInvalid: Mysql2::Error::ConnectionError: Lost connection to MySQL server during query
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:151:in `_query'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:151:in `block in query'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:150:in `handle_interrupt'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/mysql2-0.5.5/lib/mysql2/client.rb:150:in `query'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:206:in `block (2 levels) in execute'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/dependencies/interlock.rb:48:in `block in permit_concurrent_loads'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/dependencies/interlock.rb:47:in `permit_concurrent_loads'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:205:in `block in execute'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_adapter.rb:696:in `block (2 levels) in log'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_adapter.rb:695:in `block in log'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activesupport-6.1.7.6/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_adapter.rb:687:in `log'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:204:in `execute'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/mysql/database_statements.rb:52:in `execute'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:215:in `execute_and_free'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/mysql/database_statements.rb:57:in `exec_query'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/database_statements.rb:532:in `select'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/database_statements.rb:69:in `select_all'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/query_cache.rb:103:in `select_all'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/mysql/database_statements.rb:12:in `select_all'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/querying.rb:47:in `find_by_sql'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:843:in `block in exec_queries'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:861:in `skip_query_cache_if_necessary'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:828:in `exec_queries'
[9] [2024-02-12T00:22:50.906] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:631:in `load'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:249:in `records'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:244:in `to_ary'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation/finder_methods.rb:553:in `find_nth_with_limit'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation/finder_methods.rb:538:in `find_nth'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/bundle/gems/activerecord-6.1.7.6/lib/active_record/relation/finder_methods.rb:122:in `first'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /opt/postal/app/lib/postal/smtp_server/client.rb:218:in `authenticate'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /opt/postal/app/lib/postal/smtp_server/client.rb:199:in `block in auth_login'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /opt/postal/app/lib/postal/smtp_server/client.rb:49:in `handle'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /opt/postal/app/lib/postal/smtp_server/server.rb:184:in `block (2 levels) in run_event_loop'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /opt/postal/app/lib/postal/smtp_server/server.rb:86:in `select'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /opt/postal/app/lib/postal/smtp_server/server.rb:86:in `block in run_event_loop'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /opt/postal/app/lib/postal/smtp_server/server.rb:84:in `loop'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /opt/postal/app/lib/postal/smtp_server/server.rb:84:in `run_event_loop'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /opt/postal/app/lib/postal/smtp_server/server.rb:287:in `run'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /opt/postal/app/lib/tasks/postal.rake:15:in `block (2 levels) in <top (required)>'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/lib/ruby/gems/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `block in execute'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/lib/ruby/gems/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `each'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/lib/ruby/gems/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `execute'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/rake.rb:24:in `execute'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/lib/ruby/gems/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:219:in `block in invoke_with_call_chain'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/lib/ruby/gems/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:199:in `synchronize'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/lib/ruby/gems/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:199:in `invoke_with_call_chain'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/lib/ruby/gems/3.2.0/gems/rake-13.0.6/lib/rake/task.rb:188:in `invoke'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/lib/ruby/gems/3.2.0/gems/rake-13.0.6/lib/rake/application.rb:160:in `invoke_task'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/lib/ruby/gems/3.2.0/gems/rake-13.0.6/lib/rake/application.rb:116:in `block (2 levels) in top_level'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/lib/ruby/gems/3.2.0/gems/rake-13.0.6/lib/rake/application.rb:116:in `each'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/lib/ruby/gems/3.2.0/gems/rake-13.0.6/lib/rake/application.rb:116:in `block in top_level'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/lib/ruby/gems/3.2.0/gems/rake-13.0.6/lib/rake/application.rb:125:in `run_with_threads'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/lib/ruby/gems/3.2.0/gems/rake-13.0.6/lib/rake/application.rb:110:in `top_level'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/lib/ruby/gems/3.2.0/gems/rake-13.0.6/lib/rake/application.rb:83:in `block in run'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/lib/ruby/gems/3.2.0/gems/rake-13.0.6/lib/rake/application.rb:186:in `standard_exception_handling'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/lib/ruby/gems/3.2.0/gems/rake-13.0.6/lib/rake/application.rb:80:in `run'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /opt/postal/app/bin/rake:4:in `<top (required)>'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/bundle/gems/bundler-2.4.9/lib/bundler/cli/exec.rb:58:in `load'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/bundle/gems/bundler-2.4.9/lib/bundler/cli/exec.rb:58:in `kernel_load'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/bundle/gems/bundler-2.4.9/lib/bundler/cli/exec.rb:23:in `run'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/bundle/gems/bundler-2.4.9/lib/bundler/cli.rb:492:in `exec'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/bundle/gems/bundler-2.4.9/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/bundle/gems/bundler-2.4.9/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/bundle/gems/bundler-2.4.9/lib/bundler/vendor/thor/lib/thor.rb:392:in `dispatch'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/bundle/gems/bundler-2.4.9/lib/bundler/cli.rb:34:in `dispatch'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/bundle/gems/bundler-2.4.9/lib/bundler/vendor/thor/lib/thor/base.rb:485:in `start'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/bundle/gems/bundler-2.4.9/lib/bundler/cli.rb:28:in `start'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/bundle/gems/bundler-2.4.9/exe/bundle:45:in `block in <top (required)>'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/bundle/gems/bundler-2.4.9/lib/bundler/friendly_errors.rb:117:in `with_friendly_errors'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /usr/local/bundle/gems/bundler-2.4.9/exe/bundle:33:in `<top (required)>'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /opt/postal/app/bin/bundle:108:in `load'
[9] [2024-02-12T00:22:50.907] ERROR -- : [DYEK9E] /opt/postal/app/bin/bundle:108:in `<main>'
Rabbit MQ
2024-02-11 17:56:16.807478+00:00 [info] <0.667.0> accepting AMQP connection <0.667.0> (10.0.0.138:44010 -> 10.0.0.157:5672)
2024-02-11 17:56:16.810619+00:00 [info] <0.667.0> connection <0.667.0> (10.0.0.138:44010 -> 10.0.0.157:5672): user 'postal' authenticated and granted access to vhost 'postal'
2024-02-11 17:57:05.003936+00:00 [info] <0.686.0> accepting AMQP connection <0.686.0> (10.0.0.138:34172 -> 10.0.0.157:5672)
2024-02-11 17:57:05.007537+00:00 [info] <0.686.0> connection <0.686.0> (10.0.0.138:34172 -> 10.0.0.157:5672): user 'postal' authenticated and granted access to vhost 'postal'
2024-02-11 18:11:13.318765+00:00 [warning] <0.667.0> closing AMQP connection <0.667.0> (10.0.0.138:44010 -> 10.0.0.157:5672, vhost: 'postal', user: 'postal'):
2024-02-11 18:11:13.318765+00:00 [warning] <0.667.0> client unexpectedly closed TCP connection
2024-02-11 18:11:23.896005+00:00 [info] <0.760.0> accepting AMQP connection <0.760.0> (10.0.0.138:56972 -> 10.0.0.157:5672)
2024-02-11 18:11:23.898514+00:00 [info] <0.760.0> connection <0.760.0> (10.0.0.138:56972 -> 10.0.0.157:5672): user 'postal' authenticated and granted access to vhost 'postal'
2024-02-11 18:20:11.690429+00:00 [warning] <0.760.0> closing AMQP connection <0.760.0> (10.0.0.138:56972 -> 10.0.0.157:5672, vhost: 'postal', user: 'postal'):
2024-02-11 18:20:11.690429+00:00 [warning] <0.760.0> client unexpectedly closed TCP connection
2024-02-11 18:20:22.279487+00:00 [info] <0.803.0> accepting AMQP connection <0.803.0> (10.0.0.138:36198 -> 10.0.0.157:5672)
2024-02-11 18:20:22.281829+00:00 [info] <0.803.0> connection <0.803.0> (10.0.0.138:36198 -> 10.0.0.157:5672): user 'postal' authenticated and granted access to vhost 'postal'
2024-02-11 23:47:25.942193+00:00 [info] <0.1686.0> accepting AMQP connection <0.1686.0> (10.0.0.138:51142 -> 10.0.0.157:5672)
2024-02-11 23:47:25.944604+00:00 [info] <0.1686.0> connection <0.1686.0> (10.0.0.138:51142 -> 10.0.0.157:5672): user 'postal' authenticated and granted access to vhost 'postal'
from postal.
Related Issues (20)
- messages stuck in queue HOT 12
- Cannot send incoming emails to HTTP Endpoint HOT 6
- Missing attachment when email is not multipart and only contains an attachment HOT 7
- Emails not sent from Toshiba and Kyocera printers.
- Can't use multiple simultaneous SMTP connections. HOT 1
- Postal doesn't automatically restart when host reboots (Docker installation) HOT 1
- Update quickstart script to use docker compose v2 HOT 1
- API call from internal network doesn't work HOT 1
- Issue for non-admin users to change their email address HOT 1
- Can't access Credentials-Webinterface after upgrade HOT 5
- After upgrade to 2.2.0 versione webui don't work HOT 17
- cURL Timeouts to postal via API HOT 1
- 'MySQL client is not connected' error HOT 20
- strip_received_headers may be problematic HOT 4
- strip_received_headers sends headers when using API HOT 3
- list-unsubscribe-post header missing from DKIM signature for one-click email unsubscribe
- Support ARM64 based CPU HOT 4
- Update Source Sans font to support more locales
- Postal gives a random 403 after many UI requests HOT 2
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from postal.