Re: Review: DTrace probes (merged version) ver_03

I performed review of merged patch from Robert Treat. At first point the patch
does not work (SunOS 5.11 snv_86 sun4u sparc SUNW,Sun-Fire-V240)

truncate ... ok
alter_table ... FAILED (test process exited with exit code 2)
sequence ... ok
polymorphism ... ok
rowtypes ... ok
returning ... ok
largeobject ... FAILED (test process exited with exit code 2)
xml ... ok
test stats ... FAILED (test process exited with exit code 2)
test tablespace ... FAILED (test process exited with exit code 2)

However I went through a code and I have following comments:

1) Naming convention:

- Some probes uses "*end", some "*done". It would be good to select one name.
- I prefer to use clog instead of slru in probes name. clog is widely known.
- It seems to me better to have checkpoint-clog..., checkpoint-subtrans
instead of clog-checkpoint.
- buffer-flush was originally dirty-buffer-write-start. I prefer Robert Lor's
naming.

2) storage read write probes

smgr-read*, smgr-writes probes are in md.c. I personally think it make more
sense to put them into smgr.c. Only advantage to have it in md.c is that actual
amount of bytes is possible to monitor.

3) query rewrite probe

There are several probes for query measurement but query rewrite phase is
missing. See analyze_and_rewrite or pg_parse_and_rewrite

4) autovacuum_start

Autovacuum_start probe is alone. I propose following probes for completeness:

proc-autovacuum-start
proc-autovacuum-stop
proc-bgwriter-start
proc-bgwriter-stop
proc-backend-start
proc-backend-stop
proc-master-start
proc-master-stop

5) Need explain of usage:

I have some doubts about following probes. Could you please explain usage of
them? example dtrace script is welcome

- all exec-* probes
- mark-dirty, local-mark-dirty

6) several comments about placement:

I published patch on http://reviewdemo.postgresql.org/r/25/. I added several
comments there.

7) SLRU/CLOG

SLRU probes could be return more info. For example if page was in buffer or if
physical write is not necessary and so on.

That's all for this moment

Zdenek
--
Zdenek Kotala Sun Microsystems
Prague, Czech Republic http://sun.com/postgresql

Zdenek Kotala wrote:

> 1) Naming convention:
>
> - Some probes uses "*end", some "*done". It would be good to select one name.
> - I prefer to use clog instead of slru in probes name. clog is widely known.

But slru is also used in pg_subtrans and pg_multixact. Which maybe
says that we oughta have separate probes for these rather than a single
one in slru. Otherwise it's going to be difficult telling one from the
other, yes?

> Autovacuum_start probe is alone. I propose following probes for completeness:
>
> proc-autovacuum-start
> proc-autovacuum-stop
> proc-bgwriter-start
> proc-bgwriter-stop

Separate proc-autovacuum-worker-start and proc-autovacuum-launcher-start,
perhaps. Not that I see any usefulness in tracking autovacuum launcher
start and stop, but then if we're tracking bgwriter start and stop then
it makes the same sense.

> proc-master-start
> proc-master-stop

What's "master" here?

--
Alvaro Herrera http://www.CommandPrompt.com/
PostgreSQL Replication, Consulting, Custom Development, 24x7 support

Alvaro Herrera <alvherre(at)commandprompt(dot)com> writes:
>> Autovacuum_start probe is alone. I propose following probes for completeness:
>>
>> proc-autovacuum-start
>> proc-autovacuum-stop
>> proc-bgwriter-start
>> proc-bgwriter-stop

> Separate proc-autovacuum-worker-start and proc-autovacuum-launcher-start,
> perhaps. Not that I see any usefulness in tracking autovacuum launcher
> start and stop, but then if we're tracking bgwriter start and stop then
> it makes the same sense.

I see no value in cluttering the system with useless probes. The worker
start/stop are the only ones here with any conceivable application IMHO.

regards, tom lane

Alvaro Herrera napsal(a):
> Zdenek Kotala wrote:
>
>> 1) Naming convention:
>>
>> - Some probes uses "*end", some "*done". It would be good to select one name.
>> - I prefer to use clog instead of slru in probes name. clog is widely known.
>
> But slru is also used in pg_subtrans and pg_multixact. Which maybe
> says that we oughta have separate probes for these rather than a single
> one in slru. Otherwise it's going to be difficult telling one from the
> other, yes?

Yeah, you are right, I missed that it is used in other part too. slru is OK

>
>> Autovacuum_start probe is alone. I propose following probes for completeness:
>>
>> proc-autovacuum-start
>> proc-autovacuum-stop
>> proc-bgwriter-start
>> proc-bgwriter-stop
>
> Separate proc-autovacuum-worker-start and proc-autovacuum-launcher-start,
> perhaps. Not that I see any usefulness in tracking autovacuum launcher
> start and stop, but then if we're tracking bgwriter start and stop then
> it makes the same sense.

The advantage to track start and stop of procese is that you can stop the
process in dtrace script at the beginning and for example attach debugger or for
example start counting number of writes per process and so on.

>> proc-master-start
>> proc-master-stop
>
> What's "master" here?

Main process - postmaster.

Zdenek

--
Zdenek Kotala Sun Microsystems
Prague, Czech Republic http://sun.com/postgresql

Tom Lane napsal(a):
> Alvaro Herrera <alvherre(at)commandprompt(dot)com> writes:
>>> Autovacuum_start probe is alone. I propose following probes for completeness:
>>>
>>> proc-autovacuum-start
>>> proc-autovacuum-stop
>>> proc-bgwriter-start
>>> proc-bgwriter-stop
>
>> Separate proc-autovacuum-worker-start and proc-autovacuum-launcher-start,
>> perhaps. Not that I see any usefulness in tracking autovacuum launcher
>> start and stop, but then if we're tracking bgwriter start and stop then
>> it makes the same sense.
>
> I see no value in cluttering the system with useless probes. The worker
> start/stop are the only ones here with any conceivable application IMHO.

As I answered to Alvaro. I needed to catch start of backend several times to
track call flow or attach debugger. It is possible to use some other dtrace
magic for that, but it is not easy and there is not way how to determine what
kind of process it is. For example how to measure how many writes performs
bgwriter?

Zdenek

--
Zdenek Kotala Sun Microsystems
Prague, Czech Republic http://sun.com/postgresql

Zdenek Kotala wrote:
> Alvaro Herrera napsal(a):

>>> proc-master-start
>>> proc-master-stop
>>
>> What's "master" here?
>
> Main process - postmaster.

Huh, surely we're not interested in tracking postmaster start?

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

Zdenek Kotala wrote:
> Tom Lane napsal(a):

>> I see no value in cluttering the system with useless probes. The worker
>> start/stop are the only ones here with any conceivable application IMHO.
>
> As I answered to Alvaro. I needed to catch start of backend several times
> to track call flow or attach debugger. It is possible to use some other
> dtrace magic for that, but it is not easy and there is not way how to
> determine what kind of process it is. For example how to measure how
> many writes performs bgwriter?

