BUG #6184: Inconsistencies in log messages

[ moved to hackers]

Would someone review this report for me? I think there are few
reasonable changes in here, but I am not familiar enough with all the
code areas.

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

On Tue, Aug 30, 2011 at 07:15:19AM +0000, Ding Yuan wrote:

The following bug has been logged online:

Bug reference: 6184
Logged by: Ding Yuan
Email address: ding.yuan.90@hotmail.com
PostgreSQL version: 8.4.8
Operating system: All
Description: Inconsistencies in log messages
Details:

Hi Postgres developers,
(I reported this a day ago and for some reason did not see my message appear
in the archive, so I am resending it again and I apologize if it seems
duplicated).

I am a student doing research on improving software's diagnosability by
improving the error messages. Recently I run a static checker on
postgres-8.4.8 and found that some inconsistencies in log messages in
similar situations. While we suspect some of them should be fixed, we are
not 100% sure since we do not have domain expertise in Squid code.

I am reporting 10 such cases in this report. We truly appreciate your
feedback on whether our findings make sense.

Thanks,
Ding

================== Report 1 ========================
The two elog messages are of similar situations but with different verbosity
levels.
Pattern: 7478
---------------- src/backend/executor/nodeResult.c ---------------------
@@ line: 171 @@
171:    void
172:    ExecResultMarkPos(ResultState *node)
173:    {
174:            PlanState  *outerPlan = outerPlanState(node);
175:
176:            if (outerPlan != NULL)
177:                    ExecMarkPos(outerPlan);
178:            else
179:                    elog(DEBUG2, "Result nodes do not support
mark/restore");
---------------- src/backend/executor/nodeResult.c ---------------------
@@ line: 186 @@
186:    void
187:    ExecResultRestrPos(ResultState *node)
188:    {
189:            PlanState  *outerPlan = outerPlanState(node);
190:
191:            if (outerPlan != NULL)
192:                    ExecRestrPos(outerPlan);
193:            else
194:                    elog(ERROR, "Result nodes do not support
mark/restore");

======================== Report 2
==========================================
The verbosity level for error return for CreateEvent is not consistent!
Pattern: 6490
---------------- src/backend/port/win32/socket.c ---------------------
@@ line: 128 @@
128:                    waitevent = CreateEvent(NULL, TRUE, FALSE, NULL);
129:
130:                    if (waitevent == INVALID_HANDLE_VALUE)
131:                            ereport(ERROR,
132:                                            (errmsg_internal("Failed to
create socket waiting event: %i", (int) GetLastError())));
---------------- src/backend/port/win32/signal.c ---------------------
@@ line: 83 @@
83:             pgwin32_signal_event = CreateEvent(NULL, TRUE, FALSE,
NULL);
84:             if (pgwin32_signal_event == NULL)
85:                     ereport(FATAL,
86:                                     (errmsg_internal("failed to create
signal event: %d", (int) GetLastError())));

======================== Report 3
==========================================
The log message in the first snippet (line 3487) has ERROR level, while
PANIC
is logged in other similar situations.
Pattern: 4207
---------------- src/backend/access/heap/heapam.c ---------------------
@@ line: 3483 @@
3483:           if (PageGetMaxOffsetNumber(page) >= offnum)
3484:                   lp = PageGetItemId(page, offnum);
3485:
3486:           if (PageGetMaxOffsetNumber(page) < offnum ||
!ItemIdIsNormal(lp))
3487:                   elog(ERROR, "heap_inplace_update: invalid lp");
3488:
3489:           htup = (HeapTupleHeader) PageGetItem(page, lp);
3490:
3491:           oldlen = ItemIdGetLength(lp) - htup->t_hoff;
---------------- src/backend/access/heap/heapam.c ---------------------
@@ line: 4732 @@
4732:           if (PageGetMaxOffsetNumber(page) >= offnum)
4733:                   lp = PageGetItemId(page, offnum);
4734:
4735:           if (PageGetMaxOffsetNumber(page) < offnum ||
!ItemIdIsNormal(lp))
4736:                   elog(PANIC, "heap_inplace_redo: invalid lp");
4737:
4738:           htup = (HeapTupleHeader) PageGetItem(page, lp);
4739:
4740:           oldlen = ItemIdGetLength(lp) - htup->t_hoff;
---------------- src/backend/access/heap/heapam.c ---------------------
@@ line: 4268 @@
4268:           if (PageGetMaxOffsetNumber(page) >= offnum)
4269:                   lp = PageGetItemId(page, offnum);
4270:
4271:           if (PageGetMaxOffsetNumber(page) < offnum ||
!ItemIdIsNormal(lp))
4272:                   elog(PANIC, "heap_delete_redo: invalid lp");
4273:
4274:           htup = (HeapTupleHeader) PageGetItem(page, lp);
---------------- src/backend/access/heap/heapam.c ---------------------
@@ line: 4469 @@
4469:           if (PageGetMaxOffsetNumber(page) >= offnum)
4470:                   lp = PageGetItemId(page, offnum);
4471:
4472:           if (PageGetMaxOffsetNumber(page) < offnum ||
!ItemIdIsNormal(lp))
4473:                   elog(PANIC, "heap_update_redo: invalid lp");
4474:
4475:           htup = (HeapTupleHeader) PageGetItem(page, lp);
---------------- src/backend/access/heap/heapam.c ---------------------
@@ line: 4673 @@
4673:           if (PageGetMaxOffsetNumber(page) >= offnum)
4674:                   lp = PageGetItemId(page, offnum);
4675:
4676:           if (PageGetMaxOffsetNumber(page) < offnum ||
!ItemIdIsNormal(lp))
4677:                   elog(PANIC, "heap_lock_redo: invalid lp");
4678:
4679:           htup = (HeapTupleHeader) PageGetItem(page, lp);

======================== Report 4
==========================================
There is no error message in the 2nd snippet, when:
3089:           if (!SplitIdentifierString(rawname, ',', &namelist))
occurred, while there is one at line 62 under similar situations.
Pattern: 4440
---------------- src/backend/commands/variable.c ---------------------
@@ line: 46 @@
46:             char       *rawstring;
47:             char       *result;
48:             List       *elemlist;
49:             ListCell   *l;
50:
51:             /* Need a modifiable copy of string */
52:             rawstring = pstrdup(value);
53:
54:             /* Parse string into list of identifiers */
55:             if (!SplitIdentifierString(rawstring, ',', &elemlist))
56:             {
57:                     /* syntax error in list */
58:                     pfree(rawstring);
59:                     list_free(elemlist);
60:                     ereport(GUC_complaint_elevel(source),
61:                                    
(errcode(ERRCODE_INVALID_PARAMETER_VALUE),
62:                                      errmsg("invalid list syntax for
parameter \"datestyle\"")));
63:                     return NULL;
64:             }
65:
66:             foreach(l, elemlist)
---------------- src/backend/catalog/namespace.c ---------------------
@@ line: 3081 @@
3081:           char       *rawname;
3082:           List       *namelist;
3083:           ListCell   *l;
3084:
3085:           /* Need a modifiable copy of string */
3086:           rawname = pstrdup(newval);
3087:
3088:           /* Parse string into list of identifiers */
3089:           if (!SplitIdentifierString(rawname, ',', &namelist))
3090:           {
3091:                   /* syntax error in name list */
3092:                   pfree(rawname);
3093:                   list_free(namelist);
3094:                   return NULL;
3095:           }
3096:
3097:           /*
3098:            * If we aren't inside a transaction, we cannot do database
access so
3099:            * cannot verify the individual names.  Must accept the list
on faith.
3100:            */
3101:           if (source >= PGC_S_INTERACTIVE && IsTransactionState())
3102:           {
3103:                   /*
3104:                    * Verify that all the names are either valid
namespace names or
3105:                    * "$user" or "pg_temp".  We do not require $user to
correspond to a
3106:                    * valid namespace, and pg_temp might not exist yet.
We do not check
3107:                    * for USAGE rights, either; should we?
3108:                    *
3109:                    * When source == PGC_S_TEST, we are checking the
argument of an ALTER
3110:                    * DATABASE SET or ALTER USER SET command.      It
could be that the
3111:                    * intended use of the search path is for some other
database, so we
3112:                    * should not error out if it mentions schemas not
present in the
3113:                    * current database.  We reduce the message to
NOTICE instead.
3114:                    */
3115:                   foreach(l, namelist)

======================== Report 5
==========================================
The first log message at line 2221 is of ERROR level, while the other log
messages in similar situations are FATAL!
Pattern: 3948
---------------- src/backend/access/transam/xact.c ---------------------
@@ line: 2210 @@
2210:                   case TBLOCK_BEGIN:
2211:                   case TBLOCK_SUBBEGIN:
2212:                   case TBLOCK_END:
2213:                   case TBLOCK_SUBEND:
2214:                   case TBLOCK_ABORT_END:
2215:                   case TBLOCK_SUBABORT_END:
2216:                   case TBLOCK_ABORT_PENDING:
2217:                   case TBLOCK_SUBABORT_PENDING:
2218:                   case TBLOCK_SUBRESTART:
2219:                   case TBLOCK_SUBABORT_RESTART:
2220:                   case TBLOCK_PREPARE:
2221:                           elog(ERROR, "StartTransactionCommand:
unexpected state %s",
2222:                                   
BlockStateAsString(s->blockState));
2223:                           break;
---------------- src/backend/access/transam/xact.c ---------------------
@@ line: 2890 @@
2890:                   case TBLOCK_BEGIN:
2891:                   case TBLOCK_SUBBEGIN:
2892:                   case TBLOCK_END:
2893:                   case TBLOCK_SUBEND:
2894:                   case TBLOCK_ABORT_END:
2895:                   case TBLOCK_SUBABORT_END:
2896:                   case TBLOCK_ABORT_PENDING:
2897:                   case TBLOCK_SUBABORT_PENDING:
2898:                   case TBLOCK_SUBRESTART:
2899:                   case TBLOCK_SUBABORT_RESTART:
2900:                   case TBLOCK_PREPARE:
2901:                           elog(FATAL, "BeginTransactionBlock:
unexpected state %s",
2902:                                   
BlockStateAsString(s->blockState));
2903:                           break;
---------------- src/backend/access/transam/xact.c ---------------------
@@ line: 3058 @@
3058:                   case TBLOCK_BEGIN:
3059:                   case TBLOCK_SUBBEGIN:
3060:                   case TBLOCK_END:
3061:                   case TBLOCK_SUBEND:
3062:                   case TBLOCK_ABORT_END:
3063:                   case TBLOCK_SUBABORT_END:
3064:                   case TBLOCK_ABORT_PENDING:
3065:                   case TBLOCK_SUBABORT_PENDING:
3066:                   case TBLOCK_SUBRESTART:
3067:                   case TBLOCK_SUBABORT_RESTART:
3068:                   case TBLOCK_PREPARE:
3069:                           elog(FATAL, "EndTransactionBlock: unexpected
state %s",
3070:                                   
BlockStateAsString(s->blockState));
3071:                           break;
---------------- src/backend/access/transam/xact.c ---------------------
@@ line: 3150 @@
3150:                   case TBLOCK_BEGIN:
3151:                   case TBLOCK_SUBBEGIN:
3152:                   case TBLOCK_END:
3153:                   case TBLOCK_SUBEND:
3154:                   case TBLOCK_ABORT_END:
3155:                   case TBLOCK_SUBABORT_END:
3156:                   case TBLOCK_ABORT_PENDING:
3157:                   case TBLOCK_SUBABORT_PENDING:
3158:                   case TBLOCK_SUBRESTART:
3159:                   case TBLOCK_SUBABORT_RESTART:
3160:                   case TBLOCK_PREPARE:
3161:                           elog(FATAL, "UserAbortTransactionBlock:
unexpected state %s",
3162:                                   
BlockStateAsString(s->blockState));
3163:                           break;
---------------- src/backend/access/transam/xact.c ---------------------
@@ line: 3351 @@
3351:                   case TBLOCK_BEGIN:
3352:                   case TBLOCK_SUBBEGIN:
3353:                   case TBLOCK_END:
3354:                   case TBLOCK_SUBEND:
3355:                   case TBLOCK_ABORT_END:
3356:                   case TBLOCK_SUBABORT_END:
3357:                   case TBLOCK_ABORT_PENDING:
3358:                   case TBLOCK_SUBABORT_PENDING:
3359:                   case TBLOCK_SUBRESTART:
3360:                   case TBLOCK_SUBABORT_RESTART:
3361:                   case TBLOCK_PREPARE:
3362:                           elog(FATAL, "RollbackToSavepoint: unexpected
state %s",
3363:                                   
BlockStateAsString(s->blockState));
3364:                           break;
---------------- src/backend/access/transam/xact.c ---------------------
@@ line: 3524 @@
3524:                   case TBLOCK_BEGIN:
3525:                   case TBLOCK_SUBBEGIN:
3526:                   case TBLOCK_INPROGRESS:
3527:                   case TBLOCK_END:
3528:                   case TBLOCK_SUBEND:
3529:                   case TBLOCK_ABORT:
3530:                   case TBLOCK_ABORT_END:
3531:                   case TBLOCK_SUBABORT_END:
3532:                   case TBLOCK_ABORT_PENDING:
3533:                   case TBLOCK_SUBABORT_PENDING:
3534:                   case TBLOCK_SUBRESTART:
3535:                   case TBLOCK_SUBABORT_RESTART:
3536:                   case TBLOCK_PREPARE:
3537:                           elog(FATAL,
"RollbackAndReleaseCurrentSubTransaction: unexpected state %s",
3538:                                   
BlockStateAsString(s->blockState));
3539:                           break;

======================== Report 6
==========================================
The verbosity level of log messages are inconsistent!
Pattern: 3894
---------------- src/backend/access/transam/xlog.c ---------------------
@@ line: 7537 @@
7537:           if (fscanf(lfp, "START WAL LOCATION: %X/%X (file %24s)%c",
7538:                              &startpoint.xlogid, &startpoint.xrecoff,
startxlogfilename,
7539:                              &ch) != 4 || ch != '\n')
7540:                   ereport(ERROR,
7541:                                  
(errcode(ERRCODE_OBJECT_NOT_IN_PREREQUISITE_STATE),
7542:                                    errmsg("invalid data in file
\"%s\"", BACKUP_LABEL_FILE)));
---------------- src/backend/access/transam/xlog.c ---------------------
@@ line: 7915 @@
7915:                   if (fscanf(fp, "START WAL LOCATION: %X/%X (file
%24s)%c",
7916:                                      &startpoint.xlogid,
&startpoint.xrecoff, startxlogfilename,
7917:                                      &ch) != 4 || ch != '\n')
7918:                           ereport(FATAL,
7919:                                          
(errcode(ERRCODE_OBJECT_NOT_IN_PREREQUISITE_STATE),
7920:                                            errmsg("invalid data in
file \"%s\"", histfilename)));
---------------- src/backend/access/transam/xlog.c ---------------------
@@ line: 7921 @@
7921:                   if (fscanf(fp, "STOP WAL LOCATION: %X/%X (file
%24s)%c",
7922:                                      &stoppoint.xlogid,
&stoppoint.xrecoff, stopxlogfilename,
7923:                                      &ch) != 4 || ch != '\n')
7924:                           ereport(FATAL,
7925:                                          
(errcode(ERRCODE_OBJECT_NOT_IN_PREREQUISITE_STATE),
7926:                                            errmsg("invalid data in
file \"%s\"", histfilename)));

======================== Report 7
==========================================
The log message at line 3050 and line 3142 have inconsistent verbosity
levels!
Pattern: 3955
---------------- src/backend/access/transam/xact.c ---------------------
@@ line: 3022 @@
3022:                   case TBLOCK_SUBABORT:
3023:                           while (s->parent != NULL)
3024:                           {
3025:                                   if (s->blockState ==
TBLOCK_SUBINPROGRESS)
3026:                                           s->blockState =
TBLOCK_SUBABORT_PENDING;
3027:                                   else if (s->blockState ==
TBLOCK_SUBABORT)
3028:                                           s->blockState =
TBLOCK_SUBABORT_END;
3029:                                   else
3030:                                           elog(FATAL,
"EndTransactionBlock: unexpected state %s",
3031:                                                   
BlockStateAsString(s->blockState));
3032:                                   s = s->parent;
3033:                           }
3034:                           if (s->blockState == TBLOCK_INPROGRESS)
3035:                                   s->blockState =
TBLOCK_ABORT_PENDING;
3036:                           else if (s->blockState == TBLOCK_ABORT)
3037:                                   s->blockState = TBLOCK_ABORT_END;
3038:                           else
3039:                                   elog(FATAL, "EndTransactionBlock:
unexpected state %s",
3040:                                           
BlockStateAsString(s->blockState));
3041:                           break;
3042:
3043:                           /*
3044:                            * The user issued COMMIT when not inside a
transaction.  Issue a
3045:                            * WARNING, staying in TBLOCK_STARTED state.
The upcoming call to
3046:                            * CommitTransactionCommand() will then
close the transaction and
3047:                            * put us back into the default state.
3048:                            */
3049:                   case TBLOCK_STARTED:
3050:                           ereport(WARNING,
3051:                                          
(errcode(ERRCODE_NO_ACTIVE_SQL_TRANSACTION),
3052:                                            errmsg("there is no
transaction in progress")));
3053:                           result = true;
3054:                           break;
3055:
3056:                           /* These cases are invalid. */
3057:                   case TBLOCK_DEFAULT:
3058:                   case TBLOCK_BEGIN:
3059:                   case TBLOCK_SUBBEGIN:
3060:                   case TBLOCK_END:
3061:                   case TBLOCK_SUBEND:
3062:                   case TBLOCK_ABORT_END:
3063:                   case TBLOCK_SUBABORT_END:
3064:                   case TBLOCK_ABORT_PENDING:
3065:                   case TBLOCK_SUBABORT_PENDING:
3066:                   case TBLOCK_SUBRESTART:
3067:                   case TBLOCK_SUBABORT_RESTART:
3068:                   case TBLOCK_PREPARE:
3069:                           elog(FATAL, "EndTransactionBlock: unexpected
state %s",
3070:                                   
BlockStateAsString(s->blockState));
3071:                           break;
---------------- src/backend/access/transam/xact.c ---------------------
@@ line: 3114 @@
3114:                   case TBLOCK_SUBABORT:
3115:                           while (s->parent != NULL)
3116:                           {
3117:                                   if (s->blockState ==
TBLOCK_SUBINPROGRESS)
3118:                                           s->blockState =
TBLOCK_SUBABORT_PENDING;
3119:                                   else if (s->blockState ==
TBLOCK_SUBABORT)
3120:                                           s->blockState =
TBLOCK_SUBABORT_END;
3121:                                   else
3122:                                           elog(FATAL,
"UserAbortTransactionBlock: unexpected state %s",
3123:                                                   
BlockStateAsString(s->blockState));
3124:                                   s = s->parent;
3125:                           }
3126:                           if (s->blockState == TBLOCK_INPROGRESS)
3127:                                   s->blockState =
TBLOCK_ABORT_PENDING;
3128:                           else if (s->blockState == TBLOCK_ABORT)
3129:                                   s->blockState = TBLOCK_ABORT_END;
3130:                           else
3131:                                   elog(FATAL,
"UserAbortTransactionBlock: unexpected state %s",
3132:                                           
BlockStateAsString(s->blockState));
3133:                           break;
3134:
3135:                           /*
3136:                            * The user issued ABORT when not inside a
transaction. Issue a
3137:                            * WARNING and go to abort state.  The
upcoming call to
3138:                            * CommitTransactionCommand() will then put
us back into the
3139:                            * default state.
3140:                            */
3141:                   case TBLOCK_STARTED:
3142:                           ereport(NOTICE,
3143:                                          
(errcode(ERRCODE_NO_ACTIVE_SQL_TRANSACTION),
3144:                                            errmsg("there is no
transaction in progress")));
3145:                           s->blockState = TBLOCK_ABORT_PENDING;
3146:                           break;
3147:
3148:                           /* These cases are invalid. */
3149:                   case TBLOCK_DEFAULT:
3150:                   case TBLOCK_BEGIN:
3151:                   case TBLOCK_SUBBEGIN:
3152:                   case TBLOCK_END:
3153:                   case TBLOCK_SUBEND:
3154:                   case TBLOCK_ABORT_END:
3155:                   case TBLOCK_SUBABORT_END:
3156:                   case TBLOCK_ABORT_PENDING:
3157:                   case TBLOCK_SUBABORT_PENDING:
3158:                   case TBLOCK_SUBRESTART:
3159:                   case TBLOCK_SUBABORT_RESTART:
3160:                   case TBLOCK_PREPARE:
3161:                           elog(FATAL, "UserAbortTransactionBlock:
unexpected state %s",
3162:                                   
BlockStateAsString(s->blockState));
3163:                           break;

======================== Report 8
==========================================
The log message at 2292 is ERROR, inconsistent with the line @line 2521
(PANIC).
Pattern: 3850
---------------- src/backend/access/transam/xlog.c ---------------------
@@ line: 2289 @@
2289:           fd = BasicOpenFile(path, O_RDWR | PG_BINARY |
get_sync_bit(sync_method),
2290:                                              S_IRUSR | S_IWUSR);
2291:           if (fd < 0)
2292:                   ereport(ERROR,
2293:                                   (errcode_for_file_access(),
2294:                      errmsg("could not open file \"%s\" (log file %u,
segment %u): %m",
2295:                                     path, log, seg)));
2296:
2297:           elog(DEBUG2, "done creating and filling new WAL file");
2298:
2299:           return fd;
---------------- src/backend/access/transam/xlog.c ---------------------
@@ line: 2518 @@
2518:           fd = BasicOpenFile(path, O_RDWR | PG_BINARY |
get_sync_bit(sync_method),
2519:                                              S_IRUSR | S_IWUSR);
2520:           if (fd < 0)
2521:                   ereport(PANIC,
2522:                                   (errcode_for_file_access(),
2523:                      errmsg("could not open file \"%s\" (log file %u,
segment %u): %m",
2524:                                     path, log, seg)));
2525:
2526:           return fd;

======================== Report 9
==========================================
The 2 log messages: 624@comment.c and 663@comment.c have different
verbosity
levels!
Pattern: 8162 
---------------- src/backend/commands/comment.c ---------------------
@@ line: 607 @@
607:                    ereport(ERROR,
608:                                    (errcode(ERRCODE_SYNTAX_ERROR),
609:                                     errmsg("database name cannot be
qualified")));
610:            database = strVal(linitial(qualname));
611:
612:            /*
613:             * When loading a dump, we may see a COMMENT ON DATABASE for
the old name
614:             * of the database.  Erroring out would prevent pg_restore
from completing
615:             * (which is really pg_restore's fault, but for now we will
work around
616:             * the problem here).  Consensus is that the best fix is to
treat wrong
617:             * database name as a WARNING not an ERROR.
618:             */
619:
620:            /* First get the database OID */
621:            oid = get_database_oid(database);
622:            if (!OidIsValid(oid))
623:            {
624:                    ereport(WARNING,
625:                                   
(errcode(ERRCODE_UNDEFINED_DATABASE),
626:                                     errmsg("database \"%s\" does not
exist", database)));
627:                    return;
---------------- src/backend/commands/comment.c ---------------------
@@ line: 655 @@
655:                    ereport(ERROR,
656:                                    (errcode(ERRCODE_SYNTAX_ERROR),
657:                                     errmsg("tablespace name cannot be
qualified")));
658:            tablespace = strVal(linitial(qualname));
659:
660:            oid = get_tablespace_oid(tablespace);
661:            if (!OidIsValid(oid))
662:            {
663:                    ereport(ERROR,
664:                                    (errcode(ERRCODE_UNDEFINED_OBJECT),
665:                                     errmsg("tablespace \"%s\" does not
exist", tablespace)));
666:                    return;

======================== Report 10
==========================================
The first log message has WARNING while the others have ERROR!
Pattern: 3126
---------------- src/backend/utils/misc/guc.c ---------------------
@@ line: 7029 @@
7029:                   ParseLongOption(s, &name, &value);
7030:                   if (!value)
7031:                   {
7032:                           ereport(WARNING,
7033:                                          
(errcode(ERRCODE_SYNTAX_ERROR),
7034:                                            errmsg("could not parse
setting for parameter \"%s\"",
7035:                                                           name)));
---------------- src/backend/postmaster/postmaster.c ---------------------
@@ line: 647 @@
647:                                            ParseLongOption(optarg,
&name, &value);
648:                                            if (!value)
649:                                            {
650:                                                    if (opt == '-')
651:                                                           
ereport(ERROR,
652:                                                                        
(errcode(ERRCODE_SYNTAX_ERROR),
653:                                                                        
errmsg("--%s requires a value",
654:                                                                        
optarg)));
---------------- src/backend/bootstrap/bootstrap.c ---------------------
@@ line: 288 @@
288:                                            ParseLongOption(optarg,
&name, &value);
289:                                            if (!value)
290:                                            {
291:                                                    if (flag == '-')
292:                                                           
ereport(ERROR,
293:                                                                        
(errcode(ERRCODE_SYNTAX_ERROR),
294:                                                                        
errmsg("--%s requires a value",
295:                                                                        
optarg)));
---------------- src/backend/tcop/postgres.c ---------------------
@@ line: 3175 @@
3175:                                           ParseLongOption(optarg,
&name, &value);
3176:                                           if (!value)
3177:                                           {
3178:                                                   if (flag == '-')
3179:                                                          
ereport(ERROR,
3180:                                                                       
(errcode(ERRCODE_SYNTAX_ERROR),
3181:                                                                       
errmsg("--%s requires a value",
3182:                                                                       
optarg)));

--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

--
Bruce Momjian <bruce@momjian.us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

Bruce Momjian <bruce@momjian.us> writes:

[ moved to hackers]

Would someone review this report for me? I think there are few
reasonable changes in here, but I am not familiar enough with all the
code areas.

I see one place where we forgot to sync a comment, but otherwise this
all looks OK. Details below ...

================== Report 1 ========================
The two elog messages are of similar situations but with different verbosity
levels.

The inconsistency here is intentional: it's okay for Mark to be a no-op,
as long as you don't ever do a Restore.

======================== Report 2
==========================================
The verbosity level for error return for CreateEvent is not consistent!

I'm not too familiar with the Windows-specific code, but I don't see
anything particularly wrong here. Failing to initialize in a wait for
an individual socket is perhaps recoverable, whereas failing to set up
the signal-handling emulation at all is not.

======================== Report 3
==========================================
The log message in the first snippet (line 3487) has ERROR level, while
PANIC
is logged in other similar situations.

They're not really similar since one case is mainline code while the
others are log replay. Actually, I think the mainline case is inside a
critical section so it's not going to matter too much anyway; and for
that matter there's no practical difference between ERROR and PANIC in
replay either. But by and large we've coded PANIC explicitly in log
replay, but not in initial creation/application of WAL records.

======================== Report 4
==========================================
There is no error message in the 2nd snippet, when:
3089: if (!SplitIdentifierString(rawname, ',', &namelist))
occurred, while there is one at line 62 under similar situations.

[ shrug... ] It's not always the case that errors are to be reported
immediately where detected. In this particular case, the second
instance is inside a GUC check_hook, which is specifically required
to not throw errors, but instead return a failure indication to its
caller.

======================== Report 5
==========================================
The first log message at line 2221 is of ERROR level, while the other log
messages in similar situations are FATAL!

I think probably the point here is that erroring out of transaction
start is recoverable (you are still not in a transaction, and you could
try again) but erroring out of a later state transition is not going to
leave the transaction mechanism in a sane state. In any case, all of
those are "can't happen" errors so it's hard to get very excited about
them.

======================== Report 6
==========================================
The verbosity level of log messages are inconsistent!

Again, one of these is mainline code while the others are in recovery
context.

======================== Report 7
==========================================
The log message at line 3050 and line 3142 have inconsistent verbosity
levels!

The inconsistency here is a consequence of commit
82748bc253e00a07f0fcce3959af711b509a4e69, so it's entirely intentional,
and presumably a result of discussion in the mailing lists (I'm too lazy
to go look for the thread right now).

I notice that that commit failed to adjust the adjacent comment, though
--- tut tut, Bruce.

======================== Report 8
==========================================
The log message at 2292 is ERROR, inconsistent with the line @line 2521
(PANIC).

Failure of advance creation of an xlog file is recoverable, not having
one when we need it is not. Also see header comment for XLogFileInit.

======================== Report 9
==========================================
The 2 log messages: 624@comment.c and 663@comment.c have different
verbosity
levels!

Again, note the comment, which shows pretty clearly that this choice was
intentional. I'm not going to do a git blame for this one but you could
certainly track back where the code was changed to make it a WARNING.

======================== Report 10
==========================================
The first log message has WARNING while the others have ERROR!

Yup. The first one is in postgresql.conf parsing and the others are in
command line option parsing. We don't start up if command line options
are bad ... but once running, a mistake in postgresql.conf shouldn't
bring down the database.

On the whole, my impression is that this type of analysis might be
productive, but it would require a great deal more context awareness
(and knowledge of project-specific coding rules) to get it to the
point where it's not almost all false positives.

I doubt that there are very many mistakes in assignment of
NOTICE/WARNING/ERROR levels in our code. There's a certain lack of
consistency in use of ERROR/FATAL/PANIC in contexts where the coder
knows they're all the same anyway, namely just about anything that
runs in a non-transactional process. And the DEBUGn levels are all over
the map, because there's never been any global vision of which debug
messages are most likely to be interesting. I'm not sure if a tool
like this could help us enforce a policy about that ... but first
we'd have to have a policy ...

regards, tom lane

On Wed, Aug 15, 2012 at 06:42:51PM -0400, Tom Lane wrote:

Bruce Momjian <bruce@momjian.us> writes:

[ moved to hackers]

Would someone review this report for me? I think there are few
reasonable changes in here, but I am not familiar enough with all the
code areas.

======================== Report 7
==========================================
The log message at line 3050 and line 3142 have inconsistent verbosity
levels!

The inconsistency here is a consequence of commit
82748bc253e00a07f0fcce3959af711b509a4e69, so it's entirely intentional,
and presumably a result of discussion in the mailing lists (I'm too lazy
to go look for the thread right now).

I notice that that commit failed to adjust the adjacent comment, though
--- tut tut, Bruce.

Oops, thanks, fixed, and thanks for reviewing this report.

--
Bruce Momjian <bruce@momjian.us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +