brianmario / mysql2

A modern, simple and very fast Mysql library for Ruby - binding to libmysql
http://github.com/brianmario/mysql2
MIT License
2.25k stars 550 forks source link

Mysql2::Error: This connection is still waiting for a result, try again once you have the result #99

Closed ghazel closed 11 years ago

ghazel commented 13 years ago

Easy to reproduce. From a console, run a query and Ctrl-C it while it's running. Then try to submit a second query:

>> client
=> #<Mysql2::Client:0x40254f0>
>> client.query("select sleep(5);")
IRB::Abort: abort then interrupt!!
      from /usr/local/ruby-enterprise-1.8.7-2010.01/lib/ruby/1.8/irb.rb:89:in `irb_abort'
      from /usr/local/ruby-enterprise-1.8.7-2010.01/lib/ruby/1.8/irb.rb:255:in `signal_handle'
      from /usr/local/ruby-enterprise-1.8.7-2010.01/lib/ruby/1.8/irb.rb:66
      from (irb):2:in `call'
      from (irb):2:in `query'
      from (irb):2
>> client.query("select sleep(2);")
Mysql2::Error: This connection is still waiting for a result, try again once you have the result
      from (irb):3:in `query'
      from (irb):3

The client object remains broken forever - long after the initial query would have returned.

sheuer commented 13 years ago

I'm also having this problem.

ghazel commented 13 years ago

This also happens when using Timeout:

>> Timeout.timeout(1) { client.query("select sleep(5);"); }
Timeout::Error: execution expired
        from /usr/local/ruby-enterprise-1.8.7-2010.01/lib/ruby/1.8/timeout.rb:60
        from (irb):17
>> Timeout.timeout(1) { client.query("select sleep(5);"); }
Mysql2::Error: This connection is still waiting for a result, try again once you have the result
        from (irb):18:in `query'
        from (irb):18
        from /usr/local/ruby-enterprise-1.8.7-2010.01/lib/ruby/1.8/timeout.rb:62:in `timeout'
        from (irb):18
cpg commented 13 years ago

Same here, I had to press ctrl-c as things were becoming way too slow (we were doing some load testing). This is a reliability issue, as sooner or later things can get interrupted under load, etc. An app that needs to be available reliably cannot afford to have something like this lurking. Let us know how we can help fix this. The repro above with Timeout looks like a great start!

I am on RoR 3.0.3 with rack 1.2.1, ruby ruby-1.8.7.302-2.fc14.i686 and mysql2 0.2.6

schugabe commented 13 years ago

I have a similar problem. I'm sending out a bunch of emails and during the generation of those I get a "Exception ActiveRecord::StatementInvalid -> : execution expired" error. This happen every time but not on the same records.

After this error occurred all following queries fail with "Exception ActiveRecord::StatementInvalid -> Mysql2::Error: This connection is still waiting for a result, try again once you have the result"

RoR 3.0.3 in a Stalker background process, ruby 1.9.2; mysql2 0.2.6

iGEL commented 13 years ago

I've run into this problem in production. I'm using Timeout, so a query could have been interrupted.

Rails 3.0.3, Ruby 1.8.7, mysql2 0.2.6

conorh commented 13 years ago

Using the Mysql2::EM::Client.new class and running into this too. Ruby 1.9.2, Rails 2.3.9, EventMachine 0.12.10.

ponny commented 13 years ago

Same. Rails3/1.9.2.

JoshMcKin commented 13 years ago

Same time. Rails 3 (threadsafe), 1.9.2

deltadd commented 13 years ago

Same. Rails3.0.6/1.9.2.

jlecour commented 13 years ago

Same here ; Rails 3.0.6, Ruby 1.8.7

jlecour commented 13 years ago

When used in Rails with ActiveRecord, it's possible to recover from this exception.

# This is just to abort a query
Timeout.timeout(1) { MyModel.connection.execute("select sleep(5);"); }

# This is the recovering hack
begin
  # Any query on a model
  MyModel.first
rescue ActiveRecord::StatementInvalid => ex
  # Since all Mysql2 errors are wrapped into ActiveRecord::StatementInvalid
  # we have to retry only for this kind of error
  if ex.message["Mysql2::Error: This connection is still waiting for a result"]
    @retries ||= 0
    # Retry only 3 times
    puts @retries
    if @retries < 3
      @retries += 1
      MyModel.connection.reconnect!
      retry
    else
      raise
    end
  else
    raise
  end
else
  @retries = 0
end
ghazel commented 13 years ago

Here's a monkey-patch to auto-reconnect when this occurs:

module ActiveRecord
  module ConnectionAdapters
    class Mysql2Adapter

      def query_with_reconnect(sql)
        @connection.query(sql)
      rescue Mysql2::Error => exception
        if exception.message.starts_with? "This connection is still waiting for a result"
          reconnect!
          retry
        end
        raise
      end

      # 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
          query_with_reconnect(sql)
        else
          log(sql, name) { query_with_reconnect(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
    end
  end
end
ramsingla commented 13 years ago

Please have a look at https://github.com/brianmario/mysql2/pull/168. Does this solve the issue you guys are facing? Looking for your feedback.

ghazel commented 13 years ago

@ramsingla: I think you've addressed a different issue with the same error message. I'm using mysql2_adapter.rb not em_mysql2_adapter.rb so any EM related solution doesn't apply.

mhoran commented 13 years ago

This is also an issue if you set read_timeout in database.yml, as the connection is closed but still waiting for a result. This is with the non-EM client.

phuongnd08 commented 13 years ago

With mysql2 0.2.7, I'm also running into this problem today when upgrade to ruby 1.9.2. Never encountered before in ruby 1.8.7

aka47 commented 13 years ago

the hotfix made by @ghazel fixed the problem for us. Thanks and hope this bug gets solved .. we run into that error with lots of data in a table (sessions), it just popped up after some time without a problem. We use mysql2 0.2.7 on ruby enterprise 1.8.7 and rails 3.0.5

loe commented 13 years ago

I suspect people using Unicorn do not notice this as they kill the entire worker process which causes a new one to be spawned. The new worker reconnects when starting up. We use a timeout in the application to kill long running requests, and it causes queries to die in this state.

loe commented 13 years ago

I'm thinking rb_mysql_client_query should be wrapped in an rb_rescue and the callback should reset the connection.

brianmario commented 13 years ago

I just pushed a fix for this in the 0.2.x and master branches, would you guys mind giving it a try? I'll push another release if it fixes it for you guys.

loe commented 13 years ago

This causes another test to fail. I've amended my test to use :reconnect => true, you can pull it in as a test for this.

Failures:

  1) Mysql2::Result should raise a Mysql2::Error exception upon a bad query
     Failure/Error: lambda {
       expected no Mysql2::Error, got #<Mysql2::Error: closed MySQL connection>
     # ./spec/mysql2/result_spec.rb:26:in `block (2 levels) in <top (required)>'