If you need to attach a debugger to a backend, you can use the -W switch
(even on PGOPTIONS if you need it for a particular backend, AFAIR). If
you want to "truss" it I guess you can use -W too.

Does it have any usefulness beyond that?

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

Alvaro Herrera napsal(a):
> Zdenek Kotala wrote:
>> Alvaro Herrera napsal(a):
>
>>>> proc-master-start
>>>> proc-master-stop
>>> What's "master" here?
>> Main process - postmaster.
>
> Huh, surely we're not interested in tracking postmaster start?
>

It depends. See following schema example

postgres::proc-master-start
{
tracking = 1
}

syscall:::open:entry
/ tracking == 1/
{
... print file name ...
}

postgres::proc-master-stop
{
tracking = 0
}

It is very useful because it say when you can start and stop monitoring for
example. But I'm not DTrace expert maybe there is different way how to do it.

Zdenek

--
Zdenek Kotala Sun Microsystems
Prague, Czech Republic http://sun.com/postgresql

Alvaro Herrera napsal(a):
> Zdenek Kotala wrote:
>> Tom Lane napsal(a):
>
>>> I see no value in cluttering the system with useless probes. The worker
>>> start/stop are the only ones here with any conceivable application IMHO.
>> As I answered to Alvaro. I needed to catch start of backend several times
>> to track call flow or attach debugger. It is possible to use some other
>> dtrace magic for that, but it is not easy and there is not way how to
>> determine what kind of process it is. For example how to measure how
>> many writes performs bgwriter?
>
> If you need to attach a debugger to a backend, you can use the -W switch
> (even on PGOPTIONS if you need it for a particular backend, AFAIR). If
> you want to "truss" it I guess you can use -W too.
>
> Does it have any usefulness beyond that?
>

Why use million of tools when you can use one? And truss monitors only syscalls
but with dtrace you are able to use/trace over 80000 probes in the kernel, libc
and so on. I agree that for debugger you can use -W option but in situation when
you are not able to use this switch (e.g on customer production machine) dtrace
is only possible solution. That is why I think that this probes are useful.

Zdenek

--
Zdenek Kotala Sun Microsystems
Prague, Czech Republic http://sun.com/postgresql

Apologies for the delayed response - vacation, travel, etc got in the way!

Zdenek Kotala wrote:
> I performed review of merged patch from Robert Treat. At first point
> the patch does not work (SunOS 5.11 snv_86 sun4u sparc
> SUNW,Sun-Fire-V240)

The attached patch fixed the regression test errors.
>
>
> However I went through a code and I have following comments:
>
> 1) Naming convention:
>
> - Some probes uses "*end", some "*done". It would be good to select
> one name.
Noted. Will use <name>-done per the convention. This change will be
included in an updated patch later since I think there are a number of
other changes that need to be made.
> - I prefer to use clog instead of slru in probes name. clog is widely
> known.
I think slru- is okay per your subsequent emails.
> - It seems to me better to have checkpoint-clog...,
> checkpoint-subtrans instead of clog-checkpoint.
Yes, I was thinking about this too, but the current names are more
consistent with the others. For example:

buffer-checkpoint, buffer-*
xlog-checkpoint, xlog-*
> - buffer-flush was originally dirty-buffer-write-start. I prefer
> Robert Lor's naming.
Actually, I made this change so the name is consistent with the other
buffer-* probes.
>
> 2) storage read write probes
>
> smgr-read*, smgr-writes probes are in md.c. I personally think it make
> more sense to put them into smgr.c. Only advantage to have it in md.c
> is that actual amount of bytes is possible to monitor.
The current probes return number of bytes, that's why they are in md.c
>
> 3) query rewrite probe
>
> There are several probes for query measurement but query rewrite phase
> is missing. See analyze_and_rewrite or pg_parse_and_rewrite
I believe the rewrite time is accounted for in the query-plan probe.
Need to double check on this.
>
> 4) autovacuum_start
>
> Autovacuum_start probe is alone. I propose following probes for
> completeness:
>
> proc-autovacuum-start
> proc-autovacuum-stop
> proc-bgwriter-start
> proc-bgwriter-stop
> proc-backend-start
> proc-backend-stop
> proc-master-start
> proc-master-stop
Saw a number of emails on this. Will get back on this.
>
> 5) Need explain of usage:
>
> I have some doubts about following probes. Could you please explain
> usage of them? example dtrace script is welcome
>
> - all exec-* probes
> - mark-dirty, local-mark-dirty
>
Theo/Robert, do you guys have any sample scripts on the probes you added.
>
> 6) several comments about placement:
>
> I published patch on http://reviewdemo.postgresql.org/r/25/. I added
> several comments there.
>
> 7) SLRU/CLOG
>
> SLRU probes could be return more info. For example if page was in
> buffer or if physical write is not necessary and so on.
Yes, more info could be returned if we can identify specific use cases
that the new data will enable.

--
Robert Lor Sun Microsystems
Austin, USA http://sun.com/postgresql

This patch looked OK to me, but the commit fest comment says that it does not
include comments from the reviewdemo.postgresql.org. But I don't find any
comments there. The latest version of the patch there appears to be the same
as here. Zdenek, could you clarify?

Peter Eisentraut napsal(a):
> This patch looked OK to me, but the commit fest comment says that it does not
> include comments from the reviewdemo.postgresql.org. But I don't find any
> comments there. The latest version of the patch there appears to be the same
> as here. Zdenek, could you clarify?

I'm sorry. I forgot to publish them :( (new tool). It is fixed now. I also
upload latest patch version and I will review it tomorrow.

Zdenek

--
Zdenek Kotala Sun Microsystems
Prague, Czech Republic http://sun.com/postgresql

I performed review and I prepared own patch which contains only probes without
any issue. I suggest commit this patch because the rest of patch is independent
and it can be committed next commit fest after rework.

I found following issues:

1) SLRU probes.

I think it is good to have probes there but they needs polish. See my comments
http://reviewdemo.postgresql.org/r/25/

2) XLOG probes

I think there is confuse placement of probes after merge. It needs cleanup.

3) Executor probes

I would like to see any use case for them/

4) smgr probes

I prefer to have this probes in smgr instead of md. The reason why Robert put
them into md is that it returns number of written/read bytes, but it is "always"
BLCKSZ which could be returned from smgr directly. Only difference is
when error occurs during write/read and not all data are written/read.

It needs discuss.

5) autovacuum start probes

I would like to see also stat/stop for any other process types. It was discussed
but no comment from author(s).

6) idle transaction

See my comments
http://reviewdemo.postgresql.org/r/25/

7) query-reewrite is missing

8) mark dirty and BM_HINT... flag

I remove these because I don't see any use case for it. It would be nice provide
some dtrace script or describe basic ideas.

Thats all Zdenek

On Jul 24, 2008, at 11:11 AM, Zdenek Kotala wrote:

