Rails App on Heroku Cannot Write to PostgreSQL Database, Only Read
I have a Ruby on Rails app that works fine locally with a sqlite3 database and can save and retrieve records without issue.
When deployed to Heroku at http://moviedata.herokuapp.com/ using a postgresql database, records are not saving even though it looks like the logs say they are. Records read from the db fine and data is displayed as expected.
The tailed logs for adding a record are:
2012-08-21T19:51:31+00:00 app[web.1]:
2012-08-21T19:51:31+00:00 app[web.1]:
2012-08-21T19:51:31+00:00 app[web.1]: Started POST "/" for 50.53.6.156 at 2012-08-21 19:51:31 +0000
2012-08-21T19:51:31+00:00 app[web.1]: Parameters: {"utf8"=>"✓", "authenticity_token"=>"+BYQLzhrfDkUVW8UaHikHpmtGHxpeQ/yF4VByHh9m1I=", "movie"=>{"title"=>"The Running Man", "description"=>"A documentary about a public execution game show.", "year"=>"1987", "genre"=>"science fiction"}, "commit"=>"Create Movie"}
2012-08-21T19:51:31+00:00 app[web.1]: Processing by MoviesController#index as HTML
2012-08-21T19:51:31+00:00 app[web.1]: Rendered movies/index.html.erb within layouts/application (5.1ms)
2012-08-21T19:51:31+00:00 app[web.1]: Completed 200 OK in 9ms (Views: 6.7ms | ActiveRecord: 0.9ms)
2012-08-21T19:51:31+00:00 heroku[router]: POST moviedata.herokuapp.com/ dyno=web.1 queue=0 wait=0ms service=17ms status=200 bytes=3479
The 'heroku pg' command shows the same number of rows (11) on the postgres database after a record is added.
This is a simple app I built to learn Rails and the Heroku platform. To reproduce this, just visit http://moviedata.herokuapp.com/ and click "New Movie", enter some junk data in the form, and hit "create movie". The record should be saved and show up in the list on the front page, but it doesn't.
Is there perhaps something I have to turn on, configure, or activate in order to be able to write to the postgres database? Seems very strange to me that it could be read from but not written to. Any better way to troubleshoot than the logs?
Locally I'm using Ruby 1.9.3, Rails, 3.2.8, PostgreSQL 9.1.5, SQLite 3.7.9, Heroku Toolbelt 2.30.3.
Edit/Update: I switched the local version to use psql. It also experiences the same problem where records are not saved. With the user set to log_statement='all' The log in at /var/log/postgresql/posgresql-9.1.main.log shows lots of selects, but when the record add is attempted, the log shows the database never being hit.
Foreman shows the data being posted, like so:
22:38:03 web.1 | Started POST "/" for 127.0.0.1 at 2012-08-21 22:38:02 -0700
22:38:03 web.1 | Processing by MoviesController#index as HTML
22:38:03 web.1 | Parameters: {"utf8"=>"✓", "authenticity_token"=>"0AyxRbwl/Kgi05uI1KX8uxVUJjx9ylAA1ltdWgmunm4=", "movie"=>{"title"=>"Army of Darkness", "description"=>"A man fights the living dead using a boomstick.", "year"=>"1997", "genre"=>"horror"}, "commit"=>"Create Movie"}
22:38:03 web.1 | Movie Load (0.8ms) SELECT "movies".* FROM "movies" ORDER BY title
22:38:03 web.1 | Rendered movies/index.html.erb within layouts/application (14.9ms)
A failed commit does sound like a great explanation. I'm not yet sure how to check whether the driver is set to commit or to see how/when a commit might have failed.
This is a very simple application, with no load balancing or complex configuration and most of the code was generated by the 'generate scaffold' command, but it's entirely possible that there's some constraint that's being violated somewhere before the db is ever hit. Perhaps there's a way to crank the Foreman (or Rails) log level up to 11? I also tried using thin instead and scoured the log files in the log/ folder and didn't find anything other than what's logged above.
This sounds a lot like a transaction issue, where you aren't COMMIT
ting your transactions after you do work, so the changes are lost. If your SQLite driver defaults to COMMIT
ting transactions that're closed without an explicit COMMIT
or rollback, and your Pg driver defaults to ROLLBACK
, you'd get the behaviour described. The same will happen if the SQLite defaults to autocomitting each statement by default, and the Pg driver driver defaults to opening a transaction.
This is one of the many good reasons to use the same local database for testing as you're going to deploy to when you want to go live.
If you were on a normal Pg instance I'd tell you to enable log_statement = 'all'
in postgresql.conf
, reload Pg, and watch the logs. You can't do that on Heroku, but you do have access to the Pg logs with heroku logs --ps postgres
. Try running ALTER USER my_heroku_user SET log_statement = 'all';
, re-testing, and examining the logs.
Alternately, install Pg locally.
Other less likely possibilities that come to mind:
INSERT
s, UPDATE
s, etc to fail, and your app is ignoring the resulting errors. Again, unlikely. DO INSTEAD
rules that don't do what you expect, or BEFORE
triggers that return NULL
, thus silently turning operations into no-ops. Seems unlikely if you're testing with SQLite.