Обсуждение: Update of table lags execution of statement by >1 minute?

Running 8.2.4 on Debian stable (Etch).

I'm having this issue where once or twice per day (out of ~100,000 queries)
the table doesn't reflect a committed update immediately.  Usually when this
problem occurs the update takes 1-3 minutes to be reflected in SELECT
queries.  Occasionally, it has taken more than 10 minutes.

The session could go something like this:

UPDATE mytable SET myattribute=1 WHERE id=14;
COMMIT;
SELECT myattribute FROM mytable WHERE id=14;

(Query returns myattribute with a value of 0)

(Wait 5 minutes)
SELECT myattribute FROM mytable WHERE id=14;

(Query returns myattribute with a value of 1)


Does anybody have any idea why this would be happening?  Watching the query
logs, it is clear that nothing is overwriting the value in the interim.
Simply, the update is taking an arbitrary amount of time to be reflected in
selects to the table.


Thanks,
Erik Peterson

"Erik Peterson" <epeterson@cardiomems.com> writes:
> I'm having this issue where once or twice per day (out of ~100,000 =
> queries)
> the table doesn't reflect a committed update immediately.  Usually when =
> this
> problem occurs the update takes 1-3 minutes to be reflected in SELECT
> queries.  Occasionally, it has taken more than 10 minutes.

> The session could go something like this:

> UPDATE mytable SET myattribute=3D1 WHERE id=3D14;
> COMMIT;
> SELECT myattribute FROM mytable WHERE id=3D14;

> (Query returns myattribute with a value of 0)

> (Wait 5 minutes)
> SELECT myattribute FROM mytable WHERE id=3D14;

> (Query returns myattribute with a value of 1)

To be blunt, I don't believe it.  I can think of bugs by which a commit
might be lost entirely, but there is no mechanism that would make it
good five minutes later.  I think you've misdiagnosed your problem
somehow --- either you're not really committing where you think you are,
or the observing query is using an old snapshot (maybe you are running
it in a serializable transaction?)

A somewhat more credible theory would revolve around corrupted indexes.
If there's a corrupted index on "id" in the above example, a query might
sometimes find one version of a row and sometimes find another; although
any given search would be deterministic, apparently-unrelated changes in
the index contents could change which one is found.

Have you actually been able to reproduce a problem as sketched above in
a single session --- ie, the update and the contradictory observations
all done by the same backend?  Or is this a representation of things
that are happening in different sessions?  What else is going on
meanwhile?

            regards, tom lane

"Erik Peterson" <epeterson@cardiomems.com> writes:
> I'm having this issue where once or twice per day (out of ~100,000 =
> queries)
> the table doesn't reflect a committed update immediately.  Usually when =
> this
> problem occurs the update takes 1-3 minutes to be reflected in SELECT
> queries.  Occasionally, it has taken more than 10 minutes.

> The session could go something like this:

> UPDATE mytable SET myattribute=1 WHERE id=14;
> COMMIT;
> SELECT myattribute FROM mytable WHERE id=14;

> (Query returns myattribute with a value of 0)

> (Wait 5 minutes)
> SELECT myattribute FROM mytable WHERE id=14;

> (Query returns myattribute with a value of 1)

To be blunt, I don't believe it.  I can think of bugs by which a commit
might be lost entirely, but there is no mechanism that would make it
good five minutes later.  I think you've misdiagnosed your problem
somehow --- either you're not really committing where you think you are,
or the observing query is using an old snapshot (maybe you are running
it in a serializable transaction?)

A somewhat more credible theory would revolve around corrupted indexes.
If there's a corrupted index on "id" in the above example, a query might
sometimes find one version of a row and sometimes find another; although
any given search would be deterministic, apparently-unrelated changes in
the index contents could change which one is found.

Have you actually been able to reproduce a problem as sketched above in
a single session --- ie, the update and the contradictory observations
all done by the same backend?  Or is this a representation of things
that are happening in different sessions?  What else is going on
meanwhile?

                        regards, tom lane

"Erik Peterson" <epeterson@cardiomems.com> writes:

> This happens in the same session.  I have an application that had been
> encountering this issue periodically, and I have rigged it to send me an
> email whenever it happens.  I¹ll get that email, fire up my client, and try
> to update the row manually.  Right after my update (autocommit is on, but it
> makes no difference if I do a manual commit), I¹ll issue a select statement
> on the same row, and it returns with the value from before the update.  I¹ll
> keep watching that row, and eventually it will show the right value in that
> column.  Once again, looking at the query logs, there are no conflicting
> updates happening.

You'll have to describe in much more detail what you're doing. Send the actual
session from your terminal of this happening, for example.


--
  Gregory Stark
  EnterpriseDB          http://www.enterprisedb.com

Erik Peterson <epeterson@cardiomems.com> writes:
> I=B9m not sure the corrupted index issue is it.  After updating, the attribut=
> e
> shows up as the =B3old=B2 value with selects on different columns, ie:

> UPDATE mytable SET myattribute=3D1 WHERE id=3D14;
> COMMIT;
> SELECT * from mytable WHERE myattribute=3D0

> Would include the that row (id=3D14).  So it isn=B9t just a single corrupted
> index, if that is indeed the issue.

Hm.  I still think there's something going on in your application that
you're missing.  While you are "watching" the row to see it update,
would you select the system columns ctid,xmin,xmax as well as the data?
That might provide some clue what's really happening.

            regards, tom lane

"Erik Peterson" <epeterson@cardiomems.com> writes:
> I'm having this issue where once or twice per day (out of ~100,000 =
> queries)
> the table doesn't reflect a committed update immediately.  Usually when =
> this
> problem occurs the update takes 1-3 minutes to be reflected in SELECT
> queries.  Occasionally, it has taken more than 10 minutes.

> The session could go something like this:

> UPDATE mytable SET myattribute=1 WHERE id=14;
> COMMIT;
> SELECT myattribute FROM mytable WHERE id=14;

> (Query returns myattribute with a value of 0)

> (Wait 5 minutes)
> SELECT myattribute FROM mytable WHERE id=14;

> (Query returns myattribute with a value of 1)

To be blunt, I don't believe it.  I can think of bugs by which a commit
might be lost entirely, but there is no mechanism that would make it
good five minutes later.  I think you've misdiagnosed your problem
somehow --- either you're not really committing where you think you are,
or the observing query is using an old snapshot (maybe you are running
it in a serializable transaction?)

A somewhat more credible theory would revolve around corrupted indexes.
If there's a corrupted index on "id" in the above example, a query might
sometimes find one version of a row and sometimes find another; although
any given search would be deterministic, apparently-unrelated changes in
the index contents could change which one is found.

Have you actually been able to reproduce a problem as sketched above in
a single session --- ie, the update and the contradictory observations
all done by the same backend?  Or is this a representation of things
that are happening in different sessions?  What else is going on
meanwhile?

                        regards, tom lane