mysql2
mysql2 copied to clipboard
Inexplicable Mysql2::Error: Lost connection to MySQL server during query
It seems that after upgrading to 0.4.10 the library throws the above error even for simplest queries for me. I'm using it with MySQL 5.7.11.
The issue appears when I try to upgrade to the latest version of GitLab (10.4.x). The docker image I use has upgraded the mysql2 library from 0.4.5 to 0.4.10. I never had any issues with 0.4.5 and I was using it for quite some time now with the same MySQL version. The error is thrown when I try to migrate the database to the latest version.
There's a full stack trace over here: https://github.com/sameersbn/docker-gitlab/issues/1492
The head of the stack trace looks like this:
Jan 29 17:37:40 noc docker/gitlab[853]: Migrating database... Jan 29 17:38:17 noc docker/gitlab[853]: rake aborted! Jan 29 17:38:17 noc docker/gitlab[853]: ActiveRecord::StatementInvalid: Mysql2::Error: Lost connection to MySQL server during query: SELECT
application_settings
.* FROMapplication_settings
ORDER BYapplication_settings
.id
DESC LIMIT 1 Jan 29 17:38:17 noc docker/gitlab[853]: /home/git/gitlab/vendor/bundle/ruby/2.3.0/gems/mysql2-0.4.10/lib/mysql2/client.rb:120:in_query' Jan 29 17:38:17 noc docker/gitlab[853]: /home/git/gitlab/vendor/bundle/ruby/2.3.0/gems/mysql2-0.4.10/lib/mysql2/client.rb:120:in
block in query' Jan 29 17:38:17 noc docker/gitlab[853]: /home/git/gitlab/vendor/bundle/ruby/2.3.0/gems/mysql2-0.4.10/lib/mysql2/client.rb:119:inhandle_interrupt' Jan 29 17:38:17 noc docker/gitlab[853]: /home/git/gitlab/vendor/bundle/ruby/2.3.0/gems/mysql2-0.4.10/lib/mysql2/client.rb:119:in
query'
The relevant model that initiated the query can be found here: https://gitlab.com/gitlab-org/gitlab-ce/blob/b1c501c916825626685826f9ef88efb9a9d02a3d/app/models/application_setting.rb#L227
I've enabled query logging on the MySQL server. It's quite obvious that there's no timeout issue here, as the error is thrown almost immediately after the connection is opened:
2018-01-31T14:36:40.130682Z 345 Connect [email protected] on gitlab using TCP/IP 2018-01-31T14:36:40.142067Z 345 Query SET NAMES utf8 COLLATE utf8_general_ci, @@SESSION.sql_auto_is_null = 0, @@SESSION.wait_ti meout = 2147483, @@SESSION.sql_mode = 'STRICT_ALL_TABLES' 2018-01-31T14:36:40.145440Z 345 Query SHOW TABLES LIKE 'application_settings' 2018-01-31T14:36:40.149082Z 345 Query SHOW FULL FIELDS FROM
application_settings
2018-01-31T14:36:40.172786Z 345 Query SHOW TABLES 2018-01-31T14:36:40.174938Z 345 Query SHOW CREATE TABLEapplication_settings
2018-01-31T14:36:40.308565Z 345 Query SELECTapplication_settings
.* FROMapplication_settings
ORDER BYapplication_settin gs
.id
DESC LIMIT 1 2018-01-31T14:36:40.328810Z 345 Query SELECTapplication_settings
.* FROMapplication_settings
ORDER BYapplication_settin gs
.id
DESC LIMIT 1
I found that similar errors where caused by reaper_frequency
. But AFAIK this has been disabled now for a long time. I also couldn't find this setting anywhere in the app directory and the default is off.
So I'm stuck now. Any help or hint how to tackle the issue would be highly welcome. I can also try more debugging, if it helps. But please note, that I'm not a ruby developer, so I might need some pointers on how to do that.
If I'm wrong about my assumption that it's a problem with mysql2 I'd appreciate some pointers on where to look instead.
@sodabrew Sorry, but as you're very active here: Do you maybe have any idea or any hint for me where I could start looking to investigate the issue?
Off the top of my head I cannot think of what changed between 0.4.5 and 0.4.10 that would be implicated here. Have you also changed versions of client libraries or the server version?
MySQL version is exactly the same.
I came across the issue as user of a GitLab docker image. They've upgraded the base image from Ubuntu 14.04 to 16.04. They seem to have upgraded from libmysqlclient18 to libmysqlclient20: https://github.com/sameersbn/docker-gitlab/commit/d6f8e711757bc24f6cb1e81632b16a8a7143351e#diff-3254677a7917c6c01f55212f86c57fbf
As it seems, the issue doesn't affect all the users of that image but only a few (including poor me). Also as said before I'm not a ruby developer so any hint on how to further boil down the issue would be much appreciated.
In our app we're seeing this error lately too, still trying to figure it out where it comes from. We're using stream: true
to iterate very big result sets.
One thing to notice in our side, is that in the error trace, that we track using Rollbar, we see the three following backtrace (excluding our app back trace)
Mysql2::Error: Lost connection to MySQL server during query
- 13 non-project frames
1
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/mysql2.rb" line 238 in each
2
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/mysql2.rb" line 238 in block in fetch_rows
3
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/mysql2.rb" line 144 in _execute
4
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/utils/mysql_mysql2.rb" line 38 in block in execute
5
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/database/connecting.rb" line 264 in block in synchronize
6
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/connection_pool/threaded.rb" line 91 in hold
7
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/database/connecting.rb" line 264 in synchronize
8
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/utils/mysql_mysql2.rb" line 38 in execute
9
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/dataset/actions.rb" line 1085 in execute
10
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/mysql2.rb" line 273 in execute
11
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/mysql2.rb" line 236 in fetch_rows
12
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/dataset/actions.rb" line 151 in each
13
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/mysql2.rb" line 247 in paged_each
Mysql2::Error: Result set has already been freed
- 13 non-project frames
1
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/mysql2.rb" line 149 in each
2
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/mysql2.rb" line 149 in ensure in _execute
3
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/mysql2.rb" line 149 in _execute
4
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/utils/mysql_mysql2.rb" line 38 in block in execute
5
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/database/connecting.rb" line 264 in block in synchronize
6
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/connection_pool/threaded.rb" line 91 in hold
7
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/database/connecting.rb" line 264 in synchronize
8
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/utils/mysql_mysql2.rb" line 38 in execute
9
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/dataset/actions.rb" line 1085 in execute
10
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/mysql2.rb" line 273 in execute
11
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/mysql2.rb" line 236 in fetch_rows
12
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/dataset/actions.rb" line 151 in each
13
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/mysql2.rb" line 247 in paged_each
Sequel::DatabaseError: Mysql2::Error: Result set has already been freed
- 13 non-project frames
1
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/mysql2.rb" line 149 in each
2
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/mysql2.rb" line 149 in ensure in _execute
3
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/mysql2.rb" line 149 in _execute
4
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/utils/mysql_mysql2.rb" line 38 in block in execute
5
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/database/connecting.rb" line 264 in block in synchronize
6
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/connection_pool/threaded.rb" line 91 in hold
7
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/database/connecting.rb" line 264 in synchronize
8
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/utils/mysql_mysql2.rb" line 38 in execute
9
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/dataset/actions.rb" line 1085 in execute
10
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/mysql2.rb" line 273 in execute
11
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/mysql2.rb" line 236 in fetch_rows
12
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/dataset/actions.rb" line 151 in each
13
File "/app/shared/bundle/ruby/2.3.0/gems/sequel-5.5.0/lib/sequel/adapters/mysql2.rb" line 247 in paged_each
The code is executed from a Sidekiq worker, we limited the concurrency to just one thread to discard multi-thread problems.
With the following script is able to reproduce the failure, but it seems is not happening always at the same time or point, so we think does not depend on client/server configuration.
class Yielder
def call(row, index)
sleep(0.005)
puts "id: #{row[:id]} | #{Time.now} | #{index}"
end
end
class FetcherMysql2
def initialize(client, yielder)
@client = client
@yielder = yielder
end
def call
fetch = @client.query("SELECT * FROM my_table ORDER BY id DESC", stream: true, cache_rows: false, symbolize_keys: true)
index = 0
fetch.each do |row|
index += 1
@yielder.call(row, index)
end
end
end
# It seems is not 100% related with the GC collector execution, running disable still raise error
GC.disable
config = {database: "foo", username: "baz", password: "bar", host: "a_host", port: 3306, encoding: "utf-8}
client = Mysql2::Client.new(config.merge(reconnect: true))
thread = Thread.new do
yielder = Yielder.new
FetcherMysql2.new(client, yielder).call
end.tap { |t| t.abort_on_exception = true }
thread.join
# This code instead is raising -> 'Lost connection to MySQL server during query'
These are the variables related with timeouts:
Variable_name | Value |
---|---|
connect_timeout | 10 |
delayed_insert_timeout | 300 |
have_statement_timeout | YES |
innodb_flush_log_at_timeout | 1 |
innodb_lock_wait_timeout | 50 |
innodb_rollback_on_timeout | OFF |
interactive_timeout | 28800 |
lock_wait_timeout | 31536000 |
net_read_timeout | 300 |
net_write_timeout | 60 |
rpl_stop_slave_timeout | 31536000 |
slave_net_timeout | 60 |
wait_timeout | 2147483 |
This could be similar to https://github.com/brianmario/mysql2/issues/369 but if you take a look the net_write_timeout
is higher, we do not insert anything in the loop just puts some information, in our real use case we write to a file for later processing the operation should be quick by the way.
I found something weird: As per suggestion to my initial problem I've increased the max_connections
setting on my machine from 100 to 500 and the problem seems to be gone (see https://github.com/sameersbn/docker-gitlab/issues/1492#issuecomment-368369049).
The thing is that the actual number of connections is < 10 for me! I've checked the number before and after the change with show status like '%onn%';
and the Max_used_connections
is between 4 and 6. So how could this change have possibly fixed be the problem? Am I missing something?
Now situation gets worse for us: With the latest GitLab release 11.0.1 we always receive errors similar to the above (before it happend only when creating a backup). See https://github.com/sameersbn/docker-gitlab/issues/1652.
The weird part is, that after the error, there's a message about "Unkown MySQL server host 'mysql' (0)". If I configure the IP address of my mysql container the message changes to "Can't connect to MySQL server on '192.168.0.6' (111)". But "mysql" is the valid hostname and I can ping it from the container. And there's no connection limit or something.
Here some logs:
ActiveRecord::StatementInvalid (Mysql2::Error: Lost connection to MySQL server during query: SELECT MAX(`project_authorizations`.`
access_level`) AS maximum_access_level, `project_authorizations`.`user_id` AS project_authorizations_user_id FROM `project_authori
zations` WHERE `project_authorizations`.`project_id` = 5 AND `project_authorizations`.`user_id` = 1 GROUP BY `project_authorizatio
ns`.`user_id`):
config/initializers/connection_fix.rb:20:in `execute'
app/models/project_team.rb:163:in `block in max_member_access_for_user_ids'
app/models/concerns/bulk_member_access_load.rb:27:in `max_member_access_for_resource_ids'
app/models/project_team.rb:159:in `max_member_access_for_user_ids'
app/models/project_team.rb:168:in `max_member_access'
app/models/project_team.rb:148:in `member?'
app/models/project_feature.rb:98:in `get_permission'
app/models/project_feature.rb:56:in `feature_available?'
app/models/project.rb:50:in `feature_available?'
app/controllers/projects/application_controller.rb:85:in `check_issues_available!'
lib/gitlab/i18n.rb:50:in `with_locale'
lib/gitlab/i18n.rb:56:in `with_user_locale'
app/controllers/application_controller.rb:362:in `set_locale'
lib/gitlab/middleware/multipart.rb:95:in `call'
lib/gitlab/request_profiler/middleware.rb:14:in `call'
lib/gitlab/middleware/go.rb:17:in `call'
lib/gitlab/etag_caching/middleware.rb:23:in `call'
lib/gitlab/middleware/read_only/controller.rb:28:in `call'
lib/gitlab/middleware/read_only.rb:16:in `call'
lib/gitlab/request_context.rb:18:in `call'
lib/gitlab/metrics/requests_rack_middleware.rb:27:in `call'
lib/gitlab/middleware/release_env.rb:10:in `call'
And below that:
Mysql2::Error (Can't connect to MySQL server on '192.168.0.6' (111)):
lib/gitlab/request_context.rb:18:in `call'
lib/gitlab/metrics/requests_rack_middleware.rb:27:in `call'
lib/gitlab/middleware/release_env.rb:10:in `call'
@mikehaertl I am certain that error you're describing in this last post is not related and is caused by problems in the GitLab docker container's networking configuration.
@sodabrew I definitely double checked and can say for sure that it's not a network issue. I can ping that host, and I can connect to that host from the command line inside the container. I've downgraded to the last version with exactly the same network setup and everything works again. As soon as I upgrade to Gitlab 11.0.1 the above error appears again.
And please note: It does connect to the DB first, as it seems to execute some SQL first. But then the "Lost connection" error comes up followed by this weird "Unknown server" or "Can't connect" errors.
It also seems as these last 2 errors don't happen after each "Lost connection" error.
I know it sounds hard to believe and I can't make sense of it either. I'm happy to try things out - it's just that I'm not a ruby dev so I'd need some guidelines on what to try next.
You'll need to turn up all of the logging options you can to max, on both the app and on the mysql server, to figure out if there's a specific query perhaps that is causing an error.
Not sure if this will help anybody, but we were having this issue with a Discourse importer that uses this gem. We ended up increasing some MySQL server settings:
# GLOBAL:
net_write_timeout=3600;
net_read_timeout=3600;
delayed_insert_timeout=3600;
max_length_for_sort_data=8388608;
max_sort_length=8388608;
net_buffer_length=1048576;
max_connections=10000;
connect_timeout=31536000;
wait_timeout=31536000;
max_allowed_packet=1073741824;
mysqlx_read_timeout=2147483;
mysqlx_idle_worker_thread_timeout=3600;
mysqlx_connect_timeout=1000000000;
# SESSION:
net_write_timeout=3600;
net_read_timeout=3600;
max_length_for_sort_data=8388608;
max_sort_length=8388608;
wait_timeout=31536000;
We're not sure specifically which setting(s) fixed the connection issue, but we no longer got the error after these changes.
Not sure if it will help anybody, but we started facing "Lost connection to MySQL server during query" issue from time to time after upgrading MySQL version via Amazon RDS from 5.7.20 to 5.7.22. Interestingly, we have been using non RDS 5.7.22 version of MySQL for a long time on another environment, and we have never encountered that issue before
In case this helps anyone we were previously in this setup:
Old AWS Aurora (MySQL 5.7.12) Rails 5.1 MySQL2 gem version 0.4.10 Sidekiq 5.1.1 Per rails process connection pool: 50
New Upgraded Rails to 5.2 Mysql2 gem to 0.5.2 Sidekiq to 5.2.1 Per rails process connection pool: 20
From the investigation we've done it seems related to the Sidekiq upgrade as a result of this fix - https://github.com/mperham/sidekiq/issues/3809
Basically every sidekiq job was wrapped in in a cache block:
ActiveRecord::Base.cache(&block)
This forced every job to open a db connection regardless of whether it was doing DB work or not. This, similar to the multi-process related issues above, caused us to run up against our connection limit and start timing out on db calls. The connection pool limit decrease may have also helped but probably not the main culprit.
Hope this helps someone!
For reference, I'm experiencing this problem as well, and it's very obscure, since, also in my case, it's unrelated from typical misconfigurations.
To be specific, on:
- AWS, Ubuntu 14.04, libmysqlclient18, mysql2 0.5.2, MySQL server 5.7.19, Ruby 2.5
I don't experience any problem. When I try the exact same stack with the exception of:
- Ubuntu 18.04, libmysqlclient20
with a simple select, I get a wrong result on the first attempt, and a Lost connection to MySQL server
on the second (I guess something happens during the first query).
Rails itself is unrelated; I can reproduce the issue on an irb session.
For reference (again), the problem is related (at least in my case) to libmysqlclient20
- I don't know if it's a bug in the library itself, or in the mysql2 gem.
When on the problematic stack (the 18.04 one) I install the Ubuntu 14.04 libmysqlclient libraries:
-
libmysqlclient-dev
: 5.5.61-0ubuntu0.14.04.1 -
libmysqlclient18
: 5.5.61-0ubuntu0.14.04.1
there is no issue.
Hopefully this may help somebody. I'm not sure whether this is desirable in a production setup (the libmysqlclient-dev
package will need to be pinned, and manually updated when there are 14.04 updates), however it may be preferrable to a non-working system :smiley: .
Based on the comments above, the same principle should be valid for 16.04, as the libmysqlclient package versions are very close to 18.04.
UPDATE: Please ignore this comment below. It was a problem with MySQL itself. I got the same error when executing the SQL on the CLI client. I've now reimported the data int a fresh DB and the problem disappeared.
Meanwhile I'm on a completely fresh server. Things went well for a while but then I updated to the latest GitLab release and the error is back. As usual it's a random error. Most pages work fine but on some pages throw an immediate error (no timeout or something). It starts to drive me crazy as the server is really powerful, and there's no other traffic on the server. It can't be a limitation of the DB or similar.
@saveriomiroddi I had that suspicion before. Unfortunately I could not verify it because if I install limbysqlclien18 (and remove libmysqlclient20) it doesn't work at all. I found the below error in my unicorn.stderr.log. Do you have any recommendation on how to replace the library?
/home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activesupport-4.2.10/lib/active_support/dependencies.rb:274:in `require': Could not load 'active_record/connection_adapters/mysql2_adapter'. Make sure that the adapter in config/database.yml is valid. If you use an adapter other than 'mysql', 'mysql2', 'postgresql' or 'sqlite3' add the necessary adapter gem to the Gemfile. (LoadError)
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activesupport-4.2.10/lib/active_support/dependencies.rb:274:in `block in require'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activesupport-4.2.10/lib/active_support/dependencies.rb:240:in `load_dependency'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activesupport-4.2.10/lib/active_support/dependencies.rb:274:in `require'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/mysql2-0.4.10/lib/mysql2.rb:31:in `<top (required)>'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activesupport-4.2.10/lib/active_support/dependencies.rb:274:in `require'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activesupport-4.2.10/lib/active_support/dependencies.rb:274:in `block in require'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activesupport-4.2.10/lib/active_support/dependencies.rb:240:in `load_dependency'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activesupport-4.2.10/lib/active_support/dependencies.rb:274:in `require'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/mysql2_adapter.rb:4:in `<top (required)>'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activesupport-4.2.10/lib/active_support/dependencies.rb:274:in `require'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activesupport-4.2.10/lib/active_support/dependencies.rb:274:in `block in require'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activesupport-4.2.10/lib/active_support/dependencies.rb:240:in `load_dependency'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activesupport-4.2.10/lib/active_support/dependencies.rb:274:in `require'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/connection_specification.rb:175:in `spec'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activerecord-4.2.10/lib/active_record/connection_handling.rb:50:in `establish_connection'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activerecord-4.2.10/lib/active_record/railtie.rb:122:in `block (2 levels) in <class:Railtie>'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activesupport-4.2.10/lib/active_support/lazy_load_hooks.rb:38:in `instance_eval'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activesupport-4.2.10/lib/active_support/lazy_load_hooks.rb:38:in `execute_hook'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activesupport-4.2.10/lib/active_support/lazy_load_hooks.rb:28:in `block in on_load'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activesupport-4.2.10/lib/active_support/lazy_load_hooks.rb:27:in `each'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activesupport-4.2.10/lib/active_support/lazy_load_hooks.rb:27:in `on_load'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/activerecord-4.2.10/lib/active_record/railtie.rb:118:in `block in <class:Railtie>'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/railties-4.2.10/lib/rails/initializable.rb:30:in `instance_exec'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/railties-4.2.10/lib/rails/initializable.rb:30:in `run'
from /home/git/gitlab/vendor/bundle/ruby/2.4.0/gems/railties-4.2.10/lib/rails/initializable.rb:55:in `block in run_initializers'
from /usr/lib/ruby/2.4.0/tsort.rb:228:in `block in tsort_each'
This has been happening to us as well, also on RDS + Aurora (5.7.12).
It's sporadic and doesn't happen deterministically, but prevents even loading rails console regularly when the error is occurring.
The errors that show up in our logs look like this:
[Note] Aborted connection 199 to db: '<database>' user: '<username>' host: '<IP>' (Got an error reading communication packets)
Our issues were fixed by explicitly disabling strict mode on the client side via database.yml, by adding strict: false
to our database.yml. It appears to be related to an issue in older versions of libmysql on our end, but we aren't 100% certain about this.
not sure if my issue is related, but I'm following through from the linked minitest issue.
using rspec rails I get intermittent
Mysql2::Error: MySQL client is not connected: BEGIN
I can run the same tests with the same seed. Sometimes they run fine, sometimes they hit this error and tests from that point on all fail.
The point of failure is not consistent even on failing runs.
mysql: Server version: 5.7.10 Homebrew rails (5.2.2) mysql2 (0.5.2) rspec-core (3.8.0)
note: adding strict:false to my database.yml didn't fix the issue
Bitnami MySQL 5.6.34-0 (Azure) mysql2 (0.5.2) rails (5.1.6)
i had similar issue, with simple query that just inserted a value from webhook to text column, and it appeared that text value was too large (~20mb) for default database settings. After this exception database could lose the connection for further requests. Issue was fixed for me and never appeared after i changed architecture of code so that saving this large text became unnecessary
After trying everything you all have suggested here (without any success), let me share what I did to stop my Mysql2::Error: MySQL client is not connected
issues while running massive tests:
Added idle_timeout: 0
to my database.yml
, which actually makes senses since 'Set this to zero to keep connections forever' (accordding to docs)
Source: https://api.rubyonrails.org/v5.2.2/classes/ActiveRecord/ConnectionAdapters/ConnectionPool.html
I have the same error but I use second database on rake tasks
Added idle_timeout:0
to my database.yml
and did rails db:migrate:reset
and I haven't faced the same issue again I think
Anyone Fixed it YET?
After adding idle_timeout:0 to my database.yml, getting the error (Mysql2::Error: MySQL client is not connected: ROLLBACK):
FWIW, I keep randomly seeing this when running parallel tests, but the idle_timeout:0
trick isn't working for me.
rails 5.2.2.1 mysql2 0.5.2 mysql server Ver 14.14 Distrib 5.7.18, for osx10.12 (x86_64) using EditLine wrapper
[UPDATE: ehh, nevermind - in my particular case at least, this isn't a problem in the mysql2 gem. mysql_error.log was showing "Lock wait timeout exceeded", and turns out that my local mysql server has gotten into a bizarro state where it would lock up when inserting a row with a particular indexed value. Restarting mysql fixed it]
@saveriomiroddi Have you got any more insight on this error? I have a similar problem in production, and your report is the only similar situation I have found :/
Hoping you might help, here's the setup: on a shared AWS RDS MySQL database:
Application A: upgraded to Ubuntu18 and libmysqlclient20. After the upgrade, it behaves normally most of the time, but started throwing "ActiveRecord::StatementInvalid (Mysql2::Error: Lost connection to MySQL server during query" when multiple concurrent jobs are executed concurrently in Sidekiq. The error is thrown on a very simple query ("select * from <table> where id=<id>"
)
The even stranger part is that two other Rails applications, B and C, still running Ubuntu14 and libmysqlclient18, connecting to the same database, started throwing the same MySQL2 error, at the same time that Application A is error-ing.
This happens consistently after the upgrade, and has never happened in the previous 2-3 years.
@saveriomiroddi Have you got any more insight on this error? I have a similar problem in production, and your report is the only similar situation I have found :/
Hoping you might help, here's the setup: on a shared AWS RDS MySQL database:
Hello!
Unfortunately, I can't help - we've been having those packages pinned since then, and had no more problems (of course, sticking to this version is undesirable). Before coming to this conclusion, we've spent a significant amount of time trying to understand the problem, but it seemed to be too low level.
Ubuntu 19.10 and the upcoming 20.04 ship the 8.0 version of the libraries, which may be worth trying (assuming they're compatible). Of course, it's not ideal, but better than getting obscure production errors :grimacing:.
@saveriomiroddi Thanks for the answer. As it does not seem to be a generic "ubuntu18 + libmysqlclient20" problem, it might be related to ruby / mysql version / the mysql2 gem, I am trying to narrow it down.
Rails-independent (we use 4.2.11) Might we an AWS RDS problem (our version: MySQL 5.7.22) Might be a Ruby 2.5 problem (your version: 2.5.?, our version: 2.5.3) We are on mysql2 0.4.10, you reported it on 0.5.2
Is this correct?
@saveriomiroddi Thanks for the answer. As it does not seem to be a generic "ubuntu18 + libmysqlclient20" problem, it might be related to ruby / mysql version / the mysql2 gem, I am trying to narrow it down.
Rails-independent (we use 4.2.11) Might we an AWS RDS problem (our version: MySQL 5.7.22) Might be a Ruby 2.5 problem (your version: 2.5.?, our version: 2.5.3) We are on mysql2 0.4.10, you reported it on 0.5.2
Is this correct?
So! By the time we first experienced the issue, the versions were:
Infrastructure (certain):
- mysql: 5.7.19 (RDS)
Rails (likely, but not certain):
- ruby: 2.4.3
- rails: 5.2.1
- mysql2: 0.5.2
Thank you! Looks like the common part (besides Ubuntu and libclientmysql) is "older RDS MysSQL version". We'll try to upgrade the database first, and see if that fixes the issue.
Update: upgrading the AWS RDS DB didn't fix the issue. As it looks like a core bug, we gave up investigating and also resorted to downgrading libmysqlclient. Ubuntu 18 + libmysqlclient18 + AWS RDS MySQL 5.7.26 = <3 (works as expected)
I'm also having this issue.
In my case i'm running FROM ruby:2.5.3-alpine
hitting a 5.6 RDS database. I'm running a sinatra app behind a Puma configuration with a web concurrency of 2 and 5 threads each.
I had a situation today where there was a query that timed out, but there were other queries just seconds before. Our wait_timeout is large, 28800.
Perhaps this was a thread that hadn't been used in a while? Interestingly, we also have PHP legacy components that have this problem, and i thought the ruby reconnect
option would help manage this issue. Still doing some digging...
We were encountering these errors while trying to spin up an existing app, that uses a MySQL 5.7 database, in a new environment with the latest ubuntu/libmysqlclient. While running our old environment and the new environment at the same time, these errors would pop up pretty frequently.
On the Rails side, we got:
Mysql2::Error::ConnectionError: Lost connection to MySQL server during query
In the MySQL log, we got:
2020-09-10T20:39:26.039266Z 1385 [Note] Aborted connection 1385 to db: 'database' user: 'user' host: '172.18.4.222' (Got an error writing communication packets)
What finally fixed the issue was disabling MySQL 5.7's query cache feature, which MySQL ended up deprecating and removing in later versions anyways.
SET GLOBAL query_cache_size = 0;
I hope this helps others encountering this issue!
I'm encountering this issue on a MySQL 5.7 DB, the symptom being errors like:
ActiveRecord::StatementInvalid: Mysql2::Error: MySQL client is not connected: BEGIN
And on the mysqld
error log side:
2020-09-15T17:41:12.281083Z 20 [Note] Aborted connection 20 to db: 'xprint_test' user: 'root' host: 'localhost' (Got an error reading communication packets)
2020-09-15T17:41:12.309544Z 22 [Note] Aborted connection 22 to db: 'xprint_test' user: 'root' host: 'localhost' (Got an error reading communication packets)
2020-09-15T17:46:10.711400Z 29 [Note] Aborted connection 29 to db: 'xprint_test' user: 'root' host: 'localhost' (Got an error writing communication packets)
Notice in the above logs, that there are errors stating error writing
and error reading
.
Unfortunately setting query_cache_size
and query_cache_type
both to 0
doesn't seem to have fixed anything. Some good info here on making sure the cache is truly disabled.
I also tried disabling strict mode, and that didn't solve it either.
EDIT: I've solved my issue. There was some awful code being executed that I wasn't aware of - long the lines of:
Thread.new do
# I forget what this method is actually called or where it's located, but you get the idea
ActiveRecord::Base.with_connection do
# Do some stuff
end
end
This was getting executed and I think exceptions raised within the # Do some stuff
part were causing database connections to be left open. This is mostly just a hypothesis.
Summary
In an Ubuntu 20.04 environment, a combination of using the OS packages libmysqlclient21 and mariadb-client-10.3, as well as disabling the query cache on MySQL server's side - solved the issue for me.
Background story
I was experiencing this issue, as similarly described by @saveriomiroddi here: https://github.com/brianmario/mysql2/issues/938#issuecomment-425953296
MySQL server version: 5.7.29-0ubuntu0.18.04.1 Rails 6.0.3.2 app using Ruby 2.7.1
App's Gemfile had the mysql2 gem, version 0.5.0
App lived inside a Docker container, having as base image: passenger-ruby27:1.0.11
Dockerfile contained as extra library mysql-client-5.6
By using passenger-ruby27:1.0.11, Docker container had:
- as OS: Ubuntu 18.04
- following MySQL OS libraries:
ii libmysqlclient-dev 5.7.30-0ubuntu0.18.04.1 amd64 MySQL database development files
ii libmysqlclient20:amd64 5.7.30-0ubuntu0.18.04.1 amd64 MySQL database client library
ii mysql-client-5.7 5.7.32-0ubuntu0.18.04.1 amd64 MySQL database client binaries
ii mysql-client-core-5.7 5.7.32-0ubuntu0.18.04.1 amd64 MySQL database core client binaries
ii mysql-common 5.8+1.0.4 all MySQL database common files, e.g. /etc/mysql/my.cnf
How I reproduced the issue
In the rails console:
- with a simple select, I got no result on the first attempt
ActiveRecord::RecordNotFound (Couldn't find <..>)
- same find, a Lost connection to MySQL server on the second (I guess something happens during the first query).
ActiveRecord::StatementInvalid (Mysql2::Error::ConnectionError: Lost connection to MySQL server during query)
- same find, result is properly retrieved
How the issue could not be reproduced
Ref: https://stackoverflow.com/questions/3658000/how-to-access-mysqlresult-in-activerecord
In the rails console:
result = ActiveRecord::Base.connection.execute("select * from X where id = Y;")
result.first
# an array containing the fields of the record I was looking for
Debugging the MySQL connections
FYI note: my database.yml has:
reconnect: true
In the MySQL console, I've inspected the MySQL connections using:
select * from information_schema.processlist;
Noticed that for attempt 1, a connection was made; after attempt was made, connection lived. For attempt 2, the initial connection died. For attempt 3, a new connection was made.
Resolving the issue
Note: each following attempt carried over the changes made by its predecessor.
[Unsuccessful] Attempt 1: Use mysql-client-5.7
[Unsuccessful] Attempt 2: Use Rails 6.1.0
[Unsuccessful] Attempt 3: Use mysql2 gem, version 0.5.3
[Unsuccessful] Attempt 4: Using the latest : passenger-ruby27:1.0.12 Docker image
As explained: https://github.com/phusion/passenger-docker/blob/master/CHANGELOG.md#1012-release-date-2020-11-18 - here, it had a number of changes, one of which was changing from Ubuntu 18.04 to Ubuntu 20.04
I had to also use ruby 2.7.2 and, instead of mysql-client-5.7, use mariadb-client-10.3
FYI, inside the container, the packages needed to interact with MySQL are:
ii libdbd-mysql-perl:amd64 4.050-3 amd64 Perl5 database interface to the MariaDB/MySQL database
ii libmysqlclient-dev 8.0.22-0ubuntu0.20.04.2 amd64 MySQL database development files
ii libmysqlclient21:amd64 8.0.22-0ubuntu0.20.04.2 amd64 MySQL database client library
ii mysql-common 5.8+1.0.5ubuntu2 all MySQL database common files, e.g. /etc/mysql/my.cnf
ii mariadb-client-10.3 1:10.3.25-0ubuntu0.20.04.1 amd64 MariaDB database client binaries
ii mariadb-client-core-10.3 1:10.3.25-0ubuntu0.20.04.1 amd64 MariaDB database core client binaries
ii mariadb-common 1:10.3.25-0ubuntu0.20.04.1 all MariaDB common metapackage
Worked fine while interacting with the DB through the Rails console. A fresh db import from production to staging (where the issue occurred and still does) caused the issue to occur again..
What worked in the end
As indicated by: a-maas's comment And explained by: rilian's comment
Potential reason behind what causes the issue to occur: very large records in the database. I also disabled the query cache.
The issue was finally resolved. Any further code deployments or DB imports did not cause the issue to occur again.
Thanks for this detailed report @alexmalus!
I've recently run into this issue again, this time I'm trying to use an RDS Proxy, which has resurfaced this problem (I was previously experiencing it with Istio when using sidecars).
I've tried quite a few configurations with these variables:
24 reconnect: false,
25 reaping_frequency: 120,
26 connect_timeout: 5,
27 read_timeout: 5,
28 idle_timeout: 5
But I haven't had much success. I'm using Puma with 2 workers and 5 threads, with the on_worker_boot and before_fork ActiveRecord manipulations documented by Heroku.
I'm also using Sinatra, not rails, if that is relevant. I'm unable to reliably reproduce locally, but can on occasion. The queries are also quite simple, not lots of data coming through.
Anyone have any further ideas?
Update I've resolved my issues - they were unrelated to mysql2 (unsurprisingly). This article saved me from my many hours of anguish
I saw this error on my local dev environment running macOS 11.5.2 (Big Sur), mysql 5.7, when inserting a large blob of data.
I noticed this in the mysql log file:
2021-10-02T00:38:05.850170Z 0 [Note] /usr/local/opt/[email protected]/bin/mysqld: ready for connections.
Version: '5.7.35' socket: '/tmp/mysql.sock' port: 3306 Homebrew
2021-10-02T00:42:48.410796Z 6 [Note] Aborted connection 6 to db: 'db_name' user: 'root' host: 'localhost' (Got a packet bigger than 'max_allowed_packet' bytes)
So I increased max_allowed_packet
by adding this to my.cnf
:
# /usr/local/etc/my.cnf
max_allowed_packet = 1073741824
and then restarted mysql.
That fixed the issue for me.