Bug #928: server_min_messages (log_min_messages in CVS) have PGC_USERSET GucContext

Started by Nonamealmost 23 years ago16 messages
#1Noname
pgsql-bugs@postgresql.org

Sergey N. Yatskevich (syatskevich@n21lab.gosniias.msk.ru) reports a bug with a severity of 4
The lower the number the more severe it is.

Short Description
server_min_messages (log_min_messages in CVS) have PGC_USERSET GucContext

Long Description
In src/backend/utils/misc/guc.c "server_min_messages"
("log_min_messages" in CVS)configuration option have PGC_USERSET
GucContext. I think that it is not good idea that user can
change server log details level. I suggest change GucContext in
this case on PGC_SIGHUP.

Sample Code

No file was uploaded with this report

#2Tom Lane
tgl@sss.pgh.pa.us
In reply to: Noname (#1)
Re: Bug #928: server_min_messages (log_min_messages in CVS) have PGC_USERSET GucContext

pgsql-bugs@postgresql.org writes:

In src/backend/utils/misc/guc.c "server_min_messages"
("log_min_messages" in CVS)configuration option have PGC_USERSET
GucContext. I think that it is not good idea that user can
change server log details level. I suggest change GucContext in
this case on PGC_SIGHUP.

PGC_SUSET would be appropriate if we think that there's really a security
issue here. But ISTM this was already considered when the present setup
was designed, and we deliberately chose USERSET. Bruce, do you remember
what the reasoning was?

regards, tom lane

#3Bruce Momjian
pgman@candle.pha.pa.us
In reply to: Tom Lane (#2)
Re: Bug #928: server_min_messages (log_min_messages in CVS) have

Tom Lane wrote:

pgsql-bugs@postgresql.org writes:

In src/backend/utils/misc/guc.c "server_min_messages"
("log_min_messages" in CVS)configuration option have PGC_USERSET
GucContext. I think that it is not good idea that user can
change server log details level. I suggest change GucContext in
this case on PGC_SIGHUP.

PGC_SUSET would be appropriate if we think that there's really a security
issue here. But ISTM this was already considered when the present setup
was designed, and we deliberately chose USERSET. Bruce, do you remember
what the reasoning was?

The issue was that you might want to increase server logging in certain
clients to help debug a problem. If we had a "don't raise me" setting,
that would work.

Another idea is to add the ability to SET things perminantly.

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073
#4Neil Conway
neilc@samurai.com
In reply to: Bruce Momjian (#3)
Re: Bug #928: server_min_messages (log_min_messages in CVS)

On Sun, 2003-03-30 at 19:20, Bruce Momjian wrote:

The issue was that you might want to increase server logging in certain
clients to help debug a problem.

That seems a little obscure to me -- IMHO it's not really worth adding
additional GUC complexity to account for it. Why not just use SUSET, and
then consider how to change it if someone complains?

Cheers,

Neil

#5Bruce Momjian
pgman@candle.pha.pa.us
In reply to: Noname (#1)
Re: Bug #928: server_min_messages (log_min_messages in CVS)

pgsql-bugs@postgresql.org wrote:

Sergey N. Yatskevich (syatskevich@n21lab.gosniias.msk.ru) reports a bug with a severity of 4
The lower the number the more severe it is.

Short Description
server_min_messages (log_min_messages in CVS) have PGC_USERSET GucContext

Long Description
In src/backend/utils/misc/guc.c "server_min_messages"
("log_min_messages" in CVS)configuration option have PGC_USERSET
GucContext. I think that it is not good idea that user can
change server log details level. I suggest change GucContext in
this case on PGC_SIGHUP.

The reason it is PGC_USERSET is because we imagined people might want to
increase the amount of information sent to the server logs, and we don't
have an _increase_only_ restriction capability. However, maybe it
should be PGC_SUSET.

Comments?

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073
#6Tom Lane
tgl@sss.pgh.pa.us
In reply to: Bruce Momjian (#5)
Re: Bug #928: server_min_messages (log_min_messages in CVS)

Bruce Momjian <pgman@candle.pha.pa.us> writes:

The reason it is PGC_USERSET is because we imagined people might want to
increase the amount of information sent to the server logs, and we don't
have an _increase_only_ restriction capability. However, maybe it
should be PGC_SUSET.

Yeah, probably so. Particularly with the 7.4 error message additions,
it'd be possible to make the logs very verbose indeed, which might be
seen as a form of attack (or at least a good way to hide your traces).

regards, tom lane

#7Bruce Momjian
pgman@candle.pha.pa.us
In reply to: Tom Lane (#6)
1 attachment(s)
Re: [BUGS] Bug #928: server_min_messages (log_min_messages in CVS)

Tom Lane wrote:

Bruce Momjian <pgman@candle.pha.pa.us> writes:

The reason it is PGC_USERSET is because we imagined people might want to
increase the amount of information sent to the server logs, and we don't
have an _increase_only_ restriction capability. However, maybe it
should be PGC_SUSET.

Yeah, probably so. Particularly with the 7.4 error message additions,
it'd be possible to make the logs very verbose indeed, which might be
seen as a form of attack (or at least a good way to hide your traces).

I reviewed all the user-settable GUC variables and generated the
following patch --- there were quite a few other setting that should be
super-user only.

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073

Attachments:

/pgpatches/guctext/plainDownload
Index: src/backend/utils/misc/guc.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/utils/misc/guc.c,v
retrieving revision 1.124
diff -c -c -r1.124 guc.c
*** src/backend/utils/misc/guc.c	14 May 2003 03:26:02 -0000	1.124
--- src/backend/utils/misc/guc.c	27 May 2003 02:30:16 -0000
***************
*** 394,443 ****
  
  #ifdef USE_ASSERT_CHECKING
  	{
! 		{"debug_assertions", PGC_USERSET}, &assert_enabled,
  		true, NULL, NULL
  	},
  #endif
  
  	{
! 		{"log_statement", PGC_USERSET}, &log_statement,
  		false, NULL, NULL
  	},
  	{
! 		{"log_duration", PGC_USERSET}, &log_duration,
  		false, NULL, NULL
  	},
  	{
! 		{"debug_print_parse", PGC_USERSET}, &Debug_print_parse,
  		false, NULL, NULL
  	},
  	{
! 		{"debug_print_rewritten", PGC_USERSET}, &Debug_print_rewritten,
  		false, NULL, NULL
  	},
  	{
! 		{"debug_print_plan", PGC_USERSET}, &Debug_print_plan,
  		false, NULL, NULL
  	},
  	{
! 		{"debug_pretty_print", PGC_USERSET}, &Debug_pretty_print,
  		false, NULL, NULL
  	},
  
  	{
! 		{"log_parser_stats", PGC_USERSET}, &log_parser_stats,
  		false, NULL, NULL
  	},
  	{
! 		{"log_planner_stats", PGC_USERSET}, &log_planner_stats,
  		false, NULL, NULL
  	},
  	{
! 		{"log_executor_stats", PGC_USERSET}, &log_executor_stats,
  		false, NULL, NULL
  	},
  	{
! 		{"log_statement_stats", PGC_USERSET}, &log_statement_stats,
  		false, NULL, NULL
  	},
  #ifdef BTREE_BUILD_STATS
--- 394,443 ----
  
  #ifdef USE_ASSERT_CHECKING
  	{
! 		{"debug_assertions", PGC_SUSET}, &assert_enabled,
  		true, NULL, NULL
  	},
  #endif
  
  	{
! 		{"log_statement", PGC_SUSET}, &log_statement,
  		false, NULL, NULL
  	},
  	{
! 		{"log_duration", PGC_SUSET}, &log_duration,
  		false, NULL, NULL
  	},
  	{
! 		{"debug_print_parse", PGC_SUSET}, &Debug_print_parse,
  		false, NULL, NULL
  	},
  	{
! 		{"debug_print_rewritten", PGC_SUSET}, &Debug_print_rewritten,
  		false, NULL, NULL
  	},
  	{
! 		{"debug_print_plan", PGC_SUSET}, &Debug_print_plan,
  		false, NULL, NULL
  	},
  	{
! 		{"debug_pretty_print", PGC_SUSET}, &Debug_pretty_print,
  		false, NULL, NULL
  	},
  
  	{
! 		{"log_parser_stats", PGC_SUSET}, &log_parser_stats,
  		false, NULL, NULL
  	},
  	{
! 		{"log_planner_stats", PGC_SUSET}, &log_planner_stats,
  		false, NULL, NULL
  	},
  	{
! 		{"log_executor_stats", PGC_SUSET}, &log_executor_stats,
  		false, NULL, NULL
  	},
  	{
! 		{"log_statement_stats", PGC_SUSET}, &log_statement_stats,
  		false, NULL, NULL
  	},
  #ifdef BTREE_BUILD_STATS
***************
*** 474,480 ****
  	},
  
  	{
! 		{"trace_notify", PGC_USERSET}, &Trace_notify,
  		false, NULL, NULL
  	},
  
--- 474,480 ----
  	},
  
  	{
! 		{"trace_notify", PGC_SUSET}, &Trace_notify,
  		false, NULL, NULL
  	},
  
***************
*** 791,797 ****
  	},
  
  	{
! 		{"log_min_error_statement", PGC_USERSET}, &log_min_error_statement_str,
  		"panic", assign_min_error_statement, NULL
  	},
  
--- 791,797 ----
  	},
  
  	{
! 		{"log_min_error_statement", PGC_SUSET}, &log_min_error_statement_str,
  		"panic", assign_min_error_statement, NULL
  	},
  
***************
*** 878,884 ****
  	},
  
  	{
! 		{"log_min_messages", PGC_USERSET}, &log_min_messages_str,
  		"notice", assign_log_min_messages, NULL
  	},
  
--- 878,884 ----
  	},
  
  	{
! 		{"log_min_messages", PGC_SUSET}, &log_min_messages_str,
  		"notice", assign_log_min_messages, NULL
  	},
  
#8Tom Lane
tgl@sss.pgh.pa.us
In reply to: Bruce Momjian (#7)
Re: [BUGS] Bug #928: server_min_messages (log_min_messages in CVS)

Bruce Momjian <pgman@candle.pha.pa.us> writes:

I reviewed all the user-settable GUC variables and generated the
following patch --- there were quite a few other setting that should be
super-user only.

Where in the world did you get the idea that debug settings should be
SUSET? The log_xxx settings probably should be, but I don't agree with
the rest of these changes ...

regards, tom lane

#9Bruce Momjian
pgman@candle.pha.pa.us
In reply to: Tom Lane (#8)
1 attachment(s)
Re: [BUGS] Bug #928: server_min_messages (log_min_messages

Tom Lane wrote:

Bruce Momjian <pgman@candle.pha.pa.us> writes:

I reviewed all the user-settable GUC variables and generated the
following patch --- there were quite a few other setting that should be
super-user only.

Where in the world did you get the idea that debug settings should be
SUSET? The log_xxx settings probably should be, but I don't agree with

Do you think that is an appropriate way to respond to a patch?

the rest of these changes ...

The reason I changed the debug_ ones is that those go directly to the
server log file, not to the client. If you are worried about filling up
the server log files, those debug outputs could really fill things up
quickly. If something is going only to the server logs, does it make
sense for non-super users to be able to change it?

However, I now remember that you can set client_min_messages to DEBUG5
and see those debug messages. If we want to still allow debug_* display
to the client by non-super users, we have to give up the idea of
preventing server log filling. Of course, even with debug_ prevented,
it is still possible to fill up the log file, so probably restricting
the debug_* isn't worth it.

New patch attached, that does just the log_ ones.

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073

Attachments:

/pgpatches/guctext/plainDownload
Index: src/backend/utils/misc/guc.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/utils/misc/guc.c,v
retrieving revision 1.124
diff -c -c -r1.124 guc.c
*** src/backend/utils/misc/guc.c	14 May 2003 03:26:02 -0000	1.124
--- src/backend/utils/misc/guc.c	27 May 2003 03:46:27 -0000
***************
*** 400,410 ****
  #endif
  
  	{
! 		{"log_statement", PGC_USERSET}, &log_statement,
  		false, NULL, NULL
  	},
  	{
! 		{"log_duration", PGC_USERSET}, &log_duration,
  		false, NULL, NULL
  	},
  	{
--- 400,410 ----
  #endif
  
  	{
! 		{"log_statement", PGC_SUSET}, &log_statement,
  		false, NULL, NULL
  	},
  	{
! 		{"log_duration", PGC_SUSET}, &log_duration,
  		false, NULL, NULL
  	},
  	{
***************
*** 425,443 ****
  	},
  
  	{
! 		{"log_parser_stats", PGC_USERSET}, &log_parser_stats,
  		false, NULL, NULL
  	},
  	{
! 		{"log_planner_stats", PGC_USERSET}, &log_planner_stats,
  		false, NULL, NULL
  	},
  	{
! 		{"log_executor_stats", PGC_USERSET}, &log_executor_stats,
  		false, NULL, NULL
  	},
  	{
! 		{"log_statement_stats", PGC_USERSET}, &log_statement_stats,
  		false, NULL, NULL
  	},
  #ifdef BTREE_BUILD_STATS
--- 425,443 ----
  	},
  
  	{
! 		{"log_parser_stats", PGC_SUSET}, &log_parser_stats,
  		false, NULL, NULL
  	},
  	{
! 		{"log_planner_stats", PGC_SUSET}, &log_planner_stats,
  		false, NULL, NULL
  	},
  	{
! 		{"log_executor_stats", PGC_SUSET}, &log_executor_stats,
  		false, NULL, NULL
  	},
  	{
! 		{"log_statement_stats", PGC_SUSET}, &log_statement_stats,
  		false, NULL, NULL
  	},
  #ifdef BTREE_BUILD_STATS
***************
*** 791,797 ****
  	},
  
  	{
! 		{"log_min_error_statement", PGC_USERSET}, &log_min_error_statement_str,
  		"panic", assign_min_error_statement, NULL
  	},
  
--- 791,797 ----
  	},
  
  	{
! 		{"log_min_error_statement", PGC_SUSET}, &log_min_error_statement_str,
  		"panic", assign_min_error_statement, NULL
  	},
  
***************
*** 878,884 ****
  	},
  
  	{
! 		{"log_min_messages", PGC_USERSET}, &log_min_messages_str,
  		"notice", assign_log_min_messages, NULL
  	},
  
--- 878,884 ----
  	},
  
  	{
! 		{"log_min_messages", PGC_SUSET}, &log_min_messages_str,
  		"notice", assign_log_min_messages, NULL
  	},
  
