BIND 10 #758: Conversion of bind10 program to use new logging interface

[BIND 10 Development]

#758: Conversion of bind10 program to use new logging interface
-------------------------------------+-------------------------------------
                   Reporter:         |                 Owner:  jinmei
  stephen                            |                Status:  reviewing
                       Type:         |             Milestone:
  enhancement                        |  Sprint-20110712
                   Priority:  major  |            Resolution:
                  Component:         |             Sensitive:  0
  logging                            |           Sub-Project:  DNS
                   Keywords:         |  Estimated Difficulty:  2.0
            Defect Severity:  N/A    |           Total Hours:  0
Feature Depending on Ticket:         |
        Add Hours to Ticket:  0      |
                  Internal?:  0      |
-------------------------------------+-------------------------------------

Comment (by jinmei):

 '''general'''

 - I made some trivial changes.  but like the previous case I may have
   made a mistake, so please check them

 - I've seen some inconsistency about "msgq" vs "message bus" vs
   "message queue" with or without "daemon", etc.  Log IDs generally
   have "MSGQ".  Maybe we should leave them as is and note this in a
   msgq replacement ticket (if any, or if it doesn't exit create a
   separate ticket for cleanup).  Of course we could provide
   consistency within this ticket.

 '''specifics'''

 - shouldn't this better be "bind10", "boss", or "bob" etc?  At least
   "b10-bind10" sounds awkward (and in fact it's different from the
   program name):
 {{{
 +isc.log.init("b10-bind10")
 }}}

 - BIND10_START_AS_NON_ROOT: in my weak opinion "info" (or "notice")
   seems to be better than warn in this case.  I would generally
   consider "warn" an error (but not fatal one, e.g., when a given
   config parameter is too small/large, but there's a reasonable
   default to which we can fall back and we use it)
 - BIND10_START_AS_NON_ROOT: If we have a ticket for the socket
   creator, I'd add a note to it about this description:
 {{{
 Note that this issue should be resolved by the pending 'socket-creator'
 process; once that has been implemented, modules should not need root
 privileges anymore.
 }}}

 - BIND10_KILL_PROCESS: I'd explain the meaning of parameter (%1)

 - BIND10_STARTING_PROCESS_PORT: maybe we should change '%2:%3' to
   '%2#%3' as we discussed on jabber (and I saw a ticket about this)

 - maybe you should adjust the method document for log_starting because
   it's now not configurable only by the verbose option.

 - in my test run (with -v, from source), I couldn't find logs in
   log_starting().  am I missing something?  hmm, perhaps logs before
   creating ccsession aren't dumped?  FYI: this is what I've got
   (removing timestamps):
 {{{
 2011-06-30 18:18:06.566 INFO  [b10-bind10.bind10] BIND10_STARTING starting
 BIND10: bind10 20110223 (BIND 10 20110519)
 2011-06-30 18:18:07.787 INFO  [b10-bind10.bind10]
 BIND10_READING_BOSS_CONFIGURATION reading boss configuration
 2011-06-30 18:18:07.787 INFO  [b10-bind10.bind10]
 BIND10_CONFIGURATION_START_AUTH start authoritative server: True
 2011-06-30 18:18:07.787 INFO  [b10-bind10.bind10]
 BIND10_CONFIGURATION_START_RESOLVER start resolver: False
 2011-06-30 18:18:07.951 INFO  [b10-bind10.bind10] BIND10_STARTUP_COMPLETE
 BIND 10 started
 2011-06-30 18:18:09.384 INFO  [b10-bind10.bind10] BIND10_RECEIVED_SIGNAL
 received signal SIGINT
 2011-06-30 18:18:09.385 INFO  [b10-bind10.bind10] BIND10_SHUTDOWN stopping
 the server
 2011-06-30 18:18:10.386 INFO  [b10-bind10.bind10] BIND10_SEND_SIGTERM
 sending SIGTERM to b10-msgq (PID 71408)
 2011-06-30 18:18:10.486 INFO  [b10-bind10.bind10] BIND10_SHUTDOWN_COMPLETE
 all processes ended, shutdown complete
 }}}

 - BIND10_MSGQ_ALREADY_RUNNING: "appears to me" should be "appears to be"?

 - BIND10_SHUTDOWN: in "It will send shutdown commands to each
   process.", "shutdown commands" should be "a shutdown command" if you
   say "each process"?

 - BIND10_SEND_SIGTERM: I'd use "notice" (if we have it) because it's
   not an unexpected case even if not considered an error.  also, you
   may want to refer to BIND10_SHUTDOWN to explain when this happens.
   Same for BIND10_SEND_SIGKILL.

 - BIND10_PROCESS_ENDED_NO_EXIT_STATUS: I'd use a stronger level than
   "info" (see the previous point).  Same for other logs in this method.

 - BIND10_PROCESS_ENDED_WITH_EXIT_STATUS: as I said on jabber in a
   different context I personally don't like to repeat the same content
   in multiple places (most of it is a duplicate of NO_EXIT_STATUS),
   especially for text this long.  But understanding this may be a
   matter of opinion, I'd leave it to you.

 - BIND10_INVALID_USER: very minor point, but the use of '' seems to be
   inconsistent.  Also, 'invalid user' seems to be too simple.  Maybe
   something like 'changing user to %1 failed'?

 - BIND10_SELECT_ERROR: is the select really used "to see if a child
   process has ended"? (just checking)

 - BIND10_MSGQ_DISAPPEARED: does bind10 really shut down in this case?
   From a quick look, it seems to just exit from the for loop and
   continue the while loop.  Would someone set 'runnable' to set false
   once this happens?

 - Is it okay to simply remove this?
 {{{
 -    sys.stdout.write("[bind10] BIND 10 exiting\n");
 }}}

-- 
Ticket URL: <http://bind10.isc.org/ticket/758#comment:6>
BIND 10 Development <http://bind10.isc.org>
BIND 10 Development