Thread: Patch to log usage of temporary files
Thanks to Simon Riggs and Bruce for input that helped me put this together. -- Bill Moran Collaborative Fusion Inc.
Attachment
Bill Moran wrote: > > Thanks to Simon Riggs and Bruce for input that helped me put this together. Please change things to save the stat() syscall when the feature is not in use. Nitpick: also note our brace placement convention (though this would be fixed by pgindent, but still). -- Alvaro Herrera http://www.CommandPrompt.com/ PostgreSQL Replication, Consulting, Custom Development, 24x7 support
Bill Moran wrote:
> + if (stat(vfdP->fileName, &filestats) == 0) {
> + if (trace_temp_files)
>
Shouldn't these tests be the other way around?
cheers
andrew
In response to Alvaro Herrera <alvherre@commandprompt.com>: > Bill Moran wrote: > > > > Thanks to Simon Riggs and Bruce for input that helped me put this together. > > Please change things to save the stat() syscall when the feature is not > in use. Do you have a suggestion on how to do that and still have the PG_TRACE1() work? That was specifically requested by Simon Riggs. I'm not at all familiar with how the PG_TRACE probes work, so I'd be interested to hear suggestions on how to wrap that in an if. If I remove the PG_TRACE, it becomes a simple matter to skip the stat() if the feature is disabled. > Nitpick: also note our brace placement convention (though this would be > fixed by pgindent, but still). Sorry, I thought I _was_ following the convention. Must have missed something. Is there a written style guide somewhere? Might drive things home a little better than just looking at other folks code. -- Bill Moran Collaborative Fusion Inc.
Bill Moran <wmoran@collaborativefusion.com> writes:
> In response to Alvaro Herrera <alvherre@commandprompt.com>:
>> Please change things to save the stat() syscall when the feature is not
>> in use.
> Do you have a suggestion on how to do that and still have the PG_TRACE1()
> work? That was specifically requested by Simon Riggs.
Well, we are NOT paying a stat() call on every single file close,
whether Simon wants it or not. PG_TRACE1 doesn't even do anything
on non-Solaris platforms, for pete's sake.
Perhaps it would be reasonable to define trace_temp_files as the minimum
file size to log; then you could do something like
if (trace_temp_files > 0)
{
if (stat(vfdP->fileName, &filestats) < 0)
elog(LOG, ...);
else
{
if (filestats.st_size / BLCKSZ >= trace_temp_files)
ereport(LOG, ...);
PG_TRACE1(temp__file__cleanup, filestats.st_size);
}
}
Note that elog(ERROR) is quite inappropriate here.
regards, tom lane
On Tue, 2007-01-02 at 18:20 -0500, Tom Lane wrote:
> Bill Moran <wmoran@collaborativefusion.com> writes:
> > In response to Alvaro Herrera <alvherre@commandprompt.com>:
> >> Please change things to save the stat() syscall when the feature is not
> >> in use.
>
> > Do you have a suggestion on how to do that and still have the PG_TRACE1()
> > work? That was specifically requested by Simon Riggs.
>
> Well, we are NOT paying a stat() call on every single file close,
> whether Simon wants it or not.
Simon doesn't/wouldn't want the stat() call on each file close.
If you put the PG_TRACE macro outside of the if test, yet prior to the
file close, you can pass the filename through like this
PG_TRACE1(temp__file__cleanup, vfdP->fileName);
That way DTrace can make its own call to find out filesize, if it would
like to... and we don't need to stat() before each temp file close.
That's much more flexible and useful, as well as better performance.
--
Simon Riggs
EnterpriseDB http://www.enterprisedb.com
In response to "Simon Riggs" <simon@2ndquadrant.com>: > On Tue, 2007-01-02 at 18:20 -0500, Tom Lane wrote: > > Bill Moran <wmoran@collaborativefusion.com> writes: > > > In response to Alvaro Herrera <alvherre@commandprompt.com>: > > >> Please change things to save the stat() syscall when the feature is not > > >> in use. > > > > > Do you have a suggestion on how to do that and still have the PG_TRACE1() > > > work? That was specifically requested by Simon Riggs. > > > > Well, we are NOT paying a stat() call on every single file close, > > whether Simon wants it or not. > > Simon doesn't/wouldn't want the stat() call on each file close. > > If you put the PG_TRACE macro outside of the if test, yet prior to the > file close, you can pass the filename through like this > > PG_TRACE1(temp__file__cleanup, vfdP->fileName); > > That way DTrace can make its own call to find out filesize, if it would > like to... and we don't need to stat() before each temp file close. > That's much more flexible and useful, as well as better performance. OK, I think I've managed to adjust this patch so that everyone is happy ;) and it's better as well. * PG_TRACE will work whether the GUC var is enabled or not, it sends the fileName, as suggested by Simon * stat() call is not made if trace_temp_files is disabled * trace_temp_files is now an int: -1 disables, 0 and up equate to "log if the file is this size or larger" * Cleaned things up a bit -- should be more in line with PostgreSQL coding standards * failed stat is reported as LOG instead of ERROR Done a bit of testing here, and everything seems to be in order. -- Bill Moran Collaborative Fusion Inc.
Attachment
Bill Moran wrote:
> + if (trace_temp_files != -1)
>
Might be more robust to say
if (trace_temp_files >= 0)
cheers
andrew
Andrew Dunstan <andrew@dunslane.net> wrote: > > Bill Moran wrote: > > + if (trace_temp_files != -1) > > > > Might be more robust to say > > if (trace_temp_files >= 0) Because it would allow for the easy addition of more negative numbers with magic value?
Bill Moran wrote: > Andrew Dunstan <andrew@dunslane.net> wrote: >> >> Bill Moran wrote: >> > + if (trace_temp_files != -1) >> > >> >> Might be more robust to say >> >> if (trace_temp_files >= 0) > > Because it would allow for the easy addition of more negative numbers > with magic value? > because ISTM any negative number here should mean no action is to be taken. Otherwise how else is it different from 0? cheers andrew
In response to "Andrew Dunstan" <andrew@dunslane.net>: > Bill Moran wrote: > > Andrew Dunstan <andrew@dunslane.net> wrote: > >> > >> Bill Moran wrote: > >> > + if (trace_temp_files != -1) > >> > > >> > >> Might be more robust to say > >> > >> if (trace_temp_files >= 0) > > > > Because it would allow for the easy addition of more negative numbers > > with magic value? > > because ISTM any negative number here should mean no action is to be > taken. Otherwise how else is it different from 0? ?? I specified in the GUC config that minimum allowable value is -1. /usr/local/etc/rc.d/postgresql start FATAL: -5 is outside the valid range for parameter "trace_temp_files" (-1 .. 2147483647) set trace_temp_files to -8; ERROR: -8 is outside the valid range for parameter "trace_temp_files" (-1 .. 2147483647) Perhaps there's another reason to use the >= 0 check, but handling invalid values with POLA doesn't seem to be a good one. -- Bill Moran Collaborative Fusion Inc.
Bill Moran wrote: > In response to "Andrew Dunstan" <andrew@dunslane.net>: > > >> Bill Moran wrote: >> >>> Andrew Dunstan <andrew@dunslane.net> wrote: >>> >>>> Bill Moran wrote: >>>> >>>>> + if (trace_temp_files != -1) >>>>> >>>>> >>>> Might be more robust to say >>>> >>>> if (trace_temp_files >= 0) >>>> >>> Because it would allow for the easy addition of more negative numbers >>> with magic value? >>> >> because ISTM any negative number here should mean no action is to be >> taken. Otherwise how else is it different from 0? >> > > ?? > > I specified in the GUC config that minimum allowable value is -1. > > OK, missed that, sorry. Please return to normal viewing ... cheers andrew
Bill Moran <wmoran@collaborativefusion.com> writes:
> Andrew Dunstan <andrew@dunslane.net> wrote:
>>> Might be more robust to say
>>> if (trace_temp_files >= 0)
> I specified in the GUC config that minimum allowable value is -1.
I'd still tend to go with Andrew's suggestion because it makes this
particular bit of code self-defending against bad values. Yes, it's
reasonably safe given that bit of coding way over yonder in guc.c,
but there's no particularly good reason why this code has to depend
on that to avoid doing something stupid. And it's easier to understand
too --- you don't have to go looking in guc.c to convince yourself it's
safe.
regards, tom lane
In response to Tom Lane <tgl@sss.pgh.pa.us>: > Bill Moran <wmoran@collaborativefusion.com> writes: > > Andrew Dunstan <andrew@dunslane.net> wrote: > >>> Might be more robust to say > >>> if (trace_temp_files >= 0) > > > I specified in the GUC config that minimum allowable value is -1. > > I'd still tend to go with Andrew's suggestion because it makes this > particular bit of code self-defending against bad values. Yes, it's > reasonably safe given that bit of coding way over yonder in guc.c, > but there's no particularly good reason why this code has to depend > on that to avoid doing something stupid. And it's easier to understand > too --- you don't have to go looking in guc.c to convince yourself it's > safe. Ahh ... well, I've probably already argued about it more than it's worth. The patch is easy enough to adjust, find attached. -- Bill Moran Collaborative Fusion Inc.
Attachment
On Jan 3, 2007, at 4:20 PM, Bill Moran wrote: > * trace_temp_files is now an int: -1 disables, 0 and up equate to > "log if > the file is this size or larger" Another thought is to allow ignoring files over a certain size. The reason is that if you end up creating 10MB of temp files, you can probably avoid that by adjusting work_mem. But if you just created 10GB, you probably have no choice in the matter. -- Jim Nasby jim@nasby.net EnterpriseDB http://enterprisedb.com 512.569.9461 (cell)
Bill Moran wrote: > In response to Tom Lane <tgl@sss.pgh.pa.us>: > > > Bill Moran <wmoran@collaborativefusion.com> writes: > > > Andrew Dunstan <andrew@dunslane.net> wrote: > > >>> Might be more robust to say > > >>> if (trace_temp_files >= 0) > > > > > I specified in the GUC config that minimum allowable value is -1. > > > > I'd still tend to go with Andrew's suggestion because it makes this > > particular bit of code self-defending against bad values. Yes, it's > > reasonably safe given that bit of coding way over yonder in guc.c, > > but there's no particularly good reason why this code has to depend > > on that to avoid doing something stupid. And it's easier to understand > > too --- you don't have to go looking in guc.c to convince yourself it's > > safe. > > Ahh ... well, I've probably already argued about it more than it's worth. > The patch is easy enough to adjust, find attached. I have applied a modified version of your patch. I renamed the parameter to 'log_temp_files', for consistency, added documentation, and improved the wording, particularly mentioning that the logging happens at file deletion time. Thanks. -- Bruce Momjian bruce@momjian.us EnterpriseDB http://www.enterprisedb.com + If your life is a hard drive, Christ can be your backup. + Index: doc/src/sgml/config.sgml =================================================================== RCS file: /cvsroot/pgsql/doc/src/sgml/config.sgml,v retrieving revision 1.99 diff -c -c -r1.99 config.sgml *** doc/src/sgml/config.sgml 12 Dec 2006 21:30:33 -0000 1.99 --- doc/src/sgml/config.sgml 9 Jan 2007 21:03:51 -0000 *************** *** 2920,2925 **** --- 2920,2942 ---- </listitem> </varlistentry> + <varlistentry id="guc-log-temp-files" xreflabel="log_temp_files"> + <term><varname>log_temp_files</varname> (<type>integer</type>)</term> + <indexterm> + <primary><varname>log_temp_files</> configuration parameter</primary> + </indexterm> + <listitem> + <para> + Controls whether temporary files are logged when deleted. + A value of zero logs all temporary files, and positive + values log only files whose size is equal or greater than + the specified number of bytes. Temporary files can be + created for sorts, hashes, and temporary results. The + default is <literal>-1</> (off). + </para> + </listitem> + </varlistentry> + </variablelist> </sect2> </sect1> Index: src/backend/storage/file/fd.c =================================================================== RCS file: /cvsroot/pgsql/src/backend/storage/file/fd.c,v retrieving revision 1.132 diff -c -c -r1.132 fd.c *** src/backend/storage/file/fd.c 5 Jan 2007 22:19:37 -0000 1.132 --- src/backend/storage/file/fd.c 9 Jan 2007 21:03:54 -0000 *************** *** 50,55 **** --- 50,56 ---- #include "access/xact.h" #include "storage/fd.h" #include "storage/ipc.h" + #include "utils/guc.h" /* *************** *** 938,944 **** void FileClose(File file) { ! Vfd *vfdP; Assert(FileIsValid(file)); --- 939,946 ---- void FileClose(File file) { ! Vfd *vfdP; ! struct stat filestats; Assert(FileIsValid(file)); *************** *** 968,973 **** --- 970,988 ---- { /* reset flag so that die() interrupt won't cause problems */ vfdP->fdstate &= ~FD_TEMPORARY; + PG_TRACE1(temp__file__cleanup, vfdP->fileName); + if (log_temp_files >= 0) + { + if (stat(vfdP->fileName, &filestats) == 0) + { + if (filestats.st_size >= log_temp_files) + ereport(LOG, + (errmsg("temp file: path \"%s\" size %lu", + vfdP->fileName, (unsigned long)filestats.st_size))); + } + else + elog(LOG, "Could not stat \"%s\": %m", vfdP->fileName); + } if (unlink(vfdP->fileName)) elog(LOG, "failed to unlink \"%s\": %m", vfdP->fileName); Index: src/backend/utils/misc/guc.c =================================================================== RCS file: /cvsroot/pgsql/src/backend/utils/misc/guc.c,v retrieving revision 1.365 diff -c -c -r1.365 guc.c *** src/backend/utils/misc/guc.c 5 Jan 2007 22:19:46 -0000 1.365 --- src/backend/utils/misc/guc.c 9 Jan 2007 21:03:57 -0000 *************** *** 182,187 **** --- 182,188 ---- int log_min_messages = NOTICE; int client_min_messages = NOTICE; int log_min_duration_statement = -1; + int log_temp_files = -1; int num_temp_buffers = 1000; *************** *** 1660,1665 **** --- 1661,1676 ---- &server_version_num, PG_VERSION_NUM, PG_VERSION_NUM, PG_VERSION_NUM, NULL, NULL }, + + { + {"log_temp_files", PGC_USERSET, LOGGING_WHAT, + gettext_noop("Log the use of temporary files larger than this size."), + gettext_noop("Zero logs all files. The default is -1 (turning this feature off)."), + NULL + }, + &log_temp_files, + -1, -1, INT_MAX, NULL, NULL + }, /* End-of-list marker */ { Index: src/backend/utils/misc/postgresql.conf.sample =================================================================== RCS file: /cvsroot/pgsql/src/backend/utils/misc/postgresql.conf.sample,v retrieving revision 1.199 diff -c -c -r1.199 postgresql.conf.sample *** src/backend/utils/misc/postgresql.conf.sample 21 Nov 2006 01:23:37 -0000 1.199 --- src/backend/utils/misc/postgresql.conf.sample 9 Jan 2007 21:03:57 -0000 *************** *** 333,338 **** --- 333,341 ---- #log_statement = 'none' # none, ddl, mod, all #log_hostname = off + #log_temp_files = -1 # Log temporary files equal or larger + # than the specified number of bytes. + # -1 disables; 0 logs all temp files #--------------------------------------------------------------------------- # RUNTIME STATISTICS Index: src/include/utils/guc.h =================================================================== RCS file: /cvsroot/pgsql/src/include/utils/guc.h,v retrieving revision 1.77 diff -c -c -r1.77 guc.h *** src/include/utils/guc.h 5 Jan 2007 22:19:59 -0000 1.77 --- src/include/utils/guc.h 9 Jan 2007 21:03:58 -0000 *************** *** 123,128 **** --- 123,129 ---- extern int log_min_messages; extern int client_min_messages; extern int log_min_duration_statement; + extern int log_temp_files; extern int num_temp_buffers;
In response to Bruce Momjian <bruce@momjian.us>: > > I have applied a modified version of your patch. I renamed the > parameter to 'log_temp_files', for consistency, added documentation, and > improved the wording, particularly mentioning that the logging happens > at file deletion time. Thanks. -- Bill Moran Collaborative Fusion Inc.
Bruce Momjian <bruce@momjian.us> writes:
> + A value of zero logs all temporary files, and positive
> + values log only files whose size is equal or greater than
> + the specified number of bytes.
Surely the measurement unit should be kbytes or disk blocks. And why
aren't you using that GUC UNITS infrastructure Peter put in?
> /* reset flag so that die() interrupt won't cause problems */
> vfdP->fdstate &= ~FD_TEMPORARY;
> + PG_TRACE1(temp__file__cleanup, vfdP->fileName);
> + if (log_temp_files >= 0)
> + {
> + if (stat(vfdP->fileName, &filestats) == 0)
The TRACE is in the wrong place no? I thought it was going to be after
the stat() operation so it could pass the file size.
Also, I dunno much about DTrace, but I had the idea that you can't
simply throw a PG_TRACE macro into the source and think you are done
--- isn't there a file of probe declarations to add to? Not to mention
the documentation of what probes exist.
regards, tom lane
Tom Lane wrote:
> Bruce Momjian <bruce@momjian.us> writes:
> > + A value of zero logs all temporary files, and positive
> > + values log only files whose size is equal or greater than
> > + the specified number of bytes.
>
> Surely the measurement unit should be kbytes or disk blocks. And why
> aren't you using that GUC UNITS infrastructure Peter put in?
Agreed. I have applied the following patch to make it kilobytes, and
documented it. I didn't put '-1kB' in the postgresql.conf file because
the -1 value is special. (ideas?)
> > /* reset flag so that die() interrupt won't cause problems */
> > vfdP->fdstate &= ~FD_TEMPORARY;
> > + PG_TRACE1(temp__file__cleanup, vfdP->fileName);
> > + if (log_temp_files >= 0)
> > + {
> > + if (stat(vfdP->fileName, &filestats) == 0)
>
> The TRACE is in the wrong place no? I thought it was going to be after
> the stat() operation so it could pass the file size.
>
> Also, I dunno much about DTrace, but I had the idea that you can't
> simply throw a PG_TRACE macro into the source and think you are done
> --- isn't there a file of probe declarations to add to? Not to mention
> the documentation of what probes exist.
I didn't like the macro in that area anyway. It seems too adhock to
just throw it in when we have so few places monitored now. Removed.
--
Bruce Momjian bruce@momjian.us
EnterpriseDB http://www.enterprisedb.com
+ If your life is a hard drive, Christ can be your backup. +
Index: doc/src/sgml/config.sgml
===================================================================
RCS file: /cvsroot/pgsql/doc/src/sgml/config.sgml,v
retrieving revision 1.100
diff -c -c -r1.100 config.sgml
*** doc/src/sgml/config.sgml 9 Jan 2007 21:31:14 -0000 1.100
--- doc/src/sgml/config.sgml 9 Jan 2007 22:15:40 -0000
***************
*** 2930,2936 ****
Controls whether temporary files are logged when deleted.
A value of zero logs all temporary files, and positive
values log only files whose size is equal or greater than
! the specified number of bytes. Temporary files can be
created for sorts, hashes, and temporary results. The
default is <literal>-1</> (off).
</para>
--- 2930,2936 ----
Controls whether temporary files are logged when deleted.
A value of zero logs all temporary files, and positive
values log only files whose size is equal or greater than
! the specified number of kilobytes. Temporary files can be
created for sorts, hashes, and temporary results. The
default is <literal>-1</> (off).
</para>
Index: src/backend/utils/misc/guc.c
===================================================================
RCS file: /cvsroot/pgsql/src/backend/utils/misc/guc.c,v
retrieving revision 1.366
diff -c -c -r1.366 guc.c
*** src/backend/utils/misc/guc.c 9 Jan 2007 21:31:14 -0000 1.366
--- src/backend/utils/misc/guc.c 9 Jan 2007 22:15:43 -0000
***************
*** 1664,1672 ****
{
{"log_temp_files", PGC_USERSET, LOGGING_WHAT,
! gettext_noop("Log the use of temporary files larger than this size."),
gettext_noop("Zero logs all files. The default is -1 (turning this feature off)."),
! NULL
},
&log_temp_files,
-1, -1, INT_MAX, NULL, NULL
--- 1664,1672 ----
{
{"log_temp_files", PGC_USERSET, LOGGING_WHAT,
! gettext_noop("Log the use of temporary files larger than this number of kilobytes."),
gettext_noop("Zero logs all files. The default is -1 (turning this feature off)."),
! GUC_UNIT_KB
},
&log_temp_files,
-1, -1, INT_MAX, NULL, NULL
Index: src/backend/utils/misc/postgresql.conf.sample
===================================================================
RCS file: /cvsroot/pgsql/src/backend/utils/misc/postgresql.conf.sample,v
retrieving revision 1.200
diff -c -c -r1.200 postgresql.conf.sample
*** src/backend/utils/misc/postgresql.conf.sample 9 Jan 2007 21:31:16 -0000 1.200
--- src/backend/utils/misc/postgresql.conf.sample 9 Jan 2007 22:15:43 -0000
***************
*** 334,340 ****
#log_hostname = off
#log_temp_files = -1 # Log temporary files equal or larger
! # than the specified number of bytes.
# -1 disables; 0 logs all temp files
#---------------------------------------------------------------------------
--- 334,340 ----
#log_hostname = off
#log_temp_files = -1 # Log temporary files equal or larger
! # than the specified number of kilobytes.
# -1 disables; 0 logs all temp files
#---------------------------------------------------------------------------
Bruce Momjian <bruce@momjian.us> writes:
> Tom Lane wrote:
>> Surely the measurement unit should be kbytes or disk blocks. And why
>> aren't you using that GUC UNITS infrastructure Peter put in?
> Agreed. I have applied the following patch to make it kilobytes, and
> documented it. I didn't put '-1kB' in the postgresql.conf file because
> the -1 value is special. (ideas?)
Hmm, that could be a little bit ugly. Suggestion: redefine the value
such that files *greater than* the given size are logged, and then zero
can be the "off" position, and we need not worry about whether -1 is
-1 byte or -1 kbyte.
regards, tom lane
Tom Lane wrote: > Bruce Momjian <bruce@momjian.us> writes: > > Tom Lane wrote: > >> Surely the measurement unit should be kbytes or disk blocks. And why > >> aren't you using that GUC UNITS infrastructure Peter put in? > > > Agreed. I have applied the following patch to make it kilobytes, and > > documented it. I didn't put '-1kB' in the postgresql.conf file because > > the -1 value is special. (ideas?) > > Hmm, that could be a little bit ugly. Suggestion: redefine the value > such that files *greater than* the given size are logged, and then zero > can be the "off" position, and we need not worry about whether -1 is > -1 byte or -1 kbyte. Uh, the problem is that if you want all files logged, 1 does everything 1kb and larger, skipping a 500-byte file, for example. There are also many places where -1 is off and 0 is all, so we would be inconsistent with that too. -- Bruce Momjian bruce@momjian.us EnterpriseDB http://www.enterprisedb.com + If your life is a hard drive, Christ can be your backup. +
In response to Tom Lane <tgl@sss.pgh.pa.us>: > Bruce Momjian <bruce@momjian.us> writes: > > Tom Lane wrote: > >> Surely the measurement unit should be kbytes or disk blocks. And why > >> aren't you using that GUC UNITS infrastructure Peter put in? > > > Agreed. I have applied the following patch to make it kilobytes, and > > documented it. I didn't put '-1kB' in the postgresql.conf file because > > the -1 value is special. (ideas?) > > Hmm, that could be a little bit ugly. Suggestion: redefine the value > such that files *greater than* the given size are logged, It already is that way, with 0 effectively meaning "log all". > and then zero > can be the "off" position, and we need not worry about whether -1 is > -1 byte or -1 kbyte. All doing this does is make it impossible to log temp files of 1 byte. I thought the -1 = magic off was more intuitive. But 0 = off isn't terribly cryptic or anything. I'd considered creating two GUC variables: a boolean log_temp_files and an int log_temp_file_max_size, or something like that, but it seemed like overkill if I could just use a magic value from the int. Someone (I don't remember who) suggested that it might be useful to also have the ability to log temp files _smaller_ than a certain size. Allowing _either_ larger than _or_ smaller than will certainly complicate the config options. I had this devilish master plan that - values would be less than and positive values greater than, then I decided I was being stupid. So, that's my input. But, at this point I'm not entirely sure what the best approach is. -- Bill Moran Collaborative Fusion Inc.
Bill Moran <wmoran@collaborativefusion.com> writes:
> In response to Tom Lane <tgl@sss.pgh.pa.us>:
>> and then zero
>> can be the "off" position, and we need not worry about whether -1 is
>> -1 byte or -1 kbyte.
> All doing this does is make it impossible to log temp files of 1 byte.
How you figure that? It would make it impossible to log files of *zero*
bytes, if anyone cared about that, but not 1 byte. 1 byte > 0 kbyte.
regards, tom lane
Bill Moran <wmoran@collaborativefusion.com> writes:
> In response to Tom Lane <tgl@sss.pgh.pa.us>:
>> Hmm, that could be a little bit ugly. Suggestion: redefine the value
>> such that files *greater than* the given size are logged,
> It already is that way, with 0 effectively meaning "log all".
Oh, never mind, obviously I had my head screwed on backwards there.
Time for more caffeine.
Let's live with the -1 ... but please check that the GUC units stuff
handles setting and reading it nicely. I want to see "-1" not "-1Kb"
when I inspect the default value ...
regards, tom lane
Tom Lane wrote: > Bill Moran <wmoran@collaborativefusion.com> writes: > > In response to Tom Lane <tgl@sss.pgh.pa.us>: > >> and then zero > >> can be the "off" position, and we need not worry about whether -1 is > >> -1 byte or -1 kbyte. > > > All doing this does is make it impossible to log temp files of 1 byte. > > How you figure that? It would make it impossible to log files of *zero* > bytes, if anyone cared about that, but not 1 byte. 1 byte > 0 kbyte. Uh, if you supply just a number with no units, is that bytes or kilobytes? Do you have to say "0B". Even if we could get that to work, I don't think it is worth the inconsistency with the other GUC entries to do it. The units are mentioned in the comments in postgresql.conf. -- Bruce Momjian bruce@momjian.us EnterpriseDB http://www.enterprisedb.com + If your life is a hard drive, Christ can be your backup. +
On Tue, 2007-01-09 at 17:16 -0500, Bruce Momjian wrote:
> Tom Lane wrote:
> > > /* reset flag so that die() interrupt won't cause problems */
> > > vfdP->fdstate &= ~FD_TEMPORARY;
> > > + PG_TRACE1(temp__file__cleanup, vfdP->fileName);
> > > + if (log_temp_files >= 0)
> > > + {
> > > + if (stat(vfdP->fileName, &filestats) == 0)
> >
> > The TRACE is in the wrong place no? I thought it was going to be after
> > the stat() operation so it could pass the file size.
We had that discussion already. If you only pass it after the stat()
then you cannot use DTrace, except when you already get a message in the
log and therefore don't need DTrace. DTrace can get the filesize if it
likes, but thats up to the script author.
> > Also, I dunno much about DTrace, but I had the idea that you can't
> > simply throw a PG_TRACE macro into the source and think you are done
> > --- isn't there a file of probe declarations to add to? Not to mention
> > the documentation of what probes exist.
>
> I didn't like the macro in that area anyway. It seems too adhock to
> just throw it in when we have so few places monitored now. Removed.
err... why are we removing it? The patch should have included an
addition to the probes.d file also, but that should be fixed, not
removed. Don't we normally reject incomplete patches?
You can't say we don't have many probes so we won't add one. There never
will be many if we do that - its a circular argument.
--
Simon Riggs
EnterpriseDB http://www.enterprisedb.com
"Simon Riggs" <simon@2ndquadrant.com> writes:
>> Tom Lane wrote:
>>> The TRACE is in the wrong place no? I thought it was going to be after
>>> the stat() operation so it could pass the file size.
> We had that discussion already. If you only pass it after the stat()
> then you cannot use DTrace, except when you already get a message in the
> log and therefore don't need DTrace.
We may have had the discussion, but apparently you didn't follow it :-(.
The point of the proposal was that if you wanted to DTrace temp files you
would set log_temp_files to some large value, thus causing the stat()
call to occur but no log message to come out. This is surely a lot more
efficient than having to have DTrace open the file for itself --- and
if you don't care about micro-efficiency, what's wrong with using the
logging option?
> You can't say we don't have many probes so we won't add one. There never
> will be many if we do that - its a circular argument.
I think the real criterion has to be "is this probe useful to
developers?". I'm entirely uninterested in adding probes that are
targeted towards DBAs, as this one would have been --- if we think
there's a problem that a DBA would have, we need to offer a more
portable solution than that. Which we did, in the form of a logging
option, which makes the DTrace probe pretty useless anyway.
regards, tom lane
Simon Riggs wrote: > > > Also, I dunno much about DTrace, but I had the idea that you can't > > > simply throw a PG_TRACE macro into the source and think you are done > > > --- isn't there a file of probe declarations to add to? Not to mention > > > the documentation of what probes exist. > > > > I didn't like the macro in that area anyway. It seems too adhock to > > just throw it in when we have so few places monitored now. Removed. > > err... why are we removing it? The patch should have included an > addition to the probes.d file also, but that should be fixed, not > removed. Don't we normally reject incomplete patches? > > You can't say we don't have many probes so we won't add one. There never > will be many if we do that - its a circular argument. The trace probe was incorrect and kind of at an odd place. I don't think we want to go down the road of throwing trace in everwhere, do we? I would like to see a more systematic approach to it. -- Bruce Momjian bruce@momjian.us EnterpriseDB http://www.enterprisedb.com + If your life is a hard drive, Christ can be your backup. +
On Thu, Jan 11, 2007 at 12:35:25PM -0500, Tom Lane wrote: > I think the real criterion has to be "is this probe useful to > developers?". I'm entirely uninterested in adding probes that are > targeted towards DBAs, as this one would have been --- if we think > there's a problem that a DBA would have, we need to offer a more > portable solution than that. Which we did, in the form of a logging > option, which makes the DTrace probe pretty useless anyway. But the problem with just logging stuff is it's not a monitoring solution. Granted, it's better than nothing, but in a production environment I'd like to have some way to monitor temp file usage/utilization over time. AFAIK dtrace would provide that capability, thought I don't think it'd be unreasonable to have our own counter as well. Perhaps add temp_usage_count and temp_usage_size to pg_stat_database (number of times something spilled to disk and total size, respectively). -- Jim Nasby jim@nasby.net EnterpriseDB http://enterprisedb.com 512.569.9461 (cell)
On Thu, 2007-01-11 at 12:37 -0500, Bruce Momjian wrote: > The trace probe was incorrect Yes, incomplete, no doubt. On that point you were 100% right to reject. > and kind of at an odd place. I don't > think we want to go down the road of throwing trace in everwhere, do we? > I would like to see a more systematic approach to it. I guess my systematic approach was to add PG_TRACE to all new log points from now on, so we have a choice of which trace/log mechanism to use. I'm happy with everything but the portability of DTrace, however I'm fond of the idea of sowing seeds for the time when other solutions will work also. I've a bag of PG_TRACE trace points to add sometime soon. -- Simon Riggs EnterpriseDB http://www.enterprisedb.com
On Thu, 2007-01-11 at 12:35 -0500, Tom Lane wrote: > "Simon Riggs" <simon@2ndquadrant.com> writes: > >> Tom Lane wrote: > >>> The TRACE is in the wrong place no? I thought it was going to be after > >>> the stat() operation so it could pass the file size. > > > We had that discussion already. If you only pass it after the stat() > > then you cannot use DTrace, except when you already get a message in the > > log and therefore don't need DTrace. > > We may have had the discussion, but apparently you didn't follow it :-(. My apologies. > > You can't say we don't have many probes so we won't add one. There never > > will be many if we do that - its a circular argument. > > I think the real criterion has to be "is this probe useful to > developers?". I'm entirely uninterested in adding probes that are > targeted towards DBAs, as this one would have been --- if we think > there's a problem that a DBA would have, we need to offer a more > portable solution than that. Which we did, in the form of a logging > option, which makes the DTrace probe pretty useless anyway. Well, you know my major objection to including DTrace was all to do with portability. I'm happy that the way its been implemented allows other solutions to take advantage of the trace points also. We're working on 8.3 now and by the time that is delivered and perhaps for 2 years hence, i.e. Aug 2009, the software will be in production use. In that period, DTrace will have been ported more widely and I'm hearing that some kind of user space solution for Linux will mature in that time also. If that isn't true then I'll be more interested in some custom tracing solutions built around the PG_TRACE macro concept. My thought is to provide both a log-based trace solution as has been done, plus a hook for PG_TRACE (not just DTrace) at the same time. i.e. each time we enhance the logging infrastructure, take the time to place a trace point there also. Theologically, we both know we see things differently on the DBA v Developer discussion. The only point I would make is that the more information you give the DBA, the more comes back to you as a Developer. You, personally, could not possibly have interacted with as many server set-ups required to highlight the problems and issues you address. It's only because of the info provided by the existing system that you're able to make headway with rare optimizer problems. My perspective is that if you help the DBA you also help the Developer; if you help the Developer only, then the Developer's information is also inevitably restricted. The tip says "EXPLAIN ANALYZE is your friend". It's right, and it isn't just talking to DBAs. My feeling is that this is true for all tools/trace mechanisms. I'd rather be sent the info than have to go do it myself on an individual basis. Indirect access isn't the best way, but we harvest a much wider range of information that way. -- Simon Riggs EnterpriseDB http://www.enterprisedb.com
Hi all, Sorry for arriving so late into the discussion. I don't know if it's possible but it could be useful to have the text of the query which required the creation of the temporary files as an additional DETAIL line. At least, if it's possible to have it in this part of the code. Thoughts? -- Guillaume
Simon Riggs wrote: > On Thu, 2007-01-11 at 12:37 -0500, Bruce Momjian wrote: > > > The trace probe was incorrect > > Yes, incomplete, no doubt. On that point you were 100% right to reject. > > > and kind of at an odd place. I don't > > think we want to go down the road of throwing trace in everwhere, do we? > > I would like to see a more systematic approach to it. > > I guess my systematic approach was to add PG_TRACE to all new log points > from now on, so we have a choice of which trace/log mechanism to use. I think the right approach is to look at our existing code and come up with places we want them, and add them in one shot. Doing thing in small parts doesn't work too well with a project this size. -- Bruce Momjian bruce@momjian.us EnterpriseDB http://www.enterprisedb.com + If your life is a hard drive, Christ can be your backup. +
On Fri, 2007-01-12 at 11:44 -0500, Bruce Momjian wrote: > I think the right approach is to look at our existing code and come up > with places we want them, and add them in one shot. Doing thing > in small parts doesn't work too well with a project this size. Will do. -- Simon Riggs EnterpriseDB http://www.enterprisedb.com
Guillaume Smet wrote: > Hi all, > > Sorry for arriving so late into the discussion. > > I don't know if it's possible but it could be useful to have the text > of the query which required the creation of the temporary files as an > additional DETAIL line. At least, if it's possible to have it in this > part of the code. > > Thoughts? We have the ability to conditionally print statements based on error level, but LOG isn't a valid level for log_min_error_statement. We could add a parameter that few people would use, but the right way to do this is to log all queries. We do not allow unlimited logging control or the system would be too complex. -- Bruce Momjian bruce@momjian.us EnterpriseDB http://www.enterprisedb.com + If your life is a hard drive, Christ can be your backup. +
Hi Bruce, Thanks for your answer. On 1/12/07, Bruce Momjian <bruce@momjian.us> wrote: > We have the ability to conditionally print statements based on error > level, but LOG isn't a valid level for log_min_error_statement. > > We could add a parameter that few people would use, but the right way to > do this is to log all queries. > > We do not allow unlimited logging control or the system would be too > complex. That's not what I had in mind. I was asking if the text of the query was available when logging the temp file usage. If so it could be good to add a DETAIL line with it directly and systematically when logging the temp file usage. Sure that if you log every query, you could find which query was responsible for that temp file but I suspect that this new log feature will be used on production servers and so usually without statement logging enabled. IMHO, it's really important to know which queries are responsible for the temp file usage. If the text of the query is not available when logging the temp file usage then I agree that we cannot do anything. -- Guillaume
"Guillaume Smet" <guillaume.smet@gmail.com> writes:
> That's not what I had in mind. I was asking if the text of the query
> was available when logging the temp file usage. If so it could be good
> to add a DETAIL line with it directly and systematically when logging
> the temp file usage.
(1) you could make that argument about *any* log message whatsoever.
(2) there is already a generalized solution to this, it's called
log_min_error_statement.
regards, tom lane
Guillaume Smet wrote: > Hi Bruce, > > Thanks for your answer. > > On 1/12/07, Bruce Momjian <bruce@momjian.us> wrote: > > We have the ability to conditionally print statements based on error > > level, but LOG isn't a valid level for log_min_error_statement. > > > > We could add a parameter that few people would use, but the right way to > > do this is to log all queries. > > > > We do not allow unlimited logging control or the system would be too > > complex. > > That's not what I had in mind. I was asking if the text of the query > was available when logging the temp file usage. If so it could be good > to add a DETAIL line with it directly and systematically when logging > the temp file usage. > > Sure that if you log every query, you could find which query was > responsible for that temp file but I suspect that this new log > feature will be used on production servers and so usually without > statement logging enabled. > > IMHO, it's really important to know which queries are responsible for > the temp file usage. > > If the text of the query is not available when logging the temp file > usage then I agree that we cannot do anything. Usually people don't want th query unless they ask for it. One nify trick would be to print the query as DETAIL unless they are already logging queries, but that just seems too complex. If you want the query, why not just log them all? -- Bruce Momjian bruce@momjian.us EnterpriseDB http://www.enterprisedb.com + If your life is a hard drive, Christ can be your backup. +
On 1/12/07, Tom Lane <tgl@sss.pgh.pa.us> wrote: > "Guillaume Smet" <guillaume.smet@gmail.com> writes: > > That's not what I had in mind. I was asking if the text of the query > > was available when logging the temp file usage. If so it could be good > > to add a DETAIL line with it directly and systematically when logging > > the temp file usage. > > (1) you could make that argument about *any* log message whatsoever. Yes, probably. The fact is I can't figure out how I will use this information if I don't know why the file was created but perhaps I should just wait this release and see how I can use it in a production environment. > (2) there is already a generalized solution to this, it's called > log_min_error_statement. I didn't think of that when posting my message but Bruce seems to say that we can't use it in this case. -- Guillaume
"Guillaume Smet" <guillaume.smet@gmail.com> writes:
> On 1/12/07, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> (2) there is already a generalized solution to this, it's called
>> log_min_error_statement.
> I didn't think of that when posting my message but Bruce seems to say
> that we can't use it in this case.
Dunno why he thinks that. But there is a point here that could use
improvement: shouldn't log_min_error_statement be measured on the same
scale as log_min_messages, ie, LOG is relatively high priority rather
than relatively low priority? As the code stands, you'd have to knock
it down to DEBUG1 in order to see the statement generating a LOG
message. This might be harmless (since messages below log_min_messages
won't generate log output at all), but it's surely a bit confusing.
regards, tom lane
On 1/12/07, Bruce Momjian <bruce@momjian.us> wrote: > Usually people don't want th query unless they ask for it. One nify > trick would be to print the query as DETAIL unless they are already > logging queries, but that just seems too complex. If you want the > query, why not just log them all? Because they can't? On a highly loaded production server, people usually don't log all the queries. Anyway, if it's too complicated to implement it, perhaps it's not worth it. I'm just curious to see how people will use this information if they don't know why the temp file was created. -- Guillaume
Tom Lane wrote: > "Guillaume Smet" <guillaume.smet@gmail.com> writes: > > On 1/12/07, Tom Lane <tgl@sss.pgh.pa.us> wrote: > >> (2) there is already a generalized solution to this, it's called > >> log_min_error_statement. > > > I didn't think of that when posting my message but Bruce seems to say > > that we can't use it in this case. > > Dunno why he thinks that. But there is a point here that could use > improvement: shouldn't log_min_error_statement be measured on the same > scale as log_min_messages, ie, LOG is relatively high priority rather > than relatively low priority? As the code stands, you'd have to knock > it down to DEBUG1 in order to see the statement generating a LOG > message. This might be harmless (since messages below log_min_messages > won't generate log output at all), but it's surely a bit confusing. I assume log_min_error_messages wasn't supported because it isn't listed in the postgresql.conf file as a valid value. Let me look at adding LOG in there in the place you suggest. -- Bruce Momjian bruce@momjian.us EnterpriseDB http://www.enterprisedb.com + If your life is a hard drive, Christ can be your backup. +
In response to "Guillaume Smet" <guillaume.smet@gmail.com>: > On 1/12/07, Bruce Momjian <bruce@momjian.us> wrote: > > Usually people don't want th query unless they ask for it. One nify > > trick would be to print the query as DETAIL unless they are already > > logging queries, but that just seems too complex. If you want the > > query, why not just log them all? > > Because they can't? On a highly loaded production server, people > usually don't log all the queries. > > Anyway, if it's too complicated to implement it, perhaps it's not > worth it. I'm just curious to see how people will use this information > if they don't know why the temp file was created. I can only speak for myself but: * I'm already using the patch in our lab. Since the lab is the same hardware/config/etc as production, I can use the information to fine tune configs that then get migrated to production after careful testing. Since it's a lab environment, I'm free to turn on and off all sorts of stuff that would be unwise in production. Thus the lab frequently has full query logging turned on. * Currently, our production systems have plenty of spare IO. The result is that I _do_ log queries on production servers, and will continue to do so until it becomes an issue. Additionally, we have lots of room to grow with this hardware, so I can use the data collected about temp file usage to justify additional RAM. Don't know how long I'll be able to leave query logging enabled on the production systems, but I'm taking advantage of it as long as possible. * This variable can be tweaked per-session, which means if I've got queries that I suspect are causing unwarranted temp files on a production server, I can enable it on a per-connection basis to track down the problem and work on a specific query, on production systems, without too much disruption of the rest of the work that's going on: set log_temp_files = 0; <run suspect query> set log_temp_files = -1; <investigate logs> At least, those are my current plans ... -- Bill Moran Collaborative Fusion Inc.