#10Tom Lane
tgl@sss.pgh.pa.us
In reply to: Bruce Momjian (#9)
Re: [BUGS] Bug #928: server_min_messages (log_min_messages in CVS)

Bruce Momjian <pgman@candle.pha.pa.us> writes:

The reason I changed the debug_ ones is that those go directly to the
server log file, not to the client.

IIRC, all that stuff goes through elog (if there's anything left in the
standard build that writes straight to stderr, we need to be fixing the
code, not messing with GUC defaults). So AFAIK the log_min_messages
setting ought to control it all. What are you seeing that I don't?

regards, tom lane

#11Bruce Momjian
pgman@candle.pha.pa.us
In reply to: Tom Lane (#10)
Re: [BUGS] Bug #928: server_min_messages (log_min_messages

Tom Lane wrote:

Bruce Momjian <pgman@candle.pha.pa.us> writes:

The reason I changed the debug_ ones is that those go directly to the
server log file, not to the client.

IIRC, all that stuff goes through elog (if there's anything left in the
standard build that writes straight to stderr, we need to be fixing the
code, not messing with GUC defaults). So AFAIK the log_min_messages
setting ought to control it all. What are you seeing that I don't?

I tried this as a non-super user and saw the parser info in the logs.

Looking at the C code, the debug_* stuff goes to the logs as LOG.

I suppose you could set log_min_messages above LOG, but that seems too
dangerous. I don't have a problem changing only the log_* settings, but
we shouldn't assume there is any way to protect the log file. I think
we are restricting the log_* settings only so they can not be supressed
ffrom the logs.

---------------------------------------------------------------------------

test=> select current_user;
current_user
--------------
wilson
(1 row)

test=> set debug_print_parse to true;
SET
test=> select current_user;
current_user
--------------
wilson
(1 row)

test=> \q
(2) cat /u/pg/server.log
LOG: database system was shut down at 2003-05-27 00:23:02 EDT
IN: StartupXLOG (xlog.c:2510)
LOG: checkpoint record is at 0/263D924
IN: StartupXLOG (xlog.c:2538)
LOG: redo record is at 0/263D924; undo record is at 0/0; shutdown TRUE
IN: StartupXLOG (xlog.c:2558)
LOG: next transaction id: 6216; next oid: 154373
IN: StartupXLOG (xlog.c:2562)
LOG: database system is ready
IN: StartupXLOG (xlog.c:2819)
ERROR: CREATE USER: user name "wilson" already exists
IN: CreateUser (user.c:608)
ERROR: parser: parse error at or near "current_user"
IN: yyerror (scan.l:590)
LOG: parse tree:
{QUERY :commandType 1 :querySource 0 :canSetTag true :utilityStmt <>
:resultRelation 0 :into <> :hasAggs false :hasSubLinks false :rtable <>
:jointree {FROMEXPR :fromlist <> :quals <>} :rowMarks () :targetList
({TARGETENTRY :resdom {RESDOM :resno 1 :restype 19 :restypmod -1 :resname
current_user :ressortgroupref 0 :resorigtbl 0 :resorigcol 0 :resjunk false}
:expr {FUNCEXPR :funcid 745 :funcresulttype 19 :funcretset false :funcformat 0
:args <>}}) :groupClause <> :havingQual <> :distinctClause <> :sortClause <>
:limitOffset <> :limitCount <> :setOperations <> :resultRelations ()}

IN:  elog_node_display (print.c:85)
(
-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073
#12Tom Lane
tgl@sss.pgh.pa.us
In reply to: Bruce Momjian (#11)
Re: [BUGS] Bug #928: server_min_messages (log_min_messages in CVS)

Bruce Momjian <pgman@candle.pha.pa.us> writes:

Tom Lane wrote:

IIRC, all that stuff goes through elog (if there's anything left in the
standard build that writes straight to stderr, we need to be fixing the
code, not messing with GUC defaults). So AFAIK the log_min_messages
setting ought to control it all. What are you seeing that I don't?

I tried this as a non-super user and saw the parser info in the logs.

Yeah, but if log_min_messages becomes SUSET, then a non-superuser can't
force debug info into the log. At least not if we change its elevel to
DEBUG rather than LOG, which I think would be a reasonable compromise.
The real problem here is the choice of LOG as the elevel for output
controlled by the debug_xxx switches.

I suppose you could set log_min_messages above LOG, but that seems too
dangerous. I don't have a problem changing only the log_* settings, but
we shouldn't assume there is any way to protect the log file. I think
we are restricting the log_* settings only so they can not be supressed
ffrom the logs.

The thing is that I thought it was a major step forward for users to be
able to get debug info at their consoles, rather than needing access to
the system log to see it. If we make these settings SUSET then we're
taking that away again, and that's really not good.

A fuller description of what I'm thinking of:

* log_min_messages should indeed be SUSET, and also the other log_xxx
switches.

* Output controlled by a log_xxx switch should have error level LOG.

* Output controlled by a debug_xxx switch should have error level DEBUG.
These switches remain USERSET.

* Adjust all other debug output (non-switch-controlled) to have error
level DEBUG2 or below; this way, setting log_min_messages = DEBUG gets
you only the specifically requested output.

* Note in the Admin Guide that log_min_messages <= DEBUG is needed
if you want any debug_xxx output to appear in the log, and that this
setting can produce very voluminuous output.

If this seems reasonable, I can adjust the elevels while I'm making the
real-soon-now editing pass through the elog calls.

regards, tom lane

#13Bruce Momjian
pgman@candle.pha.pa.us
In reply to: Tom Lane (#12)
Re: [BUGS] Bug #928: server_min_messages (log_min_messages

Tom Lane wrote:

Bruce Momjian <pgman@candle.pha.pa.us> writes:

Tom Lane wrote:

IIRC, all that stuff goes through elog (if there's anything left in the
standard build that writes straight to stderr, we need to be fixing the
code, not messing with GUC defaults). So AFAIK the log_min_messages
setting ought to control it all. What are you seeing that I don't?

I tried this as a non-super user and saw the parser info in the logs.

Yeah, but if log_min_messages becomes SUSET, then a non-superuser can't
force debug info into the log. At least not if we change its elevel to
DEBUG rather than LOG, which I think would be a reasonable compromise.
The real problem here is the choice of LOG as the elevel for output
controlled by the debug_xxx switches.

Yes. I set debug_* output to LOG at the time I did the error leveling
because it traditionally has gone to the server logs. Now that we can
send to the client, it makes sense to move it to DEBUG1. The downside
is that setting the debug_ variables will send output _nowhere_ until
you change client_min_messages or log_min_messages. It clearly makes
the debug_* variables treat the client and serve logs the same way in
terms of output preference, and I think this makes sense. We just need
to be prepared to communicate that change in the release notes.

I suppose you could set log_min_messages above LOG, but that seems too
dangerous. I don't have a problem changing only the log_* settings, but
we shouldn't assume there is any way to protect the log file. I think
we are restricting the log_* settings only so they can not be supressed
ffrom the logs.

The thing is that I thought it was a major step forward for users to be
able to get debug info at their consoles, rather than needing access to
the system log to see it. If we make these settings SUSET then we're
taking that away again, and that's really not good.

Right.

A fuller description of what I'm thinking of:

* log_min_messages should indeed be SUSET, and also the other log_xxx
switches.

OK, will apply.

* Output controlled by a log_xxx switch should have error level LOG.

I thought it already did. If not, it certainly should.

* Output controlled by a debug_xxx switch should have error level DEBUG.
These switches remain USERSET.

OK. One issue is that I think you should make them all DEBUG1, and move
any existing DEBUG1 references to DEBUG2, perhaps moving DEBUG2 up as
well. Here are the totals for the various DEBUG* uses:

$ gid DEBUG1|wc -l
82
$ gid DEBUG2|wc -l
27
$ gid DEBUG3|wc -l
63
$ gid DEBUG4|wc -l
4
$ gid DEBUG5|wc -l
5

Seems we should push them all up, and merge DEBUG 4 and 5, and use
DEBUG1 for the debug_* output. That seems logical.

* Adjust all other debug output (non-switch-controlled) to have error
level DEBUG2 or below; this way, setting log_min_messages = DEBUG gets
you only the specifically requested output.

Oh, I see you already had that idea! :-)

* Note in the Admin Guide that log_min_messages <= DEBUG is needed
if you want any debug_xxx output to appear in the log, and that this
setting can produce very voluminuous output.

Good idea. This allows us to easily get debug_* stuff to the client
_without_ getting it in the server.

If this seems reasonable, I can adjust the elevels while I'm making the
real-soon-now editing pass through the elog calls.

I can do the change easily here. It will take just a few minutes. Let
me know and I can complete it in an hour.

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073
#14Tom Lane
tgl@sss.pgh.pa.us
In reply to: Bruce Momjian (#13)
Re: [BUGS] Bug #928: server_min_messages (log_min_messages in CVS)

Bruce Momjian <pgman@candle.pha.pa.us> writes:

Tom Lane wrote:

* Output controlled by a log_xxx switch should have error level LOG.

I thought it already did. If not, it certainly should.

I think it probably already does everywhere; I'm just trying to lay out
the policy in full.

OK. One issue is that I think you should make them all DEBUG1, and move
any existing DEBUG1 references to DEBUG2, perhaps moving DEBUG2 up as
well. Here are the totals for the various DEBUG* uses:

Something like that. I was planning to take a second look at the debug
level assignments and make sure they were all rational (ie, some
relationship between level and usefulness...)

I can do the change easily here. It will take just a few minutes. Let
me know and I can complete it in an hour.

If you like; doesn't matter to me who does it. I'm busy with a
different project today.

regards, tom lane

#15Bruce Momjian
pgman@candle.pha.pa.us
In reply to: Tom Lane (#14)
1 attachment(s)
Re: [BUGS] Bug #928: server_min_messages (log_min_messages

Tom Lane wrote:

Bruce Momjian <pgman@candle.pha.pa.us> writes:

Tom Lane wrote:

* Output controlled by a log_xxx switch should have error level LOG.

I thought it already did. If not, it certainly should.

I think it probably already does everywhere; I'm just trying to lay out
the policy in full.

OK.

OK. One issue is that I think you should make them all DEBUG1, and move
any existing DEBUG1 references to DEBUG2, perhaps moving DEBUG2 up as
well. Here are the totals for the various DEBUG* uses:

Something like that. I was planning to take a second look at the debug
level assignments and make sure they were all rational (ie, some
relationship between level and usefulness...)

OK, let me renumber them and you can still review them. I did find that
DEBUG4 was used only as a place holder, so I just shifted DEBUG1-3 to
DEBUG 2-4, and made the three debug_ variables to DEBUG1 (debug_pretty_print
doesn't count). I also did trace_notify.

I can do the change easily here. It will take just a few minutes. Let
me know and I can complete it in an hour.

If you like; doesn't matter to me who does it. I'm busy with a
different project today.

Patch attached and applied, with doc changes. This deals with filling
the server logs and makes debug_ more agnostic about its output
location.

I am focused on this today, so I might as well do it. :-)

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073

Attachments:

/bjm/difftext/plainDownload
Index: contrib/intarray/_int.c
===================================================================
RCS file: /cvsroot/pgsql-server/contrib/intarray/_int.c,v
retrieving revision 1.28
diff -c -c -r1.28 _int.c
*** contrib/intarray/_int.c	16 May 2003 18:49:51 -0000	1.28
--- contrib/intarray/_int.c	27 May 2003 17:42:43 -0000
***************
*** 110,116 ****
  	initStringInfo(&bbb);
  	for (l = 0; l < min(num, ARRNELEMS(a)); l++)
  		appendStringInfo(&bbb, "%d ", d[l]);
! 	elog(DEBUG3, "\t\t%s", bbb.data);
  	pfree(bbb.data);
  }
  static void
--- 110,116 ----
  	initStringInfo(&bbb);
  	for (l = 0; l < min(num, ARRNELEMS(a)); l++)
  		appendStringInfo(&bbb, "%d ", d[l]);
! 	elog(DEBUG4, "\t\t%s", bbb.data);
  	pfree(bbb.data);
  }
  static void
***************
*** 122,128 ****
  	str[SIGLENBIT] = '\0';
  	LOOPBIT(str[i] = (GETBIT(bv, i)) ? '1' : '0');
  
! 	elog(DEBUG3, "BV: %s", str);
  }
  #endif
  
--- 122,128 ----
  	str[SIGLENBIT] = '\0';
  	LOOPBIT(str[i] = (GETBIT(bv, i)) ? '1' : '0');
  
! 	elog(DEBUG4, "BV: %s", str);
  }
  #endif
  
***************
*** 589,595 ****
  	db = ARRPTR(b);
  
  #ifdef GIST_DEBUG
! 	elog(DEBUG3, "contains %d %d", na, nb);
  #endif
  
  	i = j = n = 0;
--- 589,595 ----
  	db = ARRPTR(b);
  
  #ifdef GIST_DEBUG
! 	elog(DEBUG4, "contains %d %d", na, nb);
  #endif
  
  	i = j = n = 0;
***************
*** 709,715 ****
  	db = ARRPTR(b);
  
  #ifdef GIST_DEBUG
! 	elog(DEBUG3, "g_int_overlap");
  #endif
  
  	i = j = 0;
--- 709,715 ----
  	db = ARRPTR(b);
  
  #ifdef GIST_DEBUG
! 	elog(DEBUG4, "g_int_overlap");
  #endif
  
  	i = j = 0;
***************
*** 1334,1340 ****
  	ArrayType  *tmp;
  
  #ifdef GIST_DEBUG
! 	elog(DEBUG3, "_int_common_union in");
  #endif
  
  	numranges = (VARSIZE(entryvec) - VARHDRSZ) / sizeof(GISTENTRY);
--- 1334,1340 ----
  	ArrayType  *tmp;
  
  #ifdef GIST_DEBUG
! 	elog(DEBUG4, "_int_common_union in");
  #endif
  
  	numranges = (VARSIZE(entryvec) - VARHDRSZ) / sizeof(GISTENTRY);
***************
*** 1355,1366 ****
  	{
  		pfree(out);
  #ifdef GIST_DEBUG
! 		elog(DEBUG3, "_int_common_union out1");
  #endif
  		return NULL;
  	}
  #ifdef GIST_DEBUG
! 	elog(DEBUG3, "_int_common_union out");
  #endif
  	return (out);
  
--- 1355,1366 ----
  	{
  		pfree(out);
  #ifdef GIST_DEBUG
! 		elog(DEBUG4, "_int_common_union out1");
  #endif
  		return NULL;
  	}
  #ifdef GIST_DEBUG
! 	elog(DEBUG4, "_int_common_union out");
  #endif
  	return (out);
  
***************
*** 1380,1386 ****
  				tmp2;
  
  #ifdef GIST_DEBUG
! 	elog(DEBUG3, "penalty");
  #endif
  	ud = (*unionf) ((ArrayType *) DatumGetPointer(origentry->key),
  					(ArrayType *) DatumGetPointer(newentry->key));
--- 1380,1386 ----
  				tmp2;
  
  #ifdef GIST_DEBUG
! 	elog(DEBUG4, "penalty");
  #endif
  	ud = (*unionf) ((ArrayType *) DatumGetPointer(origentry->key),
  					(ArrayType *) DatumGetPointer(newentry->key));
***************
*** 1390,1396 ****
  	pfree(ud);
  
  #ifdef GIST_DEBUG
! 	elog(DEBUG3, "--penalty\t%g", *result);
  #endif
  
  	return (result);
--- 1390,1396 ----
  	pfree(ud);
  
  #ifdef GIST_DEBUG
! 	elog(DEBUG4, "--penalty\t%g", *result);
  #endif
  
  	return (result);
***************
*** 1451,1457 ****
  	SPLITCOST  *costvector;
  
  #ifdef GIST_DEBUG
! 	elog(DEBUG3, "--------picksplit %d", (VARSIZE(entryvec) - VARHDRSZ) / sizeof(GISTENTRY));
  #endif
  
  	maxoff = ((VARSIZE(entryvec) - VARHDRSZ) / sizeof(GISTENTRY)) - 2;
--- 1451,1457 ----
  	SPLITCOST  *costvector;
  
  #ifdef GIST_DEBUG
! 	elog(DEBUG4, "--------picksplit %d", (VARSIZE(entryvec) - VARHDRSZ) / sizeof(GISTENTRY));
  #endif
  
  	maxoff = ((VARSIZE(entryvec) - VARHDRSZ) / sizeof(GISTENTRY)) - 2;
***************
*** 1609,1615 ****
  	v->spl_rdatum = PointerGetDatum(datum_r);
  
  #ifdef GIST_DEBUG
! 	elog(DEBUG3, "--------ENDpicksplit %d %d", v->spl_nleft, v->spl_nright);
  #endif
  	return v;
  }
--- 1609,1615 ----
  	v->spl_rdatum = PointerGetDatum(datum_r);
  
  #ifdef GIST_DEBUG
! 	elog(DEBUG4, "--------ENDpicksplit %d %d", v->spl_nleft, v->spl_nright);
  #endif
  	return v;
  }
***************
*** 1962,1968 ****
  findoprnd(ITEM * ptr, int4 *pos)
  {
  #ifdef BS_DEBUG
! 	elog(DEBUG3, (ptr[*pos].type == OPR) ?
  		 "%d  %c" : "%d  %d ", *pos, ptr[*pos].val);
  #endif
  	if (ptr[*pos].type == VAL)
--- 1962,1968 ----
  findoprnd(ITEM * ptr, int4 *pos)
  {
  #ifdef BS_DEBUG
! 	elog(DEBUG4, (ptr[*pos].type == OPR) ?
  		 "%d  %c" : "%d  %d ", *pos, ptr[*pos].val);
  #endif
  	if (ptr[*pos].type == VAL)
***************
*** 2045,2051 ****
  		else
  			appendStringInfo(&pbuf, "%d ", ptr[i].val);
  	}
! 	elog(DEBUG3, "POR: %s", pbuf.data);
  	pfree(pbuf.data);
  #endif
  
--- 2045,2051 ----
  		else
  			appendStringInfo(&pbuf, "%d ", ptr[i].val);
  	}
! 	elog(DEBUG4, "POR: %s", pbuf.data);
  	pfree(pbuf.data);
  #endif
  
Index: contrib/rserv/rserv.c
===================================================================
RCS file: /cvsroot/pgsql-server/contrib/rserv/rserv.c,v
retrieving revision 1.12
diff -c -c -r1.12 rserv.c
*** contrib/rserv/rserv.c	22 Nov 2002 16:25:30 -0000	1.12
--- contrib/rserv/rserv.c	27 May 2003 17:42:44 -0000
***************
*** 132,138 ****
  			 GetCurrentTransactionId(), deleted, rel->rd_id, okey);
  
  	if (debug)
! 		elog(DEBUG3, "sql: %s", sql);
  
  	ret = SPI_exec(sql, 0);
  
--- 132,138 ----
  			 GetCurrentTransactionId(), deleted, rel->rd_id, okey);
  
  	if (debug)
! 		elog(DEBUG4, "sql: %s", sql);
  
  	ret = SPI_exec(sql, 0);
  
***************
*** 153,159 ****
  				 deleted, okey);
  
  		if (debug)
! 			elog(DEBUG3, "sql: %s", sql);
  
  		ret = SPI_exec(sql, 0);
  
--- 153,159 ----
  				 deleted, okey);
  
  		if (debug)
! 			elog(DEBUG4, "sql: %s", sql);
  
  		ret = SPI_exec(sql, 0);
  
***************
*** 177,183 ****
  				 rel->rd_id, GetCurrentTransactionId(), okey);
  
  		if (debug)
! 			elog(DEBUG3, "sql: %s", sql);
  
  		ret = SPI_exec(sql, 0);
  
--- 177,183 ----
  				 rel->rd_id, GetCurrentTransactionId(), okey);
  
  		if (debug)
! 			elog(DEBUG4, "sql: %s", sql);
  
  		ret = SPI_exec(sql, 0);
  
Index: contrib/spi/refint.c
===================================================================
RCS file: /cvsroot/pgsql-server/contrib/spi/refint.c,v
retrieving revision 1.23
diff -c -c -r1.23 refint.c
*** contrib/spi/refint.c	3 Oct 2002 18:40:02 -0000	1.23
--- contrib/spi/refint.c	27 May 2003 17:42:44 -0000
***************
*** 59,65 ****
  	int			i;
  
  #ifdef	DEBUG_QUERY
