elog() patch

Bruce Momjian writes:

REALLYFATAL => PANIC
STOP => PANIC

The annoying thing about the choice PANIC is that while the previous
suggestions may not give you the most accurate idea about what the action
really is, PANIC is just about the worst possible choice, because "panic"
is *no* action at all, it's just a state of mind.

New INFO level the prints to client by default

I doubt this idea. NOTICE should really print to the client only. This
again comes down to the user-level errors vs. server-side errors issue.
But INFO doesn't convey either of these meanings.

DEBUG removed, kept as backward compatible (will be added near 7.3)
DEBUG5, DEBUG4, DEBUG3, DEBUG2, DEBUG1 added
DebugLvl removed in favor of new DEBUG[1-5] symbols

Since you've made us stick with 1-5, are there any meanings attached to
those numbers?

New server_min_messages GUC parameter with values DEBUG[5-1], INFO, LOG, ...
New client_min_messages GUC parameter with values DEBUG[5-1], LOG, INFO, ...

Now that is *really* confusing. Two different ways to number the same
things.

Postmaster -d flag effects only postmaster message, not backend messages

Why?

Remove debug_level GUC parameter

Why?

Bootstrap mode now has a -d that requires an argument, like postmaster

OK

This clears the -d debug level on backend start. Is that done correctly?

Why?

--
Peter Eisentraut peter_e@gmx.net

Peter Eisentraut wrote:

Bruce Momjian writes:

REALLYFATAL => PANIC
STOP => PANIC

The annoying thing about the choice PANIC is that while the previous
suggestions may not give you the most accurate idea about what the action
really is, PANIC is just about the worst possible choice, because "panic"
is *no* action at all, it's just a state of mind.

Yes, but PANIC was chosen by vote, and it does match the kernel-level
description.

New INFO level the prints to client by default

I doubt this idea. NOTICE should really print to the client only. This
again comes down to the user-level errors vs. server-side errors issue.
But INFO doesn't convey either of these meanings.

We could call it TIP or something like that. I think INFO is used
because it isn't a NOTICE or ERROR or something major. It is only INFO.
It is neutral information.

DEBUG removed, kept as backward compatible (will be added near 7.3)
DEBUG5, DEBUG4, DEBUG3, DEBUG2, DEBUG1 added
DebugLvl removed in favor of new DEBUG[1-5] symbols

Since you've made us stick with 1-5, are there any meanings attached to
those numbers?

5 is max, 1 is for higher level messages. I just followed what was
already there. We can adjsut these.

New server_min_messages GUC parameter with values DEBUG[5-1], INFO, LOG, ...
New client_min_messages GUC parameter with values DEBUG[5-1], LOG, INFO, ...

Now that is *really* confusing. Two different ways to number the same
things.

Sure is, but it was agreed to by the group discussing it as the cleanest
solution. postgresql.conf has these levels documented, as does the SGML
docs.

Postmaster -d flag effects only postmaster message, not backend messages

Why?

This allows you to see postmaster connection-level debug stuff without
the query debug stuff from the backend. If you want both, you have to
set the postgres -d flag too. Seemed clearer but I can remove it if
people don't want it.

Remove debug_level GUC parameter

Why?

No longer needed with new DEBUG* levels.

This clears the -d debug level on backend start. Is that done correctly?

Why?

Again, seemed clearer. The way things are in the patch, you can't do -d
0 in the backend to turn off debug on the backend, so you have to
explicitly enable it. Of course, with these new GUC paramaters, the need
for -d is less anyway, and you can see all the messages in your client
if you wish.

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 853-3000
  +  If your life is a hard drive,     |  830 Blythe Avenue
  +  Christ can be your backup.        |  Drexel Hill, Pennsylvania 19026

Bruce Momjian writes:

Yes, but PANIC was chosen by vote, and it does match the kernel-level
description.

What is the kernel-level description?

I doubt this idea. NOTICE should really print to the client only. This
again comes down to the user-level errors vs. server-side errors issue.
But INFO doesn't convey either of these meanings.

We could call it TIP or something like that. I think INFO is used
because it isn't a NOTICE or ERROR or something major. It is only INFO.
It is neutral information.

That's what NOTICE is. NOTICE is only neutral information. NOTICE could
go to the client by default, whereas if you want something in the server
log you use LOG. I doubt an extra level is needed.

New server_min_messages GUC parameter with values DEBUG[5-1], INFO, LOG, ...
New client_min_messages GUC parameter with values DEBUG[5-1], LOG, INFO, ...

