buildgrid/_app/_logging.py

-# Copyright (C) 2018 Bloomberg LP
-#
-# Licensed under the Apache License, Version 2.0 (the "License");
-# you may not use this file except in compliance with the License.
-# You may obtain a copy of the License at
-#
-#  <http://www.apache.org/licenses/LICENSE-2.0>
-#
-# Unless required by applicable law or agreed to in writing, software
-# distributed under the License is distributed on an "AS IS" BASIS,
-# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
-# See the License for the specific language governing permissions and
-# limitations under the License.
-
-
-import logging
-
-
-def bgd_logger():
-    formatter = logging.Formatter(
-        fmt='%(asctime)s - %(name)s - %(levelname)s - %(message)s'
-    )
-
-    logger = logging.getLogger()
-    logger.setLevel(logging.INFO)
-
-    handler = logging.StreamHandler()
-    handler.setFormatter(formatter)
-
-    logger.addHandler(handler)
-
-    return logger

buildgrid/_app/cli.py

@@ -21,16 +21,14 @@ Any files in the commands/ folder with the name cmd_*.py
 will be attempted to be imported.
 """
 
-import os
 import logging
+import os
 
 import click
 import grpc
 
 from buildgrid.utils import read_file
 
-from . import _logging
-
 CONTEXT_SETTINGS = dict(auto_envvar_prefix='BUILDGRID')
 
 
@@ -141,12 +139,27 @@ class BuildGridCLI(click.MultiCommand):
 
 
 @click.command(cls=BuildGridCLI, context_settings=CONTEXT_SETTINGS)
-@click.option('-v', '--verbose', is_flag=True,
-              help='Enables verbose mode.')
+@click.option('-v', '--verbose', count=True,
+              help='Increase log verbosity level.')
 @pass_context
 def cli(context, verbose):
     """BuildGrid App"""
-    logger = _logging.bgd_logger()
-    context.verbose = verbose
-    if verbose:
+    logger = logging.getLogger()
+
+    # Clean-up root logger for any pre-configuration:
+    for log_handler in logger.handlers[:]:
+        logger.removeHandler(log_handler)
+    for log_filter in logger.filters[:]:
+        logger.removeFilter(log_filter)
+
+    logging.basicConfig(
+        format='%(asctime)s:%(name)32.32s][%(levelname)5.5s]: %(message)s')
+
+    if verbose == 1:
+        logger.setLevel(logging.WARNING)
+    elif verbose == 2:
+        logger.setLevel(logging.INFO)
+    elif verbose >= 3:
         logger.setLevel(logging.DEBUG)
+    else:
+        logger.setLevel(logging.ERROR)

buildgrid/bot/bot.py

@@ -30,7 +30,7 @@ class Bot:
     """
 
     def __init__(self, bot_session, update_period=1):
-        self.logger = logging.getLogger(__name__)
+        self.__logger = logging.getLogger(__name__)
 
         self._bot_session = bot_session
         self._update_period = update_period

buildgrid/bot/bot_interface.py

@@ -31,8 +31,8 @@ class BotInterface:
     """
 
     def __init__(self, channel):
-        self.logger = logging.getLogger(__name__)
-        self.logger.info(channel)
+        self.__logger = logging.getLogger(__name__)
+
         self._stub = bots_pb2_grpc.BotsStub(channel)
 
     def create_bot_session(self, parent, bot_session):

buildgrid/bot/bot_session.py

@@ -43,8 +43,7 @@ class BotSession:
         If a bot attempts to update an invalid session, it must be rejected and
         may be put in quarantine.
         """
-
-        self.logger = logging.getLogger(__name__)
+        self.__logger = logging.getLogger(__name__)
 
         self._bot_id = '{}.{}'.format(parent, platform.node())
         self._context = None
@@ -64,20 +63,20 @@ class BotSession:
         self._worker = worker
 
     def create_bot_session(self, work, context=None):
-        self.logger.debug("Creating bot session")
+        self.__logger.debug("Creating bot session")
         self._work = work
         self._context = context
 
         session = self._interface.create_bot_session(self._parent, self.get_pb2())
         self._name = session.name
 