! 	elog(DEBUG3, "Check_primary_key Enter Function");
  #endif
  
  	/*
--- 59,65 ----
  	int			i;
  
  #ifdef	DEBUG_QUERY
! 	elog(DEBUG4, "Check_primary_key Enter Function");
  #endif
  
  	/*
***************
*** 249,255 ****
  				r;
  
  #ifdef DEBUG_QUERY
! 	elog(DEBUG3, "Check_foreign_key Enter Function");
  #endif
  
  	/*
--- 249,255 ----
  				r;
  
  #ifdef DEBUG_QUERY
! 	elog(DEBUG4, "Check_foreign_key Enter Function");
  #endif
  
  	/*
***************
*** 453,459 ****
  							 strcmp(type, "date") && strcmp(type, "timestamp")) == 0)
  							is_char_type = 1;
  #ifdef	DEBUG_QUERY
! 						elog(DEBUG3, "Check_foreign_key Debug value %s type %s %d",
  							 nv, type, is_char_type);
  #endif
  
--- 453,459 ----
  							 strcmp(type, "date") && strcmp(type, "timestamp")) == 0)
  							is_char_type = 1;
  #ifdef	DEBUG_QUERY
! 						elog(DEBUG4, "Check_foreign_key Debug value %s type %s %d",
  							 nv, type, is_char_type);
  #endif
  
***************
*** 521,527 ****
  		}
  		plan->nplans = nrefs;
  #ifdef	DEBUG_QUERY
! 		elog(DEBUG3, "Check_foreign_key Debug Query is :  %s ", sql);
  #endif
  	}
  
--- 521,527 ----
  		}
  		plan->nplans = nrefs;
  #ifdef	DEBUG_QUERY
! 		elog(DEBUG4, "Check_foreign_key Debug Query is :  %s ", sql);
  #endif
  	}
  
Index: contrib/tsearch/query.c
===================================================================
RCS file: /cvsroot/pgsql-server/contrib/tsearch/query.c,v
retrieving revision 1.10
diff -c -c -r1.10 query.c
*** contrib/tsearch/query.c	10 Mar 2003 22:28:18 -0000	1.10
--- contrib/tsearch/query.c	27 May 2003 17:42:45 -0000
***************
*** 449,455 ****
  findoprnd(ITEM * ptr, int4 *pos)
  {
  #ifdef BS_DEBUG
! 	elog(DEBUG3, (ptr[*pos].type == OPR) ?
  		 "%d  %c" : "%d  %d ", *pos, ptr[*pos].val);
  #endif
  	if (ptr[*pos].type == VAL || ptr[*pos].type == VALTRUE)
--- 449,455 ----
  findoprnd(ITEM * ptr, int4 *pos)
  {
  #ifdef BS_DEBUG
! 	elog(DEBUG4, (ptr[*pos].type == OPR) ?
  		 "%d  %c" : "%d  %d ", *pos, ptr[*pos].val);
  #endif
  	if (ptr[*pos].type == VAL || ptr[*pos].type == VALTRUE)
***************
*** 557,563 ****
  			sprintf(cur, "%d(%s) ", ptr[i].val, GETOPERAND(query) + ptr[i].distance);
  		cur = strchr(cur, '\0');
  	}
! 	elog(DEBUG3, "POR: %s", pbuf);
  #endif
  
  	return query;
--- 557,563 ----
  			sprintf(cur, "%d(%s) ", ptr[i].val, GETOPERAND(query) + ptr[i].distance);
  		cur = strchr(cur, '\0');
  	}
! 	elog(DEBUG4, "POR: %s", pbuf);
  #endif
  
  	return query;
***************
*** 610,616 ****
  			sprintf(cur, "%d(%s) ", ptr[i].val, GETOPERAND(query) + ptr[i].distance);
  		cur = strchr(cur, '\0');
  	}
! 	elog(DEBUG3, "POR: %s", pbuf);
  #endif
  	pfree(res);
  	PG_RETURN_POINTER(query);
--- 610,616 ----
  			sprintf(cur, "%d(%s) ", ptr[i].val, GETOPERAND(query) + ptr[i].distance);
  		cur = strchr(cur, '\0');
  	}
! 	elog(DEBUG4, "POR: %s", pbuf);
  #endif
  	pfree(res);
  	PG_RETURN_POINTER(query);
Index: doc/src/sgml/runtime.sgml
===================================================================
RCS file: /cvsroot/pgsql-server/doc/src/sgml/runtime.sgml,v
retrieving revision 1.181
diff -c -c -r1.181 runtime.sgml
*** doc/src/sgml/runtime.sgml	23 May 2003 16:34:36 -0000	1.181
--- doc/src/sgml/runtime.sgml	27 May 2003 17:42:50 -0000
***************
*** 993,1002 ****
        <listitem>
         <para>
          These options enable various debugging output to be sent to the
!         server log. For each executed query, they print the resulting parse
!         tree, the query rewriter output, or the execution plan.
          <option>DEBUG_PRETTY_PRINT</option> indents these displays to
          produce a more readable but much longer output format.
         </para>
        </listitem>
       </varlistentry>
--- 993,1005 ----
        <listitem>
         <para>
          These options enable various debugging output to be sent to the
!         client or server log. For each executed query, they print the resulting 
!         parse tree, the query rewriter output, or the execution plan.
          <option>DEBUG_PRETTY_PRINT</option> indents these displays to
          produce a more readable but much longer output format.
+ 	<option>CLIENT_MIN_MESSAGES</option> or <option>LOG_MIN_MESSAGES</option>
+ 	must be <literal>DEBUG1</literal> or lower to send output to the client
+         or server logs.
         </para>
        </listitem>
       </varlistentry>
***************
*** 1266,1271 ****
--- 1269,1277 ----
          Generates a great amount of debugging output for the
          <command>LISTEN</command> and <command>NOTIFY</command>
          commands.
+ 	<option>CLIENT_MIN_MESSAGES</option> or <option>LOG_MIN_MESSAGES</option>
+ 	must be <literal>DEBUG1</literal> or lower to send output to the client
+         or server logs.
         </para>
        </listitem>
       </varlistentry>
Index: src/backend/access/gist/gist.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/access/gist/gist.c,v
retrieving revision 1.102
diff -c -c -r1.102 gist.c
*** src/backend/access/gist/gist.c	10 Mar 2003 22:28:18 -0000	1.102
--- src/backend/access/gist/gist.c	27 May 2003 17:42:52 -0000
***************
*** 1925,1931 ****
  
  	maxoff = PageGetMaxOffsetNumber(page);
  
! 	elog(DEBUG3, "%sPage: %d %s blk: %d maxoff: %d free: %d", pred,
  		 coff, (opaque->flags & F_LEAF) ? "LEAF" : "INTE", (int) blk,
  		 (int) maxoff, PageGetFreeSpace(page));
  
--- 1925,1931 ----
  
  	maxoff = PageGetMaxOffsetNumber(page);
  
! 	elog(DEBUG4, "%sPage: %d %s blk: %d maxoff: %d free: %d", pred,
  		 coff, (opaque->flags & F_LEAF) ? "LEAF" : "INTE", (int) blk,
  		 (int) maxoff, PageGetFreeSpace(page));
  
***************
*** 1935,1941 ****
  		which = (IndexTuple) PageGetItem(page, iid);
  		cblk = ItemPointerGetBlockNumber(&(which->t_tid));
  #ifdef PRINTTUPLE
! 		elog(DEBUG3, "%s  Tuple. blk: %d size: %d", pred, (int) cblk,
  			 IndexTupleSize(which));
  #endif
  
--- 1935,1941 ----
  		which = (IndexTuple) PageGetItem(page, iid);
  		cblk = ItemPointerGetBlockNumber(&(which->t_tid));
  #ifdef PRINTTUPLE
! 		elog(DEBUG4, "%s  Tuple. blk: %d size: %d", pred, (int) cblk,
  			 IndexTupleSize(which));
  #endif
  
Index: src/backend/access/nbtree/nbtinsert.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/access/nbtree/nbtinsert.c,v
retrieving revision 1.99
diff -c -c -r1.99 nbtinsert.c
*** src/backend/access/nbtree/nbtinsert.c	23 Feb 2003 06:17:13 -0000	1.99
--- src/backend/access/nbtree/nbtinsert.c	27 May 2003 17:42:54 -0000
***************
*** 1193,1199 ****
  			BTPageOpaque lpageop;
  
  			if (!InRecovery)
! 				elog(DEBUG1, "_bt_insert_parent: concurrent ROOT page split");
  			lpageop = (BTPageOpaque) PageGetSpecialPointer(page);
  			/* Find the leftmost page at the next level up */
  			pbuf = _bt_get_endpoint(rel, lpageop->btpo.level + 1, false);
--- 1193,1199 ----
  			BTPageOpaque lpageop;
  
  			if (!InRecovery)
! 				elog(DEBUG2, "_bt_insert_parent: concurrent ROOT page split");
  			lpageop = (BTPageOpaque) PageGetSpecialPointer(page);
  			/* Find the leftmost page at the next level up */
  			pbuf = _bt_get_endpoint(rel, lpageop->btpo.level + 1, false);
Index: src/backend/access/nbtree/nbtpage.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/access/nbtree/nbtpage.c,v
retrieving revision 1.64
diff -c -c -r1.64 nbtpage.c
*** src/backend/access/nbtree/nbtpage.c	4 Mar 2003 21:51:20 -0000	1.64
--- src/backend/access/nbtree/nbtpage.c	27 May 2003 17:42:55 -0000
***************
*** 416,422 ****
  				_bt_pageinit(page, BufferGetPageSize(buf));
  				return buf;
  			}
! 			elog(DEBUG1, "_bt_getbuf: FSM returned nonrecyclable page");
  			_bt_relbuf(rel, buf);
  		}
  
--- 416,422 ----
  				_bt_pageinit(page, BufferGetPageSize(buf));
  				return buf;
  			}
! 			elog(DEBUG2, "_bt_getbuf: FSM returned nonrecyclable page");
  			_bt_relbuf(rel, buf);
  		}
  
Index: src/backend/bootstrap/bootparse.y
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/bootstrap/bootparse.y,v
retrieving revision 1.56
diff -c -c -r1.56 bootparse.y
*** src/backend/bootstrap/bootparse.y	14 May 2003 03:26:00 -0000	1.56
--- src/backend/bootstrap/bootparse.y	27 May 2003 17:42:55 -0000
***************
*** 56,62 ****
  do_start()
  {
  	StartTransactionCommand();
! 	elog(DEBUG3, "start transaction");
  }
  
  
--- 56,62 ----
  do_start()
  {
  	StartTransactionCommand();
! 	elog(DEBUG4, "start transaction");
  }
  
  
***************
*** 64,70 ****
  do_end()
  {
  	CommitTransactionCommand();
! 	elog(DEBUG3, "commit transaction");
  	if (isatty(0))
  	{
  		printf("bootstrap> ");
--- 64,70 ----
  do_end()
  {
  	CommitTransactionCommand();
! 	elog(DEBUG4, "commit transaction");
  	if (isatty(0))
  	{
  		printf("bootstrap> ");
***************
*** 155,161 ****
  				{
  					do_start();
  					numattr = 0;
! 					elog(DEBUG3, "creating%s%s relation %s...",
  						 $2 ? " bootstrap" : "",
  						 $3 ? " shared" : "",
  						 LexIDStr($5));
--- 155,161 ----
  				{
  					do_start();
  					numattr = 0;
! 					elog(DEBUG4, "creating%s%s relation %s...",
  						 $2 ? " bootstrap" : "",
  						 $3 ? " shared" : "",
  						 LexIDStr($5));
***************
*** 176,182 ****
  					{
  						if (boot_reldesc)
  						{
! 							elog(DEBUG3, "create bootstrap: warning, open relation exists, closing first");
  							closerel(NULL);
  						}
  
--- 176,182 ----
  					{
  						if (boot_reldesc)
  						{
! 							elog(DEBUG4, "create bootstrap: warning, open relation exists, closing first");
  							closerel(NULL);
  						}
  
***************
*** 186,192 ****
  												   $3,
  												   true,
  												   true);
! 						elog(DEBUG3, "bootstrap relation created");
  					}
  					else
  					{
--- 186,192 ----
  												   $3,
  												   true,
  												   true);
! 						elog(DEBUG4, "bootstrap relation created");
  					}
  					else
  					{
***************
*** 199,205 ****
  													  $3,
  													  ONCOMMIT_NOOP,
  													  true);
! 						elog(DEBUG3, "relation created with oid %u", id);
  					}
  					do_end();
  				}
--- 199,205 ----
  													  $3,
  													  ONCOMMIT_NOOP,
  													  true);
! 						elog(DEBUG4, "relation created with oid %u", id);
  					}
  					do_end();
  				}
***************
*** 210,218 ****
  				{
  					do_start();
  					if ($2)
! 						elog(DEBUG3, "inserting row with oid %u...", $2);
  					else
! 						elog(DEBUG3, "inserting row...");
  					num_columns_read = 0;
  				}
  		  LPAREN  boot_tuplelist RPAREN
--- 210,218 ----
  				{
  					do_start();
  					if ($2)
! 						elog(DEBUG4, "inserting row with oid %u...", $2);
  					else
! 						elog(DEBUG4, "inserting row...");
  					num_columns_read = 0;
  				}
  		  LPAREN  boot_tuplelist RPAREN
Index: src/backend/bootstrap/bootstrap.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/bootstrap/bootstrap.c,v
retrieving revision 1.157
diff -c -c -r1.157 bootstrap.c
*** src/backend/bootstrap/bootstrap.c	14 May 2003 03:26:00 -0000	1.157
--- src/backend/bootstrap/bootstrap.c	27 May 2003 17:42:57 -0000
***************
*** 537,543 ****
  	if (boot_reldesc != NULL)
  		closerel(NULL);
  
! 	elog(DEBUG3, "open relation %s, attrsize %d", relname ? relname : "(null)",
  		 (int) ATTRIBUTE_TUPLE_SIZE);
  
  	boot_reldesc = heap_openr(relname, NoLock);
--- 537,543 ----
  	if (boot_reldesc != NULL)
  		closerel(NULL);
  
! 	elog(DEBUG4, "open relation %s, attrsize %d", relname ? relname : "(null)",
  		 (int) ATTRIBUTE_TUPLE_SIZE);
  
  	boot_reldesc = heap_openr(relname, NoLock);
***************
*** 553,559 ****
  		{
  			Form_pg_attribute at = attrtypes[i];
  
! 			elog(DEBUG3, "create attribute %d name %s len %d num %d type %u",
  				 i, NameStr(at->attname), at->attlen, at->attnum,
  				 at->atttypid);
  		}
--- 553,559 ----
  		{
  			Form_pg_attribute at = attrtypes[i];
  
! 			elog(DEBUG4, "create attribute %d name %s len %d num %d type %u",
  				 i, NameStr(at->attname), at->attlen, at->attnum,
  				 at->atttypid);
  		}
***************
*** 584,590 ****
  		elog(ERROR, "no open relation to close");
  	else
  	{
! 		elog(DEBUG3, "close relation %s", relname ? relname : "(null)");
  		heap_close(boot_reldesc, NoLock);
  		boot_reldesc = (Relation) NULL;
  	}
--- 584,590 ----
  		elog(ERROR, "no open relation to close");
  	else
  	{
! 		elog(DEBUG4, "close relation %s", relname ? relname : "(null)");
  		heap_close(boot_reldesc, NoLock);
  		boot_reldesc = (Relation) NULL;
  	}
***************
*** 617,623 ****
  	MemSet(attrtypes[attnum], 0, ATTRIBUTE_TUPLE_SIZE);
  
  	namestrcpy(&attrtypes[attnum]->attname, name);
! 	elog(DEBUG3, "column %s %s", NameStr(attrtypes[attnum]->attname), type);
  	attrtypes[attnum]->attnum = attnum + 1;		/* fillatt */
  
  	typeoid = gettype(type);
--- 617,623 ----
  	MemSet(attrtypes[attnum], 0, ATTRIBUTE_TUPLE_SIZE);
  
  	namestrcpy(&attrtypes[attnum]->attname, name);
! 	elog(DEBUG4, "column %s %s", NameStr(attrtypes[attnum]->attname), type);
  	attrtypes[attnum]->attnum = attnum + 1;		/* fillatt */
  
  	typeoid = gettype(type);
***************
*** 707,713 ****
  	TupleDesc	tupDesc;
  	int			i;
  
