From 28ea204d027beb3f95360c7f372dfc3c7d50c356 Mon Sep 17 00:00:00 2001 From: rashidsp Date: Thu, 1 Aug 2019 16:56:42 +0500 Subject: [PATCH 01/30] feat(eventProcessor): Adds EventProcessor and BatchEventProcessor --- .rubocop_todo.yml | 1 + lib/optimizely/event/batch_event_processor.rb | 202 +++++++++++++++ lib/optimizely/event/event_processor.rb | 25 ++ spec/event/batch_event_processor_spec.rb | 244 ++++++++++++++++++ 4 files changed, 472 insertions(+) create mode 100644 lib/optimizely/event/batch_event_processor.rb create mode 100644 lib/optimizely/event/event_processor.rb create mode 100644 spec/event/batch_event_processor_spec.rb diff --git a/.rubocop_todo.yml b/.rubocop_todo.yml index baf926ef..1df75dba 100644 --- a/.rubocop_todo.yml +++ b/.rubocop_todo.yml @@ -28,6 +28,7 @@ Metrics/ParameterLists: - 'lib/optimizely/event/entity/snapshot_event.rb' - 'lib/optimizely/event/entity/conversion_event.rb' - 'lib/optimizely/event/entity/event_context.rb' + - 'lib/optimizely/event/batch_event_processor.rb' Naming/AccessorMethodName: Exclude: diff --git a/lib/optimizely/event/batch_event_processor.rb b/lib/optimizely/event/batch_event_processor.rb new file mode 100644 index 00000000..a21a98ca --- /dev/null +++ b/lib/optimizely/event/batch_event_processor.rb @@ -0,0 +1,202 @@ +# frozen_string_literal: true + +# +# Copyright 2019, Optimizely and contributors +# +# 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. +# +require_relative 'event_processor' +module Optimizely + class BatchEventProcessor < EventProcessor + # BatchEventProcessor is a batched implementation of the Interface EventProcessor. + # Events passed to the BatchEventProcessor are immediately added to a EventQueue. + # The BatchEventProcessor maintains a single consumer thread that pulls events off of + + attr_reader :event_queue + + DEFAULT_BATCH_SIZE = 10 + DEFAULT_FLUSH_INTERVAL = 30_000 + DEFAULT_TIMEOUT_INTERVAL = (5000 * 60) + + SHUTDOWN_SIGNAL = 'SHUTDOWN_SIGNAL' + FLUSH_SIGNAL = 'FLUSH_SIGNAL' + + def initialize( + event_queue:, + event_dispatcher:, + batch_size:, + flush_interval:, + timeout_interval:, + start_by_default: false, + logger: + ) + @event_queue = event_queue || [] + @event_dispatcher = event_dispatcher + @batch_size = batch_size || DEFAULT_BATCH_SIZE + @flush_interval = flush_interval || DEFAULT_BATCH_INTERVAL + @timeout_interval = timeout_interval || DEFAULT_TIMEOUT_INTERVAL + @logger = logger + @mutex = Mutex.new + @received = ConditionVariable.new + @current_batch = [] + @disposed = false + @is_started = false + start! if start_by_default == true + end + + def start! + if (@is_started == true) && !@disposed + @logger.log(Logger::WARN, 'Service already started.') + return + end + @flushing_interval_deadline = Helpers::DateTimeUtils.create_timestamp + @flush_interval + @thread = Thread.new { run } + @is_started = true + end + + def flush + @mutex.synchronize do + @event_queue << FLUSH_SIGNAL + @received.signal + end + end + + def process(user_event) + @logger.log(Logger::DEBUG, "Received userEvent: #{user_event}") + + if @disposed == true + @logger.log(Logger::WARN, 'Executor shutdown, not accepting tasks.') + return + end + + if @event_queue.include? user_event + @logger.log(Logger::WARN, 'Payload not accepted by the queue.') + return + end + + @mutex.synchronize do + @event_queue << user_event + @received.signal + end + end + + def stop! + return if @disposed + + @mutex.synchronize do + @event_queue << SHUTDOWN_SIGNAL + @received.signal + end + + @is_started = false + @logger.log(Logger::WARN, 'Stopping scheduler.') + @thread.exit + end + + def dispose + return if @disposed == true + + @disposed = true + end + + private + + def run + loop do + if Helpers::DateTimeUtils.create_timestamp > @flushing_interval_deadline + @logger.log( + Logger::DEBUG, + 'Deadline exceeded flushing current batch.' + ) + flush_queue! + end + + @mutex.synchronize do + @received.wait(@mutex, 0.05) + end + + item = @event_queue.pop + + if item.nil? + @logger.log(Logger::DEBUG, 'Empty item, sleeping for 50ms.') + sleep(0.05) + next + end + + if item == SHUTDOWN_SIGNAL + @logger.log(Logger::INFO, 'Received shutdown signal.') + break + end + + if item == FLUSH_SIGNAL + @logger.log(Logger::DEBUG, 'Received flush signal.') + flush_queue! + next + end + + if item.is_a? Optimizely::UserEvent + @logger.log(Logger::DEBUG, "Received add to batch signal. with event: #{item.event['key']}.") + add_to_batch(item) + end + end + end + + def flush_queue! + return if @current_batch.empty? + + log_event = Optimizely::EventFactory.create_log_event(@current_batch, @logger) + begin + @event_dispatcher.dispatch_event(log_event) + rescue StandardError => e + @logger.log(Logger::ERROR, "Error dispatching event: #{log_event} #{e.message}") + end + @current_batch = [] + end + + def add_to_batch(user_event) + if should_split?(user_event) + flush_queue! + @current_batch = [] + end + + # Reset the deadline if starting a new batch. + @flushing_interval_deadline = Helpers::DateTimeUtils.create_timestamp + @flush_interval if @current_batch.empty? + + @logger.log(Logger::DEBUG, "Adding user event: #{user_event.event['key']} to btach.") + @current_batch << user_event + return unless @current_batch.length >= @batch_size + + @logger.log(Logger::DEBUG, 'Flushing on max batch size!') + flush_queue! + end + + def should_split?(user_event) + return false if @current_batch.empty? + + current_context = @current_batch.last.event_context + + new_context = user_event.event_context + # Revisions should match + unless current_context[:revision] == new_context[:revision] + @logger.log(Logger::DEBUG, 'Revisions mismatched: Flushing current batch.') + return true + end + # Projects should match + unless current_context[:project_id] == new_context[:project_id] + @logger.log(Logger::DEBUG, 'Project Ids mismatched: Flushing current batch.') + return true + end + false + end + end +end diff --git a/lib/optimizely/event/event_processor.rb b/lib/optimizely/event/event_processor.rb new file mode 100644 index 00000000..88f1016d --- /dev/null +++ b/lib/optimizely/event/event_processor.rb @@ -0,0 +1,25 @@ +# frozen_string_literal: true + +# +# Copyright 2019, Optimizely and contributors +# +# 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. +# +module Optimizely + class EventProcessor + # EventProcessor interface is used to provide an intermediary processing stage within + # event production. It's assumed that the EventProcessor dispatches events via a provided + # EventHandler. + def process(user_event); end + end +end diff --git a/spec/event/batch_event_processor_spec.rb b/spec/event/batch_event_processor_spec.rb new file mode 100644 index 00000000..bd0aeaa2 --- /dev/null +++ b/spec/event/batch_event_processor_spec.rb @@ -0,0 +1,244 @@ +# frozen_string_literal: true + +# +# Copyright 2019, Optimizely and contributors +# +# 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. +# +require 'spec_helper' +require 'optimizely/event/batch_event_processor' +require 'optimizely/event/user_event_factory' +require 'optimizely/exceptions' +require 'optimizely/event_dispatcher' +require 'optimizely/error_handler' +require 'optimizely/helpers/constants' +require 'optimizely/helpers/validator' +require 'optimizely/logger' +describe Optimizely::BatchEventProcessor do + WebMock.allow_net_connect! + let(:config_body_JSON) { OptimizelySpec::VALID_CONFIG_BODY_JSON } + let(:error_handler) { Optimizely::NoOpErrorHandler.new } + let(:spy_logger) { spy('logger') } + let(:project_config) { Optimizely::DatafileProjectConfig.new(config_body_JSON, spy_logger, error_handler) } + let(:event) { project_config.get_event_from_key('test_event') } + let(:log_url) { 'https://logx.optimizely.com/v1/events' } + let(:post_headers) { {'Content-Type' => 'application/json'} } + + MAX_BATCH_SIZE = 10 + MAX_DURATION_MS = 1000 + TIMEOUT_INTERVAL_MS = 5000 + + before(:example) do + @event_queue = [] + @event_dispatcher = Optimizely::EventDispatcher.new + allow(@event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) + end + + it 'return empty event queue event is processed' do + user_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + event_processor = Optimizely::BatchEventProcessor.new( + event_queue: @event_queue, + event_dispatcher: @event_dispatcher, + batch_size: MAX_BATCH_SIZE, + flush_interval: MAX_DURATION_MS, + timeout_interval: TIMEOUT_INTERVAL_MS, + start_by_default: true, + logger: spy_logger + ) + + event_processor.process(user_event) + sleep 1.5 + expect(event_processor.event_queue).to be_empty + end + + it 'it should flush the current batch when deadline exceeded' do + user_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + event_processor = Optimizely::BatchEventProcessor.new( + event_queue: @event_queue, + event_dispatcher: @event_dispatcher, + batch_size: MAX_BATCH_SIZE, + flush_interval: MAX_DURATION_MS * 3, + timeout_interval: TIMEOUT_INTERVAL_MS, + start_by_default: true, + logger: spy_logger + ) + sleep 3.025 + event_processor.process(user_event) + + sleep 1 + expect(event_processor.event_queue).to be_empty + expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Deadline exceeded flushing current batch.').once + end + + it 'it should flush the current batch when max batch size' do + allow(Optimizely::EventFactory).to receive(:create_log_event) + + event_processor = Optimizely::BatchEventProcessor.new( + event_queue: @event_queue, + event_dispatcher: @event_dispatcher, + batch_size: MAX_BATCH_SIZE, + flush_interval: MAX_DURATION_MS, + timeout_interval: TIMEOUT_INTERVAL_MS, + start_by_default: true, + logger: spy_logger + ) + + expected_batch = [] + counter = 0 + until counter >= 10 + event['key'] = event['key'] + counter.to_s + user_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + expected_batch.unshift user_event + event_processor.process(user_event) + counter += 1 + end + + sleep 1 + + expect(Optimizely::EventFactory).to have_received(:create_log_event).with(expected_batch, spy_logger).once + + expect(@event_dispatcher).to have_received(:dispatch_event).with( + Optimizely::EventFactory.create_log_event(expected_batch, spy_logger) + ).once + + expect(spy_logger).to have_received(:log).with(Logger::DEBUG, "Received add to batch signal. with event: #{event['key']}.").exactly(10).times + expect(spy_logger).to have_received(:log).with(Logger::DEBUG, "Adding user event: #{event['key']} to btach.").exactly(10).times + expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Flushing on max batch size!').once + end + + it 'it should dispatch the event when flush is called' do + conversion_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + log_event = Optimizely::EventFactory.create_log_event(conversion_event, spy_logger) + + event_processor = Optimizely::BatchEventProcessor.new( + event_queue: @event_queue, + event_dispatcher: @event_dispatcher, + batch_size: MAX_BATCH_SIZE, + flush_interval: MAX_DURATION_MS / 2, + timeout_interval: TIMEOUT_INTERVAL_MS, + start_by_default: true, + logger: spy_logger + ) + + event_processor.process(conversion_event) + event_processor.flush + sleep 0.5 + + event_processor.process(conversion_event) + event_processor.flush + sleep 0.75 + + expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).twice + + expect(event_processor.event_queue).to be_empty + expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Received flush signal.').twice + end + + it 'it should flush on mismatch revision' do + allow(project_config).to receive(:revision).and_return('1', '2') + conversion_event1 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + conversion_event2 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + log_event = Optimizely::EventFactory.create_log_event(conversion_event2, spy_logger) + + event_processor = Optimizely::BatchEventProcessor.new( + event_queue: @event_queue, + event_dispatcher: @event_dispatcher, + batch_size: MAX_BATCH_SIZE, + flush_interval: MAX_DURATION_MS, + timeout_interval: TIMEOUT_INTERVAL_MS, + start_by_default: true, + logger: spy_logger + ) + + event_processor.process(conversion_event1) + event_processor.process(conversion_event2) + + sleep 1 + + expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once + + expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Revisions mismatched: Flushing current batch.').once + expect(spy_logger).not_to have_received(:log).with(Logger::DEBUG, 'Deadline exceeded flushing current batch.') + end + + it 'it should flush on mismatch project id' do + allow(project_config).to receive(:project_id).and_return('X', 'Y') + conversion_event1 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + conversion_event2 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + log_event = Optimizely::EventFactory.create_log_event(conversion_event2, spy_logger) + + event_processor = Optimizely::BatchEventProcessor.new( + event_queue: @event_queue, + event_dispatcher: @event_dispatcher, + batch_size: MAX_BATCH_SIZE, + flush_interval: MAX_DURATION_MS, + timeout_interval: TIMEOUT_INTERVAL_MS, + start_by_default: true, + logger: spy_logger + ) + + event_processor.process(conversion_event1) + event_processor.process(conversion_event2) + + sleep 1 + + expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once + + expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Project Ids mismatched: Flushing current batch.').once + expect(spy_logger).not_to have_received(:log).with(Logger::DEBUG, 'Deadline exceeded flushing current batch.') + end + + it 'should process and halt event when start or stop are called' do + conversion_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + log_event = Optimizely::EventFactory.create_log_event(conversion_event, spy_logger) + + event_processor = Optimizely::BatchEventProcessor.new( + event_queue: @event_queue, + event_dispatcher: @event_dispatcher, + batch_size: MAX_BATCH_SIZE, + flush_interval: MAX_DURATION_MS, + timeout_interval: TIMEOUT_INTERVAL_MS, + start_by_default: true, + logger: spy_logger + ) + + event_processor.process(conversion_event) + sleep 1.5 + expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once + + event_processor.stop! + event_processor.process(conversion_event) + expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once + event_processor.start! + event_processor.stop! + expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Deadline exceeded flushing current batch.').exactly(5).times + end + + it 'should not dispatch event when close is called during process' do + conversion_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + + event_processor = Optimizely::BatchEventProcessor.new( + event_queue: @event_queue, + event_dispatcher: @event_dispatcher, + batch_size: MAX_BATCH_SIZE, + flush_interval: MAX_DURATION_MS, + timeout_interval: TIMEOUT_INTERVAL_MS, + start_by_default: true, + logger: spy_logger + ) + + event_processor.process(conversion_event) + event_processor.stop! + expect(@event_dispatcher).not_to have_received(:dispatch_event) + end +end From bcfca1696aa72c444e4a45812b95e1a10e55e75e Mon Sep 17 00:00:00 2001 From: rashidsp Date: Fri, 2 Aug 2019 13:08:50 +0500 Subject: [PATCH 02/30] feat(forwarding-EP): Implements forwarding event processor --- .../event/forwarding_event_processor.rb | 38 ++++++++ spec/event/forwarding_event_processor_spec.rb | 97 +++++++++++++++++++ 2 files changed, 135 insertions(+) create mode 100644 lib/optimizely/event/forwarding_event_processor.rb create mode 100644 spec/event/forwarding_event_processor_spec.rb diff --git a/lib/optimizely/event/forwarding_event_processor.rb b/lib/optimizely/event/forwarding_event_processor.rb new file mode 100644 index 00000000..7e6cf02d --- /dev/null +++ b/lib/optimizely/event/forwarding_event_processor.rb @@ -0,0 +1,38 @@ +# frozen_string_literal: true + +# +# Copyright 2019, Optimizely and contributors +# +# 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. +# +require_relative 'event_processor' +module Optimizely + class ForwardingEventProcessor < EventProcessor + # ForwardingEventProcessor is a basic transformation stage for converting + # the event batch into a LogEvent to be dispatched. + def initialize(event_dispatcher, logger) + @event_dispatcher = event_dispatcher + @logger = logger + end + + def process(user_event) + log_event = Optimizely::EventFactory.create_log_event(user_event, @logger) + + begin + @event_dispatcher.dispatch_event(log_event) + rescue StandardError => e + @logger.log(Logger::ERROR, "Error dispatching event: #{log_event} #{e.message}.") + end + end + end +end diff --git a/spec/event/forwarding_event_processor_spec.rb b/spec/event/forwarding_event_processor_spec.rb new file mode 100644 index 00000000..24bd0fc3 --- /dev/null +++ b/spec/event/forwarding_event_processor_spec.rb @@ -0,0 +1,97 @@ +# frozen_string_literal: true + +# +# Copyright 2019, Optimizely and contributors +# +# 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. +# +require 'spec_helper' +require 'optimizely/event/forwarding_event_processor' +require 'optimizely/event/user_event_factory' +require 'optimizely/error_handler' +require 'optimizely/helpers/date_time_utils' +require 'optimizely/logger' +describe Optimizely::ForwardingEventProcessor do + let(:config_body_JSON) { OptimizelySpec::VALID_CONFIG_BODY_JSON } + let(:error_handler) { Optimizely::NoOpErrorHandler.new } + let(:spy_logger) { spy('logger') } + let(:project_config) { Optimizely::DatafileProjectConfig.new(config_body_JSON, spy_logger, error_handler) } + let(:event) { project_config.get_event_from_key('test_event') } + let(:log_url) { 'https://logx.optimizely.com/v1/events' } + let(:post_headers) { {'Content-Type' => 'application/json'} } + + before(:example) do + time_now = Time.now + allow(Time).to receive(:now).and_return(time_now) + allow(SecureRandom).to receive(:uuid).and_return('a68cf1ad-0393-4e18-af87-efe8f01a7c9c') + + @event_dispatcher = Optimizely::EventDispatcher.new + allow(@event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) + @conversion_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + + @expected_endpoint = 'https://logx.optimizely.com/v1/events' + @expected_conversion_params = { + account_id: '12001', + project_id: '111001', + visitors: [{ + attributes: [{ + entity_id: Optimizely::Helpers::Constants::CONTROL_ATTRIBUTES['BOT_FILTERING'], + key: Optimizely::Helpers::Constants::CONTROL_ATTRIBUTES['BOT_FILTERING'], + type: 'custom', + value: true + }], + visitor_id: 'test_user', + snapshots: [{ + events: [{ + entity_id: '111095', + timestamp: Optimizely::Helpers::DateTimeUtils.create_timestamp, + uuid: 'a68cf1ad-0393-4e18-af87-efe8f01a7c9c', + key: 'test_event' + }] + }] + }], + anonymize_ip: false, + revision: '42', + client_name: Optimizely::CLIENT_ENGINE, + enrich_decisions: true, + client_version: Optimizely::VERSION + } + end + + describe '.process' do + it 'should dispatch event when valid user event is provided' do + forwarding_event_processor = Optimizely::ForwardingEventProcessor.new(@event_dispatcher, spy_logger) + forwarding_event_processor.process(@conversion_event) + + expect(@event_dispatcher).to have_received(:dispatch_event).with( + Optimizely::Event.new(:post, log_url, @expected_conversion_params, post_headers) + ).once + end + + it 'should log an error when dispatch event raises timeout exception' do + log_event = Optimizely::Event.new(:post, log_url, @expected_conversion_params, post_headers) + allow(Optimizely::EventFactory).to receive(:create_log_event).and_return(log_event) + + timeout_error = Timeout::Error.new + allow(@event_dispatcher).to receive(:dispatch_event).and_raise(timeout_error) + + forwarding_event_processor = Optimizely::ForwardingEventProcessor.new(@event_dispatcher, spy_logger) + forwarding_event_processor.process(@conversion_event) + + expect(spy_logger).to have_received(:log).once.with( + Logger::ERROR, + "Error dispatching event: #{log_event} Timeout::Error." + ) + end + end +end From ccbea99eee6b46f2ffb4718aa0310b2dda7386c2 Mon Sep 17 00:00:00 2001 From: rashidsp Date: Wed, 31 Jul 2019 21:42:43 +0500 Subject: [PATCH 03/30] feat(notification-center): Adds LogEvent notification --- lib/optimizely/event/batch_event_processor.rb | 10 ++++++- lib/optimizely/notification_center.rb | 1 + spec/event/batch_event_processor_spec.rb | 29 +++++++++++++++++++ 3 files changed, 39 insertions(+), 1 deletion(-) diff --git a/lib/optimizely/event/batch_event_processor.rb b/lib/optimizely/event/batch_event_processor.rb index a21a98ca..dfbe8eee 100644 --- a/lib/optimizely/event/batch_event_processor.rb +++ b/lib/optimizely/event/batch_event_processor.rb @@ -38,7 +38,8 @@ def initialize( flush_interval:, timeout_interval:, start_by_default: false, - logger: + logger:, + notification_center: nil ) @event_queue = event_queue || [] @event_dispatcher = event_dispatcher @@ -46,6 +47,7 @@ def initialize( @flush_interval = flush_interval || DEFAULT_BATCH_INTERVAL @timeout_interval = timeout_interval || DEFAULT_TIMEOUT_INTERVAL @logger = logger + @notification_center = notification_center @mutex = Mutex.new @received = ConditionVariable.new @current_batch = [] @@ -155,6 +157,12 @@ def flush_queue! return if @current_batch.empty? log_event = Optimizely::EventFactory.create_log_event(@current_batch, @logger) + + @notification_center&.send_notifications( + NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], + log_event + ) + begin @event_dispatcher.dispatch_event(log_event) rescue StandardError => e diff --git a/lib/optimizely/notification_center.rb b/lib/optimizely/notification_center.rb index 53d6dc3d..68fc2f90 100644 --- a/lib/optimizely/notification_center.rb +++ b/lib/optimizely/notification_center.rb @@ -24,6 +24,7 @@ class NotificationCenter # DEPRECATED: ACTIVATE notification type is deprecated since relase 3.1.0. ACTIVATE: 'ACTIVATE: experiment, user_id, attributes, variation, event', DECISION: 'DECISION: type, user_id, attributes, decision_info', + LOG_EVENT: 'LOG_EVENT: type, log_event', OPTIMIZELY_CONFIG_UPDATE: 'optimizely_config_update', TRACK: 'TRACK: event_key, user_id, attributes, event_tags, event' }.freeze diff --git a/spec/event/batch_event_processor_spec.rb b/spec/event/batch_event_processor_spec.rb index bd0aeaa2..f81cd0f9 100644 --- a/spec/event/batch_event_processor_spec.rb +++ b/spec/event/batch_event_processor_spec.rb @@ -241,4 +241,33 @@ event_processor.stop! expect(@event_dispatcher).not_to have_received(:dispatch_event) end + + it 'should send notification log event when event is dispatched' do + notification_center = Optimizely::NotificationCenter.new(spy_logger, error_handler) + allow(@event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) + allow(notification_center).to receive(:send_notifications) + conversion_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + log_event = Optimizely::EventFactory.create_log_event(conversion_event, spy_logger) + + event_processor = Optimizely::BatchEventProcessor.new( + event_queue: @event_queue, + event_dispatcher: @event_dispatcher, + batch_size: MAX_BATCH_SIZE, + flush_interval: MAX_DURATION_MS, + timeout_interval: TIMEOUT_INTERVAL_MS, + start_by_default: true, + logger: spy_logger, + notification_center: notification_center + ) + + event_processor.process(conversion_event) + sleep 1.5 + + expect(notification_center).to have_received(:send_notifications).with( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], + log_event + ).once + + expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once + end end From f7a5b97293c2d70f49ee58053580ba0d57852927 Mon Sep 17 00:00:00 2001 From: rashidsp Date: Fri, 2 Aug 2019 16:22:39 +0500 Subject: [PATCH 04/30] log event in forward-EP --- lib/optimizely/event/forwarding_event_processor.rb | 8 +++++++- spec/event/forwarding_event_processor_spec.rb | 14 ++++++++++++-- 2 files changed, 19 insertions(+), 3 deletions(-) diff --git a/lib/optimizely/event/forwarding_event_processor.rb b/lib/optimizely/event/forwarding_event_processor.rb index 7e6cf02d..3b9d3ee7 100644 --- a/lib/optimizely/event/forwarding_event_processor.rb +++ b/lib/optimizely/event/forwarding_event_processor.rb @@ -20,14 +20,20 @@ module Optimizely class ForwardingEventProcessor < EventProcessor # ForwardingEventProcessor is a basic transformation stage for converting # the event batch into a LogEvent to be dispatched. - def initialize(event_dispatcher, logger) + def initialize(event_dispatcher, logger, notification_center = nil) @event_dispatcher = event_dispatcher @logger = logger + @notification_center = notification_center end def process(user_event) log_event = Optimizely::EventFactory.create_log_event(user_event, @logger) + @notification_center&.send_notifications( + NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], + log_event + ) + begin @event_dispatcher.dispatch_event(log_event) rescue StandardError => e diff --git a/spec/event/forwarding_event_processor_spec.rb b/spec/event/forwarding_event_processor_spec.rb index 24bd0fc3..36cbe0e3 100644 --- a/spec/event/forwarding_event_processor_spec.rb +++ b/spec/event/forwarding_event_processor_spec.rb @@ -69,10 +69,20 @@ end describe '.process' do - it 'should dispatch event when valid user event is provided' do - forwarding_event_processor = Optimizely::ForwardingEventProcessor.new(@event_dispatcher, spy_logger) + it 'should dispatch and send log event when valid event is provided' do + notification_center = Optimizely::NotificationCenter.new(spy_logger, error_handler) + allow(notification_center).to receive(:send_notifications) + forwarding_event_processor = Optimizely::ForwardingEventProcessor.new( + @event_dispatcher, spy_logger, notification_center + ) + forwarding_event_processor.process(@conversion_event) + expect(notification_center).to have_received(:send_notifications).with( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], + Optimizely::Event.new(:post, log_url, @expected_conversion_params, post_headers) + ).once + expect(@event_dispatcher).to have_received(:dispatch_event).with( Optimizely::Event.new(:post, log_url, @expected_conversion_params, post_headers) ).once From f5db35b5dfae21466a91c9ae8ebc25243914a15a Mon Sep 17 00:00:00 2001 From: rashidsp Date: Fri, 2 Aug 2019 18:52:28 +0500 Subject: [PATCH 05/30] Addressing feedback --- lib/optimizely/event/batch_event_processor.rb | 10 ++-- lib/optimizely/event/event_processor.rb | 2 +- spec/event/batch_event_processor_spec.rb | 53 +++++++++---------- 3 files changed, 31 insertions(+), 34 deletions(-) diff --git a/lib/optimizely/event/batch_event_processor.rb b/lib/optimizely/event/batch_event_processor.rb index a21a98ca..c1bd8c12 100644 --- a/lib/optimizely/event/batch_event_processor.rb +++ b/lib/optimizely/event/batch_event_processor.rb @@ -26,7 +26,6 @@ class BatchEventProcessor < EventProcessor DEFAULT_BATCH_SIZE = 10 DEFAULT_FLUSH_INTERVAL = 30_000 - DEFAULT_TIMEOUT_INTERVAL = (5000 * 60) SHUTDOWN_SIGNAL = 'SHUTDOWN_SIGNAL' FLUSH_SIGNAL = 'FLUSH_SIGNAL' @@ -36,7 +35,6 @@ def initialize( event_dispatcher:, batch_size:, flush_interval:, - timeout_interval:, start_by_default: false, logger: ) @@ -44,7 +42,6 @@ def initialize( @event_dispatcher = event_dispatcher @batch_size = batch_size || DEFAULT_BATCH_SIZE @flush_interval = flush_interval || DEFAULT_BATCH_INTERVAL - @timeout_interval = timeout_interval || DEFAULT_TIMEOUT_INTERVAL @logger = logger @mutex = Mutex.new @received = ConditionVariable.new @@ -121,12 +118,13 @@ def run flush_queue! end + item = nil + @mutex.synchronize do @received.wait(@mutex, 0.05) + item = @event_queue.pop end - item = @event_queue.pop - if item.nil? @logger.log(Logger::DEBUG, 'Empty item, sleeping for 50ms.') sleep(0.05) @@ -172,7 +170,7 @@ def add_to_batch(user_event) # Reset the deadline if starting a new batch. @flushing_interval_deadline = Helpers::DateTimeUtils.create_timestamp + @flush_interval if @current_batch.empty? - @logger.log(Logger::DEBUG, "Adding user event: #{user_event.event['key']} to btach.") + @logger.log(Logger::DEBUG, "Adding user event: #{user_event.event['key']} to batch.") @current_batch << user_event return unless @current_batch.length >= @batch_size diff --git a/lib/optimizely/event/event_processor.rb b/lib/optimizely/event/event_processor.rb index 88f1016d..0ddfc648 100644 --- a/lib/optimizely/event/event_processor.rb +++ b/lib/optimizely/event/event_processor.rb @@ -19,7 +19,7 @@ module Optimizely class EventProcessor # EventProcessor interface is used to provide an intermediary processing stage within # event production. It's assumed that the EventProcessor dispatches events via a provided - # EventHandler. + # EventDispatcher. def process(user_event); end end end diff --git a/spec/event/batch_event_processor_spec.rb b/spec/event/batch_event_processor_spec.rb index bd0aeaa2..ce19b113 100644 --- a/spec/event/batch_event_processor_spec.rb +++ b/spec/event/batch_event_processor_spec.rb @@ -36,7 +36,6 @@ MAX_BATCH_SIZE = 10 MAX_DURATION_MS = 1000 - TIMEOUT_INTERVAL_MS = 5000 before(:example) do @event_queue = [] @@ -44,21 +43,24 @@ allow(@event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) end - it 'return empty event queue event is processed' do - user_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + it 'return return empty event queue and dispatch log event when event is processed' do + conversion_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + log_event = Optimizely::EventFactory.create_log_event(conversion_event, spy_logger) + event_processor = Optimizely::BatchEventProcessor.new( event_queue: @event_queue, event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) - event_processor.process(user_event) + event_processor.process(conversion_event) sleep 1.5 + expect(event_processor.event_queue).to be_empty + expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once end it 'it should flush the current batch when deadline exceeded' do @@ -68,7 +70,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS * 3, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) @@ -88,7 +89,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) @@ -112,7 +112,7 @@ ).once expect(spy_logger).to have_received(:log).with(Logger::DEBUG, "Received add to batch signal. with event: #{event['key']}.").exactly(10).times - expect(spy_logger).to have_received(:log).with(Logger::DEBUG, "Adding user event: #{event['key']} to btach.").exactly(10).times + expect(spy_logger).to have_received(:log).with(Logger::DEBUG, "Adding user event: #{event['key']} to batch.").exactly(10).times expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Flushing on max batch size!').once end @@ -125,7 +125,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS / 2, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) @@ -146,24 +145,25 @@ it 'it should flush on mismatch revision' do allow(project_config).to receive(:revision).and_return('1', '2') - conversion_event1 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) - conversion_event2 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) - log_event = Optimizely::EventFactory.create_log_event(conversion_event2, spy_logger) - + user_event1 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + user_event2 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + log_event = Optimizely::EventFactory.create_log_event(user_event2, spy_logger) event_processor = Optimizely::BatchEventProcessor.new( event_queue: @event_queue, event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) - event_processor.process(conversion_event1) - event_processor.process(conversion_event2) + expect(user_event1.event_context[:revision]).to eq('1') + event_processor.process(user_event1) - sleep 1 + expect(user_event2.event_context[:revision]).to eq('2') + event_processor.process(user_event2) + + sleep 0.25 expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once @@ -173,24 +173,25 @@ it 'it should flush on mismatch project id' do allow(project_config).to receive(:project_id).and_return('X', 'Y') - conversion_event1 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) - conversion_event2 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) - log_event = Optimizely::EventFactory.create_log_event(conversion_event2, spy_logger) - + user_event1 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + user_event2 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + log_event = Optimizely::EventFactory.create_log_event(user_event2, spy_logger) event_processor = Optimizely::BatchEventProcessor.new( event_queue: @event_queue, event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) - event_processor.process(conversion_event1) - event_processor.process(conversion_event2) + expect(user_event1.event_context[:project_id]).to eq('X') + event_processor.process(user_event1) - sleep 1 + expect(user_event2.event_context[:project_id]).to eq('Y') + event_processor.process(user_event2) + + sleep 0.25 expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once @@ -207,7 +208,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) @@ -232,7 +232,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) From 32a566ec63672759ee5a17181cdfab73fcc81937 Mon Sep 17 00:00:00 2001 From: rashidsp Date: Fri, 2 Aug 2019 18:52:28 +0500 Subject: [PATCH 06/30] Addressing feedback --- lib/optimizely/event/batch_event_processor.rb | 10 ++-- lib/optimizely/event/event_processor.rb | 2 +- spec/event/batch_event_processor_spec.rb | 53 +++++++++---------- 3 files changed, 31 insertions(+), 34 deletions(-) diff --git a/lib/optimizely/event/batch_event_processor.rb b/lib/optimizely/event/batch_event_processor.rb index a21a98ca..c1bd8c12 100644 --- a/lib/optimizely/event/batch_event_processor.rb +++ b/lib/optimizely/event/batch_event_processor.rb @@ -26,7 +26,6 @@ class BatchEventProcessor < EventProcessor DEFAULT_BATCH_SIZE = 10 DEFAULT_FLUSH_INTERVAL = 30_000 - DEFAULT_TIMEOUT_INTERVAL = (5000 * 60) SHUTDOWN_SIGNAL = 'SHUTDOWN_SIGNAL' FLUSH_SIGNAL = 'FLUSH_SIGNAL' @@ -36,7 +35,6 @@ def initialize( event_dispatcher:, batch_size:, flush_interval:, - timeout_interval:, start_by_default: false, logger: ) @@ -44,7 +42,6 @@ def initialize( @event_dispatcher = event_dispatcher @batch_size = batch_size || DEFAULT_BATCH_SIZE @flush_interval = flush_interval || DEFAULT_BATCH_INTERVAL - @timeout_interval = timeout_interval || DEFAULT_TIMEOUT_INTERVAL @logger = logger @mutex = Mutex.new @received = ConditionVariable.new @@ -121,12 +118,13 @@ def run flush_queue! end + item = nil + @mutex.synchronize do @received.wait(@mutex, 0.05) + item = @event_queue.pop end - item = @event_queue.pop - if item.nil? @logger.log(Logger::DEBUG, 'Empty item, sleeping for 50ms.') sleep(0.05) @@ -172,7 +170,7 @@ def add_to_batch(user_event) # Reset the deadline if starting a new batch. @flushing_interval_deadline = Helpers::DateTimeUtils.create_timestamp + @flush_interval if @current_batch.empty? - @logger.log(Logger::DEBUG, "Adding user event: #{user_event.event['key']} to btach.") + @logger.log(Logger::DEBUG, "Adding user event: #{user_event.event['key']} to batch.") @current_batch << user_event return unless @current_batch.length >= @batch_size diff --git a/lib/optimizely/event/event_processor.rb b/lib/optimizely/event/event_processor.rb index 88f1016d..0ddfc648 100644 --- a/lib/optimizely/event/event_processor.rb +++ b/lib/optimizely/event/event_processor.rb @@ -19,7 +19,7 @@ module Optimizely class EventProcessor # EventProcessor interface is used to provide an intermediary processing stage within # event production. It's assumed that the EventProcessor dispatches events via a provided - # EventHandler. + # EventDispatcher. def process(user_event); end end end diff --git a/spec/event/batch_event_processor_spec.rb b/spec/event/batch_event_processor_spec.rb index bd0aeaa2..ce19b113 100644 --- a/spec/event/batch_event_processor_spec.rb +++ b/spec/event/batch_event_processor_spec.rb @@ -36,7 +36,6 @@ MAX_BATCH_SIZE = 10 MAX_DURATION_MS = 1000 - TIMEOUT_INTERVAL_MS = 5000 before(:example) do @event_queue = [] @@ -44,21 +43,24 @@ allow(@event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) end - it 'return empty event queue event is processed' do - user_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + it 'return return empty event queue and dispatch log event when event is processed' do + conversion_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + log_event = Optimizely::EventFactory.create_log_event(conversion_event, spy_logger) + event_processor = Optimizely::BatchEventProcessor.new( event_queue: @event_queue, event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) - event_processor.process(user_event) + event_processor.process(conversion_event) sleep 1.5 + expect(event_processor.event_queue).to be_empty + expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once end it 'it should flush the current batch when deadline exceeded' do @@ -68,7 +70,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS * 3, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) @@ -88,7 +89,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) @@ -112,7 +112,7 @@ ).once expect(spy_logger).to have_received(:log).with(Logger::DEBUG, "Received add to batch signal. with event: #{event['key']}.").exactly(10).times - expect(spy_logger).to have_received(:log).with(Logger::DEBUG, "Adding user event: #{event['key']} to btach.").exactly(10).times + expect(spy_logger).to have_received(:log).with(Logger::DEBUG, "Adding user event: #{event['key']} to batch.").exactly(10).times expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Flushing on max batch size!').once end @@ -125,7 +125,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS / 2, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) @@ -146,24 +145,25 @@ it 'it should flush on mismatch revision' do allow(project_config).to receive(:revision).and_return('1', '2') - conversion_event1 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) - conversion_event2 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) - log_event = Optimizely::EventFactory.create_log_event(conversion_event2, spy_logger) - + user_event1 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + user_event2 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + log_event = Optimizely::EventFactory.create_log_event(user_event2, spy_logger) event_processor = Optimizely::BatchEventProcessor.new( event_queue: @event_queue, event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) - event_processor.process(conversion_event1) - event_processor.process(conversion_event2) + expect(user_event1.event_context[:revision]).to eq('1') + event_processor.process(user_event1) - sleep 1 + expect(user_event2.event_context[:revision]).to eq('2') + event_processor.process(user_event2) + + sleep 0.25 expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once @@ -173,24 +173,25 @@ it 'it should flush on mismatch project id' do allow(project_config).to receive(:project_id).and_return('X', 'Y') - conversion_event1 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) - conversion_event2 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) - log_event = Optimizely::EventFactory.create_log_event(conversion_event2, spy_logger) - + user_event1 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + user_event2 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + log_event = Optimizely::EventFactory.create_log_event(user_event2, spy_logger) event_processor = Optimizely::BatchEventProcessor.new( event_queue: @event_queue, event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) - event_processor.process(conversion_event1) - event_processor.process(conversion_event2) + expect(user_event1.event_context[:project_id]).to eq('X') + event_processor.process(user_event1) - sleep 1 + expect(user_event2.event_context[:project_id]).to eq('Y') + event_processor.process(user_event2) + + sleep 0.25 expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once @@ -207,7 +208,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) @@ -232,7 +232,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) From c8ed3f7435b5d9c352dc77fb383b56018fdb7255 Mon Sep 17 00:00:00 2001 From: rashidsp Date: Fri, 2 Aug 2019 18:52:28 +0500 Subject: [PATCH 07/30] Addressing feedback --- lib/optimizely/event/batch_event_processor.rb | 10 ++-- lib/optimizely/event/event_processor.rb | 2 +- spec/event/batch_event_processor_spec.rb | 53 +++++++++---------- 3 files changed, 31 insertions(+), 34 deletions(-) diff --git a/lib/optimizely/event/batch_event_processor.rb b/lib/optimizely/event/batch_event_processor.rb index dfbe8eee..bdbffe15 100644 --- a/lib/optimizely/event/batch_event_processor.rb +++ b/lib/optimizely/event/batch_event_processor.rb @@ -26,7 +26,6 @@ class BatchEventProcessor < EventProcessor DEFAULT_BATCH_SIZE = 10 DEFAULT_FLUSH_INTERVAL = 30_000 - DEFAULT_TIMEOUT_INTERVAL = (5000 * 60) SHUTDOWN_SIGNAL = 'SHUTDOWN_SIGNAL' FLUSH_SIGNAL = 'FLUSH_SIGNAL' @@ -36,7 +35,6 @@ def initialize( event_dispatcher:, batch_size:, flush_interval:, - timeout_interval:, start_by_default: false, logger:, notification_center: nil @@ -45,7 +43,6 @@ def initialize( @event_dispatcher = event_dispatcher @batch_size = batch_size || DEFAULT_BATCH_SIZE @flush_interval = flush_interval || DEFAULT_BATCH_INTERVAL - @timeout_interval = timeout_interval || DEFAULT_TIMEOUT_INTERVAL @logger = logger @notification_center = notification_center @mutex = Mutex.new @@ -123,12 +120,13 @@ def run flush_queue! end + item = nil + @mutex.synchronize do @received.wait(@mutex, 0.05) + item = @event_queue.pop end - item = @event_queue.pop - if item.nil? @logger.log(Logger::DEBUG, 'Empty item, sleeping for 50ms.') sleep(0.05) @@ -180,7 +178,7 @@ def add_to_batch(user_event) # Reset the deadline if starting a new batch. @flushing_interval_deadline = Helpers::DateTimeUtils.create_timestamp + @flush_interval if @current_batch.empty? - @logger.log(Logger::DEBUG, "Adding user event: #{user_event.event['key']} to btach.") + @logger.log(Logger::DEBUG, "Adding user event: #{user_event.event['key']} to batch.") @current_batch << user_event return unless @current_batch.length >= @batch_size diff --git a/lib/optimizely/event/event_processor.rb b/lib/optimizely/event/event_processor.rb index 88f1016d..0ddfc648 100644 --- a/lib/optimizely/event/event_processor.rb +++ b/lib/optimizely/event/event_processor.rb @@ -19,7 +19,7 @@ module Optimizely class EventProcessor # EventProcessor interface is used to provide an intermediary processing stage within # event production. It's assumed that the EventProcessor dispatches events via a provided - # EventHandler. + # EventDispatcher. def process(user_event); end end end diff --git a/spec/event/batch_event_processor_spec.rb b/spec/event/batch_event_processor_spec.rb index f81cd0f9..3ad2a7a6 100644 --- a/spec/event/batch_event_processor_spec.rb +++ b/spec/event/batch_event_processor_spec.rb @@ -36,7 +36,6 @@ MAX_BATCH_SIZE = 10 MAX_DURATION_MS = 1000 - TIMEOUT_INTERVAL_MS = 5000 before(:example) do @event_queue = [] @@ -44,21 +43,24 @@ allow(@event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) end - it 'return empty event queue event is processed' do - user_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + it 'return return empty event queue and dispatch log event when event is processed' do + conversion_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + log_event = Optimizely::EventFactory.create_log_event(conversion_event, spy_logger) + event_processor = Optimizely::BatchEventProcessor.new( event_queue: @event_queue, event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) - event_processor.process(user_event) + event_processor.process(conversion_event) sleep 1.5 + expect(event_processor.event_queue).to be_empty + expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once end it 'it should flush the current batch when deadline exceeded' do @@ -68,7 +70,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS * 3, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) @@ -88,7 +89,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) @@ -112,7 +112,7 @@ ).once expect(spy_logger).to have_received(:log).with(Logger::DEBUG, "Received add to batch signal. with event: #{event['key']}.").exactly(10).times - expect(spy_logger).to have_received(:log).with(Logger::DEBUG, "Adding user event: #{event['key']} to btach.").exactly(10).times + expect(spy_logger).to have_received(:log).with(Logger::DEBUG, "Adding user event: #{event['key']} to batch.").exactly(10).times expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Flushing on max batch size!').once end @@ -125,7 +125,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS / 2, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) @@ -146,24 +145,25 @@ it 'it should flush on mismatch revision' do allow(project_config).to receive(:revision).and_return('1', '2') - conversion_event1 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) - conversion_event2 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) - log_event = Optimizely::EventFactory.create_log_event(conversion_event2, spy_logger) - + user_event1 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + user_event2 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + log_event = Optimizely::EventFactory.create_log_event(user_event2, spy_logger) event_processor = Optimizely::BatchEventProcessor.new( event_queue: @event_queue, event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) - event_processor.process(conversion_event1) - event_processor.process(conversion_event2) + expect(user_event1.event_context[:revision]).to eq('1') + event_processor.process(user_event1) - sleep 1 + expect(user_event2.event_context[:revision]).to eq('2') + event_processor.process(user_event2) + + sleep 0.25 expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once @@ -173,24 +173,25 @@ it 'it should flush on mismatch project id' do allow(project_config).to receive(:project_id).and_return('X', 'Y') - conversion_event1 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) - conversion_event2 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) - log_event = Optimizely::EventFactory.create_log_event(conversion_event2, spy_logger) - + user_event1 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + user_event2 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + log_event = Optimizely::EventFactory.create_log_event(user_event2, spy_logger) event_processor = Optimizely::BatchEventProcessor.new( event_queue: @event_queue, event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) - event_processor.process(conversion_event1) - event_processor.process(conversion_event2) + expect(user_event1.event_context[:project_id]).to eq('X') + event_processor.process(user_event1) - sleep 1 + expect(user_event2.event_context[:project_id]).to eq('Y') + event_processor.process(user_event2) + + sleep 0.25 expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once @@ -207,7 +208,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) @@ -232,7 +232,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger ) From c0946eadd38af17c9c9d0946d27b10d9711d9826 Mon Sep 17 00:00:00 2001 From: rashidsp Date: Fri, 2 Aug 2019 19:40:25 +0500 Subject: [PATCH 08/30] fixes log event issue --- lib/optimizely/event/batch_event_processor.rb | 12 +++---- .../event/forwarding_event_processor.rb | 10 +++--- spec/event/batch_event_processor_spec.rb | 34 +++++++++++++++++-- spec/event/forwarding_event_processor_spec.rb | 9 ++++- 4 files changed, 51 insertions(+), 14 deletions(-) diff --git a/lib/optimizely/event/batch_event_processor.rb b/lib/optimizely/event/batch_event_processor.rb index bdbffe15..844e4376 100644 --- a/lib/optimizely/event/batch_event_processor.rb +++ b/lib/optimizely/event/batch_event_processor.rb @@ -156,15 +156,15 @@ def flush_queue! log_event = Optimizely::EventFactory.create_log_event(@current_batch, @logger) - @notification_center&.send_notifications( - NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], - log_event - ) - begin @event_dispatcher.dispatch_event(log_event) + + @notification_center&.send_notifications( + NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], + log_event + ) rescue StandardError => e - @logger.log(Logger::ERROR, "Error dispatching event: #{log_event} #{e.message}") + @logger.log(Logger::ERROR, "Error dispatching event: #{log_event} #{e.message}.") end @current_batch = [] end diff --git a/lib/optimizely/event/forwarding_event_processor.rb b/lib/optimizely/event/forwarding_event_processor.rb index 3b9d3ee7..31c0b539 100644 --- a/lib/optimizely/event/forwarding_event_processor.rb +++ b/lib/optimizely/event/forwarding_event_processor.rb @@ -29,13 +29,13 @@ def initialize(event_dispatcher, logger, notification_center = nil) def process(user_event) log_event = Optimizely::EventFactory.create_log_event(user_event, @logger) - @notification_center&.send_notifications( - NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], - log_event - ) - begin @event_dispatcher.dispatch_event(log_event) + + @notification_center&.send_notifications( + NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], + log_event + ) rescue StandardError => e @logger.log(Logger::ERROR, "Error dispatching event: #{log_event} #{e.message}.") end diff --git a/spec/event/batch_event_processor_spec.rb b/spec/event/batch_event_processor_spec.rb index 3ad2a7a6..ee495a55 100644 --- a/spec/event/batch_event_processor_spec.rb +++ b/spec/event/batch_event_processor_spec.rb @@ -241,7 +241,7 @@ expect(@event_dispatcher).not_to have_received(:dispatch_event) end - it 'should send notification log event when event is dispatched' do + it 'should send log event notification when event is dispatched' do notification_center = Optimizely::NotificationCenter.new(spy_logger, error_handler) allow(@event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) allow(notification_center).to receive(:send_notifications) @@ -253,7 +253,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - timeout_interval: TIMEOUT_INTERVAL_MS, start_by_default: true, logger: spy_logger, notification_center: notification_center @@ -269,4 +268,35 @@ expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once end + + it 'should log an error when dispatch event raises timeout exception' do + notification_center = Optimizely::NotificationCenter.new(spy_logger, error_handler) + allow(notification_center).to receive(:send_notifications) + conversion_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + log_event = Optimizely::EventFactory.create_log_event(conversion_event, spy_logger) + allow(Optimizely::EventFactory).to receive(:create_log_event).and_return(log_event) + + timeout_error = Timeout::Error.new + allow(@event_dispatcher).to receive(:dispatch_event).and_raise(timeout_error) + + event_processor = Optimizely::BatchEventProcessor.new( + event_queue: @event_queue, + event_dispatcher: @event_dispatcher, + batch_size: MAX_BATCH_SIZE, + flush_interval: MAX_DURATION_MS, + start_by_default: true, + logger: spy_logger, + notification_center: notification_center + ) + + event_processor.process(conversion_event) + sleep 1.5 + + expect(notification_center).not_to have_received(:send_notifications) + + expect(spy_logger).to have_received(:log).once.with( + Logger::ERROR, + "Error dispatching event: #{log_event} Timeout::Error." + ) + end end diff --git a/spec/event/forwarding_event_processor_spec.rb b/spec/event/forwarding_event_processor_spec.rb index 36cbe0e3..dbd69901 100644 --- a/spec/event/forwarding_event_processor_spec.rb +++ b/spec/event/forwarding_event_processor_spec.rb @@ -89,15 +89,22 @@ end it 'should log an error when dispatch event raises timeout exception' do + notification_center = Optimizely::NotificationCenter.new(spy_logger, error_handler) + allow(notification_center).to receive(:send_notifications) log_event = Optimizely::Event.new(:post, log_url, @expected_conversion_params, post_headers) allow(Optimizely::EventFactory).to receive(:create_log_event).and_return(log_event) timeout_error = Timeout::Error.new allow(@event_dispatcher).to receive(:dispatch_event).and_raise(timeout_error) - forwarding_event_processor = Optimizely::ForwardingEventProcessor.new(@event_dispatcher, spy_logger) + forwarding_event_processor = Optimizely::ForwardingEventProcessor.new( + @event_dispatcher, spy_logger, notification_center + ) + forwarding_event_processor.process(@conversion_event) + expect(notification_center).not_to have_received(:send_notifications) + expect(spy_logger).to have_received(:log).once.with( Logger::ERROR, "Error dispatching event: #{log_event} Timeout::Error." From cfcf5a8c3c50cb44cc2997305a854e86c1495116 Mon Sep 17 00:00:00 2001 From: rashidsp Date: Mon, 5 Aug 2019 20:33:36 +0500 Subject: [PATCH 09/30] Addresses review --- .rubocop.yml | 3 ++ .rubocop_todo.yml | 10 ++--- lib/optimizely/event/batch_event_processor.rb | 43 ++++++++---------- spec/event/batch_event_processor_spec.rb | 44 ++++++++++++++----- 4 files changed, 59 insertions(+), 41 deletions(-) diff --git a/.rubocop.yml b/.rubocop.yml index d923aba4..f9ae7181 100644 --- a/.rubocop.yml +++ b/.rubocop.yml @@ -44,3 +44,6 @@ Style/RescueStandardError: Style/SignalException: Enabled: false + +Lint/RescueException: + Enabled: false diff --git a/.rubocop_todo.yml b/.rubocop_todo.yml index 1df75dba..53c17b56 100644 --- a/.rubocop_todo.yml +++ b/.rubocop_todo.yml @@ -21,14 +21,14 @@ Lint/LiteralAsCondition: Metrics/ParameterLists: Max: 6 Exclude: - - 'lib/optimizely/config_manager/http_project_config_manager.rb' - 'lib/optimizely.rb' - - 'lib/optimizely/optimizely_factory.rb' - - 'lib/optimizely/event/entity/impression_event.rb' - - 'lib/optimizely/event/entity/snapshot_event.rb' + - 'lib/optimizely/config_manager/http_project_config_manager.rb' + - 'lib/optimizely/event/batch_event_processor.rb' - 'lib/optimizely/event/entity/conversion_event.rb' - 'lib/optimizely/event/entity/event_context.rb' - - 'lib/optimizely/event/batch_event_processor.rb' + - 'lib/optimizely/event/entity/impression_event.rb' + - 'lib/optimizely/event/entity/snapshot_event.rb' + - 'lib/optimizely/optimizely_factory.rb' Naming/AccessorMethodName: Exclude: diff --git a/lib/optimizely/event/batch_event_processor.rb b/lib/optimizely/event/batch_event_processor.rb index c1bd8c12..d1b6c2d5 100644 --- a/lib/optimizely/event/batch_event_processor.rb +++ b/lib/optimizely/event/batch_event_processor.rb @@ -25,34 +25,33 @@ class BatchEventProcessor < EventProcessor attr_reader :event_queue DEFAULT_BATCH_SIZE = 10 - DEFAULT_FLUSH_INTERVAL = 30_000 + DEFAULT_BATCH_INTERVAL = 30_000 + DEFAULT_QUEUE_CAPACITY = 1000 - SHUTDOWN_SIGNAL = 'SHUTDOWN_SIGNAL' FLUSH_SIGNAL = 'FLUSH_SIGNAL' + SHUTDOWN_SIGNAL = 'SHUTDOWN_SIGNAL' def initialize( event_queue:, event_dispatcher:, batch_size:, flush_interval:, - start_by_default: false, - logger: + logger: nil ) - @event_queue = event_queue || [] + @event_queue = event_queue || SizedQueue.new(DEFAULT_QUEUE_CAPACITY) @event_dispatcher = event_dispatcher @batch_size = batch_size || DEFAULT_BATCH_SIZE @flush_interval = flush_interval || DEFAULT_BATCH_INTERVAL - @logger = logger + @logger = logger || NoOpLogger.new @mutex = Mutex.new @received = ConditionVariable.new @current_batch = [] - @disposed = false @is_started = false - start! if start_by_default == true + start! end def start! - if (@is_started == true) && !@disposed + if @is_started == true @logger.log(Logger::WARN, 'Service already started.') return end @@ -71,24 +70,24 @@ def flush def process(user_event) @logger.log(Logger::DEBUG, "Received userEvent: #{user_event}") - if @disposed == true + unless @thread.alive? @logger.log(Logger::WARN, 'Executor shutdown, not accepting tasks.') return end - if @event_queue.include? user_event - @logger.log(Logger::WARN, 'Payload not accepted by the queue.') - return - end - @mutex.synchronize do - @event_queue << user_event + begin + @event_queue << user_event + rescue Exception + @logger.log(Logger::WARN, 'Payload not accepted by the queue.') + return + end @received.signal end end def stop! - return if @disposed + return unless @thread.alive? @mutex.synchronize do @event_queue << SHUTDOWN_SIGNAL @@ -97,13 +96,7 @@ def stop! @is_started = false @logger.log(Logger::WARN, 'Stopping scheduler.') - @thread.exit - end - - def dispose - return if @disposed == true - - @disposed = true + @thread.join end private @@ -168,7 +161,7 @@ def add_to_batch(user_event) end # Reset the deadline if starting a new batch. - @flushing_interval_deadline = Helpers::DateTimeUtils.create_timestamp + @flush_interval if @current_batch.empty? + @flushing_interval_deadline = (Helpers::DateTimeUtils.create_timestamp + @flush_interval) if @current_batch.empty? @logger.log(Logger::DEBUG, "Adding user event: #{user_event.event['key']} to batch.") @current_batch << user_event diff --git a/spec/event/batch_event_processor_spec.rb b/spec/event/batch_event_processor_spec.rb index ce19b113..4d2361d7 100644 --- a/spec/event/batch_event_processor_spec.rb +++ b/spec/event/batch_event_processor_spec.rb @@ -43,6 +43,36 @@ allow(@event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) end + it 'should log waring when service is already started' do + event_processor = Optimizely::BatchEventProcessor.new( + event_queue: @event_queue, + event_dispatcher: @event_dispatcher, + batch_size: MAX_BATCH_SIZE, + flush_interval: MAX_DURATION_MS, + logger: spy_logger + ) + event_processor.start! + expect(spy_logger).to have_received(:log).with(Logger::WARN, 'Service already started.').once + end + + it 'should log waring when payload not accepted by the queue' do + @event_queue = SizedQueue.new(2) + conversion_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + event_processor = Optimizely::BatchEventProcessor.new( + event_queue: @event_queue, + event_dispatcher: @event_dispatcher, + batch_size: MAX_BATCH_SIZE, + flush_interval: MAX_DURATION_MS, + logger: spy_logger + ) + + event_processor.process(conversion_event) + event_processor.process(conversion_event) + event_processor.process(conversion_event) + sleep 1 + expect(spy_logger).to have_received(:log).with(Logger::WARN, 'Payload not accepted by the queue.').once + end + it 'return return empty event queue and dispatch log event when event is processed' do conversion_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) log_event = Optimizely::EventFactory.create_log_event(conversion_event, spy_logger) @@ -52,14 +82,13 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - start_by_default: true, logger: spy_logger ) event_processor.process(conversion_event) sleep 1.5 - expect(event_processor.event_queue).to be_empty + expect(event_processor.event_queue.length).to eq(0) expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once end @@ -70,14 +99,13 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS * 3, - start_by_default: true, logger: spy_logger ) sleep 3.025 event_processor.process(user_event) sleep 1 - expect(event_processor.event_queue).to be_empty + expect(event_processor.event_queue.length).to eq(0) expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Deadline exceeded flushing current batch.').once end @@ -89,7 +117,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - start_by_default: true, logger: spy_logger ) @@ -125,7 +152,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS / 2, - start_by_default: true, logger: spy_logger ) @@ -139,7 +165,7 @@ expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).twice - expect(event_processor.event_queue).to be_empty + expect(event_processor.event_queue.length).to eq(0) expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Received flush signal.').twice end @@ -153,7 +179,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - start_by_default: true, logger: spy_logger ) @@ -181,7 +206,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - start_by_default: true, logger: spy_logger ) @@ -208,7 +232,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - start_by_default: true, logger: spy_logger ) @@ -232,7 +255,6 @@ event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - start_by_default: true, logger: spy_logger ) From 717adb0aebaf0d029825d11a1501af06a58f98b3 Mon Sep 17 00:00:00 2001 From: rashidsp Date: Tue, 6 Aug 2019 00:28:23 +0500 Subject: [PATCH 10/30] resolves test issue --- spec/event/batch_event_processor_spec.rb | 109 +++++------------------ 1 file changed, 23 insertions(+), 86 deletions(-) diff --git a/spec/event/batch_event_processor_spec.rb b/spec/event/batch_event_processor_spec.rb index 4d2361d7..158bf9e1 100644 --- a/spec/event/batch_event_processor_spec.rb +++ b/spec/event/batch_event_processor_spec.rb @@ -41,92 +41,59 @@ @event_queue = [] @event_dispatcher = Optimizely::EventDispatcher.new allow(@event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) - end - it 'should log waring when service is already started' do - event_processor = Optimizely::BatchEventProcessor.new( + @event_processor = Optimizely::BatchEventProcessor.new( event_queue: @event_queue, event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, logger: spy_logger ) - event_processor.start! - expect(spy_logger).to have_received(:log).with(Logger::WARN, 'Service already started.').once end - it 'should log waring when payload not accepted by the queue' do - @event_queue = SizedQueue.new(2) - conversion_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) - event_processor = Optimizely::BatchEventProcessor.new( - event_queue: @event_queue, - event_dispatcher: @event_dispatcher, - batch_size: MAX_BATCH_SIZE, - flush_interval: MAX_DURATION_MS, - logger: spy_logger - ) - - event_processor.process(conversion_event) - event_processor.process(conversion_event) - event_processor.process(conversion_event) - sleep 1 - expect(spy_logger).to have_received(:log).with(Logger::WARN, 'Payload not accepted by the queue.').once + it 'should log waring when service is already started' do + @event_processor.start! + expect(spy_logger).to have_received(:log).with(Logger::WARN, 'Service already started.').once end it 'return return empty event queue and dispatch log event when event is processed' do conversion_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) log_event = Optimizely::EventFactory.create_log_event(conversion_event, spy_logger) - event_processor = Optimizely::BatchEventProcessor.new( - event_queue: @event_queue, - event_dispatcher: @event_dispatcher, - batch_size: MAX_BATCH_SIZE, - flush_interval: MAX_DURATION_MS, - logger: spy_logger - ) - - event_processor.process(conversion_event) + @event_processor.process(conversion_event) sleep 1.5 - expect(event_processor.event_queue.length).to eq(0) + expect(@event_processor.event_queue.length).to eq(0) expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once end it 'it should flush the current batch when deadline exceeded' do user_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + logger = spy('logger') event_processor = Optimizely::BatchEventProcessor.new( event_queue: @event_queue, event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS * 3, - logger: spy_logger + logger: logger ) - sleep 3.025 + sleep 0.025 event_processor.process(user_event) sleep 1 expect(event_processor.event_queue.length).to eq(0) - expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Deadline exceeded flushing current batch.').once + expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Deadline exceeded flushing current batch.') end it 'it should flush the current batch when max batch size' do allow(Optimizely::EventFactory).to receive(:create_log_event) - - event_processor = Optimizely::BatchEventProcessor.new( - event_queue: @event_queue, - event_dispatcher: @event_dispatcher, - batch_size: MAX_BATCH_SIZE, - flush_interval: MAX_DURATION_MS, - logger: spy_logger - ) - expected_batch = [] counter = 0 until counter >= 10 event['key'] = event['key'] + counter.to_s user_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) expected_batch.unshift user_event - event_processor.process(user_event) + @event_processor.process(user_event) counter += 1 end @@ -161,7 +128,7 @@ event_processor.process(conversion_event) event_processor.flush - sleep 0.75 + sleep 1.5 expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).twice @@ -174,19 +141,12 @@ user_event1 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) user_event2 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) log_event = Optimizely::EventFactory.create_log_event(user_event2, spy_logger) - event_processor = Optimizely::BatchEventProcessor.new( - event_queue: @event_queue, - event_dispatcher: @event_dispatcher, - batch_size: MAX_BATCH_SIZE, - flush_interval: MAX_DURATION_MS, - logger: spy_logger - ) expect(user_event1.event_context[:revision]).to eq('1') - event_processor.process(user_event1) + @event_processor.process(user_event1) expect(user_event2.event_context[:revision]).to eq('2') - event_processor.process(user_event2) + @event_processor.process(user_event2) sleep 0.25 @@ -201,19 +161,12 @@ user_event1 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) user_event2 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) log_event = Optimizely::EventFactory.create_log_event(user_event2, spy_logger) - event_processor = Optimizely::BatchEventProcessor.new( - event_queue: @event_queue, - event_dispatcher: @event_dispatcher, - batch_size: MAX_BATCH_SIZE, - flush_interval: MAX_DURATION_MS, - logger: spy_logger - ) expect(user_event1.event_context[:project_id]).to eq('X') - event_processor.process(user_event1) + @event_processor.process(user_event1) expect(user_event2.event_context[:project_id]).to eq('Y') - event_processor.process(user_event2) + @event_processor.process(user_event2) sleep 0.25 @@ -227,39 +180,23 @@ conversion_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) log_event = Optimizely::EventFactory.create_log_event(conversion_event, spy_logger) - event_processor = Optimizely::BatchEventProcessor.new( - event_queue: @event_queue, - event_dispatcher: @event_dispatcher, - batch_size: MAX_BATCH_SIZE, - flush_interval: MAX_DURATION_MS, - logger: spy_logger - ) - - event_processor.process(conversion_event) + @event_processor.process(conversion_event) sleep 1.5 expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once - event_processor.stop! - event_processor.process(conversion_event) + @event_processor.stop! + @event_processor.process(conversion_event) expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once - event_processor.start! - event_processor.stop! + @event_processor.start! + @event_processor.stop! expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Deadline exceeded flushing current batch.').exactly(5).times end it 'should not dispatch event when close is called during process' do conversion_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) - event_processor = Optimizely::BatchEventProcessor.new( - event_queue: @event_queue, - event_dispatcher: @event_dispatcher, - batch_size: MAX_BATCH_SIZE, - flush_interval: MAX_DURATION_MS, - logger: spy_logger - ) - - event_processor.process(conversion_event) - event_processor.stop! + @event_processor.process(conversion_event) + @event_processor.stop! expect(@event_dispatcher).not_to have_received(:dispatch_event) end end From 6eec6bdb79a3cd77643f2948d13be03e0a551cbe Mon Sep 17 00:00:00 2001 From: rashidsp Date: Tue, 6 Aug 2019 01:29:11 +0500 Subject: [PATCH 11/30] fixes logger issue --- spec/event/batch_event_processor_spec.rb | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/spec/event/batch_event_processor_spec.rb b/spec/event/batch_event_processor_spec.rb index 158bf9e1..37bdb9e8 100644 --- a/spec/event/batch_event_processor_spec.rb +++ b/spec/event/batch_event_processor_spec.rb @@ -181,7 +181,7 @@ log_event = Optimizely::EventFactory.create_log_event(conversion_event, spy_logger) @event_processor.process(conversion_event) - sleep 1.5 + sleep 1.75 expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once @event_processor.stop! @@ -189,7 +189,7 @@ expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once @event_processor.start! @event_processor.stop! - expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Deadline exceeded flushing current batch.').exactly(5).times + expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Deadline exceeded flushing current batch.').at_least(1).times end it 'should not dispatch event when close is called during process' do From 7ac58966586448575fae492044f22eae89b00bfd Mon Sep 17 00:00:00 2001 From: rashidsp Date: Tue, 6 Aug 2019 20:06:04 +0500 Subject: [PATCH 12/30] feat(eventprocess): Integrate Event Processor with Optimizely --- lib/optimizely.rb | 63 +++--- .../http_project_config_manager.rb | 5 +- lib/optimizely/notification_center.rb | 4 + spec/notification_center_spec.rb | 31 +++ spec/project_spec.rb | 187 ++++++++++++++++-- 5 files changed, 245 insertions(+), 45 deletions(-) diff --git a/lib/optimizely.rb b/lib/optimizely.rb index 84b914c5..456002cc 100644 --- a/lib/optimizely.rb +++ b/lib/optimizely.rb @@ -22,6 +22,9 @@ require_relative 'optimizely/decision_service' require_relative 'optimizely/error_handler' require_relative 'optimizely/event_builder' +require_relative 'optimizely/event/forwarding_event_processor' +require_relative 'optimizely/event/event_factory' +require_relative 'optimizely/event/user_event_factory' require_relative 'optimizely/event_dispatcher' require_relative 'optimizely/exceptions' require_relative 'optimizely/helpers/constants' @@ -30,13 +33,12 @@ require_relative 'optimizely/helpers/variable_type' require_relative 'optimizely/logger' require_relative 'optimizely/notification_center' - module Optimizely class Project attr_reader :notification_center # @api no-doc - attr_reader :config_manager, :decision_service, :error_handler, - :event_builder, :event_dispatcher, :logger + attr_reader :config_manager, :decision_service, :error_handler, :event_dispatcher, + :event_processor, :logger, :stopped # Constructor for Projects. # @@ -61,7 +63,8 @@ def initialize( user_profile_service = nil, sdk_key = nil, config_manager = nil, - notification_center = nil + notification_center = nil, + event_processor = nil ) @logger = logger || NoOpLogger.new @error_handler = error_handler || NoOpErrorHandler.new @@ -92,7 +95,13 @@ def initialize( StaticProjectConfigManager.new(datafile, @logger, @error_handler, skip_json_validation) end @decision_service = DecisionService.new(@logger, @user_profile_service) - @event_builder = EventBuilder.new(@logger) + + @event_processor = if event_processor.respond_to?(:process) + event_processor + else + ForwardingEventProcessor.new(@event_dispatcher, @logger, @notification_center) + end + # @event_builder = EventBuilder.new(@logger) end # Buckets visitor and sends impression event to Optimizely. @@ -243,20 +252,17 @@ def track(event_key, user_id, attributes = nil, event_tags = nil) return nil end - conversion_event = @event_builder.create_conversion_event(config, event, user_id, attributes, event_tags) + user_event = UserEventFactory.create_conversion_event(config, event, user_id, attributes, event_tags) + @event_processor.process(user_event) @logger.log(Logger::INFO, "Tracking event '#{event_key}' for user '#{user_id}'.") - @logger.log(Logger::INFO, - "Dispatching conversion event to URL #{conversion_event.url} with params #{conversion_event.params}.") - begin - @event_dispatcher.dispatch_event(conversion_event) - rescue => e - @logger.log(Logger::ERROR, "Unable to dispatch conversion event. Error: #{e}") - end - @notification_center.send_notifications( - NotificationCenter::NOTIFICATION_TYPES[:TRACK], - event_key, user_id, attributes, event_tags, conversion_event - ) + if @notification_center.notification_count(NotificationCenter::NOTIFICATION_TYPES[:TRACK]).positive? + conversion_event = EventFactory.create_log_event(user_event, @logger) + @notification_center.send_notifications( + NotificationCenter::NOTIFICATION_TYPES[:TRACK], + event_key, user_id, attributes, event_tags, conversion_event + ) + end nil end @@ -507,6 +513,14 @@ def is_valid config.is_a?(Optimizely::ProjectConfig) end + def close + return if @stopped + + @stopped = true + @config_manager.stop! if @config_manager.respond_to?(:stop!) + @event_processor.stop! if @event_processor.respond_to?(:stop!) + end + private def get_variation_with_config(experiment_key, user_id, attributes, config) @@ -692,15 +706,14 @@ def validate_instantiation_options def send_impression(config, experiment, variation_key, user_id, attributes = nil) experiment_key = experiment['key'] variation_id = config.get_variation_id_from_key(experiment_key, variation_key) - impression_event = @event_builder.create_impression_event(config, experiment, variation_id, user_id, attributes) - @logger.log(Logger::INFO, - "Dispatching impression event to URL #{impression_event.url} with params #{impression_event.params}.") - begin - @event_dispatcher.dispatch_event(impression_event) - rescue => e - @logger.log(Logger::ERROR, "Unable to dispatch impression event. Error: #{e}") - end + user_event = UserEventFactory.create_impression_event(config, experiment, variation_id, user_id, attributes) + @event_processor.process(user_event) + + return unless @notification_center.notification_count(NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE]).positive? + + @logger.log(Logger::INFO, "Activating user '#{user_id}' in experiment '#{experiment_key}'.") variation = config.get_variation_from_id(experiment_key, variation_id) + impression_event = EventFactory.create_log_event(user_event, @logger) @notification_center.send_notifications( NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], experiment, user_id, attributes, variation, impression_event diff --git a/lib/optimizely/config_manager/http_project_config_manager.rb b/lib/optimizely/config_manager/http_project_config_manager.rb index 97630092..b43db688 100644 --- a/lib/optimizely/config_manager/http_project_config_manager.rb +++ b/lib/optimizely/config_manager/http_project_config_manager.rb @@ -30,7 +30,7 @@ module Optimizely class HTTPProjectConfigManager < ProjectConfigManager # Config manager that polls for the datafile and updated ProjectConfig based on an update interval. - attr_reader :config + attr_reader :config, :stopped # Initialize config manager. One of sdk_key or url has to be set to be able to use. # @@ -85,10 +85,13 @@ def ready? def start! @async_scheduler.start! + @stopped = false end def stop! @async_scheduler.stop! + @config = nil + @stopped = true end def get_config diff --git a/lib/optimizely/notification_center.rb b/lib/optimizely/notification_center.rb index 68fc2f90..4a3b0169 100644 --- a/lib/optimizely/notification_center.rb +++ b/lib/optimizely/notification_center.rb @@ -138,6 +138,10 @@ def send_notifications(notification_type, *args) end end + def notification_count(notification_type) + @notifications.include?(notification_type) ? @notifications[notification_type].count : 0 + end + private def notification_type_valid?(notification_type) diff --git a/spec/notification_center_spec.rb b/spec/notification_center_spec.rb index 540c4420..be3a4b8e 100644 --- a/spec/notification_center_spec.rb +++ b/spec/notification_center_spec.rb @@ -486,6 +486,37 @@ def deliver_three; end end end + describe '.notification_count' do + it 'should return count of added notification types' do + notification_center.add_notification_listener( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], + @callback_reference + ) + + notification_center.add_notification_listener( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], + method(:test) + ) + + notification_center.add_notification_listener( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:TRACK], + method(:test) + ) + + expect( + notification_center.notification_count(Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE]) + ).to eq(2) + + expect( + notification_center.notification_count(Optimizely::NotificationCenter::NOTIFICATION_TYPES[:TRACK]) + ).to eq(1) + + expect( + notification_center.notification_count(Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT]) + ).to eq(0) + end + end + describe '@error_handler' do let(:raise_error_handler) { Optimizely::RaiseErrorHandler.new } let(:notification_center) { Optimizely::NotificationCenter.new(spy_logger, raise_error_handler) } diff --git a/spec/project_spec.rb b/spec/project_spec.rb index ab538d7d..b61c6e8e 100644 --- a/spec/project_spec.rb +++ b/spec/project_spec.rb @@ -585,7 +585,11 @@ class InvalidErrorHandler; end end it 'should log and send activate notification when an impression event is dispatched' do - params = @expected_activate_params + def callback(_args); end + project_instance.notification_center.add_notification_listener( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], + method(:callback) + ) variation_to_return = project_instance.config_manager.config.get_variation_from_id('test_experiment', '111128') allow(project_instance.decision_service.bucketer).to receive(:bucket).and_return(variation_to_return) allow(project_instance.event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) @@ -595,7 +599,14 @@ class InvalidErrorHandler; end experiment = project_instance.config_manager.config.get_experiment_from_key('test_experiment') # Decision listener - expect(project_instance.notification_center).to receive(:send_notifications).ordered + expect(project_instance.notification_center).to receive(:send_notifications).with( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:DECISION], any_args + ).ordered + + # Log event + expect(project_instance.notification_center).to receive(:send_notifications).with( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], any_args + ).ordered # Activate listener expect(project_instance.notification_center).to receive(:send_notifications).with( @@ -606,16 +617,20 @@ class InvalidErrorHandler; end project_instance.activate('test_experiment', 'test_user') - expect(spy_logger).to have_received(:log).once.with(Logger::INFO, include('Dispatching impression event to' \ - " URL #{impression_log_url} with params #{params}")) + expect(spy_logger).to have_received(:log).once.with(Logger::INFO, "Activating user 'test_user' in experiment 'test_experiment'.") end it 'should log when an exception has occurred during dispatching the impression event' do + params = @expected_activate_params + stub_request(:post, impression_log_url).with(query: params) + log_event = Optimizely::Event.new(:post, impression_log_url, params, post_headers) + allow(Optimizely::EventFactory).to receive(:create_log_event).and_return(log_event) + variation_to_return = project_instance.config_manager.config.get_variation_from_id('test_experiment', '111128') allow(project_instance.decision_service.bucketer).to receive(:bucket).and_return(variation_to_return) allow(project_instance.event_dispatcher).to receive(:dispatch_event).with(any_args).and_raise(RuntimeError) project_instance.activate('test_experiment', 'test_user') - expect(spy_logger).to have_received(:log).once.with(Logger::ERROR, 'Unable to dispatch impression event. Error: RuntimeError') + expect(spy_logger).to have_received(:log).once.with(Logger::ERROR, "Error dispatching event: #{log_event} RuntimeError.") end it 'should raise an exception when called with invalid attributes' do @@ -865,22 +880,43 @@ class InvalidErrorHandler; end end it 'should log a message if an exception has occurred during dispatching of the event' do + params = @expected_track_event_params + stub_request(:post, conversion_log_url).with(query: params) + log_event = Optimizely::Event.new(:post, conversion_log_url, params, post_headers) + allow(Optimizely::EventFactory).to receive(:create_log_event).and_return(log_event) allow(project_instance.event_dispatcher).to receive(:dispatch_event).with(any_args).and_raise(RuntimeError) + project_instance.track('test_event', 'test_user') - expect(spy_logger).to have_received(:log).once.with(Logger::ERROR, 'Unable to dispatch conversion event. Error: RuntimeError') + expect(spy_logger).to have_received(:log).once.with(Logger::ERROR, "Error dispatching event: #{log_event} RuntimeError.") end it 'should send track notification and properly track an event by calling dispatch_event with right params with revenue provided' do params = @expected_track_event_params - params[:visitors][0][:snapshots][0][:events][0].merge!(revenue: 42, - tags: {'revenue' => 42}) + params[:visitors][0][:snapshots][0][:events][0].merge!( + revenue: 42, + tags: {'revenue' => 42} + ) + + def callback(_args); end + project_instance.notification_center.add_notification_listener( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:TRACK], + method(:callback) + ) + allow(project_instance.event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) conversion_event = Optimizely::Event.new(:post, conversion_log_url, params, post_headers) + + expect(project_instance.notification_center).to receive(:send_notifications) + .with( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], any_args + ).ordered + expect(project_instance.notification_center).to receive(:send_notifications) .with( Optimizely::NotificationCenter::NOTIFICATION_TYPES[:TRACK], 'test_event', 'test_user', nil, {'revenue' => 42}, conversion_event - ).once + ).ordered + project_instance.track('test_event', 'test_user', nil, 'revenue' => 42) expect(project_instance.event_dispatcher).to have_received(:dispatch_event).with(Optimizely::Event.new(:post, conversion_log_url, params, post_headers)).once end @@ -1014,13 +1050,13 @@ class InvalidErrorHandler; end it 'should log when a conversion event is dispatched' do params = @expected_track_event_params - params[:visitors][0][:snapshots][0][:events][0].merge!(revenue: 42, - tags: {'revenue' => 42}) - + params[:visitors][0][:snapshots][0][:events][0].merge!( + revenue: 42, + tags: {'revenue' => 42} + ) allow(project_instance.event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) project_instance.track('test_event', 'test_user', nil, 'revenue' => 42) - expect(spy_logger).to have_received(:log).with(Logger::INFO, include('Dispatching conversion event to' \ - " URL #{conversion_log_url} with params #{params}")) + expect(spy_logger).to have_received(:log).with(Logger::INFO, "Tracking event 'test_event' for user 'test_user'.") end it 'should raise an exception when called with attributes in an invalid format' do @@ -1451,7 +1487,14 @@ class InvalidErrorHandler; end end it 'should return true, send activate notification and an impression if the user is bucketed into a feature experiment' do + def callback(_args); end + project_instance.notification_center.add_notification_listener( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], + method(:callback) + ) + allow(project_instance.event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) + experiment_to_return = config_body['experiments'][3] variation_to_return = experiment_to_return['variations'][0] decision_to_return = Optimizely::DecisionService::Decision.new( @@ -1460,6 +1503,11 @@ class InvalidErrorHandler; end Optimizely::DecisionService::DECISION_SOURCES['FEATURE_TEST'] ) + expect(project_instance.notification_center).to receive(:send_notifications) + .with( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], any_args + ).ordered + expect(project_instance.notification_center).to receive(:send_notifications) .with( Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], @@ -1467,14 +1515,15 @@ class InvalidErrorHandler; end instance_of(Optimizely::Event) ).ordered - expect(project_instance.notification_center).to receive(:send_notifications).ordered + expect(project_instance.notification_center).to receive(:send_notifications) + .with( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:DECISION], any_args + ).ordered allow(project_instance.decision_service).to receive(:get_variation_for_feature).and_return(decision_to_return) - expected_params = @expected_bucketed_params - expect(project_instance.is_feature_enabled('multi_variate_feature', 'test_user')).to be true - expect(spy_logger).to have_received(:log).once.with(Logger::INFO, "Dispatching impression event to URL https://logx.optimizely.com/v1/events with params #{expected_params}.") + expect(spy_logger).to have_received(:log).once.with(Logger::INFO, "Activating user 'test_user' in experiment 'test_experiment_multivariate'.") expect(spy_logger).to have_received(:log).once.with(Logger::INFO, "Feature 'multi_variate_feature' is enabled for user 'test_user'.") end @@ -1727,7 +1776,7 @@ class InvalidErrorHandler; end ) expect(project_instance.notification_center).to receive(:send_notifications).twice.with( - Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], any_args + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], any_args ) expect(project_instance.notification_center).to receive(:send_notifications).once.with( @@ -2742,4 +2791,104 @@ class InvalidErrorHandler; end expect(invalid_project.is_valid).to be false end end + + describe '.close' do + it 'should stop config manager when optimizely close is called' do + http_project_config_manager = Optimizely::HTTPProjectConfigManager.new( + sdk_key: 'QBw9gFM8oTn7ogY9ANCC1z', + start_by_default: true + ) + + project_instance = Optimizely::Project.new( + config_body_JSON, nil, spy_logger, error_handler, + false, nil, nil, http_project_config_manager + ) + + project_instance.close + expect(project_instance.stopped).to be true + expect(http_project_config_manager.stopped).to be true + end + + it 'should stop invalid object' do + http_project_config_manager = Optimizely::HTTPProjectConfigManager.new( + sdk_key: 'QBw9gFM8oTn7ogY9ANCC1z' + ) + + project_instance = Optimizely::Project.new( + nil, nil, spy_logger, error_handler, + false, nil, nil, http_project_config_manager + ) + + project_instance.close + expect(project_instance.is_valid).to be false + end + + it 'shoud return optimizely as invalid for an API when close is called' do + WebMock.allow_net_connect! + http_project_config_manager = Optimizely::HTTPProjectConfigManager.new( + sdk_key: 'QBw9gFM8oTn7ogY9ANCC1z' + ) + + project_instance = Optimizely::Project.new( + config_body_JSON, nil, spy_logger, error_handler, + false, nil, nil, http_project_config_manager + ) + + sleep 1.5 + + expect(project_instance.activate('checkout_flow_experiment', 'test_user')).not_to eq(nil) + expect(project_instance.is_valid).to be true + + project_instance.close + + expect(project_instance.is_valid).to be false + expect(project_instance.activate('checkout_flow_experiment', 'test_user')).to eq(nil) + end + + it 'should not raise exception for static config manager' do + static_project_config_manager = Optimizely::StaticProjectConfigManager.new( + config_body_JSON, spy_logger, error_handler, false + ) + + project_instance = Optimizely::Project.new( + nil, nil, spy_logger, error_handler, + false, nil, nil, static_project_config_manager + ) + + project_instance.close + expect(project_instance.stopped).to be true + end + + it 'should not raise exception in any API using static config manager' do + static_project_config_manager = Optimizely::StaticProjectConfigManager.new( + config_body_JSON, spy_logger, error_handler, false + ) + + project_instance = Optimizely::Project.new( + nil, nil, spy_logger, error_handler, + false, nil, nil, static_project_config_manager + ) + + project_instance.close + + expect(project_instance.stopped).to be true + expect(project_instance.activate('checkout_flow_experiment', 'test_user')).to eq(nil) + expect(project_instance.get_variation('checkout_flow_experiment', 'test_user')).to eq(nil) + expect(project_instance.track('test_event', 'test_user')).to eq(nil) + expect(project_instance.is_feature_enabled('boolean_single_variable_feature', 'test_user')).to be false + expect(project_instance.get_enabled_features('test_user')).to be_empty + expect(project_instance.set_forced_variation('test_experiment', 'test', 'variation')).to eq(nil) + expect(project_instance.get_forced_variation('test_experiment', 'test_user')).to eq(nil) + expect(project_instance.get_feature_variable('integer_single_variable_feature', 'integer_variable', 'test_user', nil)) + .to eq(nil) + expect(project_instance.get_feature_variable_string('string_single_variable_feature', 'string_variable', 'test_user', nil)) + .to eq(nil) + expect(project_instance.get_feature_variable_boolean('boolean_single_variable_feature', 'boolean_variable', 'test_user', nil)) + .to eq(nil) + expect(project_instance.get_feature_variable_double('double_single_variable_feature', 'double_variable', 'test_user', nil)) + .to eq(nil) + expect(project_instance.get_feature_variable_integer('integer_single_variable_feature', 'integer_variable', 'test_user', nil)) + .to eq(nil) + end + end end From 899f3a6f0cda67b9edfd4ab9df5799fed1bd39bd Mon Sep 17 00:00:00 2001 From: rashidsp Date: Tue, 6 Aug 2019 20:35:04 +0500 Subject: [PATCH 13/30] fixes: failing test --- spec/project_spec.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/spec/project_spec.rb b/spec/project_spec.rb index b61c6e8e..293e3d5e 100644 --- a/spec/project_spec.rb +++ b/spec/project_spec.rb @@ -2834,7 +2834,7 @@ def callback(_args); end false, nil, nil, http_project_config_manager ) - sleep 1.5 + until http_project_config_manager.ready?; end expect(project_instance.activate('checkout_flow_experiment', 'test_user')).not_to eq(nil) expect(project_instance.is_valid).to be true From a31a9da4d2589c7e5e35ada015e335e0da7b3370 Mon Sep 17 00:00:00 2001 From: rashidsp Date: Wed, 7 Aug 2019 19:55:22 +0500 Subject: [PATCH 14/30] tests: adds SizedQueue --- lib/optimizely/event/batch_event_processor.rb | 6 ++--- spec/event/batch_event_processor_spec.rb | 25 +++++++++++-------- 2 files changed, 18 insertions(+), 13 deletions(-) diff --git a/lib/optimizely/event/batch_event_processor.rb b/lib/optimizely/event/batch_event_processor.rb index d1b6c2d5..f521934e 100644 --- a/lib/optimizely/event/batch_event_processor.rb +++ b/lib/optimizely/event/batch_event_processor.rb @@ -78,11 +78,11 @@ def process(user_event) @mutex.synchronize do begin @event_queue << user_event + @received.signal rescue Exception @logger.log(Logger::WARN, 'Payload not accepted by the queue.') return end - @received.signal end end @@ -96,7 +96,7 @@ def stop! @is_started = false @logger.log(Logger::WARN, 'Stopping scheduler.') - @thread.join + @thread.exit end private @@ -115,7 +115,7 @@ def run @mutex.synchronize do @received.wait(@mutex, 0.05) - item = @event_queue.pop + item = @event_queue.pop if @event_queue.length.positive? end if item.nil? diff --git a/spec/event/batch_event_processor_spec.rb b/spec/event/batch_event_processor_spec.rb index 37bdb9e8..313c0b98 100644 --- a/spec/event/batch_event_processor_spec.rb +++ b/spec/event/batch_event_processor_spec.rb @@ -38,7 +38,7 @@ MAX_DURATION_MS = 1000 before(:example) do - @event_queue = [] + @event_queue = SizedQueue.new(100) @event_dispatcher = Optimizely::EventDispatcher.new allow(@event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) @@ -51,6 +51,11 @@ ) end + after(:example) do + @event_processor.stop! + @event_queue.clear + end + it 'should log waring when service is already started' do @event_processor.start! expect(spy_logger).to have_received(:log).with(Logger::WARN, 'Service already started.').once @@ -67,7 +72,7 @@ expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once end - it 'it should flush the current batch when deadline exceeded' do + it 'should flush the current batch when deadline exceeded' do user_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) logger = spy('logger') event_processor = Optimizely::BatchEventProcessor.new( @@ -85,14 +90,14 @@ expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Deadline exceeded flushing current batch.') end - it 'it should flush the current batch when max batch size' do - allow(Optimizely::EventFactory).to receive(:create_log_event) + it 'should flush the current batch when max batch size' do + allow(Optimizely::EventFactory).to receive(:create_log_event).with(any_args) expected_batch = [] counter = 0 until counter >= 10 event['key'] = event['key'] + counter.to_s user_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) - expected_batch.unshift user_event + expected_batch << user_event @event_processor.process(user_event) counter += 1 end @@ -110,7 +115,7 @@ expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Flushing on max batch size!').once end - it 'it should dispatch the event when flush is called' do + it 'should dispatch the event when flush is called' do conversion_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) log_event = Optimizely::EventFactory.create_log_event(conversion_event, spy_logger) @@ -136,11 +141,11 @@ expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Received flush signal.').twice end - it 'it should flush on mismatch revision' do + it 'should flush on mismatch revision' do allow(project_config).to receive(:revision).and_return('1', '2') user_event1 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) user_event2 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) - log_event = Optimizely::EventFactory.create_log_event(user_event2, spy_logger) + log_event = Optimizely::EventFactory.create_log_event(user_event1, spy_logger) expect(user_event1.event_context[:revision]).to eq('1') @event_processor.process(user_event1) @@ -156,11 +161,11 @@ expect(spy_logger).not_to have_received(:log).with(Logger::DEBUG, 'Deadline exceeded flushing current batch.') end - it 'it should flush on mismatch project id' do + it 'should flush on mismatch project id' do allow(project_config).to receive(:project_id).and_return('X', 'Y') user_event1 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) user_event2 = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) - log_event = Optimizely::EventFactory.create_log_event(user_event2, spy_logger) + log_event = Optimizely::EventFactory.create_log_event(user_event1, spy_logger) expect(user_event1.event_context[:project_id]).to eq('X') @event_processor.process(user_event1) From 096ae95ca7d8f68cf913b5c9583dccf22063db9d Mon Sep 17 00:00:00 2001 From: rashidsp Date: Thu, 8 Aug 2019 11:23:26 +0500 Subject: [PATCH 15/30] Addresses feedback --- lib/optimizely/event/batch_event_processor.rb | 2 +- spec/event/batch_event_processor_spec.rb | 6 ++++-- 2 files changed, 5 insertions(+), 3 deletions(-) diff --git a/lib/optimizely/event/batch_event_processor.rb b/lib/optimizely/event/batch_event_processor.rb index f521934e..cda76a60 100644 --- a/lib/optimizely/event/batch_event_processor.rb +++ b/lib/optimizely/event/batch_event_processor.rb @@ -22,7 +22,7 @@ class BatchEventProcessor < EventProcessor # Events passed to the BatchEventProcessor are immediately added to a EventQueue. # The BatchEventProcessor maintains a single consumer thread that pulls events off of - attr_reader :event_queue + attr_reader :event_queue, :current_batch DEFAULT_BATCH_SIZE = 10 DEFAULT_BATCH_INTERVAL = 30_000 diff --git a/spec/event/batch_event_processor_spec.rb b/spec/event/batch_event_processor_spec.rb index 313c0b98..b955d4d9 100644 --- a/spec/event/batch_event_processor_spec.rb +++ b/spec/event/batch_event_processor_spec.rb @@ -94,7 +94,7 @@ allow(Optimizely::EventFactory).to receive(:create_log_event).with(any_args) expected_batch = [] counter = 0 - until counter >= 10 + until counter >= 11 event['key'] = event['key'] + counter.to_s user_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) expected_batch << user_event @@ -104,8 +104,10 @@ sleep 1 - expect(Optimizely::EventFactory).to have_received(:create_log_event).with(expected_batch, spy_logger).once + expected_batch.pop # Removes 11th element + expect(@event_processor.current_batch.size).to be 10 + expect(Optimizely::EventFactory).to have_received(:create_log_event).with(expected_batch, spy_logger).once expect(@event_dispatcher).to have_received(:dispatch_event).with( Optimizely::EventFactory.create_log_event(expected_batch, spy_logger) ).once From 1341177833262800a8c45ecf265bfc8d545353a3 Mon Sep 17 00:00:00 2001 From: rashidsp Date: Fri, 9 Aug 2019 18:43:20 +0500 Subject: [PATCH 16/30] Addresses feedback --- lib/optimizely.rb | 10 +++---- .../http_project_config_manager.rb | 17 +++++++++--- lib/optimizely/event/batch_event_processor.rb | 26 +++++++++---------- .../event/forwarding_event_processor.rb | 4 +-- spec/project_spec.rb | 24 +++++++++++------ 5 files changed, 50 insertions(+), 31 deletions(-) diff --git a/lib/optimizely.rb b/lib/optimizely.rb index 456002cc..7951623d 100644 --- a/lib/optimizely.rb +++ b/lib/optimizely.rb @@ -94,6 +94,7 @@ def initialize( else StaticProjectConfigManager.new(datafile, @logger, @error_handler, skip_json_validation) end + @decision_service = DecisionService.new(@logger, @user_profile_service) @event_processor = if event_processor.respond_to?(:process) @@ -101,7 +102,6 @@ def initialize( else ForwardingEventProcessor.new(@event_dispatcher, @logger, @notification_center) end - # @event_builder = EventBuilder.new(@logger) end # Buckets visitor and sends impression event to Optimizely. @@ -257,10 +257,10 @@ def track(event_key, user_id, attributes = nil, event_tags = nil) @logger.log(Logger::INFO, "Tracking event '#{event_key}' for user '#{user_id}'.") if @notification_center.notification_count(NotificationCenter::NOTIFICATION_TYPES[:TRACK]).positive? - conversion_event = EventFactory.create_log_event(user_event, @logger) + log_event = EventFactory.create_log_event(user_event, @logger) @notification_center.send_notifications( NotificationCenter::NOTIFICATION_TYPES[:TRACK], - event_key, user_id, attributes, event_tags, conversion_event + event_key, user_id, attributes, event_tags, log_event ) end nil @@ -713,10 +713,10 @@ def send_impression(config, experiment, variation_key, user_id, attributes = nil @logger.log(Logger::INFO, "Activating user '#{user_id}' in experiment '#{experiment_key}'.") variation = config.get_variation_from_id(experiment_key, variation_id) - impression_event = EventFactory.create_log_event(user_event, @logger) + log_event = EventFactory.create_log_event(user_event, @logger) @notification_center.send_notifications( NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], - experiment, user_id, attributes, variation, impression_event + experiment, user_id, attributes, variation, log_event ) end diff --git a/lib/optimizely/config_manager/http_project_config_manager.rb b/lib/optimizely/config_manager/http_project_config_manager.rb index b43db688..2cc0a593 100644 --- a/lib/optimizely/config_manager/http_project_config_manager.rb +++ b/lib/optimizely/config_manager/http_project_config_manager.rb @@ -30,7 +30,7 @@ module Optimizely class HTTPProjectConfigManager < ProjectConfigManager # Config manager that polls for the datafile and updated ProjectConfig based on an update interval. - attr_reader :config, :stopped + attr_reader :config, :started # Initialize config manager. One of sdk_key or url has to be set to be able to use. # @@ -72,6 +72,7 @@ def initialize( @last_modified = nil @async_scheduler = AsyncScheduler.new(method(:fetch_datafile_config), @polling_interval, auto_update, @logger) @async_scheduler.start! if start_by_default == true + @started = start_by_default @skip_json_validation = skip_json_validation @notification_center = notification_center.is_a?(Optimizely::NotificationCenter) ? notification_center : NotificationCenter.new(@logger, @error_handler) @config = datafile.nil? ? nil : DatafileProjectConfig.create(datafile, @logger, @error_handler, @skip_json_validation) @@ -84,14 +85,24 @@ def ready? end def start! + if @started + @logger.log(Logger::WARN, 'Manager already started.') + return + end + @async_scheduler.start! - @stopped = false + @started = true end def stop! + unless @started + @logger.log(Logger::WARN, 'Not pausing. Manager has not been started.') + return + end + @async_scheduler.stop! @config = nil - @stopped = true + @started = false end def get_config diff --git a/lib/optimizely/event/batch_event_processor.rb b/lib/optimizely/event/batch_event_processor.rb index 5abf0895..aecfdba4 100644 --- a/lib/optimizely/event/batch_event_processor.rb +++ b/lib/optimizely/event/batch_event_processor.rb @@ -22,7 +22,7 @@ class BatchEventProcessor < EventProcessor # Events passed to the BatchEventProcessor are immediately added to a EventQueue. # The BatchEventProcessor maintains a single consumer thread that pulls events off of - attr_reader :event_queue + attr_reader :event_queue, :started DEFAULT_BATCH_SIZE = 10 DEFAULT_BATCH_INTERVAL = 30_000 @@ -32,34 +32,34 @@ class BatchEventProcessor < EventProcessor SHUTDOWN_SIGNAL = 'SHUTDOWN_SIGNAL' def initialize( - event_queue:, + event_queue: SizedQueue.new(DEFAULT_QUEUE_CAPACITY), event_dispatcher:, - batch_size:, - flush_interval:, - logger: nil, + batch_size: DEFAULT_BATCH_SIZE, + flush_interval: DEFAULT_BATCH_INTERVAL, + logger: NoOpLogger.new, notification_center: nil ) - @event_queue = event_queue || SizedQueue.new(DEFAULT_QUEUE_CAPACITY) + @event_queue = event_queue @event_dispatcher = event_dispatcher - @batch_size = batch_size || DEFAULT_BATCH_SIZE - @flush_interval = flush_interval || DEFAULT_BATCH_INTERVAL - @logger = logger || NoOpLogger.new + @batch_size = batch_size + @flush_interval = flush_interval + @logger = logger @notification_center = notification_center @mutex = Mutex.new @received = ConditionVariable.new @current_batch = [] - @is_started = false + @started = false start! end def start! - if @is_started == true + if @started == true @logger.log(Logger::WARN, 'Service already started.') return end @flushing_interval_deadline = Helpers::DateTimeUtils.create_timestamp + @flush_interval @thread = Thread.new { run } - @is_started = true + @started = true end def flush @@ -96,7 +96,7 @@ def stop! @received.signal end - @is_started = false + @started = false @logger.log(Logger::WARN, 'Stopping scheduler.') @thread.exit end diff --git a/lib/optimizely/event/forwarding_event_processor.rb b/lib/optimizely/event/forwarding_event_processor.rb index 31c0b539..81596b68 100644 --- a/lib/optimizely/event/forwarding_event_processor.rb +++ b/lib/optimizely/event/forwarding_event_processor.rb @@ -20,9 +20,9 @@ module Optimizely class ForwardingEventProcessor < EventProcessor # ForwardingEventProcessor is a basic transformation stage for converting # the event batch into a LogEvent to be dispatched. - def initialize(event_dispatcher, logger, notification_center = nil) + def initialize(event_dispatcher, logger = nil, notification_center = nil) @event_dispatcher = event_dispatcher - @logger = logger + @logger = logger || NoOpLogger.new @notification_center = notification_center end diff --git a/spec/project_spec.rb b/spec/project_spec.rb index 293e3d5e..972cf1bd 100644 --- a/spec/project_spec.rb +++ b/spec/project_spec.rb @@ -19,8 +19,10 @@ require 'optimizely' require 'optimizely/audience' require 'optimizely/config_manager/http_project_config_manager' -require 'optimizely/helpers/validator' +require 'optimizely/event_dispatcher' +require 'optimizely/event/batch_event_processor' require 'optimizely/exceptions' +require 'optimizely/helpers/validator' require 'optimizely/version' describe 'Optimizely' do @@ -2793,20 +2795,26 @@ def callback(_args); end end describe '.close' do - it 'should stop config manager when optimizely close is called' do - http_project_config_manager = Optimizely::HTTPProjectConfigManager.new( + it 'should stop config manager and event processor when optimizely close is called' do + config_manager = Optimizely::HTTPProjectConfigManager.new( sdk_key: 'QBw9gFM8oTn7ogY9ANCC1z', start_by_default: true ) - project_instance = Optimizely::Project.new( - config_body_JSON, nil, spy_logger, error_handler, - false, nil, nil, http_project_config_manager - ) + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: Optimizely::EventDispatcher.new) + + Optimizely::Project.new(config_body_JSON, nil, spy_logger, error_handler) + + project_instance = Optimizely::Project.new(nil, nil, nil, nil, true, nil, nil, config_manager, nil, event_processor) + + expect(config_manager.started).to be true + expect(event_processor.started).to be true project_instance.close + + expect(config_manager.started).to be false + expect(event_processor.started).to be false expect(project_instance.stopped).to be true - expect(http_project_config_manager.stopped).to be true end it 'should stop invalid object' do From ededaa70e6827d4f2bfb6d6af74583249a638927 Mon Sep 17 00:00:00 2001 From: rashidsp Date: Fri, 9 Aug 2019 20:05:32 +0500 Subject: [PATCH 17/30] reverts log-event changes --- lib/optimizely.rb | 16 +++----- lib/optimizely/event/batch_event_processor.rb | 8 +--- .../event/forwarding_event_processor.rb | 8 +--- lib/optimizely/notification_center.rb | 5 --- spec/event/batch_event_processor_spec.rb | 40 +------------------ spec/event/forwarding_event_processor_spec.rb | 17 ++------ spec/notification_center_spec.rb | 31 -------------- spec/project_spec.rb | 20 ++-------- 8 files changed, 15 insertions(+), 130 deletions(-) diff --git a/lib/optimizely.rb b/lib/optimizely.rb index 7951623d..07766ec4 100644 --- a/lib/optimizely.rb +++ b/lib/optimizely.rb @@ -100,7 +100,7 @@ def initialize( @event_processor = if event_processor.respond_to?(:process) event_processor else - ForwardingEventProcessor.new(@event_dispatcher, @logger, @notification_center) + ForwardingEventProcessor.new(@event_dispatcher, @logger) end end @@ -256,13 +256,11 @@ def track(event_key, user_id, attributes = nil, event_tags = nil) @event_processor.process(user_event) @logger.log(Logger::INFO, "Tracking event '#{event_key}' for user '#{user_id}'.") - if @notification_center.notification_count(NotificationCenter::NOTIFICATION_TYPES[:TRACK]).positive? - log_event = EventFactory.create_log_event(user_event, @logger) - @notification_center.send_notifications( - NotificationCenter::NOTIFICATION_TYPES[:TRACK], - event_key, user_id, attributes, event_tags, log_event - ) - end + log_event = EventFactory.create_log_event(user_event, @logger) + @notification_center.send_notifications( + NotificationCenter::NOTIFICATION_TYPES[:TRACK], + event_key, user_id, attributes, event_tags, log_event + ) nil end @@ -709,8 +707,6 @@ def send_impression(config, experiment, variation_key, user_id, attributes = nil user_event = UserEventFactory.create_impression_event(config, experiment, variation_id, user_id, attributes) @event_processor.process(user_event) - return unless @notification_center.notification_count(NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE]).positive? - @logger.log(Logger::INFO, "Activating user '#{user_id}' in experiment '#{experiment_key}'.") variation = config.get_variation_from_id(experiment_key, variation_id) log_event = EventFactory.create_log_event(user_event, @logger) diff --git a/lib/optimizely/event/batch_event_processor.rb b/lib/optimizely/event/batch_event_processor.rb index aecfdba4..141d7649 100644 --- a/lib/optimizely/event/batch_event_processor.rb +++ b/lib/optimizely/event/batch_event_processor.rb @@ -36,15 +36,13 @@ def initialize( event_dispatcher:, batch_size: DEFAULT_BATCH_SIZE, flush_interval: DEFAULT_BATCH_INTERVAL, - logger: NoOpLogger.new, - notification_center: nil + logger: NoOpLogger.new ) @event_queue = event_queue @event_dispatcher = event_dispatcher @batch_size = batch_size @flush_interval = flush_interval @logger = logger - @notification_center = notification_center @mutex = Mutex.new @received = ConditionVariable.new @current_batch = [] @@ -150,10 +148,6 @@ def flush_queue! log_event = Optimizely::EventFactory.create_log_event(@current_batch, @logger) begin @event_dispatcher.dispatch_event(log_event) - @notification_center&.send_notifications( - NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], - log_event - ) rescue StandardError => e @logger.log(Logger::ERROR, "Error dispatching event: #{log_event} #{e.message}.") end diff --git a/lib/optimizely/event/forwarding_event_processor.rb b/lib/optimizely/event/forwarding_event_processor.rb index 81596b68..679174ae 100644 --- a/lib/optimizely/event/forwarding_event_processor.rb +++ b/lib/optimizely/event/forwarding_event_processor.rb @@ -20,10 +20,9 @@ module Optimizely class ForwardingEventProcessor < EventProcessor # ForwardingEventProcessor is a basic transformation stage for converting # the event batch into a LogEvent to be dispatched. - def initialize(event_dispatcher, logger = nil, notification_center = nil) + def initialize(event_dispatcher, logger = nil) @event_dispatcher = event_dispatcher @logger = logger || NoOpLogger.new - @notification_center = notification_center end def process(user_event) @@ -31,11 +30,6 @@ def process(user_event) begin @event_dispatcher.dispatch_event(log_event) - - @notification_center&.send_notifications( - NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], - log_event - ) rescue StandardError => e @logger.log(Logger::ERROR, "Error dispatching event: #{log_event} #{e.message}.") end diff --git a/lib/optimizely/notification_center.rb b/lib/optimizely/notification_center.rb index 4a3b0169..53d6dc3d 100644 --- a/lib/optimizely/notification_center.rb +++ b/lib/optimizely/notification_center.rb @@ -24,7 +24,6 @@ class NotificationCenter # DEPRECATED: ACTIVATE notification type is deprecated since relase 3.1.0. ACTIVATE: 'ACTIVATE: experiment, user_id, attributes, variation, event', DECISION: 'DECISION: type, user_id, attributes, decision_info', - LOG_EVENT: 'LOG_EVENT: type, log_event', OPTIMIZELY_CONFIG_UPDATE: 'optimizely_config_update', TRACK: 'TRACK: event_key, user_id, attributes, event_tags, event' }.freeze @@ -138,10 +137,6 @@ def send_notifications(notification_type, *args) end end - def notification_count(notification_type) - @notifications.include?(notification_type) ? @notifications[notification_type].count : 0 - end - private def notification_type_valid?(notification_type) diff --git a/spec/event/batch_event_processor_spec.rb b/spec/event/batch_event_processor_spec.rb index b274031e..313c0b98 100644 --- a/spec/event/batch_event_processor_spec.rb +++ b/spec/event/batch_event_processor_spec.rb @@ -42,16 +42,12 @@ @event_dispatcher = Optimizely::EventDispatcher.new allow(@event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) - @notification_center = Optimizely::NotificationCenter.new(spy_logger, error_handler) - allow(@notification_center).to receive(:send_notifications) - @event_processor = Optimizely::BatchEventProcessor.new( event_queue: @event_queue, event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - logger: spy_logger, - notification_center: @notification_center + logger: spy_logger ) end @@ -208,38 +204,4 @@ @event_processor.stop! expect(@event_dispatcher).not_to have_received(:dispatch_event) end - - it 'should send log event notification when event is dispatched' do - conversion_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) - log_event = Optimizely::EventFactory.create_log_event(conversion_event, spy_logger) - - @event_processor.process(conversion_event) - sleep 1.5 - - expect(@notification_center).to have_received(:send_notifications).with( - Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], - log_event - ).once - - expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once - end - - it 'should log an error when dispatch event raises timeout exception' do - conversion_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) - log_event = Optimizely::EventFactory.create_log_event(conversion_event, spy_logger) - allow(Optimizely::EventFactory).to receive(:create_log_event).and_return(log_event) - - timeout_error = Timeout::Error.new - allow(@event_dispatcher).to receive(:dispatch_event).and_raise(timeout_error) - - @event_processor.process(conversion_event) - sleep 1.5 - - expect(@notification_center).not_to have_received(:send_notifications) - - expect(spy_logger).to have_received(:log).once.with( - Logger::ERROR, - "Error dispatching event: #{log_event} Timeout::Error." - ) - end end diff --git a/spec/event/forwarding_event_processor_spec.rb b/spec/event/forwarding_event_processor_spec.rb index dbd69901..7be502f0 100644 --- a/spec/event/forwarding_event_processor_spec.rb +++ b/spec/event/forwarding_event_processor_spec.rb @@ -69,28 +69,19 @@ end describe '.process' do - it 'should dispatch and send log event when valid event is provided' do - notification_center = Optimizely::NotificationCenter.new(spy_logger, error_handler) - allow(notification_center).to receive(:send_notifications) + it 'should dispatch log event when valid event is provided' do forwarding_event_processor = Optimizely::ForwardingEventProcessor.new( - @event_dispatcher, spy_logger, notification_center + @event_dispatcher, spy_logger ) forwarding_event_processor.process(@conversion_event) - expect(notification_center).to have_received(:send_notifications).with( - Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], - Optimizely::Event.new(:post, log_url, @expected_conversion_params, post_headers) - ).once - expect(@event_dispatcher).to have_received(:dispatch_event).with( Optimizely::Event.new(:post, log_url, @expected_conversion_params, post_headers) ).once end it 'should log an error when dispatch event raises timeout exception' do - notification_center = Optimizely::NotificationCenter.new(spy_logger, error_handler) - allow(notification_center).to receive(:send_notifications) log_event = Optimizely::Event.new(:post, log_url, @expected_conversion_params, post_headers) allow(Optimizely::EventFactory).to receive(:create_log_event).and_return(log_event) @@ -98,13 +89,11 @@ allow(@event_dispatcher).to receive(:dispatch_event).and_raise(timeout_error) forwarding_event_processor = Optimizely::ForwardingEventProcessor.new( - @event_dispatcher, spy_logger, notification_center + @event_dispatcher, spy_logger ) forwarding_event_processor.process(@conversion_event) - expect(notification_center).not_to have_received(:send_notifications) - expect(spy_logger).to have_received(:log).once.with( Logger::ERROR, "Error dispatching event: #{log_event} Timeout::Error." diff --git a/spec/notification_center_spec.rb b/spec/notification_center_spec.rb index be3a4b8e..540c4420 100644 --- a/spec/notification_center_spec.rb +++ b/spec/notification_center_spec.rb @@ -486,37 +486,6 @@ def deliver_three; end end end - describe '.notification_count' do - it 'should return count of added notification types' do - notification_center.add_notification_listener( - Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], - @callback_reference - ) - - notification_center.add_notification_listener( - Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], - method(:test) - ) - - notification_center.add_notification_listener( - Optimizely::NotificationCenter::NOTIFICATION_TYPES[:TRACK], - method(:test) - ) - - expect( - notification_center.notification_count(Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE]) - ).to eq(2) - - expect( - notification_center.notification_count(Optimizely::NotificationCenter::NOTIFICATION_TYPES[:TRACK]) - ).to eq(1) - - expect( - notification_center.notification_count(Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT]) - ).to eq(0) - end - end - describe '@error_handler' do let(:raise_error_handler) { Optimizely::RaiseErrorHandler.new } let(:notification_center) { Optimizely::NotificationCenter.new(spy_logger, raise_error_handler) } diff --git a/spec/project_spec.rb b/spec/project_spec.rb index 972cf1bd..e36c72ed 100644 --- a/spec/project_spec.rb +++ b/spec/project_spec.rb @@ -605,11 +605,6 @@ def callback(_args); end Optimizely::NotificationCenter::NOTIFICATION_TYPES[:DECISION], any_args ).ordered - # Log event - expect(project_instance.notification_center).to receive(:send_notifications).with( - Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], any_args - ).ordered - # Activate listener expect(project_instance.notification_center).to receive(:send_notifications).with( Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], @@ -725,6 +720,7 @@ def callback(_args); end expect(notification_center).to receive(:send_notifications).ordered expect(notification_center).to receive(:send_notifications).ordered + http_project_config_manager = Optimizely::HTTPProjectConfigManager.new( url: 'https://cdn.optimizely.com/datafiles/QBw9gFM8oTn7ogY9ANCC1z.json', notification_center: notification_center @@ -750,6 +746,7 @@ def callback(_args); end ).ordered expect(notification_center).to receive(:send_notifications).ordered + expect(notification_center).to receive(:send_notifications).ordered http_project_config_manager = Optimizely::HTTPProjectConfigManager.new( @@ -908,11 +905,6 @@ def callback(_args); end allow(project_instance.event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) conversion_event = Optimizely::Event.new(:post, conversion_log_url, params, post_headers) - expect(project_instance.notification_center).to receive(:send_notifications) - .with( - Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], any_args - ).ordered - expect(project_instance.notification_center).to receive(:send_notifications) .with( Optimizely::NotificationCenter::NOTIFICATION_TYPES[:TRACK], @@ -1505,11 +1497,6 @@ def callback(_args); end Optimizely::DecisionService::DECISION_SOURCES['FEATURE_TEST'] ) - expect(project_instance.notification_center).to receive(:send_notifications) - .with( - Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], any_args - ).ordered - expect(project_instance.notification_center).to receive(:send_notifications) .with( Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], @@ -1590,7 +1577,6 @@ def callback(_args); end ) allow(project_instance.decision_service).to receive(:get_variation_for_feature).and_return(decision_to_return) - expect(project_instance.notification_center).to receive(:send_notifications).ordered # DECISION listener called when the user is in experiment with variation feature off. @@ -1778,7 +1764,7 @@ def callback(_args); end ) expect(project_instance.notification_center).to receive(:send_notifications).twice.with( - Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], any_args + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], any_args ) expect(project_instance.notification_center).to receive(:send_notifications).once.with( From 61e3426c6a9d2056df9c18cb0b603b4802b889cf Mon Sep 17 00:00:00 2001 From: rashidsp Date: Fri, 9 Aug 2019 22:00:48 +0500 Subject: [PATCH 18/30] config manager update --- lib/optimizely.rb | 2 ++ .../http_project_config_manager.rb | 14 ++++---- spec/project_spec.rb | 36 ++++--------------- 3 files changed, 15 insertions(+), 37 deletions(-) diff --git a/lib/optimizely.rb b/lib/optimizely.rb index 07766ec4..7eb634f7 100644 --- a/lib/optimizely.rb +++ b/lib/optimizely.rb @@ -33,6 +33,7 @@ require_relative 'optimizely/helpers/variable_type' require_relative 'optimizely/logger' require_relative 'optimizely/notification_center' + module Optimizely class Project attr_reader :notification_center @@ -53,6 +54,7 @@ class Project # Must provide at least one of datafile or sdk_key. # @param config_manager - Optional Responds to get_config. # @param notification_center - Optional Instance of NotificationCenter. + # @param event_processor - Optional Responds to process. def initialize( datafile = nil, diff --git a/lib/optimizely/config_manager/http_project_config_manager.rb b/lib/optimizely/config_manager/http_project_config_manager.rb index 2cc0a593..da92d0e4 100644 --- a/lib/optimizely/config_manager/http_project_config_manager.rb +++ b/lib/optimizely/config_manager/http_project_config_manager.rb @@ -30,7 +30,7 @@ module Optimizely class HTTPProjectConfigManager < ProjectConfigManager # Config manager that polls for the datafile and updated ProjectConfig based on an update interval. - attr_reader :config, :started + attr_reader :config, :closed # Initialize config manager. One of sdk_key or url has to be set to be able to use. # @@ -72,7 +72,7 @@ def initialize( @last_modified = nil @async_scheduler = AsyncScheduler.new(method(:fetch_datafile_config), @polling_interval, auto_update, @logger) @async_scheduler.start! if start_by_default == true - @started = start_by_default + @closed = false @skip_json_validation = skip_json_validation @notification_center = notification_center.is_a?(Optimizely::NotificationCenter) ? notification_center : NotificationCenter.new(@logger, @error_handler) @config = datafile.nil? ? nil : DatafileProjectConfig.create(datafile, @logger, @error_handler, @skip_json_validation) @@ -85,24 +85,24 @@ def ready? end def start! - if @started - @logger.log(Logger::WARN, 'Manager already started.') + if @closed + @logger.log(Logger::WARN, 'Not starting. Already closed.') return end @async_scheduler.start! - @started = true + @closed = false end def stop! - unless @started + if @closed @logger.log(Logger::WARN, 'Not pausing. Manager has not been started.') return end @async_scheduler.stop! @config = nil - @started = false + @closed = true end def get_config diff --git a/spec/project_spec.rb b/spec/project_spec.rb index e36c72ed..ece7b934 100644 --- a/spec/project_spec.rb +++ b/spec/project_spec.rb @@ -587,11 +587,6 @@ class InvalidErrorHandler; end end it 'should log and send activate notification when an impression event is dispatched' do - def callback(_args); end - project_instance.notification_center.add_notification_listener( - Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], - method(:callback) - ) variation_to_return = project_instance.config_manager.config.get_variation_from_id('test_experiment', '111128') allow(project_instance.decision_service.bucketer).to receive(:bucket).and_return(variation_to_return) allow(project_instance.event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) @@ -720,7 +715,6 @@ def callback(_args); end expect(notification_center).to receive(:send_notifications).ordered expect(notification_center).to receive(:send_notifications).ordered - http_project_config_manager = Optimizely::HTTPProjectConfigManager.new( url: 'https://cdn.optimizely.com/datafiles/QBw9gFM8oTn7ogY9ANCC1z.json', notification_center: notification_center @@ -746,7 +740,6 @@ def callback(_args); end ).ordered expect(notification_center).to receive(:send_notifications).ordered - expect(notification_center).to receive(:send_notifications).ordered http_project_config_manager = Optimizely::HTTPProjectConfigManager.new( @@ -891,26 +884,15 @@ def callback(_args); end it 'should send track notification and properly track an event by calling dispatch_event with right params with revenue provided' do params = @expected_track_event_params - params[:visitors][0][:snapshots][0][:events][0].merge!( - revenue: 42, - tags: {'revenue' => 42} - ) - - def callback(_args); end - project_instance.notification_center.add_notification_listener( - Optimizely::NotificationCenter::NOTIFICATION_TYPES[:TRACK], - method(:callback) - ) - + params[:visitors][0][:snapshots][0][:events][0].merge!(revenue: 42, + tags: {'revenue' => 42}) allow(project_instance.event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) conversion_event = Optimizely::Event.new(:post, conversion_log_url, params, post_headers) - expect(project_instance.notification_center).to receive(:send_notifications) .with( Optimizely::NotificationCenter::NOTIFICATION_TYPES[:TRACK], 'test_event', 'test_user', nil, {'revenue' => 42}, conversion_event - ).ordered - + ).once project_instance.track('test_event', 'test_user', nil, 'revenue' => 42) expect(project_instance.event_dispatcher).to have_received(:dispatch_event).with(Optimizely::Event.new(:post, conversion_log_url, params, post_headers)).once end @@ -1481,14 +1463,7 @@ def callback(_args); end end it 'should return true, send activate notification and an impression if the user is bucketed into a feature experiment' do - def callback(_args); end - project_instance.notification_center.add_notification_listener( - Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], - method(:callback) - ) - allow(project_instance.event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) - experiment_to_return = config_body['experiments'][3] variation_to_return = experiment_to_return['variations'][0] decision_to_return = Optimizely::DecisionService::Decision.new( @@ -1577,6 +1552,7 @@ def callback(_args); end ) allow(project_instance.decision_service).to receive(:get_variation_for_feature).and_return(decision_to_return) + expect(project_instance.notification_center).to receive(:send_notifications).ordered # DECISION listener called when the user is in experiment with variation feature off. @@ -2793,12 +2769,12 @@ def callback(_args); end project_instance = Optimizely::Project.new(nil, nil, nil, nil, true, nil, nil, config_manager, nil, event_processor) - expect(config_manager.started).to be true + expect(config_manager.closed).to be false expect(event_processor.started).to be true project_instance.close - expect(config_manager.started).to be false + expect(config_manager.closed).to be true expect(event_processor.started).to be false expect(project_instance.stopped).to be true end From b409edfa3d73ffce3b19ead03c202fccd58a9757 Mon Sep 17 00:00:00 2001 From: Sohail Hussain Date: Thu, 15 Aug 2019 03:32:46 -0700 Subject: [PATCH 19/30] Removed verbose log. --- lib/optimizely/event/batch_event_processor.rb | 1 - 1 file changed, 1 deletion(-) diff --git a/lib/optimizely/event/batch_event_processor.rb b/lib/optimizely/event/batch_event_processor.rb index cda76a60..76341163 100644 --- a/lib/optimizely/event/batch_event_processor.rb +++ b/lib/optimizely/event/batch_event_processor.rb @@ -119,7 +119,6 @@ def run end if item.nil? - @logger.log(Logger::DEBUG, 'Empty item, sleeping for 50ms.') sleep(0.05) next end From 2fd378faed133f91433344ab860b1e396d8276c1 Mon Sep 17 00:00:00 2001 From: rashidsp Date: Fri, 16 Aug 2019 12:54:06 +0500 Subject: [PATCH 20/30] Resolves unit test --- spec/event/batch_event_processor_spec.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/spec/event/batch_event_processor_spec.rb b/spec/event/batch_event_processor_spec.rb index b955d4d9..6ceb281c 100644 --- a/spec/event/batch_event_processor_spec.rb +++ b/spec/event/batch_event_processor_spec.rb @@ -131,7 +131,7 @@ event_processor.process(conversion_event) event_processor.flush - sleep 0.5 + sleep 1.5 event_processor.process(conversion_event) event_processor.flush From efab9f4a8b6093bf144a8c30a828e13e770c5449 Mon Sep 17 00:00:00 2001 From: rashidsp Date: Fri, 16 Aug 2019 14:34:50 +0500 Subject: [PATCH 21/30] removes log --- lib/optimizely/event/batch_event_processor.rb | 5 +---- spec/event/batch_event_processor_spec.rb | 2 -- 2 files changed, 1 insertion(+), 6 deletions(-) diff --git a/lib/optimizely/event/batch_event_processor.rb b/lib/optimizely/event/batch_event_processor.rb index 76341163..e8ed3e0a 100644 --- a/lib/optimizely/event/batch_event_processor.rb +++ b/lib/optimizely/event/batch_event_processor.rb @@ -134,10 +134,7 @@ def run next end - if item.is_a? Optimizely::UserEvent - @logger.log(Logger::DEBUG, "Received add to batch signal. with event: #{item.event['key']}.") - add_to_batch(item) - end + add_to_batch(item) if item.is_a? Optimizely::UserEvent end end diff --git a/spec/event/batch_event_processor_spec.rb b/spec/event/batch_event_processor_spec.rb index 6ceb281c..554c5e5b 100644 --- a/spec/event/batch_event_processor_spec.rb +++ b/spec/event/batch_event_processor_spec.rb @@ -111,8 +111,6 @@ expect(@event_dispatcher).to have_received(:dispatch_event).with( Optimizely::EventFactory.create_log_event(expected_batch, spy_logger) ).once - - expect(spy_logger).to have_received(:log).with(Logger::DEBUG, "Received add to batch signal. with event: #{event['key']}.").exactly(10).times expect(spy_logger).to have_received(:log).with(Logger::DEBUG, "Adding user event: #{event['key']} to batch.").exactly(10).times expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Flushing on max batch size!').once end From 3c4a9805b9a9822b0ce03e62816fac5133cb2e81 Mon Sep 17 00:00:00 2001 From: rashidsp Date: Fri, 16 Aug 2019 19:54:45 +0500 Subject: [PATCH 22/30] adds positive number conditions --- lib/optimizely/event/batch_event_processor.rb | 29 ++++++---- spec/event/batch_event_processor_spec.rb | 54 +++++++++++++++++++ 2 files changed, 74 insertions(+), 9 deletions(-) diff --git a/lib/optimizely/event/batch_event_processor.rb b/lib/optimizely/event/batch_event_processor.rb index e8ed3e0a..99c48dbe 100644 --- a/lib/optimizely/event/batch_event_processor.rb +++ b/lib/optimizely/event/batch_event_processor.rb @@ -16,13 +16,14 @@ # limitations under the License. # require_relative 'event_processor' +require_relative '../helpers/validator' module Optimizely class BatchEventProcessor < EventProcessor # BatchEventProcessor is a batched implementation of the Interface EventProcessor. # Events passed to the BatchEventProcessor are immediately added to a EventQueue. # The BatchEventProcessor maintains a single consumer thread that pulls events off of - attr_reader :event_queue, :current_batch + attr_reader :event_queue, :current_batch, :batch_size, :flush_interval DEFAULT_BATCH_SIZE = 10 DEFAULT_BATCH_INTERVAL = 30_000 @@ -32,17 +33,21 @@ class BatchEventProcessor < EventProcessor SHUTDOWN_SIGNAL = 'SHUTDOWN_SIGNAL' def initialize( - event_queue:, + event_queue: SizedQueue.new(DEFAULT_QUEUE_CAPACITY), event_dispatcher:, - batch_size:, - flush_interval:, - logger: nil + batch_size: DEFAULT_BATCH_SIZE, + flush_interval: DEFAULT_BATCH_INTERVAL, + logger: NoOpLogger.new ) - @event_queue = event_queue || SizedQueue.new(DEFAULT_QUEUE_CAPACITY) + @event_queue = event_queue @event_dispatcher = event_dispatcher - @batch_size = batch_size || DEFAULT_BATCH_SIZE - @flush_interval = flush_interval || DEFAULT_BATCH_INTERVAL - @logger = logger || NoOpLogger.new + @batch_size = if (batch_size.is_a? Integer) && positive_number?(batch_size) + batch_size + else + DEFAULT_BATCH_SIZE + end + @flush_interval = positive_number?(flush_interval) ? flush_interval : DEFAULT_BATCH_INTERVAL + @logger = logger @mutex = Mutex.new @received = ConditionVariable.new @current_batch = [] @@ -185,5 +190,11 @@ def should_split?(user_event) end false end + + def positive_number?(value) + # Returns true if the given value is positive finite number. + # false otherwise. + Helpers::Validator.finite_number?(value) && value.positive? + end end end diff --git a/spec/event/batch_event_processor_spec.rb b/spec/event/batch_event_processor_spec.rb index 554c5e5b..0f94c824 100644 --- a/spec/event/batch_event_processor_spec.rb +++ b/spec/event/batch_event_processor_spec.rb @@ -204,4 +204,58 @@ @event_processor.stop! expect(@event_dispatcher).not_to have_received(:dispatch_event) end + + it 'should set default batch size when provided invalid' do + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher) + expect(event_processor.batch_size).to eq(10) + event_processor.stop! + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, batch_size: 'test') + expect(event_processor.batch_size).to eq(10) + event_processor.stop! + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, batch_size: []) + expect(event_processor.batch_size).to eq(10) + event_processor.stop! + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, batch_size: 0) + expect(event_processor.batch_size).to eq(10) + event_processor.stop! + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, batch_size: -5) + expect(event_processor.batch_size).to eq(10) + event_processor.stop! + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, batch_size: 5.5) + expect(event_processor.batch_size).to eq(10) + event_processor.stop! + end + + it 'should set batch size when provided valid' do + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, batch_size: 5) + expect(event_processor.batch_size).to eq(5) + event_processor.stop! + end + + it 'should set default flush interval when provided invalid' do + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher) + expect(event_processor.flush_interval).to eq(30_000) + event_processor.stop! + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, flush_interval: 'test') + expect(event_processor.flush_interval).to eq(30_000) + event_processor.stop! + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, flush_interval: []) + expect(event_processor.flush_interval).to eq(30_000) + event_processor.stop! + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, flush_interval: 0) + expect(event_processor.flush_interval).to eq(30_000) + event_processor.stop! + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, flush_interval: -5) + expect(event_processor.flush_interval).to eq(30_000) + event_processor.stop! + end + + it 'should set flush interval when provided valid' do + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, flush_interval: 2000) + expect(event_processor.flush_interval).to eq(2000) + event_processor.stop! + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, flush_interval: 2000.5) + expect(event_processor.flush_interval).to eq(2000.5) + event_processor.stop! + end end From 6634c544ae6143296740ea14162bf1a987fdfcb1 Mon Sep 17 00:00:00 2001 From: rashidsp Date: Mon, 19 Aug 2019 16:19:46 +0500 Subject: [PATCH 23/30] feat(notification-center): Adds LogEvent notification --- lib/optimizely.rb | 15 +++--- lib/optimizely/event/batch_event_processor.rb | 8 +++- .../event/forwarding_event_processor.rb | 7 ++- lib/optimizely/notification_center.rb | 5 ++ spec/event/batch_event_processor_spec.rb | 39 +++++++++++++++- spec/event/forwarding_event_processor_spec.rb | 18 ++++++-- spec/notification_center_spec.rb | 31 +++++++++++++ spec/project_spec.rb | 46 ++++++++++++++++++- 8 files changed, 156 insertions(+), 13 deletions(-) diff --git a/lib/optimizely.rb b/lib/optimizely.rb index 7eb634f7..1f1cad71 100644 --- a/lib/optimizely.rb +++ b/lib/optimizely.rb @@ -102,7 +102,7 @@ def initialize( @event_processor = if event_processor.respond_to?(:process) event_processor else - ForwardingEventProcessor.new(@event_dispatcher, @logger) + ForwardingEventProcessor.new(@event_dispatcher, @logger, @notification_center) end end @@ -258,11 +258,13 @@ def track(event_key, user_id, attributes = nil, event_tags = nil) @event_processor.process(user_event) @logger.log(Logger::INFO, "Tracking event '#{event_key}' for user '#{user_id}'.") - log_event = EventFactory.create_log_event(user_event, @logger) - @notification_center.send_notifications( - NotificationCenter::NOTIFICATION_TYPES[:TRACK], - event_key, user_id, attributes, event_tags, log_event - ) + if @notification_center.notification_count(NotificationCenter::NOTIFICATION_TYPES[:TRACK]).positive? + log_event = EventFactory.create_log_event(user_event, @logger) + @notification_center.send_notifications( + NotificationCenter::NOTIFICATION_TYPES[:TRACK], + event_key, user_id, attributes, event_tags, log_event + ) + end nil end @@ -708,6 +710,7 @@ def send_impression(config, experiment, variation_key, user_id, attributes = nil variation_id = config.get_variation_id_from_key(experiment_key, variation_key) user_event = UserEventFactory.create_impression_event(config, experiment, variation_id, user_id, attributes) @event_processor.process(user_event) + return unless @notification_center.notification_count(NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE]).positive? @logger.log(Logger::INFO, "Activating user '#{user_id}' in experiment '#{experiment_key}'.") variation = config.get_variation_from_id(experiment_key, variation_id) diff --git a/lib/optimizely/event/batch_event_processor.rb b/lib/optimizely/event/batch_event_processor.rb index e8893891..7817d5a8 100644 --- a/lib/optimizely/event/batch_event_processor.rb +++ b/lib/optimizely/event/batch_event_processor.rb @@ -37,7 +37,8 @@ def initialize( event_dispatcher:, batch_size: DEFAULT_BATCH_SIZE, flush_interval: DEFAULT_BATCH_INTERVAL, - logger: NoOpLogger.new + logger: NoOpLogger.new, + notification_center: nil ) @event_queue = event_queue @event_dispatcher = event_dispatcher @@ -48,6 +49,7 @@ def initialize( end @flush_interval = positive_number?(flush_interval) ? flush_interval : DEFAULT_BATCH_INTERVAL @logger = logger + @notification_center = notification_center @mutex = Mutex.new @received = ConditionVariable.new @current_batch = [] @@ -149,6 +151,10 @@ def flush_queue! log_event = Optimizely::EventFactory.create_log_event(@current_batch, @logger) begin @event_dispatcher.dispatch_event(log_event) + @notification_center&.send_notifications( + NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], + log_event + ) rescue StandardError => e @logger.log(Logger::ERROR, "Error dispatching event: #{log_event} #{e.message}.") end diff --git a/lib/optimizely/event/forwarding_event_processor.rb b/lib/optimizely/event/forwarding_event_processor.rb index 679174ae..8970f301 100644 --- a/lib/optimizely/event/forwarding_event_processor.rb +++ b/lib/optimizely/event/forwarding_event_processor.rb @@ -20,9 +20,10 @@ module Optimizely class ForwardingEventProcessor < EventProcessor # ForwardingEventProcessor is a basic transformation stage for converting # the event batch into a LogEvent to be dispatched. - def initialize(event_dispatcher, logger = nil) + def initialize(event_dispatcher, logger = nil, notification_center = nil) @event_dispatcher = event_dispatcher @logger = logger || NoOpLogger.new + @notification_center = notification_center end def process(user_event) @@ -30,6 +31,10 @@ def process(user_event) begin @event_dispatcher.dispatch_event(log_event) + @notification_center&.send_notifications( + NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], + log_event + ) rescue StandardError => e @logger.log(Logger::ERROR, "Error dispatching event: #{log_event} #{e.message}.") end diff --git a/lib/optimizely/notification_center.rb b/lib/optimizely/notification_center.rb index 53d6dc3d..4a3b0169 100644 --- a/lib/optimizely/notification_center.rb +++ b/lib/optimizely/notification_center.rb @@ -24,6 +24,7 @@ class NotificationCenter # DEPRECATED: ACTIVATE notification type is deprecated since relase 3.1.0. ACTIVATE: 'ACTIVATE: experiment, user_id, attributes, variation, event', DECISION: 'DECISION: type, user_id, attributes, decision_info', + LOG_EVENT: 'LOG_EVENT: type, log_event', OPTIMIZELY_CONFIG_UPDATE: 'optimizely_config_update', TRACK: 'TRACK: event_key, user_id, attributes, event_tags, event' }.freeze @@ -137,6 +138,10 @@ def send_notifications(notification_type, *args) end end + def notification_count(notification_type) + @notifications.include?(notification_type) ? @notifications[notification_type].count : 0 + end + private def notification_type_valid?(notification_type) diff --git a/spec/event/batch_event_processor_spec.rb b/spec/event/batch_event_processor_spec.rb index 0f94c824..33fd2468 100644 --- a/spec/event/batch_event_processor_spec.rb +++ b/spec/event/batch_event_processor_spec.rb @@ -41,13 +41,16 @@ @event_queue = SizedQueue.new(100) @event_dispatcher = Optimizely::EventDispatcher.new allow(@event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) + @notification_center = Optimizely::NotificationCenter.new(spy_logger, error_handler) + allow(@notification_center).to receive(:send_notifications) @event_processor = Optimizely::BatchEventProcessor.new( event_queue: @event_queue, event_dispatcher: @event_dispatcher, batch_size: MAX_BATCH_SIZE, flush_interval: MAX_DURATION_MS, - logger: spy_logger + logger: spy_logger, + notification_center: @notification_center ) end @@ -258,4 +261,38 @@ expect(event_processor.flush_interval).to eq(2000.5) event_processor.stop! end + + it 'should send log event notification when event is dispatched' do + conversion_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + log_event = Optimizely::EventFactory.create_log_event(conversion_event, spy_logger) + + @event_processor.process(conversion_event) + sleep 1.5 + + expect(@notification_center).to have_received(:send_notifications).with( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], + log_event + ).once + + expect(@event_dispatcher).to have_received(:dispatch_event).with(log_event).once + end + + it 'should log an error when dispatch event raises timeout exception' do + conversion_event = Optimizely::UserEventFactory.create_conversion_event(project_config, event, 'test_user', nil, nil) + log_event = Optimizely::EventFactory.create_log_event(conversion_event, spy_logger) + allow(Optimizely::EventFactory).to receive(:create_log_event).and_return(log_event) + + timeout_error = Timeout::Error.new + allow(@event_dispatcher).to receive(:dispatch_event).and_raise(timeout_error) + + @event_processor.process(conversion_event) + sleep 1.5 + + expect(@notification_center).not_to have_received(:send_notifications) + + expect(spy_logger).to have_received(:log).once.with( + Logger::ERROR, + "Error dispatching event: #{log_event} Timeout::Error." + ) + end end diff --git a/spec/event/forwarding_event_processor_spec.rb b/spec/event/forwarding_event_processor_spec.rb index 7be502f0..f58d0e90 100644 --- a/spec/event/forwarding_event_processor_spec.rb +++ b/spec/event/forwarding_event_processor_spec.rb @@ -69,19 +69,29 @@ end describe '.process' do - it 'should dispatch log event when valid event is provided' do + it 'should dispatch and send log event when valid event is provided' do + notification_center = Optimizely::NotificationCenter.new(spy_logger, error_handler) + allow(notification_center).to receive(:send_notifications) forwarding_event_processor = Optimizely::ForwardingEventProcessor.new( - @event_dispatcher, spy_logger + @event_dispatcher, spy_logger, notification_center ) forwarding_event_processor.process(@conversion_event) + expect(notification_center).to have_received(:send_notifications).with( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], + Optimizely::Event.new(:post, log_url, @expected_conversion_params, post_headers) + ).once + expect(@event_dispatcher).to have_received(:dispatch_event).with( Optimizely::Event.new(:post, log_url, @expected_conversion_params, post_headers) ).once end it 'should log an error when dispatch event raises timeout exception' do + notification_center = Optimizely::NotificationCenter.new(spy_logger, error_handler) + allow(notification_center).to receive(:send_notifications) + log_event = Optimizely::Event.new(:post, log_url, @expected_conversion_params, post_headers) allow(Optimizely::EventFactory).to receive(:create_log_event).and_return(log_event) @@ -89,11 +99,13 @@ allow(@event_dispatcher).to receive(:dispatch_event).and_raise(timeout_error) forwarding_event_processor = Optimizely::ForwardingEventProcessor.new( - @event_dispatcher, spy_logger + @event_dispatcher, spy_logger, notification_center ) forwarding_event_processor.process(@conversion_event) + expect(notification_center).not_to have_received(:send_notifications) + expect(spy_logger).to have_received(:log).once.with( Logger::ERROR, "Error dispatching event: #{log_event} Timeout::Error." diff --git a/spec/notification_center_spec.rb b/spec/notification_center_spec.rb index 540c4420..be3a4b8e 100644 --- a/spec/notification_center_spec.rb +++ b/spec/notification_center_spec.rb @@ -486,6 +486,37 @@ def deliver_three; end end end + describe '.notification_count' do + it 'should return count of added notification types' do + notification_center.add_notification_listener( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], + @callback_reference + ) + + notification_center.add_notification_listener( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], + method(:test) + ) + + notification_center.add_notification_listener( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:TRACK], + method(:test) + ) + + expect( + notification_center.notification_count(Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE]) + ).to eq(2) + + expect( + notification_center.notification_count(Optimizely::NotificationCenter::NOTIFICATION_TYPES[:TRACK]) + ).to eq(1) + + expect( + notification_center.notification_count(Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT]) + ).to eq(0) + end + end + describe '@error_handler' do let(:raise_error_handler) { Optimizely::RaiseErrorHandler.new } let(:notification_center) { Optimizely::NotificationCenter.new(spy_logger, raise_error_handler) } diff --git a/spec/project_spec.rb b/spec/project_spec.rb index ece7b934..fa462c16 100644 --- a/spec/project_spec.rb +++ b/spec/project_spec.rb @@ -587,6 +587,11 @@ class InvalidErrorHandler; end end it 'should log and send activate notification when an impression event is dispatched' do + def callback(_args); end + project_instance.notification_center.add_notification_listener( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], + method(:callback) + ) variation_to_return = project_instance.config_manager.config.get_variation_from_id('test_experiment', '111128') allow(project_instance.decision_service.bucketer).to receive(:bucket).and_return(variation_to_return) allow(project_instance.event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) @@ -600,6 +605,11 @@ class InvalidErrorHandler; end Optimizely::NotificationCenter::NOTIFICATION_TYPES[:DECISION], any_args ).ordered + # Log event + expect(project_instance.notification_center).to receive(:send_notifications).with( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], any_args + ).ordered + # Activate listener expect(project_instance.notification_center).to receive(:send_notifications).with( Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], @@ -886,13 +896,26 @@ class InvalidErrorHandler; end params = @expected_track_event_params params[:visitors][0][:snapshots][0][:events][0].merge!(revenue: 42, tags: {'revenue' => 42}) + + def callback(_args); end + project_instance.notification_center.add_notification_listener( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:TRACK], + method(:callback) + ) allow(project_instance.event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) conversion_event = Optimizely::Event.new(:post, conversion_log_url, params, post_headers) + + expect(project_instance.notification_center).to receive(:send_notifications) + .with( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], any_args + ).ordered + expect(project_instance.notification_center).to receive(:send_notifications) .with( Optimizely::NotificationCenter::NOTIFICATION_TYPES[:TRACK], 'test_event', 'test_user', nil, {'revenue' => 42}, conversion_event - ).once + ).ordered + project_instance.track('test_event', 'test_user', nil, 'revenue' => 42) expect(project_instance.event_dispatcher).to have_received(:dispatch_event).with(Optimizely::Event.new(:post, conversion_log_url, params, post_headers)).once end @@ -1463,6 +1486,12 @@ class InvalidErrorHandler; end end it 'should return true, send activate notification and an impression if the user is bucketed into a feature experiment' do + def callback(_args); end + project_instance.notification_center.add_notification_listener( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], + method(:callback) + ) + allow(project_instance.event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) experiment_to_return = config_body['experiments'][3] variation_to_return = experiment_to_return['variations'][0] @@ -1472,6 +1501,11 @@ class InvalidErrorHandler; end Optimizely::DecisionService::DECISION_SOURCES['FEATURE_TEST'] ) + expect(project_instance.notification_center).to receive(:send_notifications) + .with( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], any_args + ).ordered + expect(project_instance.notification_center).to receive(:send_notifications) .with( Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], @@ -1709,6 +1743,12 @@ class InvalidErrorHandler; end describe '.decision listener' do it 'should return enabled features and call decision listener for all features' do + def callback(_args); end + project_instance.notification_center.add_notification_listener( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], + method(:callback) + ) + allow(project_instance.event_dispatcher).to receive(:dispatch_event).with(instance_of(Optimizely::Event)) enabled_features = %w[boolean_feature integer_single_variable_feature] @@ -1739,6 +1779,10 @@ class InvalidErrorHandler; end nil ) + expect(project_instance.notification_center).to receive(:send_notifications).twice.with( + Optimizely::NotificationCenter::NOTIFICATION_TYPES[:LOG_EVENT], any_args + ) + expect(project_instance.notification_center).to receive(:send_notifications).twice.with( Optimizely::NotificationCenter::NOTIFICATION_TYPES[:ACTIVATE], any_args ) From cbdce5e9347299cea29937482b96cc25ca98187e Mon Sep 17 00:00:00 2001 From: rashidsp Date: Mon, 19 Aug 2019 21:05:29 +0500 Subject: [PATCH 24/30] fixes visitor_attributes bug --- lib/optimizely/event/event_factory.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/optimizely/event/event_factory.rb b/lib/optimizely/event/event_factory.rb index 16f4d1f8..754117b5 100644 --- a/lib/optimizely/event/event_factory.rb +++ b/lib/optimizely/event/event_factory.rb @@ -87,7 +87,7 @@ def build_attribute_list(user_attributes, project_config) ) end - return unless Helpers::Validator.boolean? project_config.bot_filtering + return visitor_attributes unless Helpers::Validator.boolean? project_config.bot_filtering # Append Bot Filtering Attribute visitor_attributes.push( From 6021aefaca84197e2b99e9985e337e2a09aa90c0 Mon Sep 17 00:00:00 2001 From: rashidsp Date: Mon, 19 Aug 2019 21:05:29 +0500 Subject: [PATCH 25/30] fixes visitor_attributes bug --- lib/optimizely/event/event_factory.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/optimizely/event/event_factory.rb b/lib/optimizely/event/event_factory.rb index 16f4d1f8..754117b5 100644 --- a/lib/optimizely/event/event_factory.rb +++ b/lib/optimizely/event/event_factory.rb @@ -87,7 +87,7 @@ def build_attribute_list(user_attributes, project_config) ) end - return unless Helpers::Validator.boolean? project_config.bot_filtering + return visitor_attributes unless Helpers::Validator.boolean? project_config.bot_filtering # Append Bot Filtering Attribute visitor_attributes.push( From 184fd06adb0ecdda67c2abffcbfcd4eb3bc9813f Mon Sep 17 00:00:00 2001 From: rashidsp Date: Tue, 20 Aug 2019 11:54:54 +0500 Subject: [PATCH 26/30] Addressed review --- lib/optimizely/event/batch_event_processor.rb | 10 +++++++--- lib/optimizely/helpers/date_time_utils.rb | 6 +++--- spec/event/batch_event_processor_spec.rb | 11 ++++++----- 3 files changed, 16 insertions(+), 11 deletions(-) diff --git a/lib/optimizely/event/batch_event_processor.rb b/lib/optimizely/event/batch_event_processor.rb index 99c48dbe..eeb730d4 100644 --- a/lib/optimizely/event/batch_event_processor.rb +++ b/lib/optimizely/event/batch_event_processor.rb @@ -22,11 +22,13 @@ class BatchEventProcessor < EventProcessor # BatchEventProcessor is a batched implementation of the Interface EventProcessor. # Events passed to the BatchEventProcessor are immediately added to a EventQueue. # The BatchEventProcessor maintains a single consumer thread that pulls events off of + # the BlockingQueue and buffers them for either a configured batch size or for a + # maximum duration before the resulting LogEvent is sent to the NotificationCenter. attr_reader :event_queue, :current_batch, :batch_size, :flush_interval DEFAULT_BATCH_SIZE = 10 - DEFAULT_BATCH_INTERVAL = 30_000 + DEFAULT_BATCH_INTERVAL = 30_000 # interval in milliseconds DEFAULT_QUEUE_CAPACITY = 1000 FLUSH_SIGNAL = 'FLUSH_SIGNAL' @@ -40,14 +42,15 @@ def initialize( logger: NoOpLogger.new ) @event_queue = event_queue + @logger = logger @event_dispatcher = event_dispatcher @batch_size = if (batch_size.is_a? Integer) && positive_number?(batch_size) batch_size else + @logger.log(Logger::DEBUG, "Setting to default batch_size: #{DEFAULT_BATCH_SIZE}.") DEFAULT_BATCH_SIZE end @flush_interval = positive_number?(flush_interval) ? flush_interval : DEFAULT_BATCH_INTERVAL - @logger = logger @mutex = Mutex.new @received = ConditionVariable.new @current_batch = [] @@ -176,13 +179,14 @@ def should_split?(user_event) return false if @current_batch.empty? current_context = @current_batch.last.event_context - new_context = user_event.event_context + # Revisions should match unless current_context[:revision] == new_context[:revision] @logger.log(Logger::DEBUG, 'Revisions mismatched: Flushing current batch.') return true end + # Projects should match unless current_context[:project_id] == new_context[:project_id] @logger.log(Logger::DEBUG, 'Project Ids mismatched: Flushing current batch.') diff --git a/lib/optimizely/helpers/date_time_utils.rb b/lib/optimizely/helpers/date_time_utils.rb index aa62639b..97fb987b 100644 --- a/lib/optimizely/helpers/date_time_utils.rb +++ b/lib/optimizely/helpers/date_time_utils.rb @@ -21,9 +21,9 @@ module DateTimeUtils module_function def create_timestamp - # Returns Integer Current timestamp - - (Time.now.to_f * 1000).to_i + # Returns Integer current UTC timestamp + utc = Time.now.getutc + (utc.to_f * 1000).to_i end end end diff --git a/spec/event/batch_event_processor_spec.rb b/spec/event/batch_event_processor_spec.rb index 0f94c824..4794e075 100644 --- a/spec/event/batch_event_processor_spec.rb +++ b/spec/event/batch_event_processor_spec.rb @@ -209,21 +209,22 @@ event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher) expect(event_processor.batch_size).to eq(10) event_processor.stop! - event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, batch_size: 'test') + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, batch_size: 'test', logger: spy_logger) expect(event_processor.batch_size).to eq(10) event_processor.stop! - event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, batch_size: []) + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, batch_size: [], logger: spy_logger) expect(event_processor.batch_size).to eq(10) event_processor.stop! - event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, batch_size: 0) + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, batch_size: 0, logger: spy_logger) expect(event_processor.batch_size).to eq(10) event_processor.stop! - event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, batch_size: -5) + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, batch_size: -5, logger: spy_logger) expect(event_processor.batch_size).to eq(10) event_processor.stop! - event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, batch_size: 5.5) + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, batch_size: 5.5, logger: spy_logger) expect(event_processor.batch_size).to eq(10) event_processor.stop! + expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Setting to default batch_size: 10.').exactly(5).times end it 'should set batch size when provided valid' do From f807970a1e4aea785477fd4437d1dd1c81ccb40d Mon Sep 17 00:00:00 2001 From: rashidsp Date: Wed, 21 Aug 2019 22:20:01 +0500 Subject: [PATCH 27/30] Fixes event bug --- lib/optimizely/event/batch_event_processor.rb | 2 +- spec/event/batch_event_processor_spec.rb | 1 - 2 files changed, 1 insertion(+), 2 deletions(-) diff --git a/lib/optimizely/event/batch_event_processor.rb b/lib/optimizely/event/batch_event_processor.rb index ed1a6274..ba1f98c8 100644 --- a/lib/optimizely/event/batch_event_processor.rb +++ b/lib/optimizely/event/batch_event_processor.rb @@ -173,7 +173,7 @@ def add_to_batch(user_event) # Reset the deadline if starting a new batch. @flushing_interval_deadline = (Helpers::DateTimeUtils.create_timestamp + @flush_interval) if @current_batch.empty? - @logger.log(Logger::DEBUG, "Adding user event: #{user_event.event['key']} to batch.") + @logger.log(Logger::DEBUG, "Adding user event: #{user_event} to batch.") @current_batch << user_event return unless @current_batch.length >= @batch_size diff --git a/spec/event/batch_event_processor_spec.rb b/spec/event/batch_event_processor_spec.rb index 58774dd5..86b46098 100644 --- a/spec/event/batch_event_processor_spec.rb +++ b/spec/event/batch_event_processor_spec.rb @@ -114,7 +114,6 @@ expect(@event_dispatcher).to have_received(:dispatch_event).with( Optimizely::EventFactory.create_log_event(expected_batch, spy_logger) ).once - expect(spy_logger).to have_received(:log).with(Logger::DEBUG, "Adding user event: #{event['key']} to batch.").exactly(10).times expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Flushing on max batch size!').once end From d3a7495e13098151d7afcffaa7960c96ad8b4b96 Mon Sep 17 00:00:00 2001 From: rashidsp Date: Wed, 21 Aug 2019 22:20:01 +0500 Subject: [PATCH 28/30] Fixes event bug --- lib/optimizely/event/batch_event_processor.rb | 2 +- spec/event/batch_event_processor_spec.rb | 1 - 2 files changed, 1 insertion(+), 2 deletions(-) diff --git a/lib/optimizely/event/batch_event_processor.rb b/lib/optimizely/event/batch_event_processor.rb index 5fe967b4..e1147570 100644 --- a/lib/optimizely/event/batch_event_processor.rb +++ b/lib/optimizely/event/batch_event_processor.rb @@ -167,7 +167,7 @@ def add_to_batch(user_event) # Reset the deadline if starting a new batch. @flushing_interval_deadline = (Helpers::DateTimeUtils.create_timestamp + @flush_interval) if @current_batch.empty? - @logger.log(Logger::DEBUG, "Adding user event: #{user_event.event['key']} to batch.") + @logger.log(Logger::DEBUG, "Adding user event: #{user_event} to batch.") @current_batch << user_event return unless @current_batch.length >= @batch_size diff --git a/spec/event/batch_event_processor_spec.rb b/spec/event/batch_event_processor_spec.rb index 4794e075..a5351ca4 100644 --- a/spec/event/batch_event_processor_spec.rb +++ b/spec/event/batch_event_processor_spec.rb @@ -111,7 +111,6 @@ expect(@event_dispatcher).to have_received(:dispatch_event).with( Optimizely::EventFactory.create_log_event(expected_batch, spy_logger) ).once - expect(spy_logger).to have_received(:log).with(Logger::DEBUG, "Adding user event: #{event['key']} to batch.").exactly(10).times expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Flushing on max batch size!').once end From e8028602b2ab4e402bd9407621db411b56a7815b Mon Sep 17 00:00:00 2001 From: rashidsp Date: Tue, 27 Aug 2019 16:37:46 +0500 Subject: [PATCH 29/30] review changes --- lib/optimizely/event/batch_event_processor.rb | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/lib/optimizely/event/batch_event_processor.rb b/lib/optimizely/event/batch_event_processor.rb index e1147570..6575bc32 100644 --- a/lib/optimizely/event/batch_event_processor.rb +++ b/lib/optimizely/event/batch_event_processor.rb @@ -78,7 +78,7 @@ def flush def process(user_event) @logger.log(Logger::DEBUG, "Received userEvent: #{user_event}") - unless @thread.alive? + if !@started || !@thread.alive? @logger.log(Logger::WARN, 'Executor shutdown, not accepting tasks.') return end @@ -95,7 +95,7 @@ def process(user_event) end def stop! - return unless @thread.alive? + return unless @started @mutex.synchronize do @event_queue << SHUTDOWN_SIGNAL From ecf2d6e46432863201d4ef2b563e48321f80d505 Mon Sep 17 00:00:00 2001 From: rashidsp Date: Thu, 29 Aug 2019 17:27:21 +0500 Subject: [PATCH 30/30] log default interval message. --- lib/optimizely/event/batch_event_processor.rb | 7 ++++++- spec/event/batch_event_processor_spec.rb | 9 +++++---- 2 files changed, 11 insertions(+), 5 deletions(-) diff --git a/lib/optimizely/event/batch_event_processor.rb b/lib/optimizely/event/batch_event_processor.rb index 70b4382c..f6785d03 100644 --- a/lib/optimizely/event/batch_event_processor.rb +++ b/lib/optimizely/event/batch_event_processor.rb @@ -51,7 +51,12 @@ def initialize( @logger.log(Logger::DEBUG, "Setting to default batch_size: #{DEFAULT_BATCH_SIZE}.") DEFAULT_BATCH_SIZE end - @flush_interval = positive_number?(flush_interval) ? flush_interval : DEFAULT_BATCH_INTERVAL + @flush_interval = if positive_number?(flush_interval) + flush_interval + else + @logger.log(Logger::DEBUG, "Setting to default flush_interval: #{DEFAULT_BATCH_INTERVAL} ms.") + DEFAULT_BATCH_INTERVAL + end @notification_center = notification_center @mutex = Mutex.new @received = ConditionVariable.new diff --git a/spec/event/batch_event_processor_spec.rb b/spec/event/batch_event_processor_spec.rb index 86b46098..8411cbdc 100644 --- a/spec/event/batch_event_processor_spec.rb +++ b/spec/event/batch_event_processor_spec.rb @@ -239,18 +239,19 @@ event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher) expect(event_processor.flush_interval).to eq(30_000) event_processor.stop! - event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, flush_interval: 'test') + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, flush_interval: 'test', logger: spy_logger) expect(event_processor.flush_interval).to eq(30_000) event_processor.stop! - event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, flush_interval: []) + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, flush_interval: [], logger: spy_logger) expect(event_processor.flush_interval).to eq(30_000) event_processor.stop! - event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, flush_interval: 0) + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, flush_interval: 0, logger: spy_logger) expect(event_processor.flush_interval).to eq(30_000) event_processor.stop! - event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, flush_interval: -5) + event_processor = Optimizely::BatchEventProcessor.new(event_dispatcher: @event_dispatcher, flush_interval: -5, logger: spy_logger) expect(event_processor.flush_interval).to eq(30_000) event_processor.stop! + expect(spy_logger).to have_received(:log).with(Logger::DEBUG, 'Setting to default flush_interval: 30000 ms.').exactly(4).times end it 'should set flush interval when provided valid' do