> I performed review and I prepared own patch which contains only
> probes without any issue. I suggest commit this patch because the
> rest of patch is independent and it can be committed next commit
> fest after rework.
>
> I found following issues:
>
> 1) SLRU probes.
>
> I think it is good to have probes there but they needs polish. See
> my comments
> http://reviewdemo.postgresql.org/r/25/

The slru's are quite useful and general enough to use easily. I used
them to verify the metered checkpointing stuff:

http://lethargy.org/~jesus/archives/112-Probing-for-Success.html

> 2) XLOG probes
>
> I think there is confuse placement of probes after merge. It needs
> cleanup.
>
>
> 3) Executor probes
>
> I would like to see any use case for them/

I added them with two thoughts (and knowing that they cost nothing).
(1) you can trace them to assist in debugging an explain plan and to
better understand the flow of the execution engine. This is not a
compelling reason, but a reason none-the-less.
(2) you can trace and existing long-running query for which you do not
have the original plan (may have changed) and make an educated guess
at the plan chosen at time of execution.

> 4) smgr probes
>
> I prefer to have this probes in smgr instead of md. The reason why
> Robert put them into md is that it returns number of written/read
> bytes, but it is "always" BLCKSZ which could be returned from smgr
> directly. Only difference is
> when error occurs during write/read and not all data are written/read.
>
> It needs discuss.
>
> 5) autovacuum start probes
>
> I would like to see also stat/stop for any other process types. It
> was discussed but no comment from author(s).
>
> 6) idle transaction
>
> See my comments
> http://reviewdemo.postgresql.org/r/25/
>
> 7) query-reewrite is missing
>
>
> 8) mark dirty and BM_HINT... flag
>
> I remove these because I don't see any use case for it. It would be
> nice provide some dtrace script or describe basic ideas.

Perhaps I misunderstood what mark dirty does, but here was my thinking:

Because of the background writer, it is difficult to understand which
postgres process (and thus query) induced disk writes. Marking a page
as dirty is a good indication that a query will be causing I/O and you
can measure calls to mark dirty per query as a telling metric.

Perhaps I misunderstood, but I have a very serious problem that I
can't reliably track write I/O to postgresql process ID as the
bgwriter and the kernel are flushing those dirty blocks to disk while
the process isn't running. In my (albeit naive) tests, the mark dirty
gave me quite expected results for correlating query execution to disk
I/O to be induced.

--
Theo Schlossnagle
Esoteric Curio -- http://lethargy.org/
OmniTI Computer Consulting, Inc. -- http://omniti.com/

Theo Schlossnagle napsal(a):
>
> On Jul 24, 2008, at 11:11 AM, Zdenek Kotala wrote:
>
>> I performed review and I prepared own patch which contains only probes
>> without any issue. I suggest commit this patch because the rest of
>> patch is independent and it can be committed next commit fest after
>> rework.
>>
>> I found following issues:
>>
>> 1) SLRU probes.
>>
>> I think it is good to have probes there but they needs polish. See my
>> comments
>> http://reviewdemo.postgresql.org/r/25/
>
> The slru's are quite useful and general enough to use easily. I used
> them to verify the metered checkpointing stuff:
>
> http://lethargy.org/~jesus/archives/112-Probing-for-Success.html

I agree that SLRU probes are useful but I'm worry about implementation. I think
that these probes need more work before commit. Currently there are several bugs
in placement and arguments (from my point of view).

>> 3) Executor probes
>>
>> I would like to see any use case for them/
>
> I added them with two thoughts (and knowing that they cost nothing).
> (1) you can trace them to assist in debugging an explain plan and to
> better understand the flow of the execution engine. This is not a
> compelling reason, but a reason none-the-less.
> (2) you can trace and existing long-running query for which you do not
> have the original plan (may have changed) and make an educated guess at
> the plan chosen at time of execution.

I'm not executor expert and (1) is useful for me :-). What I'm thinking about is
if we can mine more information from executor like number of tuples processed by
node number and so on. I think that it needs discussion.

>> 8) mark dirty and BM_HINT... flag
>>
>> I remove these because I don't see any use case for it. It would be
>> nice provide some dtrace script or describe basic ideas.
>
>
> Perhaps I misunderstood what mark dirty does, but here was my thinking:
>
> Because of the background writer, it is difficult to understand which
> postgres process (and thus query) induced disk writes. Marking a page
> as dirty is a good indication that a query will be causing I/O and you
> can measure calls to mark dirty per query as a telling metric.
>
> Perhaps I misunderstood, but I have a very serious problem that I can't
> reliably track write I/O to postgresql process ID as the bgwriter and
> the kernel are flushing those dirty blocks to disk while the process
> isn't running. In my (albeit naive) tests, the mark dirty gave me quite
> expected results for correlating query execution to disk I/O to be induced.
>

If I understand correctly you need to analyze number of writes per
query/session. It seems to me, that to use mark dirty is good way, but it
probably needs more probes. (Robert L. any idea?)

However what I suggested is commit probes without issue now and the rest will be
processed on the next commit fest after rework/discussion.

Zdenek

--
Zdenek Kotala Sun Microsystems
Prague, Czech Republic http://sun.com/postgresql

Zdenek Kotala wrote:
> I performed review and I prepared own patch which contains only probes
> without any issue. I suggest commit this patch because the rest of patch
> is independent and it can be committed next commit fest after rework.
>
> I found following issues:

I noticed that CLOG, Subtrans and Multixact probes are added during a
regular Checkpoint, but not during a shutdown flush. I think the probes
should count that too (probably with the same counter).

In the pgstat_report_activity probe, is it good to call the probe before
taking the fast path out?

In the BUFFER_READ_START probe, we do not include the smgrnblocks()
call, which could be significant since it includes a number of system
calls.

I think BUFFER_HIT and BUFFER_MISS should include the "isLocalBuf" flag.
I also wonder whether BUFFER_HIT should be called in the block above,
lines 220-238, where we check the "found" flag, i.e.

if (isLocalBuf)
{
ReadLocalBufferCount++;
bufHdr = LocalBufferAlloc(smgr, blockNum, &found);
if (found)
{
LocalBufferHitCount++;
TRACE_POSTGRESQL_BUFFER_HIT(true); /* local buffer */
}
else
{
TRACE_POSTGRESQL_BUFFER_MISS(true); /* ditto */
}
}
else
{
ReadBufferCount++;

/*
* lookup the buffer. IO_IN_PROGRESS is set if the requested block is
* not currently in memory.
*/
bufHdr = BufferAlloc(smgr, blockNum, strategy, &found);
if (found)
{
BufferHitCount++;
TRACE_POSTGRESQL_BUFFER_HIT(false); /* not local */
}
else
{
TRACE_POSTGRESQL_BUFFER_MISS(false); /* ditto */
}
}

(note that this changes the semantics w.r.t. the isExtend flag).

I understand the desire to have DEADLOCK_FOUND, but is there really a
point in having a DEADLOCK_NOTFOUND probe? Since this code runs every
time someone waits for a lock longer than a second, there would be a lot
of useless counts and nothing useful.