! 	elog(DEBUG3, "inserting row oid %u, %d columns", objectid, numattr);
  
  	tupDesc = CreateTupleDesc(numattr,
  							  RelationGetForm(boot_reldesc)->relhasoids,
--- 707,713 ----
  	TupleDesc	tupDesc;
  	int			i;
  
! 	elog(DEBUG4, "inserting row oid %u, %d columns", objectid, numattr);
  
  	tupDesc = CreateTupleDesc(numattr,
  							  RelationGetForm(boot_reldesc)->relhasoids,
***************
*** 719,725 ****
  
  	simple_heap_insert(boot_reldesc, tuple);
  	heap_freetuple(tuple);
! 	elog(DEBUG3, "row inserted");
  
  	/*
  	 * Reset blanks for next tuple
--- 719,725 ----
  
  	simple_heap_insert(boot_reldesc, tuple);
  	heap_freetuple(tuple);
! 	elog(DEBUG4, "row inserted");
  
  	/*
  	 * Reset blanks for next tuple
***************
*** 741,753 ****
  
  	AssertArg(i >= 0 || i < MAXATTR);
  
! 	elog(DEBUG3, "inserting column %d value '%s'", i, value);
  
  	if (Typ != (struct typmap **) NULL)
  	{
  		struct typmap *ap;
  
! 		elog(DEBUG3, "Typ != NULL");
  		app = Typ;
  		while (*app && (*app)->am_oid != boot_reldesc->rd_att->attrs[i]->atttypid)
  			++app;
--- 741,753 ----
  
  	AssertArg(i >= 0 || i < MAXATTR);
  
! 	elog(DEBUG4, "inserting column %d value '%s'", i, value);
  
  	if (Typ != (struct typmap **) NULL)
  	{
  		struct typmap *ap;
  
! 		elog(DEBUG4, "Typ != NULL");
  		app = Typ;
  		while (*app && (*app)->am_oid != boot_reldesc->rd_att->attrs[i]->atttypid)
  			++app;
***************
*** 765,771 ****
  											   values[i],
  									ObjectIdGetDatum(ap->am_typ.typelem),
  											   Int32GetDatum(-1)));
! 		elog(DEBUG3, " -> %s", prt);
  		pfree(prt);
  	}
  	else
--- 765,771 ----
  											   values[i],
  									ObjectIdGetDatum(ap->am_typ.typelem),
  											   Int32GetDatum(-1)));
! 		elog(DEBUG4, " -> %s", prt);
  		pfree(prt);
  	}
  	else
***************
*** 777,783 ****
  		}
  		if (typeindex >= n_types)
  			elog(ERROR, "type oid %u not found", attrtypes[i]->atttypid);
! 		elog(DEBUG3, "Typ == NULL, typeindex = %u", typeindex);
  		values[i] = OidFunctionCall3(Procid[typeindex].inproc,
  									 CStringGetDatum(value),
  								ObjectIdGetDatum(Procid[typeindex].elem),
--- 777,783 ----
  		}
  		if (typeindex >= n_types)
  			elog(ERROR, "type oid %u not found", attrtypes[i]->atttypid);
! 		elog(DEBUG4, "Typ == NULL, typeindex = %u", typeindex);
  		values[i] = OidFunctionCall3(Procid[typeindex].inproc,
  									 CStringGetDatum(value),
  								ObjectIdGetDatum(Procid[typeindex].elem),
***************
*** 786,795 ****
  											   values[i],
  								ObjectIdGetDatum(Procid[typeindex].elem),
  											   Int32GetDatum(-1)));
! 		elog(DEBUG3, " -> %s", prt);
  		pfree(prt);
  	}
! 	elog(DEBUG3, "inserted");
  }
  
  /* ----------------
--- 786,795 ----
  											   values[i],
  								ObjectIdGetDatum(Procid[typeindex].elem),
  											   Int32GetDatum(-1)));
! 		elog(DEBUG4, " -> %s", prt);
  		pfree(prt);
  	}
! 	elog(DEBUG4, "inserted");
  }
  
  /* ----------------
***************
*** 799,805 ****
  void
  InsertOneNull(int i)
  {
! 	elog(DEBUG3, "inserting column %d NULL", i);
  	Assert(i >= 0 || i < MAXATTR);
  	values[i] = PointerGetDatum(NULL);
  	Blanks[i] = 'n';
--- 799,805 ----
  void
  InsertOneNull(int i)
  {
! 	elog(DEBUG4, "inserting column %d NULL", i);
  	Assert(i >= 0 || i < MAXATTR);
  	values[i] = PointerGetDatum(NULL);
  	Blanks[i] = 'n';
***************
*** 893,899 ****
  			if (strncmp(type, Procid[i].name, NAMEDATALEN) == 0)
  				return i;
  		}
! 		elog(DEBUG3, "external type: %s", type);
  		rel = heap_openr(TypeRelationName, NoLock);
  		scan = heap_beginscan(rel, SnapshotNow, 0, (ScanKey) NULL);
  		i = 0;
--- 893,899 ----
  			if (strncmp(type, Procid[i].name, NAMEDATALEN) == 0)
  				return i;
  		}
! 		elog(DEBUG4, "external type: %s", type);
  		rel = heap_openr(TypeRelationName, NoLock);
  		scan = heap_beginscan(rel, SnapshotNow, 0, (ScanKey) NULL);
  		i = 0;
Index: src/backend/catalog/aclchk.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/catalog/aclchk.c,v
retrieving revision 1.80
diff -c -c -r1.80 aclchk.c
*** src/backend/catalog/aclchk.c	23 Jan 2003 23:38:55 -0000	1.80
--- src/backend/catalog/aclchk.c	27 May 2003 17:42:57 -0000
***************
*** 57,67 ****
  	int			i;
  	AclItem    *aip;
  
! 	elog(DEBUG1, "acl size = %d, # acls = %d",
  		 ACL_SIZE(acl), ACL_NUM(acl));
  	aip = ACL_DAT(acl);
  	for (i = 0; i < ACL_NUM(acl); ++i)
! 		elog(DEBUG1, "	acl[%d]: %s", i,
  			 DatumGetCString(DirectFunctionCall1(aclitemout,
  											 PointerGetDatum(aip + i))));
  }
--- 57,67 ----
  	int			i;
  	AclItem    *aip;
  
! 	elog(DEBUG2, "acl size = %d, # acls = %d",
  		 ACL_SIZE(acl), ACL_NUM(acl));
  	aip = ACL_DAT(acl);
  	for (i = 0; i < ACL_NUM(acl); ++i)
! 		elog(DEBUG2, "	acl[%d]: %s", i,
  			 DatumGetCString(DirectFunctionCall1(aclitemout,
  											 PointerGetDatum(aip + i))));
  }
***************
*** 894,900 ****
  		!usecatupd)
  	{
  #ifdef ACLDEBUG
! 		elog(DEBUG1, "pg_class_aclcheck: catalog update: permission denied");
  #endif
  		ReleaseSysCache(tuple);
  		return ACLCHECK_NO_PRIV;
--- 894,900 ----
  		!usecatupd)
  	{
  #ifdef ACLDEBUG
! 		elog(DEBUG2, "pg_class_aclcheck: catalog update: permission denied");
  #endif
  		ReleaseSysCache(tuple);
  		return ACLCHECK_NO_PRIV;
***************
*** 906,912 ****
  	if (usesuper)
  	{
  #ifdef ACLDEBUG
! 		elog(DEBUG1, "pg_class_aclcheck: %u is superuser", userid);
  #endif
  		ReleaseSysCache(tuple);
  		return ACLCHECK_OK;
--- 906,912 ----
  	if (usesuper)
  	{
  #ifdef ACLDEBUG
! 		elog(DEBUG2, "pg_class_aclcheck: %u is superuser", userid);
  #endif
  		ReleaseSysCache(tuple);
  		return ACLCHECK_OK;
Index: src/backend/catalog/dependency.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/catalog/dependency.c,v
retrieving revision 1.23
diff -c -c -r1.23 dependency.c
*** src/backend/catalog/dependency.c	6 Mar 2003 22:54:49 -0000	1.23
--- src/backend/catalog/dependency.c	27 May 2003 17:42:58 -0000
***************
*** 224,230 ****
  	 */
  	if (!deleteDependentObjects(object, objDescription,
  								DROP_CASCADE,
! 								showNotices ? NOTICE : DEBUG1,
  								&oktodelete, depRel))
  		elog(ERROR, "Failed to drop all objects depending on %s",
  			 objDescription);
--- 224,230 ----
  	 */
  	if (!deleteDependentObjects(object, objDescription,
  								DROP_CASCADE,
! 								showNotices ? NOTICE : DEBUG2,
  								&oktodelete, depRel))
  		elog(ERROR, "Failed to drop all objects depending on %s",
  			 objDescription);
***************
*** 522,528 ****
  	if (amOwned)
  	{
  		if (object_address_present(&owningObject, oktodelete))
! 			elog(DEBUG1, "Drop auto-cascades to %s",
  				 getObjectDescription(&owningObject));
  		else if (behavior == DROP_RESTRICT)
  		{
--- 522,528 ----
  	if (amOwned)
  	{
  		if (object_address_present(&owningObject, oktodelete))
! 			elog(DEBUG2, "Drop auto-cascades to %s",
  				 getObjectDescription(&owningObject));
  		else if (behavior == DROP_RESTRICT)
  		{
***************
*** 669,675 ****
  				 * In that case, act like this link is AUTO, too.
  				 */
  				if (object_address_present(&otherObject, oktodelete))
! 					elog(DEBUG1, "Drop auto-cascades to %s",
  						 getObjectDescription(&otherObject));
  				else if (behavior == DROP_RESTRICT)
  				{
--- 669,675 ----
  				 * In that case, act like this link is AUTO, too.
  				 */
  				if (object_address_present(&otherObject, oktodelete))
! 					elog(DEBUG2, "Drop auto-cascades to %s",
  						 getObjectDescription(&otherObject));
  				else if (behavior == DROP_RESTRICT)
  				{
***************
*** 694,700 ****
  				 * RESTRICT case.  (However, normal dependencies on the
  				 * component object could still cause failure.)
  				 */
! 				elog(DEBUG1, "Drop auto-cascades to %s",
  					 getObjectDescription(&otherObject));
  
  				if (!recursiveDeletion(&otherObject, behavior, msglevel,
--- 694,700 ----
  				 * RESTRICT case.  (However, normal dependencies on the
  				 * component object could still cause failure.)
  				 */
! 				elog(DEBUG2, "Drop auto-cascades to %s",
  					 getObjectDescription(&otherObject));
  
  				if (!recursiveDeletion(&otherObject, behavior, msglevel,
Index: src/backend/commands/analyze.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/commands/analyze.c,v
retrieving revision 1.53
diff -c -c -r1.53 analyze.c
*** src/backend/commands/analyze.c	25 Apr 2003 21:29:18 -0000	1.53
--- src/backend/commands/analyze.c	27 May 2003 17:43:00 -0000
***************
*** 161,167 ****
  	if (vacstmt->verbose)
  		elevel = INFO;
  	else
! 		elevel = DEBUG1;
  
  	/*
  	 * Use the current context for storing analysis info.  vacuum.c
--- 161,167 ----
  	if (vacstmt->verbose)
  		elevel = INFO;
  	else
! 		elevel = DEBUG2;
  
  	/*
  	 * Use the current context for storing analysis info.  vacuum.c
Index: src/backend/commands/async.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/commands/async.c,v
retrieving revision 1.94
diff -c -c -r1.94 async.c
*** src/backend/commands/async.c	14 May 2003 03:26:01 -0000	1.94
--- src/backend/commands/async.c	27 May 2003 17:43:01 -0000
***************
*** 150,156 ****
  Async_Notify(char *relname)
  {
  	if (Trace_notify)
! 		elog(LOG, "Async_Notify: %s", relname);
  
  	/* no point in making duplicate entries in the list ... */
  	if (!AsyncExistsPendingNotify(relname))
--- 150,156 ----
  Async_Notify(char *relname)
  {
  	if (Trace_notify)
! 		elog(DEBUG1, "Async_Notify: %s", relname);
  
  	/* no point in making duplicate entries in the list ... */
  	if (!AsyncExistsPendingNotify(relname))
***************
*** 198,204 ****
  	bool		alreadyListener = false;
  
  	if (Trace_notify)
! 		elog(LOG, "Async_Listen: %s", relname);
  
  	lRel = heap_openr(ListenerRelationName, AccessExclusiveLock);
  
--- 198,204 ----
  	bool		alreadyListener = false;
  
  	if (Trace_notify)
! 		elog(DEBUG1, "Async_Listen: %s", relname);
  
  	lRel = heap_openr(ListenerRelationName, AccessExclusiveLock);
  
***************
*** 293,299 ****
  	}
  
  	if (Trace_notify)
! 		elog(LOG, "Async_Unlisten %s", relname);
  
  	lRel = heap_openr(ListenerRelationName, AccessExclusiveLock);
  
--- 293,299 ----
  	}
  
  	if (Trace_notify)
! 		elog(DEBUG1, "Async_Unlisten %s", relname);
  
  	lRel = heap_openr(ListenerRelationName, AccessExclusiveLock);
  
***************
*** 351,357 ****
  	ScanKeyData key[1];
  
  	if (Trace_notify)
! 		elog(LOG, "Async_UnlistenAll");
  
  	lRel = heap_openr(ListenerRelationName, AccessExclusiveLock);
  	tdesc = RelationGetDescr(lRel);
--- 351,357 ----
  	ScanKeyData key[1];
  
  	if (Trace_notify)
! 		elog(DEBUG1, "Async_UnlistenAll");
  
  	lRel = heap_openr(ListenerRelationName, AccessExclusiveLock);
  	tdesc = RelationGetDescr(lRel);
***************
*** 453,459 ****
  	}
  
  	if (Trace_notify)
! 		elog(LOG, "AtCommit_Notify");
  
  	/* preset data to update notify column to MyProcPid */
  	nulls[0] = nulls[1] = nulls[2] = ' ';
--- 453,459 ----
  	}
  
  	if (Trace_notify)
! 		elog(DEBUG1, "AtCommit_Notify");
  
  	/* preset data to update notify column to MyProcPid */
  	nulls[0] = nulls[1] = nulls[2] = ' ';
***************
*** 485,498 ****
  			 */
  
  			if (Trace_notify)
! 				elog(LOG, "AtCommit_Notify: notifying self");
  
  			NotifyMyFrontEnd(relname, listenerPID);
  		}
  		else
  		{
  			if (Trace_notify)
! 				elog(LOG, "AtCommit_Notify: notifying pid %d",
  					 listenerPID);
  
  			/*
--- 485,498 ----
  			 */
  
  			if (Trace_notify)
! 				elog(DEBUG1, "AtCommit_Notify: notifying self");
  
  			NotifyMyFrontEnd(relname, listenerPID);
  		}
  		else
  		{
  			if (Trace_notify)
! 				elog(DEBUG1, "AtCommit_Notify: notifying pid %d",
  					 listenerPID);
  
  			/*
***************
*** 541,547 ****
  	ClearPendingNotifies();
  
  	if (Trace_notify)
! 		elog(LOG, "AtCommit_Notify: done");
  }
  
  /*
--- 541,547 ----
  	ClearPendingNotifies();
  
  	if (Trace_notify)
! 		elog(DEBUG1, "AtCommit_Notify: done");
  }
  
  /*
***************
*** 628,639 ****
  			{
  				/* Here, it is finally safe to do stuff. */
  				if (Trace_notify)
! 					elog(LOG, "Async_NotifyHandler: perform async notify");
  
  				ProcessIncomingNotify();
  
  				if (Trace_notify)
! 					elog(LOG, "Async_NotifyHandler: done");
  			}
  		}
  
--- 628,639 ----
  			{
  				/* Here, it is finally safe to do stuff. */
  				if (Trace_notify)
! 					elog(DEBUG1, "Async_NotifyHandler: perform async notify");
  
  				ProcessIncomingNotify();
  
  				if (Trace_notify)
! 					elog(DEBUG1, "Async_NotifyHandler: done");
  			}
  		}
  
***************
*** 707,718 ****
  		if (notifyInterruptOccurred)
  		{
  			if (Trace_notify)
! 				elog(LOG, "EnableNotifyInterrupt: perform async notify");
  
  			ProcessIncomingNotify();
  
  			if (Trace_notify)
! 				elog(LOG, "EnableNotifyInterrupt: done");
  		}
  	}
  }
--- 707,718 ----
  		if (notifyInterruptOccurred)
  		{
  			if (Trace_notify)
! 				elog(DEBUG1, "EnableNotifyInterrupt: perform async notify");
  
  			ProcessIncomingNotify();
  
  			if (Trace_notify)
! 				elog(DEBUG1, "EnableNotifyInterrupt: done");
  		}
  	}
  }
***************
*** 763,769 ****
  				nulls[Natts_pg_listener];
  
  	if (Trace_notify)
! 		elog(LOG, "ProcessIncomingNotify");
  
  	set_ps_display("async_notify");
  
--- 763,769 ----
  				nulls[Natts_pg_listener];
  
  	if (Trace_notify)
! 		elog(DEBUG1, "ProcessIncomingNotify");
  
  	set_ps_display("async_notify");
  
***************
*** 799,805 ****
  			/* Notify the frontend */
  
  			if (Trace_notify)
! 				elog(LOG, "ProcessIncomingNotify: received %s from %d",
  					 relname, (int) sourcePID);
  
  			NotifyMyFrontEnd(relname, sourcePID);
--- 799,805 ----
  			/* Notify the frontend */
  
  			if (Trace_notify)
! 				elog(DEBUG1, "ProcessIncomingNotify: received %s from %d",
  					 relname, (int) sourcePID);
  
  			NotifyMyFrontEnd(relname, sourcePID);
***************
*** 834,840 ****
  	set_ps_display("idle");
  
  	if (Trace_notify)
! 		elog(LOG, "ProcessIncomingNotify: done");
  }
  
  /*
--- 834,840 ----
  	set_ps_display("idle");
  
  	if (Trace_notify)
! 		elog(DEBUG1, "ProcessIncomingNotify: done");
  }
  
  /*
Index: src/backend/commands/vacuum.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/commands/vacuum.c,v
retrieving revision 1.253
diff -c -c -r1.253 vacuum.c
*** src/backend/commands/vacuum.c	14 May 2003 03:26:01 -0000	1.253
--- src/backend/commands/vacuum.c	27 May 2003 17:43:05 -0000
***************
*** 166,172 ****
  	if (vacstmt->verbose)
  		elevel = INFO;
  	else
! 		elevel = DEBUG1;
  
  	/*
  	 * We cannot run VACUUM inside a user transaction block; if we were
--- 166,172 ----
  	if (vacstmt->verbose)
  		elevel = INFO;
  	else
! 		elevel = DEBUG2;
  
  	/*
  	 * We cannot run VACUUM inside a user transaction block; if we were
***************
*** 1673,1679 ****
  				/* Quick exit if we have no vtlinks to search in */
  				if (vacrelstats->vtlinks == NULL)
  				{
! 					elog(DEBUG1, "Parent item in update-chain not found - can't continue repair_frag");
  					break;		/* out of walk-along-page loop */
  				}
  
--- 1673,1679 ----
  				/* Quick exit if we have no vtlinks to search in */
  				if (vacrelstats->vtlinks == NULL)
  				{
! 					elog(DEBUG2, "Parent item in update-chain not found - can't continue repair_frag");
  					break;		/* out of walk-along-page loop */
  				}
  
***************
*** 1710,1716 ****
  						 * in scan_heap(), but it's not implemented at the
  						 * moment and so we just stop shrinking here.
  						 */
! 						elog(DEBUG1, "Child itemid in update-chain marked as unused - can't continue repair_frag");
  						chain_move_failed = true;
  						break;	/* out of loop to move to chain end */
  					}
--- 1710,1716 ----
  						 * in scan_heap(), but it's not implemented at the
  						 * moment and so we just stop shrinking here.
  						 */
! 						elog(DEBUG2, "Child itemid in update-chain marked as unused - can't continue repair_frag");
  						chain_move_failed = true;
  						break;	/* out of loop to move to chain end */
  					}
***************
*** 1795,1801 ****
  					if (vtlp == NULL)
  					{
  						/* see discussion above */
! 						elog(DEBUG1, "Parent item in update-chain not found - can't continue repair_frag");
  						chain_move_failed = true;
  						break;	/* out of check-all-items loop */
  					}