Now that is *really* confusing. Two different ways to number the same
things.

Sure is, but it was agreed to by the group discussing it as the cleanest
solution. postgresql.conf has these levels documented, as does the SGML
docs.

I doubt that agreement.

Consider, what and how much I want to debug is really quite independent of
what amount of regular "neutral" messages I want to see where. The latter
is a rather permanent administrative decision, whereas the former is a
temporary decision to isolate problems. A "debug level" is really a
universal concept in any package, and I hate to see it go.

Secondly, once I have decided how much debugging I want to do, it is
unlikely that I want to do a different amount of debugging on the client
and on the server. I can see users becoming confused by this: "I already
set the debugging level to 5, but I still only see the same messages in
the client". I think that the current debug_level, plus a new Boolean
setting "debug_to_client" or such is sufficient and much clearer.

As far as the non-debug levels go, there isn't much choice. ERROR and
above really needs to be communicated to the client anyway. So you might
be able to tune which one of LOG, INFO, NOTICE goes where. But that's
about all.

Postmaster -d flag effects only postmaster message, not backend messages

Why?

This allows you to see postmaster connection-level debug stuff without
the query debug stuff from the backend. If you want both, you have to
set the postgres -d flag too. Seemed clearer but I can remove it if
people don't want it.

We had wanted to get rid of the discrepancy between postmaster and
postgres flag, not add new ones.

--
Peter Eisentraut peter_e@gmx.net

Peter Eisentraut wrote:

Bruce Momjian writes:

Yes, but PANIC was chosen by vote, and it does match the kernel-level
description.

What is the kernel-level description?

Kernel stops, can't continue. kernel panic.

I doubt this idea. NOTICE should really print to the client only. This
again comes down to the user-level errors vs. server-side errors issue.
But INFO doesn't convey either of these meanings.

We could call it TIP or something like that. I think INFO is used
because it isn't a NOTICE or ERROR or something major. It is only INFO.
It is neutral information.

That's what NOTICE is. NOTICE is only neutral information. NOTICE could
go to the client by default, whereas if you want something in the server
log you use LOG. I doubt an extra level is needed.

Notice isn't as neutral. It is for truncation of long identifiers and
stuff like that.

New server_min_messages GUC parameter with values DEBUG[5-1], INFO, LOG, ...
New client_min_messages GUC parameter with values DEBUG[5-1], LOG, INFO, ...

Now that is *really* confusing. Two different ways to number the same
things.

Sure is, but it was agreed to by the group discussing it as the cleanest
solution. postgresql.conf has these levels documented, as does the SGML
docs.

I doubt that agreement.

Well, we discussed it on the lists, and no one objected after this
result was found.

Consider, what and how much I want to debug is really quite independent of
what amount of regular "neutral" messages I want to see where. The latter
is a rather permanent administrative decision, whereas the former is a
temporary decision to isolate problems. A "debug level" is really a
universal concept in any package, and I hate to see it go.

Well, yes, but unless we want a really complicated setup, we may as well
just emit the neutral messages with the debug. It has to be simple.
There is usually one neutral message per query, if any, so I don't see
the point.

Secondly, once I have decided how much debugging I want to do, it is
unlikely that I want to do a different amount of debugging on the client
and on the server. I can see users becoming confused by this: "I already
set the debugging level to 5, but I still only see the same messages in
the client". I think that the current debug_level, plus a new Boolean
setting "debug_to_client" or such is sufficient and much clearer.

I disagree. The patch gives us clear control over the various levels.
Tom wanted the DebugLvl variable stuff rolled into elog, and I think
this is a very clean solution.

I think Tom's point was that we want to control the independently, and
that is what this does. I think it a valid use.

As far as the non-debug levels go, there isn't much choice. ERROR and
above really needs to be communicated to the client anyway. So you might
be able to tune which one of LOG, INFO, NOTICE goes where. But that's
about all.

Yes, that is all the options you have for client, ERROR and below.

Postmaster -d flag effects only postmaster message, not backend messages

Why?

This allows you to see postmaster connection-level debug stuff without
the query debug stuff from the backend. If you want both, you have to
set the postgres -d flag too. Seemed clearer but I can remove it if
people don't want it.

We had wanted to get rid of the discrepancy between postmaster and
postgres flag, not add new ones.

