Thread: elog() patch
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 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? -- 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, Pennsylvania19026
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, Pennsylvania19026
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, Pennsylvania19026
> > 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, Pennsylvania19026
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, Pennsylvania19026
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, Pennsylvania19026
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, Pennsylvania19026
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, Pennsylvania19026
> 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, Pennsylvania19026
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, Pennsylvania19026
Zeugswetter Andreas SB SD wrote: > > > 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". OK, now that the current elog() patch seems to be OK with everyone, we can discuss if we want to change the remaining non-INFO NOTICE messages to WARNING. Seems to more closely match the SQL standard. All messages will continue using the 'N' protocol type so this shouldn't be an issue. I don't know any clients that parse the NOTICE: tag, but they are going to have to change things for INFO: anyway so we might as well make the change during 7.3 too. Comments? > I also like LOG, since I don't like the current NOTICES in the log. Good, that was one of my goals. > 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). Well, that is interesting. Currently we would send WARNING/NOTICE to the logs because it is an exceptional condition, though not as serious as error. -- 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, Pennsylvania19026
> > 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". > > OK, now that the current elog() patch seems to be OK with everyone, we > can discuss if we want to change the remaining non-INFO NOTICE messages > to WARNING. Seems to more closely match the SQL standard. All messages > will continue using the 'N' protocol type so this shouldn't be an issue. Yes, I think that would be good. > I don't know any clients that parse the NOTICE: tag, but they are going > to have to change things for INFO: anyway so we might as well make the > change during 7.3 too. Good point. > > I also like LOG, since I don't like the current NOTICES in the log. > > Good, that was one of my goals. > > > 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). > > Well, that is interesting. Currently we would send WARNING/NOTICE to > the logs because it is an exceptional condition, though not as serious > as error. Well, string truncation is imho not for the log, might interest the app programmer but probably not the dba ? And if your point was to get rid of the notices in the log (as is mine) you would have to not log Warning, no ? Andreas
Peter 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. All agreed, matches what I was trying to say. Only I like the keyword WARNING more than NOTICE. Andreas
> > > I also like LOG, since I don't like the current NOTICES in the log. > > > > Good, that was one of my goals. > > > > > 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). > > > > Well, that is interesting. Currently we would send WARNING/NOTICE to > > the logs because it is an exceptional condition, though not as serious > > as error. > > Well, string truncation is imho not for the log, might interest the app > programmer but probably not the dba ? And if your point was to get rid > of the notices in the log (as is mine) you would have to not log Warning, > no ? OK, now things could get complicated. If we don't want to see NOTICE/WARNING in the log, you could say you don't want to see ERROR in the log, particularly syntax errors. Where do we go from here? You could set your server_min_messages to FATAL, but then you don't see LOG messages about server startup. I have considered allowing individual message types to be specified, particularly for the server logs, but the user API for that, particilarly as SET from psql, becomes very complicated. Maybe I have the ordering wrong for server_min_messages. Perhaps it should be: DEBUG5-1, INFO, NOTICE/WARNING, ERROR, LOG, FATAL, PANIC Nothing prevents us from doing that. Well, anyway, not sure how much I like it but I throw it out as an idea. -- 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, Pennsylvania19026
> Maybe I have the ordering wrong for server_min_messages. Perhaps it > should be: > > DEBUG5-1, INFO, NOTICE/WARNING, ERROR, LOG, FATAL, PANIC > > Nothing prevents us from doing that. Well, anyway, not sure how much I > like it but I throw it out as an idea. Ah, yes, that sounds optimal to me. Andreas
Bruce Momjian <pgman@candle.pha.pa.us> writes:
>> 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.
So VACUUM will use either INFO or DEBUG1 level depending on VERBOSE,
and from there it works as usual. Seems okay.
regards, tom lane
Tom Lane wrote: > Bruce Momjian <pgman@candle.pha.pa.us> writes: > >> 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. > > So VACUUM will use either INFO or DEBUG1 level depending on VERBOSE, > and from there it works as usual. Seems okay. Yep. -- 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, Pennsylvania19026
...
> 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".
fwiw, I find the connotations of these terms to be, in increasing order
of severity:
INFO, NOTICE, WARNING
though the distinction between INFO and NOTICE is not so great that one
absolutely could not replace the other.
- Thomas
Thomas Lockhart wrote: > ... > > 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". > > fwiw, I find the connotations of these terms to be, in increasing order > of severity: > > INFO, NOTICE, WARNING > > though the distinction between INFO and NOTICE is not so great that one > absolutely could not replace the other. Yes, that was my thought to. I am not sure we have any need for NOTICE when we have INFO and WARNING. The NOTICE sort of kept both meanings, and we don't need that anymore. On a humorous note, when we got the code from Berkeley, WARN was the original tag to error out a query. -- 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, Pennsylvania19026
Zeugswetter Andreas SB SD wrote: > > > Maybe I have the ordering wrong for server_min_messages. Perhaps it > > should be: > > > > DEBUG5-1, INFO, NOTICE/WARNING, ERROR, LOG, FATAL, PANIC > > > > Nothing prevents us from doing that. Well, anyway, not sure how much I > > like it but I throw it out as an idea. > > Ah, yes, that sounds optimal to me. What do others think of this. I can easily do it. -- 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, Pennsylvania19026
Bruce Momjian writes: > Zeugswetter Andreas SB SD wrote: > > > > > Maybe I have the ordering wrong for server_min_messages. Perhaps it > > > should be: > > > > > > DEBUG5-1, INFO, NOTICE/WARNING, ERROR, LOG, FATAL, PANIC > > > > > > Nothing prevents us from doing that. Well, anyway, not sure how much I > > > like it but I throw it out as an idea. > > > > Ah, yes, that sounds optimal to me. > > What do others think of this. I can easily do it. I'd rather keep NOTICE instead of WARNING. It's just to keep things looking familiar a bit. -- Peter Eisentraut peter_e@gmx.net
Tom Lane wrote: > 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. Is this what you were looking for? I set client_min_messages to the max of debug5 and the output is attached. -- 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 DEBUG: ./bin/postmaster child[10023]: starting with ( DEBUG: postgres DEBUG: -v131072 DEBUG: -p DEBUG: test DEBUG: ) DEBUG: InitPostgres DEBUG: StartTransactionCommand DEBUG: ProcessQuery DEBUG: CommitTransactionCommand DEBUG: StartTransactionCommand DEBUG: ProcessQuery DEBUG: CommitTransactionCommand Welcome to psql, the PostgreSQL interactive terminal. Type: \copyright for distribution terms \h for help with SQL commands \? for help on internal slash commands \g or terminate with semicolon to execute query \q to quit test=> show client_min_messages; DEBUG: StartTransactionCommand DEBUG: ProcessUtility INFO: client_min_messages is debug5 DEBUG: CommitTransactionCommand SHOW VARIABLE test=> \q
Bruce Momjian <pgman@candle.pha.pa.us> writes:
> Is this what you were looking for? I set client_min_messages to the max
> of debug5 and the output is attached.
If the DBA wants to do that, I don't have a problem with it. I'm
wondering what happens if an unprivileged user tries to do it,
via either PGOPTIONS or Peter's new user/database-local options.
Please note also that I'm wondering about the messages emitted during
an authorization *failure*, not a successful connection.
regards, tom lane
Tom Lane wrote:
> Bruce Momjian <pgman@candle.pha.pa.us> writes:
> > Is this what you were looking for? I set client_min_messages to the max
> > of debug5 and the output is attached.
>
> If the DBA wants to do that, I don't have a problem with it. I'm
> wondering what happens if an unprivileged user tries to do it,
> via either PGOPTIONS or Peter's new user/database-local options.
>
> Please note also that I'm wondering about the messages emitted during
> an authorization *failure*, not a successful connection.
You ask a very good question here. I never tested authentication with
debug sent to the client. The answer is that it doesn't work without
the attached patch. Now, I am not about to apply this because it does
change getNotice() to an extern and moves its prototype to libpq-int.h.
This is necessary because I now use getNotice() in fe-connect.c.
The second issue is that this isn't going to work for pre-7.2 clients
because the protocol doesn't expect 'N' messages during the
authentication phase. I think we can live with a client_min_messages
level of debug* not working on old clients, though we should make a
mention of it in the release notes.
And finally, here is the output from a failed password login with the
patch applied:
$ psql test
Password:
DEBUG: received password packet with len=12, pw=lkjasdf
DEBUG: received password packet with len=12, pw=lkjasdf
psql: FATAL: Password authentication failed for user "postgres"
Basically it echoes the failed password back to the user. Again, this
is only with client_min_messages set to debug1-5. I don't know how to
fix this because we specifically set things up so the client could see
everything the server logs see. I wonder if echoing the failed password
into the logs is a good idea either. I don't think so.
Someone please advise on patch application. Are there other places that
don't expect a NOTICE in the middle of a protocol handshake?
--
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
Index: src/interfaces/libpq/fe-connect.c
===================================================================
RCS file: /cvsroot/pgsql/src/interfaces/libpq/fe-connect.c,v
retrieving revision 1.182
diff -c -r1.182 fe-connect.c
*** src/interfaces/libpq/fe-connect.c 2 Mar 2002 00:49:22 -0000 1.182
--- src/interfaces/libpq/fe-connect.c 3 Mar 2002 02:33:51 -0000
***************
*** 1296,1301 ****
--- 1296,1310 ----
return PGRES_POLLING_READING;
}
+ /* Grab NOTICE/INFO/DEBUG and discard them. */
+ while (beresp == 'N')
+ {
+ if (getNotice(conn))
+ return PGRES_POLLING_READING;
+ if (pqGetc(&beresp, conn))
+ return PGRES_POLLING_READING;
+ }
+
/* Handle errors. */
if (beresp == 'E')
{
***************
*** 1314,1319 ****
--- 1323,1337 ----
*/
appendPQExpBufferChar(&conn->errorMessage, '\n');
goto error_return;
+ }
+
+ /* Grab NOTICE/INFO/DEBUG and discard them. */
+ while (beresp == 'N')
+ {
+ if (getNotice(conn))
+ return PGRES_POLLING_READING;
+ if (pqGetc(&beresp, conn))
+ return PGRES_POLLING_READING;
}
/* Otherwise it should be an authentication request. */
Index: src/interfaces/libpq/fe-exec.c
===================================================================
RCS file: /cvsroot/pgsql/src/interfaces/libpq/fe-exec.c,v
retrieving revision 1.113
diff -c -r1.113 fe-exec.c
*** src/interfaces/libpq/fe-exec.c 25 Oct 2001 05:50:13 -0000 1.113
--- src/interfaces/libpq/fe-exec.c 3 Mar 2002 02:33:52 -0000
***************
*** 54,60 ****
static int getRowDescriptions(PGconn *conn);
static int getAnotherTuple(PGconn *conn, int binary);
static int getNotify(PGconn *conn);
- static int getNotice(PGconn *conn);
/* ---------------
* Escaping arbitrary strings to get valid SQL strings/identifiers.
--- 54,59 ----
***************
*** 1379,1385 ****
* Exit: returns 0 if successfully consumed Notice message.
* returns EOF if not enough data.
*/
! static int
getNotice(PGconn *conn)
{
/*
--- 1378,1384 ----
* Exit: returns 0 if successfully consumed Notice message.
* returns EOF if not enough data.
*/
! int
getNotice(PGconn *conn)
{
/*
Index: src/interfaces/libpq/libpq-fe.h
===================================================================
RCS file: /cvsroot/pgsql/src/interfaces/libpq/libpq-fe.h,v
retrieving revision 1.80
diff -c -r1.80 libpq-fe.h
*** src/interfaces/libpq/libpq-fe.h 8 Nov 2001 20:37:52 -0000 1.80
--- src/interfaces/libpq/libpq-fe.h 3 Mar 2002 02:33:56 -0000
***************
*** 252,257 ****
--- 252,258 ----
extern size_t PQescapeString(char *to, const char *from, size_t length);
extern unsigned char *PQescapeBytea(unsigned char *bintext, size_t binlen,
size_t *bytealen);
+ extern int getNotice(PGconn *conn);
/* Simple synchronous query */
extern PGresult *PQexec(PGconn *conn, const char *query);
> Basically it echoes the failed password back to the user. Again, this > is only with client_min_messages set to debug1-5. I don't know how to > fix this because we specifically set things up so the client could see > everything the server logs see. I wonder if echoing the failed password > into the logs is a good idea either. I don't think so. Crypt/MD5 authentication does output the password encrypted: DEBUG: received password packet with len=40, pw=md515e315f11670d4ba385d0c1615476780 DEBUG: received password packet with len=40, pw=md515e315f11670d4ba385d0c1615476780 psql: FATAL: Password authentication failed for user "postgres" However, I still don't think we should be echoing this to the server logs or the client. There is just little value to it and potential problems, especially with 'password' authentication. -- 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, Pennsylvania19026
Here is a better patch I am inclined to apply. I fixes the debug messages during authentication problem in a cleaner way, and removes password echo to server logs and client. --------------------------------------------------------------------------- Bruce Momjian wrote: > Tom Lane wrote: > > Bruce Momjian <pgman@candle.pha.pa.us> writes: > > > Is this what you were looking for? I set client_min_messages to the max > > > of debug5 and the output is attached. > > > > If the DBA wants to do that, I don't have a problem with it. I'm > > wondering what happens if an unprivileged user tries to do it, > > via either PGOPTIONS or Peter's new user/database-local options. > > > > Please note also that I'm wondering about the messages emitted during > > an authorization *failure*, not a successful connection. > > You ask a very good question here. I never tested authentication with > debug sent to the client. The answer is that it doesn't work without > the attached patch. Now, I am not about to apply this because it does > change getNotice() to an extern and moves its prototype to libpq-int.h. > This is necessary because I now use getNotice() in fe-connect.c. > > The second issue is that this isn't going to work for pre-7.2 clients > because the protocol doesn't expect 'N' messages during the > authentication phase. I think we can live with a client_min_messages > level of debug* not working on old clients, though we should make a > mention of it in the release notes. > > And finally, here is the output from a failed password login with the > patch applied: > > $ psql test > Password: > DEBUG: received password packet with len=12, pw=lkjasdf > > DEBUG: received password packet with len=12, pw=lkjasdf > > psql: FATAL: Password authentication failed for user "postgres" > > Basically it echoes the failed password back to the user. Again, this > is only with client_min_messages set to debug1-5. I don't know how to > fix this because we specifically set things up so the client could see > everything the server logs see. I wonder if echoing the failed password > into the logs is a good idea either. I don't think so. > > Someone please advise on patch application. Are there other places that > don't expect a NOTICE in the middle of a protocol handshake? -- 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 Index: src/backend/libpq/auth.c =================================================================== RCS file: /cvsroot/pgsql/src/backend/libpq/auth.c,v retrieving revision 1.76 diff -c -r1.76 auth.c *** src/backend/libpq/auth.c 2 Mar 2002 21:39:25 -0000 1.76 --- src/backend/libpq/auth.c 3 Mar 2002 21:39:40 -0000 *************** *** 854,861 **** return STATUS_EOF; } ! elog(DEBUG5, "received password packet with len=%d, pw=%s\n", ! len, buf.data); result = checkPassword(port, port->user, buf.data); pfree(buf.data); --- 854,861 ---- return STATUS_EOF; } ! /* For security reasons, do not output contents of password packet */ ! elog(DEBUG5, "received password packet"); result = checkPassword(port, port->user, buf.data); pfree(buf.data); Index: src/interfaces/libpq/fe-connect.c =================================================================== RCS file: /cvsroot/pgsql/src/interfaces/libpq/fe-connect.c,v retrieving revision 1.182 diff -c -r1.182 fe-connect.c *** src/interfaces/libpq/fe-connect.c 2 Mar 2002 00:49:22 -0000 1.182 --- src/interfaces/libpq/fe-connect.c 3 Mar 2002 21:39:42 -0000 *************** *** 1296,1301 **** --- 1296,1310 ---- return PGRES_POLLING_READING; } + /* Grab NOTICE/INFO/DEBUG and discard them. */ + while (beresp == 'N') + { + if (getNotice(conn)) + return PGRES_POLLING_READING; + if (pqGetc(&beresp, conn)) + return PGRES_POLLING_READING; + } + /* Handle errors. */ if (beresp == 'E') { Index: src/interfaces/libpq/fe-exec.c =================================================================== RCS file: /cvsroot/pgsql/src/interfaces/libpq/fe-exec.c,v retrieving revision 1.113 diff -c -r1.113 fe-exec.c *** src/interfaces/libpq/fe-exec.c 25 Oct 2001 05:50:13 -0000 1.113 --- src/interfaces/libpq/fe-exec.c 3 Mar 2002 21:39:44 -0000 *************** *** 54,60 **** static int getRowDescriptions(PGconn *conn); static int getAnotherTuple(PGconn *conn, int binary); static int getNotify(PGconn *conn); - static int getNotice(PGconn *conn); /* --------------- * Escaping arbitrary strings to get valid SQL strings/identifiers. --- 54,59 ---- *************** *** 1379,1385 **** * Exit: returns 0 if successfully consumed Notice message. * returns EOF if not enough data. */ ! static int getNotice(PGconn *conn) { /* --- 1378,1384 ---- * Exit: returns 0 if successfully consumed Notice message. * returns EOF if not enough data. */ ! int getNotice(PGconn *conn) { /* Index: src/interfaces/libpq/libpq-int.h =================================================================== RCS file: /cvsroot/pgsql/src/interfaces/libpq/libpq-int.h,v retrieving revision 1.44 diff -c -r1.44 libpq-int.h *** src/interfaces/libpq/libpq-int.h 5 Nov 2001 17:46:38 -0000 1.44 --- src/interfaces/libpq/libpq-int.h 3 Mar 2002 21:39:44 -0000 *************** *** 305,310 **** --- 305,311 ---- extern void *pqResultAlloc(PGresult *res, size_t nBytes, bool isBinary); extern char *pqResultStrdup(PGresult *res, const char *str); extern void pqClearAsyncResult(PGconn *conn); + extern int getNotice(PGconn *conn); /* === in fe-misc.c === */
Bruce Momjian <pgman@candle.pha.pa.us> writes:
> Here is a better patch I am inclined to apply.
Please do not ... I am about to commit a patch that fixes it properly,
ie, suppresses all non-error reports to the client during
authentication. I do not think that we can assume that clients will
be prepared to handle notice messages in the auth cycle.
regards, tom lane
Tom Lane wrote: > Bruce Momjian <pgman@candle.pha.pa.us> writes: > > Here is a better patch I am inclined to apply. > > Please do not ... I am about to commit a patch that fixes it properly, > ie, suppresses all non-error reports to the client during > authentication. I do not think that we can assume that clients will > be prepared to handle notice messages in the auth cycle. OK, great. Can you take care of the echo of entered password too, or I will fix it once you are done? -- 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, Pennsylvania19026
Bruce Momjian <pgman@candle.pha.pa.us> writes:
> Can you take care of the echo of entered password too,
I'm unconvinced that that's wrong, and will not change it without
more discussion. (1) The reason it was put in was to allow debugging
of "that's the wrong password" mistakes. (2) The postmaster log
inherently contains a great deal of sensitive information, so anyone
who runs with it world-readable has a problem already. (3) The password
is not emitted unless the message level is a lot lower than anyone would
routinely use. (4) If you're using the recommended MD5 encryption
approach, then what's logged is encrypted; it seems no more dangerous
than having encrypted passwords in pg_shadow.
regards, tom lane
Tom Lane wrote: > Bruce Momjian <pgman@candle.pha.pa.us> writes: > > Can you take care of the echo of entered password too, > > I'm unconvinced that that's wrong, and will not change it without > more discussion. (1) The reason it was put in was to allow debugging > of "that's the wrong password" mistakes. (2) The postmaster log > inherently contains a great deal of sensitive information, so anyone > who runs with it world-readable has a problem already. (3) The password > is not emitted unless the message level is a lot lower than anyone would > routinely use. (4) If you're using the recommended MD5 encryption > approach, then what's logged is encrypted; it seems no more dangerous > than having encrypted passwords in pg_shadow. That's a good point, particularly that MD5 echos the MD5 string and not the actual password. We can leave it and wait to see if anyone complains. -- 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, Pennsylvania19026
Zeugswetter Andreas SB SD wrote: > > > > 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". > > > > OK, now that the current elog() patch seems to be OK with everyone, we > > can discuss if we want to change the remaining non-INFO NOTICE messages > > to WARNING. Seems to more closely match the SQL standard. All messages > > will continue using the 'N' protocol type so this shouldn't be an issue. > > Yes, I think that would be good. OK, now that the elog() patch is in, we can discuss NOTICE. I know Peter wants to keep NOTICE to reduce the number of changes, but I already have a few votes that the existing NOTICE messages should be changed to a tag of WARNING. I have looked through the NOTICE elog calls, and they all appear as warnings to me --- of course with the informative messages now INFO, that is no surprise. I realize the change will be large, ~240 entries, but we are doing elog() changes right now, and I think this is a good time to do it. It is more informative, and closer to SQL standard. The priority of NOTICE will not change, it will just be called WARNING in the code and as sent to the user. I did look at keeping both NOTICE and WARNING but didn't see any value in both of them. NOTICE was sufficiently generic to handle info and warning message, but now that we have INFO, NOTICE just doesn't seem right and WARNING makes more sense. -- 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, Pennsylvania19026
Tom Lane wrote: > Bruce Momjian <pgman@candle.pha.pa.us> writes: > > Can you take care of the echo of entered password too, > > I'm unconvinced that that's wrong, and will not change it without > more discussion. (1) The reason it was put in was to allow debugging > of "that's the wrong password" mistakes. (2) The postmaster log > inherently contains a great deal of sensitive information, so anyone > who runs with it world-readable has a problem already. (3) The password > is not emitted unless the message level is a lot lower than anyone would > routinely use. (4) If you're using the recommended MD5 encryption > approach, then what's logged is encrypted; it seems no more dangerous > than having encrypted passwords in pg_shadow. I assume with your changes that the password will no longer be echoed to the client on failure at debug5, right? -- 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, Pennsylvania19026
Tom Lane wrote:
> Bruce Momjian <pgman@candle.pha.pa.us> writes:
> > I assume with your changes that the password will no longer be echoed to
> > the client on failure at debug5, right?
>
> Nope.
>
> I've noticed a bunch of breakage with this patch at high (or is it low?)
> debug output levels; for example client disconnection leaves this in the
> log:
> DEBUG: proc_exit(0)
> DEBUG: shmem_exit(0)
> LOG: pq_flush: send() failed: Broken pipe
> DEBUG: exit(0)
> LOG: pq_flush: send() failed: Bad file number
> DEBUG: reaping dead processes
> DEBUG: child process (pid 12462) exited with exit code 0
> The problem is that elog is still trying to send stuff to the client
> after client disconnection. I propose to fix that by resetting
> whereToSendOutput to None as soon as we detect client disconnect.
That is exactly the solution I would recommend. Clearly we are
stressing elog() and the client by forcing more information than we used
to.
> A more serious problem has to do with error reports for communication
> problems, for example this fragment in pqcomm.c:
>
> /*
> * Careful: an elog() that tries to write to the client
> * would cause recursion to here, leading to stack overflow
> * and core dump! This message must go *only* to the postmaster
> * log. elog(LOG) is presently safe.
> */
> elog(LOG, "pq_recvbuf: recv() failed: %m");
>
> elog(LOG) is NOT safe anymore :-(.
Sure isn't. We know we can always output to the server logs, but not
always to the client.
> I am thinking of inventing an additional elog level, perhaps called
> COMMERR, to be used specifically for reports of client communication
> trouble. This could be treated the same as LOG as far as output to
> the server log goes, but we would hard-wire it to never be reported
> to the client (for fear of recursive failure).
>
> Comments?
Couldn't we just set whereToSendOutput to None to fix this, or is there
a sense that we may be able to send messages later.
If needed, we can put COMMERR into the existing numbering. I would be
glad to add it for you if you wish. There would be no mention of it in
the docs because it is just like LOG but only to server logs.
> BTW, I am also looking at normalizing all the backend/libpq reports
> that look like
> snprintf(PQerrormsg, ...);
> fputs(PQerrormsg, stderr);
> pqdebug("%s", PQerrormsg);
> to just use elog. As-is this code is fairly broken since it doesn't
> honor the syslog option. Any objections?
Yes, I never liked this stuff. Please remove it.
-- 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,
Pennsylvania19026
Tom Lane wrote: > Bruce Momjian <pgman@candle.pha.pa.us> writes: > >> I am thinking of inventing an additional elog level, perhaps called > >> COMMERR, to be used specifically for reports of client communication > >> trouble. This could be treated the same as LOG as far as output to > >> the server log goes, but we would hard-wire it to never be reported > >> to the client (for fear of recursive failure). > > > Couldn't we just set whereToSendOutput to None to fix this, or is there > > a sense that we may be able to send messages later. > > We might as well just do proc_exit() as do that: once you reset > whereToSendOutput, you are effectively done talking to the client > (because SELECT won't send results to the client anymore). The > errors that libpq notices might or might not be hard failures, but > I don't want to take the approach of changing global state in order > to report them. Oh, I thought whereToSendOutput only affected elog(). I now see it is used in many places. Sure new log-only code is fine. -- 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, Pennsylvania19026
Bruce Momjian <pgman@candle.pha.pa.us> writes:
> I assume with your changes that the password will no longer be echoed to
> the client on failure at debug5, right?
Nope.
I've noticed a bunch of breakage with this patch at high (or is it low?)
debug output levels; for example client disconnection leaves this in the
log:DEBUG: proc_exit(0)DEBUG: shmem_exit(0)LOG: pq_flush: send() failed: Broken pipeDEBUG: exit(0)LOG: pq_flush:
send()failed: Bad file numberDEBUG: reaping dead processesDEBUG: child process (pid 12462) exited with exit code 0
The problem is that elog is still trying to send stuff to the client
after client disconnection. I propose to fix that by resetting
whereToSendOutput to None as soon as we detect client disconnect.
A more serious problem has to do with error reports for communication
problems, for example this fragment in pqcomm.c:
/* * Careful: an elog() that tries to write to the client * would cause recursion to
here,leading to stack overflow * and core dump! This message must go *only* to the postmaster *
log. elog(LOG) is presently safe. */ elog(LOG, "pq_recvbuf: recv() failed: %m");
elog(LOG) is NOT safe anymore :-(.
I am thinking of inventing an additional elog level, perhaps called
COMMERR, to be used specifically for reports of client communication
trouble. This could be treated the same as LOG as far as output to
the server log goes, but we would hard-wire it to never be reported
to the client (for fear of recursive failure).
Comments?
BTW, I am also looking at normalizing all the backend/libpq reports
that look like snprintf(PQerrormsg, ...); fputs(PQerrormsg, stderr); pqdebug("%s", PQerrormsg);
to just use elog. As-is this code is fairly broken since it doesn't
honor the syslog option. Any objections?
regards, tom lane
Bruce Momjian <pgman@candle.pha.pa.us> writes:
>> I am thinking of inventing an additional elog level, perhaps called
>> COMMERR, to be used specifically for reports of client communication
>> trouble. This could be treated the same as LOG as far as output to
>> the server log goes, but we would hard-wire it to never be reported
>> to the client (for fear of recursive failure).
> Couldn't we just set whereToSendOutput to None to fix this, or is there
> a sense that we may be able to send messages later.
We might as well just do proc_exit() as do that: once you reset
whereToSendOutput, you are effectively done talking to the client
(because SELECT won't send results to the client anymore). The
errors that libpq notices might or might not be hard failures, but
I don't want to take the approach of changing global state in order
to report them.
regards, tom lane
Bruce Momjian <pgman@candle.pha.pa.us> writes:
> OK, now that the elog() patch is in, we can discuss NOTICE. I know
> Peter wants to keep NOTICE to reduce the number of changes, but I
> already have a few votes that the existing NOTICE messages should be
> changed to a tag of WARNING.
If you're taking a vote, I vote with Peter. I don't much care for the
thought of EXPLAIN results coming out tagged WARNING ;-)
In any case, simple renamings like this ought to be carried out as part
of the prefix-tagging of elog names that we intend to do late in 7.3,
no? I see no value in having two rounds of widespread changes instead
of just one.
regards, tom lane
EXPLAIN would come out as INFO would it not? -- Rod Taylor This message represents the official view of the voices in my head ----- Original Message ----- From: "Tom Lane" <tgl@sss.pgh.pa.us> To: "Bruce Momjian" <pgman@candle.pha.pa.us> Cc: "Zeugswetter Andreas SB SD" <ZeugswetterA@spardat.at>; <pgsql-hackers@postgresql.org> Sent: Sunday, March 03, 2002 9:02 PM Subject: Re: [HACKERS] elog() patch > Bruce Momjian <pgman@candle.pha.pa.us> writes: > > OK, now that the elog() patch is in, we can discuss NOTICE. I know > > Peter wants to keep NOTICE to reduce the number of changes, but I > > already have a few votes that the existing NOTICE messages should be > > changed to a tag of WARNING. > > If you're taking a vote, I vote with Peter. I don't much care for the > thought of EXPLAIN results coming out tagged WARNING ;-) > > In any case, simple renamings like this ought to be carried out as part > of the prefix-tagging of elog names that we intend to do late in 7.3, > no? I see no value in having two rounds of widespread changes instead > of just one. > > regards, tom lane > > ---------------------------(end of broadcast)--------------------------- > TIP 1: subscribe and unsubscribe commands go to majordomo@postgresql.org >
"Rod Taylor" <rbt@zort.ca> writes:
> EXPLAIN would come out as INFO would it not?
If we make it INFO it won't come out at all, at the message level that
a lot of more-advanced users will prefer to use. That's no solution.
regards, tom lane
Tom Lane wrote: > Bruce Momjian <pgman@candle.pha.pa.us> writes: > > OK, now that the elog() patch is in, we can discuss NOTICE. I know > > Peter wants to keep NOTICE to reduce the number of changes, but I > > already have a few votes that the existing NOTICE messages should be > > changed to a tag of WARNING. > > If you're taking a vote, I vote with Peter. I don't much care for the > thought of EXPLAIN results coming out tagged WARNING ;-) EXPLAIN now comes out as INFO. > In any case, simple renamings like this ought to be carried out as part > of the prefix-tagging of elog names that we intend to do late in 7.3, > no? I see no value in having two rounds of widespread changes instead > of just one. Agreed. So you think WARNING makes sense, but let's do it at the right time. Perhaps that is what Peter was saying anyway. However, with DEBUG symbol gone, or at least gone after 7.3, I don't see a big need to add PG_ to the beginning of every elog() symbol. Can I get some votes on that? DEBUG was our big culprit of conflict with other interfaces, specifically Perl. With that split into DEBUG1-5, do we need to prefix the remaining symbols? -- 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, Pennsylvania19026
Tom Lane wrote: > "Rod Taylor" <rbt@zort.ca> writes: > > EXPLAIN would come out as INFO would it not? > > If we make it INFO it won't come out at all, at the message level that > a lot of more-advanced users will prefer to use. That's no solution. Well, right now it is INFO. It is certainly not a notice/warning or error. Seems we will have to address this. Let me look at the existing INFO message and see if there are any others that _have_ to be emitted. I will add a new symbol INFOFORCE which will always be sent to the client no matter what the client_min_messages level. Seems this is the only good way to fix this. Even if we make that NOTICE/WARNING, people may turn that off 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, Pennsylvania19026
Tom Lane wrote: > Bruce Momjian <pgman@candle.pha.pa.us> writes: > > I will add a new symbol INFOFORCE which will always be sent to the > > client no matter what the client_min_messages level. > > I was thinking along the same lines, but I hate that name. > INFOALWAYS maybe? Love it. :-) Sounds like a song. Info-always on my mind, ... > Also, should it be different from INFO as far as the server log > goes? Not sure. No, I think we add too much confusion doing that. It should behave like info to the server or we have to add an additional server_min_messages level. My feeling is that they would want INFOALWAYS in server logs in the same cases they would want INFO. -- 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, Pennsylvania19026
Bruce Momjian <pgman@candle.pha.pa.us> writes:
> I will add a new symbol INFOFORCE which will always be sent to the
> client no matter what the client_min_messages level.
I was thinking along the same lines, but I hate that name.
INFOALWAYS maybe?
Also, should it be different from INFO as far as the server log
goes? Not sure.
regards, tom lane
Tom Lane wrote: > Bruce Momjian <pgman@candle.pha.pa.us> writes: > > However, with DEBUG symbol gone, or at least gone after 7.3, I don't see > > a big need to add PG_ to the beginning of every elog() symbol. Can I > > get some votes on that? DEBUG was our big culprit of conflict with > > other interfaces, specifically Perl. > > Wrong: ERROR is a problem too. And if you think that INFO or WARNING > or PANIC will not create new problems, you are a hopeless optimist. > > We are already forcing renamings of a lot of elog symbols (eg, NOTICE > and DEBUG), so we may as well go the extra step and actually solve the > problem, rather than continue to ignore it. > > BTW, I'd go with PGERROR etc, not PG_ERROR, just to save typing. OK, unless someone else responds, we will go with PG* and NOTICE->WARNING near 7.3 beta start when tree is quiet. We will keep old symbols around for 7.3 release. -- 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, Pennsylvania19026
Bruce Momjian <pgman@candle.pha.pa.us> writes:
> However, with DEBUG symbol gone, or at least gone after 7.3, I don't see
> a big need to add PG_ to the beginning of every elog() symbol. Can I
> get some votes on that? DEBUG was our big culprit of conflict with
> other interfaces, specifically Perl.
Wrong: ERROR is a problem too. And if you think that INFO or WARNING
or PANIC will not create new problems, you are a hopeless optimist.
We are already forcing renamings of a lot of elog symbols (eg, NOTICE
and DEBUG), so we may as well go the extra step and actually solve the
problem, rather than continue to ignore it.
BTW, I'd go with PGERROR etc, not PG_ERROR, just to save typing.
regards, tom lane
Tom Lane wrote: > Bruce Momjian <pgman@candle.pha.pa.us> writes: > > I will add a new symbol INFOFORCE which will always be sent to the > > client no matter what the client_min_messages level. > > I was thinking along the same lines, but I hate that name. > INFOALWAYS maybe? > > Also, should it be different from INFO as far as the server log > goes? Not sure. In going over the existing INFO messages, I now see that there are several places that must send messages to the client no matter what client_min_messages is set to. The areas are EXPLAIN, VACUUM, ANALYZE, SHOW, and various "unsuported" messages. So, I am now thinking that INFOALWAYS is not the proper way to handle these cases. While I saw no value in splitting the current NOTICE messagees into WARNING and NOTICE (they all seem pretty much the same), I now see a value in splitting INFO into INFO for "always to client" and NOTICE which will be things like automatic sequence creation. So, based on current CVS, NOTICE -> WARNING, and some INFO will be changed to NOTICE and remaining INFO will always be sent to the client. If I don't create a new tag, then people who set the client_min_messages to ERROR will be confused to see INFO messages in some cases and not others. In the final code, client_min_messages will not have an INFO level option because INFO will always go to the client. server_min_messages will have an INFO option. Comments? -- 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, Pennsylvania19026
OK, I talked to Tom on the phone and here is what I would like to do: o Change all current CVS messages of NOTICE to WARNING. We were going to do this just before 7.3 beta but it has to be done now, as you will see below. o Change current INFO messages that should be controlled by client_min_messages to NOTICE. o Force remaining INFO messages, like from EXPLAIN, VACUUM VERBOSE, etc. to always go to the client. o Remove INFO from the client_min_messages options and add NOTICE. Seems we do need three non-ERROR elog levels to handle the various behaviors we need for these messages. -- 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, Pennsylvania19026
Tom Lane wrote: > Bruce Momjian <pgman@candle.pha.pa.us> writes: > > Can you take care of the echo of entered password too, > > I'm unconvinced that that's wrong, and will not change it without > more discussion. (1) The reason it was put in was to allow debugging > of "that's the wrong password" mistakes. (2) The postmaster log > inherently contains a great deal of sensitive information, so anyone > who runs with it world-readable has a problem already. (3) The password > is not emitted unless the message level is a lot lower than anyone would > routinely use. (4) If you're using the recommended MD5 encryption > approach, then what's logged is encrypted; it seems no more dangerous > than having encrypted passwords in pg_shadow. OK, I have thought about how we display invalid passwords in the server logs. This isn't an issue if the password is the same as stored in pg_shadow. However, if the invalid password was incorrect because it was their Unix password or a password on another machine, I think we do have an issue storing it in the server logs. I can't think of any unix utility that stores invalid passwords in the log, no matter what the debugging level, and I don't think we should be doing it either. -- 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, Pennsylvania19026
Bruce Momjian <pgman@candle.pha.pa.us> writes:
> OK, I have thought about how we display invalid passwords in the server
> logs. This isn't an issue if the password is the same as stored in
> pg_shadow. However, if the invalid password was incorrect because it
> was their Unix password or a password on another machine, I think we do
> have an issue storing it in the server logs.
Good point. Okay, yank it out ...
regards, tom lane
Tom Lane wrote: > Bruce Momjian <pgman@candle.pha.pa.us> writes: > > OK, I have thought about how we display invalid passwords in the server > > logs. This isn't an issue if the password is the same as stored in > > pg_shadow. However, if the invalid password was incorrect because it > > was their Unix password or a password on another machine, I think we do > > have an issue storing it in the server logs. > > Good point. Okay, yank it out ... Done. -- 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, Pennsylvania19026
Changes committed. Regression passes. We now have three elog levels to client, INFO for always to client, NOTICE for tips, and WARNING for non-error problems. See elog.h for discription. --------------------------------------------------------------------------- Bruce Momjian wrote: > OK, I talked to Tom on the phone and here is what I would like to do: > > o Change all current CVS messages of NOTICE to WARNING. We were going > to do this just before 7.3 beta but it has to be done now, as you will > see below. > > o Change current INFO messages that should be controlled by > client_min_messages to NOTICE. > > o Force remaining INFO messages, like from EXPLAIN, VACUUM VERBOSE, etc. > to always go to the client. > > o Remove INFO from the client_min_messages options and add NOTICE. > > Seems we do need three non-ERROR elog levels to handle the various > behaviors we need for these messages. > > -- > 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 | 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, Pennsylvania19026