-        self.logger.info("Created bot session with name: [{}]".format(self._name))
+        self.__logger.info("Created bot session with name: [%s]", self._name)
 
         for lease in session.leases:
             self._update_lease_from_server(lease)
 
     def update_bot_session(self):
-        self.logger.debug("Updating bot session: [{}]".format(self._bot_id))
+        self.__logger.debug("Updating bot session: [%s]", self._bot_id)
         session = self._interface.update_bot_session(self.get_pb2())
         for k, v in list(self._leases.items()):
             if v.state == LeaseState.COMPLETED.value:
@@ -113,25 +112,25 @@ class BotSession:
             asyncio.ensure_future(self.create_work(lease))
 
     async def create_work(self, lease):
-        self.logger.debug("Work created: [{}]".format(lease.id))
+        self.__logger.debug("Work created: [%s]", lease.id)
         loop = asyncio.get_event_loop()
 
         try:
             lease = await loop.run_in_executor(None, self._work, self._context, lease)
 
         except grpc.RpcError as e:
-            self.logger.error("RPC error thrown: [{}]".format(e))
+            self.__logger.error(e)
             lease.status.CopyFrom(e.code())
 
         except BotError as e:
-            self.logger.error("Internal bot error thrown: [{}]".format(e))
+            self.__logger.error(e)
             lease.status.code = code_pb2.INTERNAL
 
         except Exception as e:
-            self.logger.error("Exception thrown: [{}]".format(e))
+            self.__logger.error(e)
             lease.status.code = code_pb2.INTERNAL
 
-        self.logger.debug("Work complete: [{}]".format(lease.id))
+        self.__logger.debug("Work complete: [%s]", lease.id)
         self.lease_completed(lease)
 
 

buildgrid/client/cas.py

@@ -311,7 +311,7 @@ class Downloader:
 
         return read_blobs
 