We now separate them so they act independently.

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 853-3000
  +  If your life is a hard drive,     |  830 Blythe Avenue
  +  Christ can be your backup.        |  Drexel Hill, Pennsylvania 19026

Postmaster -d flag effects only postmaster message, not backend messages

Why?

OK, how about this? What if we add a new GUC parameter,
postmaster_min_messages, and that controls the postmaster printing to
the server logs. (Postmaster has no client to print to.) Then, we can
propogate the -d flag to the backends, and if someone wants just
postmaster loggging, they can use the GUC parameter.

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 853-3000
  +  If your life is a hard drive,     |  830 Blythe Avenue
  +  Christ can be your backup.        |  Drexel Hill, Pennsylvania 19026

OK, I have talked with Peter via phone and he is OK with the patch
assuming the changes I have outlined below. This is not a total
overhaul of elog() but rather a major cleanup. These changes are in the
direction of where we want to head.

Peter is also concerned if allowing clients to see elog() messages is a
security problem. Clients can't see postmaster messages because there
is no client at the time, but backend messages will be visible. I can't
think of any server log messages that shouldn't be seen by the client.
Does anyone else?

Here is a patch to clean up elog():

ftp://candle.pha.pa.us/pub/postgresql/mypatches/elog

Here is the detail:

REALLYFATAL => PANIC
STOP => PANIC
New INFO level the prints to client by default
New LOG level the prints to server log by default
Cause VACUUM information to print only to the client in verbose mode
VACUUM doesn't output to server logs
NOTICE => INFO where purely information messages are sent
DEBUG => LOG for purely server status messages
DEBUG removed, kept as backward compatible (will be added near 7.3)
DEBUG5, DEBUG4, DEBUG3, DEBUG2, DEBUG1 added
DebugLvl removed in favor of new DEBUG[1-5] symbols
New server_min_messages GUC parameter with values DEBUG[5-1], INFO, LOG, ...
New client_min_messages GUC parameter with values DEBUG[5-1], LOG, INFO, ...
Server startup now logged with LOG instead of DEBUG
Postmaster -d flag effects only postmaster message, not backend messages

Changed. Postmaster -d propogates to backends, like current. New -d 0
postgres parameter allows this propogation to be turned off.

Remove debug_level GUC parameter
elog() numbers now start at 10
Add test to print error message if older elog() values are passed to elog()
Bootstrap mode now has a -d that requires an argument, like postmaster

This clears the -d debug level on backend start. Is that done correctly?

I cleared this up with Peter.

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 853-3000
  +  If your life is a hard drive,     |  830 Blythe Avenue
  +  Christ can be your backup.        |  Drexel Hill, Pennsylvania 19026

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

Peter is also concerned if allowing clients to see elog() messages is a
security problem. Clients can't see postmaster messages because there
is no client at the time, but backend messages will be visible. I can't
think of any server log messages that shouldn't be seen by the client.

The only thing I can think of is the detailed authorization-failure
messages that the postmaster has traditionally logged but not sent to
the client. We need to be sure that the client cannot change that
behavior by setting PGOPTIONS. I *think* this is OK, since client
options aren't processed till after the auth cycle finishes --- but
check it. If you are using IsUnderPostmaster to control things then
you might have a problem, because that gets set too soon.

regards, tom lane

We could call it TIP or something like that. I think INFO is used
because it isn't a NOTICE or ERROR or something major. It is only INFO.
It is neutral information.

That's what NOTICE is. NOTICE is only neutral information. NOTICE could
go to the client by default, whereas if you want something in the server
log you use LOG. I doubt an extra level is needed.

SQL92 has WARNING, would that be a suitable addition to NOTICE ?
INFO would not be added since it is like old NOTICE which would stay.
So, instead of introducing a lighter level we would introduce a
stronger level. (WARNING more important than NOTICE)
If we change, we might as well adopt some more SQL'ism.

e.g. string truncation is defined to return SUCCESS with WARNING.

