mysql2 icon indicating copy to clipboard operation
mysql2 copied to clipboard

Inexplicable Mysql2::Error: Lost connection to MySQL server during query

Open mikehaertl opened this issue 6 years ago • 42 comments

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.* FROM application_settings ORDER BY application_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:in handle_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 TABLE application_settings 2018-01-31T14:36:40.308565Z 345 Query SELECT application_settings.* FROM application_settings ORDER BY application_settin gs.id DESC LIMIT 1 2018-01-31T14:36:40.328810Z 345 Query SELECT application_settings.* FROM application_settings ORDER BY application_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.

mikehaertl avatar Feb 06 '18 08:02 mikehaertl

@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?

mikehaertl avatar Feb 16 '18 07:02 mikehaertl

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?

sodabrew avatar Feb 16 '18 15:02 sodabrew

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.

mikehaertl avatar Feb 16 '18 16:02 mikehaertl

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.

pacoguzman avatar Feb 19 '18 19:02 pacoguzman

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

pacoguzman avatar Feb 20 '18 18:02 pacoguzman

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.

pacoguzman avatar Feb 20 '18 19:02 pacoguzman

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?

mikehaertl avatar Feb 26 '18 07:02 mikehaertl

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 avatar Jun 26 '18 19:06 mikehaertl

@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 avatar Jun 26 '18 19:06 sodabrew

@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.

mikehaertl avatar Jun 26 '18 19:06 mikehaertl

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.

sodabrew avatar Jul 04 '18 14:07 sodabrew

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.

colin-marshall avatar Jul 04 '18 23:07 colin-marshall

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

IevgenRagulin avatar Aug 28 '18 09:08 IevgenRagulin

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!

TheCorp avatar Sep 08 '18 04:09 TheCorp

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.

64kramsystem avatar Oct 01 '18 15:10 64kramsystem

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.

64kramsystem avatar Oct 01 '18 15:10 64kramsystem

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'

mikehaertl avatar Nov 25 '18 15:11 mikehaertl

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)

robcole avatar Dec 30 '18 06:12 robcole

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.

robcole avatar Dec 31 '18 18:12 robcole

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)

ConfusedVorlon avatar Jan 10 '19 14:01 ConfusedVorlon

note: adding strict:false to my database.yml didn't fix the issue

ConfusedVorlon avatar Jan 10 '19 14:01 ConfusedVorlon

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

rilian avatar Jan 10 '19 15:01 rilian

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

SofiaSousa avatar Feb 21 '19 16:02 SofiaSousa

I have the same error but I use second database on rake tasks

ramzieus avatar Mar 13 '19 08:03 ramzieus

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

AmanRelan avatar Apr 03 '19 05:04 AmanRelan

Anyone Fixed it YET? After adding idle_timeout:0 to my database.yml, getting the error (Mysql2::Error: MySQL client is not connected: ROLLBACK):

wft-dev avatar Apr 12 '19 05:04 wft-dev

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]

jdelStrother avatar Sep 05 '19 12:09 jdelStrother

@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.

dira avatar Feb 24 '20 15:02 dira

@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:.

64kramsystem avatar Feb 24 '20 19:02 64kramsystem

@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?

dira avatar Feb 25 '20 09:02 dira

@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

64kramsystem avatar Feb 26 '20 09:02 64kramsystem

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.

dira avatar Feb 27 '20 13:02 dira

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)

dira avatar Apr 16 '20 09:04 dira

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...

futbolpal avatar May 08 '20 20:05 futbolpal

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!

a-maas avatar Sep 14 '20 16:09 a-maas

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.

taylorthurlow avatar Sep 15 '20 17:09 taylorthurlow

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:

  1. with a simple select, I got no result on the first attempt

ActiveRecord::RecordNotFound (Couldn't find <..>)

  1. 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)

  1. 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.

alexmalus avatar Dec 21 '20 14:12 alexmalus

Thanks for this detailed report @alexmalus!

sodabrew avatar Dec 21 '20 15:12 sodabrew

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

jl-gogovapps avatar Jun 28 '21 19:06 jl-gogovapps

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.

jasonbosco avatar Oct 02 '21 00:10 jasonbosco