--- 1795,1801 ----
  					if (vtlp == NULL)
  					{
  						/* see discussion above */
! 						elog(DEBUG2, "Parent item in update-chain not found - can't continue repair_frag");
  						chain_move_failed = true;
  						break;	/* out of check-all-items loop */
  					}
***************
*** 1831,1837 ****
  									 HeapTupleHeaderGetXmin(tp.t_data))))
  					{
  						ReleaseBuffer(Pbuf);
! 						elog(DEBUG1, "Too old parent tuple found - can't continue repair_frag");
  						chain_move_failed = true;
  						break;	/* out of check-all-items loop */
  					}
--- 1831,1837 ----
  									 HeapTupleHeaderGetXmin(tp.t_data))))
  					{
  						ReleaseBuffer(Pbuf);
! 						elog(DEBUG2, "Too old parent tuple found - can't continue repair_frag");
  						chain_move_failed = true;
  						break;	/* out of check-all-items loop */
  					}
Index: src/backend/commands/vacuumlazy.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/commands/vacuumlazy.c,v
retrieving revision 1.27
diff -c -c -r1.27 vacuumlazy.c
*** src/backend/commands/vacuumlazy.c	4 Mar 2003 21:51:21 -0000	1.27
--- src/backend/commands/vacuumlazy.c	27 May 2003 17:43:06 -0000
***************
*** 133,139 ****
  	if (vacstmt->verbose)
  		elevel = INFO;
  	else
! 		elevel = DEBUG1;
  
  	vacuum_set_xid_limits(vacstmt, onerel->rd_rel->relisshared,
  						  &OldestXmin, &FreezeLimit);
--- 133,139 ----
  	if (vacstmt->verbose)
  		elevel = INFO;
  	else
! 		elevel = DEBUG2;
  
  	vacuum_set_xid_limits(vacstmt, onerel->rd_rel->relisshared,
  						  &OldestXmin, &FreezeLimit);
Index: src/backend/executor/execAmi.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/executor/execAmi.c,v
retrieving revision 1.70
diff -c -c -r1.70 execAmi.c
*** src/backend/executor/execAmi.c	10 Mar 2003 03:53:49 -0000	1.70
--- src/backend/executor/execAmi.c	27 May 2003 17:43:06 -0000
***************
*** 208,214 ****
  
  		default:
  			/* don't make hard error unless caller asks to restore... */
! 			elog(DEBUG1, "ExecMarkPos: node type %d not supported",
  				 nodeTag(node));
  			break;
  	}
--- 208,214 ----
  
  		default:
  			/* don't make hard error unless caller asks to restore... */
! 			elog(DEBUG2, "ExecMarkPos: node type %d not supported",
  				 nodeTag(node));
  			break;
  	}
Index: src/backend/libpq/be-fsstubs.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/libpq/be-fsstubs.c,v
retrieving revision 1.63
diff -c -c -r1.63 be-fsstubs.c
*** src/backend/libpq/be-fsstubs.c	2 Sep 2002 02:47:02 -0000	1.63
--- src/backend/libpq/be-fsstubs.c	27 May 2003 17:43:07 -0000
***************
*** 81,87 ****
  	MemoryContext currentContext;
  
  #if FSDB
! 	elog(DEBUG3, "lo_open(%u,%d)", lobjId, mode);
  #endif
  
  	if (fscxt == NULL)
--- 81,87 ----
  	MemoryContext currentContext;
  
  #if FSDB
! 	elog(DEBUG4, "lo_open(%u,%d)", lobjId, mode);
  #endif
  
  	if (fscxt == NULL)
***************
*** 99,105 ****
  	{							/* lookup failed */
  		MemoryContextSwitchTo(currentContext);
  #if FSDB
! 		elog(DEBUG3, "cannot open large object %u", lobjId);
  #endif
  		PG_RETURN_INT32(-1);
  	}
--- 99,105 ----
  	{							/* lookup failed */
  		MemoryContextSwitchTo(currentContext);
  #if FSDB
! 		elog(DEBUG4, "cannot open large object %u", lobjId);
  #endif
  		PG_RETURN_INT32(-1);
  	}
***************
*** 123,129 ****
  		PG_RETURN_INT32(-1);
  	}
  #if FSDB
! 	elog(DEBUG3, "lo_close(%d)", fd);
  #endif
  
  	Assert(fscxt != NULL);
--- 123,129 ----
  		PG_RETURN_INT32(-1);
  	}
  #if FSDB
! 	elog(DEBUG4, "lo_close(%d)", fd);
  #endif
  
  	Assert(fscxt != NULL);
Index: src/backend/libpq/be-secure.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/libpq/be-secure.c,v
retrieving revision 1.32
diff -c -c -r1.32 be-secure.c
*** src/backend/libpq/be-secure.c	15 May 2003 16:35:28 -0000	1.32
--- src/backend/libpq/be-secure.c	27 May 2003 17:43:08 -0000
***************
*** 442,448 ****
  		return NULL;
  	dh = PEM_read_bio_DHparams(bio, NULL, NULL, NULL);
  	if (dh == NULL)
! 		elog(DEBUG1, "DH load buffer: %s", SSLerrmessage());
  	BIO_free(bio);
  
  	return dh;
--- 442,448 ----
  		return NULL;
  	dh = PEM_read_bio_DHparams(bio, NULL, NULL, NULL);
  	if (dh == NULL)
! 		elog(DEBUG2, "DH load buffer: %s", SSLerrmessage());
  	BIO_free(bio);
  
  	return dh;
***************
*** 514,520 ****
  	/* this may take a long time, but it may be necessary... */
  	if (r == NULL || 8 * DH_size(r) < keylength)
  	{
! 		elog(DEBUG1, "DH: generating parameters (%d bits)....", keylength);
  		r = DH_generate_parameters(keylength, DH_GENERATOR_2, NULL, NULL);
  	}
  
--- 514,520 ----
  	/* this may take a long time, but it may be necessary... */
  	if (r == NULL || 8 * DH_size(r) < keylength)
  	{
! 		elog(DEBUG2, "DH: generating parameters (%d bits)....", keylength);
  		r = DH_generate_parameters(keylength, DH_GENERATOR_2, NULL, NULL);
  	}
  
***************
*** 548,575 ****
  	switch (type)
  	{
  		case SSL_CB_HANDSHAKE_START:
! 			elog(DEBUG3, "SSL: handshake start");
  			break;
  		case SSL_CB_HANDSHAKE_DONE:
! 			elog(DEBUG3, "SSL: handshake done");
  			break;
  		case SSL_CB_ACCEPT_LOOP:
! 			elog(DEBUG3, "SSL: accept loop");
  			break;
  		case SSL_CB_ACCEPT_EXIT:
! 			elog(DEBUG3, "SSL: accept exit (%d)", args);
  			break;
  		case SSL_CB_CONNECT_LOOP:
! 			elog(DEBUG3, "SSL: connect loop");
  			break;
  		case SSL_CB_CONNECT_EXIT:
! 			elog(DEBUG3, "SSL: connect exit (%d)", args);
  			break;
  		case SSL_CB_READ_ALERT:
! 			elog(DEBUG3, "SSL: read alert (0x%04x)", args);
  			break;
  		case SSL_CB_WRITE_ALERT:
! 			elog(DEBUG3, "SSL: write alert (0x%04x)", args);
  			break;
  	}
  }
--- 548,575 ----
  	switch (type)
  	{
  		case SSL_CB_HANDSHAKE_START:
! 			elog(DEBUG4, "SSL: handshake start");
  			break;
  		case SSL_CB_HANDSHAKE_DONE:
! 			elog(DEBUG4, "SSL: handshake done");
  			break;
  		case SSL_CB_ACCEPT_LOOP:
! 			elog(DEBUG4, "SSL: accept loop");
  			break;
  		case SSL_CB_ACCEPT_EXIT:
! 			elog(DEBUG4, "SSL: accept exit (%d)", args);
  			break;
  		case SSL_CB_CONNECT_LOOP:
! 			elog(DEBUG4, "SSL: connect loop");
  			break;
  		case SSL_CB_CONNECT_EXIT:
! 			elog(DEBUG4, "SSL: connect exit (%d)", args);
  			break;
  		case SSL_CB_READ_ALERT:
! 			elog(DEBUG4, "SSL: read alert (0x%04x)", args);
  			break;
  		case SSL_CB_WRITE_ALERT:
! 			elog(DEBUG4, "SSL: write alert (0x%04x)", args);
  			break;
  	}
  }
***************
*** 702,708 ****
  				   NID_commonName, port->peer_cn, sizeof(port->peer_cn));
  		port->peer_cn[sizeof(port->peer_cn) - 1] = '\0';
  	}
! 	elog(DEBUG1, "secure connection from '%s'", port->peer_cn);
  
  	/* set up debugging/info callback */
  	SSL_CTX_set_info_callback(SSL_context, info_cb);
--- 702,708 ----
  				   NID_commonName, port->peer_cn, sizeof(port->peer_cn));
  		port->peer_cn[sizeof(port->peer_cn) - 1] = '\0';
  	}
! 	elog(DEBUG2, "secure connection from '%s'", port->peer_cn);
  
  	/* set up debugging/info callback */
  	SSL_CTX_set_info_callback(SSL_context, info_cb);
Index: src/backend/optimizer/geqo/geqo_main.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/optimizer/geqo/geqo_main.c,v
retrieving revision 1.34
diff -c -c -r1.34 geqo_main.c
*** src/backend/optimizer/geqo/geqo_main.c	20 Jan 2003 18:54:49 -0000	1.34
--- src/backend/optimizer/geqo/geqo_main.c	27 May 2003 17:43:09 -0000
***************
*** 120,149 ****
  	daddy = alloc_chromo(pool->string_length);
  
  #if defined (ERX)
! 	elog(DEBUG1, "geqo_main: using edge recombination crossover [ERX]");
  /* allocate edge table memory */
  	edge_table = alloc_edge_table(pool->string_length);
  #elif defined(PMX)
! 	elog(DEBUG1, "geqo_main: using partially matched crossover [PMX]");
  /* allocate chromosome kid memory */
  	kid = alloc_chromo(pool->string_length);
  #elif defined(CX)
! 	elog(DEBUG1, "geqo_main: using cycle crossover [CX]");
  /* allocate city table memory */
  	kid = alloc_chromo(pool->string_length);
  	city_table = alloc_city_table(pool->string_length);
  #elif defined(PX)
! 	elog(DEBUG1, "geqo_main: using position crossover [PX]");
  /* allocate city table memory */
  	kid = alloc_chromo(pool->string_length);
  	city_table = alloc_city_table(pool->string_length);
  #elif defined(OX1)
! 	elog(DEBUG1, "geqo_main: using order crossover [OX1]");
  /* allocate city table memory */
  	kid = alloc_chromo(pool->string_length);
  	city_table = alloc_city_table(pool->string_length);
  #elif defined(OX2)
! 	elog(DEBUG1, "geqo_main: using order crossover [OX2]");
  /* allocate city table memory */
  	kid = alloc_chromo(pool->string_length);
  	city_table = alloc_city_table(pool->string_length);
--- 120,149 ----
  	daddy = alloc_chromo(pool->string_length);
  
  #if defined (ERX)
! 	elog(DEBUG2, "geqo_main: using edge recombination crossover [ERX]");
  /* allocate edge table memory */
  	edge_table = alloc_edge_table(pool->string_length);
  #elif defined(PMX)
! 	elog(DEBUG2, "geqo_main: using partially matched crossover [PMX]");
  /* allocate chromosome kid memory */
  	kid = alloc_chromo(pool->string_length);
  #elif defined(CX)
! 	elog(DEBUG2, "geqo_main: using cycle crossover [CX]");
  /* allocate city table memory */
  	kid = alloc_chromo(pool->string_length);
  	city_table = alloc_city_table(pool->string_length);
  #elif defined(PX)
! 	elog(DEBUG2, "geqo_main: using position crossover [PX]");
  /* allocate city table memory */
  	kid = alloc_chromo(pool->string_length);
  	city_table = alloc_city_table(pool->string_length);
  #elif defined(OX1)
! 	elog(DEBUG2, "geqo_main: using order crossover [OX1]");
  /* allocate city table memory */
  	kid = alloc_chromo(pool->string_length);
  	city_table = alloc_city_table(pool->string_length);
  #elif defined(OX2)
! 	elog(DEBUG2, "geqo_main: using order crossover [OX2]");
  /* allocate city table memory */
  	kid = alloc_chromo(pool->string_length);
  	city_table = alloc_city_table(pool->string_length);
Index: src/backend/optimizer/path/clausesel.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/optimizer/path/clausesel.c,v
retrieving revision 1.57
diff -c -c -r1.57 clausesel.c
*** src/backend/optimizer/path/clausesel.c	3 Feb 2003 21:15:44 -0000	1.57
--- src/backend/optimizer/path/clausesel.c	27 May 2003 17:43:09 -0000
***************
*** 550,556 ****
  	}
  
  #ifdef SELECTIVITY_DEBUG
! 	elog(DEBUG3, "clause_selectivity: s1 %f", s1);
  #endif   /* SELECTIVITY_DEBUG */
  
  	return s1;
--- 550,556 ----
  	}
  
  #ifdef SELECTIVITY_DEBUG
! 	elog(DEBUG4, "clause_selectivity: s1 %f", s1);
  #endif   /* SELECTIVITY_DEBUG */
  
  	return s1;
Index: src/backend/optimizer/path/indxpath.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/optimizer/path/indxpath.c,v
retrieving revision 1.140
diff -c -c -r1.140 indxpath.c
*** src/backend/optimizer/path/indxpath.c	26 May 2003 00:11:27 -0000	1.140
--- src/backend/optimizer/path/indxpath.c	27 May 2003 17:43:12 -0000
***************
*** 1279,1285 ****
  	if (isNull)
  	{
  		/* Treat a null result as false ... but it's a tad fishy ... */
! 		elog(DEBUG1, "pred_test_simple_clause: null test result");
  		return false;
  	}
  	return DatumGetBool(test_result);
--- 1279,1285 ----
  	if (isNull)
  	{
  		/* Treat a null result as false ... but it's a tad fishy ... */
! 		elog(DEBUG2, "pred_test_simple_clause: null test result");
  		return false;
  	}
  	return DatumGetBool(test_result);
Index: src/backend/postmaster/postmaster.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/postmaster/postmaster.c,v
retrieving revision 1.328
diff -c -c -r1.328 postmaster.c
*** src/backend/postmaster/postmaster.c	15 May 2003 16:35:29 -0000	1.328
--- src/backend/postmaster/postmaster.c	27 May 2003 17:43:15 -0000
***************
*** 631,641 ****
  		extern char **environ;
  		char	  **p;
  
! 		elog(DEBUG2, "%s: PostmasterMain: initial environ dump:", progname);
! 		elog(DEBUG2, "-----------------------------------------");
  		for (p = environ; *p; ++p)
! 			elog(DEBUG2, "\t%s", *p);
! 		elog(DEBUG2, "-----------------------------------------");
  	}
  
  	/*
--- 631,641 ----
  		extern char **environ;
  		char	  **p;
  
! 		elog(DEBUG3, "%s: PostmasterMain: initial environ dump:", progname);
! 		elog(DEBUG3, "-----------------------------------------");
  		for (p = environ; *p; ++p)
! 			elog(DEBUG3, "\t%s", *p);
! 		elog(DEBUG3, "-----------------------------------------");
  	}
  
  	/*
***************
*** 1407,1413 ****
  
  	if (backendPID == CheckPointPID)
  	{
! 		elog(DEBUG1, "processCancelRequest: CheckPointPID in cancel request for process %d", backendPID);
  		return;
  	}
  	else if (ExecBackend)
--- 1407,1413 ----
  
  	if (backendPID == CheckPointPID)
  	{
! 		elog(DEBUG2, "processCancelRequest: CheckPointPID in cancel request for process %d", backendPID);
  		return;
  	}
  	else if (ExecBackend)
***************
*** 1425,1444 ****
  			if (bp->cancel_key == cancelAuthCode)
  			{
  				/* Found a match; signal that backend to cancel current op */
! 				elog(DEBUG1, "processing cancel request: sending SIGINT to process %d",
  					 backendPID);
  				kill(bp->pid, SIGINT);
  			}
  			else
  				/* Right PID, wrong key: no way, Jose */
! 				elog(DEBUG1, "bad key in cancel request for process %d",
  					 backendPID);
  			return;
  		}
  	}
  
  	/* No matching backend */
! 	elog(DEBUG1, "bad pid in cancel request for process %d", backendPID);
  }
  
  /*
--- 1425,1444 ----
  			if (bp->cancel_key == cancelAuthCode)
  			{
  				/* Found a match; signal that backend to cancel current op */
! 				elog(DEBUG2, "processing cancel request: sending SIGINT to process %d",
  					 backendPID);
  				kill(bp->pid, SIGINT);
  			}
  			else
  				/* Right PID, wrong key: no way, Jose */
! 				elog(DEBUG2, "bad key in cancel request for process %d",
  					 backendPID);
  			return;
  		}
  	}
  
  	/* No matching backend */