I find it bogus that we include query rewriting in QUERY_PARSE_START/DONE.
I think query rewriting should be a separate probe.

QUERY_PLAN_START is badly placed -- it should be after the check for
utility commands (alternatively there could be a QUERY_PLAN_DONE in the
fast way out for utility commands, but in that case a "is utility" flag
would be needed. I don't see that there's any point in tracing planning
of utility commands though).

Why are there no probes for the v3 protocol stuff? There should
be probes for Parse, Bind, Execute message processing too, for
completeness. Also, I wonder if these probes should be in the for(;;)
loop in PostgresMain() instead of sprinkled in the other routines.
I note that the probes in PortalRun and PortalRunMulti are schizophrenic
about whether they include utility functions or not.

--
Alvaro Herrera http://www.CommandPrompt.com/
PostgreSQL Replication, Consulting, Custom Development, 24x7 support

Zdenek Kotala <Zdenek(dot)Kotala(at)Sun(dot)COM> writes:
> I performed review and I prepared own patch which contains only probes
> without any issue. I suggest commit this patch because the rest of
> patch is independent and it can be committed next commit fest after
> rework.

I looked at this patch a little bit. In addition to the comments Alvaro
made, I have a couple more issues:

* The probes that pass buffer tag elements are already broken by the
pending "relation forks" patch: there is soon going to be another field
in buffer tags. Perhaps it'd be feasible to pass the buffer tag as a
single probe argument to make that a bit more future-proof? I'm not
sure if that would complicate the use of the probe so much as to be
counterproductive.

* I find this to be truly bletcherous:

> ! /*
> ! * Due to a bug in Mac OS X 10.5, using defined types (e.g. uintptr_t,
> ! * uint32_t, etc.) cause compilation error.
> ! */
> !
> ! probe transaction__start(unsigned int transactionId);
> ! probe transaction__commit(unsigned int transactionId);
> ! probe transaction__abort(unsigned int transactionId);

especially since some of the manual translations in the file are flat
out wrong (Oid is unsigned for instance). Furthermore the comment is
wrong, at least according to my tests with XCode 3.1. Typedefs seem to
work fine. What doesn't work fine is #include "postgres.h", which would
be the ideal way to suck in TransactionId and other needed typedefs.
You can get dtrace to invoke the C preprocessor, but at least on OS X,
the D compiler spits up anyway on the contents of some of the system
header files that are pulled in by postgres.h.

What I suggest might be a reasonable compromise is to copy needed
typedefs directly into the probes.d file:

typedef unsigned int LocalTransactionId;

