TinyTds::Error: Attempt to initiate a new Adaptive Server operation with results pending

[Andrea Campolonghi]

Hi,

I am having a strage and randomic issue.

Sometimes my application start to throw this kind of error:

ActiveRecord::StatementInvalid: TinyTds::Error: Attempt to initiate a new Adaptive Server operation with results pending: EXEC sp_executesql N'SELECT TOP (1) [users].* FROM [users] WHERE [users].[id] = 136'

Basically fails on the first query done by the request.

This happens on about 30/40 % of the requests while the others runs fine.

After a touch tmp/restart.txt anything is back on normal operation maybe for days or weeks.

Is this possibly related to a missing available connections in the pool?

I am using:

* activerecord-sqlserver-adapter (3.2.9)

* rails 3.2.3

* sql server 2008 web edition

Btw. What should be the correct pool size?

Thanks

Andrea

[Ken Collins]

Hey Andrea,

I am having a strage and randomic issue.

Sometimes my application start to throw this kind of error:

ActiveRecord::StatementInvalid: TinyTds::Error: Attempt to initiate a new Adaptive Server operation with results pending: EXEC sp_executesql N'SELECT TOP (1) [users].* FROM [users] WHERE [users].[id] = 136'

Basically fails on the first query done by the request.

This happens on about 30/40 % of the requests while the others runs fine.

That error happens when the low level connection, in this case TinyTDS, has been told to execute some SQL and then not told to iterate over the results, hence cleaning the batch. Since the adapter is well tested and will not let such a thing happen, the most common reason left is your own code. So I won't be able to tell you were in your code you can go look, but common patterns would be anywhere you use the #raw_connection (TinyTds::Client) object. 

After a touch tmp/restart.txt anything is back on normal operation maybe for days or weeks.

Is this possibly related to a missing available connections in the pool?

No.

Btw. What should be the correct pool size?

Leave it blank, no value with let ActiveReocrd use the default, which I think is 5. Moot for most people anyway. Only in threaded conditions will the connection pool ever go above 1 anyway.

  - Ken

[Andrea Campolonghi]

Thanks Ken,

your answer is very helpful and gave me an idea where to look for.

Andrea

--
You received this message because you are subscribed to the Google Groups "Rails SQLServer Adapter" group.
To post to this group, send email to rails-sqlse...@googlegroups.com.
To unsubscribe from this group, send email to rails-sqlserver-a...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/rails-sqlserver-adapter?hl=en.

Andrea Campolonghi

acampo...@gmail.com

[Andrea Campolonghi]

Ken,

a question about this.

I can confirm that this happens even with wrongly format sql statements.

An example can be an advanced search service that passes conditions to a paginator like will_paginate.

If for some reason the condition string result in a not well formatted sql statement thw query fails but the batch is not cleaned and the connection will remain pending forever.

I am not sure I get the point of why this is working in this way.

Should not make more sense just clean the batch after throwing the exception in any case? 

Thanks

Andrea

On Thursday, November 15, 2012 2:19:19 PM UTC+1, Andrea Campolonghi wrote:

Thanks Ken,

your answer is very helpful and gave me an idea where to look for.

Andrea

On Nov 15, 2012, at 2:12 PM, Ken Collins <k...@metaskills.net> wrote:

Hey Andrea,

I am having a strage and randomic issue.

Sometimes my application start to throw this kind of error:

ActiveRecord::StatementInvalid: TinyTds::Error: Attempt to initiate a new Adaptive Server operation with results pending: EXEC sp_executesql N'SELECT TOP (1) [users].* FROM [users] WHERE [users].[id] = 136'

Basically fails on the first query done by the request.

This happens on about 30/40 % of the requests while the others runs fine.

That error happens when the low level connection, in this case TinyTDS, has been told to execute some SQL and then not told to iterate over the results, hence cleaning the batch. Since the adapter is well tested and will not let such a thing happen, the most common reason left is your own code. So I won't be able to tell you were in your code you can go look, but common patterns would be anywhere you use the #raw_connection (TinyTds::Client) object. 

After a touch tmp/restart.txt anything is back on normal operation maybe for days or weeks.

Is this possibly related to a missing available connections in the pool?

No.

Btw. What should be the correct pool size?

Leave it blank, no value with let ActiveReocrd use the default, which I think is 5. Moot for most people anyway. Only in threaded conditions will the connection pool ever go above 1 anyway.

  - Ken

--
You received this message because you are subscribed to the Google Groups "Rails SQLServer Adapter" group.

To post to this group, send email to rails-sqlserver-adapter@googlegroups.com.
To unsubscribe from this group, send email to rails-sqlserver-adapter+unsub...@googlegroups.com.

For more options, visit this group at http://groups.google.com/group/rails-sqlserver-adapter?hl=en.

Andrea Campolonghi

acampo...@gmail.com

[Ken Collins]

Hey Andrea,

I am not sure I get the point of why this is working in this way.

Should not make more sense just clean the batch after throwing the exception in any case? 

As I said before:

> Since the adapter is well tested and will not let such a thing happen,