! 	elog(DEBUG2, "bad pid in cancel request for process %d", backendPID);
  }
  
  /*
***************
*** 1603,1609 ****
  
  	PG_SETMASK(&BlockSig);
  
! 	elog(DEBUG1, "pmdie %d", postgres_signal_arg);
  
  	switch (postgres_signal_arg)
  	{
--- 1603,1609 ----
  
  	PG_SETMASK(&BlockSig);
  
! 	elog(DEBUG2, "pmdie %d", postgres_signal_arg);
  
  	switch (postgres_signal_arg)
  	{
***************
*** 1727,1733 ****
  
  	PG_SETMASK(&BlockSig);
  
! 	elog(DEBUG3, "reaping dead processes");
  #ifdef HAVE_WAITPID
  	while ((pid = waitpid(-1, &status, WNOHANG)) > 0)
  	{
--- 1727,1733 ----
  
  	PG_SETMASK(&BlockSig);
  
! 	elog(DEBUG4, "reaping dead processes");
  #ifdef HAVE_WAITPID
  	while ((pid = waitpid(-1, &status, WNOHANG)) > 0)
  	{
***************
*** 1863,1869 ****
  			   *next;
  	Backend    *bp;
  
! 	LogChildExit(DEBUG1, gettext("child process"), pid, exitstatus);
  
  	/*
  	 * If a backend dies in an ugly way (i.e. exit status not 0) then we
--- 1863,1869 ----
  			   *next;
  	Backend    *bp;
  
! 	LogChildExit(DEBUG2, gettext("child process"), pid, exitstatus);
  
  	/*
  	 * If a backend dies in an ugly way (i.e. exit status not 0) then we
***************
*** 1933,1939 ****
  			 */
  			if (!FatalError)
  			{
! 				elog(DEBUG1, "CleanupProc: sending %s to process %d",
  					 (SendStop ? "SIGSTOP" : "SIGQUIT"), (int) bp->pid);
  				kill(bp->pid, (SendStop ? SIGSTOP : SIGQUIT));
  			}
--- 1933,1939 ----
  			 */
  			if (!FatalError)
  			{
! 				elog(DEBUG2, "CleanupProc: sending %s to process %d",
  					 (SendStop ? "SIGSTOP" : "SIGQUIT"), (int) bp->pid);
  				kill(bp->pid, (SendStop ? SIGSTOP : SIGQUIT));
  			}
***************
*** 2005,2011 ****
  
  		if (bp->pid != MyProcPid)
  		{
! 			elog(DEBUG1, "SignalChildren: sending signal %d to process %d",
  				 signal, (int) bp->pid);
  			kill(bp->pid, signal);
  		}
--- 2005,2011 ----
  
  		if (bp->pid != MyProcPid)
  		{
! 			elog(DEBUG2, "SignalChildren: sending signal %d to process %d",
  				 signal, (int) bp->pid);
  			kill(bp->pid, signal);
  		}
***************
*** 2097,2103 ****
  	}
  
  	/* in parent, normal */
! 	elog(DEBUG1, "BackendStartup: forked pid=%d socket=%d", (int) pid,
  		 port->sock);
  
  	/*
--- 2097,2103 ----
  	}
  
  	/* in parent, normal */
! 	elog(DEBUG2, "BackendStartup: forked pid=%d socket=%d", (int) pid,
  		 port->sock);
  
  	/*
***************
*** 2469,2478 ****
  	/*
  	 * Debug: print arguments being passed to backend
  	 */
! 	elog(DEBUG2, "%s child[%d]: starting with (", progname, MyProcPid);
  	for (i = 0; i < ac; ++i)
! 		elog(DEBUG2, "\t%s", av[i]);
! 	elog(DEBUG2, ")");
  
  	ClientAuthInProgress = false;		/* client_min_messages is active
  										 * now */
--- 2469,2478 ----
  	/*
  	 * Debug: print arguments being passed to backend
  	 */
! 	elog(DEBUG3, "%s child[%d]: starting with (", progname, MyProcPid);
  	for (i = 0; i < ac; ++i)
! 		elog(DEBUG3, "\t%s", av[i]);
! 	elog(DEBUG3, ")");
  
  	ClientAuthInProgress = false;		/* client_min_messages is active
  										 * now */
Index: src/backend/storage/ipc/ipc.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/storage/ipc/ipc.c,v
retrieving revision 1.81
diff -c -c -r1.81 ipc.c
*** src/backend/storage/ipc/ipc.c	4 Sep 2002 20:31:25 -0000	1.81
--- src/backend/storage/ipc/ipc.c	27 May 2003 17:43:15 -0000
***************
*** 92,98 ****
  	InterruptHoldoffCount = 1;
  	CritSectionCount = 0;
  
! 	elog(DEBUG2, "proc_exit(%d)", code);
  
  	/* do our shared memory exits first */
  	shmem_exit(code);
--- 92,98 ----
  	InterruptHoldoffCount = 1;
  	CritSectionCount = 0;
  
! 	elog(DEBUG3, "proc_exit(%d)", code);
  
  	/* do our shared memory exits first */
  	shmem_exit(code);
***************
*** 110,116 ****
  		(*on_proc_exit_list[on_proc_exit_index].function) (code,
  							  on_proc_exit_list[on_proc_exit_index].arg);
  
! 	elog(DEBUG2, "exit(%d)", code);
  	exit(code);
  }
  
--- 110,116 ----
  		(*on_proc_exit_list[on_proc_exit_index].function) (code,
  							  on_proc_exit_list[on_proc_exit_index].arg);
  
! 	elog(DEBUG3, "exit(%d)", code);
  	exit(code);
  }
  
***************
*** 123,129 ****
  void
  shmem_exit(int code)
  {
! 	elog(DEBUG2, "shmem_exit(%d)", code);
  
  	/*
  	 * call all the registered callbacks.
--- 123,129 ----
  void
  shmem_exit(int code)
  {
! 	elog(DEBUG3, "shmem_exit(%d)", code);
  
  	/*
  	 * call all the registered callbacks.
Index: src/backend/storage/ipc/ipci.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/storage/ipc/ipci.c,v
retrieving revision 1.52
diff -c -c -r1.52 ipci.c
*** src/backend/storage/ipc/ipci.c	3 May 2003 03:52:07 -0000	1.52
--- src/backend/storage/ipc/ipci.c	27 May 2003 17:43:16 -0000
***************
*** 70,76 ****
  	/* might as well round it off to a multiple of a typical page size */
  	size += 8192 - (size % 8192);
  
! 	elog(DEBUG2, "invoking IpcMemoryCreate(size=%d)", size);
  
  	/*
  	 * Create the shmem segment
--- 70,76 ----
  	/* might as well round it off to a multiple of a typical page size */
  	size += 8192 - (size % 8192);
  
! 	elog(DEBUG3, "invoking IpcMemoryCreate(size=%d)", size);
  
  	/*
  	 * Create the shmem segment
Index: src/backend/storage/ipc/shmqueue.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/storage/ipc/shmqueue.c,v
retrieving revision 1.23
diff -c -c -r1.23 shmqueue.c
*** src/backend/storage/ipc/shmqueue.c	7 Jan 2003 22:23:17 -0000	1.23
--- src/backend/storage/ipc/shmqueue.c	27 May 2003 17:43:16 -0000
***************
*** 229,235 ****
  	}
  	snprintf(elem, sizeof(elem), "--->%lx", MAKE_OFFSET(q));
  	strcat(buf, elem);
! 	elog(DEBUG1, "%s: %s", s, buf);
  
  	snprintf(buf, sizeof(buf), "q nexts: %lx", MAKE_OFFSET(q));
  	count = 0;
--- 229,235 ----
  	}
  	snprintf(elem, sizeof(elem), "--->%lx", MAKE_OFFSET(q));
  	strcat(buf, elem);
! 	elog(DEBUG2, "%s: %s", s, buf);
  
  	snprintf(buf, sizeof(buf), "q nexts: %lx", MAKE_OFFSET(q));
  	count = 0;
***************
*** 249,255 ****
  	}
  	snprintf(elem, sizeof(elem), "--->%lx", MAKE_OFFSET(q));
  	strcat(buf, elem);
! 	elog(DEBUG1, "%s: %s", s, buf);
  }
  
  #endif   /* SHMQUEUE_DEBUG */
--- 249,255 ----
  	}
  	snprintf(elem, sizeof(elem), "--->%lx", MAKE_OFFSET(q));
  	strcat(buf, elem);
! 	elog(DEBUG2, "%s: %s", s, buf);
  }
  
  #endif   /* SHMQUEUE_DEBUG */
Index: src/backend/storage/ipc/sinval.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/storage/ipc/sinval.c,v
retrieving revision 1.54
diff -c -c -r1.54 sinval.c
*** src/backend/storage/ipc/sinval.c	23 Feb 2003 23:20:52 -0000	1.54
--- src/backend/storage/ipc/sinval.c	27 May 2003 17:43:16 -0000
***************
*** 65,71 ****
  	insertOK = SIInsertDataEntry(shmInvalBuffer, msg);
  	LWLockRelease(SInvalLock);
  	if (!insertOK)
! 		elog(DEBUG3, "SendSharedInvalidMessage: SI buffer overflow");
  }
  
  /*
--- 65,71 ----
  	insertOK = SIInsertDataEntry(shmInvalBuffer, msg);
  	LWLockRelease(SInvalLock);
  	if (!insertOK)
! 		elog(DEBUG4, "SendSharedInvalidMessage: SI buffer overflow");
  }
  
  /*
***************
*** 108,114 ****
  		if (getResult < 0)
  		{
  			/* got a reset message */
! 			elog(DEBUG3, "ReceiveSharedInvalidMessages: cache state reset");
  			resetFunction();
  		}
  		else
--- 108,114 ----
  		if (getResult < 0)
  		{
  			/* got a reset message */
! 			elog(DEBUG4, "ReceiveSharedInvalidMessages: cache state reset");
  			resetFunction();
  		}
  		else
Index: src/backend/storage/ipc/sinvaladt.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/storage/ipc/sinvaladt.c,v
retrieving revision 1.49
diff -c -c -r1.49 sinvaladt.c
*** src/backend/storage/ipc/sinvaladt.c	21 Nov 2002 06:36:08 -0000	1.49
--- src/backend/storage/ipc/sinvaladt.c	27 May 2003 17:43:16 -0000
***************
*** 121,127 ****
  	MyBackendId = (stateP - &segP->procState[0]) + 1;
  
  #ifdef	INVALIDDEBUG
! 	elog(DEBUG1, "SIBackendInit: backend id %d", MyBackendId);
  #endif   /* INVALIDDEBUG */
  
  	/* Reduce free slot count */
--- 121,127 ----
  	MyBackendId = (stateP - &segP->procState[0]) + 1;
  
  #ifdef	INVALIDDEBUG
! 	elog(DEBUG2, "SIBackendInit: backend id %d", MyBackendId);
  #endif   /* INVALIDDEBUG */
  
  	/* Reduce free slot count */
***************
*** 226,232 ****
  	if (numMsgs == (MAXNUMMESSAGES * 70 / 100) &&
  		IsUnderPostmaster)
  	{
! 		elog(DEBUG3, "SIInsertDataEntry: table is 70%% full, signaling postmaster");
  		SendPostmasterSignal(PMSIGNAL_WAKEN_CHILDREN);
  	}
  
--- 226,232 ----
  	if (numMsgs == (MAXNUMMESSAGES * 70 / 100) &&
  		IsUnderPostmaster)
  	{
! 		elog(DEBUG4, "SIInsertDataEntry: table is 70%% full, signaling postmaster");
  		SendPostmasterSignal(PMSIGNAL_WAKEN_CHILDREN);
  	}
  
Index: src/backend/tcop/postgres.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/tcop/postgres.c,v
retrieving revision 1.345
diff -c -c -r1.345 postgres.c
*** src/backend/tcop/postgres.c	14 May 2003 18:40:37 -0000	1.345
--- src/backend/tcop/postgres.c	27 May 2003 17:43:20 -0000
***************
*** 513,519 ****
  		Query	   *querytree = (Query *) lfirst(list_item);
  
  		if (Debug_print_parse)
! 			elog_node_display(LOG, "parse tree", querytree,
  							  Debug_pretty_print);
  
  		if (querytree->commandType == CMD_UTILITY)
--- 513,519 ----
  		Query	   *querytree = (Query *) lfirst(list_item);
  
  		if (Debug_print_parse)
! 			elog_node_display(DEBUG1, "parse tree", querytree,
  							  Debug_pretty_print);
  
  		if (querytree->commandType == CMD_UTILITY)
***************
*** 550,556 ****
  #endif
  
  	if (Debug_print_rewritten)
! 		elog_node_display(LOG, "rewritten parse tree", querytree_list,
  						  Debug_pretty_print);
  
  	return querytree_list;
--- 550,556 ----
  #endif
  
  	if (Debug_print_rewritten)
! 		elog_node_display(DEBUG1, "rewritten parse tree", querytree_list,
  						  Debug_pretty_print);
  
  	return querytree_list;
***************
*** 599,605 ****
  	 * Print plan if debugging.
  	 */
  	if (Debug_print_plan)
! 		elog_node_display(LOG, "plan", plan, Debug_pretty_print);
  
  	return plan;
  }
--- 599,605 ----
  	 * Print plan if debugging.
  	 */
  	if (Debug_print_plan)
! 		elog_node_display(DEBUG1, "plan", plan, Debug_pretty_print);
  
  	return plan;
  }