provider postgresql {

probe transaction__start(LocalTransactionId);

This at least makes it possible to declare the probes cleanly,
and it's fairly obvious what to fix if the principal definition of
LocalTransactionId ever changes. I don't have Solaris to test on, but
on OS X this seems to behave the way we'd like: the typedef itself isn't
copied into the emitted probes.h file, but the emitted extern
declarations use it.

regards, tom lane

Alvaro Herrera napsal(a):
> Zdenek Kotala wrote:
>> I performed review and I prepared own patch which contains only probes
>> without any issue. I suggest commit this patch because the rest of patch
>> is independent and it can be committed next commit fest after rework.
>>
>> I found following issues:
>
> I noticed that CLOG, Subtrans and Multixact probes are added during a
> regular Checkpoint, but not during a shutdown flush. I think the probes
> should count that too (probably with the same counter).

Yeah, good catch.

> In the pgstat_report_activity probe, is it good to call the probe before
> taking the fast path out?

If you mean to put it behind "if (!pgstat_track_activities || !beentry)" then I
think that current placement is OK. You should be possibility to track it
without dependency on pgstat_track_activities GUC variable. Keep in mind that
DTrace is designed to monitor/trace production system and ability to monitor
something without any configuration change is main idea.

> In the BUFFER_READ_START probe, we do not include the smgrnblocks()
> call, which could be significant since it includes a number of system
> calls.

It is because the BUFFER_READ_START needs to report correct blockno. My
suggestion is to add probes to smgrblock function.

> I think BUFFER_HIT and BUFFER_MISS should include the "isLocalBuf" flag.
> I also wonder whether BUFFER_HIT should be called in the block above,
> lines 220-238, where we check the "found" flag, i.e.
>
> if (isLocalBuf)
> {
> ReadLocalBufferCount++;
> bufHdr = LocalBufferAlloc(smgr, blockNum, &found);
> if (found)
> {
> LocalBufferHitCount++;
> TRACE_POSTGRESQL_BUFFER_HIT(true); /* local buffer */
> }
> else
> {
> TRACE_POSTGRESQL_BUFFER_MISS(true); /* ditto */
> }
> }
> else
> {
> ReadBufferCount++;
>
> /*
> * lookup the buffer. IO_IN_PROGRESS is set if the requested block is
> * not currently in memory.
> */
> bufHdr = BufferAlloc(smgr, blockNum, strategy, &found);
> if (found)
> {
> BufferHitCount++;
> TRACE_POSTGRESQL_BUFFER_HIT(false); /* not local */
> }
> else
> {
> TRACE_POSTGRESQL_BUFFER_MISS(false); /* ditto */
> }
> }
>
> (note that this changes the semantics w.r.t. the isExtend flag).

Good point. The question about isExted is if we want to have exact output
include corner case or be to sync with ReadBufferCount counter. I prefer your
suggested placement.

>
> I understand the desire to have DEADLOCK_FOUND, but is there really a
> point in having a DEADLOCK_NOTFOUND probe? Since this code runs every
> time someone waits for a lock longer than a second, there would be a lot
> of useless counts and nothing useful.

No idea. Robert any comment?

> I find it bogus that we include query rewriting in QUERY_PARSE_START/DONE.
> I think query rewriting should be a separate probe.

agree

> QUERY_PLAN_START is badly placed -- it should be after the check for
> utility commands (alternatively there could be a QUERY_PLAN_DONE in the
> fast way out for utility commands, but in that case a "is utility" flag
> would be needed. I don't see that there's any point in tracing planning
> of utility commands though).

agree

> Why are there no probes for the v3 protocol stuff? There should
> be probes for Parse, Bind, Execute message processing too, for
> completeness. Also, I wonder if these probes should be in the for(;;)
> loop in PostgresMain() instead of sprinkled in the other routines.
> I note that the probes in PortalRun and PortalRunMulti are schizophrenic
> about whether they include utility functions or not.

+1 It is good suggestion. I hope that Robert will put it on his probe todo list.
Same like probes for memory management.

Zdenek

Tom Lane napsal(a):
> Zdenek Kotala <Zdenek(dot)Kotala(at)Sun(dot)COM> writes:
>> I performed review and I prepared own patch which contains only probes
>> without any issue. I suggest commit this patch because the rest of
>> patch is independent and it can be committed next commit fest after
>> rework.
>
> I looked at this patch a little bit. In addition to the comments Alvaro
> made, I have a couple more issues:
>
> * The probes that pass buffer tag elements are already broken by the
> pending "relation forks" patch: there is soon going to be another field
> in buffer tags. Perhaps it'd be feasible to pass the buffer tag as a
> single probe argument to make that a bit more future-proof? I'm not
> sure if that would complicate the use of the probe so much as to be
> counterproductive.

It is difficult to say. If you pass only pointer to a structure you can mine all
data from them but it is little bit complicated. It should be possible to use
typedef and cast pointer to correct structure. However main problem is that you
cannot use easily any indirect data in predicates. It needs extra magic. By my
opinion best approach is use mix of approaches. Important data should be pass
directly as a argument and rest as a pointer to data structure.

> * I find this to be truly bletcherous:

<snip>

> What doesn't work fine is #include "postgres.h", which would
> be the ideal way to suck in TransactionId and other needed typedefs.

Whats about #include "c.h"? Does it work or does it have same issue?

>
> What I suggest might be a reasonable compromise is to copy needed
> typedefs directly into the probes.d file:
>
> typedef unsigned int LocalTransactionId;
>
> provider postgresql {
>
> probe transaction__start(LocalTransactionId);
>
> This at least makes it possible to declare the probes cleanly,
> and it's fairly obvious what to fix if the principal definition of
> LocalTransactionId ever changes. I don't have Solaris to test on, but
> on OS X this seems to behave the way we'd like: the typedef itself isn't
> copied into the emitted probes.h file, but the emitted extern
> declarations use it.

It works on Solaris as well. However, I think that better solution is to put
this typedef to the separate header file. DTrace script allows to use typedef or
include header with typedefs. It would be better to have header file which could
be used for probe.d and for any other DTrace script.

Zdenek

Zdenek Kotala napsal(a):
> Alvaro Herrera napsal(a):
>> Zdenek Kotala wrote:
>>> I performed review and I prepared own patch which contains only
>>> probes without any issue. I suggest commit this patch because the
>>> rest of patch is independent and it can be committed next commit fest
>>> after rework.
>>>
>>> I found following issues:
>>
>> I noticed that CLOG, Subtrans and Multixact probes are added during a
>> regular Checkpoint, but not during a shutdown flush. I think the probes
>> should count that too (probably with the same counter).
>
> Yeah, good catch.

When I'm thinking about it, It seems to me better idea to have

TRACE_POSTGRESQL_CLOG_SHUTDOWN_START();
TRACE_POSTGRESQL_XLOG_SHUTDOWN_START();

Because you will able to determine what was a reason for flush and how log take
shutting down.

By the way why the shutdown order is following:

05617 CreateCheckPoint(CHECKPOINT_IS_SHUTDOWN | CHECKPOINT_IMMEDIATE);
05618 ShutdownCLOG();
05619 ShutdownSUBTRANS();
05620 ShutdownMultiXact();

What does happen when kill -9/power lost comes between lines 5617 and 5618?

Zdenek

Zdenek Kotala <Zdenek(dot)Kotala(at)Sun(dot)COM> writes:
> Whats about #include "c.h"? Does it work or does it have same issue?

Same problem --- postgres.h isn't actually including any of the
problematic files for itself.

>> What I suggest might be a reasonable compromise is to copy needed
>> typedefs directly into the probes.d file:

> It works on Solaris as well. However, I think that better solution is to put
> this typedef to the separate header file.

Not going to work, at least not in the general case, because the
typedefs involved are ultimately dependent on system headers that might
or might not be DTrace-clean. In any case I'm going to resist doing
random restructuring of our core header files for the convenience
of DTrace --- if we take that approach, adding a new probe becomes
a major PITA instead of just a couple more lines of code. You're likely
to find requests for new probes getting rejected because the required
header rearrangements are too ugly; do you want to take that risk?

We could put the typedefs into probes.d as a stopgap measure, hoping
that Apple (and Sun?) will someday fix their headers and/or the D
compiler so that #include'ing postgres.h works properly.

regards, tom lane

Zdenek Kotala wrote:
> However what I suggested is commit probes without issue now and the
> rest will be processed on the next commit fest after rework/discussion.
>
>

Agreed. I'll fix up the remaining issues with the patch you sent.

--
Robert Lor Sun Microsystems
Austin, USA http://sun.com/postgresql

Zdenek Kotala wrote:
> Alvaro Herrera napsal(a):
>> Zdenek Kotala wrote:
>>> I performed review and I prepared own patch which contains only
>>> probes without any issue. I suggest commit this patch because the
>>> rest of patch is independent and it can be committed next commit
>>> fest after rework.
>>>
>>> I found following issues:
>>
>> I noticed that CLOG, Subtrans and Multixact probes are added during a
>> regular Checkpoint, but not during a shutdown flush. I think the probes
>> should count that too (probably with the same counter).
>
> Yeah, good catch.

Ok. I think the names should be the same but pass a true/false argument
to differentiate the call just like how it's used in SimpleLruFlush.

e.g.

TRACE_POSTGRESQL_CLOG_CHECKPOINT_START(false) # shutdown case
TRACE_POSTGRESQL_CLOG_CHECKPOINT_START(true)

>
>> In the pgstat_report_activity probe, is it good to call the probe before
>> taking the fast path out?
>
> If you mean to put it behind "if (!pgstat_track_activities ||
> !beentry)" then I think that current placement is OK. You should be
> possibility to track it without dependency on pgstat_track_activities
> GUC variable. Keep in mind that DTrace is designed to monitor/trace
> production system and ability to monitor something without any
> configuration change is main idea.

This probe just prints out the statement, and it doesn't matter whether
or not track_activities is enabled.

>
>> In the BUFFER_READ_START probe, we do not include the smgrnblocks()
>> call, which could be significant since it includes a number of system
>> calls.
>
> It is because the BUFFER_READ_START needs to report correct blockno.
> My suggestion is to add probes to smgrblock function.

Yes, that's the main reason.

>
>> I think BUFFER_HIT and BUFFER_MISS should include the "isLocalBuf" flag.
>> I also wonder whether BUFFER_HIT should be called in the block above,
>> lines 220-238, where we check the "found" flag, i.e.
>>
>> if (isLocalBuf)
>> {
>> ReadLocalBufferCount++;
>> bufHdr = LocalBufferAlloc(smgr, blockNum, &found);
>> if (found)
>> {
>> LocalBufferHitCount++;
>> TRACE_POSTGRESQL_BUFFER_HIT(true); /* local buffer */
>> }
>> else
>> {
>> TRACE_POSTGRESQL_BUFFER_MISS(true); /* ditto */
>> }
>> }
>> else
>> {
>> ReadBufferCount++;
>>
>> /*
>> * lookup the buffer. IO_IN_PROGRESS is set if the requested
>> block is
>> * not currently in memory.
>> */
>> bufHdr = BufferAlloc(smgr, blockNum, strategy, &found);
>> if (found)
>> {
>> BufferHitCount++;
>> TRACE_POSTGRESQL_BUFFER_HIT(false); /* not local */
>> }
>> else
>> {
>> TRACE_POSTGRESQL_BUFFER_MISS(false); /* ditto */
>> }
>> }
>>
>> (note that this changes the semantics w.r.t. the isExtend flag).
>
> Good point. The question about isExted is if we want to have exact
> output include corner case or be to sync with ReadBufferCount counter.
> I prefer your suggested placement.

Agree.

>
>>
>> I understand the desire to have DEADLOCK_FOUND, but is there really a
>> point in having a DEADLOCK_NOTFOUND probe? Since this code runs every
>> time someone waits for a lock longer than a second, there would be a lot
>> of useless counts and nothing useful.
>
> No idea. Robert any comment?

Yes, you're right. Will delete.

>
>> I find it bogus that we include query rewriting in
>> QUERY_PARSE_START/DONE. I think query rewriting should be a separate
>> probe.
>
> agree

Will fix. I was also thinking about having the probes by modules but
wanted to limit the number of probes, but I'm fine having another one.

>
>> QUERY_PLAN_START is badly placed -- it should be after the check for
>> utility commands (alternatively there could be a QUERY_PLAN_DONE in the
>> fast way out for utility commands, but in that case a "is utility" flag
>> would be needed. I don't see that there's any point in tracing planning
>> of utility commands though).
>
> agree
Ok

>
>> Why are there no probes for the v3 protocol stuff? There should
>> be probes for Parse, Bind, Execute message processing too, for
>> completeness.

Thanks for catching this.

>> Also, I wonder if these probes should be in the for(;;)
>> loop in PostgresMain() instead of sprinkled in the other routines.
>> I note that the probes in PortalRun and PortalRunMulti are schizophrenic
>> about whether they include utility functions or not.
As are as I can tell, the current probes in PortalRun/Multi don't
include utility functions. Should they be included?

I'll send the patch for the above changes tomorrow!

--
Robert Lor Sun Microsystems
Austin, USA http://sun.com/postgresql

Tom Lane wrote:
>
> * The probes that pass buffer tag elements are already broken by the
> pending "relation forks" patch: there is soon going to be another field
> in buffer tags. Perhaps it'd be feasible to pass the buffer tag as a
> single probe argument to make that a bit more future-proof? I'm not
> sure if that would complicate the use of the probe so much as to be
> counterproductive.
>
Are you referring to this struct?

typedef struct buftag
{
RelFileNode rnode; /* physical relation
identifier */
BlockNumber blockNum; /* blknum relative to begin of
reln */
} BufferTag;

I'm not familiar with this pending patch, but why would it break when
another field is added?

It's certainly possible to pass the buffer tag, but I'd say it's not a
good idea if the other fields will never be used.

> * I find this to be truly bletcherous:
>
>
>> ! /*
>> ! * Due to a bug in Mac OS X 10.5, using defined types (e.g. uintptr_t,
>> ! * uint32_t, etc.) cause compilation error.
>> ! */
>> !
>> ! probe transaction__start(unsigned int transactionId);
>> ! probe transaction__commit(unsigned int transactionId);
>> ! probe transaction__abort(unsigned int transactionId);
>>
>
> especially since some of the manual translations in the file are flat
> out wrong (Oid is unsigned for instance).
Oops!
> Furthermore the comment is
> wrong, at least according to my tests with XCode 3.1. Typedefs seem to
> work fine.

The issue is with Apple's dtrace implementation, not Xcode. For more
info, please see the link below.

http://www.opensolaris.org/jive/thread.jspa?messageID=252503&#252503

> What I suggest might be a reasonable compromise is to copy needed
> typedefs directly into the probes.d file:
>
> typedef unsigned int LocalTransactionId;
>
> provider postgresql {
>
> probe transaction__start(LocalTransactionId);
>
>
I like this solution.

--
Robert Lor Sun Microsystems
Austin, USA http://sun.com/postgresql

Robert Lor <Robert(dot)Lor(at)Sun(dot)COM> writes:
> Tom Lane wrote:
>> * The probes that pass buffer tag elements are already broken by the
>> pending "relation forks" patch: there is soon going to be another field
>> in buffer tags.

> I'm not familiar with this pending patch, but why would it break when
> another field is added?

By "break" I meant "fail to function usefully". Yes, it would still
compile, but if you don't have the fork number available then you won't
be able to tell what's really happening in the buffer pool. You might
as well not pass any of the buffer tag as pass only part of it.

>> Furthermore the comment is
>> wrong, at least according to my tests with XCode 3.1. Typedefs seem to
>> work fine.

> The issue is with Apple's dtrace implementation, not Xcode. For more
> info, please see the link below.
> http://www.opensolaris.org/jive/thread.jspa?messageID=252503&#252503

I think what this is complaining about is whether allegedly built-in
typedefs like uintptr_t work. What we care about is different: can
we write an explicit typedef in the .d file? I do not know if that
worked in XCode 3.0 or not, but it seems to work fine in the version
of dtrace shipped in 3.1. (And I'm perfectly fine with telling people
that they can't compile Postgres dtrace support with less than the most
recent tool set, especially since it'll be fairly old by the time 8.4
ships.)

regards, tom lane

Tom Lane wrote:
> By "break" I meant "fail to function usefully". Yes, it would still
> compile, but if you don't have the fork number available then you won't
> be able to tell what's really happening in the buffer pool. You might
> as well not pass any of the buffer tag as pass only part of it.
>

Got it.

>> The issue is with Apple's dtrace implementation, not Xcode. For more
>> info, please see the link below.
>> http://www.opensolaris.org/jive/thread.jspa?messageID=252503&#252503
>>
>
> I think what this is complaining about is whether allegedly built-in
> typedefs like uintptr_t work.

This is the message I tried to convey with the comment in probe.d, but I
guess it was not clear.
> What we care about is different: can
> we write an explicit typedef in the .d file?

Yes.

> I do not know if that
> worked in XCode 3.0 or not, but it seems to work fine in the version
> of dtrace shipped in 3.1. (And I'm perfectly fine with telling people
> that they can't compile Postgres dtrace support with less than the most
> recent tool set, especially since it'll be fairly old by the time 8.4
> ships.)
>
I tested on both Xcode 3.0 & 3.1 and both worked.

--
Robert Lor Sun Microsystems
Austin, USA http://sun.com/postgresql

Updated patch attached.

This patch addresses all of Alvaro's feedback except the new probes for
v3 protocol which will be submitted later along with the rest of the probes.

It also incorporates Tom's feedback as explained inline below.

I hope this patch is good to go for this commit fest. Will take care of
the rest in the next fest.

Tom Lane wrote:
> Zdenek Kotala <Zdenek(dot)Kotala(at)Sun(dot)COM> writes:
>
>> I performed review and I prepared own patch which contains only probes
>> without any issue. I suggest commit this patch because the rest of
>> patch is independent and it can be committed next commit fest after
>> rework.
>>
>
> I looked at this patch a little bit. In addition to the comments Alvaro
> made, I have a couple more issues:
>
> * The probes that pass buffer tag elements are already broken by the
> pending "relation forks" patch: there is soon going to be another field
> in buffer tags. Perhaps it'd be feasible to pass the buffer tag as a
> single probe argument to make that a bit more future-proof? I'm not
> sure if that would complicate the use of the probe so much as to be
> counterproductive.
>
>
>
Took out the buffer tag argument for now. Will figure out how to best
solve this after this relation forks patch is committed.
>
> What I suggest might be a reasonable compromise is to copy needed
> typedefs directly into the probes.d file:
>
> typedef unsigned int LocalTransactionId;
>
> provider postgresql {
>
> probe transaction__start(LocalTransactionId);
>
> This at least makes it possible to declare the probes cleanly,
> and it's fairly obvious what to fix if the principal definition of
> LocalTransactionId ever changes. I don't have Solaris to test on, but
> on OS X this seems to behave the way we'd like: the typedef itself isn't
> copied into the emitted probes.h file, but the emitted extern
> declarations use it.
>
>
Implemented this suggestion. There are some weirdness with the OS X
compiler causing some of the probe declarations not to compile (see
comments in probe.d). The compiler spits out some warnings because the
types don't show up in the function prototype in probes.h, but the
probes work okay. I think we can safely ignore the warnings.

--
Robert Lor Sun Microsystems
Austin, USA http://sun.com/postgresql

Robert Lor wrote:

Hi,

>> What I suggest might be a reasonable compromise is to copy needed
>> typedefs directly into the probes.d file:

> Implemented this suggestion. There are some weirdness with the OS X
> compiler causing some of the probe declarations not to compile (see
> comments in probe.d). The compiler spits out some warnings because the
> types don't show up in the function prototype in probes.h, but the
> probes work okay. I think we can safely ignore the warnings.

These make sense, because they are already typedef's in our code:

> +typedef unsigned int LocalTransactionId;
> +typedef int LWLockId;
> +typedef int LWLockMode;
> +typedef int LOCKMODE;
> +typedef unsigned int BlockNumber;
> +typedef unsigned int Oid;

But I don't see a reason to define the rest:

> +typedef unsigned int locktag_field2;
> +typedef const char * query_string;
> +typedef int sortType;
> +typedef int trueFalse;
> +typedef int nkeys;
> +typedef int workMem;
> +typedef int randomAccess;
> +typedef unsigned long LogicalTapeSetPtr;
> +typedef long spaceUsed;
> +typedef int isLocalBuf;
> +typedef int found;
> +typedef int flags;
> +typedef int num_to_write;
> +typedef int num_written;
> +typedef int NBuffers;
> +typedef int buf_id;

I think you should add a #define Size, perhaps #define bool, and use
those where applicable, and the plain types (int, long, etc) in the rest.

> + /* The following probe declarations cause compilation errors
> + * on Mac OS X but not on Solaris. Need further investigation.
> + * probe lock__wait__start(locktag_field2, LOCKMODE);
> + * probe lock__wait__done(locktag_field2, LOCKMODE);
> + */
> + probe lock__wait__start(unsigned int, int);
> + probe lock__wait__done(unsigned int, int);

For example I think this should look like

probe lock__wait__start(unsigned int, LOCKMODE);

That Mac OS X problem merits some extra investigation, I think.

Other than this, I think this patch can be committed.

--
Alvaro Herrera http://www.CommandPrompt.com/
PostgreSQL Replication, Consulting, Custom Development, 24x7 support

Alvaro Herrera wrote:
> But I don't see a reason to define the rest:
>
>
>> +typedef unsigned int locktag_field2;
>> +typedef const char * query_string;
>> +typedef int sortType;
>> +typedef int trueFalse;
>> +typedef int nkeys;
>> +typedef int workMem;
>> +typedef int randomAccess;
>> +typedef unsigned long LogicalTapeSetPtr;
>> +typedef long spaceUsed;
>> +typedef int isLocalBuf;
>> +typedef int found;
>> +typedef int flags;
>> +typedef int num_to_write;
>> +typedef int num_written;
>> +typedef int NBuffers;
>> +typedef int buf_id;
>>
>
> I think you should add a #define Size, perhaps #define bool, and use
> those where applicable, and the plain types (int, long, etc) in the rest.
>

Fixed. Patch attached.
>
> That Mac OS X problem merits some extra investigation, I think.
>
I'm investigating this one and will find the root cause, but I don't
think it should hold back this patch.
> Other than this, I think this patch can be committed.
>
>
I'd appreciate if it can be committed today.

Alvaro, thanks a bunch for the feedback!

--
Robert Lor Sun Microsystems
Austin, USA http://sun.com/postgresql

Robert Lor wrote:

>> That Mac OS X problem merits some extra investigation, I think.
>>
> I'm investigating this one and will find the root cause, but I don't
> think it should hold back this patch.
>> Other than this, I think this patch can be committed.
>>
> I'd appreciate if it can be committed today.

I'm looking at it.

FWIW I found that the machinery to compile on non-probes-enabled
machines needs to be updated per the attached patch.

--
Alvaro Herrera http://www.CommandPrompt.com/
PostgreSQL Replication, Consulting, Custom Development, 24x7 support

Robert Lor wrote:

> Tom Lane wrote:

>> * The probes that pass buffer tag elements are already broken by the
>> pending "relation forks" patch: there is soon going to be another field
>> in buffer tags. Perhaps it'd be feasible to pass the buffer tag as a
>> single probe argument to make that a bit more future-proof? I'm not
>> sure if that would complicate the use of the probe so much as to be
>> counterproductive.
>
> Took out the buffer tag argument for now. Will figure out how to best
> solve this after this relation forks patch is committed.

I was checking the DTrace docs for other reasons and I came across this,
which maybe can be useful here:

http://docs.sun.com/app/docs/doc/817-6223/chp-xlate?a=view

--
Alvaro Herrera http://www.CommandPrompt.com/
PostgreSQL Replication, Consulting, Custom Development, 24x7 support

Here's what I have. Please confirm that this compiles for you.

--
Alvaro Herrera http://www.CommandPrompt.com/
PostgreSQL Replication, Consulting, Custom Development, 24x7 support

Alvaro Herrera wrote:
> Here's what I have. Please confirm that this compiles for you.
>
I made some changes to the sed script so it works with the sed on
Solaris & OS X. I tested this patch on both Solaris and OS X with DTrace
enabled and disabled and also verified that the sed script works with
GNU sed. I hope this is the final change for this patch. Thanks for
catching all the issues, and my bad for not testing with DTrace disabled.

>
> ------------------------------------------------------------------------
>
>

--
Robert Lor Sun Microsystems
Austin, USA http://sun.com/postgresql

Alvaro Herrera wrote:
> I was checking the DTrace docs for other reasons and I came across this,
> which maybe can be useful here:
>
> http://docs.sun.com/app/docs/doc/817-6223/chp-xlate?a=view
>
>
Yes, I think using the translator is the best approach to expose
internal structures in a stable manner.

--
Robert Lor Sun Microsystems
Austin, USA http://sun.com/postgresql

Robert Lor wrote:

> I made some changes to the sed script so it works with the sed on
> Solaris & OS X. I tested this patch on both Solaris and OS X with DTrace
> enabled and disabled and also verified that the sed script works with
> GNU sed. I hope this is the final change for this patch. Thanks for
> catching all the issues, and my bad for not testing with DTrace disabled.

Applied.

Something seems wrong with this argument:

> + /* The following probe declarations cause compilation errors
> + * on Mac OS X but not on Solaris. Need further investigation.
> + * probe buffer__read__start(BlockNumber, Oid, Oid, Oid, bool);
> + * probe buffer__read__done(BlockNumber, Oid, Oid, Oid, bool, bool);
> + */
> + probe buffer__read__start(unsigned int, unsigned int, unsigned int, unsigned int, bool);
> + probe buffer__read__done(unsigned int, unsigned int, unsigned int, unsigned int, bool, bool);
> +
> + probe buffer__flush__start(Oid, Oid, Oid);
> + probe buffer__flush__done(Oid, Oid, Oid);

How come "Oid" works for FLUSH_START but not READ_START and READ_DONE?

Also, I wonder if there's any proof that this works at all on Mac OS X,
given that the rule to create probes.o from probes.d is conditionally
pulled in only for Solaris?

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

Alvaro Herrera wrote:

> Applied.

I forgot to mention that I renamed the sort_end probe to sort_done, to
keep the naming convention. It is a backwards-incompatible change, but
there were plenty other probes renamed so my guess is that one more does
not matter all that much.

Also, it seems I cannot sort pg_trace and pgstat consistently :-(

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

Alvaro Herrera wrote:
>
> Applied.
>
Thanks!
>> How come "Oid" works for FLUSH_START but not READ_START and READ_DONE?
>>

I'll get the answer for this.

>> Also, I wonder if there's any proof that this works at all on Mac OS X,
>> given that the rule to create probes.o from probes.d is conditionally
>> pulled in only for Solaris?
>>
It does work on OS X. I dare everyone to try it :-)

The implementation of DTrace on OS X is a bit different than on Solaris,
so the rule your referring to is only needed for Solaris.

--
Robert Lor Sun Microsystems
Austin, USA http://sun.com/postgresql

Alvaro Herrera wrote:
> Alvaro Herrera wrote:
>
>
>> Applied.
>>
>
> I forgot to mention that I renamed the sort_end probe to sort_done, to
> keep the naming convention. It is a backwards-incompatible change, but
> there were plenty other probes renamed so my guess is that one more does
> not matter all that much.
>
It was overlooked :-( . Good catch!
> Also, it seems I cannot sort pg_trace and pgstat consistently :-(
>
>
Not sure what you're trying to say here!

--
Robert Lor Sun Microsystems
Austin, USA http://sun.com/postgresql

One tiny change I'd suggest here: if you look at the code for checkpoint
buffer writing there are traces for two points in the process:

CheckPointBuffers(int flags)
{
+ TRACE_POSTGRESQL_BUFFER_CHECKPOINT_START(flags);
CheckpointStats.ckpt_write_t = GetCurrentTimestamp();
BufferSync(flags);
CheckpointStats.ckpt_sync_t = GetCurrentTimestamp();
smgrsync();
CheckpointStats.ckpt_sync_end_t = GetCurrentTimestamp();
+ TRACE_POSTGRESQL_BUFFER_CHECKPOINT_DONE();
}

Note how the existing code also tracks how long the sync phase took
compared to the write one, and reports both numbers in the checkpoint
logs. It would be nice to add another probe at that same point (just
after ckpt_sync_t is set) so that dtrace users could instrument all these
possibilities as well: just buffer write time/resources, just sync ones,
or both.

--
* Greg Smith gsmith(at)gregsmith(dot)com http://www.gregsmith.com Baltimore, MD

Greg Smith wrote:
> One tiny change I'd suggest here: if you look at the code for checkpoint
> buffer writing there are traces for two points in the process:
>
> CheckPointBuffers(int flags)
> {
> + TRACE_POSTGRESQL_BUFFER_CHECKPOINT_START(flags);
> CheckpointStats.ckpt_write_t = GetCurrentTimestamp();
> BufferSync(flags);
> CheckpointStats.ckpt_sync_t = GetCurrentTimestamp();
> smgrsync();
> CheckpointStats.ckpt_sync_end_t = GetCurrentTimestamp();
> + TRACE_POSTGRESQL_BUFFER_CHECKPOINT_DONE();
> }
>
> Note how the existing code also tracks how long the sync phase took
> compared to the write one, and reports both numbers in the checkpoint
> logs. It would be nice to add another probe at that same point (just
> after ckpt_sync_t is set) so that dtrace users could instrument all these
> possibilities as well: just buffer write time/resources, just sync ones,
> or both.

Sounds like the thing to do would be to pass CheckpointStats into the
DONE probe.

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

Alvaro Herrera wrote:
> Greg Smith wrote:
>
>> One tiny change I'd suggest here: if you look at the code for checkpoint
>> buffer writing there are traces for two points in the process:
>>
>> CheckPointBuffers(int flags)
>> {
>> + TRACE_POSTGRESQL_BUFFER_CHECKPOINT_START(flags);
>> CheckpointStats.ckpt_write_t = GetCurrentTimestamp();
>> BufferSync(flags);
>> CheckpointStats.ckpt_sync_t = GetCurrentTimestamp();
>> smgrsync();
>> CheckpointStats.ckpt_sync_end_t = GetCurrentTimestamp();
>> + TRACE_POSTGRESQL_BUFFER_CHECKPOINT_DONE();
>> }
>>
>> Note how the existing code also tracks how long the sync phase took
>> compared to the write one, and reports both numbers in the checkpoint
>> logs. It would be nice to add another probe at that same point (just
>> after ckpt_sync_t is set) so that dtrace users could instrument all these
>> possibilities as well: just buffer write time/resources, just sync ones,
>> or both.
>>
>
> Sounds like the thing to do would be to pass CheckpointStats into the
> DONE probe.
>
>

I like this approach as it avoids the need to have too many probes. I
will make this change and get it in with the remaining probes for the
next commit fest.

--
Robert Lor Sun Microsystems
Austin, USA http://sun.com/postgresql

On Fri, 1 Aug 2008, Alvaro Herrera wrote:

> Sounds like the thing to do would be to pass CheckpointStats into the
> DONE probe.

I thought it would be more useful to demarcate where the two phases of the
checkpoint process were at clearly--the actual times themselves are
helpful but dtrace can do more than that. The write and sync phases have
very different I/O characteristics, and it really should be easy for
people to analyze them independantly. I'm not familiar enough with dtrace
to know if that's easy with the patch as it stands, I think there needs to
be another probe in the middle there to make that straightforward.

--
* Greg Smith gsmith(at)gregsmith(dot)com http://www.gregsmith.com Baltimore, MD