Thread: BR/
I am sorry for this but I do not know how else to communicate what
is apparently happening:
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?
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"?
--
*** 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
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