***************
*** 1650,1656 ****
  {
  	if (!xact_started)
  	{
! 		elog(DEBUG2, "StartTransactionCommand");
  		StartTransactionCommand();
  
  		/* Set statement timeout running, if any */
--- 1650,1656 ----
  {
  	if (!xact_started)
  	{
! 		elog(DEBUG3, "StartTransactionCommand");
  		StartTransactionCommand();
  
  		/* Set statement timeout running, if any */
***************
*** 1673,1679 ****
  		disable_sig_alarm(true);
  
  		/* Now commit the command */
! 		elog(DEBUG2, "CommitTransactionCommand");
  
  		CommitTransactionCommand();
  
--- 1673,1679 ----
  		disable_sig_alarm(true);
  
  		/* Now commit the command */
! 		elog(DEBUG3, "CommitTransactionCommand");
  
  		CommitTransactionCommand();
  
***************
*** 2503,2509 ****
  	 * putting it inside InitPostgres() instead.  In particular, anything
  	 * that involves database access should be there, not here.
  	 */
! 	elog(DEBUG2, "InitPostgres");
  	InitPostgres(dbname, username);
  
  	SetProcessingMode(NormalProcessing);
--- 2503,2509 ----
  	 * putting it inside InitPostgres() instead.  In particular, anything
  	 * that involves database access should be there, not here.
  	 */
! 	elog(DEBUG3, "InitPostgres");
  	InitPostgres(dbname, username);
  
  	SetProcessingMode(NormalProcessing);
***************
*** 2585,2591 ****
  		MemoryContextSwitchTo(ErrorContext);
  
  		/* Do the recovery */
! 		elog(DEBUG1, "AbortCurrentTransaction");
  		AbortCurrentTransaction();
  
  		/*
--- 2585,2591 ----
  		MemoryContextSwitchTo(ErrorContext);
  
  		/* Do the recovery */
! 		elog(DEBUG2, "AbortCurrentTransaction");
  		AbortCurrentTransaction();
  
  		/*
Index: src/backend/tcop/pquery.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/tcop/pquery.c,v
retrieving revision 1.64
diff -c -c -r1.64 pquery.c
*** src/backend/tcop/pquery.c	8 May 2003 18:16:36 -0000	1.64
--- src/backend/tcop/pquery.c	27 May 2003 17:43:20 -0000
***************
*** 702,708 ****
  {
  	Node   *utilityStmt = query->utilityStmt;
  
! 	elog(DEBUG2, "ProcessUtility");
  
  	/*
  	 * Set snapshot if utility stmt needs one.  Most reliable
--- 702,708 ----
  {
  	Node   *utilityStmt = query->utilityStmt;
  
! 	elog(DEBUG3, "ProcessUtility");
  
  	/*
  	 * Set snapshot if utility stmt needs one.  Most reliable
***************
*** 806,812 ****
  			/*
  			 * process a plannable query.
  			 */
! 			elog(DEBUG2, "ProcessQuery");
  
  			/* Must always set snapshot for plannable queries */
  			SetQuerySnapshot();
--- 806,812 ----
  			/*
  			 * process a plannable query.
  			 */
! 			elog(DEBUG3, "ProcessQuery");
  
  			/* Must always set snapshot for plannable queries */
  			SetQuerySnapshot();
Index: src/backend/utils/adt/varbit.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/utils/adt/varbit.c,v
retrieving revision 1.30
diff -c -c -r1.30 varbit.c
*** src/backend/utils/adt/varbit.c	12 May 2003 23:08:50 -0000	1.30
--- src/backend/utils/adt/varbit.c	27 May 2003 17:43:21 -0000
***************
*** 1321,1327 ****
  					mask2 = end_mask << (BITS_PER_BYTE - is);
  					is_match = mask2 == 0;
  #if 0
! 					elog(DEBUG3, "S. %d %d em=%2x sm=%2x r=%d",
  						 i, is, end_mask, mask2, is_match);
  #endif
  					break;
--- 1321,1327 ----
  					mask2 = end_mask << (BITS_PER_BYTE - is);
  					is_match = mask2 == 0;
  #if 0
! 					elog(DEBUG4, "S. %d %d em=%2x sm=%2x r=%d",
  						 i, is, end_mask, mask2, is_match);
  #endif
  					break;
Index: src/backend/utils/cache/catcache.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/utils/cache/catcache.c,v
retrieving revision 1.102
diff -c -c -r1.102 catcache.c
*** src/backend/utils/cache/catcache.c	13 Nov 2002 00:39:47 -0000	1.102
--- src/backend/utils/cache/catcache.c	27 May 2003 17:43:23 -0000
***************
*** 164,170 ****
  {
  	uint32		hashValue = 0;
  
! 	CACHE4_elog(DEBUG1, "CatalogCacheComputeHashValue %s %d %p",
  				cache->cc_relname,
  				nkeys,
  				cache);
--- 164,170 ----
  {
  	uint32		hashValue = 0;
  
! 	CACHE4_elog(DEBUG2, "CatalogCacheComputeHashValue %s %d %p",
  				cache->cc_relname,
  				nkeys,
  				cache);
***************
*** 281,294 ****
  	long		cc_lsearches = 0;
  	long		cc_lhits = 0;
  
! 	elog(DEBUG1, "Catcache stats dump: %d/%d tuples in catcaches",
  		 CacheHdr->ch_ntup, CacheHdr->ch_maxtup);
  
  	for (cache = CacheHdr->ch_caches; cache; cache = cache->cc_next)
  	{
  		if (cache->cc_ntup == 0 && cache->cc_searches == 0)
  			continue;			/* don't print unused caches */
! 		elog(DEBUG1, "Catcache %s/%s: %d tup, %ld srch, %ld+%ld=%ld hits, %ld+%ld=%ld loads, %ld invals, %ld discards, %ld lsrch, %ld lhits",
  			 cache->cc_relname,
  			 cache->cc_indname,
  			 cache->cc_ntup,
--- 281,294 ----
  	long		cc_lsearches = 0;
  	long		cc_lhits = 0;
  
! 	elog(DEBUG2, "Catcache stats dump: %d/%d tuples in catcaches",
  		 CacheHdr->ch_ntup, CacheHdr->ch_maxtup);
  
  	for (cache = CacheHdr->ch_caches; cache; cache = cache->cc_next)
  	{
  		if (cache->cc_ntup == 0 && cache->cc_searches == 0)
  			continue;			/* don't print unused caches */
! 		elog(DEBUG2, "Catcache %s/%s: %d tup, %ld srch, %ld+%ld=%ld hits, %ld+%ld=%ld loads, %ld invals, %ld discards, %ld lsrch, %ld lhits",
  			 cache->cc_relname,
  			 cache->cc_indname,
  			 cache->cc_ntup,
***************
*** 312,318 ****
  		cc_lsearches += cache->cc_lsearches;
  		cc_lhits += cache->cc_lhits;
  	}
! 	elog(DEBUG1, "Catcache totals: %d tup, %ld srch, %ld+%ld=%ld hits, %ld+%ld=%ld loads, %ld invals, %ld discards, %ld lsrch, %ld lhits",
  		 CacheHdr->ch_ntup,
  		 cc_searches,
  		 cc_hits,
--- 312,318 ----
  		cc_lsearches += cache->cc_lsearches;
  		cc_lhits += cache->cc_lhits;
  	}
! 	elog(DEBUG2, "Catcache totals: %d tup, %ld srch, %ld+%ld=%ld hits, %ld+%ld=%ld loads, %ld invals, %ld discards, %ld lsrch, %ld lhits",
  		 CacheHdr->ch_ntup,
  		 cc_searches,
  		 cc_hits,
***************
*** 419,425 ****
  	 * sanity checks
  	 */
  	Assert(ItemPointerIsValid(pointer));
! 	CACHE1_elog(DEBUG1, "CatalogCacheIdInvalidate: called");
  
  	/*
  	 * inspect caches to find the proper cache
--- 419,425 ----
  	 * sanity checks
  	 */
  	Assert(ItemPointerIsValid(pointer));
! 	CACHE1_elog(DEBUG2, "CatalogCacheIdInvalidate: called");
  
  	/*
  	 * inspect caches to find the proper cache
***************
*** 476,482 ****
  					ct->dead = true;
  				else
  					CatCacheRemoveCTup(ccp, ct);
! 				CACHE1_elog(DEBUG1, "CatalogCacheIdInvalidate: invalidated");
  #ifdef CATCACHE_STATS
  				ccp->cc_invals++;
  #endif
--- 476,482 ----
  					ct->dead = true;
  				else
  					CatCacheRemoveCTup(ccp, ct);
! 				CACHE1_elog(DEBUG2, "CatalogCacheIdInvalidate: invalidated");
  #ifdef CATCACHE_STATS
  				ccp->cc_invals++;
  #endif
***************
*** 641,652 ****
  {
  	CatCache   *cache;
  
! 	CACHE1_elog(DEBUG1, "ResetCatalogCaches called");
  
  	for (cache = CacheHdr->ch_caches; cache; cache = cache->cc_next)
  		ResetCatalogCache(cache);
  
! 	CACHE1_elog(DEBUG1, "end of ResetCatalogCaches call");
  }
  
  /*
--- 641,652 ----
  {
  	CatCache   *cache;
  
! 	CACHE1_elog(DEBUG2, "ResetCatalogCaches called");
  
  	for (cache = CacheHdr->ch_caches; cache; cache = cache->cc_next)
  		ResetCatalogCache(cache);
  
! 	CACHE1_elog(DEBUG2, "end of ResetCatalogCaches call");
  }
  
  /*
***************
*** 674,680 ****
  {
  	CatCache   *cache;
  
! 	CACHE2_elog(DEBUG1, "CatalogCacheFlushRelation called for %u", relId);
  
  	for (cache = CacheHdr->ch_caches; cache; cache = cache->cc_next)
  	{
--- 674,680 ----
  {
  	CatCache   *cache;
  
! 	CACHE2_elog(DEBUG2, "CatalogCacheFlushRelation called for %u", relId);
  
  	for (cache = CacheHdr->ch_caches; cache; cache = cache->cc_next)
  	{
***************
*** 744,750 ****
  		}
  	}
  
! 	CACHE1_elog(DEBUG1, "end of CatalogCacheFlushRelation call");
  }
  
  /*
--- 744,750 ----
  		}
  	}
  
! 	CACHE1_elog(DEBUG2, "end of CatalogCacheFlushRelation call");
  }
  
  /*
***************
*** 756,769 ****
   *	structure initialized on the first access.
   */
  #ifdef CACHEDEBUG
! #define InitCatCache_DEBUG1 \
  do { \
! 	elog(DEBUG1, "InitCatCache: rel=%s id=%d nkeys=%d size=%d\n", \
  		cp->cc_relname, cp->id, cp->cc_nkeys, cp->cc_nbuckets); \
  } while(0)
  
  #else
! #define InitCatCache_DEBUG1
  #endif
  
  CatCache *
--- 756,769 ----
   *	structure initialized on the first access.
   */
  #ifdef CACHEDEBUG
! #define InitCatCache_DEBUG2 \
  do { \
! 	elog(DEBUG2, "InitCatCache: rel=%s id=%d nkeys=%d size=%d\n", \
  		cp->cc_relname, cp->id, cp->cc_nkeys, cp->cc_nbuckets); \
  } while(0)
  
  #else
! #define InitCatCache_DEBUG2
  #endif
  
  CatCache *
***************
*** 832,838 ****
  	 * new cache is initialized as far as we can go for now. print some
  	 * debugging information, if appropriate.
  	 */
! 	InitCatCache_DEBUG1;
  
  	/*
  	 * add completed cache to top of group header's list
--- 832,838 ----
  	 * new cache is initialized as far as we can go for now. print some
  	 * debugging information, if appropriate.
  	 */
! 	InitCatCache_DEBUG2;
  
  	/*
  	 * add completed cache to top of group header's list
***************
*** 856,879 ****
   * that the relcache entry can be opened at this point!
   */
  #ifdef CACHEDEBUG
! #define CatalogCacheInitializeCache_DEBUG1 \
! 	elog(DEBUG1, "CatalogCacheInitializeCache: cache @%p %s", cache, \
  		 cache->cc_relname)
  
  #define CatalogCacheInitializeCache_DEBUG2 \
  do { \
  		if (cache->cc_key[i] > 0) { \
! 			elog(DEBUG1, "CatalogCacheInitializeCache: load %d/%d w/%d, %u", \
  				i+1, cache->cc_nkeys, cache->cc_key[i], \
  				 tupdesc->attrs[cache->cc_key[i] - 1]->atttypid); \
  		} else { \
! 			elog(DEBUG1, "CatalogCacheInitializeCache: load %d/%d w/%d", \
  				i+1, cache->cc_nkeys, cache->cc_key[i]); \
  		} \
  } while(0)
  
  #else
! #define CatalogCacheInitializeCache_DEBUG1
  #define CatalogCacheInitializeCache_DEBUG2
  #endif
  
--- 856,879 ----
   * that the relcache entry can be opened at this point!
   */
  #ifdef CACHEDEBUG
! #define CatalogCacheInitializeCache_DEBUG2 \
! 	elog(DEBUG2, "CatalogCacheInitializeCache: cache @%p %s", cache, \
  		 cache->cc_relname)
  
  #define CatalogCacheInitializeCache_DEBUG2 \
  do { \
  		if (cache->cc_key[i] > 0) { \
! 			elog(DEBUG2, "CatalogCacheInitializeCache: load %d/%d w/%d, %u", \
  				i+1, cache->cc_nkeys, cache->cc_key[i], \
  				 tupdesc->attrs[cache->cc_key[i] - 1]->atttypid); \
  		} else { \
! 			elog(DEBUG2, "CatalogCacheInitializeCache: load %d/%d w/%d", \
  				i+1, cache->cc_nkeys, cache->cc_key[i]); \
  		} \
  } while(0)
  
  #else
! #define CatalogCacheInitializeCache_DEBUG2
  #define CatalogCacheInitializeCache_DEBUG2
  #endif
  
***************
*** 885,891 ****
  	TupleDesc	tupdesc;
  	int			i;
  
! 	CatalogCacheInitializeCache_DEBUG1;
  
  	/*
  	 * Open the relation without locking --- we only need the tupdesc,
--- 885,891 ----
  	TupleDesc	tupdesc;
  	int			i;
  
! 	CatalogCacheInitializeCache_DEBUG2;
  
  	/*
  	 * Open the relation without locking --- we only need the tupdesc,
***************
*** 920,926 ****
  
  	heap_close(relation, NoLock);
  
! 	CACHE3_elog(DEBUG1, "CatalogCacheInitializeCache: %s, %d keys",
  				cache->cc_relname, cache->cc_nkeys);
  
  	/*
--- 920,926 ----
  
  	heap_close(relation, NoLock);
  
! 	CACHE3_elog(DEBUG2, "CatalogCacheInitializeCache: %s, %d keys",
  				cache->cc_relname, cache->cc_nkeys);
  
  	/*
***************
*** 958,964 ****
  		/* Initialize sk_attno suitably for HeapKeyTest() and heap scans */
  		cache->cc_skey[i].sk_attno = cache->cc_key[i];
  
! 		CACHE4_elog(DEBUG1, "CatalogCacheInit %s %d %p",
  					cache->cc_relname,
  					i,
  					cache);
--- 958,964 ----
  		/* Initialize sk_attno suitably for HeapKeyTest() and heap scans */
  		cache->cc_skey[i].sk_attno = cache->cc_key[i];
  
! 		CACHE4_elog(DEBUG2, "CatalogCacheInit %s %d %p",
  					cache->cc_relname,
  					i,
  					cache);
***************
*** 1150,1156 ****
  		{
  			ct->refcount++;
  
! 			CACHE3_elog(DEBUG1, "SearchCatCache(%s): found in bucket %d",
  						cache->cc_relname, hashIndex);
  
  #ifdef CATCACHE_STATS
--- 1150,1156 ----
  		{
  			ct->refcount++;
  
! 			CACHE3_elog(DEBUG2, "SearchCatCache(%s): found in bucket %d",
  						cache->cc_relname, hashIndex);
  
  #ifdef CATCACHE_STATS
***************
*** 1161,1167 ****
  		}
  		else
  		{
! 			CACHE3_elog(DEBUG1, "SearchCatCache(%s): found neg entry in bucket %d",
  						cache->cc_relname, hashIndex);
  
  #ifdef CATCACHE_STATS
--- 1161,1167 ----
  		}
  		else
  		{
! 			CACHE3_elog(DEBUG2, "SearchCatCache(%s): found neg entry in bucket %d",
  						cache->cc_relname, hashIndex);
  
  #ifdef CATCACHE_STATS
***************
*** 1223,1231 ****
  									 true);
  		heap_freetuple(ntp);
  
! 		CACHE4_elog(DEBUG1, "SearchCatCache(%s): Contains %d/%d tuples",
  					cache->cc_relname, cache->cc_ntup, CacheHdr->ch_ntup);
! 		CACHE3_elog(DEBUG1, "SearchCatCache(%s): put neg entry in bucket %d",
  					cache->cc_relname, hashIndex);
  
  		/*
--- 1223,1231 ----
  									 true);
  		heap_freetuple(ntp);
  
! 		CACHE4_elog(DEBUG2, "SearchCatCache(%s): Contains %d/%d tuples",
  					cache->cc_relname, cache->cc_ntup, CacheHdr->ch_ntup);
! 		CACHE3_elog(DEBUG2, "SearchCatCache(%s): put neg entry in bucket %d",
  					cache->cc_relname, hashIndex);
  
  		/*
***************
*** 1237,1245 ****
  		return NULL;
  	}
  
! 	CACHE4_elog(DEBUG1, "SearchCatCache(%s): Contains %d/%d tuples",
  				cache->cc_relname, cache->cc_ntup, CacheHdr->ch_ntup);
! 	CACHE3_elog(DEBUG1, "SearchCatCache(%s): put in bucket %d",
  				cache->cc_relname, hashIndex);
  
  #ifdef CATCACHE_STATS
--- 1237,1245 ----
  		return NULL;
  	}
  
! 	CACHE4_elog(DEBUG2, "SearchCatCache(%s): Contains %d/%d tuples",
  				cache->cc_relname, cache->cc_ntup, CacheHdr->ch_ntup);
! 	CACHE3_elog(DEBUG2, "SearchCatCache(%s): put in bucket %d",
  				cache->cc_relname, hashIndex);
  
  #ifdef CATCACHE_STATS
***************
*** 1388,1394 ****
  		/* Bump the list's refcount and return it */
  		cl->refcount++;
  
! 		CACHE2_elog(DEBUG1, "SearchCatCacheList(%s): found list",
  					cache->cc_relname);
  
  #ifdef CATCACHE_STATS
--- 1388,1394 ----
  		/* Bump the list's refcount and return it */
  		cl->refcount++;
  
! 		CACHE2_elog(DEBUG2, "SearchCatCacheList(%s): found list",
  					cache->cc_relname);
  
  #ifdef CATCACHE_STATS
***************
*** 1510,1516 ****
  
  	DLAddHead(&cache->cc_lists, &cl->cache_elem);
  
! 	CACHE3_elog(DEBUG1, "SearchCatCacheList(%s): made list of %d members",
  				cache->cc_relname, nmembers);
  
  	return cl;
--- 1510,1516 ----
  
  	DLAddHead(&cache->cc_lists, &cl->cache_elem);
  
! 	CACHE3_elog(DEBUG2, "SearchCatCacheList(%s): made list of %d members",
  				cache->cc_relname, nmembers);
  
  	return cl;
***************
*** 1613,1619 ****
  
  			if (oldct->refcount == 0)
  			{
! 				CACHE2_elog(DEBUG1, "CatCacheCreateEntry(%s): Overflow, LRU removal",
  							cache->cc_relname);
  #ifdef CATCACHE_STATS
  				oldct->my_cache->cc_discards++;
--- 1613,1619 ----
  
  			if (oldct->refcount == 0)
  			{
! 				CACHE2_elog(DEBUG2, "CatCacheCreateEntry(%s): Overflow, LRU removal",
  							cache->cc_relname);
  #ifdef CATCACHE_STATS
  				oldct->my_cache->cc_discards++;
***************
*** 1731,1737 ****
  	CatCache   *ccp;
  	Oid			reloid;
  
! 	CACHE1_elog(DEBUG1, "PrepareToInvalidateCacheTuple: called");
  
  	/*
  	 * sanity checks
--- 1731,1737 ----
  	CatCache   *ccp;
  	Oid			reloid;
  
! 	CACHE1_elog(DEBUG2, "PrepareToInvalidateCacheTuple: called");
  
  	/*
  	 * sanity checks
Index: src/backend/utils/fmgr/dfmgr.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/utils/fmgr/dfmgr.c,v
retrieving revision 1.59
diff -c -c -r1.59 dfmgr.c
*** src/backend/utils/fmgr/dfmgr.c	5 Apr 2003 19:54:12 -0000	1.59
--- src/backend/utils/fmgr/dfmgr.c	27 May 2003 17:43:23 -0000
***************
*** 402,408 ****
  		sprintf(full, "%s/%s", mangled, basename);
  		pfree(mangled);
  
! 		elog(DEBUG2, "find_in_dynamic_libpath: trying %s", full);
  
  		if (file_exists(full))
  			return full;
--- 402,408 ----
  		sprintf(full, "%s/%s", mangled, basename);
  		pfree(mangled);
  
! 		elog(DEBUG3, "find_in_dynamic_libpath: trying %s", full);
  
  		if (file_exists(full))
  			return full;
Index: src/backend/utils/init/findbe.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/utils/init/findbe.c,v
retrieving revision 1.33
diff -c -c -r1.33 findbe.c
*** src/backend/utils/init/findbe.c	15 May 2003 16:35:29 -0000	1.33
--- src/backend/utils/init/findbe.c	27 May 2003 17:43:23 -0000
***************
*** 62,74 ****
  	 */
  	if (stat(path, &buf) < 0)
  	{
! 		elog(DEBUG2, "ValidateBinary: can't stat \"%s\"", path);
  		return -1;
  	}
  
  	if ((buf.st_mode & S_IFMT) != S_IFREG)
  	{
! 		elog(DEBUG2, "ValidateBinary: \"%s\" is not a regular file", path);
  		return -1;
  	}
  
--- 62,74 ----
  	 */
  	if (stat(path, &buf) < 0)
  	{
! 		elog(DEBUG3, "ValidateBinary: can't stat \"%s\"", path);
  		return -1;
  	}
  
  	if ((buf.st_mode & S_IFMT) != S_IFREG)
  	{
! 		elog(DEBUG3, "ValidateBinary: \"%s\" is not a regular file", path);
  		return -1;
  	}
  
***************
*** 95,101 ****
  		is_r = buf.st_mode & S_IRUSR;
  		is_x = buf.st_mode & S_IXUSR;
  		if (!(is_r && is_x))
! 			elog(DEBUG2, "ValidateBinary: \"%s\" is not user read/execute", path);
  		return is_x ? (is_r ? 0 : -2) : -1;
  	}
  	pwp = getpwuid(euid);
--- 95,101 ----
  		is_r = buf.st_mode & S_IRUSR;
  		is_x = buf.st_mode & S_IXUSR;
  		if (!(is_r && is_x))
! 			elog(DEBUG3, "ValidateBinary: \"%s\" is not user read/execute", path);
  		return is_x ? (is_r ? 0 : -2) : -1;
  	}
  	pwp = getpwuid(euid);
***************
*** 121,127 ****
  			is_r = buf.st_mode & S_IRGRP;
  			is_x = buf.st_mode & S_IXGRP;
  			if (!(is_r && is_x))
! 				elog(DEBUG2, "ValidateBinary: \"%s\" is not group read/execute",
  					 path);
  			return is_x ? (is_r ? 0 : -2) : -1;
  		}
--- 121,127 ----
  			is_r = buf.st_mode & S_IRGRP;
  			is_x = buf.st_mode & S_IXGRP;
  			if (!(is_r && is_x))
! 				elog(DEBUG3, "ValidateBinary: \"%s\" is not group read/execute",
  					 path);
  			return is_x ? (is_r ? 0 : -2) : -1;
  		}
***************
*** 129,135 ****
  	is_r = buf.st_mode & S_IROTH;
  	is_x = buf.st_mode & S_IXOTH;
  	if (!(is_r && is_x))
! 		elog(DEBUG2, "ValidateBinary: \"%s\" is not other read/execute",
  			 path);
  	return is_x ? (is_r ? 0 : -2) : -1;
  #endif
--- 129,135 ----
  	is_r = buf.st_mode & S_IROTH;
  	is_x = buf.st_mode & S_IXOTH;
  	if (!(is_r && is_x))
! 		elog(DEBUG3, "ValidateBinary: \"%s\" is not other read/execute",
  			 path);
  	return is_x ? (is_r ? 0 : -2) : -1;
  #endif
***************
*** 179,185 ****
  		if (ValidateBinary(buf) == 0)
  		{
  			strncpy(full_path, buf, MAXPGPATH);
! 			elog(DEBUG1, "FindExec: found \"%s\" using argv[0]", full_path);
  			return 0;
  		}
  		elog(LOG, "FindExec: invalid binary \"%s\"", buf);
--- 179,185 ----
  		if (ValidateBinary(buf) == 0)
  		{
  			strncpy(full_path, buf, MAXPGPATH);
! 			elog(DEBUG2, "FindExec: found \"%s\" using argv[0]", full_path);
  			return 0;
  		}
  		elog(LOG, "FindExec: invalid binary \"%s\"", buf);
***************
*** 192,198 ****
  	 */
  	if ((p = getenv("PATH")) && *p)
  	{
! 		elog(DEBUG1, "FindExec: searching PATH ...");
  		path = strdup(p);		/* make a modifiable copy */
  		for (startp = path, endp = strchr(path, ':');
  			 startp && *startp;
--- 192,198 ----
  	 */
  	if ((p = getenv("PATH")) && *p)
  	{
! 		elog(DEBUG2, "FindExec: searching PATH ...");
  		path = strdup(p);		/* make a modifiable copy */
  		for (startp = path, endp = strchr(path, ':');
  			 startp && *startp;
***************
*** 213,219 ****
  			{
  				case 0: /* found ok */
  					strncpy(full_path, buf, MAXPGPATH);
! 					elog(DEBUG1, "FindExec: found \"%s\" using PATH",
  						 full_path);
  					free(path);
  					return 0;
--- 213,219 ----
  			{
  				case 0: /* found ok */
  					strncpy(full_path, buf, MAXPGPATH);
! 					elog(DEBUG2, "FindExec: found \"%s\" using PATH",
  						 full_path);
  					free(path);
  					return 0;
Index: src/backend/utils/misc/guc-file.l
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/utils/misc/guc-file.l,v
retrieving revision 1.14
diff -c -c -r1.14 guc-file.l
*** src/backend/utils/misc/guc-file.l	8 Nov 2002 20:23:57 -0000	1.14
--- src/backend/utils/misc/guc-file.l	27 May 2003 17:43:25 -0000
***************
*** 136,142 ****
  	Assert(context == PGC_POSTMASTER || context == PGC_BACKEND 
  		|| context == PGC_SIGHUP);
  	Assert(DataDir);
! 	elevel = (context == PGC_SIGHUP) ? DEBUG3 : ERROR;
  
  	/*
  	 * Open file
--- 136,142 ----
  	Assert(context == PGC_POSTMASTER || context == PGC_BACKEND 
  		|| context == PGC_SIGHUP);
  	Assert(DataDir);
! 	elevel = (context == PGC_SIGHUP) ? DEBUG4 : ERROR;
  
  	/*
  	 * Open file
Index: src/backend/utils/misc/guc.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/utils/misc/guc.c,v
retrieving revision 1.124
diff -c -c -r1.124 guc.c
*** src/backend/utils/misc/guc.c	14 May 2003 03:26:02 -0000	1.124
--- src/backend/utils/misc/guc.c	27 May 2003 17:43:27 -0000
***************
*** 1721,1727 ****
  	bool		makeDefault;
  
  	if (context == PGC_SIGHUP || source == PGC_S_DEFAULT)
! 		elevel = DEBUG1;
  	else if (source == PGC_S_DATABASE || source == PGC_S_USER)
  		elevel = INFO;
  	else
--- 1721,1727 ----
  	bool		makeDefault;
  
  	if (context == PGC_SIGHUP || source == PGC_S_DEFAULT)
! 		elevel = DEBUG2;
  	else if (source == PGC_S_DATABASE || source == PGC_S_USER)
  		elevel = INFO;
  	else
***************
*** 1830,1836 ****
  	{
  		if (DoIt && !makeDefault)
  		{
! 			elog(DEBUG2, "%s: setting ignored because previous source is higher priority",
  				 name);
  			return true;
  		}
--- 1830,1836 ----
  	{
  		if (DoIt && !makeDefault)
  		{
! 			elog(DEBUG3, "%s: setting ignored because previous source is higher priority",
  				 name);
  			return true;
  		}
***************
*** 2855,2861 ****
  
  	Assert(context == PGC_POSTMASTER || context == PGC_SIGHUP);
  	Assert(DataDir);
! 	elevel = (context == PGC_SIGHUP) ? DEBUG3 : ERROR;
  
  	/*
  	 * Open file
--- 2855,2861 ----
  
  	Assert(context == PGC_POSTMASTER || context == PGC_SIGHUP);
  	Assert(DataDir);
! 	elevel = (context == PGC_SIGHUP) ? DEBUG4 : ERROR;
  
  	/*
  	 * Open file
***************
*** 3366,3372 ****
  	if (strcasecmp(newval, "debug") == 0)
  	{
  		if (doit)
! 			(*var) = DEBUG1;
  	}
  	else if (strcasecmp(newval, "debug5") == 0)
  	{
--- 3366,3372 ----
  	if (strcasecmp(newval, "debug") == 0)
  	{
  		if (doit)
! 			(*var) = DEBUG2;
  	}
  	else if (strcasecmp(newval, "debug5") == 0)
  	{
Index: src/include/utils/elog.h
===================================================================
RCS file: /cvsroot/pgsql-server/src/include/utils/elog.h,v
retrieving revision 1.43
diff -c -c -r1.43 elog.h
*** src/include/utils/elog.h	22 May 2003 17:20:43 -0000	1.43
--- src/include/utils/elog.h	27 May 2003 17:43:28 -0000
***************
*** 20,26 ****
  #define DEBUG4		11
  #define DEBUG3		12
  #define DEBUG2		13
! #define DEBUG1		14
  #define LOG			15			/* Server operational messages; sent only
  								 * to server log by default. */
  #define COMMERROR	16			/* Client communication problems; same as
--- 20,26 ----
  #define DEBUG4		11
  #define DEBUG3		12
  #define DEBUG2		13
! #define DEBUG1		14			/* used by GUC debug_* variables */
  #define LOG			15			/* Server operational messages; sent only
  								 * to server log by default. */
  #define COMMERROR	16			/* Client communication problems; same as
Index: src/pl/plperl/eloglvl.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/pl/plperl/eloglvl.c,v
retrieving revision 1.7
diff -c -c -r1.7 eloglvl.c
*** src/pl/plperl/eloglvl.c	4 Sep 2002 20:31:47 -0000	1.7
--- src/pl/plperl/eloglvl.c	27 May 2003 17:43:29 -0000
***************
*** 13,19 ****
  int
  elog_DEBUG(void)
  {
! 	return DEBUG1;
  }
  
  int
--- 13,19 ----
  int
  elog_DEBUG(void)
  {
! 	return DEBUG2;
  }
  
  int
Index: src/pl/plpgsql/src/gram.y
===================================================================
RCS file: /cvsroot/pgsql-server/src/pl/plpgsql/src/gram.y,v
retrieving revision 1.43
diff -c -c -r1.43 gram.y
*** src/pl/plpgsql/src/gram.y	5 May 2003 16:46:27 -0000	1.43
--- src/pl/plpgsql/src/gram.y	27 May 2003 17:43:30 -0000
***************
*** 1294,1300 ****
  					}
  				| K_DEBUG
  					{
! 						$$ = DEBUG1;
  					}
  				;
  
--- 1294,1300 ----
  					}
  				| K_DEBUG
  					{
! 						$$ = DEBUG2;
  					}
  				;
  
Index: src/pl/plpython/plpython.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/pl/plpython/plpython.c,v
retrieving revision 1.31
diff -c -c -r1.31 plpython.c
*** src/pl/plpython/plpython.c	10 Mar 2003 22:28:22 -0000	1.31
--- src/pl/plpython/plpython.c	27 May 2003 17:43:33 -0000
***************
*** 2661,2667 ****
  PyObject *
  PLy_debug(PyObject * self, PyObject * args)
  {
! 	return PLy_output(DEBUG1, self, args);
  }
  
  PyObject *
--- 2661,2667 ----
  PyObject *
  PLy_debug(PyObject * self, PyObject * args)
  {
! 	return PLy_output(DEBUG2, self, args);
  }
  
  PyObject *
Index: src/pl/plpython/plpython.h
===================================================================
RCS file: /cvsroot/pgsql-server/src/pl/plpython/plpython.h,v
retrieving revision 1.6
diff -c -c -r1.6 plpython.h
*** src/pl/plpython/plpython.h	6 Mar 2002 06:10:48 -0000	1.6
--- src/pl/plpython/plpython.h	27 May 2003 17:43:33 -0000
***************
*** 43,50 ****
  
  #if DEBUG_LEVEL
  #define CALL_LEVEL_INC() do { PLy_call_level += 1; \
! 	elog(DEBUG3, "Level: %d", PLy_call_level); } while (0)
! #define CALL_LEVEL_DEC() do { elog(DEBUG3, "Level: %d", PLy_call_level); \
  	PLy_call_level -= 1; } while (0)
  #else
  #define CALL_LEVEL_INC() do { PLy_call_level += 1; } while (0)
--- 43,50 ----
  
  #if DEBUG_LEVEL
  #define CALL_LEVEL_INC() do { PLy_call_level += 1; \
! 	elog(DEBUG4, "Level: %d", PLy_call_level); } while (0)
! #define CALL_LEVEL_DEC() do { elog(DEBUG4, "Level: %d", PLy_call_level); \
  	PLy_call_level -= 1; } while (0)
  #else
  #define CALL_LEVEL_INC() do { PLy_call_level += 1; } while (0)
***************
*** 54,63 ****
  /* temporary debugging macros
   */
  #if DEBUG_LEVEL
! #define enter() elog(DEBUG3, "Enter(%d): %s", func_enter_calls++,__FUNCTION__)
! #define leave() elog(DEBUG3, "Leave(%d): %s", func_leave_calls++,__FUNCTION__)
! #define mark() elog(DEBUG3, "Mark: %s:%d", __FUNCTION__, __LINE__);
! #define refc(O) elog(DEBUG3, "Ref<%p>:<%d>:%s:%d", (O), (((O) == NULL) ? -1 : (O)->ob_refcnt), __FUNCTION__, __LINE__)
  #else
  #define enter()
  #define leave()
--- 54,63 ----
  /* temporary debugging macros
   */
  #if DEBUG_LEVEL
! #define enter() elog(DEBUG4, "Enter(%d): %s", func_enter_calls++,__FUNCTION__)
! #define leave() elog(DEBUG4, "Leave(%d): %s", func_leave_calls++,__FUNCTION__)
! #define mark() elog(DEBUG4, "Mark: %s:%d", __FUNCTION__, __LINE__);
! #define refc(O) elog(DEBUG4, "Ref<%p>:<%d>:%s:%d", (O), (((O) == NULL) ? -1 : (O)->ob_refcnt), __FUNCTION__, __LINE__)
  #else
  #define enter()
  #define leave()
Index: src/pl/tcl/pltcl.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/pl/tcl/pltcl.c,v
retrieving revision 1.70
diff -c -c -r1.70 pltcl.c
*** src/pl/tcl/pltcl.c	16 May 2003 13:37:00 -0000	1.70
--- src/pl/tcl/pltcl.c	27 May 2003 17:43:35 -0000
***************
*** 1272,1278 ****
  	}
  
  	if (strcmp(argv[1], "DEBUG") == 0)
! 		level = DEBUG1;
  	else if (strcmp(argv[1], "LOG") == 0)
  		level = LOG;
  	else if (strcmp(argv[1], "INFO") == 0)
--- 1272,1278 ----
  	}
  
  	if (strcmp(argv[1], "DEBUG") == 0)
! 		level = DEBUG2;
  	else if (strcmp(argv[1], "LOG") == 0)
  		level = LOG;
  	else if (strcmp(argv[1], "INFO") == 0)
Index: src/test/regress/regress.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/test/regress/regress.c,v
retrieving revision 1.55
diff -c -c -r1.55 regress.c
*** src/test/regress/regress.c	20 Mar 2003 04:52:35 -0000	1.55
--- src/test/regress/regress.c	27 May 2003 17:43:35 -0000
***************
*** 435,441 ****
  																	))));
  	}
  
! 	elog(DEBUG3, "funny_dup17 (fired %s) on level %3d: %d/%d tuples inserted/selected",
  		 when, *level, inserted, selected);
  
  	SPI_finish();
--- 435,441 ----
  																	))));
  	}
  
