Opened 7 years ago

Closed 7 years ago

#2672 closed task (fixed)

Go through message IDs saying ERROR and check at which level they are logged

Reported by: vorner Owned by: muks
Priority: medium Milestone: Sprint-20130219
Component: logging Version:
Keywords: Cc:
CVSS Scoring: Parent Tickets:
Sensitive: no Defect Severity: N/A
Sub-Project: Core Feature Depending on Ticket:
Estimated Difficulty: 3 Add Hours to Ticket: 0
Total Hours: 0.97 Internal?: no

Description

We have some log messages that contain the word „ERROR“ in their ID, but they are logged at lower severity, like info. This is confusing and looks wrong in the code and log files. We should go through such messages and either rename their IDs (see git 5351989c3736c027df8f164ee257feb6d51f9b72 for example) or change the log level.

Subtickets

Change History (12)

comment:1 Changed 7 years ago by jelte

  • Milestone changed from New Tasks to Sprint-20130219

comment:2 Changed 7 years ago by muks

  • Owner set to muks
  • Status changed from new to assigned

Picking

comment:3 follow-up: Changed 7 years ago by muks

  • Owner changed from muks to UnAssigned
  • Status changed from assigned to reviewing

This is ready for review.

  • I have left IDs logged at FATAL to contain ERROR in some places as there's no better way to say it:
        logger.fatal(BIND10_SELECT_ERROR, err)
        logger.fatal(BIND10_SOCKCREATOR_TRANSPORT_ERROR, str(se))
        logger.fatal(BIND10_STARTUP_ERROR, startup_result)
        logger.fatal(CMDCTL_CC_SESSION_ERROR, err)
        logger.fatal(STATSHTTPD_CC_SESSION_ERROR, se)
        logger.fatal(STATS_START_ERROR, se)
        logger.fatal(STATSHTTPD_START_SERVER_INIT_ERROR, hse)
        logger.fatal(STATS_CC_SESSION_ERROR, se)
        logger.fatal(STATS_START_ERROR, se)
        LOG_FATAL(logger, CC_CONN_ERROR).arg(se.what());
        LOG_FATAL(logger, CC_WRITE_ERROR).arg(asio_ex.what());
        logger.fatal(CFGMGR_CC_SESSION_ERROR, se)
        logger.fatal(CFGMGR_DATA_READ_ERROR, cmdre)
    
  • I've also left LOG_READ_ERROR and LOG_WRITE_ERROR in the logger test code as-is. They are used in multiple places there with different severity levels for testing.
  • The following (logged at DEBUG) were also untouched, as they seem to have the right IDs:
    % NSAS_ERROR_RESPONSE error response of %1 returned in query for %2
    The NSAS (nameserver address store - part of the resolver) made a query
    for information it needed.  The query completed successfully but the
    RCODE in the response was something other than NOERROR.
    
    % RESLIB_ERROR_RESPONSE unspecified error received in response to query for <%1>
    A debug message, the response to the specified query to an upstream
    nameserver indicated that the response was classified as an erroneous
    response, but that the nature of the error cannot be identified.
    A SERVFAIL will be returned to the system making the original query.
    
  • ChangeLog is required:
    +XYZ.   [func]          muks
    +       Various message IDs have been renamed to remove the word 'ERROR'
    +       from them when they are not logged at ERROR severity level.
    +       (Trac #2672, git ...)
    +
    

comment:4 Changed 7 years ago by vorner

  • Owner changed from UnAssigned to vorner

comment:5 in reply to: ↑ 3 Changed 7 years ago by vorner

  • Owner changed from vorner to muks
  • Total Hours changed from 0 to 0.48

Hello

Replying to muks:

  • I have left IDs logged at FATAL to contain ERROR in some places as there's no better way to say it:
        logger.fatal(BIND10_SELECT_ERROR, err)
        logger.fatal(BIND10_SOCKCREATOR_TRANSPORT_ERROR, str(se))
        logger.fatal(BIND10_STARTUP_ERROR, startup_result)
        logger.fatal(CMDCTL_CC_SESSION_ERROR, err)
        logger.fatal(STATSHTTPD_CC_SESSION_ERROR, se)
        logger.fatal(STATS_START_ERROR, se)
        logger.fatal(STATSHTTPD_START_SERVER_INIT_ERROR, hse)
        logger.fatal(STATS_CC_SESSION_ERROR, se)
        logger.fatal(STATS_START_ERROR, se)
        LOG_FATAL(logger, CC_CONN_ERROR).arg(se.what());
        LOG_FATAL(logger, CC_WRITE_ERROR).arg(asio_ex.what());
        logger.fatal(CFGMGR_CC_SESSION_ERROR, se)
        logger.fatal(CFGMGR_DATA_READ_ERROR, cmdre)
    

I think these are not confusing, fatals are errors of kind too (even if it doesn't explicitly say error in the severity).

  • I've also left LOG_READ_ERROR and LOG_WRITE_ERROR in the logger test code as-is. They are used in multiple places there with different severity levels for testing.

That seems OK too, as user won't meet these.

  • The following (logged at DEBUG) were also untouched, as they seem to have the right IDs:
    % NSAS_ERROR_RESPONSE error response of %1 returned in query for %2
    The NSAS (nameserver address store - part of the resolver) made a query
    for information it needed.  The query completed successfully but the
    RCODE in the response was something other than NOERROR.
    
    % RESLIB_ERROR_RESPONSE unspecified error received in response to query for <%1>
    A debug message, the response to the specified query to an upstream
    nameserver indicated that the response was classified as an erroneous
    response, but that the nature of the error cannot be identified.
    A SERVFAIL will be returned to the system making the original query.
    

I guess it is reasonable too. As the error is not at the end, we just received an error response (which is not an error by itself).

  • ChangeLog is required:
    +XYZ.   [func]          muks
    +       Various message IDs have been renamed to remove the word 'ERROR'
    +       from them when they are not logged at ERROR severity level.
    +       (Trac #2672, git ...)
    +
    

OK

The lettuce tests failed for me, but they don't if I merge with master, so I guess it's some kind of unrelated problem. This can be merged.

comment:6 follow-up: Changed 7 years ago by jreed

Please also look for ERR that was not ERROR. Maybe they should be renamed to be consistent or fixed too.

comment:7 follow-up: Changed 7 years ago by jreed

After our first production release we need to be clear to document any logging identifier changes. Maybe for practice the changelog entry can mention the renames or significant changes here.

comment:8 in reply to: ↑ 6 Changed 7 years ago by muks

  • Owner changed from muks to vorner

Replying to jreed:

Please also look for ERR that was not ERROR. Maybe they should be renamed to be consistent or fixed too.

The _ERR suffix matched the severity levels in these cases, and I have renamed them to end with _ERROR for consistency.

comment:9 in reply to: ↑ 7 Changed 7 years ago by muks

Replying to jreed:

After our first production release we need to be clear to document any logging identifier changes. Maybe for practice the changelog entry can mention the renames or significant changes here.

There are several here. The ChangeLog mentions that ids were changed, but there is a lot of churn to list individually. We can probably start doing this after release.

comment:10 Changed 7 years ago by muks

Some fixes were also done, such as fixing duplicate use of IDs, removing some unused ones, etc.

BTW, that reminds me.. we should have a ticket to remove unused message IDs. There are several, esp. in datasrc.

comment:11 Changed 7 years ago by vorner

  • Owner changed from vorner to muks
  • Total Hours changed from 0.48 to 0.97

Hello

These changes look OK too and all tests pass. I guess this too is OK to merge.

I have no opinion about the changelog, though.

comment:12 Changed 7 years ago by muks

  • Resolution set to fixed
  • Status changed from reviewing to closed

Merged to master branch in commit 660a0d164feaf055677f375977f7ed327ead893e:

* 1a80b1d [2672] Rename _ERR suffix to _ERROR in message IDs
* a12aed4 [2672] Remove ERROR from various message IDs where not applicable
* ac75b8d [2672] Remove unused message ID
* 3fa52fb [2672] Fix duplicate use of message ID
* 55f8f41 [2672] Make some comment updates fixing spelling, etc.
* 4d6818e [2672] Remove unused message ID

Updated ChangeLog too:

* 7782afc [master] Update ChangeLog for #2672

Resolving as fixed. Thank you for the reviews Michal and Jeremy.

Note: See TracTickets for help on using tickets.