1 #!/usr/bin/env python

     2 #

     3 # Copyright 2001-2004 by Vinay Sajip. All Rights Reserved.

     4 #

     5 # Permission to use, copy, modify, and distribute this software and its

     6 # documentation for any purpose and without fee is hereby granted,

     7 # provided that the above copyright notice appear in all copies and that

     8 # both that copyright notice and this permission notice appear in

     9 # supporting documentation, and that the name of Vinay Sajip

    10 # not be used in advertising or publicity pertaining to distribution

    11 # of the software without specific, written prior permission.

    12 # VINAY SAJIP DISCLAIMS ALL WARRANTIES WITH REGARD TO THIS SOFTWARE, INCLUDING

    13 # ALL IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL

    14 # VINAY SAJIP BE LIABLE FOR ANY SPECIAL, INDIRECT OR CONSEQUENTIAL DAMAGES OR

    15 # ANY DAMAGES WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER

    16 # IN AN ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT

    17 # OF OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.

    18 #

    19 # This file is part of the Python logging distribution. See

    20 # http://www.red-dove.com/python_logging.html

    21 #

    22 """Test harness for the logging module. Run all tests.

    23 

    24 Copyright (C) 2001-2002 Vinay Sajip. All Rights Reserved.

    25 """

    26 

    27 import select

    28 import os, sys, string, struct, types, cPickle, cStringIO

    29 import socket, tempfile, threading, time

    30 import logging, logging.handlers, logging.config

    31 from test.test_support import run_with_locale

    32 

    33 BANNER = "-- %-10s %-6s ---------------------------------------------------\n"

    34 

    35 FINISH_UP = "Finish up, it's closing time. Messages should bear numbers 0 through 24."

    36 

    37 #----------------------------------------------------------------------------

    38 # Log receiver

    39 #----------------------------------------------------------------------------

    40 

    41 TIMEOUT         = 10

    42 

    43 from SocketServer import ThreadingTCPServer, StreamRequestHandler

    44 

    45 class LogRecordStreamHandler(StreamRequestHandler):

    46     """

    47     Handler for a streaming logging request. It basically logs the record

    48     using whatever logging policy is configured locally.

    49     """

    50 

    51     def handle(self):

    52         """

    53         Handle multiple requests - each expected to be a 4-byte length,

    54         followed by the LogRecord in pickle format. Logs the record

    55         according to whatever policy is configured locally.

    56         """

    57         while 1:

    58             try:

    59                 chunk = self.connection.recv(4)

    60                 if len(chunk) < 4:

    61                     break

    62                 slen = struct.unpack(">L", chunk)[0]

    63                 chunk = self.connection.recv(slen)

    64                 while len(chunk) < slen:

    65                     chunk = chunk + self.connection.recv(slen - len(chunk))

    66                 obj = self.unPickle(chunk)

    67                 record = logging.makeLogRecord(obj)

    68                 self.handleLogRecord(record)

    69             except:

    70                 raise

    71 

    72     def unPickle(self, data):

    73         return cPickle.loads(data)

    74 

    75     def handleLogRecord(self, record):

    76         logname = "logrecv.tcp." + record.name

    77         #If the end-of-messages sentinel is seen, tell the server to terminate

    78         if record.msg == FINISH_UP:

    79             self.server.abort = 1

    80         record.msg = record.msg + " (via " + logname + ")"

    81         logger = logging.getLogger(logname)

    82         logger.handle(record)

    83 

    84 # The server sets socketDataProcessed when it's done.

    85 socketDataProcessed = threading.Event()

    86 

    87 class LogRecordSocketReceiver(ThreadingTCPServer):

    88     """

    89     A simple-minded TCP socket-based logging receiver suitable for test

    90     purposes.

    91     """

    92 

    93     allow_reuse_address = 1

    94 

    95     def __init__(self, host='localhost',

    96                              port=logging.handlers.DEFAULT_TCP_LOGGING_PORT,

    97                      handler=LogRecordStreamHandler):

    98         ThreadingTCPServer.__init__(self, (host, port), handler)

    99         self.abort = 0

   100         self.timeout = 1

   101 

   102     def serve_until_stopped(self):

   103         while not self.abort:

   104             rd, wr, ex = select.select([self.socket.fileno()], [], [],

   105                                        self.timeout)

   106             if rd:

   107                 self.handle_request()

   108         #notify the main thread that we're about to exit

   109         socketDataProcessed.set()

   110         # close the listen socket

   111         self.server_close()

   112 

   113     def process_request(self, request, client_address):

   114         #import threading

   115         t = threading.Thread(target = self.finish_request,

   116                              args = (request, client_address))

   117         t.start()

   118 

   119 def runTCP(tcpserver):

   120     tcpserver.serve_until_stopped()

   121 

   122 #----------------------------------------------------------------------------

   123 # Test 0

   124 #----------------------------------------------------------------------------

   125 

   126 msgcount = 0

   127 

   128 def nextmessage():

   129     global msgcount

   130     rv = "Message %d" % msgcount

   131     msgcount = msgcount + 1

   132     return rv

   133 

   134 def test0():

   135     ERR = logging.getLogger("ERR")

   136     ERR.setLevel(logging.ERROR)

   137     INF = logging.getLogger("INF")

   138     INF.setLevel(logging.INFO)

   139     INF_ERR  = logging.getLogger("INF.ERR")

   140     INF_ERR.setLevel(logging.ERROR)

   141     DEB = logging.getLogger("DEB")

   142     DEB.setLevel(logging.DEBUG)

   143 

   144     INF_UNDEF = logging.getLogger("INF.UNDEF")

   145     INF_ERR_UNDEF = logging.getLogger("INF.ERR.UNDEF")

   146     UNDEF = logging.getLogger("UNDEF")

   147 

   148     GRANDCHILD = logging.getLogger("INF.BADPARENT.UNDEF")

   149     CHILD = logging.getLogger("INF.BADPARENT")

   150 

   151     #These should log

   152     ERR.log(logging.FATAL, nextmessage())

   153     ERR.error(nextmessage())

   154 

   155     INF.log(logging.FATAL, nextmessage())

   156     INF.error(nextmessage())

   157     INF.warn(nextmessage())

   158     INF.info(nextmessage())

   159 

   160     INF_UNDEF.log(logging.FATAL, nextmessage())

   161     INF_UNDEF.error(nextmessage())

   162     INF_UNDEF.warn (nextmessage())

   163     INF_UNDEF.info (nextmessage())

   164 

   165     INF_ERR.log(logging.FATAL, nextmessage())

   166     INF_ERR.error(nextmessage())

   167 

   168     INF_ERR_UNDEF.log(logging.FATAL, nextmessage())

   169     INF_ERR_UNDEF.error(nextmessage())

   170 

   171     DEB.log(logging.FATAL, nextmessage())

   172     DEB.error(nextmessage())

   173     DEB.warn (nextmessage())

   174     DEB.info (nextmessage())

   175     DEB.debug(nextmessage())

   176 

   177     UNDEF.log(logging.FATAL, nextmessage())

   178     UNDEF.error(nextmessage())

   179     UNDEF.warn (nextmessage())

   180     UNDEF.info (nextmessage())

   181 

   182     GRANDCHILD.log(logging.FATAL, nextmessage())

   183     CHILD.log(logging.FATAL, nextmessage())

   184 

   185     #These should not log

   186     ERR.warn(nextmessage())

   187     ERR.info(nextmessage())

   188     ERR.debug(nextmessage())

   189 

   190     INF.debug(nextmessage())

   191     INF_UNDEF.debug(nextmessage())

   192 

   193     INF_ERR.warn(nextmessage())

   194     INF_ERR.info(nextmessage())

   195     INF_ERR.debug(nextmessage())

   196     INF_ERR_UNDEF.warn(nextmessage())

   197     INF_ERR_UNDEF.info(nextmessage())

   198     INF_ERR_UNDEF.debug(nextmessage())

   199 

   200     INF.info(FINISH_UP)

   201 

   202 #----------------------------------------------------------------------------

   203 # Test 1

   204 #----------------------------------------------------------------------------

   205 

   206 #

   207 #   First, we define our levels. There can be as many as you want - the only

   208 #     limitations are that they should be integers, the lowest should be > 0 and

   209 #   larger values mean less information being logged. If you need specific

   210 #   level values which do not fit into these limitations, you can use a

   211 #   mapping dictionary to convert between your application levels and the

   212 #   logging system.

   213 #

   214 SILENT      = 10

   215 TACITURN    = 9

   216 TERSE       = 8

   217 EFFUSIVE    = 7

   218 SOCIABLE    = 6

   219 VERBOSE     = 5

   220 TALKATIVE   = 4

   221 GARRULOUS   = 3

   222 CHATTERBOX  = 2

   223 BORING      = 1

   224 

   225 LEVEL_RANGE = range(BORING, SILENT + 1)

   226 

   227 #

   228 #   Next, we define names for our levels. You don't need to do this - in which

   229 #   case the system will use "Level n" to denote the text for the level.

   230 #

   231 my_logging_levels = {

   232     SILENT      : 'Silent',

   233     TACITURN    : 'Taciturn',

   234     TERSE       : 'Terse',

   235     EFFUSIVE    : 'Effusive',

   236     SOCIABLE    : 'Sociable',

   237     VERBOSE     : 'Verbose',

   238     TALKATIVE   : 'Talkative',

   239     GARRULOUS   : 'Garrulous',

   240     CHATTERBOX  : 'Chatterbox',

   241     BORING      : 'Boring',

   242 }

   243 

   244 #

   245 #   Now, to demonstrate filtering: suppose for some perverse reason we only

   246 #   want to print out all except GARRULOUS messages. Let's create a filter for

   247 #   this purpose...

   248 #

   249 class SpecificLevelFilter(logging.Filter):

   250     def __init__(self, lvl):

   251         self.level = lvl

   252 

   253     def filter(self, record):

   254         return self.level != record.levelno

   255 

   256 class GarrulousFilter(SpecificLevelFilter):

   257     def __init__(self):

   258         SpecificLevelFilter.__init__(self, GARRULOUS)

   259 

   260 #

   261 #   Now, let's demonstrate filtering at the logger. This time, use a filter

   262 #   which excludes SOCIABLE and TACITURN messages. Note that GARRULOUS events

   263 #   are still excluded.

   264 #

   265 class VerySpecificFilter(logging.Filter):

   266     def filter(self, record):

   267         return record.levelno not in [SOCIABLE, TACITURN]

   268 

   269 def message(s):

   270     sys.stdout.write("%s\n" % s)

   271 

   272 SHOULD1 = "This should only be seen at the '%s' logging level (or lower)"

   273 

   274 def test1():

   275 #

   276 #   Now, tell the logging system to associate names with our levels.

   277 #

   278     for lvl in my_logging_levels.keys():

   279         logging.addLevelName(lvl, my_logging_levels[lvl])

   280 

   281 #

   282 #   Now, define a test function which logs an event at each of our levels.

   283 #

   284 

   285     def doLog(log):

   286         for lvl in LEVEL_RANGE:

   287             log.log(lvl, SHOULD1, logging.getLevelName(lvl))

   288 

   289     log = logging.getLogger("")

   290     hdlr = log.handlers[0]

   291 #

   292 #   Set the logging level to each different value and call the utility

   293 #   function to log events.

   294 #   In the output, you should see that each time round the loop, the number of

   295 #   logging events which are actually output decreases.

   296 #

   297     for lvl in LEVEL_RANGE:

   298         message("-- setting logging level to '%s' -----" %

   299                         logging.getLevelName(lvl))

   300         log.setLevel(lvl)

   301         doLog(log)

   302   #

   303   #   Now, we demonstrate level filtering at the handler level. Tell the

   304   #   handler defined above to filter at level 'SOCIABLE', and repeat the

   305   #   above loop. Compare the output from the two runs.

   306   #

   307     hdlr.setLevel(SOCIABLE)

   308     message("-- Filtering at handler level to SOCIABLE --")

   309     for lvl in LEVEL_RANGE:

   310         message("-- setting logging level to '%s' -----" %

   311                       logging.getLevelName(lvl))

   312         log.setLevel(lvl)

   313         doLog(log)

   314 

   315     hdlr.setLevel(0)    #turn off level filtering at the handler

   316 

   317     garr = GarrulousFilter()

   318     hdlr.addFilter(garr)

   319     message("-- Filtering using GARRULOUS filter --")

   320     for lvl in LEVEL_RANGE:

   321         message("-- setting logging level to '%s' -----" %

   322                         logging.getLevelName(lvl))

   323         log.setLevel(lvl)

   324         doLog(log)

   325     spec = VerySpecificFilter()

   326     log.addFilter(spec)

   327     message("-- Filtering using specific filter for SOCIABLE, TACITURN --")

   328     for lvl in LEVEL_RANGE:

   329         message("-- setting logging level to '%s' -----" %

   330                       logging.getLevelName(lvl))

   331         log.setLevel(lvl)

   332         doLog(log)

   333 

   334     log.removeFilter(spec)

   335     hdlr.removeFilter(garr)

   336     #Undo the one level which clashes...for regression tests

   337     logging.addLevelName(logging.DEBUG, "DEBUG")

   338 

   339 #----------------------------------------------------------------------------

   340 # Test 2

   341 #----------------------------------------------------------------------------

   342 

   343 MSG = "-- logging %d at INFO, messages should be seen every 10 events --"

   344 def test2():

   345     logger = logging.getLogger("")

   346     sh = logger.handlers[0]

   347     sh.close()

   348     logger.removeHandler(sh)

   349     mh = logging.handlers.MemoryHandler(10,logging.WARNING, sh)

   350     logger.setLevel(logging.DEBUG)

   351     logger.addHandler(mh)

   352     message("-- logging at DEBUG, nothing should be seen yet --")

   353     logger.debug("Debug message")

   354     message("-- logging at INFO, nothing should be seen yet --")

   355     logger.info("Info message")

   356     message("-- logging at WARNING, 3 messages should be seen --")

   357     logger.warn("Warn message")

   358     for i in xrange(102):

   359         message(MSG % i)

   360         logger.info("Info index = %d", i)

   361     mh.close()

   362     logger.removeHandler(mh)

   363     logger.addHandler(sh)

   364 

   365 #----------------------------------------------------------------------------

   366 # Test 3

   367 #----------------------------------------------------------------------------

   368 

   369 FILTER = "a.b"

   370 

   371 def doLog3():

   372     logging.getLogger("a").info("Info 1")

   373     logging.getLogger("a.b").info("Info 2")

   374     logging.getLogger("a.c").info("Info 3")

   375     logging.getLogger("a.b.c").info("Info 4")

   376     logging.getLogger("a.b.c.d").info("Info 5")

   377     logging.getLogger("a.bb.c").info("Info 6")

   378     logging.getLogger("b").info("Info 7")

   379     logging.getLogger("b.a").info("Info 8")

   380     logging.getLogger("c.a.b").info("Info 9")

   381     logging.getLogger("a.bb").info("Info 10")

   382 

   383 def test3():

   384     root = logging.getLogger()

   385     root.setLevel(logging.DEBUG)

   386     hand = root.handlers[0]

   387     message("Unfiltered...")

   388     doLog3()

   389     message("Filtered with '%s'..." % FILTER)

   390     filt = logging.Filter(FILTER)

   391     hand.addFilter(filt)

   392     doLog3()

   393     hand.removeFilter(filt)

   394 

   395 #----------------------------------------------------------------------------

   396 # Test 4

   397 #----------------------------------------------------------------------------

   398 

   399 # config0 is a standard configuration.

   400 config0 = """

   401 [loggers]

   402 keys=root

   403 

   404 [handlers]

   405 keys=hand1

   406 

   407 [formatters]

   408 keys=form1

   409 

   410 [logger_root]

   411 level=NOTSET

   412 handlers=hand1

   413 

   414 [handler_hand1]

   415 class=StreamHandler

   416 level=NOTSET

   417 formatter=form1

   418 args=(sys.stdout,)

   419 

   420 [formatter_form1]

   421 format=%(levelname)s:%(name)s:%(message)s

   422 datefmt=

   423 """

   424 

   425 # config1 adds a little to the standard configuration.

   426 config1 = """

   427 [loggers]

   428 keys=root,parser

   429 

   430 [handlers]

   431 keys=hand1

   432 

   433 [formatters]

   434 keys=form1

   435 

   436 [logger_root]

   437 level=NOTSET

   438 handlers=hand1

   439 

   440 [logger_parser]

   441 level=DEBUG

   442 handlers=hand1

   443 propagate=1

   444 qualname=compiler.parser

   445 

   446 [handler_hand1]

   447 class=StreamHandler

   448 level=NOTSET

   449 formatter=form1

   450 args=(sys.stdout,)

   451 

   452 [formatter_form1]

   453 format=%(levelname)s:%(name)s:%(message)s

   454 datefmt=

   455 """

   456 

   457 # config2 has a subtle configuration error that should be reported

   458 config2 = string.replace(config1, "sys.stdout", "sys.stbout")

   459 

   460 # config3 has a less subtle configuration error

   461 config3 = string.replace(

   462     config1, "formatter=form1", "formatter=misspelled_name")

   463 

   464 def test4():

   465     for i in range(4):

   466         conf = globals()['config%d' % i]

   467         sys.stdout.write('config%d: ' % i)

   468         loggerDict = logging.getLogger().manager.loggerDict

   469         logging._acquireLock()

   470         try:

   471             saved_handlers = logging._handlers.copy()

   472             saved_handler_list = logging._handlerList[:]

   473             saved_loggers = loggerDict.copy()

   474         finally:

   475             logging._releaseLock()

   476         try:

   477             fn = tempfile.mktemp(".ini")

   478             f = open(fn, "w")

   479             f.write(conf)

   480             f.close()

   481             try:

   482                 logging.config.fileConfig(fn)

   483                 #call again to make sure cleanup is correct

   484                 logging.config.fileConfig(fn)

   485             except:

   486                 t = sys.exc_info()[0]

   487                 message(str(t))

   488             else:

   489                 message('ok.')

   490             os.remove(fn)

   491         finally:

   492             logging._acquireLock()

   493             try:

   494                 logging._handlers.clear()

   495                 logging._handlers.update(saved_handlers)

   496                 logging._handlerList[:] = saved_handler_list

   497                 loggerDict = logging.getLogger().manager.loggerDict

   498                 loggerDict.clear()

   499                 loggerDict.update(saved_loggers)

   500             finally:

   501                 logging._releaseLock()

   502 

   503 #----------------------------------------------------------------------------

   504 # Test 5

   505 #----------------------------------------------------------------------------

   506 

   507 test5_config = """

   508 [loggers]

   509 keys=root

   510 

   511 [handlers]

   512 keys=hand1

   513 

   514 [formatters]

   515 keys=form1

   516 

   517 [logger_root]

   518 level=NOTSET

   519 handlers=hand1

   520 

   521 [handler_hand1]

   522 class=StreamHandler

   523 level=NOTSET

   524 formatter=form1

   525 args=(sys.stdout,)

   526 

   527 [formatter_form1]

   528 class=test.test_logging.FriendlyFormatter

   529 format=%(levelname)s:%(name)s:%(message)s

   530 datefmt=

   531 """

   532 

   533 class FriendlyFormatter (logging.Formatter):

   534     def formatException(self, ei):

   535         return "%s... Don't panic!" % str(ei[0])

   536 

   537 

   538 def test5():

   539     loggerDict = logging.getLogger().manager.loggerDict

   540     logging._acquireLock()

   541     try:

   542         saved_handlers = logging._handlers.copy()

   543         saved_handler_list = logging._handlerList[:]

   544         saved_loggers = loggerDict.copy()

   545     finally:

   546         logging._releaseLock()

   547     try:

   548         fn = tempfile.mktemp(".ini")

   549         f = open(fn, "w")

   550         f.write(test5_config)

   551         f.close()

   552         logging.config.fileConfig(fn)

   553         try:

   554             raise KeyError

   555         except KeyError:

   556             logging.exception("just testing")

   557         os.remove(fn)

   558         hdlr = logging.getLogger().handlers[0]

   559         logging.getLogger().handlers.remove(hdlr)

   560     finally:

   561         logging._acquireLock()

   562         try:

   563             logging._handlers.clear()

   564             logging._handlers.update(saved_handlers)

   565             logging._handlerList[:] = saved_handler_list

   566             loggerDict = logging.getLogger().manager.loggerDict

   567             loggerDict.clear()

   568             loggerDict.update(saved_loggers)

   569         finally:

   570             logging._releaseLock()

   571 

   572 

   573 #----------------------------------------------------------------------------

   574 # Test Harness

   575 #----------------------------------------------------------------------------

   576 def banner(nm, typ):

   577     sep = BANNER % (nm, typ)

   578     sys.stdout.write(sep)

   579     sys.stdout.flush()

   580 

   581 def test_main_inner():

   582     rootLogger = logging.getLogger("")

   583     rootLogger.setLevel(logging.DEBUG)

   584     hdlr = logging.StreamHandler(sys.stdout)

   585     fmt = logging.Formatter(logging.BASIC_FORMAT)

   586     hdlr.setFormatter(fmt)

   587     rootLogger.addHandler(hdlr)

   588 

   589     # Find an unused port number

   590     port = logging.handlers.DEFAULT_TCP_LOGGING_PORT

   591     while port < logging.handlers.DEFAULT_TCP_LOGGING_PORT+100:

   592         try:

   593             tcpserver = LogRecordSocketReceiver(port=port)

   594         except socket.error:

   595             port += 1

   596         else:

   597             break

   598     else:

   599         raise ImportError, "Could not find unused port"

   600 

   601 

   602     #Set up a handler such that all events are sent via a socket to the log

   603     #receiver (logrecv).

   604     #The handler will only be added to the rootLogger for some of the tests

   605     shdlr = logging.handlers.SocketHandler('localhost', port)

   606 

   607     #Configure the logger for logrecv so events do not propagate beyond it.

   608     #The sockLogger output is buffered in memory until the end of the test,

   609     #and printed at the end.

   610     sockOut = cStringIO.StringIO()

   611     sockLogger = logging.getLogger("logrecv")

   612     sockLogger.setLevel(logging.DEBUG)

   613     sockhdlr = logging.StreamHandler(sockOut)

   614     sockhdlr.setFormatter(logging.Formatter(

   615                                    "%(name)s -> %(levelname)s: %(message)s"))

   616     sockLogger.addHandler(sockhdlr)

   617     sockLogger.propagate = 0

   618 

   619     #Set up servers

   620     threads = []

   621     #sys.stdout.write("About to start TCP server...\n")

   622     threads.append(threading.Thread(target=runTCP, args=(tcpserver,)))

   623 

   624     for thread in threads:

   625         thread.start()

   626     try:

   627         banner("log_test0", "begin")

   628 

   629         rootLogger.addHandler(shdlr)

   630         test0()

   631         # XXX(nnorwitz): Try to fix timing related test failures.

   632         # This sleep gives us some extra time to read messages.

   633         # The test generally only fails on Solaris without this sleep.

   634         time.sleep(2.0)

   635         shdlr.close()

   636         rootLogger.removeHandler(shdlr)

   637 

   638         banner("log_test0", "end")

   639 

   640         for t in range(1,6):

   641             banner("log_test%d" % t, "begin")

   642             globals()['test%d' % t]()

   643             banner("log_test%d" % t, "end")

   644 

   645     finally:

   646         #wait for TCP receiver to terminate

   647         socketDataProcessed.wait()

   648         # ensure the server dies

   649         tcpserver.abort = 1

   650         for thread in threads:

   651             thread.join(2.0)

   652         banner("logrecv output", "begin")

   653         sys.stdout.write(sockOut.getvalue())

   654         sockOut.close()

   655         sockLogger.removeHandler(sockhdlr)

   656         sockhdlr.close()

   657         banner("logrecv output", "end")

   658         sys.stdout.flush()

   659         try:

   660             hdlr.close()

   661         except:

   662             pass

   663         rootLogger.removeHandler(hdlr)

   664 

   665 # Set the locale to the platform-dependent default.  I have no idea

   666 # why the test does this, but in any case we save the current locale

   667 # first and restore it at the end.

   668 @run_with_locale('LC_ALL', '')

   669 def test_main():

   670     # Save and restore the original root logger level across the tests.

   671     # Otherwise, e.g., if any test using cookielib runs after test_logging,

   672     # cookielib's debug-level logger tries to log messages, leading to

   673     # confusing:

   674     #    No handlers could be found for logger "cookielib"

   675     # output while the tests are running.

   676     root_logger = logging.getLogger("")

   677     original_logging_level = root_logger.getEffectiveLevel()

   678     try:

   679         test_main_inner()

   680     finally:

   681         root_logger.setLevel(original_logging_level)

   682 

   683 if __name__ == "__main__":

   684     sys.stdout.write("test_logging\n")

   685     test_main()