Thread: postgres randomly gets into state where it returns hstore as string

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

Sorry that I don't have repro steps for this, we have tried to figure them =
out, but it seems like the same steps work 99 times out of a hundred, then =
it just randomly fails... I'd love to hear if anyone else is experiencing t=
his problem and how they fixed it.

Details:

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 n=
ew 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 d=
atabase. 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 de=
ployment.

The deployment process seems to work perfectly well about 99 times out of 1=
00, but every once in a while, the app suddenly doesn't work. Trying to ope=
n the app, you get an error in the log like: ActionView::Template::Error(un=
defeined metghod 'keys' for "\"width\"=3D>"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=3DRow.first
    unknown OID: data(-1892003119) (SELECT  "rows".* FROM "rows"   ORDER BY=
 "rows"."id" ASC LIMIT 1)
    =3D> #<Row id: 1, data: "\"test123\"=3D>\"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=3DRow.first
    =3D> #<Row id: 1, data: {"test123"=3D>"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, y=
ou can drop and restore the database, or rename the database, and as long a=
s it's on the same postgres sever, it's still broken - you have to reinstal=
l posgtgres 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 r=
edeployment it doesn't work. We cannot figure out any repro scenario. It wo=
rks, it works, it works, then we do the same thing we've done a hundred tim=
es and it breaks.

This is exposed only in a rails app but it is clearly a postgres bug - With=
out changing the rails code, we can reinstall postgres and setup the databa=
se again and it starts working.

Has anyone ever seen anything like this?

This is an ActiveRecord/Rails bug.

When you restarted/reinstalled postgresql, it causes ActiveRecord to
refresh its data about the columns, fixing whatever problems it's having.


On Wed, Sep 3, 2014 at 10:43 AM, Zeb Haradon <zebh@alleninstitute.org>
wrote:

>  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
>
>
>
> Sorry that I don=E2=80=99t have repro steps for this, we have tried to fi=
gure them
> out, but it seems like the same steps work 99 times out of a hundred, the=
n
> it just randomly fails=E2=80=A6 I=E2=80=99d love to hear if anyone else i=
s experiencing
> this problem and how they fixed it.
>
>
>
> Details:
>
>
>
> We have an app using rails 4.04 with ruby 1.9.3, postgres database versio=
n
> 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 ge=
ts
> 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\"=3D>"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=3DRow.first
>
>     unknown OID: data(-1892003119) (SELECT  "rows".* FROM "rows"   ORDER
> BY "rows"."id" ASC LIMIT 1)
>
>     =3D> #<Row id: 1, data: "\"test123\"=3D>\"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=3DRow.first
>
>     =3D> #<Row id: 1, data: {"test123"=3D>"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 stat=
e,
> you can drop and restore the database, or rename the database, and as lon=
g
> as it's on the same postgres sever, it's still broken - you have to
> reinstall posgtgres 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.
>
>
>
> This is exposed only in a rails app but it is clearly a postgres bug -
> Without changing the rails code, we can reinstall postgres and setup the
> database again and it starts working.
>
>
>
> Has anyone ever seen anything like this?
>