-    def _fetch_file(self, digest, file_path):
+    def _fetch_file(self, digest, file_path, is_executable=False):
         """Fetches a file using ByteStream.Read()"""
         if self.instance_name:
             resource_name = '/'.join([self.instance_name, 'blobs',
@@ -332,7 +332,10 @@ class Downloader:
 
             assert byte_file.tell() == digest.size_bytes
 
-    def _queue_file(self, digest, file_path):
+        if is_executable:
+            os.chmod(file_path, 0o755)  # rwxr-xr-x
+
+    def _queue_file(self, digest, file_path, is_executable=False):
         """Queues a file for later batch download"""
         if self.__file_request_size + digest.ByteSize() > MAX_REQUEST_SIZE:
             self.flush()
@@ -341,22 +344,25 @@ class Downloader:
         elif self.__file_request_count >= MAX_REQUEST_COUNT:
             self.flush()
 
-        self.__file_requests[digest.hash] = (digest, file_path)
+        self.__file_requests[digest.hash] = (digest, file_path, is_executable)
         self.__file_request_count += 1
         self.__file_request_size += digest.ByteSize()
         self.__file_response_size += digest.size_bytes
 
     def _fetch_file_batch(self, batch):
         """Sends queued data using ContentAddressableStorage.BatchReadBlobs()"""
-        batch_digests = [digest for digest, _ in batch.values()]
+        batch_digests = [digest for digest, _, _ in batch.values()]
         batch_blobs = self._fetch_blob_batch(batch_digests)
 
-        for (_, file_path), file_blob in zip(batch.values(), batch_blobs):
+        for (_, file_path, is_executable), file_blob in zip(batch.values(), batch_blobs):
             os.makedirs(os.path.dirname(file_path), exist_ok=True)
 
             with open(file_path, 'wb') as byte_file:
                 byte_file.write(file_blob)
 
+            if is_executable:
+                os.chmod(file_path, 0o755)  # rwxr-xr-x
+
     def _fetch_directory(self, digest, directory_path):
         """Fetches a file using ByteStream.GetTree()"""
         # Better fail early if the local root path cannot be created:
@@ -414,7 +420,7 @@ class Downloader:
         for file_node in root_directory.files:
             file_path = os.path.join(root_path, file_node.name)
 
-            self._queue_file(file_node.digest, file_path)
+            self._queue_file(file_node.digest, file_path, is_executable=file_node.is_executable)
 
         for directory_node in root_directory.directories:
             directory_path = os.path.join(root_path, directory_node.name)

buildgrid/server/actioncache/service.py

@@ -32,7 +32,7 @@ from buildgrid._protos.build.bazel.remote.execution.v2 import remote_execution_p
 class ActionCacheService(remote_execution_pb2_grpc.ActionCacheServicer):
 
     def __init__(self, server):
-        self.logger = logging.getLogger(__name__)
+        self.__logger = logging.getLogger(__name__)
 
         self._instances = {}
 
@@ -42,34 +42,38 @@ class ActionCacheService(remote_execution_pb2_grpc.ActionCacheServicer):
         self._instances[name] = instance
 
     def GetActionResult(self, request, context):
+        self.__logger.debug("GetActionResult request from [%s]", context.peer())
+
         try:
             instance = self._get_instance(request.instance_name)
             return instance.get_action_result(request.action_digest)
 
         except InvalidArgumentError as e:
-            self.logger.error(e)
+            self.__logger.error(e)
             context.set_details(str(e))
             context.set_code(grpc.StatusCode.INVALID_ARGUMENT)
 
         except NotFoundError as e:
-            self.logger.debug(e)
+            self.__logger.debug(e)
             context.set_code(grpc.StatusCode.NOT_FOUND)
 
         return remote_execution_pb2.ActionResult()
 
     def UpdateActionResult(self, request, context):
+        self.__logger.debug("UpdateActionResult request from [%s]", context.peer())
+
         try:
             instance = self._get_instance(request.instance_name)
             instance.update_action_result(request.action_digest, request.action_result)
             return request.action_result
 
         except InvalidArgumentError as e:
-            self.logger.error(e)
+            self.__logger.error(e)
             context.set_details(str(e))
             context.set_code(grpc.StatusCode.INVALID_ARGUMENT)
 
         except NotImplementedError as e:
-            self.logger.error(e)
+            self.__logger.error(e)
             context.set_code(grpc.StatusCode.UNIMPLEMENTED)
 
         return remote_execution_pb2.ActionResult()

buildgrid/server/bots/instance.py

@@ -31,7 +31,7 @@ from ..job import LeaseState
 class BotsInterface:
 
     def __init__(self, scheduler):
-        self.logger = logging.getLogger(__name__)
+        self.__logger = logging.getLogger(__name__)
 
         self._bot_ids = {}
         self._bot_sessions = {}
@@ -64,7 +64,7 @@ class BotsInterface:
 
         self._bot_ids[name] = bot_id
         self._bot_sessions[name] = bot_session
-        self.logger.info("Created bot session name=[{}] with bot_id=[{}]".format(name, bot_id))
+        self.__logger.info("Created bot session name=[%s] with bot_id=[%s]", name, bot_id)
 
         # TODO: Send worker capabilities to the scheduler!
         leases = self._scheduler.request_job_leases({})
@@ -77,7 +77,7 @@ class BotsInterface:
         """ Client updates the server. Any changes in state to the Lease should be
         registered server side. Assigns available leases with work.
         """
-        self.logger.debug("Updating bot session name={}".format(name))
+        self.__logger.debug("Updating bot session name=[%s]", name)
         self._check_bot_ids(bot_session.bot_id, name)
 
         leases = filter(None, [self.check_states(lease) for lease in bot_session.leases])
@@ -173,12 +173,12 @@ class BotsInterface:
         if bot_id is None:
             raise InvalidArgumentError("Bot id does not exist: [{}]".format(name))
 
-        self.logger.debug("Attempting to close [{}] with name: [{}]".format(bot_id, name))
+        self.__logger.debug("Attempting to close [%s] with name: [%s]", bot_id, name)
         for lease in self._bot_sessions[name].leases:
             if lease.state != LeaseState.COMPLETED.value:
                 # TODO: Be wary here, may need to handle rejected leases in future
                 self._scheduler.retry_job(lease.id)
 
-        self.logger.debug("Closing bot session: [{}]".format(name))
+        self.__logger.debug("Closing bot session: [%s]", name)
         self._bot_ids.pop(name)
-        self.logger.info("Closed bot [{}] with name: [{}]".format(bot_id, name))
+        self.__logger.info("Closed bot [%s] with name: [%s]", bot_id, name)

buildgrid/server/bots/service.py

@@ -33,7 +33,7 @@ from buildgrid._protos.google.devtools.remoteworkers.v1test2 import bots_pb2_grp
 class BotsService(bots_pb2_grpc.BotsServicer):
 
     def __init__(self, server):
-        self.logger = logging.getLogger(__name__)
+        self.__logger = logging.getLogger(__name__)
 
         self._instances = {}
 
@@ -43,6 +43,8 @@ class BotsService(bots_pb2_grpc.BotsServicer):
         self._instances[name] = instance
 
     def CreateBotSession(self, request, context):
+        self.__logger.debug("CreateBotSession request from [%s]", context.peer())
+
         try:
             parent = request.parent
             instance = self._get_instance(request.parent)
@@ -50,13 +52,15 @@ class BotsService(bots_pb2_grpc.BotsServicer):
                                                request.bot_session)
 
         except InvalidArgumentError as e:
-            self.logger.error(e)
+            self.__logger.error(e)
             context.set_details(str(e))
             context.set_code(grpc.StatusCode.INVALID_ARGUMENT)
 
         return bots_pb2.BotSession()
 
     def UpdateBotSession(self, request, context):
+        self.__logger.debug("UpdateBotSession request from [%s]", context.peer())
+
         try:
             names = request.name.split("/")
             # Operation name should be in format:
@@ -68,23 +72,25 @@ class BotsService(bots_pb2_grpc.BotsServicer):
                                                request.bot_session)
 
         except InvalidArgumentError as e:
