Martin Blanchard pushed to branch mablanch/23-new-logging at BuildGrid / buildgrid
Commits:
- 
0550b93a
by Martin Blanchard at 2018-11-12T14:39:46Z
- 
b7029a51
by Martin Blanchard at 2018-11-12T14:40:36Z
- 
3984c93a
by Martin Blanchard at 2018-11-12T14:40:38Z
3 changed files:
Changes:
| ... | ... | @@ -27,6 +27,7 @@ import os | 
| 27 | 27 |  import click
 | 
| 28 | 28 |  import grpc
 | 
| 29 | 29 |  | 
| 30 | +from buildgrid.settings import LOG_RECORD_FORMAT
 | |
| 30 | 31 |  from buildgrid.utils import read_file
 | 
| 31 | 32 |  | 
| 32 | 33 |  CONTEXT_SETTINGS = dict(auto_envvar_prefix='BUILDGRID')
 | 
| ... | ... | @@ -139,10 +140,12 @@ class BuildGridCLI(click.MultiCommand): | 
| 139 | 140 |  | 
| 140 | 141 |  | 
| 141 | 142 |  @click.command(cls=BuildGridCLI, context_settings=CONTEXT_SETTINGS)
 | 
| 143 | +@click.option('--no-print', is_flag=True, show_default=True,
 | |
| 144 | +              help="Do not print log records to stdout/stderr.")
 | |
| 142 | 145 |  @click.option('-v', '--verbose', count=True,
 | 
| 143 | 146 |                help='Increase log verbosity level.')
 | 
| 144 | 147 |  @pass_context
 | 
| 145 | -def cli(context, verbose):
 | |
| 148 | +def cli(context, no_print, verbose):
 | |
| 146 | 149 |      """BuildGrid App"""
 | 
| 147 | 150 |      logger = logging.getLogger()
 | 
| 148 | 151 |  | 
| ... | ... | @@ -152,14 +155,15 @@ def cli(context, verbose): | 
| 152 | 155 |      for log_filter in logger.filters[:]:
 | 
| 153 | 156 |          logger.removeFilter(log_filter)
 | 
| 154 | 157 |  | 
| 155 | -    logging.basicConfig(
 | |
| 156 | -        format='%(asctime)s:%(name)32.32s][%(levelname)5.5s]: %(message)s')
 | |
| 157 | - | |
| 158 | +    # Do not register a stream handler if no-print is requested:
 | |
| 159 | +    if not no_print:
 | |
| 160 | +        logging.basicConfig(format=LOG_RECORD_FORMAT)
 | |
| 161 | +    else:
 | |
| 162 | +        logging.basicConfig(format=LOG_RECORD_FORMAT,
 | |
| 163 | +                            handlers=[logging.NullHandler()])
 | |
| 158 | 164 |      if verbose == 1:
 | 
| 159 | 165 |          logger.setLevel(logging.WARNING)
 | 
| 160 | 166 |      elif verbose == 2:
 | 
| 161 | 167 |          logger.setLevel(logging.INFO)
 | 
| 162 | 168 |      elif verbose >= 3:
 | 
| 163 | 169 |          logger.setLevel(logging.DEBUG) | 
| 164 | -    else:
 | |
| 165 | -        logger.setLevel(logging.ERROR) | 
| ... | ... | @@ -16,10 +16,12 @@ | 
| 16 | 16 |  import asyncio
 | 
| 17 | 17 |  from concurrent import futures
 | 
| 18 | 18 |  import logging
 | 
| 19 | +from logging.handlers import QueueHandler
 | |
| 19 | 20 |  import os
 | 
| 20 | 21 |  import time
 | 
| 21 | 22 |  | 
| 22 | 23 |  import grpc
 | 
| 24 | +import janus
 | |
| 23 | 25 |  | 
| 24 | 26 |  from buildgrid.server.cas.service import ByteStreamService, ContentAddressableStorageService
 | 
| 25 | 27 |  from buildgrid.server.actioncache.service import ActionCacheService
 | 
| ... | ... | @@ -54,6 +56,10 @@ class BuildGridServer: | 
| 54 | 56 |  | 
| 55 | 57 |          self.__main_loop = asyncio.get_event_loop()
 | 
| 56 | 58 |          self.__monitoring_task = None
 | 
