Rails - Mar 2010 - ActiveRecord::StatementInvalid: Mysql::Error: Lock wait timeout exceeded

Hi all,

Ive been getting this error on one particular query repeatedly for the
past few days.

ActiveRecord::StatementInvalid: Mysql::Error: Lock wait timeout
exceeded; try restarting transaction: UPDATE `posts` SET `updated_at`
= ''2010-03-17 05:35:00'', `view_count` = 54 WHERE `id` = 158

Googling around, I found that this is basically because the
transaction times out after waiting for the time period thats defined
in the InnoDB settings. I also found that acts_as_ferret could cause
this while it locks down the row in question for indexing purposes.
However, I dont have any such background processes running that might
lock down rows in mass like this.

Is there some technique for pinpointing a process thats locking down
the rows in question? I found a plugin called deadlock-retry (http://
github.com/rails/deadlock_retry/) by Jamis Buck. But im not sure if
this will solve the problem at all. Besides, since this error is
happening only in production, im reluctant to deploy the plugin to
production and waiting to see if it does anything at all.

Anyone got any pointers on this?

Thanks!

-- 
You received this message because you are subscribed to the Google Groups
"Ruby on Rails: Talk" group.
To post to this group, send email to
rubyonrails-talk-/JYPxA39Uh5TLH3MbocFF+G/Ez6ZCGd0@public.gmane.org
To unsubscribe from this group, send email to
rubyonrails-talk+unsubscribe-/JYPxA39Uh5TLH3MbocFF+G/Ez6ZCGd0@public.gmane.org
For more options, visit this group at
http://groups.google.com/group/rubyonrails-talk?hl=en.

On Mar 17, 6:12 am, Ram
<yourstruly.vi...-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org>
wrote:
> Hi all,
>
> Ive been getting this error on one particular query repeatedly for the
> past few days.
>
> ActiveRecord::StatementInvalid: Mysql::Error: Lock wait timeout
> exceeded; try restarting transaction: UPDATE `posts` SET `updated_at`
> = ''2010-03-17 05:35:00'', `view_count` = 54 WHERE `id` =
158
>
> Googling around, I found that this is basically because the
> transaction times out after waiting for the time period thats defined
> in the InnoDB settings. I also found that acts_as_ferret could cause
> this while it locks down the row in question for indexing purposes.
> However, I dont have any such background processes running that might
> lock down rows in mass like this.
>
> Is there some technique for pinpointing a process thats locking down
> the rows in question? I found a plugin called deadlock-retry (http://
> github.com/rails/deadlock_retry/) by Jamis Buck. But im not sure if
> this will solve the problem at all. Besides, since this error is
> happening only in production, im reluctant to deploy the plugin to
> production and waiting to see if it does anything at all.
>
Mike Perham''s http://github.com/mperham/deadlock_retry/commits/master
fork of this logs the current innodb status when this happens (i think
the database user rails runs as needs certain permissions to be able
to run that statement).
Another thing worth looking for is whether there were any actions that
took a long time to run at round about the same time that that error
occurred - if that action was slow because of a large database query
it could be the cause

Fred
> Anyone got any pointers on this?
>
> Thanks!
-- 
You received this message because you are subscribed to the Google Groups
"Ruby on Rails: Talk" group.
To post to this group, send email to
rubyonrails-talk-/JYPxA39Uh5TLH3MbocFF+G/Ez6ZCGd0@public.gmane.org
To unsubscribe from this group, send email to
rubyonrails-talk+unsubscribe@googlegroups.com.
For more options, visit this group at
http://groups.google.com/group/rubyonrails-talk?hl=en.

Thanks Fred!

I have a staging server where I could deploy this. But I need to
reproduce the lockdown. Any hacks that I can use for that?

The tables are all quite small and there are no large db queries that
could be causing this that I know of. Will crawl through the rails
logs and see if I can find anything. However, given that Im not
logging the db connection times, I doubt I''ll be able to point a
finger at any one such query. This seems to be happening even when the
server is under relatively low load.

