BR/

In response to "James B. Byrne" <byrnejb@harte-lyne.ca>:

This is a portion of the log for the most recent run that exhibits
the problem:

...
2009-07-10 15:59:17 EDT hll_theheart_test 216.185.71.24(49133)
hll_theheart_db_admin : LOG: 00000: duration: 0.446 ms statement:
INSERT INTO "currencies" ("is_invoicable", "is_payable",
"changed_by", "created_by", "premium_factor", "discount_factor",
"effective_from", "currency_name", "superseded_after", "changed_at",
"currency_code", "created_at") VALUES('f', 'f', E'not available',
E'not available', 0.9, 1.1, '1785-07-06 04:56:02.000000', E'United
States Dollar', NULL, '2009-07-10 19:59:17', E'USD', '2009-07-10
19:59:17.634473')

That seems a valid insert.

2009-07-10 15:59:17 EDT hll_theheart_test 216.185.71.24(49133)
hll_theheart_db_admin : LOCATION: exec_simple_query,
postgres.c:1105
2009-07-10 15:59:17 EDT hll_theheart_test 216.185.71.24(49133)
hll_theheart_db_admin : LOG: 00000: duration: 0.172 ms statement:
SELECT currval('currencies_id_seq')
2009-07-10 15:59:17 EDT hll_theheart_test 216.185.71.24(49133)
hll_theheart_db_admin : LOCATION: exec_simple_query,
postgres.c:1105
2009-07-10 15:59:17 EDT hll_theheart_test 216.185.71.24(49133)
hll_theheart_db_admin : LOG: 00000: duration: 0.067 ms statement:
RELEASE SAVEPOINT active_record_1

This seems ok but the absence of proof does not ensure the absence
of error. If the insert failed would I see this fact reflected in a
log entry?

Unless you have some really bizarre config in your postgresql.conf,
then a failure of that insert would result in a logged error message.

Why not just intentionally try an invalid insert statement to be
sure that it logs.

2009-07-10 15:59:17 EDT hll_theheart_test 216.185.71.24(49133)
hll_theheart_db_admin : LOCATION: exec_simple_query,
postgres.c:1105
2009-07-10 15:59:17 EDT hll_theheart_test 216.185.71.24(49133)
hll_theheart_db_admin : LOG: 00000: duration: 0.782 ms statement:
SELECT * FROM "currencies"

The client program that receives this result reports that there are
no rows returned. So where did they go"?

What happens between the INSERT and the SELECT? Are there DELETE,
TRUNCATE, or ROLLBACK statements?

Also, look for a BEGIN statement that is never COMMITed. If the client
starts a transaction, INSERTs a bunch of stuff, then disconnects without
issuing a COMMIT, Postgres will rollback the transaction, thus it will
be as if the data was never inserted.

HTH.

--
Bill Moran
http://www.potentialtech.com
http://people.collaborativefusion.com/~wmoran/

On Fri, July 10, 2009 16:20, Bill Moran wrote:

Also, look for a BEGIN statement that is never COMMITed. If
the client starts a transaction, INSERTs a bunch of stuff, then
disconnects without issuing a COMMIT, Postgres will rollback
the transaction, thus it will be as if the data was never
inserted.

There is one ROLLBACK statement, but it occurs after all of the
problems have evidenced themselves and not before. I believe this to
be the Rails test harness unrolling the transaction that it wraps
all test runs in. There is one BEGIN. This is located close to the
very top of the run log, which seems congruent with the one ROLLBACK
just before the very end.

Evidently, all this test processing takes place within a single,
never completed, transaction.

--
*** E-Mail is NOT a SECURE channel ***
James B. Byrne mailto:ByrneJB@Harte-Lyne.ca
Harte & Lyne Limited http://www.harte-lyne.ca
9 Brockley Drive vox: +1 905 561 1241
Hamilton, Ontario fax: +1 905 561 0757
Canada L8E 3C3

James B. Byrne wrote:

2009-07-10 15:59:17 EDT hll_theheart_test 216.185.71.24(49133)
hll_theheart_db_admin : LOG: 00000: duration: 0.782 ms statement:
SELECT * FROM "currencies"

The client program that receives this result reports that there are
no rows returned. So where did they go"?

Is it using a different PG connection than the one doing the insert? In
that case, it won't see the new row until the inserting transaction
commits.

BTW it seems necessary to clarify that LOCATION lines correspond to the
LOG/NOTICE/WARNING/ERROR line immediately _above_ it, not the one below.
So if you see this:

LOG: foo bar
LOCATION: somewhere line N
ERROR: baz qux
LOCATION: another line

you know what to make of it, and it's not this:

LOCATION: somewhere line N
ERROR: baz qux

--
Alvaro Herrera http://www.CommandPrompt.com/
The PostgreSQL Company - Command Prompt, Inc.

On Fri, Jul 10, 2009 at 2:13 PM, James B. Byrne<byrnejb@harte-lyne.ca> wrote:

2009-07-10 15:59:17 EDT hll_theheart_test 216.185.71.24(49133)
hll_theheart_db_admin : LOCATION:  exec_simple_query,
postgres.c:1105
2009-07-10 15:59:17 EDT hll_theheart_test 216.185.71.24(49133)
hll_theheart_db_admin : LOG:  00000: duration: 0.782 ms  statement:
SELECT * FROM "currencies"

The client program that receives this result reports that there are
no rows returned. So where did they go"?

Maybe there were no rows to return??

On Fri, July 10, 2009 18:48, Scott Marlowe wrote:

On Fri, Jul 10, 2009 at 2:13 PM, James B.
Byrne<byrnejb@harte-lyne.ca> wrote:

2009-07-10 15:59:17 EDT hll_theheart_test 216.185.71.24(49133)
hll_theheart_db_admin : LOCATION:  exec_simple_query,
postgres.c:1105
2009-07-10 15:59:17 EDT hll_theheart_test 216.185.71.24(49133)
hll_theheart_db_admin : LOG:  00000: duration: 0.782 ms
 statement:
SELECT * FROM "currencies"

The client program that receives this result reports that there
are
no rows returned. So where did they go"?

Maybe there were no rows to return??

Clearly there are no rows. That is the problem. The question
begging an answer is: where are the rows added in the immediately
previous INSERTS?

--
*** E-Mail is NOT a SECURE channel ***
James B. Byrne mailto:ByrneJB@Harte-Lyne.ca
Harte & Lyne Limited http://www.harte-lyne.ca
9 Brockley Drive vox: +1 905 561 1241
Hamilton, Ontario fax: +1 905 561 0757
Canada L8E 3C3

On Fri, Jul 10, 2009 at 4:53 PM, James B. Byrne<byrnejb@harte-lyne.ca> wrote:

On Fri, July 10, 2009 18:48, Scott Marlowe wrote:

On Fri, Jul 10, 2009 at 2:13 PM, James B.
Byrne<byrnejb@harte-lyne.ca> wrote:

2009-07-10 15:59:17 EDT hll_theheart_test 216.185.71.24(49133)
hll_theheart_db_admin : LOCATION:  exec_simple_query,
postgres.c:1105
2009-07-10 15:59:17 EDT hll_theheart_test 216.185.71.24(49133)
hll_theheart_db_admin : LOG:  00000: duration: 0.782 ms
 statement:
SELECT * FROM "currencies"

The client program that receives this result reports that there
are
no rows returned. So where did they go"?

Maybe there were no rows to return??

Clearly there are no rows.  That is the problem. The question
begging an answer is: where are the rows added in the immediately
previous INSERTS?

Trigger or rule put them somewhere else or ignored them? Hard to say without

\d currencies

On Fri, July 10, 2009 18:13, Alvaro Herrera wrote:

Is it using a different PG connection than the one doing the
insert? In that case, it won't see the new row until the
inserting transaction commits.

That is almost certainly the exact problem. I will check and
determine if this is so but I it seems to me unavoidable that
launching a new shell for the script under test will cause another,
different, connection to be used. If this proves the case then I
will report back. If not then no doubt you will hear from me as
well.

Thank you for illuminating this for me.

BTW it seems necessary to clarify that LOCATION lines correspond
to the LOG/NOTICE/WARNING/ERROR line immediately _above_ it, not
the one below.

So noted, with thanks.

Regards,

--
*** E-Mail is NOT a SECURE channel ***
James B. Byrne mailto:ByrneJB@Harte-Lyne.ca
Harte & Lyne Limited http://www.harte-lyne.ca
9 Brockley Drive vox: +1 905 561 1241
Hamilton, Ontario fax: +1 905 561 0757
Canada L8E 3C3