| 59 | +        self.__logging_task = None
 | |
| 60 | + | |
| 61 | +        self.__logging_queue = janus.Queue(loop=self.__main_loop)
 | |
| 62 | +        self.__logging_handler = None
 | |
| 57 | 63 |  | 
| 58 | 64 |          self._execution_service = None
 | 
| 59 | 65 |          self._bots_service = None
 | 
| ... | ... | @@ -72,8 +78,13 @@ class BuildGridServer: | 
| 72 | 78 |          """
 | 
| 73 | 79 |          self.__grpc_server.start()
 | 
| 74 | 80 |  | 
| 81 | +        self._setup_logging_handler()
 | |
| 82 | +        self.__logging_task = asyncio.ensure_future(
 | |
| 83 | +            self._logging_worker(), loop=self.__main_loop)
 | |
| 84 | + | |
| 75 | 85 |          self.__monitoring_task = asyncio.ensure_future(
 | 
| 76 | 86 |              self._monitoring_worker(period=MONITORING_PERIOD), loop=self.__main_loop)
 | 
| 87 | + | |
| 77 | 88 |          self.__main_loop.run_forever()
 | 
| 78 | 89 |  | 
| 79 | 90 |      def stop(self, grace=0):
 | 
| ... | ... | @@ -84,6 +95,8 @@ class BuildGridServer: | 
| 84 | 95 |          """
 | 
| 85 | 96 |          if self.__monitoring_task is not None:
 | 
| 86 | 97 |              self.__monitoring_task.cancel()
 | 
| 98 | +        if self.__logging_task is not None:
 | |
| 99 | +            self.__logging_task.cancel()
 | |
| 87 | 100 |  | 
| 88 | 101 |          self.__grpc_server.stop(grace)
 | 
| 89 | 102 |  | 
| ... | ... | @@ -205,6 +218,25 @@ class BuildGridServer: | 
| 205 | 218 |  | 
| 206 | 219 |      # --- Private API ---
 | 
| 207 | 220 |  | 
| 221 | +    def _setup_logging_handler(self):
 | |
| 222 | +        self.__logging_handler = QueueHandler(self.__logging_queue.sync_q)
 | |
| 223 | + | |
| 224 | +        root_logger = logging.getLogger()
 | |
| 225 | +        root_logger.addHandler(self.__logging_handler)
 | |
| 226 | + | |
| 227 | +    async def _logging_worker(self):
 | |
| 228 | +        while True:
 | |
| 229 | +            try:
 | |
| 230 | +                log_record = await self.__logging_queue.async_q.get()
 | |
| 231 | + | |
| 232 | +                print(log_record)
 | |
| 233 | + | |
| 234 | +            except asyncio.CancelledError:
 | |
| 235 | +                break
 | |
| 236 | + | |
| 237 | +        if len(asyncio.all_tasks(loop=self.__main_loop)) <= 1:
 | |
| 238 | +            self.__main_loop.stop()
 | |
| 239 | + | |
| 208 | 240 |      async def _monitoring_worker(self, period=1):
 | 
| 209 | 241 |          while True:
 | 
| 210 | 242 |              try:
 | 
| ... | ... | @@ -229,4 +261,5 @@ class BuildGridServer: | 
| 229 | 261 |              except asyncio.CancelledError:
 | 
| 230 | 262 |                  break
 | 
| 231 | 263 |  | 
| 232 | -        self.__main_loop.stop() | |
| 264 | +        if len(asyncio.all_tasks(loop=self.__main_loop)) <= 1:
 | |
| 265 | +            self.__main_loop.stop() | 
| ... | ... | @@ -24,3 +24,8 @@ HASH_LENGTH = HASH().digest_size * 2 | 
| 24 | 24 |  | 
| 25 | 25 |  # Period, in seconds, for the monitoring cycle:
 | 
| 26 | 26 |  MONITORING_PERIOD = 5.0
 | 
| 27 | + | |
| 28 | +# String format for log records:
 | |
| 29 | +LOG_RECORD_FORMAT = '%(asctime)s:%(name)36.36s][%(levelname)5.5s]: %(message)s'
 | |
| 30 | +# The different log record attributes are documented here:
 | |
| 31 | +# https://docs.python.org/3/library/logging.html#logrecord-attributes | 