> the most common reason left is your own code.

So I agree, this should _not_ happen. And I will extend the statement to include other code, like WillPaginate. 

Also, I have a whole section of tests in TinyTDS for this.

https://github.com/rails-sqlserver/tiny_tds/blob/master/test/result_test.rb#L580

Specifically for invalid syntax too and a graceful handling of the followup query.

https://github.com/rails-sqlserver/tiny_tds/blob/master/test/result_test.rb#L639

Here is another test in the adapter. If the adapter or a library underneath like TinyTDS was not coping with invalid statements, then the suite would start to fail badly after this test, which it does not.

https://github.com/rails-sqlserver/activerecord-sqlserver-adapter/blob/master/test/cases/adapter_test_sqlserver.rb#L26-L28

So I still assert that someone is doing something wrong. Perhaps you have found a bug and some monkey patching in WillPaginate? Perhaps you have found an edge case in your setup. Can you help track that down?

 - Ken

[Andrea Campolonghi]

Ken,

I am actually looking for a test case to send to you.

I am on my log files looking for the culprit :)

Is quite hard to go back and find where the issue has started but I will surely find and report to you asap.

Andrea

--
You received this message because you are subscribed to a topic in the Google Groups "Rails SQLServer Adapter" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/rails-sqlserver-adapter/tHfF_gdwctI/unsubscribe?hl=en.
To unsubscribe from this group and all its topics, send an email to rails-sqlserver-a...@googlegroups.com.
To post to this group, send email to rails-sqlse...@googlegroups.com.
Visit this group at http://groups.google.com/group/rails-sqlserver-adapter?hl=en.
For more options, visit https://groups.google.com/groups/opt_out.
 
 

Andrea Campolonghi

acampo...@gmail.com

[Andrea Campolonghi]

Ken.

Does this error tells you something more?

TinyTds::Error: Attempt to initiate a new Adaptive Server operation with results pending: EXEC sp_executesql N'SELECT @@TRANCOUNT'

Does @@TRANCOUNT tells you something?

Thanks

Andrea

Andrea Campolonghi

acampo...@gmail.com

[Ken Collins]

Andrea,

It does. It tells me you are in a deep transaction rabbit hole that I have seen before. Be prepared to get frustrated. I will try to conjure up to the best of my abilities my old knowledge base to see if I can help. Here we go :)

So let's talk ActiveRecord and the connection pool. The basic workings of this is to allow a pool of distinct database connections to be used per thread. This also gets a little hair when you have multiple connections, say to a legacy DB. If you use #establish_connection anywhere in your code, you are creating another unique connection pool, this is why I tell people to use abstract connection classes. https://gist.github.com/metaskills/4065702

Can you tell me if you have multiple connections? Do you have models invoked in a callback using different connections from the parent connection? Hence cross DB transactions? Anything with Threads that would cause the normal connection pool to grow past 1?

 - Ken

[Andrea Campolonghi]

Ken,

Yes I have 2 dbs but only one is invoked here.

Second DB has his own abstract class and is only used by resque workers to make different tasks.

I got the point where the error begins.

I try to with one example:

# Controller