brianmario commented 13 years ago

Ah good catch, lemme get a fix pushed for that

loe commented 13 years ago

Sent a pull request for each branch, you can just pull one and merge/cherry-pick.

brianmario commented 13 years ago

Ok just pushed another patch, try again?

loe commented 13 years ago

Yay:

Finished in 5.56 seconds 137 examples, 0 failures, 1 pending

brianmario commented 13 years ago

@ghzel - summary of the changes to fix this issue:

The problem: if a signal interrupted the rb_thread_select call, the connection would never get marked as "inactive" (meaning, ready for another command to be sent) and would permanently be stuck in that state.

The fix: Wrap the rb_thread_select code in an rb_rescue2 call. If an exception is raised and caught, mark the connection closed and inactive, then manually shutdown the socket (not mysql_close). Since the MySQL protocol is asynchronous- if we're interrupted after the query has been sent but before we were able to process the result the protocol is essentially in a bad state and the next command would be sent out of order. If :reconnect => true is set, the next command sent would force a reconnect transparently.

This should fix the issue, but I'd like to hear back from at least another person that it has before closing the issue.

loe commented 13 years ago

I will ship this into production on 3 well trafficked applications.

ramsingla commented 13 years ago

This fix works well even with high concurrency using em_mysql2 adapter. I was able to server 4000 requests with concurrency of 40 with each action taking 1 second to complete in around 106 seconds without any request failures. That was not the case before the fix. Only a handful of about 80 requests used to be served, all other resulted in MySQL::Error. Kudos @brianmario. It is indeed a great fix. I agree that the problem has been correctly nailed and fix correctly addresses it.

mhoran commented 13 years ago

Will test tomorrow, but this looks good. Thanks for bumping the 0.2.x branch as well.

ghazel commented 13 years ago

