Обсуждение: How to trace client sql requests?

I have a situation with a Rails project where test data in
mysteriously "disappearing" in the middle of a test run.  I would
like to see the exact SQL of all client requests issued against a
single table during a fixed time span.

How can I best accomplish this in PostgreSQL?

#client_min_messages = notice
#log_min_messages = notice
#log_min_duration_statement = -1
...
#log_duration = off

Which of these, if any, should I alter; and to what?  Am I
constrained to system wide logging or can this be enabled by
database?

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

On Fri, Jul 10, 2009 at 01:38:57PM -0400, James B. Byrne wrote:
> I have a situation with a Rails project where test data in
> mysteriously "disappearing" in the middle of a test run.  I would
> like to see the exact SQL of all client requests issued against a
> single table during a fixed time span.
> How can I best accomplish this in PostgreSQL?
> #client_min_messages = notice
> #log_min_messages = notice
> #log_min_duration_statement = -1
> ...
> #log_duration = off
>
> Which of these, if any, should I alter; and to what?  Am I

I prefer to set log_min_duration_statement to 0. It will log all queries
and their running time.

> constrained to system wide logging or can this be enabled by
> database?

You can enable by database:

alter database x set log_min_duration_statement = 0;

Best regards,

depesz

--
Linkedin: http://www.linkedin.com/in/depesz  /  blog: http://www.depesz.com/
jid/gtalk: depesz@depesz.com / aim:depeszhdl / skype:depesz_hdl / gg:6749007

On Fri, July 10, 2009 14:58, hubert depesz lubaczewski wrote:
> You can enable by database:
>
> alter database x set log_min_duration_statement = 0;


Many, many thanks.  Now of course I need more help...

The situation is that data inserted into the DB is not being found
on a subsequent select and I am unaware of any deletes being done.
So, I am hoping to find where the data is going or why the select is
not working.

This is the critical insert:

...
2009-07-10 15:13:00 EDT hll_theheart_test 216.185.71.24(57637)
hll_theheart_db_admin : LOCATION:  exec_simple_query,
postgres.c:1105

2009-07-10 15:13:00 EDT hll_theheart_test 216.185.71.24(57637)
hll_theheart_db_admin : LOG:  00000: duration: 1.366 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', 1.0, 1.0, '1858-01-01 04:56:02.000000', E'Canadian
Dollar', NULL, '2009-07-10 19:13:00', E'CAD', '2009-07-10
19:13:00.151885')

2009-07-10 15:13:00 EDT hll_theheart_test 216.185.71.24(57637)
hll_theheart_db_admin : LOCATION:  exec_simple_query,
postgres.c:1105

2009-07-10 15:13:00 EDT hll_theheart_test 216.185.71.24(57637)
hll_theheart_db_admin : LOG:  00000: duration: 0.379 ms  statement:
SELECT currval('currencies_id_seq')

2009-07-10 15:13:00 EDT hll_theheart_test 216.185.71.24(57637)
hll_theheart_db_admin : LOCATION:  exec_simple_query,
postgres.c:1105

2009-07-10 15:13:00 EDT hll_theheart_test 216.185.71.24(57637)
hll_theheart_db_admin : LOG:  00000: duration: 0.073 ms  statement:
RELEASE SAVEPOINT active_record_1
...

This seems to have worked.  Would the log show if it did not?

The I see a bunch of these:

2009-07-10 15:13:02 EDT hll_theheart_test 216.185.71.24(57638)
hll_theheart_db_admin : LOG:  00000: duration: 0.082 ms  statement:
SET client_min_messages TO 'notice'

2009-07-10 15:13:02 EDT hll_theheart_test 216.185.71.24(57638)
hll_theheart_db_admin : LOCATION:  exec_simple_query,
postgres.c:1105

2009-07-10 15:13:02 EDT hll_theheart_test 216.185.71.24(57638)
hll_theheart_db_admin : LOG:  00000: duration: 6.155 ms  statement:
           SELECT a.attname, format_type(a.atttypid, a.atttypmod),
d.adsrc, a.attnotnull

2009-07-10 15:13:02 EDT hll_theheart_test 216.185.71.24(57638)
hll_theheart_db_admin : LOCATION:  exec_simple_query,
postgres.c:1105

2009-07-10 15:13:02 EDT hll_theheart_test 216.185.71.24(57638)
hll_theheart_db_admin : LOG:  00000: duration: 1.285 ms  statement:
           SELECT a.attname, format_type(a.atttypid, a.atttypmod),
d.adsrc, a.attnotnull

and finally, I get a long list of these:

2009-07-10 15:13:02 EDT hll_theheart_test 216.185.71.24(57638)
hll_theheart_db_admin : LOG:  00000: duration: 1.779 ms  statement:
SELECT * FROM "currencies" WHERE ("currencies"."currency_code" =
E'CAD')  LIMIT 1
...

I believe that this is what I want to examine.  Is there a server
side technique that I can use which will tell me what data this
statement returned or if it found nothing?

In any case, I see the INSERTS and I can find NO DELETES at all.  Is
there any other way to remove some or all data from a table?


--
***          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 03:45:35PM -0400, James B. Byrne wrote:
> I believe that this is what I want to examine.  Is there a server
> side technique that I can use which will tell me what data this
> statement returned or if it found nothing?

not really, sorry.

> In any case, I see the INSERTS and I can find NO DELETES at all.  Is
> there any other way to remove some or all data from a table?

truncate. but first simple question - did you commit the inserts?

Best regards,

depesz

--
Linkedin: http://www.linkedin.com/in/depesz  /  blog: http://www.depesz.com/
jid/gtalk: depesz@depesz.com / aim:depeszhdl / skype:depesz_hdl / gg:6749007

On Jul 10, 2009, at 7:38 PM, James B. Byrne wrote:

> I have a situation with a Rails project where test data in
> mysteriously "disappearing" in the middle of a test run.  I would
> like to see the exact SQL of all client requests issued against a
> single table during a fixed time span.


Are you sure you're looking at that data from the same connection, or
if not, that the inserts get committed? I've seen data "disappear" if
people forgot they were in a transaction block and didn't commit at
the end.

Alban Hertroys

--
If you can't see the forest for the trees,
cut the trees and you'll see there is no forest.


!DSPAM:737,4a58614910131561119940!