I guess it would be a horror for existing client code though :-(

Andreas

New LOG level the prints to server log by default

Cause VACUUM information to print only to the client in verbose mode
VACUUM doesn't output to server logs

Why that ? For me vacuum was one of the more useful messages in the log.
Or have you added a separate elog(LOG,... ?
It told me whether the interval between vacuums was good or not.

Andreas

Zeugswetter Andreas SB SD wrote:

New LOG level the prints to server log by default

Cause VACUUM information to print only to the client in verbose mode
VACUUM doesn't output to server logs

Why that ? For me vacuum was one of the more useful messages in the log.
Or have you added a separate elog(LOG,... ?
It told me whether the interval between vacuums was good or not.

If you set server_min_messages to DEBUG1, you will get those in the log.
Vacuum was unusual because it was doing DEBUG to the log and not to the
user. I can change this so it does LOG to the log all the time. I
changed it to DEBUG1 because I was not sure every VACUUM show be spewing
to the log file. It didn't see like a standard log message.

Another option is to set server_min_messages to INFO and do a VACUUM
VERBOSE. That will force those to the log without other DEBUG1
messages. As you can see, this is going to allow more control over
sending information to different places.

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 853-3000
  +  If your life is a hard drive,     |  830 Blythe Avenue
  +  Christ can be your backup.        |  Drexel Hill, Pennsylvania 19026

Zeugswetter Andreas SB SD wrote:

We could call it TIP or something like that. I think INFO is used
because it isn't a NOTICE or ERROR or something major. It is only INFO.
It is neutral information.

That's what NOTICE is. NOTICE is only neutral information. NOTICE could
go to the client by default, whereas if you want something in the server
log you use LOG. I doubt an extra level is needed.

SQL92 has WARNING, would that be a suitable addition to NOTICE ?
INFO would not be added since it is like old NOTICE which would stay.
So, instead of introducing a lighter level we would introduce a
stronger level. (WARNING more important than NOTICE)
If we change, we might as well adopt some more SQL'ism.

e.g. string truncation is defined to return SUCCESS with WARNING.

I guess it would be a horror for existing client code though :-(

That is a good point. We don't have tons of NOTICE messages, and
WARNING does better describe the new functionality of NOTICE, because
all those informative messages like sequence creation are now doing INFO
instead of NOTICE.

I can make a followup patch to do this. The current patch doesn't touch
the NOTICE messages that are left alone, so a separate patch makes
sense. How about WARN as a tag? Seems shorter than WARNING. Or maybe
WARNING is fine. It is just one more letter than NOTICE.

We can keep a NOTICE define for backward compatibility for 7.3, as I
have done with DEBUG.

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 853-3000
  +  If your life is a hard drive,     |  830 Blythe Avenue
  +  Christ can be your backup.        |  Drexel Hill, Pennsylvania 19026

Zeugswetter Andreas SB SD wrote:

We could call it TIP or something like that. I think INFO is used
because it isn't a NOTICE or ERROR or something major. It is only INFO.
It is neutral information.

That's what NOTICE is. NOTICE is only neutral information. NOTICE could
go to the client by default, whereas if you want something in the server
log you use LOG. I doubt an extra level is needed.

SQL92 has WARNING, would that be a suitable addition to NOTICE ?
INFO would not be added since it is like old NOTICE which would stay.
So, instead of introducing a lighter level we would introduce a
stronger level. (WARNING more important than NOTICE)
If we change, we might as well adopt some more SQL'ism.

e.g. string truncation is defined to return SUCCESS with WARNING.

I guess it would be a horror for existing client code though :-(

Actually, an interesting idea would be to leave NOTICE alone and make
the more serious messages WARNING. The problem with that is I think
INFO is clearer as something for client/user, and LOG something for the
logs. I don't think NOTICE has the same conotation. I just thought I
would mention that possibility.

So, with WARNING, NOTICE would go away and become INFO or WARNING, and
DEBUG goes away to become DEBUG1-5. With DEBUG gone, our need to add
PG_* to the beginning of the elog symbols may not be necessary.

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 853-3000
  +  If your life is a hard drive,     |  830 Blythe Avenue
  +  Christ can be your backup.        |  Drexel Hill, Pennsylvania 19026

Actually, an interesting idea would be to leave NOTICE alone and make
the more serious messages WARNING. The problem with that is I think
INFO is clearer as something for client/user, and LOG something for the
logs. I don't think NOTICE has the same conotation. I just thought I
would mention that possibility.

So, with WARNING, NOTICE would go away and become INFO or WARNING, and
DEBUG goes away to become DEBUG1-5. With DEBUG gone, our need to add
PG_* to the beginning of the elog symbols may not be necessary.

Now I am verwirrt (== brain all knots) :-)

My take was to have WARNING and NOTICE, yours is WARNING and INFO ?
For me INFO is also better to understand than NOTICE.
Not sure that alone is worth the change though, since lots of
clients will currently parse "NOTICE".

I also like LOG, since I don't like the current NOTICES in the log.
Imho INFO and WARNING would be nothing for the log per default.
LOG would be things that are only of concern to the DBA.
My preferred client level would prbbly be WARNING (no INFO).

Andreas

Zeugswetter Andreas SB SD writes:

SQL92 has WARNING, would that be a suitable addition to NOTICE ?
INFO would not be added since it is like old NOTICE which would stay.
So, instead of introducing a lighter level we would introduce a
stronger level. (WARNING more important than NOTICE)
If we change, we might as well adopt some more SQL'ism.

At the client side SQL knows two levels, namely a "completion condition"
and an "exception condition". In the PostgreSQL client protocol, these
are distinguished as N and E message packets. The tags of the messages
are irrelevant, they just serve as a guide to the user reading the
message.

--
Peter Eisentraut peter_e@gmx.net

Peter writes:

SQL92 has WARNING, would that be a suitable addition to NOTICE ?
INFO would not be added since it is like old NOTICE which would stay.
So, instead of introducing a lighter level we would introduce a
stronger level. (WARNING more important than NOTICE)
If we change, we might as well adopt some more SQL'ism.

At the client side SQL knows two levels, namely a "completion condition"
and an "exception condition". In the PostgreSQL client protocol, these
are distinguished as N and E message packets. The tags of the messages
are irrelevant, they just serve as a guide to the user reading the
message.

I am referring to "completion condition" messages according to SQLSTATE:

00xxx: Success
01xxx: Success with Warning
02xxx: Success but no rows found
03 and > : Failure

I see that there is no notion of INFO, thus I agree that INFO should not be
something normally sent to the user. INFO could be the first DEBUG Level,
or completely skipped.

I think that LOG would be more worth the trouble than INFO.

Andreas

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

Vacuum was unusual because it was doing DEBUG to the log and not to the
user. I can change this so it does LOG to the log all the time.

I think that VACUUM's messages should not appear at the default logging
level (which is going to be LOG, no?). DEBUG1 seems a reasonable level
for VACUUM.

What exactly will VACUUM VERBOSE do?

regards, tom lane

Zeugswetter Andreas SB SD writes:

I am referring to "completion condition" messages according to SQLSTATE:

00xxx: Success

This is an INFO (or no message at all). The idea was that things like the
automatic index creation for a PK would be INFO, and you could easily turn
off INFO somehow.

01xxx: Success with Warning

This is a NOTICE.

02xxx: Success but no rows found

This is nothing special.

03 and > : Failure

This is is ERROR or above.

I see that there is no notion of INFO, thus I agree that INFO should not be
something normally sent to the user. INFO could be the first DEBUG Level,
or completely skipped.

It's sort of the "tip" level. A lot of people don't like to see them, so
it's reasonable to separate them from NOTICE. You could think of them as
first debug level, if you like.

--
Peter Eisentraut peter_e@gmx.net

Tom Lane wrote:

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

Vacuum was unusual because it was doing DEBUG to the log and not to the
user. I can change this so it does LOG to the log all the time.

I think that VACUUM's messages should not appear at the default logging
level (which is going to be LOG, no?). DEBUG1 seems a reasonable level
for VACUUM.

Right.

What exactly will VACUUM VERBOSE do?

VACUUM VERBOSE will send INFO vacuum stats to client, and if you set
server_min_messages to INFO, you will get them in the logs too.

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 853-3000
  +  If your life is a hard drive,     |  830 Blythe Avenue
  +  Christ can be your backup.        |  Drexel Hill, Pennsylvania 19026

Peter Eisentraut wrote:

Zeugswetter Andreas SB SD writes:

SQL92 has WARNING, would that be a suitable addition to NOTICE ?
INFO would not be added since it is like old NOTICE which would stay.
So, instead of introducing a lighter level we would introduce a
stronger level. (WARNING more important than NOTICE)
If we change, we might as well adopt some more SQL'ism.

At the client side SQL knows two levels, namely a "completion condition"
and an "exception condition". In the PostgreSQL client protocol, these
are distinguished as N and E message packets. The tags of the messages
are irrelevant, they just serve as a guide to the user reading the
message.

Yes, both INFO and NOTICE/WARNING will come to the client as N. Only
the message tags will be different.

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 853-3000
  +  If your life is a hard drive,     |  830 Blythe Avenue
  +  Christ can be your backup.        |  Drexel Hill, Pennsylvania 19026