-            self.logger.error(e)
+            self.__logger.error(e)
             context.set_details(str(e))
             context.set_code(grpc.StatusCode.INVALID_ARGUMENT)
 
         except OutOfSyncError as e:
-            self.logger.error(e)
+            self.__logger.error(e)
             context.set_details(str(e))
             context.set_code(grpc.StatusCode.DATA_LOSS)
 
         except NotImplementedError as e:
-            self.logger.error(e)
+            self.__logger.error(e)
             context.set_details(str(e))
             context.set_code(grpc.StatusCode.UNIMPLEMENTED)
 
         return bots_pb2.BotSession()
 
     def PostBotEventTemp(self, request, context):
+        self.__logger.debug("PostBotEventTemp request from [%s]", context.peer())
+
         context.set_code(grpc.StatusCode.UNIMPLEMENTED)
         return Empty()
 

buildgrid/server/cas/instance.py

@@ -19,6 +19,8 @@ Storage Instances
 Instances of CAS and ByteStream
 """
 
+import logging
+
 from buildgrid._exceptions import InvalidArgumentError, NotFoundError, OutOfRangeError
 from buildgrid._protos.google.bytestream import bytestream_pb2
 from buildgrid._protos.build.bazel.remote.execution.v2 import remote_execution_pb2 as re_pb2
@@ -28,6 +30,8 @@ from buildgrid.settings import HASH
 class ContentAddressableStorageInstance:
 
     def __init__(self, storage):
+        self.__logger = logging.getLogger(__name__)
+
         self._storage = storage
 
     def register_instance_with_server(self, instance_name, server):
@@ -60,6 +64,8 @@ class ByteStreamInstance:
     BLOCK_SIZE = 1 * 1024 * 1024  # 1 MB block size
 
     def __init__(self, storage):
+        self.__logger = logging.getLogger(__name__)
+
         self._storage = storage
 
     def register_instance_with_server(self, instance_name, server):

buildgrid/server/cas/service.py

@@ -35,7 +35,7 @@ from buildgrid._protos.build.bazel.remote.execution.v2 import remote_execution_p
 class ContentAddressableStorageService(remote_execution_pb2_grpc.ContentAddressableStorageServicer):
 
     def __init__(self, server):
-        self.logger = logging.getLogger(__name__)
+        self.__logger = logging.getLogger(__name__)
 
         self._instances = {}
 
@@ -45,42 +45,48 @@ class ContentAddressableStorageService(remote_execution_pb2_grpc.ContentAddressa
         self._instances[name] = instance
 
     def FindMissingBlobs(self, request, context):
+        self.__logger.debug("FindMissingBlobs request from [%s]", context.peer())
+
         try:
-            self.logger.debug("FindMissingBlobs request: [{}]".format(request))
             instance = self._get_instance(request.instance_name)
             response = instance.find_missing_blobs(request.blob_digests)
-            self.logger.debug("FindMissingBlobs response: [{}]".format(response))
+
             return response
 
         except InvalidArgumentError as e:
-            self.logger.error(e)
+            self.__logger.error(e)
             context.set_details(str(e))
             context.set_code(grpc.StatusCode.INVALID_ARGUMENT)
 
         return remote_execution_pb2.FindMissingBlobsResponse()
 
     def BatchUpdateBlobs(self, request, context):
+        self.__logger.debug("BatchUpdateBlobs request from [%s]", context.peer())
+
         try:
-            self.logger.debug("BatchUpdateBlobs request: [{}]".format(request))
             instance = self._get_instance(request.instance_name)
             response = instance.batch_update_blobs(request.requests)
-            self.logger.debug("FindMissingBlobs response: [{}]".format(response))
+
             return response
 
         except InvalidArgumentError as e:
-            self.logger.error(e)
+            self.__logger.error(e)
             context.set_details(str(e))
             context.set_code(grpc.StatusCode.INVALID_ARGUMENT)
 
         return remote_execution_pb2.BatchReadBlobsResponse()
 
     def BatchReadBlobs(self, request, context):
+        self.__logger.debug("BatchReadBlobs request from [%s]", context.peer())
+
         context.set_code(grpc.StatusCode.UNIMPLEMENTED)
         context.set_details('Method not implemented!')
 
         return remote_execution_pb2.BatchReadBlobsResponse()
 
     def GetTree(self, request, context):
+        self.__logger.debug("GetTree request from [%s]", context.peer())
+
         context.set_code(grpc.StatusCode.UNIMPLEMENTED)
         context.set_details('Method not implemented!')
 
@@ -97,7 +103,7 @@ class ContentAddressableStorageService(remote_execution_pb2_grpc.ContentAddressa
 class ByteStreamService(bytestream_pb2_grpc.ByteStreamServicer):
 
     def __init__(self, server):
-        self.logger = logging.getLogger(__name__)
+        self.__logger = logging.getLogger(__name__)
 
         self._instances = {}
 
@@ -107,8 +113,9 @@ class ByteStreamService(bytestream_pb2_grpc.ByteStreamServicer):
         self._instances[name] = instance
 
     def Read(self, request, context):
+        self.__logger.debug("Read request from [%s]", context.peer())
+
         try:
-            self.logger.debug("Read request: [{}]".format(request))
             path = request.resource_name.split("/")
             instance_name = path[0]
 
@@ -131,30 +138,29 @@ class ByteStreamService(bytestream_pb2_grpc.ByteStreamServicer):
                                      request.read_limit)
 
         except InvalidArgumentError as e:
-            self.logger.error(e)
+            self.__logger.error(e)
             context.set_details(str(e))
             context.set_code(grpc.StatusCode.INVALID_ARGUMENT)
             yield bytestream_pb2.ReadResponse()
 
         except NotFoundError as e:
-            self.logger.error(e)
+            self.__logger.error(e)
             context.set_details(str(e))
             context.set_code(grpc.StatusCode.NOT_FOUND)
             yield bytestream_pb2.ReadResponse()
 
         except OutOfRangeError as e:
-            self.logger.error(e)
+            self.__logger.error(e)
             context.set_details(str(e))
             context.set_code(grpc.StatusCode.OUT_OF_RANGE)
             yield bytestream_pb2.ReadResponse()
 
-            self.logger.debug("Read finished.")
-
     def Write(self, requests, context):
+        self.__logger.debug("Write request from [%s]", context.peer())
+
         try:
             requests, request_probe = tee(requests, 2)
             first_request = next(request_probe)
-            self.logger.debug("First write request: [{}]".format(first_request))
 
             path = first_request.resource_name.split("/")
 
@@ -175,21 +181,21 @@ class ByteStreamService(bytestream_pb2_grpc.ByteStreamServicer):
 
             instance = self._get_instance(instance_name)
             response = instance.write(requests)
-            self.logger.debug("Write response: [{}]".format(response))
+
             return response
 
         except NotImplementedError as e:
-            self.logger.error(e)
+            self.__logger.error(e)
             context.set_details(str(e))
             context.set_code(grpc.StatusCode.UNIMPLEMENTED)
 
         except InvalidArgumentError as e:
-            self.logger.error(e)
+            self.__logger.error(e)
             context.set_details(str(e))
             context.set_code(grpc.StatusCode.INVALID_ARGUMENT)
 
         except NotFoundError as e:
-            self.logger.error(e)
+            self.__logger.error(e)
             context.set_details(str(e))
             context.set_code(grpc.StatusCode.NOT_FOUND)
 

buildgrid/server/cas/storage/disk.py

@@ -20,6 +20,7 @@ DiskStorage
 A CAS storage provider that stores files as blobs on disk.
 """
 
