diff --git a/.gitignore b/.gitignore index ecfb4766..6274eec6 100644 --- a/.gitignore +++ b/.gitignore @@ -9,9 +9,16 @@ MANIFEST dist # Output of running coverage locally +cover .coverage # From python-testapp.git .idea/ .virt/ datafile.json + +# vim swap files +*.swp + +# OSX folder metadata +*.DS_Store diff --git a/README.md b/README.md index 210387af..4c0948fb 100644 --- a/README.md +++ b/README.md @@ -26,23 +26,20 @@ See the Optimizely Full Stack [developer documentation](http://developers.optimi ### Building the SDK -Build the SDK using the following command: +Build and install the SDK with pip, using the following command: ``` -python setup.py sdist +pip install -e . ``` -This will create a tarball under `dist/` +### Unit tests -You can then install the SDK and its dependencies with: +##### Running all tests +To get test dependencies installed, use a modified version of the install command: ``` -pip install dist/optimizely-sdk-{VERSION}.tar.gz +pip install -e .[test] ``` - -### Unit tests - -##### Running all tests You can run all unit tests with: ``` diff --git a/optimizely/__init__.py b/optimizely/__init__.py index cc653bcd..e0ed6ba3 100644 --- a/optimizely/__init__.py +++ b/optimizely/__init__.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/optimizely/bucketer.py b/optimizely/bucketer.py index ca3d2c07..4815625e 100644 --- a/optimizely/bucketer.py +++ b/optimizely/bucketer.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. @@ -80,9 +80,10 @@ def find_bucket(self, bucketing_id, parent_id, traffic_allocations): bucketing_key = BUCKETING_ID_TEMPLATE.format(bucketing_id=bucketing_id, parent_id=parent_id) bucketing_number = self._generate_bucket_value(bucketing_key) - self.config.logger.log(enums.LogLevels.DEBUG, - 'Assigned bucket %s to user with bucketing ID "%s".' % (bucketing_number, - bucketing_id)) + self.config.logger.debug('Assigned bucket %s to user with bucketing ID "%s".' % ( + bucketing_number, + bucketing_id + )) for traffic_allocation in traffic_allocations: current_end_of_range = traffic_allocation.get('endOfRange') @@ -115,24 +116,33 @@ def bucket(self, experiment, user_id, bucketing_id): user_experiment_id = self.find_bucket(bucketing_id, experiment.groupId, group.trafficAllocation) if not user_experiment_id: - self.config.logger.log(enums.LogLevels.INFO, 'User "%s" is in no experiment.' % user_id) + self.config.logger.info('User "%s" is in no experiment.' % user_id) return None if user_experiment_id != experiment.id: - self.config.logger.log(enums.LogLevels.INFO, 'User "%s" is not in experiment "%s" of group %s.' % - (user_id, experiment.key, experiment.groupId)) + self.config.logger.info('User "%s" is not in experiment "%s" of group %s.' % ( + user_id, + experiment.key, + experiment.groupId + )) return None - self.config.logger.log(enums.LogLevels.INFO, 'User "%s" is in experiment %s of group %s.' % - (user_id, experiment.key, experiment.groupId)) + self.config.logger.info('User "%s" is in experiment %s of group %s.' % ( + user_id, + experiment.key, + experiment.groupId + )) # Bucket user if not in white-list and in group (if any) variation_id = self.find_bucket(bucketing_id, experiment.id, experiment.trafficAllocation) if variation_id: variation = self.config.get_variation_from_id(experiment.key, variation_id) - self.config.logger.log(enums.LogLevels.INFO, 'User "%s" is in variation "%s" of experiment %s.' % - (user_id, variation.key, experiment.key)) + self.config.logger.info('User "%s" is in variation "%s" of experiment %s.' % ( + user_id, + variation.key, + experiment.key + )) return variation - self.config.logger.log(enums.LogLevels.INFO, 'User "%s" is in no variation.' % user_id) + self.config.logger.info('User "%s" is in no variation.' % user_id) return None diff --git a/optimizely/decision_service.py b/optimizely/decision_service.py index a3d8ee37..6b50f77b 100644 --- a/optimizely/decision_service.py +++ b/optimizely/decision_service.py @@ -4,14 +4,13 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. # See the License for the specific language governing permissions and # limitations under the License. -import sys from collections import namedtuple from . import bucketer @@ -21,7 +20,6 @@ from .helpers import validator from .user_profile import UserProfile - Decision = namedtuple('Decision', 'experiment variation source') DECISION_SOURCE_EXPERIMENT = 'experiment' DECISION_SOURCE_ROLLOUT = 'rollout' @@ -67,8 +65,7 @@ def get_forced_variation(self, experiment, user_id): variation_key = forced_variations.get(user_id) variation = self.config.get_variation_from_key(experiment.key, variation_key) if variation: - self.config.logger.log(enums.LogLevels.INFO, - 'User "%s" is forced in variation "%s".' % (user_id, variation_key)) + self.logger.info('User "%s" is forced in variation "%s".' % (user_id, variation_key)) return variation return None @@ -90,9 +87,11 @@ def get_stored_variation(self, experiment, user_profile): if variation_id: variation = self.config.get_variation_from_id(experiment.key, variation_id) if variation: - self.config.logger.log(enums.LogLevels.INFO, - 'Found a stored decision. User "%s" is in variation "%s" of experiment "%s".' % - (user_id, variation.key, experiment.key)) + self.logger.info('Found a stored decision. User "%s" is in variation "%s" of experiment "%s".' % ( + user_id, + variation.key, + experiment.key + )) return variation return None @@ -118,7 +117,7 @@ def get_variation(self, experiment, user_id, attributes, ignore_user_profile=Fal # Check if experiment is running if not experiment_helper.is_experiment_running(experiment): - self.logger.log(enums.LogLevels.INFO, 'Experiment "%s" is not running.' % experiment.key) + self.logger.info('Experiment "%s" is not running.' % experiment.key) return None # Check if the user is forced into a variation @@ -137,11 +136,7 @@ def get_variation(self, experiment, user_id, attributes, ignore_user_profile=Fal try: retrieved_profile = self.user_profile_service.lookup(user_id) except: - error = sys.exc_info()[1] - self.logger.log( - enums.LogLevels.ERROR, - 'Unable to retrieve user profile for user "%s" as lookup failed. Error: %s' % (user_id, str(error)) - ) + self.logger.exception('Unable to retrieve user profile for user "%s" as lookup failed.' % user_id) retrieved_profile = None if validator.is_user_profile_valid(retrieved_profile): @@ -150,14 +145,14 @@ def get_variation(self, experiment, user_id, attributes, ignore_user_profile=Fal if variation: return variation else: - self.logger.log(enums.LogLevels.WARNING, 'User profile has invalid format.') + self.logger.warning('User profile has invalid format.') # Bucket user and store the new decision if not audience_helper.is_user_in_experiment(self.config, experiment, attributes): - self.logger.log( - enums.LogLevels.INFO, - 'User "%s" does not meet conditions to be in experiment "%s".' % (user_id, experiment.key) - ) + self.logger.info('User "%s" does not meet conditions to be in experiment "%s".' % ( + user_id, + experiment.key + )) return None # Determine bucketing ID to be used @@ -171,9 +166,7 @@ def get_variation(self, experiment, user_id, attributes, ignore_user_profile=Fal user_profile.save_variation_for_experiment(experiment.id, variation.id) self.user_profile_service.save(user_profile.__dict__) except: - error = sys.exc_info()[1] - self.logger.log(enums.LogLevels.ERROR, - 'Unable to save user profile for user "%s". Error: %s' % (user_id, str(error))) + self.logger.exception('Unable to save user profile for user "%s".' % user_id) return variation return None @@ -198,25 +191,27 @@ def get_variation_for_rollout(self, rollout, user_id, attributes=None): # Check if user meets audience conditions for targeting rule if not audience_helper.is_user_in_experiment(self.config, experiment, attributes): - self.logger.log( - enums.LogLevels.DEBUG, - 'User "%s" does not meet conditions for targeting rule %s.' % (user_id, idx + 1) - ) + self.logger.debug('User "%s" does not meet conditions for targeting rule %s.' % ( + user_id, + idx + 1 + )) continue - self.logger.log(enums.LogLevels.DEBUG, 'User "%s" meets conditions for targeting rule %s.' % (user_id, idx + 1)) + self.logger.debug('User "%s" meets conditions for targeting rule %s.' % (user_id, idx + 1)) # Determine bucketing ID to be used bucketing_id = self._get_bucketing_id(user_id, attributes) variation = self.bucketer.bucket(experiment, user_id, bucketing_id) if variation: - self.logger.log(enums.LogLevels.DEBUG, - 'User "%s" is in variation %s of experiment %s.' % (user_id, variation.key, experiment.key)) + self.logger.debug('User "%s" is in variation %s of experiment %s.' % ( + user_id, + variation.key, + experiment.key + )) return Decision(experiment, variation, DECISION_SOURCE_ROLLOUT) else: # Evaluate no further rules - self.logger.log(enums.LogLevels.DEBUG, - 'User "%s" is not in the traffic group for the targeting else. ' - 'Checking "Everyone Else" rule now.' % user_id) + self.logger.debug('User "%s" is not in the traffic group for the targeting else. ' + 'Checking "Everyone Else" rule now.' % user_id) break # Evaluate last rule i.e. "Everyone Else" rule @@ -228,8 +223,7 @@ def get_variation_for_rollout(self, rollout, user_id, attributes=None): bucketing_id = self._get_bucketing_id(user_id, attributes) variation = self.bucketer.bucket(everyone_else_experiment, user_id, bucketing_id) if variation: - self.logger.log(enums.LogLevels.DEBUG, - 'User "%s" meets conditions for targeting rule "Everyone Else".' % user_id) + self.logger.debug('User "%s" meets conditions for targeting rule "Everyone Else".' % user_id) return Decision(everyone_else_experiment, variation, DECISION_SOURCE_ROLLOUT) return Decision(None, None, DECISION_SOURCE_ROLLOUT) @@ -249,14 +243,17 @@ def get_experiment_in_group(self, group, bucketing_id): if experiment_id: experiment = self.config.get_experiment_from_id(experiment_id) if experiment: - self.logger.log(enums.LogLevels.INFO, - 'User with bucketing ID "%s" is in experiment %s of group %s.' % - (bucketing_id, experiment.key, group.id)) + self.logger.info('User with bucketing ID "%s" is in experiment %s of group %s.' % ( + bucketing_id, + experiment.key, + group.id + )) return experiment - self.logger.log(enums.LogLevels.INFO, - 'User with bucketing ID "%s" is not in any experiments of group %s.' % - (bucketing_id, group.id)) + self.logger.info('User with bucketing ID "%s" is not in any experiments of group %s.' % ( + bucketing_id, + group.id + )) return None @@ -285,10 +282,13 @@ def get_variation_for_feature(self, feature, user_id, attributes=None): variation = self.get_variation(experiment, user_id, attributes) if variation: - self.logger.log(enums.LogLevels.DEBUG, - 'User "%s" is in variation %s of experiment %s.' % (user_id, variation.key, experiment.key)) + self.logger.debug('User "%s" is in variation %s of experiment %s.' % ( + user_id, + variation.key, + experiment.key + )) else: - self.logger.log(enums.LogLevels.ERROR, enums.Errors.INVALID_GROUP_ID_ERROR.format('_get_variation_for_feature')) + self.logger.error(enums.Errors.INVALID_GROUP_ID_ERROR.format('_get_variation_for_feature')) # Next check if the feature is being experimented on elif feature.experimentIds: @@ -298,8 +298,11 @@ def get_variation_for_feature(self, feature, user_id, attributes=None): variation = self.get_variation(experiment, user_id, attributes) if variation: - self.logger.log(enums.LogLevels.DEBUG, - 'User "%s" is in variation %s of experiment %s.' % (user_id, variation.key, experiment.key)) + self.logger.debug('User "%s" is in variation %s of experiment %s.' % ( + user_id, + variation.key, + experiment.key + )) # Next check if user is part of a rollout if not variation and feature.rolloutId: diff --git a/optimizely/entities.py b/optimizely/entities.py index df5e76ca..c9d70d26 100644 --- a/optimizely/entities.py +++ b/optimizely/entities.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/optimizely/error_handler.py b/optimizely/error_handler.py index d3b70acd..452ac1d8 100644 --- a/optimizely/error_handler.py +++ b/optimizely/error_handler.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/optimizely/event_builder.py b/optimizely/event_builder.py index 1b944fd5..ad2aed41 100644 --- a/optimizely/event_builder.py +++ b/optimizely/event_builder.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/optimizely/event_dispatcher.py b/optimizely/event_dispatcher.py index ec873be5..f263c988 100644 --- a/optimizely/event_dispatcher.py +++ b/optimizely/event_dispatcher.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/optimizely/exceptions.py b/optimizely/exceptions.py index 6cadf0fb..dc7db6ad 100644 --- a/optimizely/exceptions.py +++ b/optimizely/exceptions.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/optimizely/helpers/__init__.py b/optimizely/helpers/__init__.py index cc653bcd..e0ed6ba3 100644 --- a/optimizely/helpers/__init__.py +++ b/optimizely/helpers/__init__.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/optimizely/helpers/audience.py b/optimizely/helpers/audience.py index 3c8040a8..b1c7a6b1 100644 --- a/optimizely/helpers/audience.py +++ b/optimizely/helpers/audience.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/optimizely/helpers/condition.py b/optimizely/helpers/condition.py index d55ff16e..37b669ec 100644 --- a/optimizely/helpers/condition.py +++ b/optimizely/helpers/condition.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/optimizely/helpers/constants.py b/optimizely/helpers/constants.py index 85df7252..a9cb3b97 100644 --- a/optimizely/helpers/constants.py +++ b/optimizely/helpers/constants.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/optimizely/helpers/enums.py b/optimizely/helpers/enums.py index 35cf2ab1..a8ff454a 100644 --- a/optimizely/helpers/enums.py +++ b/optimizely/helpers/enums.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/optimizely/helpers/event_tag_utils.py b/optimizely/helpers/event_tag_utils.py index 870bb918..3baf0406 100644 --- a/optimizely/helpers/event_tag_utils.py +++ b/optimizely/helpers/event_tag_utils.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/optimizely/helpers/experiment.py b/optimizely/helpers/experiment.py index 8768581e..6d1c21e0 100644 --- a/optimizely/helpers/experiment.py +++ b/optimizely/helpers/experiment.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/optimizely/helpers/validator.py b/optimizely/helpers/validator.py index 55f828f0..9c27418f 100644 --- a/optimizely/helpers/validator.py +++ b/optimizely/helpers/validator.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/optimizely/lib/__init__.py b/optimizely/lib/__init__.py index cc653bcd..e0ed6ba3 100644 --- a/optimizely/lib/__init__.py +++ b/optimizely/lib/__init__.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/optimizely/logger.py b/optimizely/logger.py index 9b2c333b..a1c483f3 100644 --- a/optimizely/logger.py +++ b/optimizely/logger.py @@ -4,42 +4,114 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. # See the License for the specific language governing permissions and # limitations under the License. - -import inspect import logging +import warnings from .helpers import enums +_DEFAULT_LOG_FORMAT = '%(levelname)-8s %(asctime)s %(filename)s:%(lineno)s:%(message)s' + + +def reset_logger(name, level=None, handler=None): + """ + Make a standard python logger object with default formatter, handler, etc. + + Defaults are: + - level == logging.INFO + - handler == logging.StreamHandler() + + Args: + name: a logger name. + level: an optional initial log level for this logger. + handler: an optional initial handler for this logger. + + Returns: a standard python logger with a single handler. + + """ + # Make the logger and set its level. + if level is None: + level = logging.INFO + logger = logging.getLogger(name) + logger.setLevel(level) + + # Make the handler and attach it. + handler = handler or logging.StreamHandler() + handler.setFormatter(logging.Formatter(_DEFAULT_LOG_FORMAT)) + + # We don't use ``.addHandler``, since this logger may have already been + # instantiated elsewhere with a different handler. It should only ever + # have one, not many. + logger.handlers = [handler] + return logger + + class BaseLogger(object): """ Class encapsulating logging functionality. Override with your own logger providing log method. """ @staticmethod def log(*args): - pass + pass # pragma: no cover class NoOpLogger(BaseLogger): """ Class providing log method which logs nothing. """ + def __init__(self): + self.logger = reset_logger( + name='.'.join([__name__, self.__class__.__name__]), + level=logging.NOTSET, + handler=logging.NullHandler() + ) class SimpleLogger(BaseLogger): """ Class providing log method which logs to stdout. """ def __init__(self, min_level=enums.LogLevels.INFO): - logging.basicConfig(level=min_level, - format='%(levelname)-8s %(asctime)s %(message)s') + self.level = min_level + self.logger = reset_logger( + name='.'.join([__name__, self.__class__.__name__]), + level=min_level + ) def log(self, log_level, message): - # Figure out calling method and format message to include that information before logging - caller = inspect.stack()[1][0] - info = inspect.getframeinfo(caller) - self.logger = logging.getLogger() - message = '%s:%s:%s' % (info.filename, info.lineno, message) + # Log a deprecation/runtime warning. + # Clients should be using standard loggers instead of this wrapper. + warning = '{} is deprecated. Please use standard python loggers.'.format( + self.__class__ + ) + warnings.warn(warning, DeprecationWarning) + + # Log the message. self.logger.log(log_level, message) + + +def adapt_logger(logger): + """ + Adapt our custom logger.BaseLogger object into a standard logging.Logger object. + + Adaptations are: + - NoOpLogger turns into a logger with a single NullHandler. + - SimpleLogger turns into a logger with a StreamHandler and level. + + Args: + logger: Possibly a logger.BaseLogger, or a standard python logging.Logger. + + Returns: a standard python logging.Logger. + + """ + if isinstance(logger, logging.Logger): + return logger + + # Use the standard python logger created by these classes. + if isinstance(logger, (SimpleLogger, NoOpLogger)): + return logger.logger + + # Otherwise, return a default logger instance. + return logger diff --git a/optimizely/notification_center.py b/optimizely/notification_center.py index c305e7d2..69ae8ce2 100644 --- a/optimizely/notification_center.py +++ b/optimizely/notification_center.py @@ -4,15 +4,15 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. # See the License for the specific language governing permissions and # limitations under the License. -import sys from functools import reduce + from .helpers import enums @@ -98,5 +98,4 @@ def send_notifications(self, notification_type, *args): try: callback(*args) except: - error = sys.exc_info()[1] - self.logger.log(enums.LogLevels.ERROR, 'Problem calling notify callback. Error: %s' % str(error)) + self.logger.exception('Problem calling notify callback!') diff --git a/optimizely/optimizely.py b/optimizely/optimizely.py index 1455c58f..a229422e 100644 --- a/optimizely/optimizely.py +++ b/optimizely/optimizely.py @@ -4,27 +4,24 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. # See the License for the specific language governing permissions and # limitations under the License. - -import numbers -import sys +import logging from . import decision_service from . import entities from . import event_builder from . import exceptions +from . import logger as _logging from . import project_config from .error_handler import NoOpErrorHandler as noop_error_handler from .event_dispatcher import EventDispatcher as default_event_dispatcher from .helpers import enums from .helpers import validator -from .logger import NoOpLogger as noop_logger -from .logger import SimpleLogger from .notification_center import NotificationCenter as notification_center @@ -50,18 +47,20 @@ def __init__(self, By default JSON schema validation will be performed. user_profile_service: Optional component which provides methods to store and manage user profiles. """ - + self.logger_name = '.'.join([__name__, self.__class__.__name__]) self.is_valid = True self.event_dispatcher = event_dispatcher or default_event_dispatcher - self.logger = logger or noop_logger + self.logger = _logging.adapt_logger(logger or _logging.NoOpLogger()) self.error_handler = error_handler or noop_error_handler try: self._validate_instantiation_options(datafile, skip_json_validation) except exceptions.InvalidInputException as error: self.is_valid = False - self.logger = SimpleLogger() - self.logger.log(enums.LogLevels.ERROR, str(error)) + # We actually want to log this error to stderr, so make sure the logger + # has a handler capable of doing that. + self.logger = _logging.reset_logger(self.logger_name) + self.logger.exception(str(error)) return try: @@ -69,14 +68,17 @@ def __init__(self, except: self.is_valid = False self.config = None - self.logger = SimpleLogger() - self.logger.log(enums.LogLevels.ERROR, enums.Errors.INVALID_INPUT_ERROR.format('datafile')) + # We actually want to log this error to stderr, so make sure the logger + # has a handler capable of doing that. + self.logger = _logging.reset_logger(self.logger_name) + self.logger.error(enums.Errors.INVALID_INPUT_ERROR.format('datafile')) return if not self.config.was_parsing_successful(): self.is_valid = False - self.logger = SimpleLogger() - self.logger.log(enums.LogLevels.ERROR, enums.Errors.UNSUPPORTED_DATAFILE_VERSION) + # We actually want to log this error to stderr, so make sure the logger + # has a handler capable of doing that. + self.logger.error(enums.Errors.UNSUPPORTED_DATAFILE_VERSION) return self.event_builder = event_builder.EventBuilder(self.config) @@ -119,12 +121,12 @@ def _validate_user_inputs(self, attributes=None, event_tags=None): """ if attributes and not validator.are_attributes_valid(attributes): - self.logger.log(enums.LogLevels.ERROR, 'Provided attributes are in an invalid format.') + self.logger.error('Provided attributes are in an invalid format.') self.error_handler.handle_error(exceptions.InvalidAttributeException(enums.Errors.INVALID_ATTRIBUTE_FORMAT)) return False if event_tags and not validator.are_event_tags_valid(event_tags): - self.logger.log(enums.LogLevels.ERROR, 'Provided event tags are in an invalid format.') + self.logger.error('Provided event tags are in an invalid format.') self.error_handler.handle_error(exceptions.InvalidEventTagException(enums.Errors.INVALID_EVENT_TAG_FORMAT)) return False @@ -147,7 +149,7 @@ def _get_decisions(self, event, user_id, attributes): variation_key = self.get_variation(experiment.key, user_id, attributes) if not variation_key: - self.logger.log(enums.LogLevels.INFO, 'Not tracking user "%s" for experiment "%s".' % (user_id, experiment.key)) + self.logger.info('Not tracking user "%s" for experiment "%s".' % (user_id, experiment.key)) continue variation = self.config.get_variation_from_key(experiment.key, variation_key) @@ -170,15 +172,15 @@ def _send_impression_event(self, experiment, variation, user_id, attributes): user_id, attributes) - self.logger.log(enums.LogLevels.DEBUG, - 'Dispatching impression event to URL %s with params %s.' % (impression_event.url, - impression_event.params)) + self.logger.debug('Dispatching impression event to URL %s with params %s.' % ( + impression_event.url, + impression_event.params + )) try: self.event_dispatcher.dispatch_event(impression_event) except: - error = sys.exc_info()[1] - self.logger.log(enums.LogLevels.ERROR, 'Unable to dispatch impression event. Error: %s' % str(error)) + self.logger.exception('Unable to dispatch impression event!') self.notification_center.send_notifications(enums.NotificationTypes.ACTIVATE, experiment, user_id, attributes, variation, impression_event) @@ -199,15 +201,15 @@ def _get_feature_variable_for_type(self, feature_key, variable_key, variable_typ - Mismatch with type of variable. """ if feature_key is None: - self.logger.log(enums.LogLevels.ERROR, enums.Errors.NONE_FEATURE_KEY_PARAMETER) + self.logger.error(enums.Errors.NONE_FEATURE_KEY_PARAMETER) return None if variable_key is None: - self.logger.log(enums.LogLevels.ERROR, enums.Errors.NONE_VARIABLE_KEY_PARAMETER) + self.logger.error(enums.Errors.NONE_VARIABLE_KEY_PARAMETER) return None if user_id is None: - self.logger.log(enums.LogLevels.ERROR, enums.Errors.NONE_USER_ID_PARAMETER) + self.logger.error(enums.Errors.NONE_USER_ID_PARAMETER) return None feature_flag = self.config.get_feature_from_key(feature_key) @@ -220,8 +222,7 @@ def _get_feature_variable_for_type(self, feature_key, variable_key, variable_typ # Return None if type differs if variable.type != variable_type: - self.logger.log( - enums.LogLevels.WARNING, + self.logger.warning( 'Requested variable type "%s", but variable is of type "%s". ' 'Use correct API to retrieve value. Returning None.' % (variable_type, variable.type) ) @@ -233,8 +234,7 @@ def _get_feature_variable_for_type(self, feature_key, variable_key, variable_typ else: variable_value = variable.defaultValue - self.logger.log( - enums.LogLevels.INFO, + self.logger.info( 'User "%s" is not in any variation or rollout rule. ' 'Returning default value for variable "%s" of feature flag "%s".' % (user_id, variable_key, feature_key) ) @@ -242,7 +242,7 @@ def _get_feature_variable_for_type(self, feature_key, variable_key, variable_typ try: actual_value = self.config.get_typecast_value(variable_value, variable_type) except: - self.logger.log(enums.LogLevels.ERROR, 'Unable to cast value. Returning None.') + self.logger.error('Unable to cast value. Returning None.') actual_value = None return actual_value @@ -261,20 +261,20 @@ def activate(self, experiment_key, user_id, attributes=None): """ if not self.is_valid: - self.logger.log(enums.LogLevels.ERROR, enums.Errors.INVALID_DATAFILE.format('activate')) + self.logger.error(enums.Errors.INVALID_DATAFILE.format('activate')) return None variation_key = self.get_variation(experiment_key, user_id, attributes) if not variation_key: - self.logger.log(enums.LogLevels.INFO, 'Not activating user "%s".' % user_id) + self.logger.info('Not activating user "%s".' % user_id) return None experiment = self.config.get_experiment_from_key(experiment_key) variation = self.config.get_variation_from_key(experiment_key, variation_key) # Create and dispatch impression event - self.logger.log(enums.LogLevels.INFO, 'Activating user "%s" in experiment "%s".' % (user_id, experiment.key)) + self.logger.info('Activating user "%s" in experiment "%s".' % (user_id, experiment.key)) self._send_impression_event(experiment, variation, user_id, attributes) return variation.key @@ -290,7 +290,7 @@ def track(self, event_key, user_id, attributes=None, event_tags=None): """ if not self.is_valid: - self.logger.log(enums.LogLevels.ERROR, enums.Errors.INVALID_DATAFILE.format('track')) + self.logger.error(enums.Errors.INVALID_DATAFILE.format('track')) return if not self._validate_user_inputs(attributes, event_tags): @@ -298,7 +298,7 @@ def track(self, event_key, user_id, attributes=None, event_tags=None): event = self.config.get_event(event_key) if not event: - self.logger.log(enums.LogLevels.INFO, 'Not tracking user "%s" for event "%s".' % (user_id, event_key)) + self.logger.info('Not tracking user "%s" for event "%s".' % (user_id, event_key)) return # Filter out experiments that are not running or that do not include the user in audience @@ -310,19 +310,19 @@ def track(self, event_key, user_id, attributes=None, event_tags=None): conversion_event = self.event_builder.create_conversion_event( event_key, user_id, attributes, event_tags, decisions ) - self.logger.log(enums.LogLevels.INFO, 'Tracking event "%s" for user "%s".' % (event_key, user_id)) - self.logger.log(enums.LogLevels.DEBUG, - 'Dispatching conversion event to URL %s with params %s.' % (conversion_event.url, - conversion_event.params)) + self.logger.info('Tracking event "%s" for user "%s".' % (event_key, user_id)) + self.logger.debug('Dispatching conversion event to URL %s with params %s.' % ( + conversion_event.url, + conversion_event.params + )) try: self.event_dispatcher.dispatch_event(conversion_event) except: - error = sys.exc_info()[1] - self.logger.log(enums.LogLevels.ERROR, 'Unable to dispatch conversion event. Error: %s' % str(error)) + self.logger.exception('Unable to dispatch conversion event!') self.notification_center.send_notifications(enums.NotificationTypes.TRACK, event_key, user_id, attributes, event_tags, conversion_event) else: - self.logger.log(enums.LogLevels.INFO, 'There are no valid experiments for event "%s" to track.' % event_key) + self.logger.info('There are no valid experiments for event "%s" to track.' % event_key) def get_variation(self, experiment_key, user_id, attributes=None): """ Gets variation where user will be bucketed. @@ -338,15 +338,16 @@ def get_variation(self, experiment_key, user_id, attributes=None): """ if not self.is_valid: - self.logger.log(enums.LogLevels.ERROR, enums.Errors.INVALID_DATAFILE.format('get_variation')) + self.logger.error(enums.Errors.INVALID_DATAFILE.format('get_variation')) return None experiment = self.config.get_experiment_from_key(experiment_key) if not experiment: - self.logger.log(enums.LogLevels.INFO, - 'Experiment key "%s" is invalid. Not activating user "%s".' % (experiment_key, - user_id)) + self.logger.info('Experiment key "%s" is invalid. Not activating user "%s".' % ( + experiment_key, + user_id + )) return None if not self._validate_user_inputs(attributes): @@ -371,15 +372,15 @@ def is_feature_enabled(self, feature_key, user_id, attributes=None): """ if not self.is_valid: - self.logger.log(enums.LogLevels.ERROR, enums.Errors.INVALID_DATAFILE.format('is_feature_enabled')) + self.logger.error(enums.Errors.INVALID_DATAFILE.format('is_feature_enabled')) return False if feature_key is None: - self.logger.log(enums.LogLevels.ERROR, enums.Errors.NONE_FEATURE_KEY_PARAMETER) + self.logger.error(enums.Errors.NONE_FEATURE_KEY_PARAMETER) return False if user_id is None: - self.logger.log(enums.LogLevels.ERROR, enums.Errors.NONE_USER_ID_PARAMETER) + self.logger.error(enums.Errors.NONE_USER_ID_PARAMETER) return False feature = self.config.get_feature_from_key(feature_key) @@ -388,7 +389,7 @@ def is_feature_enabled(self, feature_key, user_id, attributes=None): decision = self.decision_service.get_variation_for_feature(feature, user_id, attributes) if decision.variation and decision.variation.featureEnabled: - self.logger.log(enums.LogLevels.INFO, 'Feature "%s" is enabled for user "%s".' % (feature_key, user_id)) + self.logger.info('Feature "%s" is enabled for user "%s".' % (feature_key, user_id)) # Send event if Decision came from an experiment. if decision.source == decision_service.DECISION_SOURCE_EXPERIMENT: self._send_impression_event(decision.experiment, @@ -398,7 +399,7 @@ def is_feature_enabled(self, feature_key, user_id, attributes=None): return True - self.logger.log(enums.LogLevels.INFO, 'Feature "%s" is not enabled for user "%s".' % (feature_key, user_id)) + self.logger.info('Feature "%s" is not enabled for user "%s".' % (feature_key, user_id)) return False def get_enabled_features(self, user_id, attributes=None): @@ -414,7 +415,7 @@ def get_enabled_features(self, user_id, attributes=None): enabled_features = [] if not self.is_valid: - self.logger.log(enums.LogLevels.ERROR, enums.Errors.INVALID_DATAFILE.format('get_enabled_features')) + self.logger.error(enums.Errors.INVALID_DATAFILE.format('get_enabled_features')) return enabled_features for feature in self.config.feature_key_map.values(): diff --git a/optimizely/project_config.py b/optimizely/project_config.py index 77da812c..53c8a0d3 100644 --- a/optimizely/project_config.py +++ b/optimizely/project_config.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. @@ -236,7 +236,7 @@ def get_experiment_from_key(self, experiment_key): if experiment: return experiment - self.logger.log(enums.LogLevels.ERROR, 'Experiment key "%s" is not in datafile.' % experiment_key) + self.logger.error('Experiment key "%s" is not in datafile.' % experiment_key) self.error_handler.handle_error(exceptions.InvalidExperimentException(enums.Errors.INVALID_EXPERIMENT_KEY_ERROR)) return None @@ -255,7 +255,7 @@ def get_experiment_from_id(self, experiment_id): if experiment: return experiment - self.logger.log(enums.LogLevels.ERROR, 'Experiment ID "%s" is not in datafile.' % experiment_id) + self.logger.error('Experiment ID "%s" is not in datafile.' % experiment_id) self.error_handler.handle_error(exceptions.InvalidExperimentException(enums.Errors.INVALID_EXPERIMENT_KEY_ERROR)) return None @@ -274,7 +274,7 @@ def get_group(self, group_id): if group: return group - self.logger.log(enums.LogLevels.ERROR, 'Group ID "%s" is not in datafile.' % group_id) + self.logger.error('Group ID "%s" is not in datafile.' % group_id) self.error_handler.handle_error(exceptions.InvalidGroupException(enums.Errors.INVALID_GROUP_ID_ERROR)) return None @@ -292,7 +292,7 @@ def get_audience(self, audience_id): if audience: return audience - self.logger.log(enums.LogLevels.ERROR, 'Audience ID "%s" is not in datafile.' % audience_id) + self.logger.error('Audience ID "%s" is not in datafile.' % audience_id) self.error_handler.handle_error(exceptions.InvalidAudienceException((enums.Errors.INVALID_AUDIENCE_ERROR))) def get_variation_from_key(self, experiment_key, variation_key): @@ -313,11 +313,11 @@ def get_variation_from_key(self, experiment_key, variation_key): if variation: return variation else: - self.logger.log(enums.LogLevels.ERROR, 'Variation key "%s" is not in datafile.' % variation_key) + self.logger.error('Variation key "%s" is not in datafile.' % variation_key) self.error_handler.handle_error(exceptions.InvalidVariationException(enums.Errors.INVALID_VARIATION_ERROR)) return None - self.logger.log(enums.LogLevels.ERROR, 'Experiment key "%s" is not in datafile.' % experiment_key) + self.logger.error('Experiment key "%s" is not in datafile.' % experiment_key) self.error_handler.handle_error(exceptions.InvalidExperimentException(enums.Errors.INVALID_EXPERIMENT_KEY_ERROR)) return None @@ -339,11 +339,11 @@ def get_variation_from_id(self, experiment_key, variation_id): if variation: return variation else: - self.logger.log(enums.LogLevels.ERROR, 'Variation ID "%s" is not in datafile.' % variation_id) + self.logger.error('Variation ID "%s" is not in datafile.' % variation_id) self.error_handler.handle_error(exceptions.InvalidVariationException(enums.Errors.INVALID_VARIATION_ERROR)) return None - self.logger.log(enums.LogLevels.ERROR, 'Experiment key "%s" is not in datafile.' % experiment_key) + self.logger.error('Experiment key "%s" is not in datafile.' % experiment_key) self.error_handler.handle_error(exceptions.InvalidExperimentException(enums.Errors.INVALID_EXPERIMENT_KEY_ERROR)) return None @@ -362,7 +362,7 @@ def get_event(self, event_key): if event: return event - self.logger.log(enums.LogLevels.ERROR, 'Event "%s" is not in datafile.' % event_key) + self.logger.error('Event "%s" is not in datafile.' % event_key) self.error_handler.handle_error(exceptions.InvalidEventException(enums.Errors.INVALID_EVENT_KEY_ERROR)) return None @@ -381,16 +381,15 @@ def get_attribute_id(self, attribute_key): if attribute: if has_reserved_prefix: - self.logger.log(enums.LogLevels.WARNING, - ('Attribute %s unexpectedly has reserved prefix %s; using attribute ID ' - 'instead of reserved attribute name.' % (attribute_key, RESERVED_ATTRIBUTE_PREFIX))) + self.logger.warning(('Attribute %s unexpectedly has reserved prefix %s; using attribute ID ' + 'instead of reserved attribute name.' % (attribute_key, RESERVED_ATTRIBUTE_PREFIX))) return attribute.id if has_reserved_prefix and attribute_key != enums.ControlAttributes.BOT_FILTERING: return attribute_key - self.logger.log(enums.LogLevels.ERROR, 'Attribute "%s" is not in datafile.' % attribute_key) + self.logger.error('Attribute "%s" is not in datafile.' % attribute_key) self.error_handler.handle_error(exceptions.InvalidAttributeException(enums.Errors.INVALID_ATTRIBUTE_ERROR)) return None @@ -408,7 +407,7 @@ def get_feature_from_key(self, feature_key): if feature: return feature - self.logger.log(enums.LogLevels.ERROR, 'Feature "%s" is not in datafile.' % feature_key) + self.logger.error('Feature "%s" is not in datafile.' % feature_key) return None def get_rollout_from_id(self, rollout_id): @@ -425,7 +424,7 @@ def get_rollout_from_id(self, rollout_id): if layer: return layer - self.logger.log(enums.LogLevels.ERROR, 'Rollout with ID "%s" is not in datafile.' % rollout_id) + self.logger.error('Rollout with ID "%s" is not in datafile.' % rollout_id) return None def get_variable_value_for_variation(self, variable, variation): @@ -443,7 +442,7 @@ def get_variable_value_for_variation(self, variable, variation): return None if variation.id not in self.variation_variable_usage_map: - self.logger.log(enums.LogLevels.ERROR, 'Variation with ID "%s" is not in the datafile.' % variation.id) + self.logger.error('Variation with ID "%s" is not in the datafile.' % variation.id) return None # Get all variable usages for the given variation @@ -456,19 +455,19 @@ def get_variable_value_for_variation(self, variable, variation): if variable_usage: variable_value = variable_usage.value - self.logger.log( - enums.LogLevels.INFO, - 'Value for variable "%s" for variation "%s" is "%s".' % ( - variable.key, variation.key, variable_value - )) + self.logger.info('Value for variable "%s" for variation "%s" is "%s".' % ( + variable.key, + variation.key, + variable_value + )) else: variable_value = variable.defaultValue - self.logger.log( - enums.LogLevels.INFO, - 'Variable "%s" is not used in variation "%s". Assinging default value "%s".' % ( - variable.key, variation.key, variable_value - )) + self.logger.info('Variable "%s" is not used in variation "%s". Assigning default value "%s".' % ( + variable.key, + variation.key, + variable_value + )) return variable_value @@ -484,11 +483,11 @@ def get_variable_for_feature(self, feature_key, variable_key): """ feature = self.feature_key_map.get(feature_key) if not feature: - self.logger.log(enums.LogLevels.ERROR, 'Feature with key "%s" not found in the datafile.' % feature_key) + self.logger.error('Feature with key "%s" not found in the datafile.' % feature_key) return None if variable_key not in feature.variables: - self.logger.log(enums.LogLevels.ERROR, 'Variable with key "%s" not found in the datafile.' % variable_key) + self.logger.error('Variable with key "%s" not found in the datafile.' % variable_key) return None return feature.variables.get(variable_key) @@ -505,7 +504,7 @@ def set_forced_variation(self, experiment_key, user_id, variation_key): A boolean value that indicates if the set completed successfully. """ if not user_id: - self.logger.log(enums.LogLevels.DEBUG, 'User ID is invalid.') + self.logger.debug('User ID is invalid.') return False experiment = self.get_experiment_from_key(experiment_key) @@ -519,16 +518,17 @@ def set_forced_variation(self, experiment_key, user_id, variation_key): experiment_to_variation_map = self.forced_variation_map.get(user_id) if experiment_id in experiment_to_variation_map: del(self.forced_variation_map[user_id][experiment_id]) - self.logger.log(enums.LogLevels.DEBUG, - 'Variation mapped to experiment "%s" has been removed for user "%s".' - % (experiment_key, user_id)) + self.logger.debug('Variation mapped to experiment "%s" has been removed for user "%s".' % ( + experiment_key, + user_id + )) else: - self.logger.log(enums.LogLevels.DEBUG, - 'Nothing to remove. Variation mapped to experiment "%s" for user "%s" does not exist.' - % (experiment_key, user_id)) + self.logger.debug('Nothing to remove. Variation mapped to experiment "%s" for user "%s" does not exist.' % ( + experiment_key, + user_id + )) else: - self.logger.log(enums.LogLevels.DEBUG, - 'Nothing to remove. User "%s" does not exist in the forced variation map.' % user_id) + self.logger.debug('Nothing to remove. User "%s" does not exist in the forced variation map.' % user_id) return True forced_variation = self.get_variation_from_key(experiment_key, variation_key) @@ -543,9 +543,11 @@ def set_forced_variation(self, experiment_key, user_id, variation_key): else: self.forced_variation_map[user_id][experiment_id] = variation_id - self.logger.log(enums.LogLevels.DEBUG, - 'Set variation "%s" for experiment "%s" and user "%s" in the forced variation map.' - % (variation_id, experiment_id, user_id)) + self.logger.debug('Set variation "%s" for experiment "%s" and user "%s" in the forced variation map.' % ( + variation_id, + experiment_id, + user_id + )) return True def get_forced_variation(self, experiment_key, user_id): @@ -559,11 +561,11 @@ def get_forced_variation(self, experiment_key, user_id): The variation which the given user and experiment should be forced into. """ if not user_id: - self.logger.log(enums.LogLevels.DEBUG, 'User ID is invalid.') + self.logger.debug('User ID is invalid.') return None if user_id not in self.forced_variation_map: - self.logger.log(enums.LogLevels.DEBUG, 'User "%s" is not in the forced variation map.' % user_id) + self.logger.debug('User "%s" is not in the forced variation map.' % user_id) return None experiment = self.get_experiment_from_key(experiment_key) @@ -574,23 +576,26 @@ def get_forced_variation(self, experiment_key, user_id): experiment_to_variation_map = self.forced_variation_map.get(user_id) if not experiment_to_variation_map: - self.logger.log(enums.LogLevels.DEBUG, - 'No experiment "%s" mapped to user "%s" in the forced variation map.' - % (experiment_key, user_id)) + self.logger.debug('No experiment "%s" mapped to user "%s" in the forced variation map.' % ( + experiment_key, + user_id + )) return None variation_id = experiment_to_variation_map.get(experiment.id) if variation_id is None: - self.logger.log(enums.LogLevels.DEBUG, - 'No variation mapped to experiment "%s" in the forced variation map.' - % experiment_key) + self.logger.debug( + 'No variation mapped to experiment "%s" in the forced variation map.' % experiment_key + ) return None variation = self.get_variation_from_id(experiment_key, variation_id) - self.logger.log(enums.LogLevels.DEBUG, - 'Variation "%s" is mapped to experiment "%s" and user "%s" in the forced variation map' - % (variation.key, experiment_key, user_id)) + self.logger.debug('Variation "%s" is mapped to experiment "%s" and user "%s" in the forced variation map' % ( + variation.key, + experiment_key, + user_id + )) return variation def get_anonymize_ip_value(self): diff --git a/optimizely/user_profile.py b/optimizely/user_profile.py index 572ea823..67452dd4 100644 --- a/optimizely/user_profile.py +++ b/optimizely/user_profile.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/optimizely/version.py b/optimizely/version.py index 206688f0..90e0d1d7 100644 --- a/optimizely/version.py +++ b/optimizely/version.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/setup.py b/setup.py index 78808133..54907c11 100644 --- a/setup.py +++ b/setup.py @@ -39,6 +39,7 @@ packages=find_packages( exclude=['tests'] ), + extras_require={'test': TEST_REQUIREMENTS}, install_requires=REQUIREMENTS, tests_require=TEST_REQUIREMENTS, test_suite='tests' diff --git a/tests/__init__.py b/tests/__init__.py index cc653bcd..e0ed6ba3 100644 --- a/tests/__init__.py +++ b/tests/__init__.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/tests/base.py b/tests/base.py index 9f3d285b..72b78c7a 100644 --- a/tests/base.py +++ b/tests/base.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. @@ -14,12 +14,7 @@ import json import unittest - -from optimizely import error_handler -from optimizely import event_builder -from optimizely import logger from optimizely import optimizely -from optimizely import project_config class BaseTest(unittest.TestCase): diff --git a/tests/benchmarking/benchmarking_tests.py b/tests/benchmarking/benchmarking_tests.py index 16817a25..97fdddbe 100644 --- a/tests/benchmarking/benchmarking_tests.py +++ b/tests/benchmarking/benchmarking_tests.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/tests/benchmarking/data.py b/tests/benchmarking/data.py index 59facc06..4bd16a25 100644 --- a/tests/benchmarking/data.py +++ b/tests/benchmarking/data.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/tests/helpers_tests/__init__.py b/tests/helpers_tests/__init__.py index cc653bcd..e0ed6ba3 100644 --- a/tests/helpers_tests/__init__.py +++ b/tests/helpers_tests/__init__.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/tests/helpers_tests/test_audience.py b/tests/helpers_tests/test_audience.py index 0453b1c3..6302ad8a 100644 --- a/tests/helpers_tests/test_audience.py +++ b/tests/helpers_tests/test_audience.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/tests/helpers_tests/test_condition.py b/tests/helpers_tests/test_condition.py index e863d41b..828b33cb 100644 --- a/tests/helpers_tests/test_condition.py +++ b/tests/helpers_tests/test_condition.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/tests/helpers_tests/test_event_tag_utils.py b/tests/helpers_tests/test_event_tag_utils.py index ada654e0..878a8d24 100644 --- a/tests/helpers_tests/test_event_tag_utils.py +++ b/tests/helpers_tests/test_event_tag_utils.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/tests/helpers_tests/test_experiment.py b/tests/helpers_tests/test_experiment.py index eb951854..fd46f3b4 100644 --- a/tests/helpers_tests/test_experiment.py +++ b/tests/helpers_tests/test_experiment.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/tests/helpers_tests/test_validator.py b/tests/helpers_tests/test_validator.py index 3f7da189..4c833d95 100644 --- a/tests/helpers_tests/test_validator.py +++ b/tests/helpers_tests/test_validator.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/tests/test_bucketing.py b/tests/test_bucketing.py index 0db43d3c..4895ad14 100644 --- a/tests/test_bucketing.py +++ b/tests/test_bucketing.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. @@ -165,61 +165,49 @@ def test_bucket(self): # Variation 1 with mock.patch('optimizely.bucketer.Bucketer._generate_bucket_value', return_value=42),\ - mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + mock.patch.object(self.bucketer.config, 'logger') as mock_config_logging: self.assertEqual(entities.Variation('111128', 'control'), self.bucketer.bucket(self.project_config.get_experiment_from_key('test_experiment'), 'test_user', 'test_user')) - self.assertEqual(2, mock_logging.call_count) - self.assertEqual(mock.call(enums.LogLevels.DEBUG, 'Assigned bucket 42 to user with bucketing ID "test_user".'), - mock_logging.call_args_list[0]) - self.assertEqual( - mock.call(enums.LogLevels.INFO, 'User "test_user" is in variation "control" of experiment test_experiment.'), - mock_logging.call_args_list[1] + mock_config_logging.debug.assert_called_once_with('Assigned bucket 42 to user with bucketing ID "test_user".') + mock_config_logging.info.assert_called_once_with( + 'User "test_user" is in variation "control" of experiment test_experiment.' ) # Empty entity ID with mock.patch('optimizely.bucketer.Bucketer._generate_bucket_value', return_value=4242), \ - mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + mock.patch.object(self.bucketer.config, 'logger') as mock_config_logging: self.assertIsNone(self.bucketer.bucket( self.project_config.get_experiment_from_key('test_experiment'), 'test_user', 'test_user' )) - self.assertEqual(2, mock_logging.call_count) - self.assertEqual(mock.call(enums.LogLevels.DEBUG, 'Assigned bucket 4242 to user with bucketing ID "test_user".'), - mock_logging.call_args_list[0]) - self.assertEqual( - mock.call(enums.LogLevels.INFO, 'User "test_user" is in no variation.'), - mock_logging.call_args_list[1] - ) + mock_config_logging.debug.assert_called_once_with('Assigned bucket 4242 to user with bucketing ID "test_user".') + mock_config_logging.info.assert_called_once_with('User "test_user" is in no variation.') # Variation 2 with mock.patch('optimizely.bucketer.Bucketer._generate_bucket_value', return_value=5042),\ - mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + mock.patch.object(self.bucketer.config, 'logger') as mock_config_logging: self.assertEqual(entities.Variation('111129', 'variation'), self.bucketer.bucket(self.project_config.get_experiment_from_key('test_experiment'), 'test_user', 'test_user')) - self.assertEqual(2, mock_logging.call_count) - self.assertEqual(mock.call(enums.LogLevels.DEBUG, 'Assigned bucket 5042 to user with bucketing ID "test_user".'), - mock_logging.call_args_list[0]) - self.assertEqual( - mock.call(enums.LogLevels.INFO, 'User "test_user" is in variation "variation" of experiment test_experiment.'), - mock_logging.call_args_list[1] + + mock_config_logging.debug.assert_called_once_with('Assigned bucket 5042 to user with bucketing ID "test_user".') + mock_config_logging.info.assert_called_once_with( + 'User "test_user" is in variation "variation" of experiment test_experiment.' ) # No matching variation with mock.patch('optimizely.bucketer.Bucketer._generate_bucket_value', return_value=424242),\ - mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + mock.patch.object(self.bucketer.config, 'logger') as mock_config_logging: self.assertIsNone(self.bucketer.bucket(self.project_config.get_experiment_from_key('test_experiment'), 'test_user', 'test_user')) - self.assertEqual(2, mock_logging.call_count) - self.assertEqual(mock.call(enums.LogLevels.DEBUG, 'Assigned bucket 424242 to user with bucketing ID "test_user".'), - mock_logging.call_args_list[0]) - self.assertEqual(mock.call(enums.LogLevels.INFO, 'User "test_user" is in no variation.'), - mock_logging.call_args_list[1]) + + mock_config_logging.debug.assert_called_once_with('Assigned bucket 424242 to user with bucketing ID "test_user".') + mock_config_logging.info.assert_called_once_with('User "test_user" is in no variation.') def test_bucket__experiment_in_group(self): """ Test that for provided bucket values correct variation ID is returned. """ @@ -227,81 +215,74 @@ def test_bucket__experiment_in_group(self): # In group, matching experiment and variation with mock.patch('optimizely.bucketer.Bucketer._generate_bucket_value', side_effect=[42, 4242]),\ - mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: - self.assertEqual(entities.Variation('28902', 'group_exp_1_variation'), - self.bucketer.bucket(self.project_config.get_experiment_from_key('group_exp_1'), - 'test_user', - 'test_user')) - self.assertEqual(4, mock_logging.call_count) - self.assertEqual(mock.call(enums.LogLevels.DEBUG, 'Assigned bucket 42 to user with bucketing ID "test_user".'), - mock_logging.call_args_list[0]) - self.assertEqual(mock.call(enums.LogLevels.INFO, 'User "test_user" is in experiment group_exp_1 of group 19228.'), - mock_logging.call_args_list[1]) - self.assertEqual(mock.call(enums.LogLevels.DEBUG, 'Assigned bucket 4242 to user with bucketing ID "test_user".'), - mock_logging.call_args_list[2]) - self.assertEqual( - mock.call(enums.LogLevels.INFO, - 'User "test_user" is in variation "group_exp_1_variation" of experiment group_exp_1.'), - mock_logging.call_args_list[3] - ) + mock.patch.object(self.bucketer.config, 'logger') as mock_config_logging: + self.assertEqual( + entities.Variation('28902', 'group_exp_1_variation'), + self.bucketer.bucket( + self.project_config.get_experiment_from_key('group_exp_1'), + 'test_user', + 'test_user' + ) + ) + mock_config_logging.debug.assert_has_calls([ + mock.call('Assigned bucket 42 to user with bucketing ID "test_user".'), + mock.call('Assigned bucket 4242 to user with bucketing ID "test_user".') + ]) + mock_config_logging.info.assert_has_calls([ + mock.call('User "test_user" is in experiment group_exp_1 of group 19228.'), + mock.call('User "test_user" is in variation "group_exp_1_variation" of experiment group_exp_1.') + ]) # In group, but in no experiment with mock.patch('optimizely.bucketer.Bucketer._generate_bucket_value', side_effect=[8400, 9500]),\ - mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + mock.patch.object(self.bucketer.config, 'logger') as mock_config_logging: self.assertIsNone(self.bucketer.bucket(self.project_config.get_experiment_from_key('group_exp_1'), 'test_user', 'test_user')) - self.assertEqual(2, mock_logging.call_count) - self.assertEqual(mock.call(enums.LogLevels.DEBUG, 'Assigned bucket 8400 to user with bucketing ID "test_user".'), - mock_logging.call_args_list[0]) - self.assertEqual(mock.call(enums.LogLevels.INFO, 'User "test_user" is in no experiment.'), - mock_logging.call_args_list[1]) + mock_config_logging.debug.assert_called_once_with('Assigned bucket 8400 to user with bucketing ID "test_user".') + mock_config_logging.info.assert_called_once_with('User "test_user" is in no experiment.') # In group, no matching experiment with mock.patch('optimizely.bucketer.Bucketer._generate_bucket_value', side_effect=[42, 9500]),\ - mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + mock.patch.object(self.bucketer.config, 'logger') as mock_config_logging: self.assertIsNone(self.bucketer.bucket( self.project_config.get_experiment_from_key('group_exp_1'), 'test_user', 'test_user')) - self.assertEqual(4, mock_logging.call_count) - self.assertEqual(mock.call(enums.LogLevels.DEBUG, 'Assigned bucket 42 to user with bucketing ID "test_user".'), - mock_logging.call_args_list[0]) - self.assertEqual(mock.call(enums.LogLevels.INFO, 'User "test_user" is in experiment group_exp_1 of group 19228.'), - mock_logging.call_args_list[1]) - self.assertEqual(mock.call(enums.LogLevels.DEBUG, 'Assigned bucket 9500 to user with bucketing ID "test_user".'), - mock_logging.call_args_list[2]) - self.assertEqual(mock.call(enums.LogLevels.INFO, 'User "test_user" is in no variation.'), - mock_logging.call_args_list[3]) + mock_config_logging.debug.assert_has_calls([ + mock.call('Assigned bucket 42 to user with bucketing ID "test_user".'), + mock.call('Assigned bucket 9500 to user with bucketing ID "test_user".') + ]) + mock_config_logging.info.assert_has_calls([ + mock.call('User "test_user" is in experiment group_exp_1 of group 19228.'), + mock.call('User "test_user" is in no variation.') + ]) # In group, experiment does not match with mock.patch('optimizely.bucketer.Bucketer._generate_bucket_value', side_effect=[42, 4242]),\ - mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + mock.patch.object(self.bucketer.config, 'logger') as mock_config_logging: self.assertIsNone(self.bucketer.bucket(self.project_config.get_experiment_from_key('group_exp_2'), 'test_user', 'test_user')) - self.assertEqual(2, mock_logging.call_count) - self.assertEqual(mock.call(enums.LogLevels.DEBUG, 'Assigned bucket 42 to user with bucketing ID "test_user".'), - mock_logging.call_args_list[0]) - self.assertEqual( - mock.call(enums.LogLevels.INFO, 'User "test_user" is not in experiment "group_exp_2" of group 19228.'), - mock_logging.call_args_list[1] + mock_config_logging.debug.assert_called_once_with('Assigned bucket 42 to user with bucketing ID "test_user".') + mock_config_logging.info.assert_called_once_with( + 'User "test_user" is not in experiment "group_exp_2" of group 19228.' ) # In group no matching variation with mock.patch('optimizely.bucketer.Bucketer._generate_bucket_value', side_effect=[42, 424242]),\ - mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + mock.patch.object(self.bucketer.config, 'logger') as mock_config_logging: self.assertIsNone(self.bucketer.bucket(self.project_config.get_experiment_from_key('group_exp_1'), 'test_user', 'test_user')) - self.assertEqual(4, mock_logging.call_count) - self.assertEqual(mock.call(enums.LogLevels.DEBUG, 'Assigned bucket 42 to user with bucketing ID "test_user".'), - mock_logging.call_args_list[0]) - self.assertEqual(mock.call(enums.LogLevels.INFO, 'User "test_user" is in experiment group_exp_1 of group 19228.'), - mock_logging.call_args_list[1]) - self.assertEqual(mock.call(enums.LogLevels.DEBUG, 'Assigned bucket 424242 to user with bucketing ID "test_user".'), - mock_logging.call_args_list[2]) - self.assertEqual(mock.call(enums.LogLevels.INFO, 'User "test_user" is in no variation.'), - mock_logging.call_args_list[3]) + + mock_config_logging.debug.assert_has_calls([ + mock.call('Assigned bucket 42 to user with bucketing ID "test_user".'), + mock.call('Assigned bucket 424242 to user with bucketing ID "test_user".') + ]) + mock_config_logging.info.assert_has_calls([ + mock.call('User "test_user" is in experiment group_exp_1 of group 19228.'), + mock.call('User "test_user" is in no variation.') + ]) diff --git a/tests/test_config.py b/tests/test_config.py index cc5b9d00..d1b5e0b0 100644 --- a/tests/test_config.py +++ b/tests/test_config.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. @@ -923,10 +923,10 @@ def test_get_rollout_from_id__invalid_rollout_id(self): opt_obj = optimizely.Optimizely(json.dumps(self.config_dict_with_features), logger=logger.NoOpLogger()) project_config = opt_obj.config - with mock.patch('optimizely.logger.NoOpLogger.log') as mock_logging: + with mock.patch.object(project_config, 'logger') as mock_config_logging: self.assertIsNone(project_config.get_rollout_from_id('aabbccdd')) - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Rollout with ID "aabbccdd" is not in datafile.') + mock_config_logging.error.assert_called_once_with('Rollout with ID "aabbccdd" is not in datafile.') def test_get_variable_value_for_variation__returns_valid_value(self): """ Test that the right value is returned. """ @@ -1017,11 +1017,11 @@ def test_get_forced_variation_with_none_set_for_user(self): self.project_config.forced_variation_map = {} self.project_config.forced_variation_map['test_user'] = {} - with mock.patch('optimizely.logger.NoOpLogger.log') as mock_logging: + with mock.patch.object(self.project_config, 'logger') as mock_config_logging: self.assertIsNone(self.project_config.get_forced_variation('test_experiment', 'test_user')) - mock_logging.assert_called_once_with( - enums.LogLevels.DEBUG, - 'No experiment "test_experiment" mapped to user "test_user" in the forced variation map.') + mock_config_logging.debug.assert_called_once_with( + 'No experiment "test_experiment" mapped to user "test_user" in the forced variation map.' + ) def test_get_forced_variation_missing_variation_mapped_to_experiment(self): """ Test get_forced_variation when no variation found against given experiment for the user. """ @@ -1029,11 +1029,12 @@ def test_get_forced_variation_missing_variation_mapped_to_experiment(self): self.project_config.forced_variation_map['test_user'] = {} self.project_config.forced_variation_map['test_user']['test_experiment'] = None - with mock.patch('optimizely.logger.NoOpLogger.log') as mock_logging: + with mock.patch.object(self.project_config, 'logger') as mock_config_logging: self.assertIsNone(self.project_config.get_forced_variation('test_experiment', 'test_user')) - mock_logging.assert_called_once_with( - enums.LogLevels.DEBUG, - 'No variation mapped to experiment "test_experiment" in the forced variation map.') + + mock_config_logging.debug.assert_called_once_with( + 'No variation mapped to experiment "test_experiment" in the forced variation map.' + ) # set_forced_variation tests def test_set_forced_variation__invalid_user_id(self): @@ -1087,21 +1088,21 @@ def test_set_forced_variation_when_called_to_remove_forced_variation(self): self.project_config.forced_variation_map = {} self.project_config.set_forced_variation('test_experiment', 'test_user', 'variation') - with mock.patch('optimizely.logger.NoOpLogger.log') as mock_logging: + with mock.patch.object(self.project_config, 'logger') as mock_config_logging: self.assertTrue(self.project_config.set_forced_variation('test_experiment', 'test_user', None)) - mock_logging.assert_called_once_with( - enums.LogLevels.DEBUG, - 'Variation mapped to experiment "test_experiment" has been removed for user "test_user".') + mock_config_logging.debug.assert_called_once_with( + 'Variation mapped to experiment "test_experiment" has been removed for user "test_user".' + ) # Test case where user is present in the forced variation map, but the given experiment isn't self.project_config.forced_variation_map = {} self.project_config.set_forced_variation('test_experiment', 'test_user', 'variation') - with mock.patch('optimizely.logger.NoOpLogger.log') as mock_logging: + with mock.patch.object(self.project_config, 'logger') as mock_config_logging: self.assertTrue(self.project_config.set_forced_variation('group_exp_1', 'test_user', None)) - mock_logging.assert_called_once_with( - enums.LogLevels.DEBUG, - 'Nothing to remove. Variation mapped to experiment "group_exp_1" for user "test_user" does not exist.') + mock_config_logging.debug.assert_called_once_with( + 'Nothing to remove. Variation mapped to experiment "group_exp_1" for user "test_user" does not exist.' + ) class ConfigLoggingTest(base.BaseTest): @@ -1115,86 +1116,85 @@ def setUp(self): def test_get_experiment_from_key__invalid_key(self): """ Test that message is logged when provided experiment key is invalid. """ - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + with mock.patch.object(self.project_config, 'logger') as mock_config_logging: self.project_config.get_experiment_from_key('invalid_key') - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Experiment key "invalid_key" is not in datafile.') + mock_config_logging.error.assert_called_once_with('Experiment key "invalid_key" is not in datafile.') def test_get_audience__invalid_id(self): """ Test that message is logged when provided audience ID is invalid. """ - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + with mock.patch.object(self.project_config, 'logger') as mock_config_logging: self.project_config.get_audience('42') - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Audience ID "42" is not in datafile.') + mock_config_logging.error.assert_called_once_with('Audience ID "42" is not in datafile.') def test_get_variation_from_key__invalid_experiment_key(self): """ Test that message is logged when provided experiment key is invalid. """ - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + with mock.patch.object(self.project_config, 'logger') as mock_config_logging: self.project_config.get_variation_from_key('invalid_key', 'control') - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Experiment key "invalid_key" is not in datafile.') + mock_config_logging.error.assert_called_once_with('Experiment key "invalid_key" is not in datafile.') def test_get_variation_from_key__invalid_variation_key(self): """ Test that message is logged when provided variation key is invalid. """ - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + with mock.patch.object(self.project_config, 'logger') as mock_config_logging: self.project_config.get_variation_from_key('test_experiment', 'invalid_key') - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Variation key "invalid_key" is not in datafile.') + mock_config_logging.error.assert_called_once_with('Variation key "invalid_key" is not in datafile.') def test_get_variation_from_id__invalid_experiment_key(self): """ Test that message is logged when provided experiment key is invalid. """ - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + with mock.patch.object(self.project_config, 'logger') as mock_config_logging: self.project_config.get_variation_from_id('invalid_key', '111128') - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Experiment key "invalid_key" is not in datafile.') + mock_config_logging.error.assert_called_once_with('Experiment key "invalid_key" is not in datafile.') def test_get_variation_from_id__invalid_variation_id(self): """ Test that message is logged when provided variation ID is invalid. """ - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + with mock.patch.object(self.project_config, 'logger') as mock_config_logging: self.project_config.get_variation_from_id('test_experiment', '42') - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Variation ID "42" is not in datafile.') + mock_config_logging.error.assert_called_once_with('Variation ID "42" is not in datafile.') def test_get_event__invalid_key(self): """ Test that message is logged when provided event key is invalid. """ - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + with mock.patch.object(self.project_config, 'logger') as mock_config_logging: self.project_config.get_event('invalid_key') - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Event "invalid_key" is not in datafile.') + mock_config_logging.error.assert_called_once_with('Event "invalid_key" is not in datafile.') def test_get_attribute_id__invalid_key(self): """ Test that message is logged when provided attribute key is invalid. """ - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + with mock.patch.object(self.project_config, 'logger') as mock_config_logging: self.project_config.get_attribute_id('invalid_key') - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Attribute "invalid_key" is not in datafile.') + mock_config_logging.error.assert_called_once_with('Attribute "invalid_key" is not in datafile.') def test_get_attribute_id__key_with_opt_prefix_but_not_a_control_attribute(self): """ Test that message is logged when provided attribute key has $opt_ in prefix and key is not one of the control attributes. """ self.project_config.attribute_key_map['$opt_abc'] = entities.Attribute('007', '$opt_abc') - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + with mock.patch.object(self.project_config, 'logger') as mock_config_logging: self.project_config.get_attribute_id('$opt_abc') - mock_logging.assert_called_once_with(enums.LogLevels.WARNING, - ("Attribute $opt_abc unexpectedly has reserved prefix $opt_; " - "using attribute ID instead of reserved attribute name.")) + mock_config_logging.warning.assert_called_once_with(("Attribute $opt_abc unexpectedly has reserved prefix $opt_; " + "using attribute ID instead of reserved attribute name.")) def test_get_group__invalid_id(self): """ Test that message is logged when provided group ID is invalid. """ - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + with mock.patch.object(self.project_config, 'logger') as mock_config_logging: self.project_config.get_group('42') - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Group ID "42" is not in datafile.') + mock_config_logging.error.assert_called_once_with('Group ID "42" is not in datafile.') class ConfigExceptionTest(base.BaseTest): diff --git a/tests/test_decision_service.py b/tests/test_decision_service.py index ebdd6ff6..f3bb6c03 100644 --- a/tests/test_decision_service.py +++ b/tests/test_decision_service.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. @@ -51,11 +51,13 @@ def test_get_forced_variation__user_in_forced_variation(self): """ Test that expected variation is returned if user is forced in a variation. """ experiment = self.project_config.get_experiment_from_key('test_experiment') - with mock.patch('optimizely.logger.NoOpLogger.log') as mock_logging: + with mock.patch.object(self.decision_service, 'logger') as mock_decision_logging: self.assertEqual(entities.Variation('111128', 'control'), self.decision_service.get_forced_variation(experiment, 'user_1')) - mock_logging.assert_called_with(enums.LogLevels.INFO, 'User "user_1" is forced in variation "control".') + mock_decision_logging.info.assert_called_once_with( + 'User "user_1" is forced in variation "control".' + ) def test_get_forced_variation__user_in_forced_variation__invalid_variation_id(self): """ Test that get_forced_variation returns None when variation user is forced in is invalid. """ @@ -72,12 +74,11 @@ def test_get_stored_variation__stored_decision_available(self): experiment = self.project_config.get_experiment_from_key('test_experiment') profile = user_profile.UserProfile('test_user', experiment_bucket_map={'111127': {'variation_id': '111128'}}) - with mock.patch('optimizely.logger.NoOpLogger.log') as mock_logging: + with mock.patch.object(self.decision_service, 'logger') as mock_decision_logging: self.assertEqual(entities.Variation('111128', 'control'), self.decision_service.get_stored_variation(experiment, profile)) - mock_logging.assert_called_with( - enums.LogLevels.INFO, + mock_decision_logging.info.assert_called_once_with( 'Found a stored decision. User "test_user" is in variation "control" of experiment "test_experiment".' ) @@ -95,7 +96,7 @@ def test_get_variation__experiment_not_running(self): # Mark experiment paused experiment.status = 'Paused' with mock.patch('optimizely.decision_service.DecisionService.get_forced_variation') as mock_get_forced_variation, \ - mock.patch('optimizely.logger.NoOpLogger.log') as mock_logging, \ + mock.patch.object(self.decision_service, 'logger') as mock_decision_logging, \ mock.patch('optimizely.decision_service.DecisionService.get_stored_variation') as mock_get_stored_variation, \ mock.patch('optimizely.helpers.audience.is_user_in_experiment') as mock_audience_check, \ mock.patch('optimizely.bucketer.Bucketer.bucket') as mock_bucket, \ @@ -103,7 +104,7 @@ def test_get_variation__experiment_not_running(self): mock.patch('optimizely.user_profile.UserProfileService.save') as mock_save: self.assertIsNone(self.decision_service.get_variation(experiment, 'test_user', None)) - mock_logging.assert_called_once_with(enums.LogLevels.INFO, 'Experiment "test_experiment" is not running.') + mock_decision_logging.info.assert_called_once_with('Experiment "test_experiment" is not running.') # Assert no calls are made to other services self.assertEqual(0, mock_get_forced_variation.call_count) self.assertEqual(0, mock_get_stored_variation.call_count) @@ -265,7 +266,7 @@ def test_get_variation__user_profile_in_invalid_format(self): mock.patch('optimizely.helpers.audience.is_user_in_experiment', return_value=True) as mock_audience_check, \ mock.patch('optimizely.bucketer.Bucketer.bucket', return_value=entities.Variation('111129', 'variation')) as mock_bucket, \ - mock.patch('optimizely.logger.NoOpLogger.log') as mock_logging, \ + mock.patch.object(self.decision_service, 'logger') as mock_decision_logging, \ mock.patch('optimizely.user_profile.UserProfileService.lookup', return_value='invalid_profile') as mock_lookup, \ mock.patch('optimizely.user_profile.UserProfileService.save') as mock_save: @@ -278,7 +279,7 @@ def test_get_variation__user_profile_in_invalid_format(self): # Stored decision is not consulted as user profile is invalid self.assertEqual(0, mock_get_stored_variation.call_count) mock_audience_check.assert_called_once_with(self.project_config, experiment, None) - mock_logging.assert_called_with(enums.LogLevels.WARNING, 'User profile has invalid format.') + mock_decision_logging.warning.assert_called_once_with('User profile has invalid format.') mock_bucket.assert_called_once_with(experiment, 'test_user', 'test_user') mock_save.assert_called_once_with({'user_id': 'test_user', 'experiment_bucket_map': {'111127': {'variation_id': '111129'}}}) @@ -293,7 +294,7 @@ def test_get_variation__user_profile_lookup_fails(self): mock.patch('optimizely.helpers.audience.is_user_in_experiment', return_value=True) as mock_audience_check, \ mock.patch('optimizely.bucketer.Bucketer.bucket', return_value=entities.Variation('111129', 'variation')) as mock_bucket, \ - mock.patch('optimizely.logger.NoOpLogger.log') as mock_logging, \ + mock.patch.object(self.decision_service, 'logger') as mock_decision_logging, \ mock.patch('optimizely.user_profile.UserProfileService.lookup', side_effect=Exception('major problem')) as mock_lookup, \ mock.patch('optimizely.user_profile.UserProfileService.save') as mock_save: @@ -306,9 +307,9 @@ def test_get_variation__user_profile_lookup_fails(self): # Stored decision is not consulted as lookup failed self.assertEqual(0, mock_get_stored_variation.call_count) mock_audience_check.assert_called_once_with(self.project_config, experiment, None) - mock_logging.assert_any_call( - enums.LogLevels.ERROR, - 'Unable to retrieve user profile for user "test_user" as lookup failed. Error: major problem') + mock_decision_logging.exception.assert_called_once_with( + 'Unable to retrieve user profile for user "test_user" as lookup failed.' + ) mock_bucket.assert_called_once_with(experiment, 'test_user', 'test_user') mock_save.assert_called_once_with({'user_id': 'test_user', 'experiment_bucket_map': {'111127': {'variation_id': '111129'}}}) @@ -323,7 +324,7 @@ def test_get_variation__user_profile_save_fails(self): mock.patch('optimizely.helpers.audience.is_user_in_experiment', return_value=True) as mock_audience_check, \ mock.patch('optimizely.bucketer.Bucketer.bucket', return_value=entities.Variation('111129', 'variation')) as mock_bucket, \ - mock.patch('optimizely.logger.NoOpLogger.log') as mock_logging, \ + mock.patch.object(self.decision_service, 'logger') as mock_decision_logging, \ mock.patch('optimizely.user_profile.UserProfileService.lookup', return_value=None) as mock_lookup, \ mock.patch('optimizely.user_profile.UserProfileService.save', side_effect=Exception('major problem')) as mock_save: @@ -335,9 +336,9 @@ def test_get_variation__user_profile_save_fails(self): mock_lookup.assert_called_once_with('test_user') self.assertEqual(0, mock_get_stored_variation.call_count) mock_audience_check.assert_called_once_with(self.project_config, experiment, None) - mock_logging.assert_any_call( - enums.LogLevels.ERROR, - 'Unable to save user profile for user "test_user". Error: major problem') + mock_decision_logging.exception.assert_called_once_with( + 'Unable to save user profile for user "test_user".' + ) mock_bucket.assert_called_once_with(experiment, 'test_user', 'test_user') mock_save.assert_called_once_with({'user_id': 'test_user', 'experiment_bucket_map': {'111127': {'variation_id': '111129'}}}) @@ -364,7 +365,6 @@ def test_get_variation__ignore_user_profile_when_specified(self): self.assertEqual(0, mock_save.call_count) -@mock.patch('optimizely.logger.NoOpLogger.log') class FeatureFlagDecisionTests(base.BaseTest): def setUp(self): @@ -372,48 +372,55 @@ def setUp(self): opt_obj = optimizely.Optimizely(json.dumps(self.config_dict_with_features)) self.project_config = opt_obj.config self.decision_service = opt_obj.decision_service + self.mock_decision_logger = mock.patch.object(self.decision_service, 'logger') + self.mock_config_logger = mock.patch.object(self.project_config, 'logger') - def test_get_variation_for_rollout__returns_none_if_no_experiments(self, mock_logging): + def test_get_variation_for_rollout__returns_none_if_no_experiments(self): """ Test that get_variation_for_rollout returns None if there are no experiments (targeting rules). """ - no_experiment_rollout = self.project_config.get_rollout_from_id('201111') - self.assertEqual(decision_service.Decision(None, None, decision_service.DECISION_SOURCE_ROLLOUT), - self.decision_service.get_variation_for_rollout(no_experiment_rollout, 'test_user')) + with self.mock_config_logger as mock_logging: + no_experiment_rollout = self.project_config.get_rollout_from_id('201111') + self.assertEqual( + decision_service.Decision(None, None, decision_service.DECISION_SOURCE_ROLLOUT), + self.decision_service.get_variation_for_rollout(no_experiment_rollout, 'test_user') + ) # Assert no log messages were generated self.assertEqual(0, mock_logging.call_count) - def test_get_variation_for_rollout__returns_decision_if_user_in_rollout(self, mock_logging): + def test_get_variation_for_rollout__returns_decision_if_user_in_rollout(self): """ Test that get_variation_for_rollout returns Decision with experiment/variation if user meets targeting conditions for a rollout rule. """ rollout = self.project_config.get_rollout_from_id('211111') with mock.patch('optimizely.helpers.audience.is_user_in_experiment', return_value=True),\ - mock.patch('optimizely.bucketer.Bucketer.bucket', - return_value=self.project_config.get_variation_from_id('211127', '211129')) as mock_bucket: + self.mock_decision_logger as mock_decision_logging, \ + mock.patch('optimizely.bucketer.Bucketer.bucket', + return_value=self.project_config.get_variation_from_id('211127', '211129')) as mock_bucket: self.assertEqual(decision_service.Decision(self.project_config.get_experiment_from_id('211127'), self.project_config.get_variation_from_id('211127', '211129'), decision_service.DECISION_SOURCE_ROLLOUT), self.decision_service.get_variation_for_rollout(rollout, 'test_user')) # Check all log messages - self.assertEqual( - [mock.call(enums.LogLevels.DEBUG, 'User "test_user" meets conditions for targeting rule 1.'), - mock.call(enums.LogLevels.DEBUG, 'User "test_user" is in variation 211129 of experiment 211127.') - ], mock_logging.call_args_list) + mock_decision_logging.debug.assert_has_calls([ + mock.call('User "test_user" meets conditions for targeting rule 1.'), + mock.call('User "test_user" is in variation 211129 of experiment 211127.'), + ]) # Check that bucket is called with correct parameters mock_bucket.assert_called_once_with(self.project_config.get_experiment_from_id('211127'), 'test_user', 'test_user') - def test_get_variation_for_rollout__calls_bucket_with_bucketing_id(self, mock_logging): + def test_get_variation_for_rollout__calls_bucket_with_bucketing_id(self): """ Test that get_variation_for_rollout calls Bucketer.bucket with bucketing ID when provided. """ rollout = self.project_config.get_rollout_from_id('211111') with mock.patch('optimizely.helpers.audience.is_user_in_experiment', return_value=True),\ - mock.patch('optimizely.bucketer.Bucketer.bucket', - return_value=self.project_config.get_variation_from_id('211127', '211129')) as mock_bucket: + self.mock_decision_logger as mock_decision_logging, \ + mock.patch('optimizely.bucketer.Bucketer.bucket', + return_value=self.project_config.get_variation_from_id('211127', '211129')) as mock_bucket: self.assertEqual(decision_service.Decision(self.project_config.get_experiment_from_id('211127'), self.project_config.get_variation_from_id('211127', '211129'), decision_service.DECISION_SOURCE_ROLLOUT), @@ -422,17 +429,16 @@ def test_get_variation_for_rollout__calls_bucket_with_bucketing_id(self, mock_lo {'$opt_bucketing_id': 'user_bucket_value'})) # Check all log messages - self.assertEqual( - [mock.call(enums.LogLevels.DEBUG, 'User "test_user" meets conditions for targeting rule 1.'), - mock.call(enums.LogLevels.DEBUG, 'User "test_user" is in variation 211129 of experiment 211127.') - ], mock_logging.call_args_list) - + mock_decision_logging.debug.assert_has_calls([ + mock.call('User "test_user" meets conditions for targeting rule 1.'), + mock.call('User "test_user" is in variation 211129 of experiment 211127.') + ]) # Check that bucket is called with correct parameters mock_bucket.assert_called_once_with(self.project_config.get_experiment_from_id('211127'), 'test_user', 'user_bucket_value') - def test_get_variation_for_rollout__skips_to_everyone_else_rule(self, mock_logging): + def test_get_variation_for_rollout__skips_to_everyone_else_rule(self): """ Test that if a user is in an audience, but does not qualify for the experiment, then it skips to the Everyone Else rule. """ @@ -441,6 +447,7 @@ def test_get_variation_for_rollout__skips_to_everyone_else_rule(self, mock_loggi variation_to_mock = self.project_config.get_variation_from_id('211147', '211149') with mock.patch('optimizely.helpers.audience.is_user_in_experiment', return_value=True) as mock_audience_check,\ + self.mock_decision_logger as mock_decision_logging, \ mock.patch('optimizely.bucketer.Bucketer.bucket', side_effect=[None, variation_to_mock]): self.assertEqual( decision_service.Decision(everyone_else_exp, variation_to_mock, decision_service.DECISION_SOURCE_ROLLOUT), @@ -454,20 +461,20 @@ def test_get_variation_for_rollout__skips_to_everyone_else_rule(self, mock_loggi ) # Check all log messages - self.assertEqual( - [mock.call(enums.LogLevels.DEBUG, 'User "test_user" meets conditions for targeting rule 1.'), - mock.call(enums.LogLevels.DEBUG, 'User "test_user" is not in the traffic group for the targeting else. ' - 'Checking "Everyone Else" rule now.'), - mock.call(enums.LogLevels.DEBUG, 'User "test_user" meets conditions for targeting rule "Everyone Else".')], - mock_logging.call_args_list - ) - - def test_get_variation_for_rollout__returns_none_for_user_not_in_rollout(self, mock_logging): + mock_decision_logging.debug.assert_has_calls([ + mock.call('User "test_user" meets conditions for targeting rule 1.'), + mock.call('User "test_user" is not in the traffic group for the targeting else. ' + 'Checking "Everyone Else" rule now.'), + mock.call('User "test_user" meets conditions for targeting rule "Everyone Else".') + ]) + + def test_get_variation_for_rollout__returns_none_for_user_not_in_rollout(self): """ Test that get_variation_for_rollout returns None for the user not in the associated rollout. """ rollout = self.project_config.get_rollout_from_id('211111') - with mock.patch('optimizely.helpers.audience.is_user_in_experiment', return_value=False) as mock_audience_check: + with mock.patch('optimizely.helpers.audience.is_user_in_experiment', return_value=False) as mock_audience_check, \ + self.mock_decision_logger as mock_decision_logging: self.assertEqual(decision_service.Decision(None, None, decision_service.DECISION_SOURCE_ROLLOUT), self.decision_service.get_variation_for_rollout(rollout, 'test_user')) @@ -480,20 +487,23 @@ def test_get_variation_for_rollout__returns_none_for_user_not_in_rollout(self, m ) # Check all log messages - self.assertEqual( - [mock.call(enums.LogLevels.DEBUG, 'User "test_user" does not meet conditions for targeting rule 1.'), - mock.call(enums.LogLevels.DEBUG, 'User "test_user" does not meet conditions for targeting rule 2.')], - mock_logging.call_args_list) + mock_decision_logging.debug.assert_has_calls([ + mock.call('User "test_user" does not meet conditions for targeting rule 1.'), + mock.call('User "test_user" does not meet conditions for targeting rule 2.') + ]) - def test_get_variation_for_feature__returns_variation_for_feature_in_experiment(self, mock_logging): + def test_get_variation_for_feature__returns_variation_for_feature_in_experiment(self): """ Test that get_variation_for_feature returns the variation of the experiment the feature is associated with. """ feature = self.project_config.get_feature_from_key('test_feature_in_experiment') expected_experiment = self.project_config.get_experiment_from_key('test_experiment') expected_variation = self.project_config.get_variation_from_id('test_experiment', '111129') - with mock.patch('optimizely.decision_service.DecisionService.get_variation', - return_value=expected_variation) as mock_decision: + decision_patch = mock.patch( + 'optimizely.decision_service.DecisionService.get_variation', + return_value=expected_variation + ) + with decision_patch as mock_decision, self.mock_decision_logger as mock_decision_logging: self.assertEqual(decision_service.Decision(expected_experiment, expected_variation, decision_service.DECISION_SOURCE_EXPERIMENT), @@ -504,27 +514,33 @@ def test_get_variation_for_feature__returns_variation_for_feature_in_experiment( ) # Check log message - mock_logging.assert_called_once_with(enums.LogLevels.DEBUG, - 'User "test_user" is in variation variation of experiment test_experiment.') + mock_decision_logging.debug.assert_called_once_with( + 'User "test_user" is in variation variation of experiment test_experiment.' + ) - def test_get_variation_for_feature__returns_variation_for_feature_in_rollout(self, mock_logging): + def test_get_variation_for_feature__returns_variation_for_feature_in_rollout(self): """ Test that get_variation_for_feature returns the variation of the experiment in the rollout that the user is bucketed into. """ feature = self.project_config.get_feature_from_key('test_feature_in_rollout') expected_variation = self.project_config.get_variation_from_id('211127', '211129') - with mock.patch('optimizely.decision_service.DecisionService.get_variation_for_rollout', - return_value=expected_variation) as mock_get_variation_for_rollout: + get_variation_for_rollout_patch = mock.patch( + 'optimizely.decision_service.DecisionService.get_variation_for_rollout', + return_value=expected_variation + ) + with get_variation_for_rollout_patch as mock_get_variation_for_rollout, \ + self.mock_decision_logger as mock_decision_logging: self.assertEqual(expected_variation, self.decision_service.get_variation_for_feature(feature, 'test_user')) expected_rollout = self.project_config.get_rollout_from_id('211111') mock_get_variation_for_rollout.assert_called_once_with(expected_rollout, 'test_user', None) # Assert no log messages were generated - self.assertEqual(0, mock_logging.call_count) + self.assertEqual(0, mock_decision_logging.debug.call_count) + self.assertEqual(0, len(mock_decision_logging.method_calls)) - def test_get_variation_for_feature__returns_variation_if_user_not_in_experiment_but_in_rollout(self, _): + def test_get_variation_for_feature__returns_variation_if_user_not_in_experiment_but_in_rollout(self): """ Test that get_variation_for_feature returns the variation of the experiment in the feature's rollout even if the user is not bucketed into the feature's experiment. """ @@ -547,7 +563,7 @@ def test_get_variation_for_feature__returns_variation_if_user_not_in_experiment_ mock_audience_check.assert_any_call(self.project_config, self.project_config.get_experiment_from_key('211127'), None) - def test_get_variation_for_feature__returns_variation_for_feature_in_group(self, _): + def test_get_variation_for_feature__returns_variation_for_feature_in_group(self): """ Test that get_variation_for_feature returns the variation of the experiment the user is bucketed in the feature's group. """ @@ -568,7 +584,7 @@ def test_get_variation_for_feature__returns_variation_for_feature_in_group(self, mock_get_experiment_in_group.assert_called_once_with(self.project_config.get_group('19228'), 'test_user') mock_decision.assert_called_once_with(self.project_config.get_experiment_from_key('group_exp_1'), 'test_user', None) - def test_get_variation_for_feature__returns_none_for_user_not_in_group(self, _): + def test_get_variation_for_feature__returns_none_for_user_not_in_group(self): """ Test that get_variation_for_feature returns None for user not in group and the feature is not part of a rollout. """ @@ -583,7 +599,7 @@ def test_get_variation_for_feature__returns_none_for_user_not_in_group(self, _): mock_get_experiment_in_group.assert_called_once_with(self.project_config.get_group('19228'), 'test_user') self.assertFalse(mock_decision.called) - def test_get_variation_for_feature__returns_none_for_user_not_in_experiment(self, _): + def test_get_variation_for_feature__returns_none_for_user_not_in_experiment(self): """ Test that get_variation_for_feature returns None for user not in the associated experiment. """ feature = self.project_config.get_feature_from_key('test_feature_in_experiment') @@ -599,20 +615,22 @@ def test_get_variation_for_feature__returns_none_for_user_not_in_experiment(self self.project_config.get_experiment_from_key('test_experiment'), 'test_user', None ) - def test_get_variation_for_feature__returns_none_for_invalid_group_id(self, mock_logging): + def test_get_variation_for_feature__returns_none_for_invalid_group_id(self): """ Test that get_variation_for_feature returns None for unknown group ID. """ feature = self.project_config.get_feature_from_key('test_feature_in_group') feature.groupId = 'aabbccdd' - self.assertEqual( - decision_service.Decision(None, None, decision_service.DECISION_SOURCE_EXPERIMENT), - self.decision_service.get_variation_for_feature(feature, 'test_user') + with self.mock_decision_logger as mock_decision_logging: + self.assertEqual( + decision_service.Decision(None, None, decision_service.DECISION_SOURCE_EXPERIMENT), + self.decision_service.get_variation_for_feature(feature, 'test_user') + ) + mock_decision_logging.error.assert_called_once_with( + enums.Errors.INVALID_GROUP_ID_ERROR.format('_get_variation_for_feature') ) - mock_logging.assert_called_with(enums.LogLevels.ERROR, - enums.Errors.INVALID_GROUP_ID_ERROR.format('_get_variation_for_feature')) - def test_get_variation_for_feature__returns_none_for_user_in_group_experiment_not_associated_with_feature(self, _): + def test_get_variation_for_feature__returns_none_for_user_in_group_experiment_not_associated_with_feature(self): """ Test that if a user is in the mutex group but the experiment is not targeting a feature, then None is returned. """ @@ -628,23 +646,27 @@ def test_get_variation_for_feature__returns_none_for_user_in_group_experiment_no mock_decision.assert_called_once_with(self.project_config.get_group('19228'), 'test_user') - def test_get_experiment_in_group(self, mock_logging): + def test_get_experiment_in_group(self): """ Test that get_experiment_in_group returns the bucketed experiment for the user. """ group = self.project_config.get_group('19228') experiment = self.project_config.get_experiment_from_id('32222') - with mock.patch('optimizely.bucketer.Bucketer.find_bucket', return_value='32222'): + with mock.patch('optimizely.bucketer.Bucketer.find_bucket', return_value='32222'), \ + self.mock_decision_logger as mock_decision_logging: self.assertEqual(experiment, self.decision_service.get_experiment_in_group(group, 'test_user')) - mock_logging.assert_called_with(enums.LogLevels.INFO, 'User with bucketing ID "test_user" is in ' - 'experiment group_exp_1 of group 19228.') + mock_decision_logging.info.assert_called_once_with( + 'User with bucketing ID "test_user" is in experiment group_exp_1 of group 19228.' + ) - def test_get_experiment_in_group__returns_none_if_user_not_in_group(self, mock_logging): + def test_get_experiment_in_group__returns_none_if_user_not_in_group(self): """ Test that get_experiment_in_group returns None if the user is not bucketed into the group. """ group = self.project_config.get_group('19228') - with mock.patch('optimizely.bucketer.Bucketer.find_bucket', return_value=None): + with mock.patch('optimizely.bucketer.Bucketer.find_bucket', return_value=None), \ + self.mock_decision_logger as mock_decision_logging: self.assertIsNone(self.decision_service.get_experiment_in_group(group, 'test_user')) - mock_logging.assert_called_with(enums.LogLevels.INFO, 'User with bucketing ID "test_user" is ' - 'not in any experiments of group 19228.') + mock_decision_logging.info.assert_called_once_with( + 'User with bucketing ID "test_user" is not in any experiments of group 19228.' + ) diff --git a/tests/test_event_builder.py b/tests/test_event_builder.py index bb848e85..7dd46729 100644 --- a/tests/test_event_builder.py +++ b/tests/test_event_builder.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/tests/test_event_dispatcher.py b/tests/test_event_dispatcher.py index 923609b7..a6ce0456 100644 --- a/tests/test_event_dispatcher.py +++ b/tests/test_event_dispatcher.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/tests/test_logger.py b/tests/test_logger.py new file mode 100644 index 00000000..fcfb72f8 --- /dev/null +++ b/tests/test_logger.py @@ -0,0 +1,147 @@ +# Copyright 2016, 2018, Optimizely +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +import logging +import unittest +import uuid + +import mock + +from optimizely import logger as _logger + + +class SimpleLoggerTests(unittest.TestCase): + + def test_log__deprecation_warning(self): + """Test that SimpleLogger now outputs a deprecation warning on ``.log`` calls.""" + simple_logger = _logger.SimpleLogger() + actual_log_patch = mock.patch.object(simple_logger, 'logger') + warnings_patch = mock.patch('warnings.warn') + with warnings_patch as patched_warnings, actual_log_patch as log_patch: + simple_logger.log(logging.INFO, 'Message') + + msg = " is deprecated. " \ + "Please use standard python loggers." + patched_warnings.assert_called_once_with(msg, DeprecationWarning) + log_patch.log.assert_called_once_with(logging.INFO, 'Message') + + +class AdaptLoggerTests(unittest.TestCase): + + def test_adapt_logger__standard_logger(self): + """Test that adapt_logger does nothing to standard python loggers.""" + logger_name = str(uuid.uuid4()) + standard_logger = logging.getLogger(logger_name) + adapted = _logger.adapt_logger(standard_logger) + self.assertIs(standard_logger, adapted) + + def test_adapt_logger__simple(self): + """Test that adapt_logger returns a standard python logger from a SimpleLogger.""" + simple_logger = _logger.SimpleLogger() + standard_logger = _logger.adapt_logger(simple_logger) + + # adapt_logger knows about the loggers attached to this class. + self.assertIs(simple_logger.logger, standard_logger) + + # Verify the standard properties of the logger. + self.assertIsInstance(standard_logger, logging.Logger) + self.assertEqual('optimizely.logger.SimpleLogger', standard_logger.name) + self.assertEqual(logging.INFO, standard_logger.level) + + # Should have a single StreamHandler with our default formatting. + self.assertEqual(1, len(standard_logger.handlers)) + handler = standard_logger.handlers[0] + self.assertIsInstance(handler, logging.StreamHandler) + self.assertEqual( + '%(levelname)-8s %(asctime)s %(filename)s:%(lineno)s:%(message)s', + handler.formatter._fmt + ) + + def test_adapt_logger__noop(self): + """Test that adapt_logger returns a standard python logger from a NoOpLogger.""" + noop_logger = _logger.NoOpLogger() + standard_logger = _logger.adapt_logger(noop_logger) + + # adapt_logger knows about the loggers attached to this class. + self.assertIs(noop_logger.logger, standard_logger) + + # Verify properties of the logger + self.assertIsInstance(standard_logger, logging.Logger) + self.assertEqual('optimizely.logger.NoOpLogger', standard_logger.name) + self.assertEqual(logging.NOTSET, standard_logger.level) + + # Should have a single NullHandler (with a default formatter). + self.assertEqual(1, len(standard_logger.handlers)) + handler = standard_logger.handlers[0] + self.assertIsInstance(handler, logging.NullHandler) + self.assertEqual( + '%(levelname)-8s %(asctime)s %(filename)s:%(lineno)s:%(message)s', + handler.formatter._fmt + ) + + def test_adapt_logger__unknown(self): + """Test that adapt_logger gives back things it can't adapt.""" + obj = object() + value = _logger.adapt_logger(obj) + self.assertIs(obj, value) + + +class GetLoggerTests(unittest.TestCase): + + def test_reset_logger(self): + """Test that reset_logger gives back a standard python logger with defaults.""" + logger_name = str(uuid.uuid4()) + logger = _logger.reset_logger(logger_name) + self.assertEqual(logger_name, logger.name) + self.assertEqual(1, len(logger.handlers)) + handler = logger.handlers[0] + self.assertIsInstance(handler, logging.StreamHandler) + self.assertEqual( + '%(levelname)-8s %(asctime)s %(filename)s:%(lineno)s:%(message)s', + handler.formatter._fmt + ) + + def test_reset_logger__replaces_handlers(self): + """Test that reset_logger replaces existing handlers with a StreamHandler.""" + logger_name = 'test-logger-{}'.format(uuid.uuid4()) + logger = logging.getLogger(logger_name) + logger.handlers = [logging.StreamHandler() for _ in range(10)] + + reset_logger = _logger.reset_logger(logger_name) + self.assertEqual(1, len(reset_logger.handlers)) + + handler = reset_logger.handlers[0] + self.assertIsInstance(handler, logging.StreamHandler) + self.assertEqual( + '%(levelname)-8s %(asctime)s %(filename)s:%(lineno)s:%(message)s', + handler.formatter._fmt + ) + + def test_reset_logger__with_handler__existing(self): + """Test that reset_logger deals with provided handlers correctly.""" + existing_handler = logging.NullHandler() + logger_name = 'test-logger-{}'.format(uuid.uuid4()) + reset_logger = _logger.reset_logger(logger_name, handler=existing_handler) + self.assertEqual(1, len(reset_logger.handlers)) + + handler = reset_logger.handlers[0] + self.assertIs(existing_handler, handler) + self.assertEqual( + '%(levelname)-8s %(asctime)s %(filename)s:%(lineno)s:%(message)s', + handler.formatter._fmt + ) + + def test_reset_logger__with_level(self): + """Test that reset_logger sets log levels correctly.""" + logger_name = 'test-logger-{}'.format(uuid.uuid4()) + reset_logger = _logger.reset_logger(logger_name, level=logging.DEBUG) + self.assertEqual(logging.DEBUG, reset_logger.level) diff --git a/tests/test_optimizely.py b/tests/test_optimizely.py index 60b201f6..c9dae881 100644 --- a/tests/test_optimizely.py +++ b/tests/test_optimizely.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. @@ -36,8 +36,7 @@ class OptimizelyTest(base.BaseTest): try: isinstance("test", basestring) # attempt to evaluate basestring - _expected_notification_failure = \ - 'Problem calling notify callback. Error: on_custom_event() takes exactly 1 argument (4 given)' + _expected_notification_failure = 'Problem calling notify callback.' def isstr(self, s): return isinstance(s, basestring) @@ -45,8 +44,6 @@ def isstr(self, s): strTest = isstr except NameError: - _expected_notification_failure = \ - 'Problem calling notify callback. Error: on_custom_event() takes 1 positional argument but 4 were given' def isstr(self, s): return isinstance(s, str) @@ -74,10 +71,11 @@ def _validate_event_object_event_tags(self, event_obj, expected_event_metric_par def test_init__invalid_datafile__logs_error(self): """ Test that invalid datafile logs error on init. """ - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + mock_client_logger = mock.MagicMock() + with mock.patch('optimizely.logger.reset_logger', return_value=mock_client_logger): opt_obj = optimizely.Optimizely('invalid_datafile') - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Provided "datafile" is in an invalid format.') + mock_client_logger.exception.assert_called_once_with('Provided "datafile" is in an invalid format.') self.assertFalse(opt_obj.is_valid) def test_init__invalid_event_dispatcher__logs_error(self): @@ -86,10 +84,11 @@ def test_init__invalid_event_dispatcher__logs_error(self): class InvalidDispatcher(object): pass - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + mock_client_logger = mock.MagicMock() + with mock.patch('optimizely.logger.reset_logger', return_value=mock_client_logger): opt_obj = optimizely.Optimizely(json.dumps(self.config_dict), event_dispatcher=InvalidDispatcher) - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Provided "event_dispatcher" is in an invalid format.') + mock_client_logger.exception.assert_called_once_with('Provided "event_dispatcher" is in an invalid format.') self.assertFalse(opt_obj.is_valid) def test_init__invalid_logger__logs_error(self): @@ -98,10 +97,11 @@ def test_init__invalid_logger__logs_error(self): class InvalidLogger(object): pass - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + mock_client_logger = mock.MagicMock() + with mock.patch('optimizely.logger.reset_logger', return_value=mock_client_logger): opt_obj = optimizely.Optimizely(json.dumps(self.config_dict), logger=InvalidLogger) - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Provided "logger" is in an invalid format.') + mock_client_logger.exception.assert_called_once_with('Provided "logger" is in an invalid format.') self.assertFalse(opt_obj.is_valid) def test_init__invalid_error_handler__logs_error(self): @@ -110,21 +110,22 @@ def test_init__invalid_error_handler__logs_error(self): class InvalidErrorHandler(object): pass - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + mock_client_logger = mock.MagicMock() + with mock.patch('optimizely.logger.reset_logger', return_value=mock_client_logger): opt_obj = optimizely.Optimizely(json.dumps(self.config_dict), error_handler=InvalidErrorHandler) - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Provided "error_handler" is in an invalid format.') + mock_client_logger.exception.assert_called_once_with('Provided "error_handler" is in an invalid format.') self.assertFalse(opt_obj.is_valid) def test_init__v1_datafile__logs_error(self): """ Test that v1 datafile logs error on init. """ self.config_dict['version'] = project_config.V1_CONFIG_VERSION - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + mock_client_logger = mock.MagicMock() + with mock.patch('optimizely.logger.reset_logger', return_value=mock_client_logger): opt_obj = optimizely.Optimizely(json.dumps(self.config_dict)) - mock_logging.assert_called_once_with( - enums.LogLevels.ERROR, + mock_client_logger.error.assert_called_once_with( 'Provided datafile has unsupported version. Please use SDK version 1.1.0 or earlier for datafile version 1.' ) self.assertFalse(opt_obj.is_valid) @@ -141,17 +142,19 @@ def test_invalid_json_raises_schema_validation_off(self): """ Test that invalid JSON logs error if schema validation is turned off. """ # Not JSON - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + mock_client_logger = mock.MagicMock() + with mock.patch('optimizely.logger.reset_logger', return_value=mock_client_logger): optimizely.Optimizely('invalid_json', skip_json_validation=True) - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Provided "datafile" is in an invalid format.') + mock_client_logger.error.assert_called_once_with('Provided "datafile" is in an invalid format.') + mock_client_logger.reset_mock() # JSON having valid version, but entities have invalid format - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + with mock.patch('optimizely.logger.reset_logger', return_value=mock_client_logger): optimizely.Optimizely({'version': '2', 'events': 'invalid_value', 'experiments': 'invalid_value'}, skip_json_validation=True) - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Provided "datafile" is in an invalid format.') + mock_client_logger.error.assert_called_once_with('Provided "datafile" is in an invalid format.') def test_activate(self): """ Test that activate calls dispatch_event with right params and returns expected variation. """ @@ -303,13 +306,11 @@ def test_invalid_notification_send(self): def on_custom_event(test_string): custom_called[0] = True print('Custom notification event tracked with parameter test_string={}', test_string) - - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: - notification_center = NotificationCenter(SimpleLogger()) - notification_center.add_notification_listener(custom_type, on_custom_event) - notification_center.send_notifications(custom_type, 1, 2, "5", 6) - - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, self._expected_notification_failure) + mock_logger = mock.Mock() + notification_center = NotificationCenter(mock_logger) + notification_center.add_notification_listener(custom_type, on_custom_event) + notification_center.send_notifications(custom_type, 1, 2, "5", 6) + mock_logger.exception.assert_called_once_with('Problem calling notify callback!') def test_add_invalid_listener(self): """ Test adding a invalid listener """ @@ -705,10 +706,10 @@ def test_activate__invalid_object(self): opt_obj = optimizely.Optimizely('invalid_datafile') - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + with mock.patch.object(opt_obj, 'logger') as mock_client_logging: self.assertIsNone(opt_obj.activate('test_experiment', 'test_user')) - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Datafile has invalid format. Failing "activate".') + mock_client_logging.error.assert_called_once_with('Datafile has invalid format. Failing "activate".') def test_track__with_attributes(self): """ Test that track calls dispatch_event with right params when attributes are provided. """ @@ -1101,14 +1102,13 @@ def test_track__experiment_not_running(self): def test_track_invalid_event_key(self): """ Test that track does not call dispatch_event when event does not exist. """ - - with mock.patch('optimizely.event_dispatcher.EventDispatcher.dispatch_event') as mock_dispatch_event,\ - mock.patch('optimizely.logger.NoOpLogger.log') as mock_logging: + dispatch_event_patch = mock.patch('optimizely.event_dispatcher.EventDispatcher.dispatch_event') + with dispatch_event_patch as mock_dispatch_event, \ + mock.patch.object(self.optimizely, 'logger') as mock_client_logging: self.optimizely.track('aabbcc_event', 'test_user') self.assertEqual(0, mock_dispatch_event.call_count) - mock_logging.assert_called_with( - enums.LogLevels.INFO, + mock_client_logging.info.assert_called_with( 'Not tracking user "test_user" for event "aabbcc_event".' ) @@ -1133,28 +1133,27 @@ def test_track__invalid_object(self): opt_obj = optimizely.Optimizely('invalid_datafile') - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + with mock.patch.object(opt_obj, 'logger') as mock_client_logging: opt_obj.track('test_event', 'test_user') - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Datafile has invalid format. Failing "track".') + mock_client_logging.error.assert_called_once_with('Datafile has invalid format. Failing "track".') def test_get_variation__invalid_object(self): """ Test that get_variation logs error if Optimizely object is not created correctly. """ opt_obj = optimizely.Optimizely('invalid_datafile') - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + with mock.patch.object(opt_obj, 'logger') as mock_client_logging: self.assertIsNone(opt_obj.get_variation('test_experiment', 'test_user')) - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Datafile has invalid format. Failing "get_variation".') + mock_client_logging.error.assert_called_once_with('Datafile has invalid format. Failing "get_variation".') def test_get_variation_invalid_experiment_key(self): """ Test that get_variation retuns None when invalid experiment key is given. """ - with mock.patch('optimizely.logger.NoOpLogger.log') as mock_logging: + with mock.patch.object(self.optimizely, 'logger') as mock_client_logging: self.optimizely.get_variation('aabbccdd', 'test_user', None) - mock_logging.assert_called_with( - enums.LogLevels.INFO, + mock_client_logging.info.assert_called_with( 'Experiment key "aabbccdd" is invalid. Not activating user "test_user".' ) @@ -1163,20 +1162,20 @@ def test_is_feature_enabled__returns_false_for_none_feature_key(self): opt_obj = optimizely.Optimizely(json.dumps(self.config_dict_with_features)) - with mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: + with mock.patch.object(opt_obj, 'logger') as mock_client_logging: self.assertFalse(opt_obj.is_feature_enabled(None, 'test_user')) - mock_logger.assert_called_once_with(enums.LogLevels.ERROR, enums.Errors.NONE_FEATURE_KEY_PARAMETER) + mock_client_logging.error.assert_called_once_with(enums.Errors.NONE_FEATURE_KEY_PARAMETER) def test_is_feature_enabled__returns_false_for_none_user_id(self): """ Test that is_feature_enabled returns false if the provided user ID is None. """ opt_obj = optimizely.Optimizely(json.dumps(self.config_dict_with_features)) - with mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: + with mock.patch.object(opt_obj, 'logger') as mock_client_logging: self.assertFalse(opt_obj.is_feature_enabled('feature_key', None)) - mock_logger.assert_called_once_with(enums.LogLevels.ERROR, enums.Errors.NONE_USER_ID_PARAMETER) + mock_client_logging.error.assert_called_once_with(enums.Errors.NONE_USER_ID_PARAMETER) def test_is_feature_enabled__returns_false_for_invalid_feature(self): """ Test that the feature is not enabled for the user if the provided feature key is invalid. """ @@ -1391,12 +1390,11 @@ def test_is_feature_enabled__invalid_object(self): opt_obj = optimizely.Optimizely('invalid_file') - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging, \ + with mock.patch.object(opt_obj, 'logger') as mock_client_logging, \ mock.patch('optimizely.event_dispatcher.EventDispatcher.dispatch_event') as mock_dispatch_event: self.assertFalse(opt_obj.is_feature_enabled('test_feature_in_experiment', 'user_1')) - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, - 'Datafile has invalid format. Failing "is_feature_enabled".') + mock_client_logging.error.assert_called_once_with('Datafile has invalid format. Failing "is_feature_enabled".') # Check that no event is sent self.assertEqual(0, mock_dispatch_event.call_count) @@ -1429,11 +1427,10 @@ def test_get_enabled_features__invalid_object(self): opt_obj = optimizely.Optimizely('invalid_file') - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + with mock.patch.object(opt_obj, 'logger') as mock_client_logging: self.assertEqual([], opt_obj.get_enabled_features('user_1')) - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, - 'Datafile has invalid format. Failing "get_enabled_features".') + mock_client_logging.error.assert_called_once_with('Datafile has invalid format. Failing "get_enabled_features".') def test_get_feature_variable_boolean(self): """ Test that get_feature_variable_boolean returns Boolean value as expected. """ @@ -1445,11 +1442,10 @@ def test_get_feature_variable_boolean(self): return_value=decision_service.Decision(mock_experiment, mock_variation, decision_service.DECISION_SOURCE_EXPERIMENT)), \ - mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: + mock.patch.object(opt_obj.config, 'logger') as mock_config_logging: self.assertTrue(opt_obj.get_feature_variable_boolean('test_feature_in_experiment', 'is_working', 'test_user')) - mock_logger.assert_called_once_with( - enums.LogLevels.INFO, + mock_config_logging.info.assert_called_once_with( 'Value for variable "is_working" for variation "variation" is "true".' ) @@ -1463,11 +1459,10 @@ def test_get_feature_variable_double(self): return_value=decision_service.Decision(mock_experiment, mock_variation, decision_service.DECISION_SOURCE_EXPERIMENT)), \ - mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: + mock.patch.object(opt_obj.config, 'logger') as mock_config_logging: self.assertEqual(10.02, opt_obj.get_feature_variable_double('test_feature_in_experiment', 'cost', 'test_user')) - mock_logger.assert_called_once_with( - enums.LogLevels.INFO, + mock_config_logging.info.assert_called_once_with( 'Value for variable "cost" for variation "variation" is "10.02".' ) @@ -1481,11 +1476,10 @@ def test_get_feature_variable_integer(self): return_value=decision_service.Decision(mock_experiment, mock_variation, decision_service.DECISION_SOURCE_EXPERIMENT)), \ - mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: + mock.patch.object(opt_obj.config, 'logger') as mock_config_logging: self.assertEqual(4243, opt_obj.get_feature_variable_integer('test_feature_in_experiment', 'count', 'test_user')) - mock_logger.assert_called_once_with( - enums.LogLevels.INFO, + mock_config_logging.info.assert_called_once_with( 'Value for variable "count" for variation "variation" is "4243".' ) @@ -1499,12 +1493,13 @@ def test_get_feature_variable_string(self): return_value=decision_service.Decision(mock_experiment, mock_variation, decision_service.DECISION_SOURCE_EXPERIMENT)), \ - mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: - self.assertEqual('staging', - opt_obj.get_feature_variable_string('test_feature_in_experiment', 'environment', 'test_user')) + mock.patch.object(opt_obj.config, 'logger') as mock_config_logging: + self.assertEqual( + 'staging', + opt_obj.get_feature_variable_string('test_feature_in_experiment', 'environment', 'test_user') + ) - mock_logger.assert_called_once_with( - enums.LogLevels.INFO, + mock_config_logging.info.assert_called_once_with( 'Value for variable "environment" for variation "variation" is "staging".' ) @@ -1522,52 +1517,52 @@ def test_get_feature_variable__returns_default_value_if_variable_usage_not_in_va with mock.patch('optimizely.decision_service.DecisionService.get_variation_for_feature', return_value=decision_service.Decision(mock_experiment, mock_variation, decision_service.DECISION_SOURCE_EXPERIMENT)), \ - mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: + mock.patch.object(opt_obj.config, 'logger') as mock_config_logger: self.assertTrue(opt_obj.get_feature_variable_boolean('test_feature_in_experiment', 'is_working', 'test_user')) - mock_logger.assert_called_once_with( - enums.LogLevels.INFO, - 'Variable "is_working" is not used in variation "variation". Assinging default value "true".' + mock_config_logger.info.assert_called_once_with( + 'Variable "is_working" is not used in variation "variation". Assigning default value "true".' ) + mock_config_logger.info.reset_mock() # Double with mock.patch('optimizely.decision_service.DecisionService.get_variation_for_feature', return_value=decision_service.Decision(mock_experiment, mock_variation, decision_service.DECISION_SOURCE_EXPERIMENT)), \ - mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: + mock.patch.object(opt_obj.config, 'logger') as mock_config_logger: self.assertEqual(10.99, opt_obj.get_feature_variable_double('test_feature_in_experiment', 'cost', 'test_user')) - mock_logger.assert_called_once_with( - enums.LogLevels.INFO, - 'Variable "cost" is not used in variation "variation". Assinging default value "10.99".' + mock_config_logger.info.assert_called_once_with( + 'Variable "cost" is not used in variation "variation". Assigning default value "10.99".' ) + mock_config_logger.info.reset_mock() # Integer with mock.patch('optimizely.decision_service.DecisionService.get_variation_for_feature', return_value=decision_service.Decision(mock_experiment, mock_variation, decision_service.DECISION_SOURCE_EXPERIMENT)), \ - mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: + mock.patch.object(opt_obj.config, 'logger') as mock_config_logger: self.assertEqual(999, opt_obj.get_feature_variable_integer('test_feature_in_experiment', 'count', 'test_user')) - mock_logger.assert_called_once_with( - enums.LogLevels.INFO, - 'Variable "count" is not used in variation "variation". Assinging default value "999".' + mock_config_logger.info.assert_called_once_with( + 'Variable "count" is not used in variation "variation". Assigning default value "999".' ) + mock_config_logger.info.reset_mock() # String with mock.patch('optimizely.decision_service.DecisionService.get_variation_for_feature', return_value=decision_service.Decision(mock_experiment, mock_variation, decision_service.DECISION_SOURCE_EXPERIMENT)), \ - mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: + mock.patch.object(opt_obj.config, 'logger') as mock_config_logger: self.assertEqual('devel', opt_obj.get_feature_variable_string('test_feature_in_experiment', 'environment', 'test_user')) - mock_logger.assert_called_once_with( - enums.LogLevels.INFO, - 'Variable "environment" is not used in variation "variation". Assinging default value "devel".' + mock_config_logger.info.assert_called_once_with( + 'Variable "environment" is not used in variation "variation". Assigning default value "devel".' ) + mock_config_logger.info.reset_mock() def test_get_feature_variable__returns_default_value_if_no_variation(self): """ Test that get_feature_variable_* returns default value if no variation. """ @@ -1579,53 +1574,52 @@ def test_get_feature_variable__returns_default_value_if_no_variation(self): with mock.patch('optimizely.decision_service.DecisionService.get_variation_for_feature', return_value=decision_service.Decision(mock_experiment, None, decision_service.DECISION_SOURCE_EXPERIMENT)), \ - mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: + mock.patch.object(opt_obj, 'logger') as mock_client_logger: self.assertTrue(opt_obj.get_feature_variable_boolean('test_feature_in_experiment', 'is_working', 'test_user')) - mock_logger.assert_called_once_with( - enums.LogLevels.INFO, + mock_client_logger.info.assert_called_once_with( 'User "test_user" is not in any variation or rollout rule. ' 'Returning default value for variable "is_working" of feature flag "test_feature_in_experiment".' ) + mock_client_logger.info.reset_mock() # Double with mock.patch('optimizely.decision_service.DecisionService.get_variation_for_feature', return_value=decision_service.Decision(mock_experiment, None, decision_service.DECISION_SOURCE_EXPERIMENT)), \ - mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: + mock.patch.object(opt_obj, 'logger') as mock_client_logger: self.assertEqual(10.99, opt_obj.get_feature_variable_double('test_feature_in_experiment', 'cost', 'test_user')) - mock_logger.assert_called_once_with( - enums.LogLevels.INFO, + mock_client_logger.info.assert_called_once_with( 'User "test_user" is not in any variation or rollout rule. ' 'Returning default value for variable "cost" of feature flag "test_feature_in_experiment".' ) + mock_client_logger.info.reset_mock() # Integer with mock.patch('optimizely.decision_service.DecisionService.get_variation_for_feature', return_value=decision_service.Decision(mock_experiment, None, decision_service.DECISION_SOURCE_EXPERIMENT)), \ - mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: + mock.patch.object(opt_obj, 'logger') as mock_client_logger: self.assertEqual(999, opt_obj.get_feature_variable_integer('test_feature_in_experiment', 'count', 'test_user')) - mock_logger.assert_called_once_with( - enums.LogLevels.INFO, + mock_client_logger.info.assert_called_once_with( 'User "test_user" is not in any variation or rollout rule. ' 'Returning default value for variable "count" of feature flag "test_feature_in_experiment".' ) + mock_client_logger.info.reset_mock() # String with mock.patch('optimizely.decision_service.DecisionService.get_variation_for_feature', return_value=decision_service.Decision(mock_experiment, None, decision_service.DECISION_SOURCE_EXPERIMENT)), \ - mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: + mock.patch.object(opt_obj, 'logger') as mock_client_logger: self.assertEqual('devel', opt_obj.get_feature_variable_string('test_feature_in_experiment', 'environment', 'test_user')) - mock_logger.assert_called_once_with( - enums.LogLevels.INFO, + mock_client_logger.info.assert_called_once_with( 'User "test_user" is not in any variation or rollout rule. ' 'Returning default value for variable "environment" of feature flag "test_feature_in_experiment".' ) @@ -1634,68 +1628,100 @@ def test_get_feature_variable__returns_none_if_none_feature_key(self): """ Test that get_feature_variable_* returns None for None feature key. """ opt_obj = optimizely.Optimizely(json.dumps(self.config_dict_with_features)) - with mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: + with mock.patch.object(opt_obj, 'logger') as mock_client_logger: + # Check for booleans self.assertIsNone(opt_obj.get_feature_variable_boolean(None, 'variable_key', 'test_user')) - mock_logger.assert_called_with(enums.LogLevels.ERROR, enums.Errors.NONE_FEATURE_KEY_PARAMETER) + mock_client_logger.error.assert_called_with(enums.Errors.NONE_FEATURE_KEY_PARAMETER) + mock_client_logger.reset_mock() + + # Check for doubles self.assertIsNone(opt_obj.get_feature_variable_double(None, 'variable_key', 'test_user')) - mock_logger.assert_called_with(enums.LogLevels.ERROR, enums.Errors.NONE_FEATURE_KEY_PARAMETER) + mock_client_logger.error.assert_called_with(enums.Errors.NONE_FEATURE_KEY_PARAMETER) + mock_client_logger.reset_mock() + + # Check for integers self.assertIsNone(opt_obj.get_feature_variable_integer(None, 'variable_key', 'test_user')) - mock_logger.assert_called_with(enums.LogLevels.ERROR, enums.Errors.NONE_FEATURE_KEY_PARAMETER) - self.assertIsNone(opt_obj.get_feature_variable_string(None, 'variable_key', 'test_user')) - mock_logger.assert_called_with(enums.LogLevels.ERROR, enums.Errors.NONE_FEATURE_KEY_PARAMETER) + mock_client_logger.error.assert_called_with(enums.Errors.NONE_FEATURE_KEY_PARAMETER) + mock_client_logger.reset_mock() - self.assertEqual(4, mock_logger.call_count) + # Check for strings + self.assertIsNone(opt_obj.get_feature_variable_string(None, 'variable_key', 'test_user')) + mock_client_logger.error.assert_called_with(enums.Errors.NONE_FEATURE_KEY_PARAMETER) + mock_client_logger.reset_mock() def test_get_feature_variable__returns_none_if_none_variable_key(self): """ Test that get_feature_variable_* returns None for None variable key. """ opt_obj = optimizely.Optimizely(json.dumps(self.config_dict_with_features)) - with mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: + with mock.patch.object(opt_obj, 'logger') as mock_client_logger: + # Check for booleans self.assertIsNone(opt_obj.get_feature_variable_boolean('feature_key', None, 'test_user')) - mock_logger.assert_called_with(enums.LogLevels.ERROR, enums.Errors.NONE_VARIABLE_KEY_PARAMETER) + mock_client_logger.error.assert_called_with(enums.Errors.NONE_VARIABLE_KEY_PARAMETER) + mock_client_logger.reset_mock() + + # Check for doubles self.assertIsNone(opt_obj.get_feature_variable_double('feature_key', None, 'test_user')) - mock_logger.assert_called_with(enums.LogLevels.ERROR, enums.Errors.NONE_VARIABLE_KEY_PARAMETER) + mock_client_logger.error.assert_called_with(enums.Errors.NONE_VARIABLE_KEY_PARAMETER) + mock_client_logger.reset_mock() + + # Check for integers self.assertIsNone(opt_obj.get_feature_variable_integer('feature_key', None, 'test_user')) - mock_logger.assert_called_with(enums.LogLevels.ERROR, enums.Errors.NONE_VARIABLE_KEY_PARAMETER) - self.assertIsNone(opt_obj.get_feature_variable_string('feature_key', None, 'test-User')) - mock_logger.assert_called_with(enums.LogLevels.ERROR, enums.Errors.NONE_VARIABLE_KEY_PARAMETER) + mock_client_logger.error.assert_called_with(enums.Errors.NONE_VARIABLE_KEY_PARAMETER) + mock_client_logger.reset_mock() - self.assertEqual(4, mock_logger.call_count) + # Check for strings + self.assertIsNone(opt_obj.get_feature_variable_string('feature_key', None, 'test-User')) + mock_client_logger.error.assert_called_with(enums.Errors.NONE_VARIABLE_KEY_PARAMETER) + mock_client_logger.reset_mock() def test_get_feature_variable__returns_none_if_none_user_id(self): """ Test that get_feature_variable_* returns None for None user ID. """ opt_obj = optimizely.Optimizely(json.dumps(self.config_dict_with_features)) - with mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: + with mock.patch.object(opt_obj, 'logger') as mock_client_logger: + # Check for booleans self.assertIsNone(opt_obj.get_feature_variable_boolean('feature_key', 'variable_key', None)) - mock_logger.assert_called_with(enums.LogLevels.ERROR, enums.Errors.NONE_USER_ID_PARAMETER) + mock_client_logger.error.assert_called_with(enums.Errors.NONE_USER_ID_PARAMETER) + mock_client_logger.reset_mock() + + # Check for doubles self.assertIsNone(opt_obj.get_feature_variable_double('feature_key', 'variable_key', None)) - mock_logger.assert_called_with(enums.LogLevels.ERROR, enums.Errors.NONE_USER_ID_PARAMETER) + mock_client_logger.error.assert_called_with(enums.Errors.NONE_USER_ID_PARAMETER) + mock_client_logger.reset_mock() + + # Check for integers self.assertIsNone(opt_obj.get_feature_variable_integer('feature_key', 'variable_key', None)) - mock_logger.assert_called_with(enums.LogLevels.ERROR, enums.Errors.NONE_USER_ID_PARAMETER) - self.assertIsNone(opt_obj.get_feature_variable_string('feature_key', 'variable_key', None)) - mock_logger.assert_called_with(enums.LogLevels.ERROR, enums.Errors.NONE_USER_ID_PARAMETER) + mock_client_logger.error.assert_called_with(enums.Errors.NONE_USER_ID_PARAMETER) + mock_client_logger.reset_mock() - self.assertEqual(4, mock_logger.call_count) + # Check for strings + self.assertIsNone(opt_obj.get_feature_variable_string('feature_key', 'variable_key', None)) + mock_client_logger.error.assert_called_with(enums.Errors.NONE_USER_ID_PARAMETER) + mock_client_logger.reset_mock() def test_get_feature_variable__returns_none_if_invalid_feature_key(self): """ Test that get_feature_variable_* returns None for invalid feature key. """ opt_obj = optimizely.Optimizely(json.dumps(self.config_dict_with_features)) - with mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: + with mock.patch.object(opt_obj.config, 'logger') as mock_config_logger: self.assertIsNone(opt_obj.get_feature_variable_boolean('invalid_feature', 'is_working', 'test_user')) self.assertIsNone(opt_obj.get_feature_variable_double('invalid_feature', 'cost', 'test_user')) self.assertIsNone(opt_obj.get_feature_variable_integer('invalid_feature', 'count', 'test_user')) self.assertIsNone(opt_obj.get_feature_variable_string('invalid_feature', 'environment', 'test_user')) - self.assertEqual(4, mock_logger.call_count) - mock_logger.assert_called_with(40, 'Feature "invalid_feature" is not in datafile.') + self.assertEqual(4, mock_config_logger.error.call_count) + mock_config_logger.error.assert_has_calls([ + mock.call('Feature "invalid_feature" is not in datafile.'), + mock.call('Feature "invalid_feature" is not in datafile.'), + mock.call('Feature "invalid_feature" is not in datafile.'), + mock.call('Feature "invalid_feature" is not in datafile.') + ]) def test_get_feature_variable__returns_none_if_invalid_variable_key(self): """ Test that get_feature_variable_* returns None for invalid variable key. """ opt_obj = optimizely.Optimizely(json.dumps(self.config_dict_with_features)) - with mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: + with mock.patch.object(opt_obj.config, 'logger') as mock_config_logger: self.assertIsNone(opt_obj.get_feature_variable_boolean('test_feature_in_experiment', 'invalid_variable', 'test_user')) @@ -1708,9 +1734,13 @@ def test_get_feature_variable__returns_none_if_invalid_variable_key(self): self.assertIsNone(opt_obj.get_feature_variable_string('test_feature_in_experiment', 'invalid_variable', 'test_user')) - - self.assertEqual(4, mock_logger.call_count) - mock_logger.assert_called_with(40, 'Variable with key "invalid_variable" not found in the datafile.') + self.assertEqual(4, mock_config_logger.error.call_count) + mock_config_logger.error.assert_has_calls([ + mock.call('Variable with key "invalid_variable" not found in the datafile.'), + mock.call('Variable with key "invalid_variable" not found in the datafile.'), + mock.call('Variable with key "invalid_variable" not found in the datafile.'), + mock.call('Variable with key "invalid_variable" not found in the datafile.') + ]) def test_get_feature_variable__returns_none_if_type_mismatch(self): """ Test that get_feature_variable_* returns None if type mismatch. """ @@ -1722,12 +1752,11 @@ def test_get_feature_variable__returns_none_if_type_mismatch(self): return_value=decision_service.Decision(mock_experiment, mock_variation, decision_service.DECISION_SOURCE_EXPERIMENT)), \ - mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: + mock.patch.object(opt_obj, 'logger') as mock_client_logger: # "is_working" is boolean variable and we are using double method on it. self.assertIsNone(opt_obj.get_feature_variable_double('test_feature_in_experiment', 'is_working', 'test_user')) - mock_logger.assert_called_with( - enums.LogLevels.WARNING, + mock_client_logger.warning.assert_called_with( 'Requested variable type "double", but variable is of type "boolean". ' 'Use correct API to retrieve value. Returning None.' ) @@ -1744,13 +1773,10 @@ def test_get_feature_variable__returns_none_if_unable_to_cast(self): decision_service.DECISION_SOURCE_EXPERIMENT)), \ mock.patch('optimizely.project_config.ProjectConfig.get_typecast_value', side_effect=ValueError()),\ - mock.patch('optimizely.logger.NoOpLogger.log') as mock_logger: + mock.patch.object(opt_obj, 'logger') as mock_client_logger: self.assertEqual(None, opt_obj.get_feature_variable_integer('test_feature_in_experiment', 'count', 'test_user')) - mock_logger.assert_called_with( - enums.LogLevels.ERROR, - 'Unable to cast value. Returning None.' - ) + mock_client_logger.error.assert_called_with('Unable to cast value. Returning None.') class OptimizelyWithExceptionTest(base.BaseTest): @@ -1789,7 +1815,10 @@ class OptimizelyWithLoggingTest(base.BaseTest): def setUp(self): base.BaseTest.setUp(self) - self.optimizely = optimizely.Optimizely(json.dumps(self.config_dict), logger=logger.SimpleLogger()) + self.optimizely = optimizely.Optimizely( + json.dumps(self.config_dict), + logger=logger.SimpleLogger() + ) self.project_config = self.optimizely.config def test_activate(self): @@ -1804,151 +1833,153 @@ def test_activate(self): 'test_experiment', '111129')), \ mock.patch('time.time', return_value=42), \ mock.patch('optimizely.event_dispatcher.EventDispatcher.dispatch_event'), \ - mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + mock.patch.object(self.optimizely, 'logger') as mock_client_logging: self.assertEqual(variation_key, self.optimizely.activate(experiment_key, user_id)) - self.assertEqual(2, mock_logging.call_count) - self.assertEqual(mock.call(enums.LogLevels.INFO, 'Activating user "%s" in experiment "%s".' - % (user_id, experiment_key)), - mock_logging.call_args_list[0]) - (debug_level, debug_message) = mock_logging.call_args_list[1][0] - self.assertEqual(enums.LogLevels.DEBUG, debug_level) - self.assertRegexpMatches(debug_message, - 'Dispatching impression event to URL https://logx.optimizely.com/v1/events with params') + mock_client_logging.info.assert_called_once_with( + 'Activating user "test_user" in experiment "test_experiment".' + ) + debug_message = mock_client_logging.debug.call_args_list[0][0][0] + self.assertRegexpMatches( + debug_message, + 'Dispatching impression event to URL https://logx.optimizely.com/v1/events with params' + ) def test_track(self): """ Test that expected log messages are logged during track. """ user_id = 'test_user' event_key = 'test_event' - experiment_key = 'test_experiment' - + mock_client_logger = mock.patch.object(self.optimizely, 'logger') + mock_config_logger = mock.patch.object(self.optimizely.config, 'logger') + mock_decision_logger = mock.patch.object(self.optimizely.decision_service, 'logger') with mock.patch('optimizely.helpers.audience.is_user_in_experiment', return_value=False), \ mock.patch('time.time', return_value=42), \ mock.patch('optimizely.event_dispatcher.EventDispatcher.dispatch_event'), \ - mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + mock_decision_logger as mock_decision_logging, \ + mock_config_logger as mock_config_logging, \ + mock_client_logger as mock_client_logging: self.optimizely.track(event_key, user_id) - self.assertEqual(4, mock_logging.call_count) - self.assertEqual(mock.call(enums.LogLevels.DEBUG, - 'User "%s" is not in the forced variation map.' % user_id), - mock_logging.call_args_list[0]) - self.assertEqual(mock.call(enums.LogLevels.INFO, - 'User "%s" does not meet conditions to be in experiment "%s".' - % (user_id, experiment_key)), - mock_logging.call_args_list[1]) - self.assertEqual(mock.call(enums.LogLevels.INFO, - 'Not tracking user "%s" for experiment "%s".' % (user_id, experiment_key)), - mock_logging.call_args_list[2]) - self.assertEqual(mock.call(enums.LogLevels.INFO, - 'There are no valid experiments for event "%s" to track.' % event_key), - mock_logging.call_args_list[3]) + mock_config_logging.debug.assert_called_once_with( + 'User "test_user" is not in the forced variation map.' + ) + mock_decision_logging.info.assert_called_once_with( + 'User "test_user" does not meet conditions to be in experiment "test_experiment".' + ) + mock_client_logging.info.assert_has_calls([ + mock.call('Not tracking user "test_user" for experiment "test_experiment".'), + mock.call('There are no valid experiments for event "test_event" to track.') + ]) def test_activate__experiment_not_running(self): """ Test that expected log messages are logged during activate when experiment is not running. """ - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging, \ + mock_client_logger = mock.patch.object(self.optimizely, 'logger') + mock_decision_logger = mock.patch.object(self.optimizely.decision_service, 'logger') + with mock_client_logger as mock_client_logging, \ + mock_decision_logger as mock_decision_logging, \ mock.patch('optimizely.helpers.experiment.is_experiment_running', return_value=False) as mock_is_experiment_running: self.optimizely.activate('test_experiment', 'test_user', attributes={'test_attribute': 'test_value'}) - self.assertEqual(2, mock_logging.call_count) - self.assertEqual(mock_logging.call_args_list[0], - mock.call(enums.LogLevels.INFO, 'Experiment "test_experiment" is not running.')) - self.assertEqual(mock_logging.call_args_list[1], - mock.call(enums.LogLevels.INFO, 'Not activating user "test_user".')) + mock_decision_logging.info.assert_called_once_with('Experiment "test_experiment" is not running.') + mock_client_logging.info.assert_called_once_with('Not activating user "test_user".') mock_is_experiment_running.assert_called_once_with(self.project_config.get_experiment_from_key('test_experiment')) def test_activate__no_audience_match(self): """ Test that expected log messages are logged during activate when audience conditions are not met. """ - experiment_key = 'test_experiment' - user_id = 'test_user' - - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: - self.optimizely.activate('test_experiment', 'test_user', attributes={'test_attribute': 'wrong_test_value'}) - - self.assertEqual(3, mock_logging.call_count) - - self.assertEqual(mock_logging.call_args_list[0], - mock.call(enums.LogLevels.DEBUG, - 'User "%s" is not in the forced variation map.' % user_id)) - self.assertEqual(mock_logging.call_args_list[1], - mock.call(enums.LogLevels.INFO, - 'User "%s" does not meet conditions to be in experiment "%s".' - % (user_id, experiment_key))) - self.assertEqual(mock_logging.call_args_list[2], - mock.call(enums.LogLevels.INFO, 'Not activating user "%s".' % user_id)) + mock_client_logger = mock.patch.object(self.optimizely, 'logger') + mock_config_logger = mock.patch.object(self.optimizely.config, 'logger') + mock_decision_logger = mock.patch.object(self.optimizely.decision_service, 'logger') + + with mock_decision_logger as mock_decision_logging, \ + mock_config_logger as mock_config_logging, \ + mock_client_logger as mock_client_logging: + self.optimizely.activate( + 'test_experiment', + 'test_user', + attributes={'test_attribute': 'wrong_test_value'} + ) + + mock_config_logging.debug.assert_called_once_with( + 'User "test_user" is not in the forced variation map.' + ) + mock_decision_logging.info.assert_called_once_with( + 'User "test_user" does not meet conditions to be in experiment "test_experiment".' + ) + mock_client_logging.info.assert_called_once_with('Not activating user "test_user".') def test_activate__dispatch_raises_exception(self): """ Test that activate logs dispatch failure gracefully. """ - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging, \ + with mock.patch.object(self.optimizely, 'logger') as mock_client_logging, \ mock.patch('optimizely.event_dispatcher.EventDispatcher.dispatch_event', side_effect=Exception('Failed to send')): self.assertEqual('control', self.optimizely.activate('test_experiment', 'user_1')) - mock_logging.assert_any_call(enums.LogLevels.ERROR, 'Unable to dispatch impression event. Error: Failed to send') + mock_client_logging.exception.assert_called_once_with('Unable to dispatch impression event!') def test_track__invalid_attributes(self): """ Test that expected log messages are logged during track when attributes are in invalid format. """ - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + mock_logger = mock.patch.object(self.optimizely, 'logger') + with mock_logger as mock_logging: self.optimizely.track('test_event', 'test_user', attributes='invalid') - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Provided attributes are in an invalid format.') + mock_logging.error.assert_called_once_with('Provided attributes are in an invalid format.') def test_track__invalid_event_tag(self): """ Test that expected log messages are logged during track when event_tag is in invalid format. """ - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + mock_client_logger = mock.patch.object(self.optimizely, 'logger') + with mock_client_logger as mock_client_logging: self.optimizely.track('test_event', 'test_user', event_tags='4200') - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Provided event tags are in an invalid format.') + mock_client_logging.error.assert_called_once_with( + 'Provided event tags are in an invalid format.' + ) - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + with mock_client_logger as mock_client_logging: self.optimizely.track('test_event', 'test_user', event_tags=4200) - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Provided event tags are in an invalid format.') + mock_client_logging.error.assert_called_once_with( + 'Provided event tags are in an invalid format.' + ) def test_track__dispatch_raises_exception(self): """ Test that track logs dispatch failure gracefully. """ - - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging, \ + with mock.patch.object(self.optimizely, 'logger') as mock_client_logging, \ mock.patch('optimizely.event_dispatcher.EventDispatcher.dispatch_event', side_effect=Exception('Failed to send')): self.optimizely.track('test_event', 'user_1') - mock_logging.assert_any_call(enums.LogLevels.ERROR, 'Unable to dispatch conversion event. Error: Failed to send') + mock_client_logging.exception.assert_called_once_with('Unable to dispatch conversion event!') def test_get_variation__invalid_attributes(self): """ Test that expected log messages are logged during get variation when attributes are in invalid format. """ - - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + with mock.patch.object(self.optimizely, 'logger') as mock_client_logging: self.optimizely.get_variation('test_experiment', 'test_user', attributes='invalid') - mock_logging.assert_called_once_with(enums.LogLevels.ERROR, 'Provided attributes are in an invalid format.') + mock_client_logging.error.assert_called_once_with('Provided attributes are in an invalid format.') def test_activate__invalid_attributes(self): """ Test that expected log messages are logged during activate when attributes are in invalid format. """ - - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: + with mock.patch.object(self.optimizely, 'logger') as mock_client_logging: self.optimizely.activate('test_experiment', 'test_user', attributes='invalid') - self.assertEqual(2, mock_logging.call_count) - self.assertEqual(mock.call(enums.LogLevels.ERROR, 'Provided attributes are in an invalid format.'), - mock_logging.call_args_list[0]) - self.assertEqual(mock.call(enums.LogLevels.INFO, 'Not activating user "test_user".'), - mock_logging.call_args_list[1]) + mock_client_logging.error.assert_called_once_with('Provided attributes are in an invalid format.') + mock_client_logging.info.assert_called_once_with('Not activating user "test_user".') def test_get_variation__experiment_not_running(self): """ Test that expected log messages are logged during get variation when experiment is not running. """ - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging, \ + with mock.patch.object(self.optimizely.decision_service, 'logger') as mock_decision_logging, \ mock.patch('optimizely.helpers.experiment.is_experiment_running', return_value=False) as mock_is_experiment_running: self.optimizely.get_variation('test_experiment', 'test_user', attributes={'test_attribute': 'test_value'}) - mock_logging.assert_called_once_with(enums.LogLevels.INFO, 'Experiment "test_experiment" is not running.') + mock_decision_logging.info.assert_called_once_with('Experiment "test_experiment" is not running.') mock_is_experiment_running.assert_called_once_with(self.project_config.get_experiment_from_key('test_experiment')) def test_get_variation__no_audience_match(self): @@ -1957,18 +1988,22 @@ def test_get_variation__no_audience_match(self): experiment_key = 'test_experiment' user_id = 'test_user' - with mock.patch('optimizely.logger.SimpleLogger.log') as mock_logging: - self.optimizely.get_variation(experiment_key, - user_id, - attributes={'test_attribute': 'wrong_test_value'}) - - self.assertEqual(2, mock_logging.call_count) - self.assertEqual(mock.call(enums.LogLevels.DEBUG, 'User "%s" is not in the forced variation map.' % user_id), - mock_logging.call_args_list[0]) - - self.assertEqual(mock.call(enums.LogLevels.INFO, 'User "%s" does not meet conditions to be in experiment "%s".' - % (user_id, experiment_key)), - mock_logging.call_args_list[1]) + mock_config_logger = mock.patch.object(self.optimizely.config, 'logger') + mock_decision_logger = mock.patch.object(self.optimizely.decision_service, 'logger') + with mock_decision_logger as mock_decision_logging, \ + mock_config_logger as mock_config_logging: + self.optimizely.get_variation( + experiment_key, + user_id, + attributes={'test_attribute': 'wrong_test_value'} + ) + + mock_config_logging.debug.assert_called_once_with( + 'User "test_user" is not in the forced variation map.' + ) + mock_decision_logging.info.assert_called_once_with( + 'User "test_user" does not meet conditions to be in experiment "test_experiment".' + ) def test_get_variation__forced_bucketing(self): """ Test that the expected forced variation is called for a valid experiment and attributes """ diff --git a/tests/test_user_profile.py b/tests/test_user_profile.py index a3cdb1d0..9b110588 100644 --- a/tests/test_user_profile.py +++ b/tests/test_user_profile.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. diff --git a/tests/testapp/application.py b/tests/testapp/application.py index 7d8eb014..5077e978 100644 --- a/tests/testapp/application.py +++ b/tests/testapp/application.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. @@ -13,18 +13,16 @@ import json import logging -from os import environ import types +from os import environ + from flask import Flask from flask import request + +import user_profile_service from optimizely import logger -from optimizely import notification_center from optimizely import optimizely from optimizely.helpers import enums -from optimizely import entities -from optimizely import event_builder - -import user_profile_service app = Flask(__name__) diff --git a/tests/testapp/user_profile_service.py b/tests/testapp/user_profile_service.py index 5603f1e3..9c01374e 100644 --- a/tests/testapp/user_profile_service.py +++ b/tests/testapp/user_profile_service.py @@ -4,7 +4,7 @@ # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 - +# # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.