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

[David Webster]

 I keep getting this type of error, and have researched this for weeks on the internet. tried every suggestion and it still persists..

An ActiveRecord::StatementInvalid occurred in customer#go_to_consultation:

  Mysql2::Error: Lost connection to MySQL server during query: SELECT  `users`.* FROM `users` WHERE `users`.`id` = xxxxx LIMIT 1
  mysql2 (0.2.18) lib/active_record/connection_adapters/mysql2_adapter.rb:265:in `query'

nginx version: nginx/1.2.4

ruby 1.8.7 (2011-06-30 patchlevel 352) [x86_64-linux]

Phusion Passenger version 3.0.18

rails (3.0.20)

mysql2 (0.2.18)

activerecord (3.0.20)

activerecord-import (0.2.11)

activerecord-mysql2-adapter (0.0.3)

Ubuntu 12.04 (precise)

other info:

  * PASSENGER_APP_SPAWNER_IDLE_TIME           : -1
  * PASSENGER_APP_TYPE                        : rack
  * PASSENGER_CONNECT_PASSWORD                : [FILTERED]
  * PASSENGER_DEBUGGER                        : false
  * PASSENGER_ENVIRONMENT                     : production
  * PASSENGER_FRAMEWORK_SPAWNER_IDLE_TIME     : -1
  * PASSENGER_FRIENDLY_ERROR_PAGES            : true
  * PASSENGER_GROUP                           :
  * PASSENGER_MAX_REQUESTS                    : 0
  * PASSENGER_MIN_INSTANCES                   : 2
  * PASSENGER_SHOW_VERSION_IN_HEADER          : true
  * PASSENGER_SPAWN_METHOD                    : smart-lv2
  * PASSENGER_USER                            :
  * PASSENGER_USE_GLOBAL_QUEUE                : true

  mysql2 (0.2.18) lib/active_record/connection_adapters/mysql2_adapter.rb:265:in `query'
  mysql2 (0.2.18) lib/active_record/connection_adapters/mysql2_adapter.rb:265:in `execute'
  activerecord (3.0.20) lib/active_record/connection_adapters/abstract_adapter.rb:202:in `log_without_newrelic_instrumentation'
  activesupport (3.0.20) lib/active_support/notifications/instrumenter.rb:21:in `instrument'
  activerecord (3.0.20) lib/active_record/connection_adapters/abstract_adapter.rb:200:in `log_without_newrelic_instrumentation'
  newrelic_rpm (3.7.2.192) lib/new_relic/agent/instrumentation/active_record.rb:46:in `log'
  newrelic_rpm (3.7.2.192) lib/new_relic/agent/method_tracer.rb:281:in `trace_execution_scoped'
  newrelic_rpm (3.7.2.192) lib/new_relic/agent/instrumentation/active_record.rb:43:in `log'
  mysql2 (0.2.18) lib/active_record/connection_adapters/mysql2_adapter.rb:265:in `execute'
  mysql2 (0.2.18) lib/active_record/connection_adapters/mysql2_adapter.rb:586:in `select'
  activerecord (3.0.20) lib/active_record/connection_adapters/abstract/database_statements.rb:7:in `select_all'
  activerecord (3.0.20) lib/active_record/connection_adapters/abstract/query_cache.rb:54:in `select_all'
  activerecord (3.0.20) lib/active_record/connection_adapters/abstract/query_cache.rb:68:in `cache_sql'
  activerecord (3.0.20) lib/active_record/connection_adapters/abstract/query_cache.rb:54:in `select_all'
  activerecord (3.0.20) lib/active_record/base.rb:473:in `find_by_sql_without_trace_ActiveRecord_self_name_find_by_sql'
  newrelic_rpm (3.7.2.192) lib/new_relic/agent/method_tracer.rb:549:in `find_by_sql'
  newrelic_rpm (3.7.2.192) lib/new_relic/agent/method_tracer.rb:281:in `trace_execution_scoped'
  newrelic_rpm (3.7.2.192) lib/new_relic/agent/method_tracer.rb:544:in `find_by_sql'
  activerecord (3.0.20) lib/active_record/relation.rb:64:in `to_a'
  activerecord (3.0.20) lib/active_record/relation/finder_methods.rb:343:in `find_first'
  activerecord (3.0.20) lib/active_record/relation/finder_methods.rb:122:in `first'
  activerecord (3.0.20) lib/active_record/relation/finder_methods.rb:244:in `send'
  activerecord (3.0.20) lib/active_record/relation/finder_methods.rb:244:in `find_by_attributes'
  activerecord (3.0.20) lib/active_record/base.rb:997:in `send'
  activerecord (3.0.20) lib/active_record/base.rb:997:in `method_missing'
  lib/authenticated_system.rb:11:in `current_user'
  app/controllers/application_controller.rb:16:in `load_org_hash'
  activesupport (3.0.20) lib/active_support/callbacks.rb:447:in `_run__1783524324__process_action__741958110__callbacks'
  activesupport (3.0.20) lib/active_support/callbacks.rb:410:in `send'
  activesupport (3.0.20) lib/active_support/callbacks.rb:410:in `_run_process_action_callbacks'
  activesupport (3.0.20) lib/active_support/callbacks.rb:94:in `send'
  activesupport (3.0.20) lib/active_support/callbacks.rb:94:in `run_callbacks'
  actionpack (3.0.20) lib/abstract_controller/callbacks.rb:17:in `process_action'
  actionpack (3.0.20) lib/action_controller/metal/rescue.rb:17:in `process_action'
  actionpack (3.0.20) lib/action_controller/metal/instrumentation.rb:30:in `process_action'
  activesupport (3.0.20) lib/active_support/notifications.rb:52:in `instrument'
  activesupport (3.0.20) lib/active_support/notifications/instrumenter.rb:21:in `instrument'
  activesupport (3.0.20) lib/active_support/notifications.rb:52:in `instrument'
  actionpack (3.0.20) lib/action_controller/metal/instrumentation.rb:29:in `process_action'
  newrelic_rpm (3.7.2.192) lib/new_relic/agent/instrumentation/rails3/action_controller.rb:38:in `process_action'
  newrelic_rpm (3.7.2.192) lib/new_relic/agent/instrumentation/controller_instrumentation.rb:339:in `perform_action_with_newrelic_trace'
  newrelic_rpm (3.7.2.192) lib/new_relic/agent/instrumentation/rails3/action_controller.rb:37:in `process_action'
  actionpack (3.0.20) lib/abstract_controller/base.rb:119:in `process'
  actionpack (3.0.20) lib/abstract_controller/rendering.rb:41:in `process'
  actionpack (3.0.20) lib/action_controller/metal.rb:138:in `dispatch'
  actionpack (3.0.20) lib/action_controller/metal/rack_delegation.rb:14:in `dispatch'
  actionpack (3.0.20) lib/action_controller/metal.rb:178:in `action'
  actionpack (3.0.20) lib/action_dispatch/routing/route_set.rb:68:in `call'
  actionpack (3.0.20) lib/action_dispatch/routing/route_set.rb:68:in `dispatch'
  actionpack (3.0.20) lib/action_dispatch/routing/route_set.rb:33:in `call'
  rack-mount (0.6.14) lib/rack/mount/route_set.rb:148:in `call'
  rack-mount (0.6.14) lib/rack/mount/code_generation.rb:93:in `recognize'
  rack-mount (0.6.14) lib/rack/mount/code_generation.rb:117:in `optimized_each'
  rack-mount (0.6.14) lib/rack/mount/code_generation.rb:92:in `recognize'
  rack-mount (0.6.14) lib/rack/mount/route_set.rb:139:in `call'
  actionpack (3.0.20) lib/action_dispatch/routing/route_set.rb:499:in `call'
  omniauth (1.1.4) lib/omniauth/strategy.rb:184:in `call!'
  omniauth (1.1.4) lib/omniauth/strategy.rb:164:in `call'
  omniauth (1.1.4) lib/omniauth/strategy.rb:184:in `call!'
  omniauth (1.1.4) lib/omniauth/strategy.rb:164:in `call'
  omniauth (1.1.4) lib/omniauth/builder.rb:49:in `call'
  newrelic_rpm (3.7.2.192) lib/new_relic/rack/error_collector.rb:55:in `call'
  newrelic_rpm (3.7.2.192) lib/new_relic/rack/agent_hooks.rb:32:in `call'
  newrelic_rpm (3.7.2.192) lib/new_relic/rack/browser_monitoring.rb:27:in `call'
  exception_notification (3.0.0) lib/exception_notifier.rb:40:in `call'
  /home/deployer/apps/mdlive/shared/bundle/ruby/1.8/bundler/gems/simple-captcha-3557b78feb5f/lib/simple_captcha/middleware.rb:20:in `call'
  actionpack (3.0.20) lib/action_dispatch/middleware/best_standards_support.rb:17:in `call'
  actionpack (3.0.20) lib/action_dispatch/middleware/head.rb:14:in `call'
  rack (1.2.8) lib/rack/methodoverride.rb:24:in `call'
  actionpack (3.0.20) lib/action_dispatch/middleware/params_parser.rb:21:in `call'
  actionpack (3.0.20) lib/action_dispatch/middleware/flash.rb:182:in `call'
  actionpack (3.0.20) lib/action_dispatch/middleware/session/abstract_store.rb:149:in `call'
  actionpack (3.0.20) lib/action_dispatch/middleware/cookies.rb:302:in `call'
  rack-ssl (1.3.3) lib/rack/ssl.rb:27:in `call'
  activerecord (3.0.20) lib/active_record/query_cache.rb:32:in `call'
  activerecord (3.0.20) lib/active_record/connection_adapters/abstract/query_cache.rb:28:in `cache'
  activerecord (3.0.20) lib/active_record/query_cache.rb:12:in `cache'
  activerecord (3.0.20) lib/active_record/query_cache.rb:31:in `call'
  activerecord (3.0.20) lib/active_record/connection_adapters/abstract/connection_pool.rb:354:in `call'
  actionpack (3.0.20) lib/action_dispatch/middleware/callbacks.rb:46:in `call'
  activesupport (3.0.20) lib/active_support/callbacks.rb:416:in `_run_call_callbacks'
  actionpack (3.0.20) lib/action_dispatch/middleware/callbacks.rb:44:in `call'
  rack (1.2.8) lib/rack/sendfile.rb:106:in `call'
  actionpack (3.0.20) lib/action_dispatch/middleware/remote_ip.rb:48:in `call'
  actionpack (3.0.20) lib/action_dispatch/middleware/show_exceptions.rb:47:in `call'
  railties (3.0.20) lib/rails/rack/logger.rb:13:in `call'
  rack (1.2.8) lib/rack/runtime.rb:17:in `call'
  activesupport (3.0.20) lib/active_support/cache/strategy/local_cache.rb:72:in `call'
  rack (1.2.8) lib/rack/lock.rb:13:in `call'
  rack (1.2.8) lib/rack/lock.rb:13:in `synchronize'
  rack (1.2.8) lib/rack/lock.rb:13:in `call'
  railties (3.0.20) lib/rails/application.rb:168:in `call'
  railties (3.0.20) lib/rails/application.rb:77:in `send'
  railties (3.0.20) lib/rails/application.rb:77:in `method_missing'
  passenger (3.0.18) lib/phusion_passenger/rack/request_handler.rb:96:in `process_request'
  passenger (3.0.18) lib/phusion_passenger/abstract_request_handler.rb:516:in `accept_and_process_next_request'
  passenger (3.0.18) lib/phusion_passenger/abstract_request_handler.rb:274:in `main_loop'
  passenger (3.0.18) lib/phusion_passenger/rack/application_spawner.rb:206:in `start_request_handler'
  passenger (3.0.18) lib/phusion_passenger/rack/application_spawner.rb:171:in `send'
  passenger (3.0.18) lib/phusion_passenger/rack/application_spawner.rb:171:in `handle_spawn_application'
  passenger (3.0.18) lib/phusion_passenger/utils.rb:470:in `safe_fork'
  passenger (3.0.18) lib/phusion_passenger/rack/application_spawner.rb:166:in `handle_spawn_application'
  passenger (3.0.18) lib/phusion_passenger/abstract_server.rb:357:in `__send__'
  passenger (3.0.18) lib/phusion_passenger/abstract_server.rb:357:in `server_main_loop'
  passenger (3.0.18) lib/phusion_passenger/abstract_server.rb:206:in `start_synchronously'
  passenger (3.0.18) lib/phusion_passenger/abstract_server.rb:180:in `start'
  passenger (3.0.18) lib/phusion_passenger/rack/application_spawner.rb:129:in `start'
  passenger (3.0.18) lib/phusion_passenger/spawn_manager.rb:253:in `spawn_rack_application'
  passenger (3.0.18) lib/phusion_passenger/abstract_server_collection.rb:132:in `lookup_or_add'
  passenger (3.0.18) lib/phusion_passenger/spawn_manager.rb:246:in `spawn_rack_application'
  passenger (3.0.18) lib/phusion_passenger/abstract_server_collection.rb:82:in `synchronize'
  passenger (3.0.18) lib/phusion_passenger/abstract_server_collection.rb:79:in `synchronize'
  passenger (3.0.18) lib/phusion_passenger/spawn_manager.rb:244:in `spawn_rack_application'
  passenger (3.0.18) lib/phusion_passenger/spawn_manager.rb:137:in `spawn_application'
  passenger (3.0.18) lib/phusion_passenger/spawn_manager.rb:275:in `handle_spawn_application'
  passenger (3.0.18) lib/phusion_passenger/abstract_server.rb:357:in `__send__'
  passenger (3.0.18) lib/phusion_passenger/abstract_server.rb:357:in `server_main_loop'
  passenger (3.0.18) lib/phusion_passenger/abstract_server.rb:206:in `start_synchronously'
  passenger (3.0.18) helper-scripts/passenger-spawn-server:99

MDLIVE, INC. CONFIDENTIALITY NOTICE:

This e-mail and any attachments are for the exclusive and confidential use of the intended recipient. If you are not the intended recipient, please do not read, distribute or take action in reliance on this message. If you have received this message in error, please notify us immediately by return e-mail and promptly delete this message and its attachments from your computer system. We do not waive attorney-client, work product, doctor-patient, therapist-client or intellectual property privileges by the transmission of this message.

[Rick]

Are you really trying to match a users.id of xxxxx or is that just a log artifact? Is your MySQL server local or remote? What happens if you issue a "Customer.find(xxxxx)" in rails console? Obviously you need to provide a valid id, not xxxxx.

[David Webster]

I am using an actual ID, just redacted it for the public post. The MySQL server is remote. We process hundreds of requests a hour without the error, but around 1-2 times a hour we get this sort of error. the MySQL DB logs do not show anything, so I have eliminated it as a cause for this error. There isn't even a corresponding query in the log on the DB server for this request, all others are in there. It seems like rails is panicking and dropping the connection. But i have no way to debug this. The TCP transactions don't show anything either. I see the requests and responses, but this error doesn't show up in tcptrace output, so thats why im thinking rails is not even using a connection from the pool. 

in the ruby console..when i do:

User.find(XXXXX)

 with a actual user id it works every time, hammered on it 30-40 times in less then a sec and it doesnt cause a issue. Not sure if its follwing

[Rick]

Can you replicate the error on a development system that is connected to a local version of the database? I'm thinking you might want to really hammer on the system and not impact the production db.

On Wednesday, March 5, 2014 10:25:36 AM UTC-5, David Webster wrote:

I am using an actual ID, just redacted it for the public post. The MySQL server is remote. We process hundreds of requests a hour without the error, but around 1-2 times a hour we get this sort of error. the MySQL DB logs do not show anything, so I have eliminated it as a cause for this error. There isn't even a corresponding query in the log on the DB server for this request, all others are in there. It seems like rails is panicking and dropping the connection. But i have no way to debug this. The TCP transactions don't show anything either. I see the requests and responses, but this error doesn't show up in tcptrace output, so thats why im thinking rails is not even using a connection from the pool. 

 

David M. Webster
MDLIVE, Inc 

Security Architect , System Admin
13630 NW 8th Street I Suite 205 I Sunrise, Florida 33325
Office: 954-251-4471 I Mobile: 954-579-7799
dweb...@mdlive.com I www.mdlive.com 

"Changing the face of medicine"

--
You received this message because you are subscribed to a topic in the Google Groups "Ruby on Rails: Talk" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/rubyonrails-talk/5zstpn9HJmE/unsubscribe.
To unsubscribe from this group and all its topics, send an email to rubyonrails-ta...@googlegroups.com.
To post to this group, send email to rubyonra...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/rubyonrails-talk/0d3a60fd-6e5c-4629-948f-31135c0c663b%40googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

[Jason Fleetwood-Boldt]

I see this come through our trafficked websites (100-600 concurrent users) running on Heroku all the time … also 1-2 times per hour.

After talking to Heroku about it, we've always just chucked it up to network failures inside of the AWS cloud (that's basically what Heroku said about these, as well as connection failures to Redis). Contrary to popular belief, TCP/IP connections do fail, rarely, but it does happen. 

Assuming those are light queries, that is the most probably explanation.

We have this in our application controller which doesn't actually solve the problem, but reconnects to MySQL if the connection is lost somehow.

    

  rescue_from ActiveRecord::StatementInvalid, :with => :handle_statement_invalid

 def handle_statement_invalid(exception=nil)

    ActiveRecord::Base.connection.reconnect!

    render_500(exception)

  end

IMHO, knowing this happens this is all the more reason to write defensive, failure-tolerant code. (of course that doesn't help for a user who has already seen your 500 message, but would help for example in a job that could re-enqueue the job if it fails). 

What's slightly misleading is that you get a ActiveRecord::StatementInvalid even though it's a network problem -- you also see ActiveRecord::StatementInvalid if the query takes too long --- like if you send it a massive query that is beyond your Rack-timeout setting (which wouldn't be the case in your example because you are doing a simple sub-ms query).

Sorry this really isn't answer, but hopefully you feel less alone!

-Jason

You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group.
To unsubscribe from this group and stop receiving emails from it, send an email to rubyonrails-ta...@googlegroups.com.

To post to this group, send email to rubyonra...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/rubyonrails-talk/48597df3-a73d-4300-a82b-05d0c5ef818e%40googlegroups.com.

[Rick]

Line 265 of mysql2_adapter.rb falls right in the middle of this method definition:

      # Executes the SQL statement in the context of this connection.
      def execute(sql, name = nil)
        # make sure we carry over any changes to ActiveRecord::Base.default_timezone that have been
        # made since we established the connection
        @connection.query_options[:database_timezone] = ActiveRecord::Base.default_timezone
        if name == :skip_logging
          @connection.query(sql)
        else
          log(sql, name) { @connection.query(sql) }
        end
      rescue ActiveRecord::StatementInvalid => exception
        if exception.message.split(":").first =~ /Packets out of order/
          raise ActiveRecord::StatementInvalid, "'Packets out of order' error was received from the database. Please update your mysql bindings (gem install mysql) and read http://dev.mysql.com/doc/mysql/en/password-hashing.html for more information.  If you're on Windows, use the Instant Rails installer to get the updated mysql bindings."
        else
          raise
        end
      end

I added the bold - have you followed the instructions?