+import logging
 import os
 import tempfile
 
@@ -29,6 +30,8 @@ from .storage_abc import StorageABC
 class DiskStorage(StorageABC):
 
     def __init__(self, path):
+        self.__logger = logging.getLogger(__name__)
+
         if not os.path.isabs(path):
             self.__root_path = os.path.abspath(path)
         else:

buildgrid/server/cas/storage/lru_memory_cache.py

@@ -43,6 +43,8 @@ class _NullBytesIO(io.BufferedIOBase):
 class LRUMemoryCache(StorageABC):
 
     def __init__(self, limit):
+        self.__logger = logging.getLogger(__name__)
+
         self._limit = limit
         self._storage = collections.OrderedDict()
         self._bytes_stored = 0

buildgrid/server/cas/storage/remote.py

@@ -35,7 +35,7 @@ from .storage_abc import StorageABC
 class RemoteStorage(StorageABC):
 
     def __init__(self, channel, instance_name):
-        self.logger = logging.getLogger(__name__)
+        self.__logger = logging.getLogger(__name__)
 
         self.instance_name = instance_name
         self.channel = channel

buildgrid/server/cas/storage/s3.py

@@ -21,6 +21,7 @@ A storage provider that stores data in an Amazon S3 bucket.
 """
 
 import io
+import logging
 
 import boto3
 from botocore.exceptions import ClientError
@@ -31,6 +32,8 @@ from .storage_abc import StorageABC
 class S3Storage(StorageABC):
 
     def __init__(self, bucket, **kwargs):
+        self.__logger = logging.getLogger(__name__)
+
         self._bucket = bucket
         self._s3 = boto3.resource('s3', **kwargs)
 

buildgrid/server/cas/storage/with_cache.py

@@ -26,6 +26,7 @@ the fallback.
 """
 
 import io