Doesn't work for me. ruby 1.8.7, win32, 0.2.x branch, 812eeefcb0f8af2c2afa2668f3d7d79a4a3cb910

First off, it seems the new blocking rb_mysql_client_async_result call on win32 is not interruptable with Ctrl-C or Timeout.timeout(1) { ... }. This is unfortunate.

Second, hitting Ctrl-C on a long running query does raise an exception when the call completes, which still seems to leave the Mysql2::Client in an unusable state, raising "This connection is still waiting for a result, try again once you have the result." when you try to use it a second time.

brianmario commented 13 years ago

Can you interrupt a query via ctrl+c or Timeout with the regular mysql gem? It's my impression that you can't, at least on unixy platforms and from poking around it's code (and that of libmysql) I don't see anything that would suggest otherwise. That being said, the changes I made yesterday should allow mysql2 to be interrupted on unixy platforms but I haven't had a chance to test the windows side. The fact that it's blocking doesn't surprise me, but I definitely don't want it to be left in that bad state. I'll try and push a fix for that right now.

ghazel commented 13 years ago

You're right, the regular mysql gem isn't interruptable either. Also it segfaults. Oh well.

mhoran commented 13 years ago

Works great. Thanks!

brianmario commented 13 years ago

@ghazel - just pushed a fix that should cleanup the connection's "active" state if interrupted on Windows. Wanna give it a try?

FYI: it still blocks until the query returns, I haven't figured out a way around that yet...

ghazel commented 13 years ago

Works great, thanks!

micke commented 13 years ago

I am getting this error when using this code: https://gist.github.com/1040161

barunio commented 13 years ago

When we updated from 0.2.6 to 0.2.13, we started getting this error almost all of the time in our app, once every handful of requests. Going back to 0.2.6 solved the issue, but obviously that's not a great solution. We're not on rails 3.1 yet so I'm stuck on the 0.2.x branch. The app is running on Heroku, and we're using the normal mysql2 client, not the EM client.

vaharoni commented 13 years ago

+1 This error is happening for us and can be reproduced using ghazel's snippet from December 21,2010 with ActiveRecord::Base.connection as the client. We're on Rails 3.1, 1.9.2-p290, mysql2 0.3.7.

zdennis commented 13 years ago

+1 to vaharoni. We are also getting this issue with mysql 0.3.7. We are not using the EM client and we are on Rails 3.1.

ilyakatz commented 13 years ago

+1 a few folks have been talking about this on capybara-webkit issue list https://github.com/thoughtbot/capybara-webkit/issues/154, i thought it was related to the server that was used for headless browser testing but now that this thread came up, perhaps this is a better place to vote for the issue

dmitriy-kiriyenko commented 13 years ago

+1

This issue still exists

I currently live without this problem on Rails 3.0.10, mysql2 0.2.10, capybara 1.0.0, selenium-webdriver 0.2.x. If I am upgrading or changing any of these, the problem occurs. For example, I meet the problem if I do any of the:

Guess, the problem exists and not closed. What could you advice me to do?

Also check the issue on thoughtbot/capybara-webkit#154

alder commented 13 years ago

+1 to dmitriy-kiriyenko. This problem makes me cry.

aratak commented 13 years ago

The same problem after updating to rails 3.1 with latest mysql2 As for me, this is a blocker to upgrade to rails3.1.

oleksiilevzhynskyi commented 13 years ago

+1 I have this problem too.

caseyprovost commented 13 years ago

+1 I have this issue with the following setup Ruby 1.9.2p-290 Rails 3.0.10 mysql 0.2.7 Capybara 1.1.1 selenium-webdriver 2.6.0

caseyprovost commented 13 years ago

apologies...mysql2 version 0.2.13

dmitriy-kiriyenko commented 13 years ago

FYI, increasing pool from 5 to say 50 in database.yml seems to suppress this issue.

dmitriy-kiriyenko commented 13 years ago

Is the project alive? The issue is marked as resolved, yet lots of people report it's still notices, however, the issue is still not reopened.

ghazel commented 13 years ago

Re-opened to show we're watching.

Does anyone who is experiencing the issue care to git-bisect with my snippet above and narrow down which revision broke it?

dmitriy-kiriyenko commented 13 years ago

Btw, solution with setting poll to 50 is definitely not a good workaround if you run tests on continuous integration server, which is also your production server. Like in my case =(