if @user.update_attributes(params[:user]) do

   

   @user.mailbox.try(:calculate_usage.try(:save)

  ........

  

end

# model

class Mailbox

  belongs_to :user

  

  def calculate_usage    

    self.some_field = some_calculation

    self

  end  

end

The try statement is there cause may exists the case where a user does not have a mailbox.

Imagine User as the root of a quite complex AR models relations that updates accepting_nested attributes.

Some of this model has callbacks that actually makes query operations and this did not create issues in the past.

I am now changed the controller like ( while the Mailbox#calculate_usage does not return self anymore):

if @user.update_attributes(params[:user]) do

   

   mailbox = @user.mailbox

   mailbox.calculate_usage

   mailbox.save

  ........

  

end

After 1 hr running I did not get anymore the error. 

My question is.

In terms of transaction what exactly change if I make an update on Mailbox in an AR callback ( say after_save ) or in the controller 

acting on the local variable ( say @user.mailbox ).

Does this makes any sense to you.

I know that looks confused but I am yet 100% sure of what is happening.

Application is a huge CRM with quite high traffic.

Andrea

--
You received this message because you are subscribed to a topic in the Google Groups "Rails SQLServer Adapter" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/rails-sqlserver-adapter/tHfF_gdwctI/unsubscribe?hl=en.
To unsubscribe from this group and all its topics, send an email to rails-sqlserver-a...@googlegroups.com.
To post to this group, send email to rails-sqlse...@googlegroups.com.
Visit this group at http://groups.google.com/group/rails-sqlserver-adapter?hl=en.
For more options, visit https://groups.google.com/groups/opt_out.
 
 

Andrea Campolonghi

acampo...@gmail.com

[Andrea Campolonghi]

Sorry a typo :)

I know that looks confused but I am NOT yet 100% sure of what is happening.

Andrea

On Mar 5, 2013, at 5:28 PM, Andrea Campolonghi <acampo...@gmail.com> wrote:

I know that looks confused but I am yet 100% sure of what is happening.

Andrea Campolonghi

acampo...@gmail.com

[Andrea Campolonghi]

Ken.

Looks like we are using FreeTDS 0.82.

Is this possibly related?

I also see that in the host config in freetds.conf we are using:

tds version = 7.0  vs a SqlServer 2008

Andrea

--
You received this message because you are subscribed to a topic in the Google Groups "Rails SQLServer Adapter" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/rails-sqlserver-adapter/tHfF_gdwctI/unsubscribe?hl=en.
To unsubscribe from this group and all its topics, send an email to rails-sqlserver-a...@googlegroups.com.
To post to this group, send email to rails-sqlse...@googlegroups.com.
Visit this group at http://groups.google.com/group/rails-sqlserver-adapter?hl=en.
For more options, visit https://groups.google.com/groups/opt_out.
 
 

Andrea Campolonghi

acampo...@gmail.com

[Ken Collins]

On Mar 6, 2013, at 6:52 AM, Andrea Campolonghi <acampo...@gmail.com> wrote:

Looks like we are using FreeTDS 0.82.

Is this possibly related?

Possible, but not likely. It would not hurt to upgrade, your version is 5 to 6 years old.

tds version = 7.0  vs a SqlServer 2008

No, that is the right setting. It does not make sense, but it is. I touch on this in the intro of the TinyTDS read me. CHeck it out if you want, but leave that as is.

 - Ken

[Andrea Campolonghi]

OK thanks.

Btw I have isolated the bunch of code that creates the issue.

And that is a good starting point.

I will advise if I can reproduce in a test case.

Andrea

--
You received this message because you are subscribed to a topic in the Google Groups "Rails SQLServer Adapter" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/rails-sqlserver-adapter/tHfF_gdwctI/unsubscribe?hl=en.
To unsubscribe from this group and all its topics, send an email to rails-sqlserver-a...@googlegroups.com.
To post to this group, send email to rails-sqlse...@googlegroups.com.
Visit this group at http://groups.google.com/group/rails-sqlserver-adapter?hl=en.
For more options, visit https://groups.google.com/groups/opt_out.
 
 

Andrea Campolonghi

acampo...@gmail.com

[Andrea Campolonghi]

I think I got.

I have isolated the piece of code.

Basically is a method that perform calculations when some particular value change and denormalize in database some value to be easier analyzed later on.

Btw. The real error is this:

ActiveRecord::StatementInvalid - TinyTds::Error: The number '1559.691097604576331784054343939935645335' is out of the range for numeric representation (maximum precision 38).:

I have 2 environment:

* Production environment (Ubuntu 10.04 with freetds 0.82) gives back the error:

Attempt to initiate a new Adaptive Server operation with results pending ...... SELECT @@TRANCOUNT 

And leaves the connection pending

* Local env (osx) with freetds 0.91 throw the correct exception and clean the batch.

I am deploying the patch on the prod env right now.

Does that makes any sense to you?

 

Andrea

 

Andrea Campolonghi

acampo...@gmail.com

[Andrea Campolonghi]

Confirmed that rounding the calculation result before sending to sql solved on production env.

I am now on the way to upgrade freetds to 0.91

Andrea

Andrea Campolonghi

acampo...@gmail.com

[Ken Collins]

I would be interested in knowing the severity of that error. You can do that by capturing the error and then doing this with it.

puts e.original_exception.message

puts e.original_exception.severity

puts e.original_exception.db_error_number

I suspect it may align with these number #10011 and EXPROGRAM which is severity 7.

http://technet.microsoft.com/en-us/library/cc917591.aspx

http://msdn.microsoft.com/en-us/library/aa937495(v=sql.80).aspx

TinyTDS does not raise errors below 10 for a good reason, there are tons of them in syb.h

https://github.com/rails-sqlserver/tiny_tds/blob/master/test/result_test.rb#L589

Can you capture all this info in an issue on TinyTDS with a link back to the google thread so I can look at this later?

BTW, GREAT JOB!

 - Ken

[Andrea Campolonghi]

Ken,

I could not get the info:

NoMethodError (undefined method `original_exception' for #<ActiveRecord::StatementInvalid:0x00000008207fd0>):

Btw I am upgrading to freetds 0.91 and anything looks nice. :)

I see there are also newer version :

0.91.49

0.91.82

Any advise??

Btw really thank you for your great assistance !

You really helped me a lot !

Andrea

--
You received this message because you are subscribed to a topic in the Google Groups "Rails SQLServer Adapter" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/rails-sqlserver-adapter/tHfF_gdwctI/unsubscribe?hl=en.
To unsubscribe from this group and all its topics, send an email to rails-sqlserver-a...@googlegroups.com.
To post to this group, send email to rails-sqlse...@googlegroups.com.
Visit this group at http://groups.google.com/group/rails-sqlserver-adapter?hl=en.
For more options, visit https://groups.google.com/groups/opt_out.
 
 

Andrea Campolonghi

acampo...@gmail.com