+import logging
 
 from .storage_abc import StorageABC
 
@@ -118,6 +119,8 @@ class _CachingTee(io.RawIOBase):
 class WithCacheStorage(StorageABC):
 
     def __init__(self, cache, fallback):
+        self.__logger = logging.getLogger(__name__)
+
         self._cache = cache
         self._fallback = fallback
 

buildgrid/server/controller.py

@@ -37,9 +37,9 @@ from .operations.instance import OperationsInstance
 class ExecutionController:
 
     def __init__(self, action_cache=None, storage=None):
-        scheduler = Scheduler(action_cache)
+        self.__logger = logging.getLogger(__name__)
 
-        self.logger = logging.getLogger(__name__)
+        scheduler = Scheduler(action_cache)
 
         self._execution_instance = ExecutionInstance(scheduler, storage)
         self._bots_interface = BotsInterface(scheduler)

buildgrid/server/execution/instance.py

@@ -30,7 +30,8 @@ from ..job import Job
 class ExecutionInstance:
 
     def __init__(self, scheduler, storage):
-        self.logger = logging.getLogger(__name__)
+        self.__logger = logging.getLogger(__name__)
+
         self._storage = storage
         self._scheduler = scheduler
 

buildgrid/server/execution/service.py

@@ -34,7 +34,8 @@ from buildgrid._protos.google.longrunning import operations_pb2
 class ExecutionService(remote_execution_pb2_grpc.ExecutionServicer):
 
     def __init__(self, server):