! 	elog(DEBUG4, "funny_dup17 (fired %s) on level %3d: %d/%d tuples inserted/selected",
  		 when, *level, inserted, selected);
  
  	SPI_finish();
#16Bruce Momjian
pgman@candle.pha.pa.us
In reply to: Tom Lane (#12)
1 attachment(s)
Re: [BUGS] Bug #928: server_min_messages (log_min_messages

A fuller description of what I'm thinking of:

* log_min_messages should indeed be SUSET, and also the other log_xxx
switches.

Let me address this. By making log SUSET, we prevent non-super users
from turning it off, but we also prevent them from turning it on,
especially using per-user/db methods.

The only solution I can think of would be to have a new permission level
between USERSET and SUSET, where the boolean could be turned on by
non-super users, but not turned off, but then again, that adds the
ability to fill up the server logs.

I am not sure how much that is used, so I am not inclined to add it at
this time, but some day, it might be needed.

Patch to tighten log_* attached and applied.

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073

Attachments:

/pgpatches/guctext/plainDownload
Index: src/backend/utils/misc/guc.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/utils/misc/guc.c,v
retrieving revision 1.124
diff -c -c -r1.124 guc.c
*** src/backend/utils/misc/guc.c	14 May 2003 03:26:02 -0000	1.124
--- src/backend/utils/misc/guc.c	27 May 2003 04:01:08 -0000
***************
*** 400,410 ****
  #endif
  
  	{
! 		{"log_statement", PGC_USERSET}, &log_statement,
  		false, NULL, NULL
  	},
  	{
! 		{"log_duration", PGC_USERSET}, &log_duration,
  		false, NULL, NULL
  	},
  	{
--- 400,410 ----
  #endif
  
  	{
! 		{"log_statement", PGC_SUSET}, &log_statement,
  		false, NULL, NULL
  	},
  	{
! 		{"log_duration", PGC_SUSET}, &log_duration,
  		false, NULL, NULL
  	},
  	{
***************
*** 425,443 ****
  	},
  
  	{
! 		{"log_parser_stats", PGC_USERSET}, &log_parser_stats,
  		false, NULL, NULL
  	},
  	{
! 		{"log_planner_stats", PGC_USERSET}, &log_planner_stats,
  		false, NULL, NULL
  	},
  	{
! 		{"log_executor_stats", PGC_USERSET}, &log_executor_stats,
  		false, NULL, NULL
  	},
  	{
! 		{"log_statement_stats", PGC_USERSET}, &log_statement_stats,
  		false, NULL, NULL
  	},
  #ifdef BTREE_BUILD_STATS
--- 425,443 ----
  	},
  
  	{
! 		{"log_parser_stats", PGC_SUSET}, &log_parser_stats,
  		false, NULL, NULL
  	},
  	{
! 		{"log_planner_stats", PGC_SUSET}, &log_planner_stats,
  		false, NULL, NULL
  	},
  	{
! 		{"log_executor_stats", PGC_SUSET}, &log_executor_stats,
  		false, NULL, NULL
  	},
  	{
! 		{"log_statement_stats", PGC_SUSET}, &log_statement_stats,
  		false, NULL, NULL
  	},
  #ifdef BTREE_BUILD_STATS
***************
*** 791,797 ****
  	},
  
  	{
! 		{"log_min_error_statement", PGC_USERSET}, &log_min_error_statement_str,
  		"panic", assign_min_error_statement, NULL
  	},
  
--- 791,797 ----
  	},
  
  	{
! 		{"log_min_error_statement", PGC_SUSET}, &log_min_error_statement_str,
  		"panic", assign_min_error_statement, NULL
  	},
  
***************
*** 878,884 ****
  	},
  
  	{
! 		{"log_min_messages", PGC_USERSET}, &log_min_messages_str,
  		"notice", assign_log_min_messages, NULL
  	},
  
--- 878,884 ----
  	},
  
  	{
! 		{"log_min_messages", PGC_SUSET}, &log_min_messages_str,
  		"notice", assign_log_min_messages, NULL
  	},