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

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.

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.

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

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.

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.

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

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?