From cbe38abcd5d259a584a65dac0e47d1730ee5f0c6 Mon Sep 17 00:00:00 2001 From: mdumandag Date: Wed, 14 Oct 2020 17:53:51 +0300 Subject: [PATCH 1/3] Follow advised logging practices Contrary to what https://docs.python.org/3/howto/logging.html#configuring-logging-for-a-library advises, we were defining our own StreamHandler with custom formatter and filter. It is strongly advised for libraries to not do that. We are following that advice now. In short, the changes done are described below. - Use module-level loggers with the module name as the logger name. It is described as a good convention in the https://docs.python.org/3/howto/logging.html#advanced-logging-tutorial. - Do not add a Handler with custom formatter and filter by default. - Do not print the latest commit id in the Lifecycle service as it requires reading a file during the client startup. Instead, the client version is printed. To make test failure reports easier to follow, the latest commit id is printed for the test logs. - For tests, a single configuration is added to the root logger in the init file. That way, all tests will reuse that. - Do not pass logger extras anymore as they don't make sense without a custom formatter or filter. We may provide utility implementations for a formatter and a filter and pass extras even if they won't be used most of the time. I chose not to pass them, but that can be discussed. - Remove `logging_level` and `logging_config` confiugration options. - Update README. --- .gitignore | 4 - README.md | 246 ++++++----------- hazelcast/__init__.py | 16 +- hazelcast/client.py | 49 ++-- hazelcast/cluster.py | 22 +- hazelcast/config.py | 35 +-- hazelcast/connection.py | 97 +++---- hazelcast/core.py | 5 +- hazelcast/discovery.py | 12 +- hazelcast/future.py | 4 +- hazelcast/invocation.py | 25 +- hazelcast/lifecycle.py | 16 +- hazelcast/listener.py | 19 +- hazelcast/partition.py | 30 +-- hazelcast/proxy/base.py | 3 - hazelcast/proxy/pn_counter.py | 7 +- hazelcast/reactor.py | 32 +-- hazelcast/statistics.py | 25 +- hazelcast/transaction.py | 9 +- hazelcast/util.py | 61 ----- hazelcast/version.py | 69 ----- setup.py | 6 - tests/__init__.py | 13 + tests/base.py | 1 - tests/client_test.py | 2 - tests/config_test.py | 21 -- tests/cp_test.py | 2 +- .../hazelcast_cloud_provider_test.py | 5 +- tests/invocation_test.py | 2 +- tests/logger/__init__.py | 0 tests/logger/detailed_config.json | 31 --- tests/logger/logger_test.py | 250 ------------------ tests/logger/simple_config.json | 16 -- tests/logger_test.py | 66 +++++ tests/proxy/flake_id_generator_test.py | 5 - tests/proxy/transactional_set_test.py | 3 +- tests/ssl/ssl_test.py | 6 +- tests/statistics_test.py | 11 +- tests/util.py | 7 - tests/version_test.py | 33 --- 40 files changed, 345 insertions(+), 921 deletions(-) delete mode 100644 hazelcast/version.py delete mode 100644 tests/logger/__init__.py delete mode 100644 tests/logger/detailed_config.json delete mode 100644 tests/logger/logger_test.py delete mode 100644 tests/logger/simple_config.json create mode 100644 tests/logger_test.py delete mode 100644 tests/version_test.py diff --git a/.gitignore b/.gitignore index 832ecb9cf2..792e84e27f 100644 --- a/.gitignore +++ b/.gitignore @@ -67,7 +67,3 @@ target/ .directory *.jar - -# Git version info related -git_info.json -hazelcast/git_info.json diff --git a/README.md b/README.md index e57e95edc6..42716021b1 100644 --- a/README.md +++ b/README.md @@ -369,8 +369,12 @@ Now that we have a working cluster and we know how to configure both our cluster distributed map in the Python client. ```python +import logging import hazelcast +# Enable logging to see the logs +logging.basicConfig(level=logging.INFO) + # Connect to Hazelcast cluster client = hazelcast.HazelcastClient() @@ -380,25 +384,22 @@ client.shutdown() This should print logs about the cluster members such as address, port and UUID to the `stderr`. ``` -Sep 03, 2020 02:33:31 PM HazelcastClient.LifecycleService -INFO: [4.0.0] [dev] [hz.client_0] (20190802 - 85a237d) HazelcastClient is STARTING -Sep 03, 2020 02:33:31 PM HazelcastClient.LifecycleService -INFO: [4.0.0] [dev] [hz.client_0] (20190802 - 85a237d) HazelcastClient is STARTED -Sep 03, 2020 02:33:31 PM HazelcastClient.ConnectionManager -INFO: [4.0.0] [dev] [hz.client_0] Trying to connect to Address(host=127.0.0.1, port=5701) -Sep 03, 2020 02:33:31 PM HazelcastClient.LifecycleService -INFO: [4.0.0] [dev] [hz.client_0] (20190802 - 85a237d) HazelcastClient is CONNECTED -Sep 03, 2020 02:33:31 PM HazelcastClient.ConnectionManager -INFO: [4.0.0] [dev] [hz.client_0] Authenticated with server Address(host=192.168.1.10, port=5701):7362c66f-ef9f-4a6a-a003-f8b33dfd292a, server version: 4.1-SNAPSHOT, local address: Address(host=127.0.0.1, port=33376) -Sep 03, 2020 02:33:31 PM HazelcastClient.ClusterService -INFO: [4.0.0] [dev] [hz.client_0] +INFO:hazelcast.lifecycle:HazelcastClient 4.0.0 is STARTING +INFO:hazelcast.lifecycle:HazelcastClient 4.0.0 is STARTED +INFO:hazelcast.connection:Trying to connect to Address(host=127.0.0.1, port=5701) +INFO:hazelcast.lifecycle:HazelcastClient 4.0.0 is CONNECTED +INFO:hazelcast.connection:Authenticated with server Address(host=172.17.0.2, port=5701):7682c357-3bec-4841-b330-6f9ae0c08253, server version: 4.0, local address: Address(host=127.0.0.1, port=56718) +INFO:hazelcast.cluster: Members [1] { - Member [192.168.1.10]:5701 - 7362c66f-ef9f-4a6a-a003-f8b33dfd292a + Member [172.17.0.2]:5701 - 7682c357-3bec-4841-b330-6f9ae0c08253 } -Sep 03, 2020 02:33:31 PM HazelcastClient -INFO: [4.0.0] [dev] [hz.client_0] Client started. +INFO:hazelcast.client:Client started +INFO:hazelcast.lifecycle:HazelcastClient 4.0.0 is SHUTTING_DOWN +INFO:hazelcast.connection:Removed connection to Address(host=127.0.0.1, port=5701):7682c357-3bec-4841-b330-6f9ae0c08253, connection: Connection(id=0, live=False, remote_address=Address(host=172.17.0.2, port=5701)) +INFO:hazelcast.lifecycle:HazelcastClient 4.0.0 is DISCONNECTED +INFO:hazelcast.lifecycle:HazelcastClient 4.0.0 is SHUTDOWN ``` Congratulations. You just started a Hazelcast Python client. @@ -1915,41 +1916,28 @@ client = hazelcast.HazelcastClient( **Output:** ``` -Sep 03, 2020 05:00:29 PM HazelcastClient.LifecycleService -INFO: [4.0.0] [dev] [hz.client_0] (20190802 - 85a237d) HazelcastClient is STARTING +INFO:hazelcast.lifecycle:HazelcastClient 4.0.0 is STARTING Lifecycle Event >>> STARTING -Sep 03, 2020 05:00:29 PM HazelcastClient.LifecycleService -INFO: [4.0.0] [dev] [hz.client_0] (20190802 - 85a237d) HazelcastClient is STARTED +INFO:hazelcast.lifecycle:HazelcastClient 4.0.0 is STARTED Lifecycle Event >>> STARTED -Sep 03, 2020 05:00:29 PM HazelcastClient.ConnectionManager -INFO: [4.0.0] [dev] [hz.client_0] Trying to connect to Address(host=127.0.0.1, port=5701) -Sep 03, 2020 05:00:29 PM HazelcastClient.LifecycleService -INFO: [4.0.0] [dev] [hz.client_0] (20190802 - 85a237d) HazelcastClient is CONNECTED +INFO:hazelcast.connection:Trying to connect to Address(host=127.0.0.1, port=5701) +INFO:hazelcast.lifecycle:HazelcastClient 4.0.0 is CONNECTED Lifecycle Event >>> CONNECTED -Sep 03, 2020 05:00:29 PM HazelcastClient.ConnectionManager -INFO: [4.0.0] [dev] [hz.client_0] Authenticated with server Address(host=192.168.1.10, port=5701):7362c66f-ef9f-4a6a-a003-f8b33dfd292a, server version: 4.1-SNAPSHOT, local address: Address(host=127.0.0.1, port=36302) -Sep 03, 2020 05:00:29 PM HazelcastClient.ClusterService -INFO: [4.0.0] [dev] [hz.client_0] +INFO:hazelcast.connection:Authenticated with server Address(host=172.17.0.2, port=5701):7682c357-3bec-4841-b330-6f9ae0c08253, server version: 4.0, local address: Address(host=127.0.0.1, port=56732) +INFO:hazelcast.cluster: Members [1] { - Member [192.168.1.10]:5701 - 7362c66f-ef9f-4a6a-a003-f8b33dfd292a + Member [172.17.0.2]:5701 - 7682c357-3bec-4841-b330-6f9ae0c08253 } -Sep 03, 2020 05:00:29 PM HazelcastClient -INFO: [4.0.0] [dev] [hz.client_0] Client started. -Sep 03, 2020 05:00:29 PM HazelcastClient.LifecycleService -INFO: [4.0.0] [dev] [hz.client_0] (20190802 - 85a237d) HazelcastClient is SHUTTING_DOWN +INFO:hazelcast.client:Client started +INFO:hazelcast.lifecycle:HazelcastClient 4.0.0 is SHUTTING_DOWN Lifecycle Event >>> SHUTTING_DOWN -Sep 03, 2020 05:00:29 PM HazelcastClient.ConnectionManager -INFO: [4.0.0] [dev] [hz.client_0] Removed connection to Address(host=127.0.0.1, port=5701):7362c66f-ef9f-4a6a-a003-f8b33dfd292a, connection: Connection(id=0, live=False, remote_address=Address(host=192.168.1.10, port=5701)) -Sep 03, 2020 05:00:29 PM HazelcastClient.LifecycleService -INFO: [4.0.0] [dev] [hz.client_0] (20190802 - 85a237d) HazelcastClient is DISCONNECTED +INFO:hazelcast.connection:Removed connection to Address(host=127.0.0.1, port=5701):7682c357-3bec-4841-b330-6f9ae0c08253, connection: Connection(id=0, live=False, remote_address=Address(host=172.17.0.2, port=5701)) +INFO:hazelcast.lifecycle:HazelcastClient 4.0.0 is DISCONNECTED Lifecycle Event >>> DISCONNECTED -Sep 03, 2020 05:00:29 PM HazelcastClient.LifecycleService -INFO: [4.0.0] [dev] [hz.client_0] (20190802 - 85a237d) HazelcastClient is SHUTDOWN +INFO:hazelcast.lifecycle:HazelcastClient 4.0.0 is SHUTDOWN Lifecycle Event >>> SHUTDOWN -Sep 03, 2020 05:00:29 PM HazelcastClient -INFO: [4.0.0] [dev] [hz.client_0] Client shutdown. ``` You can also add lifecycle listeners after client initialization using the `LifecycleService`. @@ -2581,148 +2569,86 @@ After enabling the client statistics, you can monitor your clients using Hazelca ### 7.9.2 Logging Configuration -Hazelcast Python client allows you to configure the logging through the arguments below. - -These arguments allow you to set the logging level and a custom logging configuration to the Hazelcast Python client. +Hazelcast Python client uses Python's builtin ``logging`` package to perform logging. -By default, Hazelcast Python client will log to the `sys.stderr` with the `INFO` logging level and `%(asctime)s %(name)s\n%(levelname)s: %(version_message)s %(message)s` format where the `version_message` contains the information about the client version, cluster name and client name. +All the loggers used throughout the client are identified by their module names. Hence, one may configure the ``hazelcast`` +parent logger and use the same configuration for the child loggers such as ``hazelcast.lifecycle`` without an extra effort. -Below is an example of the default logging configuration. +Below is an example of the logging configuration with ``INFO`` log level and a ``StreamHandler`` with a custom format, and its output. -**Output to the `sys.stderr`** -``` -Sep 03, 2020 05:41:35 PM HazelcastClient.LifecycleService -INFO: [4.0.0] [dev] [hz.client_0] (20190802 - 85a237d) HazelcastClient is STARTING -Sep 03, 2020 05:41:35 PM HazelcastClient.LifecycleService -INFO: [4.0.0] [dev] [hz.client_0] (20190802 - 85a237d) HazelcastClient is STARTED -Sep 03, 2020 05:41:35 PM HazelcastClient.ConnectionManager -INFO: [4.0.0] [dev] [hz.client_0] Trying to connect to Address(host=127.0.0.1, port=5701) -Sep 03, 2020 05:41:35 PM HazelcastClient.LifecycleService -INFO: [4.0.0] [dev] [hz.client_0] (20190802 - 85a237d) HazelcastClient is CONNECTED -Sep 03, 2020 05:41:35 PM HazelcastClient.ConnectionManager -INFO: [4.0.0] [dev] [hz.client_0] Authenticated with server Address(host=192.168.1.10, port=5701):7362c66f-ef9f-4a6a-a003-f8b33dfd292a, server version: 4.1-SNAPSHOT, local address: Address(host=127.0.0.1, port=37026) -Sep 03, 2020 05:41:35 PM HazelcastClient.ClusterService -INFO: [4.0.0] [dev] [hz.client_0] +```python +import logging +import hazelcast -Members [1] { - Member [192.168.1.10]:5701 - 7362c66f-ef9f-4a6a-a003-f8b33dfd292a -} +logger = logging.getLogger("hazelcast") +logger.setLevel(logging.INFO) -Sep 03, 2020 05:41:35 PM HazelcastClient -INFO: [4.0.0] [dev] [hz.client_0] Client started. -Sep 03, 2020 05:41:35 PM HazelcastClient.LifecycleService -INFO: [4.0.0] [dev] [hz.client_0] (20190802 - 85a237d) HazelcastClient is SHUTTING_DOWN -Sep 03, 2020 05:41:35 PM HazelcastClient.ConnectionManager -INFO: [4.0.0] [dev] [hz.client_0] Removed connection to Address(host=127.0.0.1, port=5701):7362c66f-ef9f-4a6a-a003-f8b33dfd292a, connection: Connection(id=0, live=False, remote_address=Address(host=192.168.1.10, port=5701)) -Sep 03, 2020 05:41:35 PM HazelcastClient.LifecycleService -INFO: [4.0.0] [dev] [hz.client_0] (20190802 - 85a237d) HazelcastClient is DISCONNECTED -Sep 03, 2020 05:41:35 PM HazelcastClient.LifecycleService -INFO: [4.0.0] [dev] [hz.client_0] (20190802 - 85a237d) HazelcastClient is SHUTDOWN -Sep 03, 2020 05:41:35 PM HazelcastClient -INFO: [4.0.0] [dev] [hz.client_0] Client shutdown. -``` +handler = logging.StreamHandler() +formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s") +handler.setFormatter(formatter) +logger.addHandler(handler) -#### Setting Logging Level +client = hazelcast.HazelcastClient() -Although you can not change the logging levels used within the Hazelcast Python client, you can specify a logging level that is used to threshold the logs that are at least as severe as your specified level using `logging_level` argument. +client.shutdown() +``` -Here is the table listing the default logging levels that come with the `logging` module and numeric values that represent their severity: +**Output** +``` +2020-10-16 13:31:35,605 - hazelcast.lifecycle - INFO - HazelcastClient 4.0.0 is STARTING +2020-10-16 13:31:35,605 - hazelcast.lifecycle - INFO - HazelcastClient 4.0.0 is STARTED +2020-10-16 13:31:35,605 - hazelcast.connection - INFO - Trying to connect to Address(host=127.0.0.1, port=5701) +2020-10-16 13:31:35,622 - hazelcast.lifecycle - INFO - HazelcastClient 4.0.0 is CONNECTED +2020-10-16 13:31:35,622 - hazelcast.connection - INFO - Authenticated with server Address(host=172.17.0.2, port=5701):7682c357-3bec-4841-b330-6f9ae0c08253, server version: 4.0, local address: Address(host=127.0.0.1, port=56752) +2020-10-16 13:31:35,623 - hazelcast.cluster - INFO - -| Level | Numeric Value | -|----------|---------------| -| CRITICAL | 50 | -| ERROR | 40 | -| WARNING | 30 | -| INFO | 20 | -| DEBUG | 10 | -| NOTSET | 0 | +Members [1] { + Member [172.17.0.2]:5701 - 7682c357-3bec-4841-b330-6f9ae0c08253 +} -For example, setting the logging level to `logging.DEBUG` will cause all the logging messages that are equal or higher than the `logging.DEBUG` in terms of severity to be emitted by your logger. +2020-10-16 13:31:35,624 - hazelcast.client - INFO - Client started +2020-10-16 13:31:35,624 - hazelcast.lifecycle - INFO - HazelcastClient 4.0.0 is SHUTTING_DOWN +2020-10-16 13:31:35,624 - hazelcast.connection - INFO - Removed connection to Address(host=127.0.0.1, port=5701):7682c357-3bec-4841-b330-6f9ae0c08253, connection: Connection(id=0, live=False, remote_address=Address(host=172.17.0.2, port=5701)) +2020-10-16 13:31:35,624 - hazelcast.lifecycle - INFO - HazelcastClient 4.0.0 is DISCONNECTED +2020-10-16 13:31:35,634 - hazelcast.lifecycle - INFO - HazelcastClient 4.0.0 is SHUTDOWN +``` -By default, the logging level is set to `logging.INFO`. +A handy alternative to above example would be configuring the root logger using the ``logging.basicConfig()`` utility method. Beware that, +every logger is the child of the root logger in Python. Hence, configuring the root logger may have application level impact. Nonetheless, +it is useful for the testing or development purposes. ```python import logging +import hazelcast -client = hazelcast.HazelcastClient( - logging_level=logging.DEBUG -) -``` - -#### Setting a Custom Logging Configuration - -`logging_config` argument can be used to configure the logger for the Hazelcast Python client entirely. - -When set, this argument should contain the logging configuration as described in the [Configuration dictionary schema](https://docs.python.org/3/library/logging.config.html#logging-config-dictschema). - -When this field is set, the `level` field is simply discarded and configuration in this file is used. - -All Hazelcast Python client related loggers have `HazelcastClient` as their parent logger. So, you can configure logging for the `HazelcastClient` base logger and this logging configuration can be used for all client related loggers. +logging.basicConfig(level=logging.INFO) -Let's replicate the default configuration used within the Hazelcast client with this configuration method. +client = hazelcast.HazelcastClient() -**some_package/log.py** -```python -import logging +client.shutdown() +``` -from hazelcast.version import CLIENT_VERSION +**Output** +``` +INFO:hazelcast.lifecycle:HazelcastClient 4.0.0 is STARTING +INFO:hazelcast.lifecycle:HazelcastClient 4.0.0 is STARTED +INFO:hazelcast.connection:Trying to connect to Address(host=127.0.0.1, port=5701) +INFO:hazelcast.lifecycle:HazelcastClient 4.0.0 is CONNECTED +INFO:hazelcast.connection:Authenticated with server Address(host=172.17.0.2, port=5701):7682c357-3bec-4841-b330-6f9ae0c08253, server version: 4.0, local address: Address(host=127.0.0.1, port=56758) +INFO:hazelcast.cluster: -class VersionMessageFilter(logging.Filter): - def filter(self, record): - record.version_message = "[" + CLIENT_VERSION + "]" - return True - -class HazelcastFormatter(logging.Formatter): - def format(self, record): - client_name = getattr(record, "client_name", None) - cluster_name = getattr(record, "cluster_name", None) - if client_name and cluster_name: - record.msg = "[" + cluster_name + "] [" + client_name + "] " + record.msg - return super(HazelcastFormatter, self).format(record) -``` - -```python -logging_config = { - "version": 1, - "disable_existing_loggers": False, - "filters": { - "version_message_filter": { - "()": "some_package.log.VersionMessageFilter" - } - }, - "formatters": { - "hazelcast_formatter": { - "()": "some_package.log.HazelcastFormatter", - "format": "%(asctime)s %(name)s\n%(levelname)s: %(version_message)s %(message)s", - "datefmt": "%b %d, %Y %I:%M:%S %p" - } - }, - "handlers": { - "console_handler": { - "class": "logging.StreamHandler", - "stream": "ext://sys.stdout", - "filters": ["version_message_filter"], - "formatter": "hazelcast_formatter" - } - }, - "loggers": { - "HazelcastClient": { - "handlers": ["console_handler"], - "level": "INFO" - } - } +Members [1] { + Member [172.17.0.2]:5701 - 7682c357-3bec-4841-b330-6f9ae0c08253 } -client = hazelcast.HazelcastClient( - logging_config=logging_config -) - -## Some operations - -client.shutdown() -``` +INFO:hazelcast.client:Client started +INFO:hazelcast.lifecycle:HazelcastClient 4.0.0 is SHUTTING_DOWN +INFO:hazelcast.connection:Removed connection to Address(host=127.0.0.1, port=5701):7682c357-3bec-4841-b330-6f9ae0c08253, connection: Connection(id=0, live=False, remote_address=Address(host=172.17.0.2, port=5701)) +INFO:hazelcast.lifecycle:HazelcastClient 4.0.0 is DISCONNECTED +INFO:hazelcast.lifecycle:HazelcastClient 4.0.0 is SHUTDOWN +``` -To learn more about the `logging` module and its capabilities, please see the [logging cookbook](https://docs.python.org/3/howto/logging-cookbook.html) and [documentation](https://docs.python.org/3/library/logging.html) of the `logging` module. +To learn more about the `logging` package and its capabilities, please see the [logging cookbook](https://docs.python.org/3/howto/logging-cookbook.html) and [documentation](https://docs.python.org/3/library/logging.html) of the `logging` package. ## 7.10. Defining Client Labels diff --git a/hazelcast/__init__.py b/hazelcast/__init__.py index a9a89be286..0db920d642 100644 --- a/hazelcast/__init__.py +++ b/hazelcast/__init__.py @@ -1,3 +1,15 @@ +__version__ = "4.0.0" + +# Set the default handler to "hazelcast" loggers +# to avoid "No handlers could be found" warnings. +import logging +try: + from logging import NullHandler +except ImportError: + class NullHandler(logging.Handler): + def emit(self, record): + pass + +logging.getLogger(__name__).addHandler(NullHandler()) + from hazelcast.client import HazelcastClient -from hazelcast.version import CLIENT_VERSION_INFO as __version_info__ -from hazelcast.version import CLIENT_VERSION as __version__ diff --git a/hazelcast/client.py b/hazelcast/client.py index 86fd9b664f..3038079c7b 100644 --- a/hazelcast/client.py +++ b/hazelcast/client.py @@ -1,5 +1,4 @@ import logging -import logging.config import threading from hazelcast import six @@ -23,10 +22,12 @@ from hazelcast.serialization import SerializationServiceV1 from hazelcast.statistics import Statistics from hazelcast.transaction import TWO_PHASE, TransactionManager -from hazelcast.util import AtomicInteger, DEFAULT_LOGGING, RoundRobinLB +from hazelcast.util import AtomicInteger, RoundRobinLB from hazelcast.discovery import HazelcastCloudAddressProvider from hazelcast.errors import IllegalStateError +_logger = logging.getLogger(__name__) + class HazelcastClient(object): """Hazelcast client instance to access access and manipulate @@ -297,7 +298,6 @@ class SomeClassSerializer(StreamSerializer): """ _CLIENT_ID = AtomicInteger() - logger = logging.getLogger("HazelcastClient") def __init__(self, **kwargs): config = _Config.from_dict(kwargs) @@ -305,38 +305,33 @@ def __init__(self, **kwargs): self._context = _ClientContext() client_id = HazelcastClient._CLIENT_ID.get_and_increment() self.name = self._create_client_name(client_id) - self._init_logger() - self._logger_extras = {"client_name": self.name, "cluster_name": self.config.cluster_name} - self._reactor = AsyncoreReactor(self._logger_extras) + self._reactor = AsyncoreReactor() self._serialization_service = SerializationServiceV1(config) self._near_cache_manager = NearCacheManager(self, self._serialization_service) - self._internal_lifecycle_service = _InternalLifecycleService(self, self._logger_extras) + self._internal_lifecycle_service = _InternalLifecycleService(self) self.lifecycle_service = LifecycleService(self._internal_lifecycle_service) - self._invocation_service = InvocationService(self, self._reactor, self._logger_extras) + self._invocation_service = InvocationService(self, self._reactor) self._address_provider = self._create_address_provider() - self._internal_partition_service = _InternalPartitionService(self, self._logger_extras) + self._internal_partition_service = _InternalPartitionService(self) self.partition_service = PartitionService(self._internal_partition_service, self._serialization_service) - self._internal_cluster_service = _InternalClusterService(self, self._logger_extras) + self._internal_cluster_service = _InternalClusterService(self) self.cluster_service = ClusterService(self._internal_cluster_service) self._connection_manager = ConnectionManager(self, self._reactor, self._address_provider, self._internal_lifecycle_service, self._internal_partition_service, self._internal_cluster_service, self._invocation_service, - self._near_cache_manager, - self._logger_extras) + self._near_cache_manager) self._load_balancer = self._init_load_balancer(config) self._listener_service = ListenerService(self, self._connection_manager, - self._invocation_service, - self._logger_extras) + self._invocation_service) self._proxy_manager = ProxyManager(self._context) self.cp_subsystem = CPSubsystem(self._context) self._proxy_session_manager = ProxySessionManager(self._context) - self._transaction_manager = TransactionManager(self._context, self._logger_extras) + self._transaction_manager = TransactionManager(self._context) self._lock_reference_id_generator = AtomicInteger(1) self._statistics = Statistics(self, self._reactor, self._connection_manager, - self._invocation_service, self._near_cache_manager, - self._logger_extras) + self._invocation_service, self._near_cache_manager) self._cluster_view_listener = ClusterViewListenerService(self, self._connection_manager, self._internal_partition_service, self._internal_cluster_service, @@ -349,7 +344,7 @@ def _init_context(self): self._context.init_context(self.config, self._invocation_service, self._internal_partition_service, self._internal_cluster_service, self._connection_manager, self._serialization_service, self._listener_service, self._proxy_manager, - self._near_cache_manager, self._lock_reference_id_generator, self._logger_extras, + self._near_cache_manager, self._lock_reference_id_generator, self.name, self._proxy_session_manager, self._reactor) def _start(self): @@ -373,7 +368,7 @@ def _start(self): except: self.shutdown() raise - self.logger.info("Client started.", extra=self._logger_extras) + _logger.info("Client started") def get_executor(self, name): """Creates cluster-wide ExecutorService. @@ -620,19 +615,10 @@ def _create_address_provider(self): if cloud_enabled: connection_timeout = self._get_connection_timeout(config) - return HazelcastCloudAddressProvider(cloud_discovery_token, connection_timeout, self._logger_extras) + return HazelcastCloudAddressProvider(cloud_discovery_token, connection_timeout) return DefaultAddressProvider(cluster_members) - def _init_logger(self): - config = self.config - logging_config = config.logging_config - if logging_config: - logging.config.dictConfig(logging_config) - else: - logging.config.dictConfig(DEFAULT_LOGGING) - self.logger.setLevel(config.logging_level) - def _create_client_name(self, client_id): client_name = self.config.client_name if client_name: @@ -668,7 +654,6 @@ def __init__(self): self.proxy_manager = None self.near_cache_manager = None self.lock_reference_id_generator = None - self.logger_extras = None self.name = None self.proxy_session_manager = None self.reactor = None @@ -676,8 +661,7 @@ def __init__(self): def init_context(self, config, invocation_service, partition_service, cluster_service, connection_manager, serialization_service, listener_service, proxy_manager, near_cache_manager, - lock_reference_id_generator, logger_extras, name, - proxy_session_manager, reactor): + lock_reference_id_generator, name, proxy_session_manager, reactor): self.config = config self.invocation_service = invocation_service self.partition_service = partition_service @@ -688,7 +672,6 @@ def init_context(self, config, invocation_service, partition_service, self.proxy_manager = proxy_manager self.near_cache_manager = near_cache_manager self.lock_reference_id_generator = lock_reference_id_generator - self.logger_extras = logger_extras self.name = name self.proxy_session_manager = proxy_session_manager self.reactor = reactor diff --git a/hazelcast/cluster.py b/hazelcast/cluster.py index eb7568b627..511749f369 100644 --- a/hazelcast/cluster.py +++ b/hazelcast/cluster.py @@ -7,6 +7,8 @@ from hazelcast.errors import TargetDisconnectedError, IllegalStateError from hazelcast.util import check_not_none +_logger = logging.getLogger(__name__) + class _MemberListSnapshot(object): __slots__ = ("version", "members") @@ -101,12 +103,10 @@ def get_members(self, member_selector=None): class _InternalClusterService(object): - logger = logging.getLogger("HazelcastClient.ClusterService") - def __init__(self, client, logger_extras): + def __init__(self, client): self._client = client self._connection_manager = None - self._logger_extras = logger_extras config = client.config self._labels = frozenset(config.labels) self._listeners = {} @@ -183,8 +183,8 @@ def wait_initial_member_list_fetched(self): raise IllegalStateError("Could not get initial member list from cluster!") def clear_member_list_version(self): - if self.logger.isEnabledFor(logging.DEBUG): - self.logger.debug("Resetting the member list version", extra=self._logger_extras) + if _logger.isEnabledFor(logging.DEBUG): + _logger.debug("Resetting the member list version") current = self._member_list_snapshot if current is not _EMPTY_SNAPSHOT: @@ -192,9 +192,9 @@ def clear_member_list_version(self): def handle_members_view_event(self, version, member_infos): snapshot = self._create_snapshot(version, member_infos) - if self.logger.isEnabledFor(logging.DEBUG): - self.logger.debug("Handling new snapshot with membership version: %s, member string: %s" - % (version, self._members_string(snapshot)), extra=self._logger_extras) + if _logger.isEnabledFor(logging.DEBUG): + _logger.debug("Handling new snapshot with membership version: %s, member string: %s" + % (version, self._members_string(snapshot))) current = self._member_list_snapshot if version >= current.version: @@ -214,7 +214,7 @@ def _apply_new_state_and_fire_events(self, current, snapshot): try: handler(removed_member) except: - self.logger.exception("Exception in membership lister", extra=self._logger_extras) + _logger.exception("Exception in membership lister") for added_member in additions: for handler, _ in six.itervalues(self._listeners): @@ -222,7 +222,7 @@ def _apply_new_state_and_fire_events(self, current, snapshot): try: handler(added_member) except: - self.logger.exception("Exception in membership lister", extra=self._logger_extras) + _logger.exception("Exception in membership lister") def _detect_membership_events(self, old, new): new_members = [] @@ -242,7 +242,7 @@ def _detect_membership_events(self, old, new): if (len(new_members) + len(dead_members)) > 0: if len(new.members) > 0: - self.logger.info(self._members_string(new), extra=self._logger_extras) + _logger.info(self._members_string(new)) return dead_members, new_members diff --git a/hazelcast/config.py b/hazelcast/config.py index d9b7c64c9c..f1ca143619 100644 --- a/hazelcast/config.py +++ b/hazelcast/config.py @@ -1,8 +1,3 @@ -""" -Hazelcast Client Configuration module contains configuration classes and various constants required to create a ClientConfig. - -""" -import logging import re from hazelcast import six @@ -457,9 +452,8 @@ class _Config(object): "_membership_listeners", "_lifecycle_listeners", "_flake_id_generators", "_labels", "_heartbeat_interval", "_heartbeat_timeout", "_invocation_timeout", "_invocation_retry_pause", "_statistics_enabled", - "_statistics_period", "_shuffle_member_list", "_logging_config", - "_logging_level", "_backup_ack_to_client_enabled", "_operation_backup_timeout", - "_fail_on_indeterminate_operation_state") + "_statistics_period", "_shuffle_member_list", "_backup_ack_to_client_enabled", + "_operation_backup_timeout", "_fail_on_indeterminate_operation_state") def __init__(self): self._cluster_members = [] @@ -506,8 +500,6 @@ def __init__(self): self._statistics_enabled = False self._statistics_period = 3.0 self._shuffle_member_list = True - self._logging_config = None - self._logging_level = logging.INFO self._backup_ack_to_client_enabled = True self._operation_backup_timeout = 5.0 self._fail_on_indeterminate_operation_state = False @@ -1112,29 +1104,6 @@ def shuffle_member_list(self, value): else: raise TypeError("shuffle_member_list must be a boolean") - @property - def logging_config(self): - return self._logging_config - - @logging_config.setter - def logging_config(self, value): - if isinstance(value, dict): - self._logging_config = value - else: - raise TypeError("logging_config must be a dict") - - @property - def logging_level(self): - return self._logging_level - - @logging_level.setter - def logging_level(self, value): - if value in {logging.NOTSET, logging.DEBUG, logging.INFO, logging.WARNING, - logging.ERROR, logging.CRITICAL}: - self._logging_level = value - else: - raise TypeError("logging_level must be a valid value") - @property def backup_ack_to_client_enabled(self): return self._backup_ack_to_client_enabled diff --git a/hazelcast/connection.py b/hazelcast/connection.py index 7311c61337..ec11efa83a 100644 --- a/hazelcast/connection.py +++ b/hazelcast/connection.py @@ -9,7 +9,7 @@ from collections import OrderedDict from hazelcast.config import ReconnectMode -from hazelcast.core import AddressHelper +from hazelcast.core import AddressHelper, CLIENT_TYPE, SERIALIZATION_VERSION from hazelcast.errors import AuthenticationError, TargetDisconnectedError, HazelcastClientNotActiveError, \ InvalidConfigurationError, ClientNotAllowedInClusterError, IllegalStateError, ClientOfflineError from hazelcast.future import ImmediateFuture, ImmediateExceptionFuture @@ -19,15 +19,14 @@ ClientMessageBuilder from hazelcast.protocol.codec import client_authentication_codec, client_ping_codec from hazelcast.util import AtomicInteger, calculate_version, UNKNOWN_VERSION -from hazelcast.version import CLIENT_TYPE, CLIENT_VERSION, SERIALIZATION_VERSION -from hazelcast import six +from hazelcast import six, __version__ +_logger = logging.getLogger(__name__) -class _WaitStrategy(object): - logger = logging.getLogger("HazelcastClient.WaitStrategy") +class _WaitStrategy(object): def __init__(self, initial_backoff, max_backoff, multiplier, - cluster_connect_timeout, jitter, logger_extras): + cluster_connect_timeout, jitter): self._initial_backoff = initial_backoff self._max_backoff = max_backoff self._multiplier = multiplier @@ -36,7 +35,6 @@ def __init__(self, initial_backoff, max_backoff, multiplier, self._attempt = None self._cluster_connect_attempt_begin = None self._current_backoff = None - self._logger_extras = logger_extras def reset(self): self._attempt = 0 @@ -48,18 +46,16 @@ def sleep(self): now = time.time() time_passed = now - self._cluster_connect_attempt_begin if time_passed > self._cluster_connect_timeout: - self.logger.warning("Unable to get live cluster connection, cluster connect timeout (%d) is reached. " - "Attempt %d." % (self._cluster_connect_timeout, self._attempt), - extra=self._logger_extras) + _logger.warning("Unable to get live cluster connection, cluster connect timeout (%d) is reached. " + "Attempt %d." % (self._cluster_connect_timeout, self._attempt)) return False # random between (-jitter * current_backoff, jitter * current_backoff) sleep_time = self._current_backoff + self._current_backoff * self._jitter * (2 * random.random() - 1) sleep_time = min(sleep_time, self._cluster_connect_timeout - time_passed) - self.logger.warning("Unable to get live cluster connection, retry in %ds, attempt: %d, " - "cluster connect timeout: %ds, max backoff: %ds" - % (sleep_time, self._attempt, self._cluster_connect_timeout, self._max_backoff), - extra=self._logger_extras) + _logger.warning("Unable to get live cluster connection, retry in %ds, attempt: %d, " + "cluster connect timeout: %ds, max backoff: %ds" + % (sleep_time, self._attempt, self._cluster_connect_timeout, self._max_backoff)) time.sleep(sleep_time) self._current_backoff = min(self._current_backoff * self._multiplier, self._max_backoff) return True @@ -74,11 +70,10 @@ class _AuthenticationStatus(object): class ConnectionManager(object): """ConnectionManager is responsible for managing ``Connection`` objects.""" - logger = logging.getLogger("HazelcastClient.ConnectionManager") def __init__(self, client, reactor, address_provider, lifecycle_service, partition_service, cluster_service, invocation_service, - near_cache_manager, logger_extras): + near_cache_manager): self.live = False self.active_connections = dict() self.client_uuid = uuid.uuid4() @@ -91,12 +86,11 @@ def __init__(self, client, reactor, address_provider, lifecycle_service, self._cluster_service = cluster_service self._invocation_service = invocation_service self._near_cache_manager = near_cache_manager - self._logger_extras = logger_extras config = self._client.config self._smart_routing_enabled = config.smart_routing self._wait_strategy = self._init_wait_strategy(config) self._reconnect_mode = config.reconnect_mode - self._heartbeat_manager = _HeartbeatManager(self, self._client, reactor, invocation_service, logger_extras) + self._heartbeat_manager = _HeartbeatManager(self, self._client, reactor, invocation_service) self._connection_listeners = [] self._connect_all_members_timer = None self._async_start = config.async_start @@ -188,8 +182,8 @@ def on_connection_close(self, closed_connection, cause): remote_uuid = closed_connection.remote_uuid if not connected_address: - self.logger.debug("Destroying %s, but it has no remote address, hence nothing is " - "removed from the connection dictionary" % closed_connection, extra=self._logger_extras) + _logger.debug("Destroying %s, but it has no remote address, hence nothing is " + "removed from the connection dictionary" % closed_connection) with self._lock: pending = self._pending_connections.pop(connected_address, None) @@ -199,9 +193,8 @@ def on_connection_close(self, closed_connection, cause): pending.set_exception(cause) if connection: - self.logger.info("Removed connection to %s:%s, connection: %s" - % (connected_address, remote_uuid, connection), - extra=self._logger_extras) + _logger.info("Removed connection to %s:%s, connection: %s" + % (connected_address, remote_uuid, connection)) if not self.active_connections: self._lifecycle_service.fire_lifecycle_event(LifecycleState.DISCONNECTED) self._trigger_cluster_reconnection() @@ -212,11 +205,11 @@ def on_connection_close(self, closed_connection, cause): try: on_connection_closed(connection, cause) except: - self.logger.exception("Exception in connection listener", extra=self._logger_extras) + _logger.exception("Exception in connection listener") else: if remote_uuid: - self.logger.debug("Destroying %s, but there is no mapping for %s in the connection dictionary" - % (closed_connection, remote_uuid), extra=self._logger_extras) + _logger.debug("Destroying %s, but there is no mapping for %s in the connection dictionary" + % (closed_connection, remote_uuid)) def check_invocation_allowed(self): if self.active_connections: @@ -229,7 +222,7 @@ def check_invocation_allowed(self): def _trigger_cluster_reconnection(self): if self._reconnect_mode == ReconnectMode.OFF: - self.logger.info("Reconnect mode is OFF. Shutting down the client", extra=self._logger_extras) + _logger.info("Reconnect mode is OFF. Shutting down the client") self._shutdown_client() return @@ -238,7 +231,7 @@ def _trigger_cluster_reconnection(self): def _init_wait_strategy(self, config): return _WaitStrategy(config.retry_initial_backoff, config.retry_max_backoff, config.retry_multiplier, - config.cluster_connect_timeout, config.retry_jitter, self._logger_extras) + config.cluster_connect_timeout, config.retry_jitter) def _start_connect_all_members_timer(self): connecting_addresses = set() @@ -284,8 +277,7 @@ def run(): self._connect_to_cluster_thread_running = False return except: - self.logger.exception("Could not connect to any cluster, shutting down the client", - extra=self._logger_extras) + _logger.exception("Could not connect to any cluster, shutting down the client") self._shutdown_client() t = threading.Thread(target=run, name='hazelcast_async_connection') @@ -296,7 +288,7 @@ def _shutdown_client(self): try: self._client.shutdown() except: - self.logger.exception("Exception during client shutdown", extra=self._logger_extras) + _logger.exception("Exception during client shutdown") def _sync_connect_to_cluster(self): tried_addresses = set() @@ -317,12 +309,11 @@ def _sync_connect_to_cluster(self): break except (ClientNotAllowedInClusterError, InvalidConfigurationError): cluster_name = self._client.config.cluster_name - self.logger.exception("Stopped trying on cluster %s" % cluster_name, extra=self._logger_extras) + _logger.exception("Stopped trying on cluster %s" % cluster_name) cluster_name = self._client.config.cluster_name - self.logger.info("Unable to connect to any address from the cluster with name: %s. " - "The following addresses were tried: %s" % (cluster_name, tried_addresses), - extra=self._logger_extras) + _logger.info("Unable to connect to any address from the cluster with name: %s. " + "The following addresses were tried: %s" % (cluster_name, tried_addresses)) if self._lifecycle_service.running: msg = "Unable to connect to any cluster" else: @@ -330,14 +321,14 @@ def _sync_connect_to_cluster(self): raise IllegalStateError(msg) def _connect(self, address): - self.logger.info("Trying to connect to %s" % address, extra=self._logger_extras) + _logger.info("Trying to connect to %s" % address) try: return self._get_or_connect(address).result() except (ClientNotAllowedInClusterError, InvalidConfigurationError) as e: - self.logger.warning("Error during initial connection to %s: %s" % (address, e), extra=self._logger_extras) + _logger.warning("Error during initial connection to %s: %s" % (address, e)) raise e except Exception as e: - self.logger.warning("Error during initial connection to %s: %s" % (address, e), extra=self._logger_extras) + _logger.warning("Error during initial connection to %s: %s" % (address, e)) return None def _get_or_connect(self, address): @@ -376,7 +367,7 @@ def _authenticate(self, connection): cluster_name = client.config.cluster_name client_name = client.name request = client_authentication_codec.encode_request(cluster_name, None, None, self.client_uuid, - CLIENT_TYPE, SERIALIZATION_VERSION, CLIENT_VERSION, + CLIENT_TYPE, SERIALIZATION_VERSION, __version__, client_name, self._labels) invocation = Invocation(request, connection=connection, urgent=True, response_handler=lambda m: m) @@ -424,9 +415,8 @@ def _handle_successful_auth(self, response, connection, address): is_initial_connection = not self.active_connections changed_cluster = is_initial_connection and self._cluster_id is not None and self._cluster_id != new_cluster_id if changed_cluster: - self.logger.warning("Switching from current cluster: %s to new cluster: %s" - % (self._cluster_id, new_cluster_id), - extra=self._logger_extras) + _logger.warning("Switching from current cluster: %s to new cluster: %s" + % (self._cluster_id, new_cluster_id)) self._on_cluster_restart() with self._lock: @@ -437,16 +427,15 @@ def _handle_successful_auth(self, response, connection, address): self._cluster_id = new_cluster_id self._lifecycle_service.fire_lifecycle_event(LifecycleState.CONNECTED) - self.logger.info("Authenticated with server %s:%s, server version: %s, local address: %s" - % (remote_address, remote_uuid, server_version_str, connection.local_address), - extra=self._logger_extras) + _logger.info("Authenticated with server %s:%s, server version: %s, local address: %s" + % (remote_address, remote_uuid, server_version_str, connection.local_address)) for on_connection_opened, _ in self._connection_listeners: if on_connection_opened: try: on_connection_opened(connection) except: - self.logger.exception("Exception in connection listener", extra=self._logger_extras) + _logger.exception("Exception in connection listener") if not connection.live: self.on_connection_close(connection, None) @@ -491,14 +480,12 @@ def _get_possible_addresses(self): class _HeartbeatManager(object): _heartbeat_timer = None - logger = logging.getLogger("HazelcastClient.HeartbeatManager") - def __init__(self, connection_manager, client, reactor, invocation_service, logger_extras): + def __init__(self, connection_manager, client, reactor, invocation_service): self._connection_manager = connection_manager self._client = client self._reactor = reactor self._invocation_service = invocation_service - self._logger_extras = logger_extras config = client.config self._heartbeat_timeout = config.heartbeat_timeout self._heartbeat_interval = config.heartbeat_interval @@ -527,7 +514,7 @@ def _check_connection(self, now, connection): return if (now - connection.last_read_time) > self._heartbeat_timeout: - self.logger.warning("Heartbeat failed over the connection: %s" % connection, extra=self._logger_extras) + _logger.warning("Heartbeat failed over the connection: %s" % connection) connection.close("Heartbeat timed out", TargetDisconnectedError("Heartbeat timed out to connection %s" % connection)) return @@ -619,7 +606,7 @@ def length(self): class Connection(object): """Connection object which stores connection related information and operations.""" - def __init__(self, connection_manager, connection_id, message_callback, logger_extras=None): + def __init__(self, connection_manager, connection_id, message_callback): self.remote_address = None self.remote_uuid = None self.connected_address = None @@ -630,10 +617,8 @@ def __init__(self, connection_manager, connection_id, message_callback, logger_e self.server_version = UNKNOWN_VERSION self.live = True self.close_reason = None - self.logger = logging.getLogger("HazelcastClient.Connection[%s]" % connection_id) self._connection_manager = connection_manager - self._logger_extras = logger_extras self._id = connection_id self._builder = ClientMessageBuilder(message_callback) self._reader = _Reader(self._builder) @@ -669,7 +654,7 @@ def close(self, reason, cause): try: self._inner_close() except: - self.logger.exception("Error while closing the the connection %s" % self, extra=self._logger_extras) + _logger.exception("Error while closing the the connection %s" % self) self._connection_manager.on_connection_close(self, cause) def _log_close(self, reason, cause): @@ -682,9 +667,9 @@ def _log_close(self, reason, cause): r = "Socket explicitly closed" if self._connection_manager.live: - self.logger.info(msg % (self, r), extra=self._logger_extras) + _logger.info(msg % (self, r)) else: - self.logger.debug(msg % (self, r), extra=self._logger_extras) + _logger.debug(msg % (self, r)) def _inner_close(self): raise NotImplementedError() diff --git a/hazelcast/core.py b/hazelcast/core.py index b93e4bb8c8..86199a4590 100644 --- a/hazelcast/core.py +++ b/hazelcast/core.py @@ -1,9 +1,12 @@ -"""Hazelcast Core objects""" +"""Hazelcast Core objects and constants.""" import json from hazelcast import six from hazelcast import util +CLIENT_TYPE = "PYH" +SERIALIZATION_VERSION = 1 + class MemberInfo(object): """ diff --git a/hazelcast/discovery.py b/hazelcast/discovery.py index 99caf07ae2..a7f8dca25e 100644 --- a/hazelcast/discovery.py +++ b/hazelcast/discovery.py @@ -10,17 +10,17 @@ except ImportError: ssl = None +_logger = logging.getLogger(__name__) + class HazelcastCloudAddressProvider(object): """Provides initial addresses for client to find and connect to a node and resolves private IP addresses of Hazelcast Cloud service. """ - logger = logging.getLogger("HazelcastClient.HazelcastCloudAddressProvider") - def __init__(self, token, connection_timeout, logger_extras): + def __init__(self, token, connection_timeout): self.cloud_discovery = HazelcastCloudDiscovery(token, connection_timeout) self._private_to_public = dict() - self._logger_extras = logger_extras def load_addresses(self): """Loads member addresses from Hazelcast Cloud endpoint. @@ -34,8 +34,7 @@ def load_addresses(self): # Every private address is primary return list(nodes.keys()), [] except Exception as e: - self.logger.warning("Failed to load addresses from Hazelcast Cloud: %s" % e, - extra=self._logger_extras) + _logger.warning("Failed to load addresses from Hazelcast Cloud: %s" % e) return [], [] def translate(self, address): @@ -63,8 +62,7 @@ def refresh(self): try: self._private_to_public = self.cloud_discovery.discover_nodes() except Exception as e: - self.logger.warning("Failed to load addresses from Hazelcast.cloud: %s" % e, - extra=self._logger_extras) + _logger.warning("Failed to load addresses from Hazelcast.cloud: %s" % e) class HazelcastCloudDiscovery(object): diff --git a/hazelcast/future.py b/hazelcast/future.py index 5cb25fcbca..5645361d39 100644 --- a/hazelcast/future.py +++ b/hazelcast/future.py @@ -5,6 +5,7 @@ from hazelcast.util import AtomicInteger from hazelcast import six +_logger = logging.getLogger(__name__) NONE_RESULT = object() @@ -14,7 +15,6 @@ class Future(object): _exception = None _traceback = None _threading_locals = threading.local() - logger = logging.getLogger("HazelcastClient.Future") def __init__(self): self._callbacks = [] @@ -123,7 +123,7 @@ def _invoke_cb(self, callback): try: callback(self) except: - self.logger.exception("Exception when invoking callback") + _logger.exception("Exception when invoking callback") def continue_with(self, continuation_func, *args): """Create a continuation that executes when the Future is completed. diff --git a/hazelcast/invocation.py b/hazelcast/invocation.py index 1c7129f3ff..c0bebc7c38 100644 --- a/hazelcast/invocation.py +++ b/hazelcast/invocation.py @@ -10,6 +10,8 @@ from hazelcast.util import AtomicInteger from hazelcast import six +_logger = logging.getLogger(__name__) + def _no_op_response_handler(_): pass @@ -50,10 +52,9 @@ def set_exception(self, exception, traceback=None): class InvocationService(object): - logger = logging.getLogger("HazelcastClient.InvocationService") _CLEAN_RESOURCES_PERIOD = 0.1 - def __init__(self, client, reactor, logger_extras): + def __init__(self, client, reactor): config = client.config smart_routing = config.smart_routing if smart_routing: @@ -63,7 +64,6 @@ def __init__(self, client, reactor, logger_extras): self._client = client self._reactor = reactor - self._logger_extras = logger_extras self._partition_service = None self._connection_manager = None self._listener_service = None @@ -100,7 +100,7 @@ def handle_client_message(self, message): invocation = self._pending.get(correlation_id, None) if not invocation: - self.logger.warning("Got message with unknown correlation id: %s", message, extra=self._logger_extras) + _logger.warning("Got message with unknown correlation id: %s", message) return if message.get_message_type() == EXCEPTION_MESSAGE_TYPE: @@ -122,21 +122,21 @@ def shutdown(self): def _invoke_on_partition_owner(self, invocation, partition_id): owner_uuid = self._partition_service.get_partition_owner(partition_id) if not owner_uuid: - self.logger.debug("Partition owner is not assigned yet", extra=self._logger_extras) + _logger.debug("Partition owner is not assigned yet") return False return self._invoke_on_target(invocation, owner_uuid) def _invoke_on_target(self, invocation, owner_uuid): connection = self._connection_manager.get_connection(owner_uuid) if not connection: - self.logger.debug("Client is not connected to target: %s" % owner_uuid, extra=self._logger_extras) + _logger.debug("Client is not connected to target: %s" % owner_uuid) return False return self._send(invocation, connection) def _invoke_on_random_connection(self, invocation): connection = self._connection_manager.get_random_connection() if not connection: - self.logger.debug("No connection found to invoke", extra=self._logger_extras) + _logger.debug("No connection found to invoke") return False return self._send(invocation, connection) @@ -206,7 +206,7 @@ def _send(self, invocation, connection): if invocation.event_handler: self._listener_service.add_event_handler(correlation_id, invocation.event_handler) - self.logger.debug("Sending %s to %s", message, connection, extra=self._logger_extras) + _logger.debug("Sending %s to %s", message, connection) if not connection.send_message(message): if invocation.event_handler: @@ -217,8 +217,7 @@ def _send(self, invocation, connection): return True def _notify_error(self, invocation, error): - self.logger.debug("Got exception for request %s, error: %s" % (invocation.request, error), - extra=self._logger_extras) + _logger.debug("Got exception for request %s, error: %s" % (invocation.request, error)) if not self._client.lifecycle_service.is_running(): self._complete_with_error(invocation, HazelcastClientNotActiveError()) @@ -229,8 +228,7 @@ def _notify_error(self, invocation, error): return if invocation.timeout < time.time(): - self.logger.debug("Error will not be retried because invocation timed out: %s", error, - extra=self._logger_extras) + _logger.debug("Error will not be retried because invocation timed out: %s", error) error = OperationTimeoutError("Request timed out because an error occurred " "after invocation timeout: %s" % error) self._complete_with_error(invocation, error) @@ -270,8 +268,7 @@ def _register_backup_listener(self): def _backup_event_handler(self, correlation_id): invocation = self._pending.get(correlation_id, None) if not invocation: - self.logger.debug("Invocation not found for backup event, invocation id %s" % correlation_id, - extra=self._logger_extras) + _logger.debug("Invocation not found for backup event, invocation id %s" % correlation_id) return self._notify_backup_complete(invocation) diff --git a/hazelcast/lifecycle.py b/hazelcast/lifecycle.py index 9257300a7c..0ffc04a458 100644 --- a/hazelcast/lifecycle.py +++ b/hazelcast/lifecycle.py @@ -1,8 +1,9 @@ import logging import uuid -from hazelcast import six -from hazelcast.util import create_git_info +from hazelcast import six, __version__ + +_logger = logging.getLogger(__name__) class LifecycleState(object): @@ -83,11 +84,8 @@ def remove_listener(self, registration_id): class _InternalLifecycleService(object): - logger = logging.getLogger("HazelcastClient.LifecycleService") - - def __init__(self, client, logger_extras): + def __init__(self, client): self._client = client - self._logger_extras = logger_extras self.running = False self._listeners = {} @@ -96,8 +94,6 @@ def __init__(self, client, logger_extras): for listener in lifecycle_listeners: self.add_listener(listener) - self._git_info = create_git_info() - def start(self): if self.running: return @@ -127,10 +123,10 @@ def fire_lifecycle_event(self, new_state): Args: new_state (str): The new state of the instance. """ - self.logger.info(self._git_info + "HazelcastClient is %s", new_state, extra=self._logger_extras) + _logger.info("HazelcastClient %s is %s" % (__version__, new_state)) for on_state_change in six.itervalues(self._listeners): if on_state_change: try: on_state_change(new_state) except: - self.logger.exception("Exception in lifecycle listener", extra=self._logger_extras) + _logger.exception("Exception in lifecycle listener") diff --git a/hazelcast/listener.py b/hazelcast/listener.py index 08bc7a79c8..6e10418d5a 100644 --- a/hazelcast/listener.py +++ b/hazelcast/listener.py @@ -9,6 +9,8 @@ from hazelcast.protocol.codec import client_add_cluster_view_listener_codec from hazelcast.util import check_not_none +_logger = logging.getLogger(__name__) + class _ListenerRegistration(object): __slots__ = ("registration_request", "decode_register_response", "encode_deregister_request", @@ -31,13 +33,10 @@ def __init__(self, server_registration_id, correlation_id): class ListenerService(object): - logger = logging.getLogger("HazelcastClient.ListenerService") - - def __init__(self, client, connection_manager, invocation_service, logger_extras): + def __init__(self, client, connection_manager, invocation_service): self._client = client self._connection_manager = connection_manager self._invocation_service = invocation_service - self._logger_extras = logger_extras self._is_smart = client.config.smart_routing self._active_registrations = {} # Dict of user_registration_id, ListenerRegistration self._registration_lock = threading.RLock() @@ -88,8 +87,8 @@ def deregister_listener(self, user_registration_id): except: if connection.live: successful = False - self.logger.warning("Deregistration for listener with ID %s has failed to address %s ", - user_registration_id, "address", exc_info=True, extra=self._logger_extras) + _logger.warning("Deregistration for listener with ID %s has failed to address %s ", + user_registration_id, "address", exc_info=True) if successful: self._active_registrations.pop(user_registration_id) @@ -100,7 +99,7 @@ def handle_client_message(self, message, correlation_id): if handler: handler(message) else: - self.logger.warning("Got event message with unknown correlation id: %s", message, extra=self._logger_extras) + _logger.warning("Got event message with unknown correlation id: %s", message) def add_event_handler(self, correlation_id, event_handler): self._event_handlers[correlation_id] = event_handler @@ -128,8 +127,8 @@ def callback(f): registration_map[connection] = registration except Exception as e: if connection.live: - self.logger.exception("Listener %s can not be added to a new connection: %s", - user_registration_id, connection, extra=self._logger_extras) + _logger.exception("Listener %s can not be added to a new connection: %s", + user_registration_id, connection) raise e return invocation.future.continue_with(callback) @@ -203,5 +202,3 @@ def inner(message): handle_partitions_view_event) return inner - - diff --git a/hazelcast/partition.py b/hazelcast/partition.py index 1d362da597..f194a88b1d 100644 --- a/hazelcast/partition.py +++ b/hazelcast/partition.py @@ -4,6 +4,8 @@ from hazelcast.hash import hash_to_index from hazelcast.serialization.data import Data +_logger = logging.getLogger(__name__) + class _PartitionTable(object): __slots__ = ("connection", "version", "partitions") @@ -64,19 +66,15 @@ def get_partition_count(self): class _InternalPartitionService(object): - logger = logging.getLogger("HazelcastClient.PartitionService") - - def __init__(self, client, logger_extras): + def __init__(self, client): self.partition_count = 0 self._client = client - self._logger_extras = logger_extras self._partition_table = _PartitionTable(None, -1, dict()) def handle_partitions_view_event(self, connection, partitions, version): - should_log = self.logger.isEnabledFor(logging.DEBUG) + should_log = _logger.isEnabledFor(logging.DEBUG) if should_log: - self.logger.debug("Handling new partition table with version: %s" % version, - extra=self._logger_extras) + _logger.debug("Handling new partition table with version: %s" % version) table = self._partition_table if not self._should_be_applied(connection, partitions, version, table, should_log): @@ -110,24 +108,22 @@ def check_and_set_partition_count(self, partition_count): def _should_be_applied(self, connection, partitions, version, current, should_log): if not partitions: if should_log: - self.logger.debug("Partition view will not be applied since response is empty. " - "Sending connection: %s, version: %s, current table: %s" - % (connection, version, current), - extra=self._logger_extras) + _logger.debug("Partition view will not be applied since response is empty. " + "Sending connection: %s, version: %s, current table: %s" + % (connection, version, current)) return False if connection != current.connection: if should_log: - self.logger.debug("Partition view event coming from a new connection. Old: %s, new: %s" - % (current.connection, connection), extra=self._logger_extras) + _logger.debug("Partition view event coming from a new connection. Old: %s, new: %s" + % (current.connection, connection)) return True if version <= current.version: if should_log: - self.logger.debug("Partition view will not be applied since response state version is older. " - "Sending connection: %s, version: %s, current table: %s" - % (connection, version, current), - extra=self._logger_extras) + _logger.debug("Partition view will not be applied since response state version is older. " + "Sending connection: %s, version: %s, current table: %s" + % (connection, version, current)) return False return True diff --git a/hazelcast/proxy/base.py b/hazelcast/proxy/base.py index 5d7fd1b641..8264294c18 100644 --- a/hazelcast/proxy/base.py +++ b/hazelcast/proxy/base.py @@ -1,5 +1,3 @@ -import logging - from hazelcast.future import make_blocking from hazelcast.invocation import Invocation from hazelcast.partition import string_partition_strategy @@ -28,7 +26,6 @@ def __init__(self, service_name, name, context): listener_service = context.listener_service self._register_listener = listener_service.register_listener self._deregister_listener = listener_service.deregister_listener - self.logger = logging.getLogger("HazelcastClient.%s(%s)" % (type(self).__name__, name)) self._is_smart = context.config.smart_routing def destroy(self): diff --git a/hazelcast/proxy/pn_counter.py b/hazelcast/proxy/pn_counter.py index fcf2114396..90f960ffc0 100644 --- a/hazelcast/proxy/pn_counter.py +++ b/hazelcast/proxy/pn_counter.py @@ -10,6 +10,8 @@ from hazelcast.errors import NoDataMemberInClusterError from hazelcast.six.moves import range +_logger = logging.getLogger(__name__) + class PNCounter(Proxy): """PN (Positive-Negative) CRDT counter. @@ -225,9 +227,8 @@ def _check_invocation_result(self, future, delegated_future, excluded_addresses, self._update_observed_replica_timestamp(result["replica_timestamps"]) delegated_future.set_result(result["value"]) except Exception as ex: - self.logger.exception("Exception occurred while invoking operation on target %s, " - "choosing different target" % target, - extra=self._context.logger_extras) + _logger.exception("Exception occurred while invoking operation on target %s, " + "choosing different target" % target) if excluded_addresses == PNCounter._EMPTY_ADDRESS_LIST: excluded_addresses = [] diff --git a/hazelcast/reactor.py b/hazelcast/reactor.py index 242fee7422..1c24dac49d 100644 --- a/hazelcast/reactor.py +++ b/hazelcast/reactor.py @@ -23,14 +23,14 @@ except ImportError: ssl = None +_logger = logging.getLogger(__name__) + class AsyncoreReactor(object): _thread = None _is_live = False - logger = logging.getLogger("HazelcastClient.AsyncoreReactor") - def __init__(self, logger_extras): - self._logger_extras = logger_extras + def __init__(self): self._timers = queue.PriorityQueue() self._map = {} @@ -41,7 +41,7 @@ def start(self): self._thread.start() def _loop(self): - self.logger.debug("Starting Reactor Thread", extra=self._logger_extras) + _logger.debug("Starting Reactor Thread") Future._threading_locals.is_reactor_thread = True while self._is_live: try: @@ -49,13 +49,13 @@ def _loop(self): self._check_timers() except select.error as err: # TODO: parse error type to catch only error "9" - self.logger.warning("Connection closed by server", extra=self._logger_extras) + _logger.warning("Connection closed by server") pass except: - self.logger.exception("Error in Reactor Thread", extra=self._logger_extras) + _logger.exception("Error in Reactor Thread") # TODO: shutdown client return - self.logger.debug("Reactor Thread exited. %s" % self._timers.qsize(), extra=self._logger_extras) + _logger.debug("Reactor Thread exited. %s" % self._timers.qsize()) self._cleanup_all_timers() def _check_timers(self): @@ -102,8 +102,8 @@ def shutdown(self): self._map.clear() def connection_factory(self, connection_manager, connection_id, address, network_config, message_callback): - return AsyncoreConnection(self._map, connection_manager, connection_id, address, - network_config, message_callback, self._logger_extras) + return AsyncoreConnection(self._map, connection_manager, connection_id, + address, network_config, message_callback) def _cleanup_timer(self, timer): try: @@ -128,9 +128,9 @@ class AsyncoreConnection(Connection, asyncore.dispatcher): read_buffer_size = _BUFFER_SIZE def __init__(self, dispatcher_map, connection_manager, connection_id, address, - config, message_callback, logger_extras): + config, message_callback): asyncore.dispatcher.__init__(self, map=dispatcher_map) - Connection.__init__(self, connection_manager, connection_id, message_callback, logger_extras) + Connection.__init__(self, connection_manager, connection_id, message_callback) self.connected_address = address self._write_lock = threading.Lock() @@ -203,7 +203,7 @@ def __init__(self, dispatcher_map, connection_manager, connection_id, address, def handle_connect(self): self.start_time = time.time() - self.logger.debug("Connected to %s", self.connected_address, extra=self._logger_extras) + _logger.debug("Connected to %s", self.connected_address) def handle_read(self): reader = self._reader @@ -230,17 +230,17 @@ def handle_write(self): self._write_queue.appendleft(data[sent:]) def handle_close(self): - self.logger.warning("Connection closed by server", extra=self._logger_extras) + _logger.warning("Connection closed by server") self.close(None, IOError("Connection closed by server")) def handle_error(self): error = sys.exc_info()[1] if sys.exc_info()[0] is socket.error: if error.errno != errno.EAGAIN and error.errno != errno.EDEADLK: - self.logger.exception("Received error", extra=self._logger_extras) + _logger.exception("Received error") self.close(None, IOError(error)) else: - self.logger.exception("Received unexpected error: %s" % error, extra=self._logger_extras) + _logger.exception("Received unexpected error: %s" % error) def readable(self): return self.live and self.sent_protocol_bytes @@ -252,7 +252,7 @@ def _write(self, buf): sent = self.send(buf) self.last_write_time = time.time() if sent < len(buf): - self.logger.info("Adding to queue", extra=self._logger_extras) + _logger.info("Adding to queue") self._write_queue.appendleft(buf[sent:]) finally: self._write_lock.release() diff --git a/hazelcast/statistics.py b/hazelcast/statistics.py index d260f35f76..32a65a9433 100644 --- a/hazelcast/statistics.py +++ b/hazelcast/statistics.py @@ -1,11 +1,11 @@ import logging import os +from hazelcast.core import CLIENT_TYPE from hazelcast.invocation import Invocation from hazelcast.protocol.codec import client_statistics_codec from hazelcast.util import current_time_in_millis, to_millis, to_nanos, current_time -from hazelcast.version import CLIENT_VERSION, CLIENT_TYPE -from hazelcast import six +from hazelcast import six, __version__ try: import psutil @@ -14,6 +14,8 @@ except ImportError: PSUTIL_ENABLED = False +_logger = logging.getLogger(__name__) + class Statistics(object): _NEAR_CACHE_CATEGORY_PREFIX = "nc." @@ -22,15 +24,13 @@ class Statistics(object): _EMPTY_STAT_VALUE = "" _DEFAULT_PROBE_VALUE = 0 - logger = logging.getLogger("HazelcastClient.Statistics") - def __init__(self, client, reactor, connection_manager, invocation_service, near_cache_manager, logger_extras): + def __init__(self, client, reactor, connection_manager, invocation_service, near_cache_manager): self._client = client self._reactor = reactor self._connection_manager = connection_manager self._invocation_service = invocation_service self._near_cache_manager = near_cache_manager - self._logger_extras = logger_extras config = client.config self._enabled = config.statistics_enabled self._period = config.statistics_period @@ -50,8 +50,7 @@ def _statistics_task(): self._statistics_timer = self._reactor.add_timer(self._period, _statistics_task) - self.logger.info("Client statistics enabled with the period of %s seconds." % self._period, - extra=self._logger_extras) + _logger.info("Client statistics enabled with the period of %s seconds." % self._period) def shutdown(self): if self._statistics_timer: @@ -60,8 +59,7 @@ def shutdown(self): def _send_statistics(self): connection = self._connection_manager.get_random_connection() if not connection: - self.logger.debug("Cannot send client statistics to the server. No connection found.", - extra=self._logger_extras) + _logger.debug("Cannot send client statistics to the server. No connection found.") return collection_timestamp = current_time_in_millis() @@ -127,7 +125,7 @@ def _fill_metrics(self, stats, connection): self._add_stat(stats, "lastStatisticsCollectionTime", current_time_in_millis()) self._add_stat(stats, "enterprise", "false") self._add_stat(stats, "clientType", CLIENT_TYPE) - self._add_stat(stats, "clientVersion", CLIENT_VERSION) + self._add_stat(stats, "clientVersion", __version__) self._add_stat(stats, "clusterConnectionTimestamp", to_millis(connection.start_time)) local_address = connection.local_address @@ -182,13 +180,12 @@ def safe_wrapper(self, psutil_stats, probe_name, *args): try: stat = func(self, psutil_stats, probe_name, *args) except AttributeError as ae: - self.logger.debug("Unable to register psutil method used for the probe %s. " - "Cause: %s" % (probe_name, ae), extra=self._logger_extras) + _logger.debug("Unable to register psutil method used for the probe %s. " + "Cause: %s" % (probe_name, ae)) self._failed_gauges.add(probe_name) return except Exception as ex: - self.logger.warning("Failed to access the probe %s. Cause: %s" % (probe_name, ex), - extra=self._logger_extras) + _logger.warning("Failed to access the probe %s. Cause: %s" % (probe_name, ex)) stat = self._DEFAULT_PROBE_VALUE psutil_stats[probe_name] = stat diff --git a/hazelcast/transaction.py b/hazelcast/transaction.py index 862a7d13d9..7a8ee524fa 100644 --- a/hazelcast/transaction.py +++ b/hazelcast/transaction.py @@ -13,6 +13,7 @@ from hazelcast.util import thread_id from hazelcast.six.moves import range +_logger = logging.getLogger(__name__) _STATE_ACTIVE = "active" _STATE_NOT_STARTED = "not_started" @@ -42,11 +43,9 @@ class TransactionManager(object): """Manages the execution of client transactions and provides Transaction objects.""" - logger = logging.getLogger("HazelcastClient.TransactionManager") - def __init__(self, context, logger_extras): + def __init__(self, context): self._context = context - self._logger_extras = logger_extras def _connect(self): connection_manager = self._context.connection_manager @@ -55,8 +54,8 @@ def _connect(self): if connection: return connection - self.logger.debug("Could not get a connection for the transaction. Attempt %d of %d", count, - RETRY_COUNT, exc_info=True, extra=self._logger_extras) + _logger.debug("Could not get a connection for the transaction. Attempt %d of %d", count, + RETRY_COUNT, exc_info=True) if count + 1 == RETRY_COUNT: raise IllegalStateError("No active connection is found") diff --git a/hazelcast/util.py b/hazelcast/util.py index cbf93b3fed..0eb17d3813 100644 --- a/hazelcast/util.py +++ b/hazelcast/util.py @@ -1,11 +1,9 @@ import random import threading import time -import logging from collections import Sequence, Iterable from hazelcast import six -from hazelcast.version import GIT_COMMIT_ID, GIT_COMMIT_DATE, CLIENT_VERSION DEFAULT_ADDRESS = "127.0.0.1" DEFAULT_PORT = 5701 @@ -190,65 +188,6 @@ def calculate_version(version_str): except ValueError: return UNKNOWN_VERSION -# Logging utilities - - -DEFAULT_LOGGING = { - "version": 1, - "disable_existing_loggers": False, - "filters": { - "version_message_filter": { - "()": "hazelcast.util.VersionMessageFilter" - } - }, - "formatters": { - "hazelcast_formatter": { - "()": "hazelcast.util.HazelcastFormatter", - "format": "%(asctime)s %(name)s\n%(levelname)s: %(version_message)s %(message)s", - "datefmt": "%b %d, %Y %I:%M:%S %p" - } - }, - "handlers": { - "console_handler": { - "class": "logging.StreamHandler", - "stream": "ext://sys.stderr", - "filters": ["version_message_filter"], - "formatter": "hazelcast_formatter" - } - }, - "loggers": { - "HazelcastClient": { - "handlers": ["console_handler"] - } - } -} - - -class VersionMessageFilter(logging.Filter): - def filter(self, record): - record.version_message = "[" + CLIENT_VERSION + "]" - return True - - -class HazelcastFormatter(logging.Formatter): - def format(self, record): - client_name = getattr(record, "client_name", None) - cluster_name = getattr(record, "cluster_name", None) - if client_name and cluster_name: - record.msg = "[" + cluster_name + "] [" + client_name + "] " + record.msg - return super(HazelcastFormatter, self).format(record) - - -def create_git_info(): - if GIT_COMMIT_DATE: - if GIT_COMMIT_ID: - return "(" + GIT_COMMIT_DATE + " - " + GIT_COMMIT_ID + ") " - return "(" + GIT_COMMIT_DATE + ") " - - if GIT_COMMIT_ID: - return "(" + GIT_COMMIT_ID + ") " - return "" - def to_list(*args, **kwargs): return list(*args, **kwargs) diff --git a/hazelcast/version.py b/hazelcast/version.py deleted file mode 100644 index 434f9cc7e0..0000000000 --- a/hazelcast/version.py +++ /dev/null @@ -1,69 +0,0 @@ -import json -import os -import subprocess - - -SERIALIZATION_VERSION = 1 -CLIENT_TYPE = "PYH" -CLIENT_VERSION_INFO = (4, 0, 0) -CLIENT_VERSION = ".".join(map(str, CLIENT_VERSION_INFO)) - - -class GitInfoProvider(object): - def __init__(self): - here = os.path.abspath(os.path.dirname(__file__)) - git_info = read_git_info(here) - - if git_info: - self.commit_id = git_info.get("commit_id", "") - self.commit_date = git_info.get("commit_date", "") - else: - self.commit_id = get_commit_id() - self.commit_date = get_commit_date() - write_git_info(here, self.commit_id, self.commit_date) - - -def read_git_info(here): - try: - file_path = os.path.abspath(os.path.join(here, "git_info.json")) - with open(file_path, "r") as f: - info = json.load(f) - return info - except: - return None - - -def write_git_info(here, commit_id, commit_date): - try: - git_info = dict() - git_info["commit_id"] = commit_id - git_info["commit_date"] = commit_date - - file_path = os.path.abspath(os.path.join(here, "git_info.json")) - with open(file_path, "w") as f: - json.dump(git_info, f) - except: - pass - - -def get_commit_id(): - try: - commit_id = subprocess.check_output(["git", "show", "-s", "--format=\"%h\""]).decode() - commit_id = commit_id.strip().replace("\"", "").replace("'", "") - return commit_id - except: - return "" - - -def get_commit_date(): - try: - commit_date = subprocess.check_output(["git", "show", "-s", "--format=\"%cd\"", "--date=short"]).decode() - commit_date = commit_date.strip().replace("\"", "").replace("'", "").replace("-", "") - return commit_date - except: - return "" - - -_info_provider = GitInfoProvider() -GIT_COMMIT_ID = _info_provider.commit_id -GIT_COMMIT_DATE = _info_provider.commit_date diff --git a/setup.py b/setup.py index 65d964bb16..b89649be45 100644 --- a/setup.py +++ b/setup.py @@ -2,14 +2,9 @@ from codecs import open from os import path from hazelcast import __version__ -from hazelcast.version import write_git_info, get_commit_id, get_commit_date here = path.abspath(path.dirname(__file__)) -commit_id = get_commit_id() -commit_date = get_commit_date() -write_git_info(here, commit_id, commit_date) - # Get the long description from the README file with open(path.join(here, 'README.md'), encoding='utf-8') as f: long_description = f.read() @@ -55,7 +50,6 @@ keywords='hazelcast,hazelcast client,In-Memory Data Grid,Distributed Computing', packages=find_packages(exclude=['benchmarks', 'examples', 'examples.*', 'docs', 'tests', 'tests.*']), package_dir={'hazelcast': 'hazelcast'}, - package_data={'hazelcast': ["git_info.json"]}, install_requires=[], extras_require=extras, tests_require=['thrift', 'nose', 'coverage', 'psutil', 'mock', 'parameterized'], diff --git a/tests/__init__.py b/tests/__init__.py index e69de29bb2..3fdc96c28c 100644 --- a/tests/__init__.py +++ b/tests/__init__.py @@ -0,0 +1,13 @@ +import logging +import subprocess + +try: + output = subprocess.check_output(["git", "show", "-s", "--format=\"%h\""]).decode() + commit_id = output.strip().replace("\"", "").replace("'", "") +except: + commit_id = "" + +logging.basicConfig( + format='%(asctime)s%(msecs)03d [' + commit_id + '][%(threadName)s][%(name)s] %(levelname)s: %(message)s', + datefmt="%H:%M:%S,") +logging.getLogger().setLevel(logging.INFO) diff --git a/tests/base.py b/tests/base.py index eda0980bc5..4f62057121 100644 --- a/tests/base.py +++ b/tests/base.py @@ -5,7 +5,6 @@ from tests.hzrc.client import HzRemoteController import hazelcast from hazelcast.core import Address -from tests.util import configure_logging class _Member(object): diff --git a/tests/client_test.py b/tests/client_test.py index 60b3211466..09db994e1f 100644 --- a/tests/client_test.py +++ b/tests/client_test.py @@ -4,7 +4,6 @@ from hazelcast.client import HazelcastClient from hazelcast.lifecycle import LifecycleState from tests.hzrc.ttypes import Lang -from tests.util import configure_logging class ClientTest(HazelcastTestCase): @@ -65,7 +64,6 @@ def message_listener(_): class ClientLabelsTest(HazelcastTestCase): @classmethod def setUpClass(cls): - configure_logging() cls.rc = cls.create_rc() cls.cluster = cls.create_cluster(cls.rc) cls.cluster.start_member() diff --git a/tests/config_test.py b/tests/config_test.py index 9d4c148c97..541a60eb0e 100644 --- a/tests/config_test.py +++ b/tests/config_test.py @@ -1,4 +1,3 @@ -import logging import unittest from hazelcast.config import _Config, SSLProtocol, ReconnectMode, IntType, InMemoryFormat, EvictionPolicy,\ @@ -718,26 +717,6 @@ def test_shuffle_member_list(self): config.shuffle_member_list = False self.assertFalse(config.shuffle_member_list) - def test_logging_config(self): - config = self.config - self.assertIsNone(config.logging_config) - - with self.assertRaises(TypeError): - config.logging_config = None - - config.logging_config = {} - self.assertEqual({}, config.logging_config) - - def test_logging_level(self): - config = self.config - self.assertEqual(logging.INFO, config.logging_level) - - with self.assertRaises(TypeError): - config.logging_level = None - - config.logging_level = logging.DEBUG - self.assertEqual(logging.DEBUG, config.logging_level) - def test_backup_ack_to_client_enabled(self): config = self.config self.assertTrue(config.backup_ack_to_client_enabled) diff --git a/tests/cp_test.py b/tests/cp_test.py index 7a6333edd1..f0cf8992a0 100644 --- a/tests/cp_test.py +++ b/tests/cp_test.py @@ -223,7 +223,7 @@ def set_thread_id(self, global_t_id): self.manager._thread_ids[(self.raft_group_id, thread_id())] = global_t_id def mock_reactor(self): - r = AsyncoreReactor({}) + r = AsyncoreReactor() r.start() m = MagicMock() m.add_timer = MagicMock(side_effect=lambda d, c: r.add_timer(d, c)) diff --git a/tests/discovery/hazelcast_cloud_provider_test.py b/tests/discovery/hazelcast_cloud_provider_test.py index c25c7ca781..89dc3bdd2d 100644 --- a/tests/discovery/hazelcast_cloud_provider_test.py +++ b/tests/discovery/hazelcast_cloud_provider_test.py @@ -19,7 +19,7 @@ def setUp(self): self.expected_addresses[self.private_address] = self.public_address self.cloud_discovery = HazelcastCloudDiscovery("", 0) self.cloud_discovery.discover_nodes = lambda: self.expected_addresses - self.provider = HazelcastCloudAddressProvider("", 0, None) + self.provider = HazelcastCloudAddressProvider("", 0) self.provider.cloud_discovery = self.cloud_discovery def test_load_addresses(self): @@ -60,10 +60,9 @@ def test_translate_when_not_found(self): def test_refresh_with_exception(self): cloud_discovery = HazelcastCloudDiscovery("", 0) cloud_discovery.discover_nodes = self.mock_discover_nodes_with_exception - provider = HazelcastCloudAddressProvider("", 0, None) + provider = HazelcastCloudAddressProvider("", 0) provider.cloud_discovery = cloud_discovery provider.refresh() def mock_discover_nodes_with_exception(self): raise Exception("Expected exception") - diff --git a/tests/invocation_test.py b/tests/invocation_test.py index 0d4c459ec5..cdbd2bcb13 100644 --- a/tests/invocation_test.py +++ b/tests/invocation_test.py @@ -133,7 +133,7 @@ def test_backup_handler_when_all_acks_are_not_received_and_reached_timeout_with_ def _start_service(self, config=_Config()): c = MagicMock(config=config) - invocation_service = InvocationService(c, c._reactor, None) + invocation_service = InvocationService(c, c._reactor) self.service = invocation_service invocation_service.init(c._internal_partition_service, c._connection_manager, c._listener_service) invocation_service.start() diff --git a/tests/logger/__init__.py b/tests/logger/__init__.py deleted file mode 100644 index e69de29bb2..0000000000 diff --git a/tests/logger/detailed_config.json b/tests/logger/detailed_config.json deleted file mode 100644 index 2f194aa393..0000000000 --- a/tests/logger/detailed_config.json +++ /dev/null @@ -1,31 +0,0 @@ -{ - "version": 1, - "loggers": { - "HazelcastClient": { - "level": "INFO", - "handlers": ["StdoutHandler", "StderrHandler"] - } - }, - "handlers": { - "StdoutHandler": { - "class": "logging.StreamHandler", - "formatter": "SimpleFormatter", - "stream": "ext://sys.stdout" - }, - "StderrHandler": { - "class": "logging.StreamHandler", - "formatter": "DetailedFormatter", - "stream": "ext://sys.stderr" - } - }, - "formatters": { - "SimpleFormatter": { - "format": "%(asctime)s*%(name)s*%(levelname)s*%(message)s", - "datefmt": "%Y-%m-%d %H:%M:%S" - }, - "DetailedFormatter": { - "format": "%(asctime)s*%(name)s*%(funcName)s*%(lineno)d*%(levelname)s*%(message)s", - "datefmt": "%Y-%m-%d %H:%M:%S" - } - } -} \ No newline at end of file diff --git a/tests/logger/logger_test.py b/tests/logger/logger_test.py deleted file mode 100644 index f78957f36b..0000000000 --- a/tests/logger/logger_test.py +++ /dev/null @@ -1,250 +0,0 @@ -import datetime -import json -import logging -import os - -from inspect import currentframe, getframeinfo -from hazelcast import HazelcastClient -from hazelcast.six import StringIO -from hazelcast.version import CLIENT_VERSION -from tests.util import get_abs_path -from tests.base import HazelcastTestCase - - -class LoggerConfigTest(HazelcastTestCase): - CUR_DIR = os.path.dirname(__file__) - - @classmethod - def setUpClass(cls): - cls.rc = cls.create_rc() - cls.cluster = cls.create_cluster(cls.rc, None) - cls.member = cls.cluster.start_member() - - @classmethod - def tearDownClass(cls): - cls.rc.exit() - - def test_default_config(self): - client = HazelcastClient(cluster_name=self.cluster.id) - - self.assertEqual(logging.INFO, client.logger.level) - self.assertTrue(client.logger.isEnabledFor(logging.INFO)) - self.assertTrue(client.logger.isEnabledFor(logging.WARNING)) - self.assertTrue(client.logger.isEnabledFor(logging.ERROR)) - self.assertTrue(client.logger.isEnabledFor(logging.CRITICAL)) - - out = StringIO() - default_handler = client.logger.handlers[0] - default_handler.stream = out - - client.logger.debug("DEBUG_TEST") - client.logger.info("INFO_TEST") - client.logger.error("ERROR_TEST") - client.logger.critical("CRITICAL_TEST") - - out.flush() - out_str = out.getvalue() - - self.assertEqual(0, out_str.count("DEBUG_TEST")) - self.assertEqual(1, out_str.count("INFO_TEST")) - self.assertEqual(1, out_str.count("ERROR_TEST")) - self.assertEqual(1, out_str.count("CRITICAL_TEST")) - - client.shutdown() - - def test_non_default_configuration_level(self): - client = HazelcastClient(cluster_name=self.cluster.id, logging_level=logging.CRITICAL) - - self.assertEqual(logging.CRITICAL, client.logger.level) - self.assertFalse(client.logger.isEnabledFor(logging.INFO)) - self.assertFalse(client.logger.isEnabledFor(logging.WARNING)) - self.assertFalse(client.logger.isEnabledFor(logging.ERROR)) - self.assertTrue(client.logger.isEnabledFor(logging.CRITICAL)) - - out = StringIO() - default_handler = client.logger.handlers[0] - default_handler.stream = out - - client.logger.debug("DEBUG_TEST") - client.logger.info("INFO_TEST") - client.logger.error("ERROR_TEST") - client.logger.critical("CRITICAL_TEST") - - out.flush() - out_str = out.getvalue() - - self.assertEqual(0, out_str.count("DEBUG_TEST")) - self.assertEqual(0, out_str.count("INFO_TEST")) - self.assertEqual(0, out_str.count("ERROR_TEST")) - self.assertEqual(1, out_str.count("CRITICAL_TEST")) - - client.shutdown() - - def test_simple_custom_logging_configuration(self): - # Outputs to stdout with the level of error - config_path = get_abs_path(self.CUR_DIR, "simple_config.json") - with open(config_path, "r") as f: - logging_config_data = f.read() - logging_config = json.loads(logging_config_data) - - client = HazelcastClient(cluster_name=self.cluster.id, logging_config=logging_config) - self.assertEqual(logging.ERROR, client.logger.getEffectiveLevel()) - self.assertFalse(client.logger.isEnabledFor(logging.INFO)) - self.assertFalse(client.logger.isEnabledFor(logging.WARNING)) - self.assertTrue(client.logger.isEnabledFor(logging.ERROR)) - self.assertTrue(client.logger.isEnabledFor(logging.CRITICAL)) - - out = StringIO() - handler = logging.getLogger("HazelcastClient").handlers[0] - handler.stream = out - - client.logger.debug("DEBUG_TEST") - client.logger.info("INFO_TEST") - client.logger.error("ERROR_TEST") - client.logger.critical("CRITICAL_TEST") - - out.flush() - out_str = out.getvalue() - - self.assertEqual(0, out_str.count("DEBUG_TEST")) - self.assertEqual(0, out_str.count("INFO_TEST")) - self.assertEqual(1, out_str.count("ERROR_TEST")) - self.assertEqual(1, out_str.count("CRITICAL_TEST")) - - client.shutdown() - - def test_default_configuration_multiple_clients(self): - config = { - "cluster_name": self.cluster.id - } - client1 = HazelcastClient(**config) - client2 = HazelcastClient(**config) - - out = StringIO() - - client1.logger.handlers[0].stream = out - client2.logger.handlers[0].stream = out - - client1.logger.info("TEST_MSG") - client2.logger.info("TEST_MSG") - - out.flush() - out_str = out.getvalue() - - self.assertEqual(2, out_str.count("TEST_MSG")) - - client1.shutdown() - client2.shutdown() - - def test_same_custom_configuration_file_with_multiple_clients(self): - config_path = get_abs_path(self.CUR_DIR, "simple_config.json") - with open(config_path, "r") as f: - logging_config_data = f.read() - logging_config = json.loads(logging_config_data) - - config = { - "cluster_name": self.cluster.id, - "logging_config": logging_config, - } - - client1 = HazelcastClient(**config) - client2 = HazelcastClient(**config) - - out = StringIO() - - logging.getLogger("HazelcastClient").handlers[0].stream = out - - client1.logger.critical("TEST_MSG") - client2.logger.critical("TEST_MSG") - - out.flush() - out_str = out.getvalue() - - self.assertEqual(2, out_str.count("TEST_MSG")) - - client1.shutdown() - client2.shutdown() - - def test_default_logger_output(self): - client = HazelcastClient(cluster_name=self.cluster.id) - - out = StringIO() - - client.logger.handlers[0].stream = out - version_message = "[" + CLIENT_VERSION + "]" - - client.logger.info("TEST_MSG") - - out.flush() - out_str = out.getvalue() - - self.assertTrue("TEST_MSG" in out_str) - - for line in out_str.split("\n"): - if "TEST_MSG" in line: - level_name, version, message = line.split(" ") - self.assertEqual("INFO:", level_name) - self.assertEqual(version_message, version) - self.assertEqual("TEST_MSG", message) - - client.shutdown() - - def test_custom_configuration_output(self): - config_path = get_abs_path(self.CUR_DIR, "detailed_config.json") - with open(config_path, "r") as f: - logging_config_data = f.read() - logging_config = json.loads(logging_config_data) - - client = HazelcastClient(cluster_name=self.cluster.id, logging_config=logging_config) - - std_out = StringIO() - std_err = StringIO() - - for handler in client.logger.handlers: - if handler.get_name() == "StdoutHandler": - handler.stream = std_out - else: - handler.stream = std_err - - frame_info = getframeinfo(currentframe()) - client.logger.info("TEST_MSG") - # These two statements above should - # follow each other without a white space. - # Otherwise, arrange the line number in - # the assert statements accordingly. - - std_out.flush() - std_err.flush() - std_out_str = std_out.getvalue() - std_err_str = std_err.getvalue() - - self.assertTrue("TEST_MSG" in std_out_str) - self.assertTrue("TEST_MSG" in std_err_str) - - for line in std_out_str.split("\n"): - if "TEST_MSG" in line: - print(line) - asc_time, name, level_name, message = line.split("*") - self.assertTrue(self._is_valid_date_string(asc_time)) - self.assertEqual("HazelcastClient", name) - self.assertEqual("INFO", level_name) - self.assertEqual("TEST_MSG", message) - - for line in std_err_str.split("\n"): - if "TEST_MSG" in line: - asc_time, name, func, line_no, level_name, message = line.split("*") - self.assertTrue(self._is_valid_date_string(asc_time)) - self.assertEqual("HazelcastClient", name) - self.assertEqual(frame_info.function, func) - self.assertEqual(str(frame_info.lineno + 1), line_no) - self.assertEqual("INFO", level_name) - self.assertEqual("TEST_MSG", message) - - client.shutdown() - - def _is_valid_date_string(self, time_str, fmt="%Y-%m-%d %H:%M:%S"): - try: - datetime.datetime.strptime(time_str, fmt) - except ValueError: - return False - return True diff --git a/tests/logger/simple_config.json b/tests/logger/simple_config.json deleted file mode 100644 index a8867b8526..0000000000 --- a/tests/logger/simple_config.json +++ /dev/null @@ -1,16 +0,0 @@ -{ - "version": 1, - "loggers": { - "HazelcastClient": { - "level": "ERROR", - "handlers": ["StdoutHandler"] - } - }, - - "handlers": { - "StdoutHandler": { - "class": "logging.StreamHandler", - "stream": "ext://sys.stdout" - } - } -} \ No newline at end of file diff --git a/tests/logger_test.py b/tests/logger_test.py new file mode 100644 index 0000000000..b9149645ce --- /dev/null +++ b/tests/logger_test.py @@ -0,0 +1,66 @@ +import logging +import unittest + +from mock import MagicMock + +from hazelcast.lifecycle import _InternalLifecycleService +from hazelcast.six import StringIO + + +class LoggerTest(unittest.TestCase): + def test_null_handler_is_added_by_default(self): + logger = logging.getLogger("hazelcast") + self.assertGreater(len(logger.handlers), 0) + + found = False + for handler in logger.handlers: + if handler.__class__.__name__ == "NullHandler": + # We check the class name instead of isinstance + # check with the logging.NullHandler as the class, + # since we might get an ImportError in __init__.py + # and fallback to our class. + found = True + break + + self.assertTrue(found) + + def test_logging_when_handlers_are_added(self): + out = StringIO() + handler = logging.StreamHandler(out) + logger = logging.getLogger("hazelcast") + original_level = logger.level + try: + logger.addHandler(handler) + logger.setLevel(logging.INFO) + + self.assertEqual(0, len(out.getvalue())) + + # Start a service that should print a log + service = _InternalLifecycleService(MagicMock()) + service.start() + + self.assertGreater(len(out.getvalue()), 0) # Something is written to stream + finally: + logger.setLevel(original_level) + logger.removeHandler(handler) + + def test_logging_when_handlers_are_added_to_root_logger(self): + out = StringIO() + handler = logging.StreamHandler(out) + logger = logging.getLogger() + original_level = logger.level + try: + logger.addHandler(handler) + logger.setLevel(logging.INFO) + + self.assertEqual(0, len(out.getvalue())) + + # Start a service that should print a log + service = _InternalLifecycleService(MagicMock()) + service.start() + + self.assertGreater(len(out.getvalue()), 0) # Something is written to stream + finally: + logger.setLevel(original_level) + logger.removeHandler(handler) + diff --git a/tests/proxy/flake_id_generator_test.py b/tests/proxy/flake_id_generator_test.py index 9b4d86557b..91bc2dcf43 100644 --- a/tests/proxy/flake_id_generator_test.py +++ b/tests/proxy/flake_id_generator_test.py @@ -4,7 +4,6 @@ from tests.base import SingleMemberTestCase, HazelcastTestCase from tests.hzrc.ttypes import Lang -from tests.util import configure_logging from hazelcast.client import HazelcastClient from hazelcast.proxy.flake_id_generator import _IdBatch, _Block, _AutoBatcher from hazelcast.future import ImmediateFuture @@ -195,10 +194,6 @@ def _id_batch_supplier(self, batch_size): class FlakeIdGeneratorIdOutOfRangeTest(HazelcastTestCase): - @classmethod - def setUpClass(cls): - configure_logging() - def setUp(self): self.rc = self.create_rc() self.cluster = self.create_cluster(self.rc, None) diff --git a/tests/proxy/transactional_set_test.py b/tests/proxy/transactional_set_test.py index 3a6cbba1ca..c4dc205924 100644 --- a/tests/proxy/transactional_set_test.py +++ b/tests/proxy/transactional_set_test.py @@ -1,5 +1,5 @@ from tests.base import SingleMemberTestCase -from tests.util import random_string, configure_logging +from tests.util import random_string class TransactionalSetTest(SingleMemberTestCase): @@ -9,7 +9,6 @@ def configure_client(cls, config): return config def setUp(self): - configure_logging() self.set = self.client.get_set(random_string()).blocking() def test_add(self): diff --git a/tests/ssl/ssl_test.py b/tests/ssl/ssl_test.py index 1103d6178e..798444e6f5 100644 --- a/tests/ssl/ssl_test.py +++ b/tests/ssl/ssl_test.py @@ -4,7 +4,7 @@ from hazelcast.client import HazelcastClient from hazelcast.errors import HazelcastError from hazelcast.config import SSLProtocol -from tests.util import get_ssl_config, configure_logging, fill_map, get_abs_path, set_attr +from tests.util import get_ssl_config, fill_map, get_abs_path, set_attr @set_attr(enterprise=True) @@ -14,10 +14,6 @@ class SSLTest(HazelcastTestCase): hazelcast_ssl_xml = get_abs_path(current_directory, "hazelcast-ssl.xml") default_ca_xml = get_abs_path(current_directory, "hazelcast-default-ca.xml") - @classmethod - def setUpClass(cls): - configure_logging() - def setUp(self): self.rc = self.create_rc() diff --git a/tests/statistics_test.py b/tests/statistics_test.py index f5c9e80837..503ea31633 100644 --- a/tests/statistics_test.py +++ b/tests/statistics_test.py @@ -1,9 +1,10 @@ import time -from tests.base import HazelcastTestCase -from hazelcast.statistics import Statistics +from hazelcast import __version__ from hazelcast.client import HazelcastClient -from hazelcast.version import CLIENT_VERSION, CLIENT_TYPE +from hazelcast.core import CLIENT_TYPE +from hazelcast.statistics import Statistics +from tests.base import HazelcastTestCase from tests.hzrc.ttypes import Lang from tests.util import random_string @@ -81,7 +82,7 @@ def test_statistics_content(self): self.assertEqual(1, result.count("lastStatisticsCollectionTime=")) self.assertEqual(1, result.count("enterprise=false")) self.assertEqual(1, result.count("clientType=" + CLIENT_TYPE)) - self.assertEqual(1, result.count("clientVersion=" + CLIENT_VERSION)) + self.assertEqual(1, result.count("clientVersion=" + __version__)) self.assertEqual(1, result.count("clusterConnectionTimestamp=")) self.assertEqual(1, result.count("clientAddress=" + local_address)) self.assertEqual(1, result.count("nc." + map_name + ".creationTime")) @@ -98,7 +99,7 @@ def test_statistics_content(self): # in different platforms. So, first try to get these statistics and then check the # response content - s = Statistics(client, None, None, None, None, None) + s = Statistics(client, None, None, None, None) psutil_stats = s._get_os_and_runtime_stats() for stat_name in psutil_stats: self.assertEqual(1, result.count(stat_name)) diff --git a/tests/util.py b/tests/util.py index b887984e75..bb5f2bb06c 100644 --- a/tests/util.py +++ b/tests/util.py @@ -1,4 +1,3 @@ -import logging import os import time @@ -10,12 +9,6 @@ def random_string(): return str(uuid4()) -def configure_logging(log_level=logging.INFO): - logging.basicConfig(format='%(asctime)s%(msecs)03d [%(threadName)s][%(name)s] %(levelname)s: %(message)s', - datefmt="%H:%M:%S,") - logging.getLogger().setLevel(log_level) - - def event_collector(): events = [] diff --git a/tests/version_test.py b/tests/version_test.py deleted file mode 100644 index 975ae6c24d..0000000000 --- a/tests/version_test.py +++ /dev/null @@ -1,33 +0,0 @@ -import os - -from hazelcast.version import get_commit_id, get_commit_date, read_git_info, write_git_info, GitInfoProvider -from unittest import TestCase - - -class VersionTest(TestCase): - def test_git_utilities(self): - commit_id = get_commit_id() - commit_date = get_commit_date() - - here = os.path.abspath(os.path.dirname(__file__)) - - write_git_info(here, commit_id, commit_date) - - info = read_git_info(here) - - self.assertEqual(commit_id, info.get("commit_id")) - self.assertEqual(commit_date, info.get("commit_date")) - - try: - os.remove(os.path.join(here, "git_info.json")) - except: - pass - - def test_git_info_provider(self): - info_provider = GitInfoProvider() - - commit_id = get_commit_id() - commit_date = get_commit_date() - - self.assertEqual(commit_id, info_provider.commit_id) - self.assertEqual(commit_date, info_provider.commit_date) From 734b199a81c33a925233c762bafb9e35a1404e6c Mon Sep 17 00:00:00 2001 From: mdumandag Date: Thu, 5 Nov 2020 16:02:50 +0300 Subject: [PATCH 2/3] fix typos --- README.md | 2 +- hazelcast/cluster.py | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/README.md b/README.md index 42716021b1..7f536a1106 100644 --- a/README.md +++ b/README.md @@ -2613,7 +2613,7 @@ Members [1] { 2020-10-16 13:31:35,634 - hazelcast.lifecycle - INFO - HazelcastClient 4.0.0 is SHUTDOWN ``` -A handy alternative to above example would be configuring the root logger using the ``logging.basicConfig()`` utility method. Beware that, +A handy alternative to the above example would be configuring the root logger using the ``logging.basicConfig()`` utility method. Beware that, every logger is the child of the root logger in Python. Hence, configuring the root logger may have application level impact. Nonetheless, it is useful for the testing or development purposes. diff --git a/hazelcast/cluster.py b/hazelcast/cluster.py index 511749f369..33144be50e 100644 --- a/hazelcast/cluster.py +++ b/hazelcast/cluster.py @@ -214,7 +214,7 @@ def _apply_new_state_and_fire_events(self, current, snapshot): try: handler(removed_member) except: - _logger.exception("Exception in membership lister") + _logger.exception("Exception in membership listener") for added_member in additions: for handler, _ in six.itervalues(self._listeners): @@ -222,7 +222,7 @@ def _apply_new_state_and_fire_events(self, current, snapshot): try: handler(added_member) except: - _logger.exception("Exception in membership lister") + _logger.exception("Exception in membership listener") def _detect_membership_events(self, old, new): new_members = [] From 238e963318db7f6ae74592294c47ac68d7c46cd5 Mon Sep 17 00:00:00 2001 From: mdumandag Date: Thu, 5 Nov 2020 16:22:52 +0300 Subject: [PATCH 3/3] do string interpolatation lazily in logs --- hazelcast/cluster.py | 7 +++--- hazelcast/connection.py | 42 +++++++++++++++++------------------ hazelcast/discovery.py | 4 ++-- hazelcast/invocation.py | 6 ++--- hazelcast/lifecycle.py | 2 +- hazelcast/partition.py | 27 +++++++++------------- hazelcast/proxy/pn_counter.py | 2 +- hazelcast/reactor.py | 4 ++-- hazelcast/statistics.py | 6 ++--- 9 files changed, 47 insertions(+), 53 deletions(-) diff --git a/hazelcast/cluster.py b/hazelcast/cluster.py index 33144be50e..a15b901b28 100644 --- a/hazelcast/cluster.py +++ b/hazelcast/cluster.py @@ -183,8 +183,7 @@ def wait_initial_member_list_fetched(self): raise IllegalStateError("Could not get initial member list from cluster!") def clear_member_list_version(self): - if _logger.isEnabledFor(logging.DEBUG): - _logger.debug("Resetting the member list version") + _logger.debug("Resetting the member list version") current = self._member_list_snapshot if current is not _EMPTY_SNAPSHOT: @@ -193,8 +192,8 @@ def clear_member_list_version(self): def handle_members_view_event(self, version, member_infos): snapshot = self._create_snapshot(version, member_infos) if _logger.isEnabledFor(logging.DEBUG): - _logger.debug("Handling new snapshot with membership version: %s, member string: %s" - % (version, self._members_string(snapshot))) + _logger.debug("Handling new snapshot with membership version: %s, member string: %s", + version, self._members_string(snapshot)) current = self._member_list_snapshot if version >= current.version: diff --git a/hazelcast/connection.py b/hazelcast/connection.py index ec11efa83a..6822fb1598 100644 --- a/hazelcast/connection.py +++ b/hazelcast/connection.py @@ -47,15 +47,15 @@ def sleep(self): time_passed = now - self._cluster_connect_attempt_begin if time_passed > self._cluster_connect_timeout: _logger.warning("Unable to get live cluster connection, cluster connect timeout (%d) is reached. " - "Attempt %d." % (self._cluster_connect_timeout, self._attempt)) + "Attempt %d.", self._cluster_connect_timeout, self._attempt) return False # random between (-jitter * current_backoff, jitter * current_backoff) sleep_time = self._current_backoff + self._current_backoff * self._jitter * (2 * random.random() - 1) sleep_time = min(sleep_time, self._cluster_connect_timeout - time_passed) _logger.warning("Unable to get live cluster connection, retry in %ds, attempt: %d, " - "cluster connect timeout: %ds, max backoff: %ds" - % (sleep_time, self._attempt, self._cluster_connect_timeout, self._max_backoff)) + "cluster connect timeout: %ds, max backoff: %ds", + sleep_time, self._attempt, self._cluster_connect_timeout, self._max_backoff) time.sleep(sleep_time) self._current_backoff = min(self._current_backoff * self._multiplier, self._max_backoff) return True @@ -183,7 +183,7 @@ def on_connection_close(self, closed_connection, cause): if not connected_address: _logger.debug("Destroying %s, but it has no remote address, hence nothing is " - "removed from the connection dictionary" % closed_connection) + "removed from the connection dictionary", closed_connection) with self._lock: pending = self._pending_connections.pop(connected_address, None) @@ -193,8 +193,8 @@ def on_connection_close(self, closed_connection, cause): pending.set_exception(cause) if connection: - _logger.info("Removed connection to %s:%s, connection: %s" - % (connected_address, remote_uuid, connection)) + _logger.info("Removed connection to %s:%s, connection: %s", + connected_address, remote_uuid, connection) if not self.active_connections: self._lifecycle_service.fire_lifecycle_event(LifecycleState.DISCONNECTED) self._trigger_cluster_reconnection() @@ -208,8 +208,8 @@ def on_connection_close(self, closed_connection, cause): _logger.exception("Exception in connection listener") else: if remote_uuid: - _logger.debug("Destroying %s, but there is no mapping for %s in the connection dictionary" - % (closed_connection, remote_uuid)) + _logger.debug("Destroying %s, but there is no mapping for %s in the connection dictionary", + closed_connection, remote_uuid) def check_invocation_allowed(self): if self.active_connections: @@ -309,11 +309,11 @@ def _sync_connect_to_cluster(self): break except (ClientNotAllowedInClusterError, InvalidConfigurationError): cluster_name = self._client.config.cluster_name - _logger.exception("Stopped trying on cluster %s" % cluster_name) + _logger.exception("Stopped trying on cluster %s", cluster_name) cluster_name = self._client.config.cluster_name _logger.info("Unable to connect to any address from the cluster with name: %s. " - "The following addresses were tried: %s" % (cluster_name, tried_addresses)) + "The following addresses were tried: %s", cluster_name, tried_addresses) if self._lifecycle_service.running: msg = "Unable to connect to any cluster" else: @@ -321,14 +321,14 @@ def _sync_connect_to_cluster(self): raise IllegalStateError(msg) def _connect(self, address): - _logger.info("Trying to connect to %s" % address) + _logger.info("Trying to connect to %s", address) try: return self._get_or_connect(address).result() except (ClientNotAllowedInClusterError, InvalidConfigurationError) as e: - _logger.warning("Error during initial connection to %s: %s" % (address, e)) + _logger.warning("Error during initial connection to %s: %s", address, e) raise e except Exception as e: - _logger.warning("Error during initial connection to %s: %s" % (address, e)) + _logger.warning("Error during initial connection to %s: %s", address, e) return None def _get_or_connect(self, address): @@ -415,8 +415,8 @@ def _handle_successful_auth(self, response, connection, address): is_initial_connection = not self.active_connections changed_cluster = is_initial_connection and self._cluster_id is not None and self._cluster_id != new_cluster_id if changed_cluster: - _logger.warning("Switching from current cluster: %s to new cluster: %s" - % (self._cluster_id, new_cluster_id)) + _logger.warning("Switching from current cluster: %s to new cluster: %s", + self._cluster_id, new_cluster_id) self._on_cluster_restart() with self._lock: @@ -427,8 +427,8 @@ def _handle_successful_auth(self, response, connection, address): self._cluster_id = new_cluster_id self._lifecycle_service.fire_lifecycle_event(LifecycleState.CONNECTED) - _logger.info("Authenticated with server %s:%s, server version: %s, local address: %s" - % (remote_address, remote_uuid, server_version_str, connection.local_address)) + _logger.info("Authenticated with server %s:%s, server version: %s, local address: %s", + remote_address, remote_uuid, server_version_str, connection.local_address) for on_connection_opened, _ in self._connection_listeners: if on_connection_opened: @@ -514,7 +514,7 @@ def _check_connection(self, now, connection): return if (now - connection.last_read_time) > self._heartbeat_timeout: - _logger.warning("Heartbeat failed over the connection: %s" % connection) + _logger.warning("Heartbeat failed over the connection: %s", connection) connection.close("Heartbeat timed out", TargetDisconnectedError("Heartbeat timed out to connection %s" % connection)) return @@ -654,7 +654,7 @@ def close(self, reason, cause): try: self._inner_close() except: - _logger.exception("Error while closing the the connection %s" % self) + _logger.exception("Error while closing the the connection %s", self) self._connection_manager.on_connection_close(self, cause) def _log_close(self, reason, cause): @@ -667,9 +667,9 @@ def _log_close(self, reason, cause): r = "Socket explicitly closed" if self._connection_manager.live: - _logger.info(msg % (self, r)) + _logger.info(msg, self, r) else: - _logger.debug(msg % (self, r)) + _logger.debug(msg, self, r) def _inner_close(self): raise NotImplementedError() diff --git a/hazelcast/discovery.py b/hazelcast/discovery.py index a7f8dca25e..ba6082ee9c 100644 --- a/hazelcast/discovery.py +++ b/hazelcast/discovery.py @@ -34,7 +34,7 @@ def load_addresses(self): # Every private address is primary return list(nodes.keys()), [] except Exception as e: - _logger.warning("Failed to load addresses from Hazelcast Cloud: %s" % e) + _logger.warning("Failed to load addresses from Hazelcast Cloud: %s", e) return [], [] def translate(self, address): @@ -62,7 +62,7 @@ def refresh(self): try: self._private_to_public = self.cloud_discovery.discover_nodes() except Exception as e: - _logger.warning("Failed to load addresses from Hazelcast.cloud: %s" % e) + _logger.warning("Failed to load addresses from Hazelcast.cloud: %s", e) class HazelcastCloudDiscovery(object): diff --git a/hazelcast/invocation.py b/hazelcast/invocation.py index c0bebc7c38..436a412662 100644 --- a/hazelcast/invocation.py +++ b/hazelcast/invocation.py @@ -129,7 +129,7 @@ def _invoke_on_partition_owner(self, invocation, partition_id): def _invoke_on_target(self, invocation, owner_uuid): connection = self._connection_manager.get_connection(owner_uuid) if not connection: - _logger.debug("Client is not connected to target: %s" % owner_uuid) + _logger.debug("Client is not connected to target: %s", owner_uuid) return False return self._send(invocation, connection) @@ -217,7 +217,7 @@ def _send(self, invocation, connection): return True def _notify_error(self, invocation, error): - _logger.debug("Got exception for request %s, error: %s" % (invocation.request, error)) + _logger.debug("Got exception for request %s, error: %s", invocation.request, error) if not self._client.lifecycle_service.is_running(): self._complete_with_error(invocation, HazelcastClientNotActiveError()) @@ -268,7 +268,7 @@ def _register_backup_listener(self): def _backup_event_handler(self, correlation_id): invocation = self._pending.get(correlation_id, None) if not invocation: - _logger.debug("Invocation not found for backup event, invocation id %s" % correlation_id) + _logger.debug("Invocation not found for backup event, invocation id %s", correlation_id) return self._notify_backup_complete(invocation) diff --git a/hazelcast/lifecycle.py b/hazelcast/lifecycle.py index 0ffc04a458..83b77a8d65 100644 --- a/hazelcast/lifecycle.py +++ b/hazelcast/lifecycle.py @@ -123,7 +123,7 @@ def fire_lifecycle_event(self, new_state): Args: new_state (str): The new state of the instance. """ - _logger.info("HazelcastClient %s is %s" % (__version__, new_state)) + _logger.info("HazelcastClient %s is %s", __version__, new_state) for on_state_change in six.itervalues(self._listeners): if on_state_change: try: diff --git a/hazelcast/partition.py b/hazelcast/partition.py index f194a88b1d..eb93faaeac 100644 --- a/hazelcast/partition.py +++ b/hazelcast/partition.py @@ -72,12 +72,10 @@ def __init__(self, client): self._partition_table = _PartitionTable(None, -1, dict()) def handle_partitions_view_event(self, connection, partitions, version): - should_log = _logger.isEnabledFor(logging.DEBUG) - if should_log: - _logger.debug("Handling new partition table with version: %s" % version) + _logger.debug("Handling new partition table with version: %s", version) table = self._partition_table - if not self._should_be_applied(connection, partitions, version, table, should_log): + if not self._should_be_applied(connection, partitions, version, table): return new_partitions = self._prepare_partitions(partitions) @@ -105,25 +103,22 @@ def check_and_set_partition_count(self, partition_count): return True return self.partition_count == partition_count - def _should_be_applied(self, connection, partitions, version, current, should_log): + def _should_be_applied(self, connection, partitions, version, current): if not partitions: - if should_log: - _logger.debug("Partition view will not be applied since response is empty. " - "Sending connection: %s, version: %s, current table: %s" - % (connection, version, current)) + _logger.debug("Partition view will not be applied since response is empty. " + "Sending connection: %s, version: %s, current table: %s", + connection, version, current) return False if connection != current.connection: - if should_log: - _logger.debug("Partition view event coming from a new connection. Old: %s, new: %s" - % (current.connection, connection)) + _logger.debug("Partition view event coming from a new connection. Old: %s, new: %s", + current.connection, connection) return True if version <= current.version: - if should_log: - _logger.debug("Partition view will not be applied since response state version is older. " - "Sending connection: %s, version: %s, current table: %s" - % (connection, version, current)) + _logger.debug("Partition view will not be applied since response state version is older. " + "Sending connection: %s, version: %s, current table: %s", + connection, version, current) return False return True diff --git a/hazelcast/proxy/pn_counter.py b/hazelcast/proxy/pn_counter.py index 90f960ffc0..10310500e0 100644 --- a/hazelcast/proxy/pn_counter.py +++ b/hazelcast/proxy/pn_counter.py @@ -228,7 +228,7 @@ def _check_invocation_result(self, future, delegated_future, excluded_addresses, delegated_future.set_result(result["value"]) except Exception as ex: _logger.exception("Exception occurred while invoking operation on target %s, " - "choosing different target" % target) + "choosing different target", target) if excluded_addresses == PNCounter._EMPTY_ADDRESS_LIST: excluded_addresses = [] diff --git a/hazelcast/reactor.py b/hazelcast/reactor.py index 1c24dac49d..b287ff9353 100644 --- a/hazelcast/reactor.py +++ b/hazelcast/reactor.py @@ -55,7 +55,7 @@ def _loop(self): _logger.exception("Error in Reactor Thread") # TODO: shutdown client return - _logger.debug("Reactor Thread exited. %s" % self._timers.qsize()) + _logger.debug("Reactor Thread exited. %s", self._timers.qsize()) self._cleanup_all_timers() def _check_timers(self): @@ -240,7 +240,7 @@ def handle_error(self): _logger.exception("Received error") self.close(None, IOError(error)) else: - _logger.exception("Received unexpected error: %s" % error) + _logger.exception("Received unexpected error: %s", error) def readable(self): return self.live and self.sent_protocol_bytes diff --git a/hazelcast/statistics.py b/hazelcast/statistics.py index 32a65a9433..7d7ee7384e 100644 --- a/hazelcast/statistics.py +++ b/hazelcast/statistics.py @@ -50,7 +50,7 @@ def _statistics_task(): self._statistics_timer = self._reactor.add_timer(self._period, _statistics_task) - _logger.info("Client statistics enabled with the period of %s seconds." % self._period) + _logger.info("Client statistics enabled with the period of %s seconds.", self._period) def shutdown(self): if self._statistics_timer: @@ -181,11 +181,11 @@ def safe_wrapper(self, psutil_stats, probe_name, *args): stat = func(self, psutil_stats, probe_name, *args) except AttributeError as ae: _logger.debug("Unable to register psutil method used for the probe %s. " - "Cause: %s" % (probe_name, ae)) + "Cause: %s", probe_name, ae) self._failed_gauges.add(probe_name) return except Exception as ex: - _logger.warning("Failed to access the probe %s. Cause: %s" % (probe_name, ex)) + _logger.warning("Failed to access the probe %s. Cause: %s", probe_name, ex) stat = self._DEFAULT_PROBE_VALUE psutil_stats[probe_name] = stat