db table locks after the first email and subsequent emails fail

[ajpierson]

When I use mailcatcher, it will receive 1 email, then the db table is locked and all other messages are rejected with:

Net::SMTPFatalError: 550 Message rejected

from /home/vagrant/.rvm/rubies/ree-1.8.7-2012.02/lib/ruby/1.8/net/smtp.rb:942:in `check_response'
from /home/vagrant/.rvm/rubies/ree-1.8.7-2012.02/lib/ruby/1.8/net/smtp.rb:896:in `data'
from /home/vagrant/.rvm/rubies/ree-1.8.7-2012.02/lib/ruby/1.8/net/smtp.rb:654:in `sendmail'
from /home/vagrant/.rvm/rubies/ree-1.8.7-2012.02/lib/ruby/1.8/net/smtp.rb:843:in `rcptto_list'
from /home/vagrant/.rvm/rubies/ree-1.8.7-2012.02/lib/ruby/1.8/net/smtp.rb:654:in `sendmail'
from /home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/mail-2.5.4/lib/mail/network/delivery_methods/smtp.rb:113:in `deliver!'
from /home/vagrant/.rvm/rubies/ree-1.8.7-2012.02/lib/ruby/1.8/net/smtp.rb:526:in `start'
from /home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/mail-2.5.4/lib/mail/network/delivery_methods/smtp.rb:112:in `deliver!'
from /home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/mail-2.5.4/lib/mail/message.rb:2129:in `do_delivery'
from /home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/mail-2.5.4/lib/mail/message.rb:232:in `deliver'
from /home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/actionmailer-3.2.14/lib/action_mailer/base.rb:415:in `deliver_mail'
from /home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/activesupport-3.2.14/lib/active_support/notifications.rb:123:in `instrument'
from /home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/activesupport-3.2.14/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
from /home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/activesupport-3.2.14/lib/active_support/notifications.rb:123:in `instrument'
from /home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/actionmailer-3.2.14/lib/action_mailer/base.rb:413:in `deliver_mail'
from /home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/mail-2.5.4/lib/mail/message.rb:232:in `deliver'

The stacktrace from mailcatcher looks like:

==> SMTP: Received message from 'survey@place.com' (607 bytes)
*** Error receiving message: {:source=>"Date: Wed, 08 Jan 2014 06:52:20 +0000\nFrom: survey@place.com\nReply-To: Support support@someplace.com\nTo: asdfasdf@asdfasdf.com\nMessage-ID: 52ccf5a4bac40_1009b4d4134524e2@bptw.localdomain.mail\nSubject: Subject\nMime-Version: 1.0\nContent-Type: text/html;\n charset=UTF-8\nContent-Transfer-Encoding: 7bit\n\n

First Name:Asdf

\n

Last Name:Asdf

\n

Full Name:Asdf Asdf

\n

Formal Name:Mr. Asdf Asdf

\n

Company Name:Some Company

\n

URL: <a href="http://localhost:3000/surveys/er2014/en\">http://localhost:3000/surveys/er2014/en

\n

 

", :sender=>"survey@place.com", :recipients=>["asdfasdf@asdfasdf.com"]}
Exception: database table is locked
Backtrace:
/home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/sqlite3-1.3.8/lib/sqlite3/statement.rb:67:in step' /home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/sqlite3-1.3.8/lib/sqlite3/statement.rb:67:inexecute'
/home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/mailcatcher-0.5.12/lib/mail_catcher/mail.rb:44:in add_message' /home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/mailcatcher-0.5.12/lib/mail_catcher/smtp.rb:42:inreceive_message'
/home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/eventmachine-1.0.3/lib/em/protocols/smtpserver.rb:535:in process_data_line' /home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/eventmachine-1.0.3/lib/em/protocols/smtpserver.rb:196:inreceive_line'
/home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/eventmachine-1.0.3/lib/em/protocols/linetext2.rb:64:in receive_data' /home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/eventmachine-1.0.3/lib/em/protocols/linetext2.rb:65:inreceive_data'
/home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/eventmachine-1.0.3/lib/eventmachine.rb:187:in run_machine' /home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/eventmachine-1.0.3/lib/eventmachine.rb:187:inrun'
/home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/mailcatcher-0.5.12/lib/mail_catcher.rb:134:in run!' /home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/gems/mailcatcher-0.5.12/bin/mailcatcher:4 /home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/bin/mailcatcher:23:inload'
/home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/bin/mailcatcher:23
/home/vagrant/.rvm/gems/ree-1.8.7-2012.02@bptw/bin/ruby_executable_hooks:14

Any idea what I'm doing wrong?

[dobermai]

I have exactly the same problem. Did you manage to resolve this issue in the meantime?

[ajpierson]

nope, never figured it out, what OS are you using? I'm on CentOS 5

[dobermai]

I'm also on CentOS5 and cannot upgrade. Very annoying problem but I don't have a clue where to start patching as I'm not a Ruby guy. :(

[jfairbank]

I'm getting the same issue on my staging environment, RHEL 5. However, I don't get the issue on my development environment, Ubuntu 12.04.

[ajpierson]

it must be a problem with RedHat/Centos 5. I'm using centos 5 in a vagrant
box. I ended up just running mailcatcher on my mac and configuring my app
to connect to it on the mac. If you are able to get it figured out I'd
love to hear about it.

On Fri, Feb 28, 2014 at 9:11 AM, Jeremy Fairbank
notifications@github.comwrote:

I'm getting the same issue on my staging environment,RHEL 5. However, I
don't get the issue on my development environment, Ubuntu 12.04.

Reply to this email directly or view it on GitHubhttps://github.com//issues/117#issuecomment-36365843
.

[jfairbank]

I'm curious if it's related to the libsqlite3 version? I don't know enough about it to determine if it could be the cause. I'll have to pull my development version tomorrow, but my staging environment currently runs an older 3.3.6.

[jfairbank]

I'll have to pull my development version tomorrow

About forgot to do this. So, my dev version is 3.7.9.

[sancromeu]

I had this issue when using with RHEL. I finally got it to work.
I am not submitting as a fix since this is rather a tweak. It looks like the issue is somewhere else, most likely in sqlite3 as jfairbank mentioned.

Short Story
This is caused by some of the conditional initializers ||= used for SELECT prepared statements.

There is only one file to patch:
https://github.com/sancromeu/mailcatcher/blob/0deddf8c335ba50e261baf0e23c94ac3110e43e1/lib/mail_catcher/mail.rb
Check out the diff:
sancromeu@0deddf8

Long story
(for others that can further research the issue, possibly with sqlite3)
I poked around, adding logging for DB events and narrowed this down to the conditional initializers ||= used for some of the SELECT prepared statements.
First I thought it was related to not closing resultsets after execute calls. So I tried handling these calls:

@query.execute.next

instead as

resultset = @query.execute
row = resultset.next
resultset.close
row

and these in a similar way:

@query.execute.map

But no luck.
So I ended up removing some conditional initializers for SELECT prepared statements.
The interesting thing is that the problem occurs only when executing these statements with:

@query.execute.next

but not with:

@messages_query.execute.map

[sj26]

@sancromeu nice investigation, albeit with frustrating results.

The whole point of prepared statements is to prepare them once then reuse them with varied bound data. This looks like an upstream bug that I can't really address except to remove an optimisation which should work for everybody.

I'm afraid the resolution here is probably to fix the upstream sqlite package in centos, or recompile it, and these things are outside my control so closing this issue.