Issue with hstore returning as string on postgres database, rails app

rubyonrails-talk
1

Summary: rails app using postgres randomly gets into a state where hstore array is returned as a string, and cannot be fixed without rebuilding the database

We have an app using rails 4.04 with ruby 1.9.3, postgres database version 9.2.6. Every day, in the test environment, we drop the database, create a new database, and restore the data from a production backup using pg_restore. The hstore extension is installed, and there is some hstore data in the database. The app doesn’t get much usage in the test environment right now. For the purposes of this problem, we can say it gets no usage other than deployment.

The deployment process seems to work perfectly well about 99 times out of 100, but every once in a while, the app suddenly doesn’t work. Trying to open the app, you get an error in the log like: ActionView::Template::Error(undefeined metghod ‘keys’ for ""width"=>“131.0"”.String)

The problem is that it is returning an hstore array as a string. From a non-working instance, here is some text from an irb session:

irb(main):002:0> r=Row.first
unknown OID: data(-1892003119) (SELECT  "rows".* FROM "rows"   ORDER BY "rows"."id" ASC LIMIT 1)
=> #<Row id: 1, data: "\"test123\"=>\"5\"", created_at: "2013-10-31 18:56:45", updated_at: "2013-10-31 18:57:05">

From a working instance, here is the same query:

irb(main):002:0> r=Row.first
=> #<Row id: 1, data: {"test123"=>"5"}, created_at: "2013-10-31 18:56:45", updated_at: "2013-10-31 18:57:05">

You can see that in the broken instance, it is returning the hstore data as a string. Some pertinent info is that once it gets in this broken state, you can drop and restore the database, or rename the database, and as long as it’s on the same postgres sever, it’s still broken - you have to rebuild the whole database for it to work. And if you point the app (change database.yml) to point to a different server, it works.

This happens with no code changes. Same ruby on rails code works, then on redeployment it doesn’t work. We cannot figure out any repro scenario. It works, it works, it works, then we do the same thing we’ve done a hundred times and it breaks.

Has anyone ever seen anything like this?

2

Summary: rails app using postgres randomly gets into a state where hstore array is returned as a string, and cannot be fixed without rebuilding the database

Not that familiar with (or fond of) postgres, but curious --

You can see that in the broken instance, it is returning the hstore data as a string. Some pertinent info is that once it gets in this broken state, you can drop and restore the database, or rename the database, and as long as it's on the same postgres sever, it's still broken - you have to rebuild the whole database for it to work.

What is the difference exactly between "drop and restore" and "rebuild"?

And if you point the app (change database.yml) to point to a different server, it works.

What's in the postgres logs when this fails? Is there anything in the Rails logs at startup that differs between working/not working?

Have you put any additional logging into the connection adapter?

3

Summary: rails app using postgres randomly gets into a state where hstore

array is returned as a string, and cannot be fixed without rebuilding the

database

Not that familiar with (or fond of) postgres, but curious –

You can see that in the broken instance, it is returning the hstore data as

a string. Some pertinent info is that once it gets in this broken state, you

can drop and restore the database, or rename the database, and as long as

it’s on the same postgres sever, it’s still broken - you have to rebuild the

whole database for it to work.

What is the difference exactly between “drop and restore” and

“rebuild”?

Sorry, I misspoke. I meant that once the problem occurs you have to actually reinstall postgres to get it to work again. So we drop and restore the database, hundreds of times, with no failure, then one day the same thing causes a failure. After that, even after dropping and restoring the database, hstore arrays are still returned as strings, for every database on the server. Then postgres is reinstalled, and it starts working again. Simply reinstalling the hstore extension is not enough to fix the problem - the whole postgres instance must be reinstalled.

And if you point the app (change

database.yml) to point to a different server, it works.

What’s in the postgres logs when this fails? Is there anything in the

Rails logs at startup that differs between working/not working?

Nothing useful beyond that it’s returning the hstore array as a string, nothing that tells us why. The cleanest log info is the info from the irb log I posted.

Have you put any additional logging into the connection adapter?

Not yet but the thing I’m trying to figure out how to do now is just repro the problem. I’ve repeated the deployment process hundreds of times with no repro… it works and works and works then the same thing fails.

4

If the problem affects every db on the server, I can't imagine how it could be anything *but* a postgres bug.

But since postgres apparently doesn't have any bug tracking system, who knows? :slight_smile:

If it were me, I'd jack the postgres logging level to max/debug/whatever provides the most data and cross fingers...

Good luck,