On Mar 17, 1:07 pm, Frederick Cheung
<frederick.che...-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org>
wrote:
> On Mar 17, 6:12 am, Ram
<yourstruly.vi...-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org> wrote:
>
>
>
>
>
> > Hi all,
>
> > Ive been getting this error on one particular query repeatedly for the
> > past few days.
>
> > ActiveRecord::StatementInvalid: Mysql::Error: Lock wait timeout
> > exceeded; try restarting transaction: UPDATE `posts` SET `updated_at`
> > = ''2010-03-17 05:35:00'', `view_count` = 54 WHERE
`id` = 158
>
> > Googling around, I found that this is basically because the
> > transaction times out after waiting for the time period thats defined
> > in the InnoDB settings. I also found that acts_as_ferret could cause
> > this while it locks down the row in question for indexing purposes.
> > However, I dont have any such background processes running that might
> > lock down rows in mass like this.
>
> > Is there some technique for pinpointing a process thats locking down
> > the rows in question? I found a plugin called deadlock-retry (http://
> > github.com/rails/deadlock_retry/) by Jamis Buck. But im not sure if
> > this will solve the problem at all. Besides, since this error is
> > happening only in production, im reluctant to deploy the plugin to
> > production and waiting to see if it does anything at all.
>
> Mike
Perham''shttp://github.com/mperham/deadlock_retry/commits/master
> fork of this logs the current innodb status when this happens (i think
> the database user rails runs as needs certain permissions to be able
> to run that statement).
> Another thing worth looking for is whether there were any actions that
> took a long time to run at round about the same time that that error
> occurred - if that action was slow because of a large database query
> it could be the cause
>
> Fred
>
>
>
> > Anyone got any pointers on this?
>
> > Thanks!
-- 
You received this message because you are subscribed to the Google Groups
"Ruby on Rails: Talk" group.
To post to this group, send email to
rubyonrails-talk-/JYPxA39Uh5TLH3MbocFF+G/Ez6ZCGd0@public.gmane.org
To unsubscribe from this group, send email to
rubyonrails-talk+unsubscribe@googlegroups.com.
For more options, visit this group at
http://groups.google.com/group/rubyonrails-talk?hl=en.

On Mar 17, 8:39 am, Ram
<yourstruly.vi...-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org>
wrote:
> Thanks Fred!
>
> I have a staging server where I could deploy this. But I need to
> reproduce the lockdown. Any hacks that I can use for that?
>
> The tables are all quite small and there are no large db queries that
> could be causing this that I know of. Will crawl through the rails
> logs and see if I can find anything. However, given that Im not
> logging the db connection times, I doubt I''ll be able to point a
> finger at any one such query. This seems to be happening even when the
> server is under relatively low load.
I''d turn on that logging. If you''re effectively blind as far
as your
application''s performance goes then this will be a needle in a
haystack affair.
given that the query mentions only the posts table it''s worth looking
at all queries that read or write to that table. Also check whether
you have any long lived transactions - any locks held during a
transaction last for the duration of the transaction

Fred
>
> On Mar 17, 1:07 pm, Frederick Cheung
<frederick.che...-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org>
> wrote:
>
>
>
> > On Mar 17, 6:12 am, Ram
<yourstruly.vi...-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org> wrote:
>
> > > Hi all,
>
> > > Ive been getting this error on one particular query repeatedly
for the
> > > past few days.
>
> > > ActiveRecord::StatementInvalid: Mysql::Error: Lock wait timeout
> > > exceeded; try restarting transaction: UPDATE `posts` SET
`updated_at`
> > > = ''2010-03-17 05:35:00'', `view_count` = 54
WHERE `id` = 158
>
> > > Googling around, I found that this is basically because the
> > > transaction times out after waiting for the time period thats
defined
> > > in the InnoDB settings. I also found that acts_as_ferret could
cause
> > > this while it locks down the row in question for indexing
purposes.
> > > However, I dont have any such background processes running that
might
> > > lock down rows in mass like this.
>
> > > Is there some technique for pinpointing a process thats locking
down
> > > the rows in question? I found a plugin called deadlock-retry
(http://
> > > github.com/rails/deadlock_retry/) by Jamis Buck. But im not sure
if
> > > this will solve the problem at all. Besides, since this error is
> > > happening only in production, im reluctant to deploy the plugin
to
> > > production and waiting to see if it does anything at all.
>
> > Mike
Perham''shttp://github.com/mperham/deadlock_retry/commits/master
> > fork of this logs the current innodb status when this happens (i think
> > the database user rails runs as needs certain permissions to be able
> > to run that statement).
> > Another thing worth looking for is whether there were any actions that
> > took a long time to run at round about the same time that that error
> > occurred - if that action was slow because of a large database query
> > it could be the cause
>
> > Fred
>
> > > Anyone got any pointers on this?
>
> > > Thanks!
-- 
You received this message because you are subscribed to the Google Groups
"Ruby on Rails: Talk" group.
To post to this group, send email to
rubyonrails-talk-/JYPxA39Uh5TLH3MbocFF+G/Ez6ZCGd0@public.gmane.org
To unsubscribe from this group, send email to
rubyonrails-talk+unsubscribe@googlegroups.com.
For more options, visit this group at
http://groups.google.com/group/rubyonrails-talk?hl=en.