-        self.logger = logging.getLogger(__name__)
+        self.__logger = logging.getLogger(__name__)
+
         self._instances = {}
         remote_execution_pb2_grpc.add_ExecutionServicer_to_server(self, server)
 
@@ -42,6 +43,8 @@ class ExecutionService(remote_execution_pb2_grpc.ExecutionServicer):
         self._instances[name] = instance
 
     def Execute(self, request, context):
+        self.__logger.debug("Execute request from [%s]", context.peer())
+
         try:
             message_queue = queue.Queue()
             instance = self._get_instance(request.instance_name)
@@ -55,7 +58,7 @@ class ExecutionService(remote_execution_pb2_grpc.ExecutionServicer):
             instanced_op_name = "{}/{}".format(request.instance_name,
                                                operation.name)
 
-            self.logger.info("Operation name: [{}]".format(instanced_op_name))
+            self.__logger.info("Operation name: [%s]", instanced_op_name)
 
             for operation in instance.stream_operation_updates(message_queue,
                                                                operation.name):
@@ -65,18 +68,20 @@ class ExecutionService(remote_execution_pb2_grpc.ExecutionServicer):
                 yield op
 
         except InvalidArgumentError as e:
-            self.logger.error(e)
+            self.__logger.error(e)
             context.set_details(str(e))
             context.set_code(grpc.StatusCode.INVALID_ARGUMENT)
             yield operations_pb2.Operation()
 
         except FailedPreconditionError as e:
-            self.logger.error(e)
+            self.__logger.error(e)
             context.set_details(str(e))
             context.set_code(grpc.StatusCode.FAILED_PRECONDITION)
             yield operations_pb2.Operation()
 
     def WaitExecution(self, request, context):
+        self.__logger.debug("WaitExecution request from [%s]", context.peer())
+
         try:
             names = request.name.split("/")
 
@@ -101,7 +106,7 @@ class ExecutionService(remote_execution_pb2_grpc.ExecutionServicer):
                 yield op
 
         except InvalidArgumentError as e:
-            self.logger.error(e)
+            self.__logger.error(e)
             context.set_details(str(e))
             context.set_code(grpc.StatusCode.INVALID_ARGUMENT)
             yield operations_pb2.Operation()

buildgrid/server/instance.py

@@ -13,9 +13,9 @@
 # limitations under the License.
 
 
+from concurrent import futures
 import logging
 import os
-from concurrent import futures
 
 import grpc
 
@@ -40,8 +40,7 @@ class BuildGridServer:
         Args:
             max_workers (int, optional): A pool of max worker threads.
         """
-
-        self.logger = logging.getLogger(__name__)
+        self.__logger = logging.getLogger(__name__)
 
         if max_workers is None:
             # Use max_workers default from Python 3.5+
@@ -80,11 +79,11 @@ class BuildGridServer:
             credentials (:obj:`grpc.ChannelCredentials`): Credentials object.
         """
         if credentials is not None:
-            self.logger.info("Adding secure connection on: [{}]".format(address))
+            self.__logger.info("Adding secure connection on: [%s]", address)
             self._server.add_secure_port(address, credentials)
 
         else:
-            self.logger.info("Adding insecure connection on [{}]".format(address))
+            self.__logger.info("Adding insecure connection on [%s]", address)
             self._server.add_insecure_port(address)
 
     def add_execution_instance(self, instance, instance_name):