From cbd91bc60571f937992fc011a7858dea2d23391f Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Fri, 16 Mar 2018 17:33:24 -0700 Subject: [PATCH 01/34] implement summary events --- lib/ldclient-rb.rb | 4 +- lib/ldclient-rb/config.rb | 42 ++- lib/ldclient-rb/evaluation.rb | 35 +- lib/ldclient-rb/event_summarizer.rb | 105 ++++++ lib/ldclient-rb/events.rb | 219 ++++++++++--- lib/ldclient-rb/ldclient.rb | 35 +- lib/ldclient-rb/simple_lru_cache.rb | 24 ++ .../{event_serializer.rb => user_filter.rb} | 38 +-- spec/evaluation_spec.rb | 24 +- spec/event_summarizer_spec.rb | 100 ++++++ spec/events_spec.rb | 307 ++++++++++++++++++ spec/fixtures/feature.json | 1 + spec/ldclient_spec.rb | 58 +++- spec/simple_lru_cache_spec.rb | 24 ++ ...serializer_spec.rb => user_filter_spec.rb} | 67 ++-- 15 files changed, 912 insertions(+), 171 deletions(-) create mode 100644 lib/ldclient-rb/event_summarizer.rb create mode 100644 lib/ldclient-rb/simple_lru_cache.rb rename lib/ldclient-rb/{event_serializer.rb => user_filter.rb} (87%) create mode 100644 spec/event_summarizer_spec.rb create mode 100644 spec/events_spec.rb create mode 100644 spec/simple_lru_cache_spec.rb rename spec/{event_serializer_spec.rb => user_filter_spec.rb} (50%) diff --git a/lib/ldclient-rb.rb b/lib/ldclient-rb.rb index ce943d13..8ef89cda 100644 --- a/lib/ldclient-rb.rb +++ b/lib/ldclient-rb.rb @@ -8,7 +8,9 @@ require "ldclient-rb/newrelic" require "ldclient-rb/stream" require "ldclient-rb/polling" -require "ldclient-rb/event_serializer" +require "ldclient-rb/user_filter" +require "ldclient-rb/simple_lru_cache" +require "ldclient-rb/event_summarizer" require "ldclient-rb/events" require "ldclient-rb/redis_store" require "ldclient-rb/requestor" diff --git a/lib/ldclient-rb/config.rb b/lib/ldclient-rb/config.rb index 5a6e7c26..3b62b2a3 100644 --- a/lib/ldclient-rb/config.rb +++ b/lib/ldclient-rb/config.rb @@ -54,7 +54,15 @@ class Config # @option opts [Boolean] :send_events (true) Whether or not to send events back to LaunchDarkly. # This differs from `offline` in that it affects only the sending of client-side events, not # streaming or polling for events from the server. - # + # @option opts [Integer] :user_keys_capacity (1000) The number of user keys that the event processor + # can remember at any one time, so that duplicate user details will not be sent in analytics events. + # @option opts [Float] :user_keys_flush_interval (300) The interval in seconds at which the event + # processor will reset its set of known user keys. + # @option opts [Boolean] :inline_users_in_events (false) Whether to include full user details in every + # analytics event. By default, events will only include the user key, except for one "index" event + # that provides the full details for the user. + # @option opts [Object] :update_processor An object that will receive feature flag data from LaunchDarkly. + # Defaults to either the streaming or the polling processor, can be customized for tests. # @return [type] [description] # rubocop:disable Metrics/AbcSize, Metrics/PerceivedComplexity def initialize(opts = {}) @@ -76,6 +84,10 @@ def initialize(opts = {}) @all_attributes_private = opts[:all_attributes_private] || false @private_attribute_names = opts[:private_attribute_names] || [] @send_events = opts.has_key?(:send_events) ? opts[:send_events] : Config.default_send_events + @user_keys_capacity = opts[:user_keys_capacity] || Config.default_user_keys_capacity + @user_keys_flush_interval = opts[:user_keys_flush_interval] || Config.default_user_keys_flush_interval + @inline_users_in_events = opts[:inline_users_in_events] || false + @update_processor = opts[:update_processor] end # @@ -186,6 +198,26 @@ def offline? # attr_reader :send_events + # + # The number of user keys that the event processor can remember at any one time, so that + # duplicate user details will not be sent in analytics events. + # + attr_reader :user_keys_capacity + + # + # The interval in seconds at which the event processor will reset its set of known user keys. + # + attr_reader :user_keys_flush_interval + + # + # Whether to include full user details in every + # analytics event. By default, events will only include the user key, except for one "index" event + # that provides the full details for the user. + # + attr_reader :inline_users_in_events + + attr_reader :update_processor + # # The default LaunchDarkly client configuration. This configuration sets # reasonable defaults for most users. @@ -264,5 +296,13 @@ def self.default_poll_interval def self.default_send_events true end + + def self.default_user_keys_capacity + 1000 + end + + def self.default_user_keys_flush_interval + 300 + end end end diff --git a/lib/ldclient-rb/evaluation.rb b/lib/ldclient-rb/evaluation.rb index 2b98c648..b40bab38 100644 --- a/lib/ldclient-rb/evaluation.rb +++ b/lib/ldclient-rb/evaluation.rb @@ -127,16 +127,19 @@ def evaluate(flag, user, store) if flag[:on] res = eval_internal(flag, user, store, events) - - return { value: res, events: events } if !res.nil? + if !res.nil? + res[:events] = events + return res + end end - if !flag[:offVariation].nil? && flag[:offVariation] < flag[:variations].length - value = flag[:variations][flag[:offVariation]] - return { value: value, events: events } + offVariation = flag[:offVariation] + if !offVariation.nil? && offVariation < flag[:variations].length + value = flag[:variations][offVariation] + return { variation: offVariation, value: value, events: events } end - { value: nil, events: events } + { variation: nil, value: nil, events: events } end def eval_internal(flag, user, store, events) @@ -150,9 +153,13 @@ def eval_internal(flag, user, store, events) else begin prereq_res = eval_internal(prereq_flag, user, store, events) - variation = get_variation(prereq_flag, prerequisite[:variation]) - events.push(kind: "feature", key: prereq_flag[:key], value: prereq_res, version: prereq_flag[:version], prereqOf: flag[:key]) - if prereq_res.nil? || prereq_res != variation + event = { + kind: "feature", key: prereq_flag[:key], variation: prereq_res[:variation], + value: prereq_res[:value], version: prereq_flag[:version], prereqOf: flag[:key], + trackEvents: prereq_flag[:trackEvents], debugEventsUntilDate: prereq_flag[:debugEventsUntilDate] + } + events.push(event) + if prereq_res.nil? || prereq_res[:variation] != prerequisite[:variation] failed_prereq = true end rescue => exn @@ -175,7 +182,9 @@ def eval_rules(flag, user, store) # Check user target matches (flag[:targets] || []).each do |target| (target[:values] || []).each do |value| - return get_variation(flag, target[:variation]) if value == user[:key] + if value == user[:key] + return { variation: target[:variation], value: get_variation(flag, target[:variation]) } + end end end @@ -245,7 +254,7 @@ def clause_match_user_no_segments(clause, user) def variation_for_user(rule, user, flag) if !rule[:variation].nil? # fixed variation - return get_variation(flag, rule[:variation]) + return { variation: rule[:variation], value: get_variation(flag, rule[:variation]) } elsif !rule[:rollout].nil? # percentage rollout rollout = rule[:rollout] bucket_by = rollout[:bucketBy].nil? ? "key" : rollout[:bucketBy] @@ -253,7 +262,9 @@ def variation_for_user(rule, user, flag) sum = 0; rollout[:variations].each do |variate| sum += variate[:weight].to_f / 100000.0 - return get_variation(flag, variate[:variation]) if bucket < sum + if bucket < sum + return { variation: variate[:variation], value: get_variation(flag, variate[:variation]) } + end end nil else # the rule isn't well-formed diff --git a/lib/ldclient-rb/event_summarizer.rb b/lib/ldclient-rb/event_summarizer.rb new file mode 100644 index 00000000..6b0c06c9 --- /dev/null +++ b/lib/ldclient-rb/event_summarizer.rb @@ -0,0 +1,105 @@ + +module LaunchDarkly + EventSummarySnapshot = Struct.new(:start_date, :end_date, :counters) + + # Manages the state of summarizable information for the EventProcessor, including the + # event counters and user deduplication. Note that the methods of this class are + # deliberately not thread-safe; the EventProcessor is responsible for enforcing + # synchronization across both the summarizer and the event queue. + class EventSummarizer + def initialize(config) + @config = config + @users = SimpleLRUCacheSet.new(@config.user_keys_capacity) + reset_state + end + + # Adds to the set of users we've noticed, and return true if the user was already known to us. + def notice_user(user) + if user.nil? || !user.has_key?(:key) + true + else + @users.add(user[:key]) + end + end + + # Resets the set of users we've seen. + def reset_users + @users.reset + end + + # Adds this event to our counters, if it is a type of event we need to count. + def summarize_event(event) + if event[:kind] == "feature" + counter_key = { + key: event[:key], + version: event[:version], + variation: event[:variation] + } + c = @counters[counter_key] + if c.nil? + @counters[counter_key] = { + value: event[:value], + default: event[:default], + count: 1 + } + else + c[:count] = c[:count] + 1 + end + time = event[:creationDate] + if !time.nil? + @start_date = time if @start_date == 0 || time < @start_date + @end_date = time if time > @end_date + end + end + end + + # Returns a snapshot of the current summarized event data, and resets this state. + def snapshot + ret = { + start_date: @start_date, + end_date: @end_date, + counters: @counters + } + reset_state + ret + end + + # Transforms the summary data into the format used for event sending. + def output(snapshot) + flags = {} + snapshot[:counters].each { |ckey, cval| + flag = flags[ckey[:key]] + if flag.nil? + flag = { + default: cval[:default], + counters: [] + } + flags[ckey[:key]] = flag + end + c = { + value: cval[:value], + count: cval[:count] + } + if ckey[:version].nil? + c[:unknown] = true + else + c[:version] = ckey[:version] + end + flag[:counters].push(c) + } + { + startDate: snapshot[:start_date], + endDate: snapshot[:end_date], + features: flags + } + end + + private + + def reset_state + @start_date = 0 + @end_date = 0 + @counters = {} + end + end +end diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index 84ea0275..5d883ce2 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -1,51 +1,193 @@ +require "concurrent" require "concurrent/atomics" require "thread" +require "time" require "faraday" module LaunchDarkly + class NullEventProcessor + def add_event(event) + end + + def flush + end + + def stop + end + end + class EventProcessor - def initialize(sdk_key, config) - @queue = Queue.new + def initialize(sdk_key, config, client) + @lock = Mutex.new + @events = [] + @summarizer = EventSummarizer.new(config) @sdk_key = sdk_key @config = config - @serializer = EventSerializer.new(config) - @client = Faraday.new + @user_filter = UserFilter.new(config) + @client = client ? client : Faraday.new @stopped = Concurrent::AtomicBoolean.new(false) - @worker = create_worker if @config.send_events - end - - def alive? - !@stopped.value + @last_known_past_time = Concurrent::AtomicFixnum.new(0) + @flush_task = Concurrent::TimerTask.new(execution_interval: @config.flush_interval) do + flush_async + end + @users_flush_task = Concurrent::TimerTask.new(execution_interval: @config.user_keys_flush_interval) do + @summarizer.reset_users + end end def stop if @stopped.make_true # There seems to be no such thing as "close" in Faraday: https://github.com/lostisland/faraday/issues/241 - if !@worker.nil? && @worker.alive? - @worker.raise "shutting down client" + @flush_task.shutdown + @users_flush_task.shutdown + end + end + + def add_event(event) + return if @stopped.value + + now_millis = (Time.now.to_f * 1000).to_i + event[:creationDate] = now_millis + + @lock.synchronize { + # For each user we haven't seen before, we add an index event - unless this is already + # an identify event for that user. + if !@config.inline_users_in_events && event.has_key?(:user) && !@summarizer.notice_user(event[:user]) + if event[:kind] != "identify" + queue_event({ + kind: "index", + creationDate: event[:creationDate], + user: event[:user] + }) + end end + + # Always record the event in the summary. + @summarizer.summarize_event(event) + + if should_track_full_event(event, now_millis) + # Queue the event as-is; we'll transform it into an output event when we're flushing. + queue_event(event) + end + } + end + + def flush + # An explicit flush should be synchronous, so we use a semaphore to wait for the result + semaphore = Concurrent::Semaphore.new(0) + flush_internal(semaphore) + semaphore.acquire + end + + private + + def should_track_full_event(event, now_millis) + if event[:kind] == "feature" + if event[:trackEvents] + true + else + if event.has_key?(:debugEventsUntilDate) + last_past = @last_known_past_time.value + (last_past != 0 && event[:debugEventsUntilDate] > last_past) || + (event[:debugEventsUntilDate] > now_millis) + else + false + end + end + else + true end end - def create_worker - Thread.new do - while !@stopped.value do + def queue_event(event) + if @events.length < @config.capacity + @config.logger.debug { "[LDClient] Enqueueing event: #{event.to_json}" } + @events.push(event) + else + @config.logger.warn { "[LDClient] Exceeded event queue capacity. Increase capacity to avoid dropping events." } + end + end + + def flush_async + flush_internal(nil) + end + + def flush_internal(reply_semaphore) + old_events, snapshot = @lock.synchronize { + old_events = @events + @events = [] + snapshot = @summarizer.snapshot + [old_events, snapshot] + } + if !old_events.empty? || !snapshot[:counters].empty? + Thread.new do begin - flush - sleep(@config.flush_interval) + post_flushed_events(old_events, snapshot) rescue StandardError => exn - log_exception(__method__.to_s, exn) + @config.logger.warn { "[LDClient] Error flushing events: #{exn.inspect}. \nTrace: #{exn.backtrace}" } end + reply_semaphore.release if !reply_semaphore.nil? end + else + reply_semaphore.release if !reply_semaphore.nil? end end - def post_flushed_events(events) + def make_output_event(event) + case event[:kind] + when "feature" + is_debug = !event[:trackEvents] && event.has_key?(:debugEventsUntilDate) + out = { + kind: is_debug ? "debug" : "feature", + creationDate: event[:creationDate], + key: event[:key], + value: event[:value] + } + out[:default] = event[:default] if event.has_key?(:default) + out[:version] = event[:version] if event.has_key?(:version) + out[:prereqOf] = event[:prereqOf] if event.has_key?(:prereqOf) + if @config.inline_users_in_events + out[:user] = @user_filter.transform_user_props(event[:user]) + else + out[:userKey] = event[:user][:key] + end + out + when "identify" + { + kind: "identify", + creationDate: event[:creationDate], + user: @user_filter.transform_user_props(event[:user]) + } + when "custom" + out = { + kind: "custom", + creationDate: event[:creationDate], + key: event[:key] + } + out[:data] = event[:data] if event.has_key?(:data) + if @config.inline_users_in_events + out[:user] = @user_filter.transform_user_props(event[:user]) + else + out[:userKey] = event[:user][:key] + end + out + else + event + end + end + + def post_flushed_events(events, snapshot) + events_out = events.map { |e| make_output_event(e) } + if !snapshot[:counters].empty? + summary_output = @summarizer.output(snapshot) + summary_output[:kind] = "summary" + events_out.push(summary_output) + end res = @client.post (@config.events_uri + "/bulk") do |req| req.headers["Authorization"] = @sdk_key req.headers["User-Agent"] = "RubyClient/" + LaunchDarkly::VERSION req.headers["Content-Type"] = "application/json" - req.body = @serializer.serialize_events(events) + req.body = events_out.to_json req.options.timeout = @config.read_timeout req.options.open_timeout = @config.connect_timeout end @@ -55,40 +197,15 @@ def post_flushed_events(events) @config.logger.error { "[LDClient] Received 401 error, no further events will be posted since SDK key is invalid" } stop end - end - end - - def flush - return if @offline || !@config.send_events - events = [] - begin - loop do - events << @queue.pop(true) - end - rescue ThreadError - end - - if !events.empty? && !@stopped.value - post_flushed_events(events) - end - end - - def add_event(event) - return if @offline || !@config.send_events || @stopped.value - - if @queue.length < @config.capacity - event[:creationDate] = (Time.now.to_f * 1000).to_i - @config.logger.debug { "[LDClient] Enqueueing event: #{event.to_json}" } - @queue.push(event) - - if !@worker.alive? - @worker = create_worker - end else - @config.logger.warn { "[LDClient] Exceeded event queue capacity. Increase capacity to avoid dropping events." } + if !res.headers.nil? && res.headers.has_key?("Date") + begin + res_time = (Time.httpdate(res.headers["Date"]).to_f * 1000).to_i + @last_known_past_time.value = res_time + rescue + end + end end end - - private :create_worker, :post_flushed_events end end diff --git a/lib/ldclient-rb/ldclient.rb b/lib/ldclient-rb/ldclient.rb index 2c91bd60..d7d91a5d 100644 --- a/lib/ldclient-rb/ldclient.rb +++ b/lib/ldclient-rb/ldclient.rb @@ -28,7 +28,11 @@ def initialize(sdk_key, config = Config.default, wait_for_sec = 5) @config = config @store = config.feature_store - @event_processor = EventProcessor.new(sdk_key, config) + if @config.offline? || !@config.send_events + @event_processor = NullEventProcessor.new + else + @event_processor = EventProcessor.new(sdk_key, config) + end if @config.use_ldd? @config.logger.info { "[LDClient] Started LaunchDarkly Client in LDD mode" } @@ -38,12 +42,16 @@ def initialize(sdk_key, config = Config.default, wait_for_sec = 5) requestor = Requestor.new(sdk_key, config) if !@config.offline? - if @config.stream? - @update_processor = StreamProcessor.new(sdk_key, config, requestor) + if @config.update_processor.nil? + if @config.stream? + @update_processor = StreamProcessor.new(sdk_key, config, requestor) + else + @config.logger.info { "Disabling streaming API" } + @config.logger.warn { "You should only disable the streaming API if instructed to do so by LaunchDarkly support" } + @update_processor = PollingProcessor.new(config, requestor) + end else - @config.logger.info { "Disabling streaming API" } - @config.logger.warn { "You should only disable the streaming API if instructed to do so by LaunchDarkly support" } - @update_processor = PollingProcessor.new(config, requestor) + @update_processor = @config.update_processor end @update_processor.start end @@ -145,17 +153,18 @@ def variation(key, user, default) @event_processor.add_event(event) end end - if !res[:value].nil? - @event_processor.add_event(kind: "feature", key: key, user: user, value: res[:value], default: default, version: feature[:version]) - return res[:value] - else + value = res[:value] + if value.nil? @config.logger.debug { "[LDClient] Result value is null in toggle" } - @event_processor.add_event(kind: "feature", key: key, user: user, value: default, default: default, version: feature[:version]) - return default + value = default end + @event_processor.add_event(kind: "feature", key: key, user: user, value: res[:value], default: default, version: feature[:version], + trackEvents: feature[:trackEvents], debugEventsUntilDate: feature[:debugEventsUntilDate]) + return value rescue => exn @config.logger.warn { "[LDClient] Error evaluating feature flag: #{exn.inspect}. \nTrace: #{exn.backtrace}" } - @event_processor.add_event(kind: "feature", key: key, user: user, value: default, default: default, version: feature[:version]) + @event_processor.add_event(kind: "feature", key: key, user: user, value: default, default: default, version: feature[:version], + trackEvents: feature[:trackEvents], debugEventsUntilDate: feature[:debugEventsUntilDate]) return default end end diff --git a/lib/ldclient-rb/simple_lru_cache.rb b/lib/ldclient-rb/simple_lru_cache.rb new file mode 100644 index 00000000..64b1a709 --- /dev/null +++ b/lib/ldclient-rb/simple_lru_cache.rb @@ -0,0 +1,24 @@ + +module LaunchDarkly + # A non-thread-safe implementation of a LRU cache set with only add and reset methods. + # Based on https://github.com/SamSaffron/lru_redux/blob/master/lib/lru_redux/cache.rb + class SimpleLRUCacheSet + def initialize(capacity) + @values = {} + @capacity = capacity + end + + # Adds a value to the cache or marks it recent if it was already there. Returns true if already there. + def add(value) + found = true + @values.delete(value) { found = false } + @values[value] = true + @values.shift if @values.length > @capacity + found + end + + def clear + @values = {} + end + end +end diff --git a/lib/ldclient-rb/event_serializer.rb b/lib/ldclient-rb/user_filter.rb similarity index 87% rename from lib/ldclient-rb/event_serializer.rb rename to lib/ldclient-rb/user_filter.rb index bc8cb27d..09e03a9d 100644 --- a/lib/ldclient-rb/event_serializer.rb +++ b/lib/ldclient-rb/user_filter.rb @@ -1,18 +1,26 @@ require "json" module LaunchDarkly - class EventSerializer + class UserFilter def initialize(config) @all_attributes_private = config.all_attributes_private @private_attribute_names = Set.new(config.private_attribute_names.map(&:to_sym)) end - def serialize_events(events) - events.map { |event| - Hash[event.map { |key, value| - [key, (key.to_sym == :user) ? transform_user_props(value) : value] - }] - }.to_json + def transform_user_props(user_props) + user_private_attrs = Set.new((user_props[:privateAttributeNames] || []).map(&:to_sym)) + + filtered_user_props, removed = filter_values(user_props, user_private_attrs, ALLOWED_TOP_LEVEL_KEYS, IGNORED_TOP_LEVEL_KEYS) + if user_props.has_key?(:custom) + filtered_user_props[:custom], removed_custom = filter_values(user_props[:custom], user_private_attrs) + removed.merge(removed_custom) + end + + unless removed.empty? + # note, :privateAttributeNames is what the developer sets; :privateAttrs is what we send to the server + filtered_user_props[:privateAttrs] = removed.to_a.sort.map { |s| s.to_s } + end + return filtered_user_props end private @@ -35,21 +43,5 @@ def filter_values(props, user_private_attrs, allowed_keys = [], keys_to_leave_as def private_attr?(name, user_private_attrs) @all_attributes_private || @private_attribute_names.include?(name) || user_private_attrs.include?(name) end - - def transform_user_props(user_props) - user_private_attrs = Set.new((user_props[:privateAttributeNames] || []).map(&:to_sym)) - - filtered_user_props, removed = filter_values(user_props, user_private_attrs, ALLOWED_TOP_LEVEL_KEYS, IGNORED_TOP_LEVEL_KEYS) - if user_props.has_key?(:custom) - filtered_user_props[:custom], removed_custom = filter_values(user_props[:custom], user_private_attrs) - removed.merge(removed_custom) - end - - unless removed.empty? - # note, :privateAttributeNames is what the developer sets; :privateAttrs is what we send to the server - filtered_user_props[:privateAttrs] = removed.to_a.sort - end - return filtered_user_props - end end end diff --git a/spec/evaluation_spec.rb b/spec/evaluation_spec.rb index b8f4ea59..eee22d24 100644 --- a/spec/evaluation_spec.rb +++ b/spec/evaluation_spec.rb @@ -24,7 +24,7 @@ variations: ['a', 'b', 'c'] } user = { key: 'x' } - expect(evaluate(flag, user, features)).to eq({value: 'b', events: []}) + expect(evaluate(flag, user, features)).to eq({variation: 1, value: 'b', events: []}) end it "returns nil if flag is off and off variation is unspecified" do @@ -35,7 +35,7 @@ variations: ['a', 'b', 'c'] } user = { key: 'x' } - expect(evaluate(flag, user, features)).to eq({value: nil, events: []}) + expect(evaluate(flag, user, features)).to eq({variation: nil, value: nil, events: []}) end it "returns off variation if prerequisite is not found" do @@ -48,7 +48,7 @@ variations: ['a', 'b', 'c'] } user = { key: 'x' } - expect(evaluate(flag, user, features)).to eq({value: 'b', events: []}) + expect(evaluate(flag, user, features)).to eq({variation: 1, value: 'b', events: []}) end it "returns off variation and event if prerequisite is not met" do @@ -70,8 +70,11 @@ } features.upsert(LaunchDarkly::FEATURES, flag1) user = { key: 'x' } - events_should_be = [{kind: 'feature', key: 'feature1', value: 'd', version: 2, prereqOf: 'feature0'}] - expect(evaluate(flag, user, features)).to eq({value: 'b', events: events_should_be}) + events_should_be = [{ + kind: 'feature', key: 'feature1', variation: 0, value: 'd', version: 2, prereqOf: 'feature0', + trackEvents: nil, debugEventsUntilDate: nil + }] + expect(evaluate(flag, user, features)).to eq({variation: 1, value: 'b', events: events_should_be}) end it "returns fallthrough variation and event if prerequisite is met and there are no rules" do @@ -93,8 +96,11 @@ } features.upsert(LaunchDarkly::FEATURES, flag1) user = { key: 'x' } - events_should_be = [{kind: 'feature', key: 'feature1', value: 'e', version: 2, prereqOf: 'feature0'}] - expect(evaluate(flag, user, features)).to eq({value: 'a', events: events_should_be}) + events_should_be = [{ + kind: 'feature', key: 'feature1', variation: 1, value: 'e', version: 2, prereqOf: 'feature0', + trackEvents: nil, debugEventsUntilDate: nil + }] + expect(evaluate(flag, user, features)).to eq({variation: 0, value: 'a', events: events_should_be}) end it "matches user from targets" do @@ -109,7 +115,7 @@ variations: ['a', 'b', 'c'] } user = { key: 'userkey' } - expect(evaluate(flag, user, features)).to eq({value: 'c', events: []}) + expect(evaluate(flag, user, features)).to eq({variation: 2, value: 'c', events: []}) end it "matches user from rules" do @@ -133,7 +139,7 @@ variations: ['a', 'b', 'c'] } user = { key: 'userkey' } - expect(evaluate(flag, user, features)).to eq({value: 'c', events: []}) + expect(evaluate(flag, user, features)).to eq({variation: 2, value: 'c', events: []}) end end diff --git a/spec/event_summarizer_spec.rb b/spec/event_summarizer_spec.rb new file mode 100644 index 00000000..a2655730 --- /dev/null +++ b/spec/event_summarizer_spec.rb @@ -0,0 +1,100 @@ +require "spec_helper" + +describe LaunchDarkly::EventSummarizer do + subject { LaunchDarkly::EventSummarizer } + + let(:user) { { key: "key" } } + + it "returns false from notice_user for never-seen user" do + es = subject.new(LaunchDarkly::Config.new) + expect(es.notice_user(user)).to be false + end + + it "returns true from notice_user for previously seen user" do + es = subject.new(LaunchDarkly::Config.new) + expect(es.notice_user(user)).to be false + expect(es.notice_user(user)).to be true + end + + it "discards oldest user if capacity is exceeded" do + config = LaunchDarkly::Config.new(user_keys_capacity: 2) + es = subject.new(config) + user1 = { key: "key1" } + user2 = { key: "key2" } + user3 = { key: "key3" } + expect(es.notice_user(user1)).to be false + expect(es.notice_user(user2)).to be false + expect(es.notice_user(user3)).to be false + expect(es.notice_user(user3)).to be true + expect(es.notice_user(user2)).to be true + expect(es.notice_user(user1)).to be false + end + + it "does not add identify event to summary" do + es = subject.new(LaunchDarkly::Config.new) + snapshot = es.snapshot + es.summarize_event({ kind: "identify", user: user }) + + expect(es.snapshot).to eq snapshot + end + + it "does not add custom event to summary" do + es = subject.new(LaunchDarkly::Config.new) + snapshot = es.snapshot + es.summarize_event({ kind: "custom", key: "whatever", user: user }) + + expect(es.snapshot).to eq snapshot + end + + it "tracks start and end dates" do + es = subject.new(LaunchDarkly::Config.new) + flag = { key: "key" } + event1 = { kind: "feature", creationDate: 2000, user: user } + event2 = { kind: "feature", creationDate: 1000, user: user } + event3 = { kind: "feature", creationDate: 1500, user: user } + es.summarize_event(event1) + es.summarize_event(event2) + es.summarize_event(event3) + data = es.output(es.snapshot) + + expect(data[:startDate]).to be 1000 + expect(data[:endDate]).to be 2000 + end + + it "counts events" do + es = subject.new(LaunchDarkly::Config.new) + flag1 = { key: "key1", version: 11 } + flag2 = { key: "key2", version: 22 } + event1 = { kind: "feature", key: "key1", version: 11, user: user, variation: 1, value: "value1", default: "default1" } + event2 = { kind: "feature", key: "key1", version: 11, user: user, variation: 2, value: "value2", default: "default1" } + event3 = { kind: "feature", key: "key2", version: 22, user: user, variation: 1, value: "value99", default: "default2" } + event4 = { kind: "feature", key: "key1", version: 11, user: user, variation: 1, value: "value1", default: "default1" } + event5 = { kind: "feature", key: "badkey", user: user, variation: nil, value: "default3", default: "default3" } + [event1, event2, event3, event4, event5].each { |e| es.summarize_event(e) } + data = es.output(es.snapshot) + + data[:features]["key1"][:counters].sort! { |a, b| a[:value] <=> b[:value] } + expectedFeatures = { + "key1" => { + default: "default1", + counters: [ + { value: "value1", version: 11, count: 2 }, + { value: "value2", version: 11, count: 1 } + ] + }, + "key2" => { + default: "default2", + counters: [ + { value: "value99", version: 22, count: 1 } + ] + }, + "badkey" => { + default: "default3", + counters: [ + { value: "default3", unknown: true, count: 1 } + ] + } + } + expect(data[:features]).to eq expectedFeatures + end +end diff --git a/spec/events_spec.rb b/spec/events_spec.rb new file mode 100644 index 00000000..9b561a04 --- /dev/null +++ b/spec/events_spec.rb @@ -0,0 +1,307 @@ +require "spec_helper" +require "faraday" +require "time" + +describe LaunchDarkly::EventProcessor do + subject { LaunchDarkly::EventProcessor } + + let(:default_config) { LaunchDarkly::Config.new } + let(:hc) { FakeHttpClient.new } + let(:user) { { key: "userkey", name: "Red" } } + + after(:each) do + if !@ep.nil? + @ep.stop + end + end + + it "queues identify event" do + @ep = subject.new("sdk_key", default_config, hc) + e = { + kind: "identify", + user: user + } + @ep.add_event(e) + + output = flush_and_get_events + expect(output).to contain_exactly(e) + end + + it "queues individual feature event with index event" do + @ep = subject.new("sdk_key", default_config, hc) + flag = { key: "flagkey", version: 11 } + fe = { + kind: "feature", + key: "flagkey", + version: 11, + user: user, + variation: 1, + value: "value", + trackEvents: true + } + @ep.add_event(fe) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(index_event(fe)), + eq(feature_event(fe, flag, false, nil)), + include(:kind => "summary") + ) + end + + it "can include inline user in feature event" do + config = LaunchDarkly::Config.new(inline_users_in_events: true) + @ep = subject.new("sdk_key", config, hc) + flag = { key: "flagkey", version: 11 } + fe = { + kind: "feature", + key: "flagkey", + version: 11, + user: user, + variation: 1, + value: "value", + trackEvents: true + } + @ep.add_event(fe) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(feature_event(fe, flag, false, user)), + include(:kind => "summary") + ) + end + + it "sets event kind to debug if flag is temporarily in debug mode" do + @ep = subject.new("sdk_key", default_config, hc) + flag = { key: "flagkey", version: 11 } + future_time = (Time.now.to_f * 1000).to_i + 1000000 + fe = { + kind: "feature", + key: "flagkey", + version: 11, + user: user, + variation: 1, + value: "value", + debugEventsUntilDate: future_time + } + @ep.add_event(fe) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(index_event(fe)), + eq(feature_event(fe, flag, true, nil)), + include(:kind => "summary") + ) + end + + it "generates only one index event for multiple events with same user" do + @ep = subject.new("sdk_key", default_config, hc) + flag1 = { key: "flagkey1", version: 11 } + flag2 = { key: "flagkey2", version: 22 } + future_time = (Time.now.to_f * 1000).to_i + 1000000 + fe1 = { + kind: "feature", + key: "flagkey1", + version: 11, + user: user, + variation: 1, + value: "value", + trackEvents: true + } + fe2 = { + kind: "feature", + key: "flagkey2", + version: 22, + user: user, + variation: 1, + value: "value", + trackEvents: true + } + @ep.add_event(fe1) + @ep.add_event(fe2) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(index_event(fe1)), + eq(feature_event(fe1, flag1, false, nil)), + eq(feature_event(fe2, flag2, false, nil)), + include(:kind => "summary") + ) + end + + it "summarizes non-tracked events" do + @ep = subject.new("sdk_key", default_config, hc) + flag1 = { key: "flagkey1", version: 11 } + flag2 = { key: "flagkey2", version: 22 } + future_time = (Time.now.to_f * 1000).to_i + 1000000 + fe1 = { + kind: "feature", + key: "flagkey1", + version: 11, + user: user, + variation: 1, + value: "value1", + default: "default1" + } + fe2 = { + kind: "feature", + key: "flagkey2", + version: 22, + user: user, + variation: 1, + value: "value2", + default: "default2" + } + @ep.add_event(fe1) + @ep.add_event(fe2) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(index_event(fe1)), + eq({ + kind: "summary", + startDate: fe1[:creationDate], + endDate: fe2[:creationDate], + features: { + flagkey1: { + default: "default1", + counters: [ + { version: 11, value: "value1", count: 1 } + ] + }, + flagkey2: { + default: "default2", + counters: [ + { version: 22, value: "value2", count: 1 } + ] + } + } + }) + ) + end + + it "queues custom event with user" do + @ep = subject.new("sdk_key", default_config, hc) + e = { + kind: "custom", + key: "eventkey", + user: user, + data: { thing: "stuff" } + } + @ep.add_event(e) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(index_event(e)), + eq(custom_event(e, nil)) + ) + end + + it "can include inline user in custom event" do + config = LaunchDarkly::Config.new(inline_users_in_events: true) + @ep = subject.new("sdk_key", config, hc) + e = { + kind: "custom", + key: "eventkey", + user: user, + data: { thing: "stuff" } + } + @ep.add_event(e) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(custom_event(e, user)) + ) + end + + it "sends nothing if there are no events" do + @ep = subject.new("sdk_key", default_config, hc) + @ep.flush + expect(hc.request_received).to be nil + end + + it "sends SDK key" do + @ep = subject.new("sdk_key", default_config, hc) + e = { + kind: "identify", + user: user + } + @ep.add_event(e) + + flush_and_get_events + expect(hc.request_received.headers["Authorization"]).to eq "sdk_key" + end + + def index_event(e) + { + kind: "index", + creationDate: e[:creationDate], + user: e[:user] + } + end + + def feature_event(e, flag, debug, inline_user) + out = { + kind: debug ? "debug" : "feature", + creationDate: e[:creationDate], + key: flag[:key], + version: flag[:version], + value: e[:value] + } + if inline_user.nil? + out[:userKey] = e[:user][:key] + else + out[:user] = inline_user + end + out + end + + def custom_event(e, inline_user) + out = { + kind: "custom", + creationDate: e[:creationDate], + key: e[:key] + } + out[:data] = e[:data] if e.has_key?(:data) + if inline_user.nil? + out[:userKey] = e[:user][:key] + else + out[:user] = inline_user + end + out + end + + def flush_and_get_events + @ep.flush + req = hc.request_received + JSON.parse(req.body, symbolize_names: true) + end + + class FakeHttpClient + def post(uri) + req = Faraday::Request.create("POST") + req.headers = {} + req.options = Faraday::RequestOptions.new + yield req + @request_received = req + resp = Faraday::Response.new + resp.finish({ + status: 200, + response_headers: { + Date: Time.now.httpdate + } + }) + resp + end + + attr_reader :request_received + end + + class FakeResponse + def initialize(status) + @status = status + end + + attr_reader :status + end +end diff --git a/spec/fixtures/feature.json b/spec/fixtures/feature.json index 152565f7..0001e990 100644 --- a/spec/fixtures/feature.json +++ b/spec/fixtures/feature.json @@ -32,5 +32,6 @@ true, false ], + "trackEvents": false, "deleted":false } \ No newline at end of file diff --git a/spec/ldclient_spec.rb b/spec/ldclient_spec.rb index bf6c69a0..4342b06f 100644 --- a/spec/ldclient_spec.rb +++ b/spec/ldclient_spec.rb @@ -3,7 +3,12 @@ describe LaunchDarkly::LDClient do subject { LaunchDarkly::LDClient } - let(:config) { LaunchDarkly::Config.new({offline: true}) } + let(:offline_config) { LaunchDarkly::Config.new({offline: true}) } + let(:offline_client) do + subject.new("secret", offline_config) + end + let(:update_processor) { NullUpdateProcessor.new } + let(:config) { LaunchDarkly::Config.new({send_events: false, update_processor: update_processor}) } let(:client) do subject.new("secret", config) end @@ -24,11 +29,32 @@ JSON.parse(data, symbolize_names: true) end + def event_processor + client.instance_variable_get(:@event_processor) + end + describe '#variation' do it "will return the default value if the client is offline" do - result = client.variation(feature[:key], user, "default") + result = offline_client.variation("doesntmatter", user, "default") expect(result).to eq "default" end + + it "queues a feature request event for an unknown feature" do + expect(event_processor).to receive(:add_event).with(hash_including( + kind: "feature", key: "badkey", user: user, value: "default", default: "default" + )) + client.variation("badkey", user, "default") + end + + it "queues a feature request event for an existing feature" do + config.feature_store.init({ LaunchDarkly::FEATURES => {} }) + config.feature_store.upsert(LaunchDarkly::FEATURES, feature) + expect(event_processor).to receive(:add_event).with(hash_including( + kind: "feature", key: feature[:key], version: feature[:version], user: user, + value: true, default: "default", trackEvents: false, debugEventsUntilDate: nil + )) + client.variation(feature[:key], user, "default") + end end describe '#secure_mode_hash' do @@ -40,22 +66,24 @@ describe '#track' do it "queues up an custom event" do - expect(client.instance_variable_get(:@event_processor)).to receive(:add_event).with(hash_including(kind: "custom", key: "custom_event_name", user: user, data: 42)) + expect(event_processor).to receive(:add_event).with(hash_including(kind: "custom", key: "custom_event_name", user: user, data: 42)) client.track("custom_event_name", user, 42) end + it "sanitizes the user in the event" do - expect(client.instance_variable_get(:@event_processor)).to receive(:add_event).with(hash_including(user: sanitized_numeric_key_user)) + expect(event_processor).to receive(:add_event).with(hash_including(user: sanitized_numeric_key_user)) client.track("custom_event_name", numeric_key_user, nil) end end describe '#identify' do it "queues up an identify event" do - expect(client.instance_variable_get(:@event_processor)).to receive(:add_event).with(hash_including(kind: "identify", key: user[:key], user: user)) + expect(event_processor).to receive(:add_event).with(hash_including(kind: "identify", key: user[:key], user: user)) client.identify(user) end + it "sanitizes the user in the event" do - expect(client.instance_variable_get(:@event_processor)).to receive(:add_event).with(hash_including(user: sanitized_numeric_key_user)) + expect(event_processor).to receive(:add_event).with(hash_including(user: sanitized_numeric_key_user)) client.identify(numeric_key_user) end end @@ -75,21 +103,17 @@ let(:config) { LaunchDarkly::Config.new({offline: true, send_events: false}) } let(:client) { subject.new("secret", config) } - let(:queue) { client.instance_variable_get(:@event_processor).instance_variable_get(:@queue) } - - it "does not enqueue a feature event" do - client.variation(feature[:key], user, "default") - expect(queue.empty?).to be true + it "uses a NullEventProcessor" do + expect(event_processor).to be_a(LaunchDarkly::NullEventProcessor) end + end - it "does not enqueue a custom event" do - client.track("custom_event_name", user, 42) - expect(queue.empty?).to be true + class NullUpdateProcessor + def start end - it "does not enqueue an identify event" do - client.identify(user) - expect(queue.empty?).to be true + def initialized? + true end end end \ No newline at end of file diff --git a/spec/simple_lru_cache_spec.rb b/spec/simple_lru_cache_spec.rb new file mode 100644 index 00000000..fabf8738 --- /dev/null +++ b/spec/simple_lru_cache_spec.rb @@ -0,0 +1,24 @@ +require "spec_helper" + +describe LaunchDarkly::SimpleLRUCacheSet do + subject { LaunchDarkly::SimpleLRUCacheSet } + + it "retains values up to capacity" do + lru = subject.new(3) + expect(lru.add("a")).to be false + expect(lru.add("b")).to be false + expect(lru.add("c")).to be false + expect(lru.add("a")).to be true + expect(lru.add("b")).to be true + expect(lru.add("c")).to be true + end + + it "discards oldest value on overflow" do + lru = subject.new(2) + expect(lru.add("a")).to be false + expect(lru.add("b")).to be false + expect(lru.add("a")).to be true + expect(lru.add("c")).to be false # b is discarded as oldest + expect(lru.add("b")).to be false + end +end \ No newline at end of file diff --git a/spec/event_serializer_spec.rb b/spec/user_filter_spec.rb similarity index 50% rename from spec/event_serializer_spec.rb rename to spec/user_filter_spec.rb index 14755045..96814289 100644 --- a/spec/event_serializer_spec.rb +++ b/spec/user_filter_spec.rb @@ -1,7 +1,7 @@ require "spec_helper" -describe LaunchDarkly::EventSerializer do - subject { LaunchDarkly::EventSerializer } +describe LaunchDarkly::UserFilter do + subject { LaunchDarkly::UserFilter } let(:base_config) { LaunchDarkly::Config.new } let(:config_with_all_attrs_private) { LaunchDarkly::Config.new({ all_attributes_private: true })} @@ -45,68 +45,47 @@ { key: 'abc', anonymous: 'true', custom: { }, privateAttrs: [ 'bizzle', 'dizzle' ]} } - - def make_event(user) - { - creationDate: 1000000, - key: 'xyz', - kind: 'thing', - user: user - } - end - - def parse_results(js) - JSON.parse(js, symbolize_names: true) - end - describe "serialize_events" do it "includes all user attributes by default" do - es = LaunchDarkly::EventSerializer.new(base_config) - event = make_event(user) - j = es.serialize_events([event]) - expect(parse_results(j)).to eq [event] + uf = LaunchDarkly::UserFilter.new(base_config) + result = uf.transform_user_props(user) + expect(result).to eq user end it "hides all except key if all_attributes_private is true" do - es = LaunchDarkly::EventSerializer.new(config_with_all_attrs_private) - event = make_event(user) - j = es.serialize_events([event]) - expect(parse_results(j)).to eq [make_event(user_with_all_attrs_hidden)] + uf = LaunchDarkly::UserFilter.new(config_with_all_attrs_private) + result = uf.transform_user_props(user) + expect(result).to eq user_with_all_attrs_hidden end it "hides some attributes if private_attribute_names is set" do - es = LaunchDarkly::EventSerializer.new(config_with_some_attrs_private) - event = make_event(user) - j = es.serialize_events([event]) - expect(parse_results(j)).to eq [make_event(user_with_some_attrs_hidden)] + uf = LaunchDarkly::UserFilter.new(config_with_some_attrs_private) + result = uf.transform_user_props(user) + expect(result).to eq user_with_some_attrs_hidden end it "hides attributes specified in per-user privateAttrs" do - es = LaunchDarkly::EventSerializer.new(base_config) - event = make_event(user_specifying_own_private_attr) - j = es.serialize_events([event]) - expect(parse_results(j)).to eq [make_event(user_with_own_specified_attr_hidden)] + uf = LaunchDarkly::UserFilter.new(base_config) + result = uf.transform_user_props(user_specifying_own_private_attr) + expect(result).to eq user_with_own_specified_attr_hidden end it "looks at both per-user privateAttrs and global config" do - es = LaunchDarkly::EventSerializer.new(config_with_some_attrs_private) - event = make_event(user_specifying_own_private_attr) - j = es.serialize_events([event]) - expect(parse_results(j)).to eq [make_event(user_with_all_attrs_hidden)] + uf = LaunchDarkly::UserFilter.new(config_with_some_attrs_private) + result = uf.transform_user_props(user_specifying_own_private_attr) + expect(result).to eq user_with_all_attrs_hidden end it "strips out any unknown top-level attributes" do - es = LaunchDarkly::EventSerializer.new(base_config) - event = make_event(user_with_unknown_top_level_attrs) - j = es.serialize_events([event]) - expect(parse_results(j)).to eq [make_event(user)] + uf = LaunchDarkly::UserFilter.new(base_config) + result = uf.transform_user_props(user_with_unknown_top_level_attrs) + expect(result).to eq user end it "leaves the anonymous attribute as is" do - es = LaunchDarkly::EventSerializer.new(config_with_all_attrs_private) - event = make_event(anon_user) - j = es.serialize_events([event]) - expect(parse_results(j)).to eq [make_event(anon_user_with_all_attrs_hidden)] + uf = LaunchDarkly::UserFilter.new(config_with_all_attrs_private) + result = uf.transform_user_props(anon_user) + expect(result).to eq anon_user_with_all_attrs_hidden end end end From 8156e4f2daa3a20baa65d20d52262188c7c01b50 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Mon, 19 Mar 2018 18:27:16 -0700 Subject: [PATCH 02/34] fix debugEventsUntilDate logic to use whichever cutoff time is later --- lib/ldclient-rb/events.rb | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index 5d883ce2..b52f99f5 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -87,9 +87,9 @@ def should_track_full_event(event, now_millis) true else if event.has_key?(:debugEventsUntilDate) + debugUntil = event[:debugEventsUntilDate] last_past = @last_known_past_time.value - (last_past != 0 && event[:debugEventsUntilDate] > last_past) || - (event[:debugEventsUntilDate] > now_millis) + debugUntil > last_past && debugUntil > now_millis else false end From 19ee62fb96189acbacf226bec606c527f8c3ede8 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Mon, 19 Mar 2018 18:27:27 -0700 Subject: [PATCH 03/34] unit tests for last known server time logic --- spec/events_spec.rb | 80 +++++++++++++++++++++++++++++++++++++++++++-- 1 file changed, 77 insertions(+), 3 deletions(-) diff --git a/spec/events_spec.rb b/spec/events_spec.rb index 9b561a04..5db52959 100644 --- a/spec/events_spec.rb +++ b/spec/events_spec.rb @@ -94,6 +94,74 @@ ) end + it "ends debug mode based on client time if client time is later than server time" do + @ep = subject.new("sdk_key", default_config, hc) + + # Pick a server time that is somewhat behind the client time + server_time = (Time.now.to_f * 1000).to_i - 20000 + + # Send and flush an event we don't care about, just to set the last server time + hc.set_server_time(server_time) + @ep.add_event({ kind: "identify", user: { key: "otherUser" }}) + flush_and_get_events + + # Now send an event with debug mode on, with a "debug until" time that is further in + # the future than the server time, but in the past compared to the client. + flag = { key: "flagkey", version: 11 } + debug_until = server_time + 1000 + fe = { + kind: "feature", + key: "flagkey", + version: 11, + user: user, + variation: 1, + value: "value", + debugEventsUntilDate: debug_until + } + @ep.add_event(fe) + + # Should get a summary event only, not a full feature event + output = flush_and_get_events + expect(output).to contain_exactly( + eq(index_event(fe)), + include(:kind => "summary") + ) + end + + it "ends debug mode based on server time if server time is later than client time" do + @ep = subject.new("sdk_key", default_config, hc) + + # Pick a server time that is somewhat ahead of the client time + server_time = (Time.now.to_f * 1000).to_i + 20000 + + # Send and flush an event we don't care about, just to set the last server time + hc.set_server_time(server_time) + @ep.add_event({ kind: "identify", user: { key: "otherUser" }}) + flush_and_get_events + + # Now send an event with debug mode on, with a "debug until" time that is further in + # the future than the server time, but in the past compared to the client. + flag = { key: "flagkey", version: 11 } + debug_until = server_time - 1000 + fe = { + kind: "feature", + key: "flagkey", + version: 11, + user: user, + variation: 1, + value: "value", + debugEventsUntilDate: debug_until + } + @ep.add_event(fe) + + # Should get a summary event only, not a full feature event + output = flush_and_get_events + expect(output).to contain_exactly( + eq(index_event(fe)), + include(:kind => "summary") + ) + end + it "generates only one index event for multiple events with same user" do @ep = subject.new("sdk_key", default_config, hc) flag1 = { key: "flagkey1", version: 11 } @@ -278,6 +346,10 @@ def flush_and_get_events end class FakeHttpClient + def set_server_time(time_millis) + @server_time = Time.at(time_millis.to_f / 1000) + end + def post(uri) req = Faraday::Request.create("POST") req.headers = {} @@ -285,11 +357,13 @@ def post(uri) yield req @request_received = req resp = Faraday::Response.new + headers = {} + if @server_time + headers["Date"] = @server_time.httpdate + end resp.finish({ status: 200, - response_headers: { - Date: Time.now.httpdate - } + response_headers: headers }) resp end From 12c7a56fa4cff30f6ec33d60a79bc4650b4aac6d Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Thu, 22 Mar 2018 11:31:16 -0700 Subject: [PATCH 04/34] misc fixes to summary events --- lib/ldclient-rb/events.rb | 109 ++++++++++++-------- spec/events_spec.rb | 210 +++++++++++++++++++++----------------- 2 files changed, 185 insertions(+), 134 deletions(-) diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index b52f99f5..f8d0434a 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -18,7 +18,7 @@ def stop class EventProcessor def initialize(sdk_key, config, client) - @lock = Mutex.new + @queue = Queue.new @events = [] @summarizer = EventSummarizer.new(config) @sdk_key = sdk_key @@ -26,62 +26,91 @@ def initialize(sdk_key, config, client) @user_filter = UserFilter.new(config) @client = client ? client : Faraday.new @stopped = Concurrent::AtomicBoolean.new(false) + @capacity_exceeded = false @last_known_past_time = Concurrent::AtomicFixnum.new(0) @flush_task = Concurrent::TimerTask.new(execution_interval: @config.flush_interval) do - flush_async + @queue << [:flush, nil] end @users_flush_task = Concurrent::TimerTask.new(execution_interval: @config.user_keys_flush_interval) do - @summarizer.reset_users + @queue << [:flush_users, nil] end + Thread.new { main_loop } end def stop + flush if @stopped.make_true # There seems to be no such thing as "close" in Faraday: https://github.com/lostisland/faraday/issues/241 @flush_task.shutdown @users_flush_task.shutdown + # Tell the worker thread to stop + @queue << [:stop] end end def add_event(event) return if @stopped.value - - now_millis = (Time.now.to_f * 1000).to_i event[:creationDate] = now_millis - - @lock.synchronize { - # For each user we haven't seen before, we add an index event - unless this is already - # an identify event for that user. - if !@config.inline_users_in_events && event.has_key?(:user) && !@summarizer.notice_user(event[:user]) - if event[:kind] != "identify" - queue_event({ - kind: "index", - creationDate: event[:creationDate], - user: event[:user] - }) - end - end - - # Always record the event in the summary. - @summarizer.summarize_event(event) - - if should_track_full_event(event, now_millis) - # Queue the event as-is; we'll transform it into an output event when we're flushing. - queue_event(event) - end - } + @queue << [:event, event] end def flush + return if @stopped.value # An explicit flush should be synchronous, so we use a semaphore to wait for the result semaphore = Concurrent::Semaphore.new(0) - flush_internal(semaphore) + @queue << [:flush, semaphore] semaphore.acquire end private - def should_track_full_event(event, now_millis) + def now_millis() + (Time.now.to_f * 1000).to_i + end + + def main_loop() + loop do + begin + message = @queue.pop + case message[0] + when :event + dispatch_event(message[1]) + when :flush + flush_internal(message[1]) + when :flush_users + @summarizer.reset_users + when :stop + break + end + rescue => e + @config.logger.warn { "[LDClient] Unexpected error in event processor: #{e.inspect}. \nTrace: #{e.backtrace}" } + end + end + end + + def dispatch_event(event) + # For each user we haven't seen before, we add an index event - unless this is already + # an identify event for that user. + if !@config.inline_users_in_events && event.has_key?(:user) && !@summarizer.notice_user(event[:user]) + if event[:kind] != "identify" + queue_event({ + kind: "index", + creationDate: event[:creationDate], + user: @user_filter.transform_user_props(event[:user]) + }) + end + end + + # Always record the event in the summary. + @summarizer.summarize_event(event) + + if should_track_full_event(event) + # Queue the event as-is; we'll transform it into an output event when we're flushing. + queue_event(event) + end + end + + def should_track_full_event(event) if event[:kind] == "feature" if event[:trackEvents] true @@ -103,23 +132,21 @@ def queue_event(event) if @events.length < @config.capacity @config.logger.debug { "[LDClient] Enqueueing event: #{event.to_json}" } @events.push(event) + @capacity_exceeded = false else - @config.logger.warn { "[LDClient] Exceeded event queue capacity. Increase capacity to avoid dropping events." } + if !@capacity_exceeded + @capacity_exceeded = true + @config.logger.warn { "[LDClient] Exceeded event queue capacity. Increase capacity to avoid dropping events." } + end end end - def flush_async - flush_internal(nil) - end - def flush_internal(reply_semaphore) - old_events, snapshot = @lock.synchronize { - old_events = @events - @events = [] - snapshot = @summarizer.snapshot - [old_events, snapshot] - } - if !old_events.empty? || !snapshot[:counters].empty? + old_events = @events + @events = [] + snapshot = @summarizer.snapshot + + if !@stopped.value && (!old_events.empty? || !snapshot[:counters].empty?) Thread.new do begin post_flushed_events(old_events, snapshot) diff --git a/spec/events_spec.rb b/spec/events_spec.rb index 5db52959..12540b09 100644 --- a/spec/events_spec.rb +++ b/spec/events_spec.rb @@ -8,6 +8,7 @@ let(:default_config) { LaunchDarkly::Config.new } let(:hc) { FakeHttpClient.new } let(:user) { { key: "userkey", name: "Red" } } + let(:filtered_user) { { key: "userkey", privateAttrs: [ "name" ] } } after(:each) do if !@ep.nil? @@ -17,33 +18,57 @@ it "queues identify event" do @ep = subject.new("sdk_key", default_config, hc) - e = { - kind: "identify", - user: user - } + e = { kind: "identify", user: user } @ep.add_event(e) output = flush_and_get_events expect(output).to contain_exactly(e) end + it "filters user in identify event" do + config = LaunchDarkly::Config.new(all_attributes_private: true) + @ep = subject.new("sdk_key", config, hc) + e = { kind: "identify", user: user } + @ep.add_event(e) + + output = flush_and_get_events + expect(output).to contain_exactly({ + kind: "identify", + creationDate: e[:creationDate], + user: filtered_user + }) + end + it "queues individual feature event with index event" do @ep = subject.new("sdk_key", default_config, hc) flag = { key: "flagkey", version: 11 } fe = { - kind: "feature", - key: "flagkey", - version: 11, - user: user, - variation: 1, - value: "value", - trackEvents: true + kind: "feature", key: "flagkey", version: 11, user: user, + variation: 1, value: "value", trackEvents: true } @ep.add_event(fe) output = flush_and_get_events expect(output).to contain_exactly( - eq(index_event(fe)), + eq(index_event(fe, user)), + eq(feature_event(fe, flag, false, nil)), + include(:kind => "summary") + ) + end + + it "filters user in index event" do + config = LaunchDarkly::Config.new(all_attributes_private: true) + @ep = subject.new("sdk_key", config, hc) + flag = { key: "flagkey", version: 11 } + fe = { + kind: "feature", key: "flagkey", version: 11, user: user, + variation: 1, value: "value", trackEvents: true + } + @ep.add_event(fe) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(index_event(fe, filtered_user)), eq(feature_event(fe, flag, false, nil)), include(:kind => "summary") ) @@ -54,13 +79,8 @@ @ep = subject.new("sdk_key", config, hc) flag = { key: "flagkey", version: 11 } fe = { - kind: "feature", - key: "flagkey", - version: 11, - user: user, - variation: 1, - value: "value", - trackEvents: true + kind: "feature", key: "flagkey", version: 11, user: user, + variation: 1, value: "value", trackEvents: true } @ep.add_event(fe) @@ -71,24 +91,36 @@ ) end + it "filters user in feature event" do + config = LaunchDarkly::Config.new(all_attributes_private: true, inline_users_in_events: true) + @ep = subject.new("sdk_key", config, hc) + flag = { key: "flagkey", version: 11 } + fe = { + kind: "feature", key: "flagkey", version: 11, user: user, + variation: 1, value: "value", trackEvents: true + } + @ep.add_event(fe) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(feature_event(fe, flag, false, filtered_user)), + include(:kind => "summary") + ) + end + it "sets event kind to debug if flag is temporarily in debug mode" do @ep = subject.new("sdk_key", default_config, hc) flag = { key: "flagkey", version: 11 } future_time = (Time.now.to_f * 1000).to_i + 1000000 fe = { - kind: "feature", - key: "flagkey", - version: 11, - user: user, - variation: 1, - value: "value", - debugEventsUntilDate: future_time + kind: "feature", key: "flagkey", version: 11, user: user, + variation: 1, value: "value", trackEvents: false, debugEventsUntilDate: future_time } @ep.add_event(fe) output = flush_and_get_events expect(output).to contain_exactly( - eq(index_event(fe)), + eq(index_event(fe, user)), eq(feature_event(fe, flag, true, nil)), include(:kind => "summary") ) @@ -110,20 +142,15 @@ flag = { key: "flagkey", version: 11 } debug_until = server_time + 1000 fe = { - kind: "feature", - key: "flagkey", - version: 11, - user: user, - variation: 1, - value: "value", - debugEventsUntilDate: debug_until + kind: "feature", key: "flagkey", version: 11, user: user, + variation: 1, value: "value", trackEvents: false, debugEventsUntilDate: debug_until } @ep.add_event(fe) # Should get a summary event only, not a full feature event output = flush_and_get_events expect(output).to contain_exactly( - eq(index_event(fe)), + eq(index_event(fe, user)), include(:kind => "summary") ) end @@ -144,20 +171,15 @@ flag = { key: "flagkey", version: 11 } debug_until = server_time - 1000 fe = { - kind: "feature", - key: "flagkey", - version: 11, - user: user, - variation: 1, - value: "value", - debugEventsUntilDate: debug_until + kind: "feature", key: "flagkey", version: 11, user: user, + variation: 1, value: "value", trackEvents: false, debugEventsUntilDate: debug_until } @ep.add_event(fe) # Should get a summary event only, not a full feature event output = flush_and_get_events expect(output).to contain_exactly( - eq(index_event(fe)), + eq(index_event(fe, user)), include(:kind => "summary") ) end @@ -168,29 +190,19 @@ flag2 = { key: "flagkey2", version: 22 } future_time = (Time.now.to_f * 1000).to_i + 1000000 fe1 = { - kind: "feature", - key: "flagkey1", - version: 11, - user: user, - variation: 1, - value: "value", - trackEvents: true + kind: "feature", key: "flagkey1", version: 11, user: user, + variation: 1, value: "value", trackEvents: true } fe2 = { - kind: "feature", - key: "flagkey2", - version: 22, - user: user, - variation: 1, - value: "value", - trackEvents: true + kind: "feature", key: "flagkey2", version: 22, user: user, + variation: 1, value: "value", trackEvents: true } @ep.add_event(fe1) @ep.add_event(fe2) output = flush_and_get_events expect(output).to contain_exactly( - eq(index_event(fe1)), + eq(index_event(fe1, user)), eq(feature_event(fe1, flag1, false, nil)), eq(feature_event(fe2, flag2, false, nil)), include(:kind => "summary") @@ -203,29 +215,19 @@ flag2 = { key: "flagkey2", version: 22 } future_time = (Time.now.to_f * 1000).to_i + 1000000 fe1 = { - kind: "feature", - key: "flagkey1", - version: 11, - user: user, - variation: 1, - value: "value1", - default: "default1" + kind: "feature", key: "flagkey1", version: 11, user: user, + variation: 1, value: "value1", default: "default1" } fe2 = { - kind: "feature", - key: "flagkey2", - version: 22, - user: user, - variation: 1, - value: "value2", - default: "default2" + kind: "feature", key: "flagkey2", version: 22, user: user, + variation: 1, value: "value2", default: "default2" } @ep.add_event(fe1) @ep.add_event(fe2) output = flush_and_get_events expect(output).to contain_exactly( - eq(index_event(fe1)), + eq(index_event(fe1, user)), eq({ kind: "summary", startDate: fe1[:creationDate], @@ -250,17 +252,12 @@ it "queues custom event with user" do @ep = subject.new("sdk_key", default_config, hc) - e = { - kind: "custom", - key: "eventkey", - user: user, - data: { thing: "stuff" } - } + e = { kind: "custom", key: "eventkey", user: user, data: { thing: "stuff" } } @ep.add_event(e) output = flush_and_get_events expect(output).to contain_exactly( - eq(index_event(e)), + eq(index_event(e, user)), eq(custom_event(e, nil)) ) end @@ -268,12 +265,7 @@ it "can include inline user in custom event" do config = LaunchDarkly::Config.new(inline_users_in_events: true) @ep = subject.new("sdk_key", config, hc) - e = { - kind: "custom", - key: "eventkey", - user: user, - data: { thing: "stuff" } - } + e = { kind: "custom", key: "eventkey", user: user, data: { thing: "stuff" } } @ep.add_event(e) output = flush_and_get_events @@ -282,6 +274,18 @@ ) end + it "filters user in custom event" do + config = LaunchDarkly::Config.new(all_attributes_private: true, inline_users_in_events: true) + @ep = subject.new("sdk_key", config, hc) + e = { kind: "custom", key: "eventkey", user: user, data: { thing: "stuff" } } + @ep.add_event(e) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(custom_event(e, filtered_user)) + ) + end + it "sends nothing if there are no events" do @ep = subject.new("sdk_key", default_config, hc) @ep.flush @@ -290,21 +294,32 @@ it "sends SDK key" do @ep = subject.new("sdk_key", default_config, hc) - e = { - kind: "identify", - user: user - } + e = { kind: "identify", user: user } @ep.add_event(e) flush_and_get_events expect(hc.request_received.headers["Authorization"]).to eq "sdk_key" end - def index_event(e) + it "stops posting events after getting a 401 error" do + @ep = subject.new("sdk_key", default_config, hc) + e = { kind: "identify", user: user } + @ep.add_event(e) + hc.set_response_status(401) + flush_and_get_events + expect(hc.request_received).not_to be_nil + hc.reset + + @ep.add_event(e) + @ep.flush + expect(hc.request_received).to be_nil + end + + def index_event(e, user) { kind: "index", creationDate: e[:creationDate], - user: e[:user] + user: user } end @@ -346,10 +361,19 @@ def flush_and_get_events end class FakeHttpClient + def set_response_status(status) + @status = status + end + def set_server_time(time_millis) @server_time = Time.at(time_millis.to_f / 1000) end + def reset + @request_received = nil + @status = 200 + end + def post(uri) req = Faraday::Request.create("POST") req.headers = {} @@ -362,7 +386,7 @@ def post(uri) headers["Date"] = @server_time.httpdate end resp.finish({ - status: 200, + status: @status ? @status : 200, response_headers: headers }) resp From 638a1787f26e2bbc6b319d09203b709748ab668c Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Thu, 22 Mar 2018 16:01:48 -0700 Subject: [PATCH 05/34] create classes for message types --- lib/ldclient-rb/events.rb | 44 ++++++++++++++++++++++++++++----------- 1 file changed, 32 insertions(+), 12 deletions(-) diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index f8d0434a..c0c9e503 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -16,6 +16,26 @@ def stop end end + class EventMessage + def initialize(event) + @event = event + end + attr_reader :event + end + + class FlushMessage + def initialize(reply) + @reply = reply + end + attr_reader :reply + end + + class FlushUsersMessage + end + + class StopMessage + end + class EventProcessor def initialize(sdk_key, config, client) @queue = Queue.new @@ -29,10 +49,10 @@ def initialize(sdk_key, config, client) @capacity_exceeded = false @last_known_past_time = Concurrent::AtomicFixnum.new(0) @flush_task = Concurrent::TimerTask.new(execution_interval: @config.flush_interval) do - @queue << [:flush, nil] + @queue << FlushMessage.new(nil) end @users_flush_task = Concurrent::TimerTask.new(execution_interval: @config.user_keys_flush_interval) do - @queue << [:flush_users, nil] + @queue << FlushUsersMessage.new end Thread.new { main_loop } end @@ -44,21 +64,21 @@ def stop @flush_task.shutdown @users_flush_task.shutdown # Tell the worker thread to stop - @queue << [:stop] + @queue << StopMessage.new end end def add_event(event) return if @stopped.value event[:creationDate] = now_millis - @queue << [:event, event] + @queue << EventMessage.new(event) end def flush return if @stopped.value # An explicit flush should be synchronous, so we use a semaphore to wait for the result semaphore = Concurrent::Semaphore.new(0) - @queue << [:flush, semaphore] + @queue << FlushMessage.new(semaphore) semaphore.acquire end @@ -72,14 +92,14 @@ def main_loop() loop do begin message = @queue.pop - case message[0] - when :event - dispatch_event(message[1]) - when :flush - flush_internal(message[1]) - when :flush_users + case message + when EventMessage + dispatch_event(message.event) + when FlushMessage + flush_internal(message.reply) + when FlushUsersMessage @summarizer.reset_users - when :stop + when StopMessage break end rescue => e From 25dd051a309935cf7f3d24398038e14b84ee3077 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Mon, 26 Mar 2018 15:49:01 -0700 Subject: [PATCH 06/34] misc reorganization of event processor/summarizer classes --- lib/ldclient-rb/event_summarizer.rb | 56 +------ lib/ldclient-rb/events.rb | 238 ++++++++++++++++++++-------- spec/event_summarizer_spec.rb | 75 +++------ 3 files changed, 191 insertions(+), 178 deletions(-) diff --git a/lib/ldclient-rb/event_summarizer.rb b/lib/ldclient-rb/event_summarizer.rb index 6b0c06c9..8adb6a80 100644 --- a/lib/ldclient-rb/event_summarizer.rb +++ b/lib/ldclient-rb/event_summarizer.rb @@ -1,32 +1,16 @@ module LaunchDarkly - EventSummarySnapshot = Struct.new(:start_date, :end_date, :counters) + EventSummary = Struct.new(:start_date, :end_date, :counters) # Manages the state of summarizable information for the EventProcessor, including the # event counters and user deduplication. Note that the methods of this class are # deliberately not thread-safe; the EventProcessor is responsible for enforcing # synchronization across both the summarizer and the event queue. class EventSummarizer - def initialize(config) - @config = config - @users = SimpleLRUCacheSet.new(@config.user_keys_capacity) + def initialize reset_state end - # Adds to the set of users we've noticed, and return true if the user was already known to us. - def notice_user(user) - if user.nil? || !user.has_key?(:key) - true - else - @users.add(user[:key]) - end - end - - # Resets the set of users we've seen. - def reset_users - @users.reset - end - # Adds this event to our counters, if it is a type of event we need to count. def summarize_event(event) if event[:kind] == "feature" @@ -55,45 +39,11 @@ def summarize_event(event) # Returns a snapshot of the current summarized event data, and resets this state. def snapshot - ret = { - start_date: @start_date, - end_date: @end_date, - counters: @counters - } + ret = EventSummary.new(@start_date, @end_date, @counters) reset_state ret end - # Transforms the summary data into the format used for event sending. - def output(snapshot) - flags = {} - snapshot[:counters].each { |ckey, cval| - flag = flags[ckey[:key]] - if flag.nil? - flag = { - default: cval[:default], - counters: [] - } - flags[ckey[:key]] = flag - end - c = { - value: cval[:value], - count: cval[:count] - } - if ckey[:version].nil? - c[:unknown] = true - else - c[:version] = ckey[:version] - end - flag[:counters].push(c) - } - { - startDate: snapshot[:start_date], - endDate: snapshot[:end_date], - features: flags - } - end - private def reset_state diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index c0c9e503..ffba4a02 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -24,10 +24,19 @@ def initialize(event) end class FlushMessage - def initialize(reply) - @reply = reply + def initialize(synchronous) + @reply = synchronous ? Concurrent::Semaphore.new(0) : nil end + attr_reader :reply + + def completed + @reply.release if !@reply.nil? + end + + def wait_for_completion + @reply.acquire if !@reply.nil? + end end class FlushUsersMessage @@ -39,47 +48,61 @@ class StopMessage class EventProcessor def initialize(sdk_key, config, client) @queue = Queue.new - @events = [] - @summarizer = EventSummarizer.new(config) - @sdk_key = sdk_key - @config = config - @user_filter = UserFilter.new(config) - @client = client ? client : Faraday.new - @stopped = Concurrent::AtomicBoolean.new(false) - @capacity_exceeded = false - @last_known_past_time = Concurrent::AtomicFixnum.new(0) - @flush_task = Concurrent::TimerTask.new(execution_interval: @config.flush_interval) do - @queue << FlushMessage.new(nil) + @flush_task = Concurrent::TimerTask.new(execution_interval: config.flush_interval) do + @queue << FlushMessage.new(false) end - @users_flush_task = Concurrent::TimerTask.new(execution_interval: @config.user_keys_flush_interval) do + @users_flush_task = Concurrent::TimerTask.new(execution_interval: config.user_keys_flush_interval) do @queue << FlushUsersMessage.new end - Thread.new { main_loop } + @consumer = EventConsumer.new(@queue, sdk_key, config, client) + @consumer.start end def stop + @flush_task.shutdown + @users_flush_task.shutdown flush - if @stopped.make_true - # There seems to be no such thing as "close" in Faraday: https://github.com/lostisland/faraday/issues/241 - @flush_task.shutdown - @users_flush_task.shutdown - # Tell the worker thread to stop - @queue << StopMessage.new - end + @consumer.stop end def add_event(event) - return if @stopped.value - event[:creationDate] = now_millis + event[:creationDate] = (Time.now.to_f * 1000).to_i @queue << EventMessage.new(event) end def flush - return if @stopped.value # An explicit flush should be synchronous, so we use a semaphore to wait for the result - semaphore = Concurrent::Semaphore.new(0) - @queue << FlushMessage.new(semaphore) - semaphore.acquire + message = FlushMessage.new(true) + @queue << message + message.wait_for_completion + end + end + + class EventConsumer + def initialize(queue, sdk_key, config, client) + @queue = queue + @sdk_key = sdk_key + @config = config + @client = client ? client : Faraday.new + @events = [] + @summarizer = EventSummarizer.new + @user_keys = SimpleLRUCacheSet.new(config.user_keys_capacity) + @stopped = Concurrent::AtomicBoolean.new(false) + @disabled = Concurrent::AtomicBoolean.new(false) + @capacity_exceeded = false + @last_known_past_time = Concurrent::AtomicFixnum.new(0) + end + + def start + Thread.new { main_loop } + end + + def stop + if @stopped.make_true + # There seems to be no such thing as "close" in Faraday: https://github.com/lostisland/faraday/issues/241 + # Tell the worker thread to stop + @queue << StopMessage.new + end end private @@ -96,9 +119,9 @@ def main_loop() when EventMessage dispatch_event(message.event) when FlushMessage - flush_internal(message.reply) + flush_internal(message) when FlushUsersMessage - @summarizer.reset_users + @user_keys.reset when StopMessage break end @@ -109,14 +132,16 @@ def main_loop() end def dispatch_event(event) + return if @disabled.value + # For each user we haven't seen before, we add an index event - unless this is already # an identify event for that user. - if !@config.inline_users_in_events && event.has_key?(:user) && !@summarizer.notice_user(event[:user]) + if !@config.inline_users_in_events && event.has_key?(:user) && !notice_user(event[:user]) if event[:kind] != "identify" queue_event({ kind: "index", creationDate: event[:creationDate], - user: @user_filter.transform_user_props(event[:user]) + user: event[:user] }) end end @@ -130,6 +155,15 @@ def dispatch_event(event) end end + # Add to the set of users we've noticed, and return true if the user was already known to us. + def notice_user(user) + if user.nil? || !user.has_key?(:key) + true + else + @user_keys.add(user[:key]) + end + end + def should_track_full_event(event) if event[:kind] == "feature" if event[:trackEvents] @@ -161,25 +195,86 @@ def queue_event(event) end end - def flush_internal(reply_semaphore) + def flush_internal(message) + if @disabled.value + message.completed + return + end + old_events = @events @events = [] snapshot = @summarizer.snapshot - if !@stopped.value && (!old_events.empty? || !snapshot[:counters].empty?) - Thread.new do + if !old_events.empty? || !snapshot[:counters].empty? + task = EventPayloadSendTask.new(@sdk_key, @config, @client, old_events, snapshot, + message, method(:on_event_response)) + task.start + else + message.completed + end + end + + def on_event_response(res) + if res.status < 200 || res.status >= 300 + @config.logger.error { "[LDClient] Unexpected status code while processing events: #{res.status}" } + if res.status == 401 + @config.logger.error { "[LDClient] Received 401 error, no further events will be posted since SDK key is invalid" } + @disabled.value = true + end + else + if !res.headers.nil? && res.headers.has_key?("Date") begin - post_flushed_events(old_events, snapshot) - rescue StandardError => exn - @config.logger.warn { "[LDClient] Error flushing events: #{exn.inspect}. \nTrace: #{exn.backtrace}" } + res_time = (Time.httpdate(res.headers["Date"]).to_f * 1000).to_i + @last_known_past_time.value = res_time + rescue end - reply_semaphore.release if !reply_semaphore.nil? end - else - reply_semaphore.release if !reply_semaphore.nil? end end + end + + class EventPayloadSendTask + def initialize(sdk_key, config, client, events, summary, message, response_callback) + @sdk_key = sdk_key + @config = config + @client = client + @events = events + @summary = summary + @message = message + @response_callback = response_callback + @user_filter = UserFilter.new(config) + end + + def start + Thread.new do + begin + post_flushed_events + rescue StandardError => exn + @config.logger.warn { "[LDClient] Error flushing events: #{exn.inspect}. \nTrace: #{exn.backtrace}" } + end + @message.completed + end + end + + private + + def post_flushed_events + events_out = @events.map { |e| make_output_event(e) } + if !@summary[:counters].empty? + events_out.push(make_summary_event(@summary)) + end + res = @client.post (@config.events_uri + "/bulk") do |req| + req.headers["Authorization"] = @sdk_key + req.headers["User-Agent"] = "RubyClient/" + LaunchDarkly::VERSION + req.headers["Content-Type"] = "application/json" + req.body = events_out.to_json + req.options.timeout = @config.read_timeout + req.options.open_timeout = @config.connect_timeout + end + @response_callback.call(res) + end + # Transforms events into the format used for event sending. def make_output_event(event) case event[:kind] when "feature" @@ -218,41 +313,46 @@ def make_output_event(event) out[:userKey] = event[:user][:key] end out + when "index" + { + kind: "index", + creationDate: event[:creationDate], + user: @user_filter.transform_user_props(event[:user]) + } else event end end - def post_flushed_events(events, snapshot) - events_out = events.map { |e| make_output_event(e) } - if !snapshot[:counters].empty? - summary_output = @summarizer.output(snapshot) - summary_output[:kind] = "summary" - events_out.push(summary_output) - end - res = @client.post (@config.events_uri + "/bulk") do |req| - req.headers["Authorization"] = @sdk_key - req.headers["User-Agent"] = "RubyClient/" + LaunchDarkly::VERSION - req.headers["Content-Type"] = "application/json" - req.body = events_out.to_json - req.options.timeout = @config.read_timeout - req.options.open_timeout = @config.connect_timeout - end - if res.status < 200 || res.status >= 300 - @config.logger.error { "[LDClient] Unexpected status code while processing events: #{res.status}" } - if res.status == 401 - @config.logger.error { "[LDClient] Received 401 error, no further events will be posted since SDK key is invalid" } - stop + # Transforms the summary data into the format used for event sending. + def make_summary_event(summary) + flags = {} + summary[:counters].each { |ckey, cval| + flag = flags[ckey[:key]] + if flag.nil? + flag = { + default: cval[:default], + counters: [] + } + flags[ckey[:key]] = flag end - else - if !res.headers.nil? && res.headers.has_key?("Date") - begin - res_time = (Time.httpdate(res.headers["Date"]).to_f * 1000).to_i - @last_known_past_time.value = res_time - rescue - end + c = { + value: cval[:value], + count: cval[:count] + } + if ckey[:version].nil? + c[:unknown] = true + else + c[:version] = ckey[:version] end - end + flag[:counters].push(c) + } + { + kind: "summary", + startDate: summary[:start_date], + endDate: summary[:end_date], + features: flags + } end end end diff --git a/spec/event_summarizer_spec.rb b/spec/event_summarizer_spec.rb index a2655730..5449e691 100644 --- a/spec/event_summarizer_spec.rb +++ b/spec/event_summarizer_spec.rb @@ -5,33 +5,8 @@ let(:user) { { key: "key" } } - it "returns false from notice_user for never-seen user" do - es = subject.new(LaunchDarkly::Config.new) - expect(es.notice_user(user)).to be false - end - - it "returns true from notice_user for previously seen user" do - es = subject.new(LaunchDarkly::Config.new) - expect(es.notice_user(user)).to be false - expect(es.notice_user(user)).to be true - end - - it "discards oldest user if capacity is exceeded" do - config = LaunchDarkly::Config.new(user_keys_capacity: 2) - es = subject.new(config) - user1 = { key: "key1" } - user2 = { key: "key2" } - user3 = { key: "key3" } - expect(es.notice_user(user1)).to be false - expect(es.notice_user(user2)).to be false - expect(es.notice_user(user3)).to be false - expect(es.notice_user(user3)).to be true - expect(es.notice_user(user2)).to be true - expect(es.notice_user(user1)).to be false - end - it "does not add identify event to summary" do - es = subject.new(LaunchDarkly::Config.new) + es = subject.new snapshot = es.snapshot es.summarize_event({ kind: "identify", user: user }) @@ -39,7 +14,7 @@ end it "does not add custom event to summary" do - es = subject.new(LaunchDarkly::Config.new) + es = subject.new snapshot = es.snapshot es.summarize_event({ kind: "custom", key: "whatever", user: user }) @@ -47,7 +22,7 @@ end it "tracks start and end dates" do - es = subject.new(LaunchDarkly::Config.new) + es = subject.new flag = { key: "key" } event1 = { kind: "feature", creationDate: 2000, user: user } event2 = { kind: "feature", creationDate: 1000, user: user } @@ -55,14 +30,14 @@ es.summarize_event(event1) es.summarize_event(event2) es.summarize_event(event3) - data = es.output(es.snapshot) + data = es.snapshot - expect(data[:startDate]).to be 1000 - expect(data[:endDate]).to be 2000 + expect(data.start_date).to be 1000 + expect(data.end_date).to be 2000 end it "counts events" do - es = subject.new(LaunchDarkly::Config.new) + es = subject.new flag1 = { key: "key1", version: 11 } flag2 = { key: "key2", version: 22 } event1 = { kind: "feature", key: "key1", version: 11, user: user, variation: 1, value: "value1", default: "default1" } @@ -71,30 +46,18 @@ event4 = { kind: "feature", key: "key1", version: 11, user: user, variation: 1, value: "value1", default: "default1" } event5 = { kind: "feature", key: "badkey", user: user, variation: nil, value: "default3", default: "default3" } [event1, event2, event3, event4, event5].each { |e| es.summarize_event(e) } - data = es.output(es.snapshot) - - data[:features]["key1"][:counters].sort! { |a, b| a[:value] <=> b[:value] } - expectedFeatures = { - "key1" => { - default: "default1", - counters: [ - { value: "value1", version: 11, count: 2 }, - { value: "value2", version: 11, count: 1 } - ] - }, - "key2" => { - default: "default2", - counters: [ - { value: "value99", version: 22, count: 1 } - ] - }, - "badkey" => { - default: "default3", - counters: [ - { value: "default3", unknown: true, count: 1 } - ] - } + data = es.snapshot + + expectedCounters = { + { key: "key1", version: 11, variation: 1 } => + { count: 2, value: "value1", default: "default1" }, + { key: "key1", version: 11, variation: 2 } => + { count: 1, value: "value2", default: "default1" }, + { key: "key2", version: 22, variation: 1 } => + { count: 1, value: "value99", default: "default2" }, + { key: "badkey", version: nil, variation: nil } => + { count: 1, value: "default3", default: "default3" } } - expect(data[:features]).to eq expectedFeatures + expect(data.counters).to eq expectedCounters end end From 71627bdf41c9e5732c78abf045a592c4cf536e03 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Mon, 26 Mar 2018 17:10:00 -0700 Subject: [PATCH 07/34] more specific rescue --- lib/ldclient-rb/events.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index ffba4a02..7dffd66a 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -226,7 +226,7 @@ def on_event_response(res) begin res_time = (Time.httpdate(res.headers["Date"]).to_f * 1000).to_i @last_known_past_time.value = res_time - rescue + rescue ArgumentError end end end From 98cc54e3e389b43e5383caf63f42d375a4184e44 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Wed, 28 Mar 2018 13:15:26 -0700 Subject: [PATCH 08/34] make flushes asynchronous, but shutdown must wait till everything is flushed --- lib/ldclient-rb/events.rb | 118 +++++++++++++++++++++++--------------- spec/events_spec.rb | 16 ++++++ 2 files changed, 87 insertions(+), 47 deletions(-) diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index 7dffd66a..ecc50114 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -1,10 +1,13 @@ require "concurrent" require "concurrent/atomics" +require "concurrent/executors" require "thread" require "time" require "faraday" module LaunchDarkly + MAX_FLUSH_WORKERS = 5 + class NullEventProcessor def add_event(event) end @@ -24,25 +27,29 @@ def initialize(event) end class FlushMessage - def initialize(synchronous) - @reply = synchronous ? Concurrent::Semaphore.new(0) : nil + end + + class FlushUsersMessage + end + + class SynchronousMessage + def initialize + @reply = Concurrent::Semaphore.new(0) end - attr_reader :reply - def completed - @reply.release if !@reply.nil? + @reply.release end def wait_for_completion - @reply.acquire if !@reply.nil? + @reply.acquire end end - class FlushUsersMessage + class TestSyncMessage < SynchronousMessage end - class StopMessage + class StopMessage < SynchronousMessage end class EventProcessor @@ -54,27 +61,38 @@ def initialize(sdk_key, config, client) @users_flush_task = Concurrent::TimerTask.new(execution_interval: config.user_keys_flush_interval) do @queue << FlushUsersMessage.new end + @stopped = Concurrent::AtomicBoolean.new(false) @consumer = EventConsumer.new(@queue, sdk_key, config, client) @consumer.start end - def stop - @flush_task.shutdown - @users_flush_task.shutdown - flush - @consumer.stop - end - def add_event(event) event[:creationDate] = (Time.now.to_f * 1000).to_i @queue << EventMessage.new(event) end def flush - # An explicit flush should be synchronous, so we use a semaphore to wait for the result - message = FlushMessage.new(true) - @queue << message - message.wait_for_completion + # flush is done asynchronously + @queue << FlushMessage.new + end + + def stop + # final shutdown, which includes a final flush, is done synchronously + if @stopped.make_true + @flush_task.shutdown + @users_flush_task.shutdown + @queue << FlushMessage.new + stop_msg = StopMessage.new + @queue << stop_msg + stop_msg.wait_for_completion + end + end + + # exposed only for testing + def wait_until_inactive + sync_msg = TestSyncMessage.new + @queue << sync_msg + sync_msg.wait_for_completion end end @@ -87,7 +105,7 @@ def initialize(queue, sdk_key, config, client) @events = [] @summarizer = EventSummarizer.new @user_keys = SimpleLRUCacheSet.new(config.user_keys_capacity) - @stopped = Concurrent::AtomicBoolean.new(false) + @flush_workers = Concurrent::FixedThreadPool.new(MAX_FLUSH_WORKERS) @disabled = Concurrent::AtomicBoolean.new(false) @capacity_exceeded = false @last_known_past_time = Concurrent::AtomicFixnum.new(0) @@ -97,14 +115,6 @@ def start Thread.new { main_loop } end - def stop - if @stopped.make_true - # There seems to be no such thing as "close" in Faraday: https://github.com/lostisland/faraday/issues/241 - # Tell the worker thread to stop - @queue << StopMessage.new - end - end - private def now_millis() @@ -112,18 +122,24 @@ def now_millis() end def main_loop() - loop do + running = true + while running do begin message = @queue.pop case message when EventMessage dispatch_event(message.event) when FlushMessage - flush_internal(message) + start_flush when FlushUsersMessage @user_keys.reset + when TestSyncMessage + synchronize_for_testing + message.completed when StopMessage - break + do_shutdown + running = false + message.completed end rescue => e @config.logger.warn { "[LDClient] Unexpected error in event processor: #{e.inspect}. \nTrace: #{e.backtrace}" } @@ -131,6 +147,19 @@ def main_loop() end end + def do_shutdown + @flush_workers.shutdown + @flush_workers.wait_for_termination + # There seems to be no such thing as "close" in Faraday: https://github.com/lostisland/faraday/issues/241 + end + + def synchronize_for_testing + # used only by unit tests + @flush_workers.shutdown + @flush_workers.wait_for_termination + @flush_workers = Concurrent::FixedThreadPool.new(MAX_FLUSH_WORKERS) + end + def dispatch_event(event) return if @disabled.value @@ -195,9 +224,8 @@ def queue_event(event) end end - def flush_internal(message) + def start_flush() if @disabled.value - message.completed return end @@ -207,10 +235,10 @@ def flush_internal(message) if !old_events.empty? || !snapshot[:counters].empty? task = EventPayloadSendTask.new(@sdk_key, @config, @client, old_events, snapshot, - message, method(:on_event_response)) - task.start - else - message.completed + method(:on_event_response)) + @flush_workers.post do + task.run + end end end @@ -234,25 +262,21 @@ def on_event_response(res) end class EventPayloadSendTask - def initialize(sdk_key, config, client, events, summary, message, response_callback) + def initialize(sdk_key, config, client, events, summary, response_callback) @sdk_key = sdk_key @config = config @client = client @events = events @summary = summary - @message = message @response_callback = response_callback @user_filter = UserFilter.new(config) end - def start - Thread.new do - begin - post_flushed_events - rescue StandardError => exn - @config.logger.warn { "[LDClient] Error flushing events: #{exn.inspect}. \nTrace: #{exn.backtrace}" } - end - @message.completed + def run + begin + post_flushed_events + rescue StandardError => exn + @config.logger.warn { "[LDClient] Error flushing events: #{exn.inspect}. \nTrace: #{exn.backtrace}" } end end diff --git a/spec/events_spec.rb b/spec/events_spec.rb index 12540b09..c7c5471e 100644 --- a/spec/events_spec.rb +++ b/spec/events_spec.rb @@ -286,6 +286,17 @@ ) end + it "does a final flush when shutting down" do + @ep = subject.new("sdk_key", default_config, hc) + e = { kind: "identify", user: user } + @ep.add_event(e) + + @ep.stop + + output = get_events_from_last_request + expect(output).to contain_exactly(e) + end + it "sends nothing if there are no events" do @ep = subject.new("sdk_key", default_config, hc) @ep.flush @@ -356,6 +367,11 @@ def custom_event(e, inline_user) def flush_and_get_events @ep.flush + @ep.wait_until_inactive + get_events_from_last_request + end + + def get_events_from_last_request req = hc.request_received JSON.parse(req.body, symbolize_names: true) end From 4b836484d9e3f91267b8e76f83946dffe07d1d1f Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Tue, 3 Apr 2018 15:47:53 -0700 Subject: [PATCH 09/34] misc reorganization --- lib/ldclient-rb/event_summarizer.rb | 7 +- lib/ldclient-rb/events.rb | 109 ++++++++++++++++------------ 2 files changed, 66 insertions(+), 50 deletions(-) diff --git a/lib/ldclient-rb/event_summarizer.rb b/lib/ldclient-rb/event_summarizer.rb index 8adb6a80..1c55b524 100644 --- a/lib/ldclient-rb/event_summarizer.rb +++ b/lib/ldclient-rb/event_summarizer.rb @@ -8,7 +8,7 @@ module LaunchDarkly # synchronization across both the summarizer and the event queue. class EventSummarizer def initialize - reset_state + clear end # Adds this event to our counters, if it is a type of event we need to count. @@ -40,13 +40,10 @@ def summarize_event(event) # Returns a snapshot of the current summarized event data, and resets this state. def snapshot ret = EventSummary.new(@start_date, @end_date, @counters) - reset_state ret end - private - - def reset_state + def clear @start_date = 0 @end_date = 0 @counters = {} diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index ecc50114..86ff2fbe 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -62,8 +62,8 @@ def initialize(sdk_key, config, client) @queue << FlushUsersMessage.new end @stopped = Concurrent::AtomicBoolean.new(false) - @consumer = EventConsumer.new(@queue, sdk_key, config, client) - @consumer.start + + EventDispatcher.new(@queue, sdk_key, config, client) end def add_event(event) @@ -96,23 +96,19 @@ def wait_until_inactive end end - class EventConsumer + class EventDispatcher def initialize(queue, sdk_key, config, client) - @queue = queue @sdk_key = sdk_key @config = config @client = client ? client : Faraday.new - @events = [] - @summarizer = EventSummarizer.new @user_keys = SimpleLRUCacheSet.new(config.user_keys_capacity) @flush_workers = Concurrent::FixedThreadPool.new(MAX_FLUSH_WORKERS) @disabled = Concurrent::AtomicBoolean.new(false) - @capacity_exceeded = false @last_known_past_time = Concurrent::AtomicFixnum.new(0) - end - def start - Thread.new { main_loop } + buffer = EventBuffer.new(config.capacity, config.logger) + + Thread.new { main_loop(queue, buffer) } end private @@ -121,16 +117,16 @@ def now_millis() (Time.now.to_f * 1000).to_i end - def main_loop() + def main_loop(queue, buffer) running = true while running do begin - message = @queue.pop + message = queue.pop case message when EventMessage - dispatch_event(message.event) + dispatch_event(message.event, buffer) when FlushMessage - start_flush + trigger_flush(buffer) when FlushUsersMessage @user_keys.reset when TestSyncMessage @@ -160,14 +156,14 @@ def synchronize_for_testing @flush_workers = Concurrent::FixedThreadPool.new(MAX_FLUSH_WORKERS) end - def dispatch_event(event) + def dispatch_event(event, buffer) return if @disabled.value # For each user we haven't seen before, we add an index event - unless this is already # an identify event for that user. if !@config.inline_users_in_events && event.has_key?(:user) && !notice_user(event[:user]) if event[:kind] != "identify" - queue_event({ + buffer.add_event({ kind: "index", creationDate: event[:creationDate], user: event[:user] @@ -176,11 +172,11 @@ def dispatch_event(event) end # Always record the event in the summary. - @summarizer.summarize_event(event) + buffer.add_to_summary(event) if should_track_full_event(event) # Queue the event as-is; we'll transform it into an output event when we're flushing. - queue_event(event) + buffer.add_event(event) end end @@ -198,8 +194,8 @@ def should_track_full_event(event) if event[:trackEvents] true else - if event.has_key?(:debugEventsUntilDate) - debugUntil = event[:debugEventsUntilDate] + debugUntil = event[:debugEventsUntilDate] + if !debugUntil.nil? last_past = @last_known_past_time.value debugUntil > last_past && debugUntil > now_millis else @@ -211,30 +207,16 @@ def should_track_full_event(event) end end - def queue_event(event) - if @events.length < @config.capacity - @config.logger.debug { "[LDClient] Enqueueing event: #{event.to_json}" } - @events.push(event) - @capacity_exceeded = false - else - if !@capacity_exceeded - @capacity_exceeded = true - @config.logger.warn { "[LDClient] Exceeded event queue capacity. Increase capacity to avoid dropping events." } - end - end - end - - def start_flush() + def trigger_flush(buffer) if @disabled.value return end - old_events = @events - @events = [] - snapshot = @summarizer.snapshot + payload = buffer.get_payload + buffer.clear - if !old_events.empty? || !snapshot[:counters].empty? - task = EventPayloadSendTask.new(@sdk_key, @config, @client, old_events, snapshot, + if !payload.events.empty? || !payload.summary.counters.empty? + task = EventPayloadSendTask.new(@sdk_key, @config, @client, payload, method(:on_event_response)) @flush_workers.post do task.run @@ -261,13 +243,50 @@ def on_event_response(res) end end + FlushPayload = Struct.new(:events, :summary) + + class EventBuffer + def initialize(capacity, logger) + @capacity = capacity + @logger = logger + @capacity_exceeded = false + @events = [] + @summarizer = EventSummarizer.new + end + + def add_event(event) + if @events.length < @capacity + @logger.debug { "[LDClient] Enqueueing event: #{event.to_json}" } + @events.push(event) + @capacity_exceeded = false + else + if !@capacity_exceeded + @capacity_exceeded = true + @logger.warn { "[LDClient] Exceeded event queue capacity. Increase capacity to avoid dropping events." } + end + end + end + + def add_to_summary(event) + @summarizer.summarize_event(event) + end + + def get_payload + return FlushPayload.new(@events, @summarizer.snapshot) + end + + def clear + @events = [] + @summarizer.clear + end + end + class EventPayloadSendTask - def initialize(sdk_key, config, client, events, summary, response_callback) + def initialize(sdk_key, config, client, payload, response_callback) @sdk_key = sdk_key @config = config @client = client - @events = events - @summary = summary + @payload = payload @response_callback = response_callback @user_filter = UserFilter.new(config) end @@ -283,9 +302,9 @@ def run private def post_flushed_events - events_out = @events.map { |e| make_output_event(e) } - if !@summary[:counters].empty? - events_out.push(make_summary_event(@summary)) + events_out = @payload.events.map { |e| make_output_event(e) } + if !@payload.summary.counters.empty? + events_out.push(make_summary_event(@payload.summary)) end res = @client.post (@config.events_uri + "/bulk") do |req| req.headers["Authorization"] = @sdk_key From eb415209d847d614123c57d6a78051b0ce15f954 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Tue, 3 Apr 2018 16:19:18 -0700 Subject: [PATCH 10/34] don't queue a flush task if we've reached pool limit --- lib/ldclient-rb/events.rb | 113 +++++++++++++++++++++----------------- 1 file changed, 64 insertions(+), 49 deletions(-) diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index 86ff2fbe..c453e039 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -102,13 +102,15 @@ def initialize(queue, sdk_key, config, client) @config = config @client = client ? client : Faraday.new @user_keys = SimpleLRUCacheSet.new(config.user_keys_capacity) - @flush_workers = Concurrent::FixedThreadPool.new(MAX_FLUSH_WORKERS) + @formatter = EventOutputFormatter.new(config) @disabled = Concurrent::AtomicBoolean.new(false) @last_known_past_time = Concurrent::AtomicFixnum.new(0) buffer = EventBuffer.new(config.capacity, config.logger) + flush_workers = Concurrent::FixedThreadPool.new(MAX_FLUSH_WORKERS) + flush_workers_semaphore = Concurrent::Semaphore.new(MAX_FLUSH_WORKERS) - Thread.new { main_loop(queue, buffer) } + Thread.new { main_loop(queue, buffer, flush_workers, flush_workers_semaphore) } end private @@ -117,7 +119,7 @@ def now_millis() (Time.now.to_f * 1000).to_i end - def main_loop(queue, buffer) + def main_loop(queue, buffer, flush_workers, flush_workers_semaphore) running = true while running do begin @@ -126,14 +128,14 @@ def main_loop(queue, buffer) when EventMessage dispatch_event(message.event, buffer) when FlushMessage - trigger_flush(buffer) + trigger_flush(buffer, flush_workers, flush_workers_semaphore) when FlushUsersMessage @user_keys.reset when TestSyncMessage - synchronize_for_testing + synchronize_for_testing(flush_workers_semaphore) message.completed when StopMessage - do_shutdown + do_shutdown(flush_workers) running = false message.completed end @@ -143,17 +145,18 @@ def main_loop(queue, buffer) end end - def do_shutdown - @flush_workers.shutdown - @flush_workers.wait_for_termination + def do_shutdown(flush_workers) + flush_workers.shutdown + flush_workers.wait_for_termination # There seems to be no such thing as "close" in Faraday: https://github.com/lostisland/faraday/issues/241 end - def synchronize_for_testing - # used only by unit tests - @flush_workers.shutdown - @flush_workers.wait_for_termination - @flush_workers = Concurrent::FixedThreadPool.new(MAX_FLUSH_WORKERS) + def synchronize_for_testing(flush_workers_semaphore) + # Used only by unit tests. Wait until all active flush workers have finished. + puts "syncing" + flush_workers_semaphore.acquire(MAX_FLUSH_WORKERS) + puts "synced" + flush_workers_semaphore.release(MAX_FLUSH_WORKERS) end def dispatch_event(event, buffer) @@ -212,23 +215,35 @@ def trigger_flush(buffer) return end - payload = buffer.get_payload - buffer.clear - + payload = buffer.get_payload if !payload.events.empty? || !payload.summary.counters.empty? - task = EventPayloadSendTask.new(@sdk_key, @config, @client, payload, - method(:on_event_response)) + # If all available worker threads are busy, we don't want to queue a flush task - we + # should just keep the events in our buffer. Unfortunately, FixedThreadPool doesn't + # give us a way to only conditionally add a task, so we use this semaphore to keep + # track of how many threads are available. + puts "want a worker" + if !@flush_workers_semaphore.try_acquire(1) + puts "can't start flush worker - full" + return + end + puts "got one - available is now #{@flush_workers_semaphore.available_permits}" + buffer.clear # Reset our internal state, these events now belong to the flush worker @flush_workers.post do - task.run + puts "starting flush worker" + resp = EventPayloadSendTask.new.run(@sdk_key, @config, @client, payload, @formatter) + puts "releasing worker" + @flush_workers_semaphore.release(1) + handle_response(resp) if !resp.nil? end end end - def on_event_response(res) + def handle_response(res) if res.status < 200 || res.status >= 300 @config.logger.error { "[LDClient] Unexpected status code while processing events: #{res.status}" } if res.status == 401 @config.logger.error { "[LDClient] Received 401 error, no further events will be posted since SDK key is invalid" } + puts "disabling" @disabled.value = true end else @@ -282,42 +297,42 @@ def clear end class EventPayloadSendTask - def initialize(sdk_key, config, client, payload, response_callback) - @sdk_key = sdk_key - @config = config - @client = client - @payload = payload - @response_callback = response_callback - @user_filter = UserFilter.new(config) - end - - def run + def run(sdk_key, config, client, payload, formatter) begin - post_flushed_events + events_out = formatter.make_output_events(payload.events, payload.summary) + res = client.post (config.events_uri + "/bulk") do |req| + req.headers["Authorization"] = sdk_key + req.headers["User-Agent"] = "RubyClient/" + LaunchDarkly::VERSION + req.headers["Content-Type"] = "application/json" + req.body = events_out.to_json + req.options.timeout = config.read_timeout + req.options.open_timeout = config.connect_timeout + end + res rescue StandardError => exn @config.logger.warn { "[LDClient] Error flushing events: #{exn.inspect}. \nTrace: #{exn.backtrace}" } + nil end end + end - private + class EventOutputFormatter + def initialize(config) + @inline_users = config.inline_users_in_events + @user_filter = UserFilter.new(config) + end - def post_flushed_events - events_out = @payload.events.map { |e| make_output_event(e) } - if !@payload.summary.counters.empty? - events_out.push(make_summary_event(@payload.summary)) - end - res = @client.post (@config.events_uri + "/bulk") do |req| - req.headers["Authorization"] = @sdk_key - req.headers["User-Agent"] = "RubyClient/" + LaunchDarkly::VERSION - req.headers["Content-Type"] = "application/json" - req.body = events_out.to_json - req.options.timeout = @config.read_timeout - req.options.open_timeout = @config.connect_timeout + # Transforms events into the format used for event sending. + def make_output_events(events, summary) + events_out = events.map { |e| make_output_event(e) } + if !summary.counters.empty? + events_out.push(make_summary_event(summary)) end - @response_callback.call(res) + events_out end - # Transforms events into the format used for event sending. + private + def make_output_event(event) case event[:kind] when "feature" @@ -331,7 +346,7 @@ def make_output_event(event) out[:default] = event[:default] if event.has_key?(:default) out[:version] = event[:version] if event.has_key?(:version) out[:prereqOf] = event[:prereqOf] if event.has_key?(:prereqOf) - if @config.inline_users_in_events + if @inline_users out[:user] = @user_filter.transform_user_props(event[:user]) else out[:userKey] = event[:user][:key] @@ -350,7 +365,7 @@ def make_output_event(event) key: event[:key] } out[:data] = event[:data] if event.has_key?(:data) - if @config.inline_users_in_events + if @inline_users out[:user] = @user_filter.transform_user_props(event[:user]) else out[:userKey] = event[:user][:key] From 4781d844564cb92f0ba29dbed4d62d1fbe4aa6b1 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Tue, 3 Apr 2018 16:25:16 -0700 Subject: [PATCH 11/34] rm debugging, misc fixes --- lib/ldclient-rb/events.rb | 16 ++++------------ 1 file changed, 4 insertions(+), 12 deletions(-) diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index c453e039..a2d3769a 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -153,9 +153,7 @@ def do_shutdown(flush_workers) def synchronize_for_testing(flush_workers_semaphore) # Used only by unit tests. Wait until all active flush workers have finished. - puts "syncing" flush_workers_semaphore.acquire(MAX_FLUSH_WORKERS) - puts "synced" flush_workers_semaphore.release(MAX_FLUSH_WORKERS) end @@ -210,7 +208,7 @@ def should_track_full_event(event) end end - def trigger_flush(buffer) + def trigger_flush(buffer, flush_workers, flush_workers_semaphore) if @disabled.value return end @@ -221,18 +219,13 @@ def trigger_flush(buffer) # should just keep the events in our buffer. Unfortunately, FixedThreadPool doesn't # give us a way to only conditionally add a task, so we use this semaphore to keep # track of how many threads are available. - puts "want a worker" - if !@flush_workers_semaphore.try_acquire(1) - puts "can't start flush worker - full" + if !flush_workers_semaphore.try_acquire(1) return end - puts "got one - available is now #{@flush_workers_semaphore.available_permits}" buffer.clear # Reset our internal state, these events now belong to the flush worker - @flush_workers.post do - puts "starting flush worker" + flush_workers.post do resp = EventPayloadSendTask.new.run(@sdk_key, @config, @client, payload, @formatter) - puts "releasing worker" - @flush_workers_semaphore.release(1) + flush_workers_semaphore.release(1) handle_response(resp) if !resp.nil? end end @@ -243,7 +236,6 @@ def handle_response(res) @config.logger.error { "[LDClient] Unexpected status code while processing events: #{res.status}" } if res.status == 401 @config.logger.error { "[LDClient] Received 401 error, no further events will be posted since SDK key is invalid" } - puts "disabling" @disabled.value = true end else From 1eff6d780c1fc91b05c67a5296977f71bbc4a3b8 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Wed, 4 Apr 2018 12:53:09 -0700 Subject: [PATCH 12/34] encapsulate thread pool logic in a class --- lib/ldclient-rb.rb | 1 + lib/ldclient-rb/events.rb | 31 +++++--------- lib/ldclient-rb/non_blocking_thread_pool.rb | 46 +++++++++++++++++++++ 3 files changed, 58 insertions(+), 20 deletions(-) create mode 100644 lib/ldclient-rb/non_blocking_thread_pool.rb diff --git a/lib/ldclient-rb.rb b/lib/ldclient-rb.rb index 8ef89cda..0e25b043 100644 --- a/lib/ldclient-rb.rb +++ b/lib/ldclient-rb.rb @@ -10,6 +10,7 @@ require "ldclient-rb/polling" require "ldclient-rb/user_filter" require "ldclient-rb/simple_lru_cache" +require "ldclient-rb/non_blocking_thread_pool" require "ldclient-rb/event_summarizer" require "ldclient-rb/events" require "ldclient-rb/redis_store" diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index a2d3769a..78e87ce4 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -107,10 +107,9 @@ def initialize(queue, sdk_key, config, client) @last_known_past_time = Concurrent::AtomicFixnum.new(0) buffer = EventBuffer.new(config.capacity, config.logger) - flush_workers = Concurrent::FixedThreadPool.new(MAX_FLUSH_WORKERS) - flush_workers_semaphore = Concurrent::Semaphore.new(MAX_FLUSH_WORKERS) + flush_workers = NonBlockingThreadPool.new(MAX_FLUSH_WORKERS) - Thread.new { main_loop(queue, buffer, flush_workers, flush_workers_semaphore) } + Thread.new { main_loop(queue, buffer, flush_workers) } end private @@ -119,7 +118,7 @@ def now_millis() (Time.now.to_f * 1000).to_i end - def main_loop(queue, buffer, flush_workers, flush_workers_semaphore) + def main_loop(queue, buffer, flush_workers) running = true while running do begin @@ -128,11 +127,11 @@ def main_loop(queue, buffer, flush_workers, flush_workers_semaphore) when EventMessage dispatch_event(message.event, buffer) when FlushMessage - trigger_flush(buffer, flush_workers, flush_workers_semaphore) + trigger_flush(buffer, flush_workers) when FlushUsersMessage @user_keys.reset when TestSyncMessage - synchronize_for_testing(flush_workers_semaphore) + synchronize_for_testing(flush_workers) message.completed when StopMessage do_shutdown(flush_workers) @@ -151,10 +150,9 @@ def do_shutdown(flush_workers) # There seems to be no such thing as "close" in Faraday: https://github.com/lostisland/faraday/issues/241 end - def synchronize_for_testing(flush_workers_semaphore) + def synchronize_for_testing(flush_workers) # Used only by unit tests. Wait until all active flush workers have finished. - flush_workers_semaphore.acquire(MAX_FLUSH_WORKERS) - flush_workers_semaphore.release(MAX_FLUSH_WORKERS) + flush_workers.wait_all end def dispatch_event(event, buffer) @@ -208,26 +206,19 @@ def should_track_full_event(event) end end - def trigger_flush(buffer, flush_workers, flush_workers_semaphore) + def trigger_flush(buffer, flush_workers) if @disabled.value return end payload = buffer.get_payload if !payload.events.empty? || !payload.summary.counters.empty? - # If all available worker threads are busy, we don't want to queue a flush task - we - # should just keep the events in our buffer. Unfortunately, FixedThreadPool doesn't - # give us a way to only conditionally add a task, so we use this semaphore to keep - # track of how many threads are available. - if !flush_workers_semaphore.try_acquire(1) - return - end - buffer.clear # Reset our internal state, these events now belong to the flush worker - flush_workers.post do + # If all available worker threads are busy, success will be false and no job will be queued. + success = flush_workers.post do resp = EventPayloadSendTask.new.run(@sdk_key, @config, @client, payload, @formatter) - flush_workers_semaphore.release(1) handle_response(resp) if !resp.nil? end + buffer.clear if success # Reset our internal state, these events now belong to the flush worker end end diff --git a/lib/ldclient-rb/non_blocking_thread_pool.rb b/lib/ldclient-rb/non_blocking_thread_pool.rb new file mode 100644 index 00000000..81b7ea14 --- /dev/null +++ b/lib/ldclient-rb/non_blocking_thread_pool.rb @@ -0,0 +1,46 @@ +require "concurrent" +require "concurrent/atomics" +require "concurrent/executors" +require "thread" + +# Simple wrapper for a FixedThreadPool that rejects new jobs if all the threads are busy, rather +# than blocking. Also provides a way to wait for all jobs to finish without shutting down. + +module LaunchDarkly + class NonBlockingThreadPool + def initialize(capacity) + @capacity = capacity + @pool = Concurrent::FixedThreadPool.new(capacity) + @semaphore = Concurrent::Semaphore.new(capacity) + end + + # Attempts to submit a job, but only if a worker is available. Unlike the regular post method, + # this returns a value: true if the job was submitted, false if all workers are busy. + def post + if !@semaphore.try_acquire(1) + return + end + @pool.post do + begin + yield + ensure + @semaphore.release(1) + end + end + end + + # Waits until no jobs are executing, without shutting down the pool. + def wait_all + @semaphore.acquire(@capacity) + @semaphore.release(@capacity) + end + + def shutdown + @pool.shutdown + end + + def wait_for_termination + @pool.wait_for_termination + end + end +end From 836a85db73c5eaf7063e676edec40673d633a137 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Mon, 9 Apr 2018 16:34:20 -0700 Subject: [PATCH 13/34] fix behavior of debug & index events --- lib/ldclient-rb/events.rb | 54 +++++++++++++++++++++------------------ spec/events_spec.rb | 21 ++++++++++++++- 2 files changed, 49 insertions(+), 26 deletions(-) diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index 78e87ce4..95c77ef0 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -158,10 +158,27 @@ def synchronize_for_testing(flush_workers) def dispatch_event(event, buffer) return if @disabled.value + # Always record the event in the summary. + buffer.add_to_summary(event) + + # Decide whether to add the event to the payload. Feature events may be added twice, once for + # the event (if tracked) and once for debugging. + will_add_full_event = false + debug_event = nil + if event[:kind] == "feature" + will_add_full_event = event[:trackEvents] + if should_debug_event(event) + debug_event = event.clone + debug_event[:debug] = true + end + else + will_add_full_event = true + end + # For each user we haven't seen before, we add an index event - unless this is already # an identify event for that user. - if !@config.inline_users_in_events && event.has_key?(:user) && !notice_user(event[:user]) - if event[:kind] != "identify" + if !(will_add_full_event && @config.inline_users_in_events) + if event.has_key?(:user) && !notice_user(event[:user]) && event[:kind] != "identify" buffer.add_event({ kind: "index", creationDate: event[:creationDate], @@ -170,13 +187,8 @@ def dispatch_event(event, buffer) end end - # Always record the event in the summary. - buffer.add_to_summary(event) - - if should_track_full_event(event) - # Queue the event as-is; we'll transform it into an output event when we're flushing. - buffer.add_event(event) - end + buffer.add_event(event) if will_add_full_event + buffer.add_event(debug_event) if !debug_event.nil? end # Add to the set of users we've noticed, and return true if the user was already known to us. @@ -188,21 +200,13 @@ def notice_user(user) end end - def should_track_full_event(event) - if event[:kind] == "feature" - if event[:trackEvents] - true - else - debugUntil = event[:debugEventsUntilDate] - if !debugUntil.nil? - last_past = @last_known_past_time.value - debugUntil > last_past && debugUntil > now_millis - else - false - end - end + def should_debug_event(event) + debug_until = event[:debugEventsUntilDate] + if !debug_until.nil? + last_past = @last_known_past_time.value + debug_until > last_past && debug_until > now_millis else - true + false end end @@ -319,7 +323,7 @@ def make_output_events(events, summary) def make_output_event(event) case event[:kind] when "feature" - is_debug = !event[:trackEvents] && event.has_key?(:debugEventsUntilDate) + is_debug = event[:debug] out = { kind: is_debug ? "debug" : "feature", creationDate: event[:creationDate], @@ -329,7 +333,7 @@ def make_output_event(event) out[:default] = event[:default] if event.has_key?(:default) out[:version] = event[:version] if event.has_key?(:version) out[:prereqOf] = event[:prereqOf] if event.has_key?(:prereqOf) - if @inline_users + if @inline_users || is_debug out[:user] = @user_filter.transform_user_props(event[:user]) else out[:userKey] = event[:user][:key] diff --git a/spec/events_spec.rb b/spec/events_spec.rb index c7c5471e..8601664f 100644 --- a/spec/events_spec.rb +++ b/spec/events_spec.rb @@ -121,7 +121,26 @@ output = flush_and_get_events expect(output).to contain_exactly( eq(index_event(fe, user)), - eq(feature_event(fe, flag, true, nil)), + eq(feature_event(fe, flag, true, user)), + include(:kind => "summary") + ) + end + + it "can be both debugging and tracking an event" do + @ep = subject.new("sdk_key", default_config, hc) + flag = { key: "flagkey", version: 11 } + future_time = (Time.now.to_f * 1000).to_i + 1000000 + fe = { + kind: "feature", key: "flagkey", version: 11, user: user, + variation: 1, value: "value", trackEvents: true, debugEventsUntilDate: future_time + } + @ep.add_event(fe) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(index_event(fe, user)), + eq(feature_event(fe, flag, false, nil)), + eq(feature_event(fe, flag, true, user)), include(:kind => "summary") ) end From 3d87ad252c406b5df5a861ecc102dba41bf11413 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Mon, 9 Apr 2018 16:38:47 -0700 Subject: [PATCH 14/34] add unit test --- spec/events_spec.rb | 17 +++++++++++++++++ 1 file changed, 17 insertions(+) diff --git a/spec/events_spec.rb b/spec/events_spec.rb index 8601664f..82aa204a 100644 --- a/spec/events_spec.rb +++ b/spec/events_spec.rb @@ -108,6 +108,23 @@ ) end + it "still generates index event if inline_users is true but feature event was not tracked" do + config = LaunchDarkly::Config.new(inline_users_in_events: true) + @ep = subject.new("sdk_key", config, hc) + flag = { key: "flagkey", version: 11 } + fe = { + kind: "feature", key: "flagkey", version: 11, user: user, + variation: 1, value: "value", trackEvents: false + } + @ep.add_event(fe) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(index_event(fe, user)), + include(:kind => "summary") + ) + end + it "sets event kind to debug if flag is temporarily in debug mode" do @ep = subject.new("sdk_key", default_config, hc) flag = { key: "flagkey", version: 11 } From bda8a00d379c3f4e20259e9f993c899dbfbc73ec Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Tue, 10 Apr 2018 15:56:50 -0700 Subject: [PATCH 15/34] retry event post once after 5xx status or connection error --- lib/ldclient-rb/events.rb | 53 ++- spec/events_spec.rb | 727 ++++++++++++++++++++------------------ 2 files changed, 421 insertions(+), 359 deletions(-) diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index 95c77ef0..fba4f865 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -227,12 +227,9 @@ def trigger_flush(buffer, flush_workers) end def handle_response(res) - if res.status < 200 || res.status >= 300 - @config.logger.error { "[LDClient] Unexpected status code while processing events: #{res.status}" } - if res.status == 401 - @config.logger.error { "[LDClient] Received 401 error, no further events will be posted since SDK key is invalid" } - @disabled.value = true - end + if res.status == 401 + @config.logger.error { "[LDClient] Received 401 error, no further events will be posted since SDK key is invalid" } + @disabled.value = true else if !res.headers.nil? && res.headers.has_key?("Date") begin @@ -285,20 +282,38 @@ def clear class EventPayloadSendTask def run(sdk_key, config, client, payload, formatter) - begin - events_out = formatter.make_output_events(payload.events, payload.summary) - res = client.post (config.events_uri + "/bulk") do |req| - req.headers["Authorization"] = sdk_key - req.headers["User-Agent"] = "RubyClient/" + LaunchDarkly::VERSION - req.headers["Content-Type"] = "application/json" - req.body = events_out.to_json - req.options.timeout = config.read_timeout - req.options.open_timeout = config.connect_timeout + events_out = formatter.make_output_events(payload.events, payload.summary) + retried = false + loop do + if retried + config.logger.warn { "[LDClient] Will retry posting events after 1 second" } + sleep(1) + end + begin + res = client.post (config.events_uri + "/bulk") do |req| + req.headers["Authorization"] = sdk_key + req.headers["User-Agent"] = "RubyClient/" + LaunchDarkly::VERSION + req.headers["Content-Type"] = "application/json" + req.body = events_out.to_json + req.options.timeout = config.read_timeout + req.options.open_timeout = config.connect_timeout + end + if res.status < 200 || res.status >= 300 + config.logger.error { "[LDClient] Unexpected status code while processing events: #{res.status}" } + if res.status >= 500 && !retried + retried = true + next + end + end + return res + rescue StandardError => exn + config.logger.warn { "[LDClient] Error flushing events: #{exn.inspect}." } + if !retried + retried = true + next + end + return nil end - res - rescue StandardError => exn - @config.logger.warn { "[LDClient] Error flushing events: #{exn.inspect}. \nTrace: #{exn.backtrace}" } - nil end end end diff --git a/spec/events_spec.rb b/spec/events_spec.rb index 82aa204a..02f649a5 100644 --- a/spec/events_spec.rb +++ b/spec/events_spec.rb @@ -16,350 +16,383 @@ end end - it "queues identify event" do - @ep = subject.new("sdk_key", default_config, hc) - e = { kind: "identify", user: user } - @ep.add_event(e) - - output = flush_and_get_events - expect(output).to contain_exactly(e) - end - - it "filters user in identify event" do - config = LaunchDarkly::Config.new(all_attributes_private: true) - @ep = subject.new("sdk_key", config, hc) - e = { kind: "identify", user: user } - @ep.add_event(e) - - output = flush_and_get_events - expect(output).to contain_exactly({ - kind: "identify", - creationDate: e[:creationDate], - user: filtered_user - }) - end - - it "queues individual feature event with index event" do - @ep = subject.new("sdk_key", default_config, hc) - flag = { key: "flagkey", version: 11 } - fe = { - kind: "feature", key: "flagkey", version: 11, user: user, - variation: 1, value: "value", trackEvents: true - } - @ep.add_event(fe) - - output = flush_and_get_events - expect(output).to contain_exactly( - eq(index_event(fe, user)), - eq(feature_event(fe, flag, false, nil)), - include(:kind => "summary") - ) - end - - it "filters user in index event" do - config = LaunchDarkly::Config.new(all_attributes_private: true) - @ep = subject.new("sdk_key", config, hc) - flag = { key: "flagkey", version: 11 } - fe = { - kind: "feature", key: "flagkey", version: 11, user: user, - variation: 1, value: "value", trackEvents: true - } - @ep.add_event(fe) - - output = flush_and_get_events - expect(output).to contain_exactly( - eq(index_event(fe, filtered_user)), - eq(feature_event(fe, flag, false, nil)), - include(:kind => "summary") - ) - end - - it "can include inline user in feature event" do - config = LaunchDarkly::Config.new(inline_users_in_events: true) - @ep = subject.new("sdk_key", config, hc) - flag = { key: "flagkey", version: 11 } - fe = { - kind: "feature", key: "flagkey", version: 11, user: user, - variation: 1, value: "value", trackEvents: true - } - @ep.add_event(fe) - - output = flush_and_get_events - expect(output).to contain_exactly( - eq(feature_event(fe, flag, false, user)), - include(:kind => "summary") - ) - end - - it "filters user in feature event" do - config = LaunchDarkly::Config.new(all_attributes_private: true, inline_users_in_events: true) - @ep = subject.new("sdk_key", config, hc) - flag = { key: "flagkey", version: 11 } - fe = { - kind: "feature", key: "flagkey", version: 11, user: user, - variation: 1, value: "value", trackEvents: true - } - @ep.add_event(fe) - - output = flush_and_get_events - expect(output).to contain_exactly( - eq(feature_event(fe, flag, false, filtered_user)), - include(:kind => "summary") - ) - end - - it "still generates index event if inline_users is true but feature event was not tracked" do - config = LaunchDarkly::Config.new(inline_users_in_events: true) - @ep = subject.new("sdk_key", config, hc) - flag = { key: "flagkey", version: 11 } - fe = { - kind: "feature", key: "flagkey", version: 11, user: user, - variation: 1, value: "value", trackEvents: false - } - @ep.add_event(fe) - - output = flush_and_get_events - expect(output).to contain_exactly( - eq(index_event(fe, user)), - include(:kind => "summary") - ) - end - - it "sets event kind to debug if flag is temporarily in debug mode" do - @ep = subject.new("sdk_key", default_config, hc) - flag = { key: "flagkey", version: 11 } - future_time = (Time.now.to_f * 1000).to_i + 1000000 - fe = { - kind: "feature", key: "flagkey", version: 11, user: user, - variation: 1, value: "value", trackEvents: false, debugEventsUntilDate: future_time - } - @ep.add_event(fe) - - output = flush_and_get_events - expect(output).to contain_exactly( - eq(index_event(fe, user)), - eq(feature_event(fe, flag, true, user)), - include(:kind => "summary") - ) - end - - it "can be both debugging and tracking an event" do - @ep = subject.new("sdk_key", default_config, hc) - flag = { key: "flagkey", version: 11 } - future_time = (Time.now.to_f * 1000).to_i + 1000000 - fe = { - kind: "feature", key: "flagkey", version: 11, user: user, - variation: 1, value: "value", trackEvents: true, debugEventsUntilDate: future_time - } - @ep.add_event(fe) - - output = flush_and_get_events - expect(output).to contain_exactly( - eq(index_event(fe, user)), - eq(feature_event(fe, flag, false, nil)), - eq(feature_event(fe, flag, true, user)), - include(:kind => "summary") - ) - end - - it "ends debug mode based on client time if client time is later than server time" do - @ep = subject.new("sdk_key", default_config, hc) - - # Pick a server time that is somewhat behind the client time - server_time = (Time.now.to_f * 1000).to_i - 20000 - - # Send and flush an event we don't care about, just to set the last server time - hc.set_server_time(server_time) - @ep.add_event({ kind: "identify", user: { key: "otherUser" }}) - flush_and_get_events - - # Now send an event with debug mode on, with a "debug until" time that is further in - # the future than the server time, but in the past compared to the client. - flag = { key: "flagkey", version: 11 } - debug_until = server_time + 1000 - fe = { - kind: "feature", key: "flagkey", version: 11, user: user, - variation: 1, value: "value", trackEvents: false, debugEventsUntilDate: debug_until - } - @ep.add_event(fe) - - # Should get a summary event only, not a full feature event - output = flush_and_get_events - expect(output).to contain_exactly( - eq(index_event(fe, user)), - include(:kind => "summary") - ) - end - - it "ends debug mode based on server time if server time is later than client time" do - @ep = subject.new("sdk_key", default_config, hc) - - # Pick a server time that is somewhat ahead of the client time - server_time = (Time.now.to_f * 1000).to_i + 20000 - - # Send and flush an event we don't care about, just to set the last server time - hc.set_server_time(server_time) - @ep.add_event({ kind: "identify", user: { key: "otherUser" }}) - flush_and_get_events - - # Now send an event with debug mode on, with a "debug until" time that is further in - # the future than the server time, but in the past compared to the client. - flag = { key: "flagkey", version: 11 } - debug_until = server_time - 1000 - fe = { - kind: "feature", key: "flagkey", version: 11, user: user, - variation: 1, value: "value", trackEvents: false, debugEventsUntilDate: debug_until - } - @ep.add_event(fe) - - # Should get a summary event only, not a full feature event - output = flush_and_get_events - expect(output).to contain_exactly( - eq(index_event(fe, user)), - include(:kind => "summary") - ) - end - - it "generates only one index event for multiple events with same user" do - @ep = subject.new("sdk_key", default_config, hc) - flag1 = { key: "flagkey1", version: 11 } - flag2 = { key: "flagkey2", version: 22 } - future_time = (Time.now.to_f * 1000).to_i + 1000000 - fe1 = { - kind: "feature", key: "flagkey1", version: 11, user: user, - variation: 1, value: "value", trackEvents: true - } - fe2 = { - kind: "feature", key: "flagkey2", version: 22, user: user, - variation: 1, value: "value", trackEvents: true - } - @ep.add_event(fe1) - @ep.add_event(fe2) - - output = flush_and_get_events - expect(output).to contain_exactly( - eq(index_event(fe1, user)), - eq(feature_event(fe1, flag1, false, nil)), - eq(feature_event(fe2, flag2, false, nil)), - include(:kind => "summary") - ) - end - - it "summarizes non-tracked events" do - @ep = subject.new("sdk_key", default_config, hc) - flag1 = { key: "flagkey1", version: 11 } - flag2 = { key: "flagkey2", version: 22 } - future_time = (Time.now.to_f * 1000).to_i + 1000000 - fe1 = { - kind: "feature", key: "flagkey1", version: 11, user: user, - variation: 1, value: "value1", default: "default1" - } - fe2 = { - kind: "feature", key: "flagkey2", version: 22, user: user, - variation: 1, value: "value2", default: "default2" - } - @ep.add_event(fe1) - @ep.add_event(fe2) - - output = flush_and_get_events - expect(output).to contain_exactly( - eq(index_event(fe1, user)), - eq({ - kind: "summary", - startDate: fe1[:creationDate], - endDate: fe2[:creationDate], - features: { - flagkey1: { - default: "default1", - counters: [ - { version: 11, value: "value1", count: 1 } - ] - }, - flagkey2: { - default: "default2", - counters: [ - { version: 22, value: "value2", count: 1 } - ] - } - } - }) - ) - end - - it "queues custom event with user" do - @ep = subject.new("sdk_key", default_config, hc) - e = { kind: "custom", key: "eventkey", user: user, data: { thing: "stuff" } } - @ep.add_event(e) - - output = flush_and_get_events - expect(output).to contain_exactly( - eq(index_event(e, user)), - eq(custom_event(e, nil)) - ) - end - - it "can include inline user in custom event" do - config = LaunchDarkly::Config.new(inline_users_in_events: true) - @ep = subject.new("sdk_key", config, hc) - e = { kind: "custom", key: "eventkey", user: user, data: { thing: "stuff" } } - @ep.add_event(e) + # it "queues identify event" do + # @ep = subject.new("sdk_key", default_config, hc) + # e = { kind: "identify", user: user } + # @ep.add_event(e) + + # output = flush_and_get_events + # expect(output).to contain_exactly(e) + # end + + # it "filters user in identify event" do + # config = LaunchDarkly::Config.new(all_attributes_private: true) + # @ep = subject.new("sdk_key", config, hc) + # e = { kind: "identify", user: user } + # @ep.add_event(e) + + # output = flush_and_get_events + # expect(output).to contain_exactly({ + # kind: "identify", + # creationDate: e[:creationDate], + # user: filtered_user + # }) + # end + + # it "queues individual feature event with index event" do + # @ep = subject.new("sdk_key", default_config, hc) + # flag = { key: "flagkey", version: 11 } + # fe = { + # kind: "feature", key: "flagkey", version: 11, user: user, + # variation: 1, value: "value", trackEvents: true + # } + # @ep.add_event(fe) + + # output = flush_and_get_events + # expect(output).to contain_exactly( + # eq(index_event(fe, user)), + # eq(feature_event(fe, flag, false, nil)), + # include(:kind => "summary") + # ) + # end + + # it "filters user in index event" do + # config = LaunchDarkly::Config.new(all_attributes_private: true) + # @ep = subject.new("sdk_key", config, hc) + # flag = { key: "flagkey", version: 11 } + # fe = { + # kind: "feature", key: "flagkey", version: 11, user: user, + # variation: 1, value: "value", trackEvents: true + # } + # @ep.add_event(fe) + + # output = flush_and_get_events + # expect(output).to contain_exactly( + # eq(index_event(fe, filtered_user)), + # eq(feature_event(fe, flag, false, nil)), + # include(:kind => "summary") + # ) + # end + + # it "can include inline user in feature event" do + # config = LaunchDarkly::Config.new(inline_users_in_events: true) + # @ep = subject.new("sdk_key", config, hc) + # flag = { key: "flagkey", version: 11 } + # fe = { + # kind: "feature", key: "flagkey", version: 11, user: user, + # variation: 1, value: "value", trackEvents: true + # } + # @ep.add_event(fe) + + # output = flush_and_get_events + # expect(output).to contain_exactly( + # eq(feature_event(fe, flag, false, user)), + # include(:kind => "summary") + # ) + # end + + # it "filters user in feature event" do + # config = LaunchDarkly::Config.new(all_attributes_private: true, inline_users_in_events: true) + # @ep = subject.new("sdk_key", config, hc) + # flag = { key: "flagkey", version: 11 } + # fe = { + # kind: "feature", key: "flagkey", version: 11, user: user, + # variation: 1, value: "value", trackEvents: true + # } + # @ep.add_event(fe) + + # output = flush_and_get_events + # expect(output).to contain_exactly( + # eq(feature_event(fe, flag, false, filtered_user)), + # include(:kind => "summary") + # ) + # end + + # it "still generates index event if inline_users is true but feature event was not tracked" do + # config = LaunchDarkly::Config.new(inline_users_in_events: true) + # @ep = subject.new("sdk_key", config, hc) + # flag = { key: "flagkey", version: 11 } + # fe = { + # kind: "feature", key: "flagkey", version: 11, user: user, + # variation: 1, value: "value", trackEvents: false + # } + # @ep.add_event(fe) + + # output = flush_and_get_events + # expect(output).to contain_exactly( + # eq(index_event(fe, user)), + # include(:kind => "summary") + # ) + # end + + # it "sets event kind to debug if flag is temporarily in debug mode" do + # @ep = subject.new("sdk_key", default_config, hc) + # flag = { key: "flagkey", version: 11 } + # future_time = (Time.now.to_f * 1000).to_i + 1000000 + # fe = { + # kind: "feature", key: "flagkey", version: 11, user: user, + # variation: 1, value: "value", trackEvents: false, debugEventsUntilDate: future_time + # } + # @ep.add_event(fe) + + # output = flush_and_get_events + # expect(output).to contain_exactly( + # eq(index_event(fe, user)), + # eq(feature_event(fe, flag, true, user)), + # include(:kind => "summary") + # ) + # end + + # it "can be both debugging and tracking an event" do + # @ep = subject.new("sdk_key", default_config, hc) + # flag = { key: "flagkey", version: 11 } + # future_time = (Time.now.to_f * 1000).to_i + 1000000 + # fe = { + # kind: "feature", key: "flagkey", version: 11, user: user, + # variation: 1, value: "value", trackEvents: true, debugEventsUntilDate: future_time + # } + # @ep.add_event(fe) + + # output = flush_and_get_events + # expect(output).to contain_exactly( + # eq(index_event(fe, user)), + # eq(feature_event(fe, flag, false, nil)), + # eq(feature_event(fe, flag, true, user)), + # include(:kind => "summary") + # ) + # end + + # it "ends debug mode based on client time if client time is later than server time" do + # @ep = subject.new("sdk_key", default_config, hc) + + # # Pick a server time that is somewhat behind the client time + # server_time = (Time.now.to_f * 1000).to_i - 20000 + + # # Send and flush an event we don't care about, just to set the last server time + # hc.set_server_time(server_time) + # @ep.add_event({ kind: "identify", user: { key: "otherUser" }}) + # flush_and_get_events + + # # Now send an event with debug mode on, with a "debug until" time that is further in + # # the future than the server time, but in the past compared to the client. + # flag = { key: "flagkey", version: 11 } + # debug_until = server_time + 1000 + # fe = { + # kind: "feature", key: "flagkey", version: 11, user: user, + # variation: 1, value: "value", trackEvents: false, debugEventsUntilDate: debug_until + # } + # @ep.add_event(fe) + + # # Should get a summary event only, not a full feature event + # output = flush_and_get_events + # expect(output).to contain_exactly( + # eq(index_event(fe, user)), + # include(:kind => "summary") + # ) + # end + + # it "ends debug mode based on server time if server time is later than client time" do + # @ep = subject.new("sdk_key", default_config, hc) + + # # Pick a server time that is somewhat ahead of the client time + # server_time = (Time.now.to_f * 1000).to_i + 20000 + + # # Send and flush an event we don't care about, just to set the last server time + # hc.set_server_time(server_time) + # @ep.add_event({ kind: "identify", user: { key: "otherUser" }}) + # flush_and_get_events + + # # Now send an event with debug mode on, with a "debug until" time that is further in + # # the future than the server time, but in the past compared to the client. + # flag = { key: "flagkey", version: 11 } + # debug_until = server_time - 1000 + # fe = { + # kind: "feature", key: "flagkey", version: 11, user: user, + # variation: 1, value: "value", trackEvents: false, debugEventsUntilDate: debug_until + # } + # @ep.add_event(fe) + + # # Should get a summary event only, not a full feature event + # output = flush_and_get_events + # expect(output).to contain_exactly( + # eq(index_event(fe, user)), + # include(:kind => "summary") + # ) + # end + + # it "generates only one index event for multiple events with same user" do + # @ep = subject.new("sdk_key", default_config, hc) + # flag1 = { key: "flagkey1", version: 11 } + # flag2 = { key: "flagkey2", version: 22 } + # future_time = (Time.now.to_f * 1000).to_i + 1000000 + # fe1 = { + # kind: "feature", key: "flagkey1", version: 11, user: user, + # variation: 1, value: "value", trackEvents: true + # } + # fe2 = { + # kind: "feature", key: "flagkey2", version: 22, user: user, + # variation: 1, value: "value", trackEvents: true + # } + # @ep.add_event(fe1) + # @ep.add_event(fe2) + + # output = flush_and_get_events + # expect(output).to contain_exactly( + # eq(index_event(fe1, user)), + # eq(feature_event(fe1, flag1, false, nil)), + # eq(feature_event(fe2, flag2, false, nil)), + # include(:kind => "summary") + # ) + # end + + # it "summarizes non-tracked events" do + # @ep = subject.new("sdk_key", default_config, hc) + # flag1 = { key: "flagkey1", version: 11 } + # flag2 = { key: "flagkey2", version: 22 } + # future_time = (Time.now.to_f * 1000).to_i + 1000000 + # fe1 = { + # kind: "feature", key: "flagkey1", version: 11, user: user, + # variation: 1, value: "value1", default: "default1" + # } + # fe2 = { + # kind: "feature", key: "flagkey2", version: 22, user: user, + # variation: 1, value: "value2", default: "default2" + # } + # @ep.add_event(fe1) + # @ep.add_event(fe2) + + # output = flush_and_get_events + # expect(output).to contain_exactly( + # eq(index_event(fe1, user)), + # eq({ + # kind: "summary", + # startDate: fe1[:creationDate], + # endDate: fe2[:creationDate], + # features: { + # flagkey1: { + # default: "default1", + # counters: [ + # { version: 11, value: "value1", count: 1 } + # ] + # }, + # flagkey2: { + # default: "default2", + # counters: [ + # { version: 22, value: "value2", count: 1 } + # ] + # } + # } + # }) + # ) + # end + + # it "queues custom event with user" do + # @ep = subject.new("sdk_key", default_config, hc) + # e = { kind: "custom", key: "eventkey", user: user, data: { thing: "stuff" } } + # @ep.add_event(e) + + # output = flush_and_get_events + # expect(output).to contain_exactly( + # eq(index_event(e, user)), + # eq(custom_event(e, nil)) + # ) + # end + + # it "can include inline user in custom event" do + # config = LaunchDarkly::Config.new(inline_users_in_events: true) + # @ep = subject.new("sdk_key", config, hc) + # e = { kind: "custom", key: "eventkey", user: user, data: { thing: "stuff" } } + # @ep.add_event(e) + + # output = flush_and_get_events + # expect(output).to contain_exactly( + # eq(custom_event(e, user)) + # ) + # end + + # it "filters user in custom event" do + # config = LaunchDarkly::Config.new(all_attributes_private: true, inline_users_in_events: true) + # @ep = subject.new("sdk_key", config, hc) + # e = { kind: "custom", key: "eventkey", user: user, data: { thing: "stuff" } } + # @ep.add_event(e) + + # output = flush_and_get_events + # expect(output).to contain_exactly( + # eq(custom_event(e, filtered_user)) + # ) + # end + + # it "does a final flush when shutting down" do + # @ep = subject.new("sdk_key", default_config, hc) + # e = { kind: "identify", user: user } + # @ep.add_event(e) + + # @ep.stop - output = flush_and_get_events - expect(output).to contain_exactly( - eq(custom_event(e, user)) - ) - end + # output = get_events_from_last_request + # expect(output).to contain_exactly(e) + # end - it "filters user in custom event" do - config = LaunchDarkly::Config.new(all_attributes_private: true, inline_users_in_events: true) - @ep = subject.new("sdk_key", config, hc) - e = { kind: "custom", key: "eventkey", user: user, data: { thing: "stuff" } } - @ep.add_event(e) + # it "sends nothing if there are no events" do + # @ep = subject.new("sdk_key", default_config, hc) + # @ep.flush + # expect(hc.get_request).to be nil + # end - output = flush_and_get_events - expect(output).to contain_exactly( - eq(custom_event(e, filtered_user)) - ) - end + # it "sends SDK key" do + # @ep = subject.new("sdk_key", default_config, hc) + # e = { kind: "identify", user: user } + # @ep.add_event(e) - it "does a final flush when shutting down" do + # @ep.flush + # @ep.wait_until_inactive + + # expect(hc.get_request.headers["Authorization"]).to eq "sdk_key" + # end + + # it "stops posting events after getting a 401 error" do + # @ep = subject.new("sdk_key", default_config, hc) + # e = { kind: "identify", user: user } + # @ep.add_event(e) + + # hc.set_response_status(401) + # @ep.flush + # @ep.wait_until_inactive + # expect(hc.get_request).not_to be_nil + # hc.reset + + # @ep.add_event(e) + # @ep.flush + # @ep.wait_until_inactive + # expect(hc.get_request).to be_nil + # end + + it "retries flush once after 5xx error" do @ep = subject.new("sdk_key", default_config, hc) e = { kind: "identify", user: user } @ep.add_event(e) - - @ep.stop - output = get_events_from_last_request - expect(output).to contain_exactly(e) - end - - it "sends nothing if there are no events" do - @ep = subject.new("sdk_key", default_config, hc) + hc.set_response_status(503) @ep.flush - expect(hc.request_received).to be nil - end - - it "sends SDK key" do - @ep = subject.new("sdk_key", default_config, hc) - e = { kind: "identify", user: user } - @ep.add_event(e) + @ep.wait_until_inactive - flush_and_get_events - expect(hc.request_received.headers["Authorization"]).to eq "sdk_key" + expect(hc.get_request).not_to be_nil + expect(hc.get_request).not_to be_nil + expect(hc.get_request).to be_nil # no 3rd request end - it "stops posting events after getting a 401 error" do + it "retries flush once after connection error" do @ep = subject.new("sdk_key", default_config, hc) e = { kind: "identify", user: user } @ep.add_event(e) - hc.set_response_status(401) - flush_and_get_events - expect(hc.request_received).not_to be_nil - hc.reset - @ep.add_event(e) + hc.set_exception(Faraday::Error::ConnectionFailed.new("fail")) @ep.flush - expect(hc.request_received).to be_nil + @ep.wait_until_inactive + + expect(hc.get_request).not_to be_nil + expect(hc.get_request).not_to be_nil + expect(hc.get_request).to be_nil # no 3rd request end def index_event(e, user) @@ -408,11 +441,15 @@ def flush_and_get_events end def get_events_from_last_request - req = hc.request_received + req = hc.get_request JSON.parse(req.body, symbolize_names: true) end class FakeHttpClient + def initialize + reset + end + def set_response_status(status) @status = status end @@ -421,8 +458,12 @@ def set_server_time(time_millis) @server_time = Time.at(time_millis.to_f / 1000) end + def set_exception(e) + @exception = e + end + def reset - @request_received = nil + @requests = [] @status = 200 end @@ -431,20 +472,26 @@ def post(uri) req.headers = {} req.options = Faraday::RequestOptions.new yield req - @request_received = req - resp = Faraday::Response.new - headers = {} - if @server_time - headers["Date"] = @server_time.httpdate + @requests.push(req) + if @exception + raise @exception + else + resp = Faraday::Response.new + headers = {} + if @server_time + headers["Date"] = @server_time.httpdate + end + resp.finish({ + status: @status ? @status : 200, + response_headers: headers + }) + resp end - resp.finish({ - status: @status ? @status : 200, - response_headers: headers - }) - resp end - attr_reader :request_received + def get_request + @requests.shift + end end class FakeResponse From 7c3e9b02b784b55963a38355124daf527374e641 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Tue, 10 Apr 2018 16:00:58 -0700 Subject: [PATCH 16/34] narrower begin/rescue block --- lib/ldclient-rb/events.rb | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index fba4f865..fd33363b 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -298,14 +298,6 @@ def run(sdk_key, config, client, payload, formatter) req.options.timeout = config.read_timeout req.options.open_timeout = config.connect_timeout end - if res.status < 200 || res.status >= 300 - config.logger.error { "[LDClient] Unexpected status code while processing events: #{res.status}" } - if res.status >= 500 && !retried - retried = true - next - end - end - return res rescue StandardError => exn config.logger.warn { "[LDClient] Error flushing events: #{exn.inspect}." } if !retried @@ -314,6 +306,14 @@ def run(sdk_key, config, client, payload, formatter) end return nil end + if res.status < 200 || res.status >= 300 + config.logger.error { "[LDClient] Unexpected status code while processing events: #{res.status}" } + if res.status >= 500 && !retried + retried = true + next + end + end + return res end end end From 18e8aa4bd1aedd452f48d77b5f21e5de113564c5 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Tue, 10 Apr 2018 16:03:29 -0700 Subject: [PATCH 17/34] uncomment tests --- spec/events_spec.rb | 688 ++++++++++++++++++++++---------------------- 1 file changed, 344 insertions(+), 344 deletions(-) diff --git a/spec/events_spec.rb b/spec/events_spec.rb index 02f649a5..6b9684d4 100644 --- a/spec/events_spec.rb +++ b/spec/events_spec.rb @@ -16,356 +16,356 @@ end end - # it "queues identify event" do - # @ep = subject.new("sdk_key", default_config, hc) - # e = { kind: "identify", user: user } - # @ep.add_event(e) - - # output = flush_and_get_events - # expect(output).to contain_exactly(e) - # end - - # it "filters user in identify event" do - # config = LaunchDarkly::Config.new(all_attributes_private: true) - # @ep = subject.new("sdk_key", config, hc) - # e = { kind: "identify", user: user } - # @ep.add_event(e) - - # output = flush_and_get_events - # expect(output).to contain_exactly({ - # kind: "identify", - # creationDate: e[:creationDate], - # user: filtered_user - # }) - # end - - # it "queues individual feature event with index event" do - # @ep = subject.new("sdk_key", default_config, hc) - # flag = { key: "flagkey", version: 11 } - # fe = { - # kind: "feature", key: "flagkey", version: 11, user: user, - # variation: 1, value: "value", trackEvents: true - # } - # @ep.add_event(fe) - - # output = flush_and_get_events - # expect(output).to contain_exactly( - # eq(index_event(fe, user)), - # eq(feature_event(fe, flag, false, nil)), - # include(:kind => "summary") - # ) - # end - - # it "filters user in index event" do - # config = LaunchDarkly::Config.new(all_attributes_private: true) - # @ep = subject.new("sdk_key", config, hc) - # flag = { key: "flagkey", version: 11 } - # fe = { - # kind: "feature", key: "flagkey", version: 11, user: user, - # variation: 1, value: "value", trackEvents: true - # } - # @ep.add_event(fe) - - # output = flush_and_get_events - # expect(output).to contain_exactly( - # eq(index_event(fe, filtered_user)), - # eq(feature_event(fe, flag, false, nil)), - # include(:kind => "summary") - # ) - # end - - # it "can include inline user in feature event" do - # config = LaunchDarkly::Config.new(inline_users_in_events: true) - # @ep = subject.new("sdk_key", config, hc) - # flag = { key: "flagkey", version: 11 } - # fe = { - # kind: "feature", key: "flagkey", version: 11, user: user, - # variation: 1, value: "value", trackEvents: true - # } - # @ep.add_event(fe) - - # output = flush_and_get_events - # expect(output).to contain_exactly( - # eq(feature_event(fe, flag, false, user)), - # include(:kind => "summary") - # ) - # end - - # it "filters user in feature event" do - # config = LaunchDarkly::Config.new(all_attributes_private: true, inline_users_in_events: true) - # @ep = subject.new("sdk_key", config, hc) - # flag = { key: "flagkey", version: 11 } - # fe = { - # kind: "feature", key: "flagkey", version: 11, user: user, - # variation: 1, value: "value", trackEvents: true - # } - # @ep.add_event(fe) - - # output = flush_and_get_events - # expect(output).to contain_exactly( - # eq(feature_event(fe, flag, false, filtered_user)), - # include(:kind => "summary") - # ) - # end - - # it "still generates index event if inline_users is true but feature event was not tracked" do - # config = LaunchDarkly::Config.new(inline_users_in_events: true) - # @ep = subject.new("sdk_key", config, hc) - # flag = { key: "flagkey", version: 11 } - # fe = { - # kind: "feature", key: "flagkey", version: 11, user: user, - # variation: 1, value: "value", trackEvents: false - # } - # @ep.add_event(fe) - - # output = flush_and_get_events - # expect(output).to contain_exactly( - # eq(index_event(fe, user)), - # include(:kind => "summary") - # ) - # end - - # it "sets event kind to debug if flag is temporarily in debug mode" do - # @ep = subject.new("sdk_key", default_config, hc) - # flag = { key: "flagkey", version: 11 } - # future_time = (Time.now.to_f * 1000).to_i + 1000000 - # fe = { - # kind: "feature", key: "flagkey", version: 11, user: user, - # variation: 1, value: "value", trackEvents: false, debugEventsUntilDate: future_time - # } - # @ep.add_event(fe) - - # output = flush_and_get_events - # expect(output).to contain_exactly( - # eq(index_event(fe, user)), - # eq(feature_event(fe, flag, true, user)), - # include(:kind => "summary") - # ) - # end - - # it "can be both debugging and tracking an event" do - # @ep = subject.new("sdk_key", default_config, hc) - # flag = { key: "flagkey", version: 11 } - # future_time = (Time.now.to_f * 1000).to_i + 1000000 - # fe = { - # kind: "feature", key: "flagkey", version: 11, user: user, - # variation: 1, value: "value", trackEvents: true, debugEventsUntilDate: future_time - # } - # @ep.add_event(fe) - - # output = flush_and_get_events - # expect(output).to contain_exactly( - # eq(index_event(fe, user)), - # eq(feature_event(fe, flag, false, nil)), - # eq(feature_event(fe, flag, true, user)), - # include(:kind => "summary") - # ) - # end - - # it "ends debug mode based on client time if client time is later than server time" do - # @ep = subject.new("sdk_key", default_config, hc) - - # # Pick a server time that is somewhat behind the client time - # server_time = (Time.now.to_f * 1000).to_i - 20000 - - # # Send and flush an event we don't care about, just to set the last server time - # hc.set_server_time(server_time) - # @ep.add_event({ kind: "identify", user: { key: "otherUser" }}) - # flush_and_get_events - - # # Now send an event with debug mode on, with a "debug until" time that is further in - # # the future than the server time, but in the past compared to the client. - # flag = { key: "flagkey", version: 11 } - # debug_until = server_time + 1000 - # fe = { - # kind: "feature", key: "flagkey", version: 11, user: user, - # variation: 1, value: "value", trackEvents: false, debugEventsUntilDate: debug_until - # } - # @ep.add_event(fe) - - # # Should get a summary event only, not a full feature event - # output = flush_and_get_events - # expect(output).to contain_exactly( - # eq(index_event(fe, user)), - # include(:kind => "summary") - # ) - # end - - # it "ends debug mode based on server time if server time is later than client time" do - # @ep = subject.new("sdk_key", default_config, hc) - - # # Pick a server time that is somewhat ahead of the client time - # server_time = (Time.now.to_f * 1000).to_i + 20000 - - # # Send and flush an event we don't care about, just to set the last server time - # hc.set_server_time(server_time) - # @ep.add_event({ kind: "identify", user: { key: "otherUser" }}) - # flush_and_get_events - - # # Now send an event with debug mode on, with a "debug until" time that is further in - # # the future than the server time, but in the past compared to the client. - # flag = { key: "flagkey", version: 11 } - # debug_until = server_time - 1000 - # fe = { - # kind: "feature", key: "flagkey", version: 11, user: user, - # variation: 1, value: "value", trackEvents: false, debugEventsUntilDate: debug_until - # } - # @ep.add_event(fe) - - # # Should get a summary event only, not a full feature event - # output = flush_and_get_events - # expect(output).to contain_exactly( - # eq(index_event(fe, user)), - # include(:kind => "summary") - # ) - # end - - # it "generates only one index event for multiple events with same user" do - # @ep = subject.new("sdk_key", default_config, hc) - # flag1 = { key: "flagkey1", version: 11 } - # flag2 = { key: "flagkey2", version: 22 } - # future_time = (Time.now.to_f * 1000).to_i + 1000000 - # fe1 = { - # kind: "feature", key: "flagkey1", version: 11, user: user, - # variation: 1, value: "value", trackEvents: true - # } - # fe2 = { - # kind: "feature", key: "flagkey2", version: 22, user: user, - # variation: 1, value: "value", trackEvents: true - # } - # @ep.add_event(fe1) - # @ep.add_event(fe2) - - # output = flush_and_get_events - # expect(output).to contain_exactly( - # eq(index_event(fe1, user)), - # eq(feature_event(fe1, flag1, false, nil)), - # eq(feature_event(fe2, flag2, false, nil)), - # include(:kind => "summary") - # ) - # end - - # it "summarizes non-tracked events" do - # @ep = subject.new("sdk_key", default_config, hc) - # flag1 = { key: "flagkey1", version: 11 } - # flag2 = { key: "flagkey2", version: 22 } - # future_time = (Time.now.to_f * 1000).to_i + 1000000 - # fe1 = { - # kind: "feature", key: "flagkey1", version: 11, user: user, - # variation: 1, value: "value1", default: "default1" - # } - # fe2 = { - # kind: "feature", key: "flagkey2", version: 22, user: user, - # variation: 1, value: "value2", default: "default2" - # } - # @ep.add_event(fe1) - # @ep.add_event(fe2) - - # output = flush_and_get_events - # expect(output).to contain_exactly( - # eq(index_event(fe1, user)), - # eq({ - # kind: "summary", - # startDate: fe1[:creationDate], - # endDate: fe2[:creationDate], - # features: { - # flagkey1: { - # default: "default1", - # counters: [ - # { version: 11, value: "value1", count: 1 } - # ] - # }, - # flagkey2: { - # default: "default2", - # counters: [ - # { version: 22, value: "value2", count: 1 } - # ] - # } - # } - # }) - # ) - # end - - # it "queues custom event with user" do - # @ep = subject.new("sdk_key", default_config, hc) - # e = { kind: "custom", key: "eventkey", user: user, data: { thing: "stuff" } } - # @ep.add_event(e) - - # output = flush_and_get_events - # expect(output).to contain_exactly( - # eq(index_event(e, user)), - # eq(custom_event(e, nil)) - # ) - # end - - # it "can include inline user in custom event" do - # config = LaunchDarkly::Config.new(inline_users_in_events: true) - # @ep = subject.new("sdk_key", config, hc) - # e = { kind: "custom", key: "eventkey", user: user, data: { thing: "stuff" } } - # @ep.add_event(e) - - # output = flush_and_get_events - # expect(output).to contain_exactly( - # eq(custom_event(e, user)) - # ) - # end - - # it "filters user in custom event" do - # config = LaunchDarkly::Config.new(all_attributes_private: true, inline_users_in_events: true) - # @ep = subject.new("sdk_key", config, hc) - # e = { kind: "custom", key: "eventkey", user: user, data: { thing: "stuff" } } - # @ep.add_event(e) - - # output = flush_and_get_events - # expect(output).to contain_exactly( - # eq(custom_event(e, filtered_user)) - # ) - # end - - # it "does a final flush when shutting down" do - # @ep = subject.new("sdk_key", default_config, hc) - # e = { kind: "identify", user: user } - # @ep.add_event(e) + it "queues identify event" do + @ep = subject.new("sdk_key", default_config, hc) + e = { kind: "identify", user: user } + @ep.add_event(e) + + output = flush_and_get_events + expect(output).to contain_exactly(e) + end + + it "filters user in identify event" do + config = LaunchDarkly::Config.new(all_attributes_private: true) + @ep = subject.new("sdk_key", config, hc) + e = { kind: "identify", user: user } + @ep.add_event(e) + + output = flush_and_get_events + expect(output).to contain_exactly({ + kind: "identify", + creationDate: e[:creationDate], + user: filtered_user + }) + end + + it "queues individual feature event with index event" do + @ep = subject.new("sdk_key", default_config, hc) + flag = { key: "flagkey", version: 11 } + fe = { + kind: "feature", key: "flagkey", version: 11, user: user, + variation: 1, value: "value", trackEvents: true + } + @ep.add_event(fe) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(index_event(fe, user)), + eq(feature_event(fe, flag, false, nil)), + include(:kind => "summary") + ) + end + + it "filters user in index event" do + config = LaunchDarkly::Config.new(all_attributes_private: true) + @ep = subject.new("sdk_key", config, hc) + flag = { key: "flagkey", version: 11 } + fe = { + kind: "feature", key: "flagkey", version: 11, user: user, + variation: 1, value: "value", trackEvents: true + } + @ep.add_event(fe) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(index_event(fe, filtered_user)), + eq(feature_event(fe, flag, false, nil)), + include(:kind => "summary") + ) + end + + it "can include inline user in feature event" do + config = LaunchDarkly::Config.new(inline_users_in_events: true) + @ep = subject.new("sdk_key", config, hc) + flag = { key: "flagkey", version: 11 } + fe = { + kind: "feature", key: "flagkey", version: 11, user: user, + variation: 1, value: "value", trackEvents: true + } + @ep.add_event(fe) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(feature_event(fe, flag, false, user)), + include(:kind => "summary") + ) + end + + it "filters user in feature event" do + config = LaunchDarkly::Config.new(all_attributes_private: true, inline_users_in_events: true) + @ep = subject.new("sdk_key", config, hc) + flag = { key: "flagkey", version: 11 } + fe = { + kind: "feature", key: "flagkey", version: 11, user: user, + variation: 1, value: "value", trackEvents: true + } + @ep.add_event(fe) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(feature_event(fe, flag, false, filtered_user)), + include(:kind => "summary") + ) + end + + it "still generates index event if inline_users is true but feature event was not tracked" do + config = LaunchDarkly::Config.new(inline_users_in_events: true) + @ep = subject.new("sdk_key", config, hc) + flag = { key: "flagkey", version: 11 } + fe = { + kind: "feature", key: "flagkey", version: 11, user: user, + variation: 1, value: "value", trackEvents: false + } + @ep.add_event(fe) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(index_event(fe, user)), + include(:kind => "summary") + ) + end + + it "sets event kind to debug if flag is temporarily in debug mode" do + @ep = subject.new("sdk_key", default_config, hc) + flag = { key: "flagkey", version: 11 } + future_time = (Time.now.to_f * 1000).to_i + 1000000 + fe = { + kind: "feature", key: "flagkey", version: 11, user: user, + variation: 1, value: "value", trackEvents: false, debugEventsUntilDate: future_time + } + @ep.add_event(fe) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(index_event(fe, user)), + eq(feature_event(fe, flag, true, user)), + include(:kind => "summary") + ) + end + + it "can be both debugging and tracking an event" do + @ep = subject.new("sdk_key", default_config, hc) + flag = { key: "flagkey", version: 11 } + future_time = (Time.now.to_f * 1000).to_i + 1000000 + fe = { + kind: "feature", key: "flagkey", version: 11, user: user, + variation: 1, value: "value", trackEvents: true, debugEventsUntilDate: future_time + } + @ep.add_event(fe) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(index_event(fe, user)), + eq(feature_event(fe, flag, false, nil)), + eq(feature_event(fe, flag, true, user)), + include(:kind => "summary") + ) + end + + it "ends debug mode based on client time if client time is later than server time" do + @ep = subject.new("sdk_key", default_config, hc) + + # Pick a server time that is somewhat behind the client time + server_time = (Time.now.to_f * 1000).to_i - 20000 + + # Send and flush an event we don't care about, just to set the last server time + hc.set_server_time(server_time) + @ep.add_event({ kind: "identify", user: { key: "otherUser" }}) + flush_and_get_events + + # Now send an event with debug mode on, with a "debug until" time that is further in + # the future than the server time, but in the past compared to the client. + flag = { key: "flagkey", version: 11 } + debug_until = server_time + 1000 + fe = { + kind: "feature", key: "flagkey", version: 11, user: user, + variation: 1, value: "value", trackEvents: false, debugEventsUntilDate: debug_until + } + @ep.add_event(fe) + + # Should get a summary event only, not a full feature event + output = flush_and_get_events + expect(output).to contain_exactly( + eq(index_event(fe, user)), + include(:kind => "summary") + ) + end + + it "ends debug mode based on server time if server time is later than client time" do + @ep = subject.new("sdk_key", default_config, hc) + + # Pick a server time that is somewhat ahead of the client time + server_time = (Time.now.to_f * 1000).to_i + 20000 + + # Send and flush an event we don't care about, just to set the last server time + hc.set_server_time(server_time) + @ep.add_event({ kind: "identify", user: { key: "otherUser" }}) + flush_and_get_events + + # Now send an event with debug mode on, with a "debug until" time that is further in + # the future than the server time, but in the past compared to the client. + flag = { key: "flagkey", version: 11 } + debug_until = server_time - 1000 + fe = { + kind: "feature", key: "flagkey", version: 11, user: user, + variation: 1, value: "value", trackEvents: false, debugEventsUntilDate: debug_until + } + @ep.add_event(fe) + + # Should get a summary event only, not a full feature event + output = flush_and_get_events + expect(output).to contain_exactly( + eq(index_event(fe, user)), + include(:kind => "summary") + ) + end + + it "generates only one index event for multiple events with same user" do + @ep = subject.new("sdk_key", default_config, hc) + flag1 = { key: "flagkey1", version: 11 } + flag2 = { key: "flagkey2", version: 22 } + future_time = (Time.now.to_f * 1000).to_i + 1000000 + fe1 = { + kind: "feature", key: "flagkey1", version: 11, user: user, + variation: 1, value: "value", trackEvents: true + } + fe2 = { + kind: "feature", key: "flagkey2", version: 22, user: user, + variation: 1, value: "value", trackEvents: true + } + @ep.add_event(fe1) + @ep.add_event(fe2) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(index_event(fe1, user)), + eq(feature_event(fe1, flag1, false, nil)), + eq(feature_event(fe2, flag2, false, nil)), + include(:kind => "summary") + ) + end + + it "summarizes non-tracked events" do + @ep = subject.new("sdk_key", default_config, hc) + flag1 = { key: "flagkey1", version: 11 } + flag2 = { key: "flagkey2", version: 22 } + future_time = (Time.now.to_f * 1000).to_i + 1000000 + fe1 = { + kind: "feature", key: "flagkey1", version: 11, user: user, + variation: 1, value: "value1", default: "default1" + } + fe2 = { + kind: "feature", key: "flagkey2", version: 22, user: user, + variation: 1, value: "value2", default: "default2" + } + @ep.add_event(fe1) + @ep.add_event(fe2) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(index_event(fe1, user)), + eq({ + kind: "summary", + startDate: fe1[:creationDate], + endDate: fe2[:creationDate], + features: { + flagkey1: { + default: "default1", + counters: [ + { version: 11, value: "value1", count: 1 } + ] + }, + flagkey2: { + default: "default2", + counters: [ + { version: 22, value: "value2", count: 1 } + ] + } + } + }) + ) + end + + it "queues custom event with user" do + @ep = subject.new("sdk_key", default_config, hc) + e = { kind: "custom", key: "eventkey", user: user, data: { thing: "stuff" } } + @ep.add_event(e) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(index_event(e, user)), + eq(custom_event(e, nil)) + ) + end + + it "can include inline user in custom event" do + config = LaunchDarkly::Config.new(inline_users_in_events: true) + @ep = subject.new("sdk_key", config, hc) + e = { kind: "custom", key: "eventkey", user: user, data: { thing: "stuff" } } + @ep.add_event(e) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(custom_event(e, user)) + ) + end + + it "filters user in custom event" do + config = LaunchDarkly::Config.new(all_attributes_private: true, inline_users_in_events: true) + @ep = subject.new("sdk_key", config, hc) + e = { kind: "custom", key: "eventkey", user: user, data: { thing: "stuff" } } + @ep.add_event(e) + + output = flush_and_get_events + expect(output).to contain_exactly( + eq(custom_event(e, filtered_user)) + ) + end + + it "does a final flush when shutting down" do + @ep = subject.new("sdk_key", default_config, hc) + e = { kind: "identify", user: user } + @ep.add_event(e) - # @ep.stop + @ep.stop - # output = get_events_from_last_request - # expect(output).to contain_exactly(e) - # end + output = get_events_from_last_request + expect(output).to contain_exactly(e) + end - # it "sends nothing if there are no events" do - # @ep = subject.new("sdk_key", default_config, hc) - # @ep.flush - # expect(hc.get_request).to be nil - # end + it "sends nothing if there are no events" do + @ep = subject.new("sdk_key", default_config, hc) + @ep.flush + expect(hc.get_request).to be nil + end - # it "sends SDK key" do - # @ep = subject.new("sdk_key", default_config, hc) - # e = { kind: "identify", user: user } - # @ep.add_event(e) + it "sends SDK key" do + @ep = subject.new("sdk_key", default_config, hc) + e = { kind: "identify", user: user } + @ep.add_event(e) - # @ep.flush - # @ep.wait_until_inactive + @ep.flush + @ep.wait_until_inactive - # expect(hc.get_request.headers["Authorization"]).to eq "sdk_key" - # end - - # it "stops posting events after getting a 401 error" do - # @ep = subject.new("sdk_key", default_config, hc) - # e = { kind: "identify", user: user } - # @ep.add_event(e) - - # hc.set_response_status(401) - # @ep.flush - # @ep.wait_until_inactive - # expect(hc.get_request).not_to be_nil - # hc.reset - - # @ep.add_event(e) - # @ep.flush - # @ep.wait_until_inactive - # expect(hc.get_request).to be_nil - # end + expect(hc.get_request.headers["Authorization"]).to eq "sdk_key" + end + + it "stops posting events after getting a 401 error" do + @ep = subject.new("sdk_key", default_config, hc) + e = { kind: "identify", user: user } + @ep.add_event(e) + + hc.set_response_status(401) + @ep.flush + @ep.wait_until_inactive + expect(hc.get_request).not_to be_nil + hc.reset + + @ep.add_event(e) + @ep.flush + @ep.wait_until_inactive + expect(hc.get_request).to be_nil + end it "retries flush once after 5xx error" do @ep = subject.new("sdk_key", default_config, hc) From fc7da777d156505069373fa14535cf2c79512731 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Tue, 10 Apr 2018 17:34:35 -0700 Subject: [PATCH 18/34] use each instead of do --- lib/ldclient-rb/events.rb | 18 ++++++++---------- 1 file changed, 8 insertions(+), 10 deletions(-) diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index fd33363b..6f4a2410 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -284,8 +284,9 @@ class EventPayloadSendTask def run(sdk_key, config, client, payload, formatter) events_out = formatter.make_output_events(payload.events, payload.summary) retried = false - loop do - if retried + res = nil + (0..1).each do |attempt| + if attempt > 0 config.logger.warn { "[LDClient] Will retry posting events after 1 second" } sleep(1) end @@ -300,21 +301,18 @@ def run(sdk_key, config, client, payload, formatter) end rescue StandardError => exn config.logger.warn { "[LDClient] Error flushing events: #{exn.inspect}." } - if !retried - retried = true - next - end - return nil + next end if res.status < 200 || res.status >= 300 config.logger.error { "[LDClient] Unexpected status code while processing events: #{res.status}" } - if res.status >= 500 && !retried - retried = true + if res.status >= 500 next end end - return res + break end + # used up our retries, return the last response if any + res end end From d5e7a0450646d54a8d7b757e3b1b7c6408d8396c Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Wed, 11 Apr 2018 11:31:57 -0700 Subject: [PATCH 19/34] rm unused --- lib/ldclient-rb/events.rb | 1 - 1 file changed, 1 deletion(-) diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index 6f4a2410..93f4de7f 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -283,7 +283,6 @@ def clear class EventPayloadSendTask def run(sdk_key, config, client, payload, formatter) events_out = formatter.make_output_events(payload.events, payload.summary) - retried = false res = nil (0..1).each do |attempt| if attempt > 0 From ef851493ade50272f08fd086d94555deb54777c4 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Wed, 18 Apr 2018 14:33:28 -0700 Subject: [PATCH 20/34] set schema header in event payload --- lib/ldclient-rb/events.rb | 1 + 1 file changed, 1 insertion(+) diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index 93f4de7f..4b238568 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -294,6 +294,7 @@ def run(sdk_key, config, client, payload, formatter) req.headers["Authorization"] = sdk_key req.headers["User-Agent"] = "RubyClient/" + LaunchDarkly::VERSION req.headers["Content-Type"] = "application/json" + req.headers["X-LaunchDarkly-Event-Schema"] = "2" req.body = events_out.to_json req.options.timeout = config.read_timeout req.options.open_timeout = config.connect_timeout From befade0fe7bef099a158e9978de99e2e8ca3165f Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Fri, 20 Apr 2018 12:56:41 -0700 Subject: [PATCH 21/34] fix error in client initialization --- lib/ldclient-rb/events.rb | 2 +- spec/ldclient_spec.rb | 15 +++++++++++++-- 2 files changed, 14 insertions(+), 3 deletions(-) diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index 4b238568..580ca3d3 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -53,7 +53,7 @@ class StopMessage < SynchronousMessage end class EventProcessor - def initialize(sdk_key, config, client) + def initialize(sdk_key, config, client = nil) @queue = Queue.new @flush_task = Concurrent::TimerTask.new(execution_interval: config.flush_interval) do @queue << FlushMessage.new(false) diff --git a/spec/ldclient_spec.rb b/spec/ldclient_spec.rb index 4342b06f..233fa91a 100644 --- a/spec/ldclient_spec.rb +++ b/spec/ldclient_spec.rb @@ -100,11 +100,22 @@ def event_processor end describe 'with send_events: false' do - let(:config) { LaunchDarkly::Config.new({offline: true, send_events: false}) } + let(:config) { LaunchDarkly::Config.new({offline: true, send_events: false, update_processor: update_processor}) } let(:client) { subject.new("secret", config) } it "uses a NullEventProcessor" do - expect(event_processor).to be_a(LaunchDarkly::NullEventProcessor) + ep = client.instance_variable_get(:@event_processor) + expect(ep).to be_a(LaunchDarkly::NullEventProcessor) + end + end + + describe 'with send_events: true' do + let(:config_with_events) { LaunchDarkly::Config.new({offline: false, send_events: true, update_processor: update_processor}) } + let(:client_with_events) { subject.new("secret", config_with_events) } + + it "does not use a NullEventProcessor" do + ep = client_with_events.instance_variable_get(:@event_processor) + expect(ep).not_to be_a(LaunchDarkly::NullEventProcessor) end end From 3bfc752abb8ae32dbb95a77fc4dd6eab0c82890c Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Fri, 20 Apr 2018 13:22:05 -0700 Subject: [PATCH 22/34] fix bug in evaluation when prerequisite is missing --- lib/ldclient-rb/evaluation.rb | 21 ++++++++++------- lib/ldclient-rb/ldclient.rb | 4 ++-- spec/evaluation_spec.rb | 43 +++++++++++++++++++++++++++++------ 3 files changed, 51 insertions(+), 17 deletions(-) diff --git a/lib/ldclient-rb/evaluation.rb b/lib/ldclient-rb/evaluation.rb index b40bab38..b4dd796c 100644 --- a/lib/ldclient-rb/evaluation.rb +++ b/lib/ldclient-rb/evaluation.rb @@ -114,7 +114,7 @@ class EvaluationError < StandardError # generated during prerequisite evaluation. Raises EvaluationError if the flag is not well-formed # Will return nil, but not raise an exception, indicating that the rules (including fallthrough) did not match # In that case, the caller should return the default value. - def evaluate(flag, user, store) + def evaluate(flag, user, store, logger) if flag.nil? raise EvaluationError, "Flag does not exist" end @@ -126,7 +126,7 @@ def evaluate(flag, user, store) events = [] if flag[:on] - res = eval_internal(flag, user, store, events) + res = eval_internal(flag, user, store, events, logger) if !res.nil? res[:events] = events return res @@ -142,7 +142,7 @@ def evaluate(flag, user, store) { variation: nil, value: nil, events: events } end - def eval_internal(flag, user, store, events) + def eval_internal(flag, user, store, events, logger) failed_prereq = false # Evaluate prerequisites, if any (flag[:prerequisites] || []).each do |prerequisite| @@ -152,18 +152,23 @@ def eval_internal(flag, user, store, events) failed_prereq = true else begin - prereq_res = eval_internal(prereq_flag, user, store, events) + prereq_res = eval_internal(prereq_flag, user, store, events, logger) event = { - kind: "feature", key: prereq_flag[:key], variation: prereq_res[:variation], - value: prereq_res[:value], version: prereq_flag[:version], prereqOf: flag[:key], - trackEvents: prereq_flag[:trackEvents], debugEventsUntilDate: prereq_flag[:debugEventsUntilDate] + kind: "feature", + key: prereq_flag[:key], + variation: prereq_res.nil? ? nil : prereq_res[:variation], + value: prereq_res.nil? ? nil : prereq_res[:value], + version: prereq_flag[:version], + prereqOf: flag[:key], + trackEvents: prereq_flag[:trackEvents], + debugEventsUntilDate: prereq_flag[:debugEventsUntilDate] } events.push(event) if prereq_res.nil? || prereq_res[:variation] != prerequisite[:variation] failed_prereq = true end rescue => exn - @config.logger.error { "[LDClient] Error evaluating prerequisite: #{exn.inspect}" } + logger.error { "[LDClient] Error evaluating prerequisite: #{exn.inspect}" } failed_prereq = true end end diff --git a/lib/ldclient-rb/ldclient.rb b/lib/ldclient-rb/ldclient.rb index d7d91a5d..f344d921 100644 --- a/lib/ldclient-rb/ldclient.rb +++ b/lib/ldclient-rb/ldclient.rb @@ -147,7 +147,7 @@ def variation(key, user, default) end begin - res = evaluate(feature, user, @store) + res = evaluate(feature, user, @store, @config.logger) if !res[:events].nil? res[:events].each do |event| @event_processor.add_event(event) @@ -209,7 +209,7 @@ def all_flags(user) features = @store.all(FEATURES) # TODO rescue if necessary - Hash[features.map{ |k, f| [k, evaluate(f, user, @store)[:value]] }] + Hash[features.map{ |k, f| [k, evaluate(f, user, @store, @config.logger)[:value]] }] rescue => exn @config.logger.warn { "[LDClient] Error evaluating all flags: #{exn.inspect}. \nTrace: #{exn.backtrace}" } return Hash.new diff --git a/spec/evaluation_spec.rb b/spec/evaluation_spec.rb index eee22d24..a8d980ae 100644 --- a/spec/evaluation_spec.rb +++ b/spec/evaluation_spec.rb @@ -12,6 +12,8 @@ } } + let(:logger) { LaunchDarkly::Config.default_logger } + include LaunchDarkly::Evaluation describe "evaluate" do @@ -24,7 +26,7 @@ variations: ['a', 'b', 'c'] } user = { key: 'x' } - expect(evaluate(flag, user, features)).to eq({variation: 1, value: 'b', events: []}) + expect(evaluate(flag, user, features, logger)).to eq({variation: 1, value: 'b', events: []}) end it "returns nil if flag is off and off variation is unspecified" do @@ -35,7 +37,7 @@ variations: ['a', 'b', 'c'] } user = { key: 'x' } - expect(evaluate(flag, user, features)).to eq({variation: nil, value: nil, events: []}) + expect(evaluate(flag, user, features, logger)).to eq({variation: nil, value: nil, events: []}) end it "returns off variation if prerequisite is not found" do @@ -48,7 +50,34 @@ variations: ['a', 'b', 'c'] } user = { key: 'x' } - expect(evaluate(flag, user, features)).to eq({variation: 1, value: 'b', events: []}) + expect(evaluate(flag, user, features, logger)).to eq({variation: 1, value: 'b', events: []}) + end + + it "returns off variation and event if prerequisite of a prerequisite is not found" do + flag = { + key: 'feature0', + on: true, + prerequisites: [{key: 'feature1', variation: 1}], + fallthrough: { variation: 0 }, + offVariation: 1, + variations: ['a', 'b', 'c'], + version: 1 + } + flag1 = { + key: 'feature1', + on: true, + prerequisites: [{key: 'feature2', variation: 1}], # feature2 doesn't exist + fallthrough: { variation: 0 }, + variations: ['d', 'e'], + version: 2 + } + features.upsert(LaunchDarkly::FEATURES, flag1) + user = { key: 'x' } + events_should_be = [{ + kind: 'feature', key: 'feature1', variation: nil, value: nil, version: 2, prereqOf: 'feature0', + trackEvents: nil, debugEventsUntilDate: nil + }] + expect(evaluate(flag, user, features, logger)).to eq({variation: 1, value: 'b', events: events_should_be}) end it "returns off variation and event if prerequisite is not met" do @@ -74,7 +103,7 @@ kind: 'feature', key: 'feature1', variation: 0, value: 'd', version: 2, prereqOf: 'feature0', trackEvents: nil, debugEventsUntilDate: nil }] - expect(evaluate(flag, user, features)).to eq({variation: 1, value: 'b', events: events_should_be}) + expect(evaluate(flag, user, features, logger)).to eq({variation: 1, value: 'b', events: events_should_be}) end it "returns fallthrough variation and event if prerequisite is met and there are no rules" do @@ -100,7 +129,7 @@ kind: 'feature', key: 'feature1', variation: 1, value: 'e', version: 2, prereqOf: 'feature0', trackEvents: nil, debugEventsUntilDate: nil }] - expect(evaluate(flag, user, features)).to eq({variation: 0, value: 'a', events: events_should_be}) + expect(evaluate(flag, user, features, logger)).to eq({variation: 0, value: 'a', events: events_should_be}) end it "matches user from targets" do @@ -115,7 +144,7 @@ variations: ['a', 'b', 'c'] } user = { key: 'userkey' } - expect(evaluate(flag, user, features)).to eq({variation: 2, value: 'c', events: []}) + expect(evaluate(flag, user, features, logger)).to eq({variation: 2, value: 'c', events: []}) end it "matches user from rules" do @@ -139,7 +168,7 @@ variations: ['a', 'b', 'c'] } user = { key: 'userkey' } - expect(evaluate(flag, user, features)).to eq({variation: 2, value: 'c', events: []}) + expect(evaluate(flag, user, features, logger)).to eq({variation: 2, value: 'c', events: []}) end end From 6d872dc01d4281906b57344a0df0d8b60d5127bb Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Fri, 20 Apr 2018 17:39:10 -0700 Subject: [PATCH 23/34] fixed omission of variation in feature request event --- lib/ldclient-rb/ldclient.rb | 25 +++++++++++++++++++++---- spec/ldclient_spec.rb | 11 +++++++++-- 2 files changed, 30 insertions(+), 6 deletions(-) diff --git a/lib/ldclient-rb/ldclient.rb b/lib/ldclient-rb/ldclient.rb index f344d921..3e3451ba 100644 --- a/lib/ldclient-rb/ldclient.rb +++ b/lib/ldclient-rb/ldclient.rb @@ -158,13 +158,30 @@ def variation(key, user, default) @config.logger.debug { "[LDClient] Result value is null in toggle" } value = default end - @event_processor.add_event(kind: "feature", key: key, user: user, value: res[:value], default: default, version: feature[:version], - trackEvents: feature[:trackEvents], debugEventsUntilDate: feature[:debugEventsUntilDate]) + @event_processor.add_event( + kind: "feature", + key: key, + user: user, + variation: res[:variation], + value: res[:value], + default: default, + version: feature[:version], + trackEvents: feature[:trackEvents], + debugEventsUntilDate: feature[:debugEventsUntilDate] + ) return value rescue => exn @config.logger.warn { "[LDClient] Error evaluating feature flag: #{exn.inspect}. \nTrace: #{exn.backtrace}" } - @event_processor.add_event(kind: "feature", key: key, user: user, value: default, default: default, version: feature[:version], - trackEvents: feature[:trackEvents], debugEventsUntilDate: feature[:debugEventsUntilDate]) + @event_processor.add_event( + kind: "feature", + key: key, + user: user, + value: default, + default: default, + version: feature[:version], + trackEvents: feature[:trackEvents], + debugEventsUntilDate: feature[:debugEventsUntilDate] + ) return default end end diff --git a/spec/ldclient_spec.rb b/spec/ldclient_spec.rb index 233fa91a..1db6028e 100644 --- a/spec/ldclient_spec.rb +++ b/spec/ldclient_spec.rb @@ -50,8 +50,15 @@ def event_processor config.feature_store.init({ LaunchDarkly::FEATURES => {} }) config.feature_store.upsert(LaunchDarkly::FEATURES, feature) expect(event_processor).to receive(:add_event).with(hash_including( - kind: "feature", key: feature[:key], version: feature[:version], user: user, - value: true, default: "default", trackEvents: false, debugEventsUntilDate: nil + kind: "feature", + key: feature[:key], + version: feature[:version], + user: user, + variation: 0, + value: true, + default: "default", + trackEvents: false, + debugEventsUntilDate: nil )) client.variation(feature[:key], user, "default") end From 6533867a30ac2a82fe311e99891e2080934fc06e Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Mon, 23 Apr 2018 16:38:31 -0700 Subject: [PATCH 24/34] re-add redundant key property to identify event --- lib/ldclient-rb/events.rb | 1 + spec/events_spec.rb | 7 ++++--- 2 files changed, 5 insertions(+), 3 deletions(-) diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index 580ca3d3..2118328f 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -356,6 +356,7 @@ def make_output_event(event) { kind: "identify", creationDate: event[:creationDate], + key: event[:user][:key], user: @user_filter.transform_user_props(event[:user]) } when "custom" diff --git a/spec/events_spec.rb b/spec/events_spec.rb index 6b9684d4..4c4e1f94 100644 --- a/spec/events_spec.rb +++ b/spec/events_spec.rb @@ -18,7 +18,7 @@ it "queues identify event" do @ep = subject.new("sdk_key", default_config, hc) - e = { kind: "identify", user: user } + e = { kind: "identify", key: user[:key], user: user } @ep.add_event(e) output = flush_and_get_events @@ -28,12 +28,13 @@ it "filters user in identify event" do config = LaunchDarkly::Config.new(all_attributes_private: true) @ep = subject.new("sdk_key", config, hc) - e = { kind: "identify", user: user } + e = { kind: "identify", key: user[:key], user: user } @ep.add_event(e) output = flush_and_get_events expect(output).to contain_exactly({ kind: "identify", + key: user[:key], creationDate: e[:creationDate], user: filtered_user }) @@ -324,7 +325,7 @@ it "does a final flush when shutting down" do @ep = subject.new("sdk_key", default_config, hc) - e = { kind: "identify", user: user } + e = { kind: "identify", key: user[:key], user: user } @ep.add_event(e) @ep.stop From 9ad3a1431645507afc8ff0970b6fdc80fcf5cd2c Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Mon, 23 Apr 2018 16:47:32 -0700 Subject: [PATCH 25/34] nil guard on user --- lib/ldclient-rb/events.rb | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index 2118328f..146ec4c4 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -349,14 +349,14 @@ def make_output_event(event) if @inline_users || is_debug out[:user] = @user_filter.transform_user_props(event[:user]) else - out[:userKey] = event[:user][:key] + out[:userKey] = event[:user].nil? ? nil : event[:user][:key] end out when "identify" { kind: "identify", creationDate: event[:creationDate], - key: event[:user][:key], + key: event[:user].nil? ? nil : event[:user][:key], user: @user_filter.transform_user_props(event[:user]) } when "custom" @@ -369,7 +369,7 @@ def make_output_event(event) if @inline_users out[:user] = @user_filter.transform_user_props(event[:user]) else - out[:userKey] = event[:user][:key] + out[:userKey] = event[:user].nil? ? nil : event[:user][:key] end out when "index" From 5134d8f7a15e8151664d147973c52a3316efb1b9 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Tue, 24 Apr 2018 10:46:54 -0700 Subject: [PATCH 26/34] fix timed event flushing --- lib/ldclient-rb/events.rb | 8 ++++++-- 1 file changed, 6 insertions(+), 2 deletions(-) diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index 146ec4c4..56014f73 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -56,11 +56,13 @@ class EventProcessor def initialize(sdk_key, config, client = nil) @queue = Queue.new @flush_task = Concurrent::TimerTask.new(execution_interval: config.flush_interval) do - @queue << FlushMessage.new(false) + @queue << FlushMessage.new end + @flush_task.execute @users_flush_task = Concurrent::TimerTask.new(execution_interval: config.user_keys_flush_interval) do @queue << FlushUsersMessage.new end + @users_flush_task.execute @stopped = Concurrent::AtomicBoolean.new(false) EventDispatcher.new(@queue, sdk_key, config, client) @@ -284,18 +286,20 @@ class EventPayloadSendTask def run(sdk_key, config, client, payload, formatter) events_out = formatter.make_output_events(payload.events, payload.summary) res = nil + body = events_out.to_json (0..1).each do |attempt| if attempt > 0 config.logger.warn { "[LDClient] Will retry posting events after 1 second" } sleep(1) end begin + config.logger.debug { "[LDClient] sending #{events_out.length} events: #{body}" } res = client.post (config.events_uri + "/bulk") do |req| req.headers["Authorization"] = sdk_key req.headers["User-Agent"] = "RubyClient/" + LaunchDarkly::VERSION req.headers["Content-Type"] = "application/json" req.headers["X-LaunchDarkly-Event-Schema"] = "2" - req.body = events_out.to_json + req.body = body req.options.timeout = config.read_timeout req.options.open_timeout = config.connect_timeout end From d3e6d9f7eb041f75f97287fb274d97fcdbe566f2 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Tue, 24 Apr 2018 11:30:13 -0700 Subject: [PATCH 27/34] fix user cache clearing --- lib/ldclient-rb/events.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index 56014f73..ca7d6412 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -131,7 +131,7 @@ def main_loop(queue, buffer, flush_workers) when FlushMessage trigger_flush(buffer, flush_workers) when FlushUsersMessage - @user_keys.reset + @user_keys.clear when TestSyncMessage synchronize_for_testing(flush_workers) message.completed From 41c02d065426f37a66902a45860024008eac4504 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Tue, 24 Apr 2018 14:44:18 -0700 Subject: [PATCH 28/34] tolerate missing user in event --- lib/ldclient-rb/user_filter.rb | 2 ++ 1 file changed, 2 insertions(+) diff --git a/lib/ldclient-rb/user_filter.rb b/lib/ldclient-rb/user_filter.rb index 09e03a9d..9f4bce82 100644 --- a/lib/ldclient-rb/user_filter.rb +++ b/lib/ldclient-rb/user_filter.rb @@ -8,6 +8,8 @@ def initialize(config) end def transform_user_props(user_props) + return nil if user_props.nil? + user_private_attrs = Set.new((user_props[:privateAttributeNames] || []).map(&:to_sym)) filtered_user_props, removed = filter_values(user_props, user_private_attrs, ALLOWED_TOP_LEVEL_KEYS, IGNORED_TOP_LEVEL_KEYS) From d94c058512a0187f826d08a6b568726682b0bde7 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Tue, 24 Apr 2018 15:11:05 -0700 Subject: [PATCH 29/34] fix value in feature event --- lib/ldclient-rb/ldclient.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/ldclient-rb/ldclient.rb b/lib/ldclient-rb/ldclient.rb index 3e3451ba..5a7254e4 100644 --- a/lib/ldclient-rb/ldclient.rb +++ b/lib/ldclient-rb/ldclient.rb @@ -163,7 +163,7 @@ def variation(key, user, default) key: key, user: user, variation: res[:variation], - value: res[:value], + value: value, default: default, version: feature[:version], trackEvents: feature[:trackEvents], From 185f2d4cc2ef7c4430c462d3acee20a9e001d376 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Tue, 24 Apr 2018 21:49:37 -0700 Subject: [PATCH 30/34] send as much of a feature event as possible even if user is invalid --- lib/ldclient-rb/ldclient.rb | 53 +++++++++++++++++-------------------- spec/fixtures/feature.json | 2 +- spec/ldclient_spec.rb | 37 +++++++++++++++++++++++++- 3 files changed, 61 insertions(+), 31 deletions(-) diff --git a/lib/ldclient-rb/ldclient.rb b/lib/ldclient-rb/ldclient.rb index 5a7254e4..ece7c4ec 100644 --- a/lib/ldclient-rb/ldclient.rb +++ b/lib/ldclient-rb/ldclient.rb @@ -121,12 +121,6 @@ def initialized? def variation(key, user, default) return default if @config.offline? - unless user - @config.logger.error { "[LDClient] Must specify user" } - @event_processor.add_event(kind: "feature", key: key, value: default, default: default, user: user) - return default - end - if !initialized? if @store.initialized? @config.logger.warn { "[LDClient] Client has not finished initializing; using last known values from feature store" } @@ -137,7 +131,7 @@ def variation(key, user, default) end end - sanitize_user(user) + sanitize_user(user) if !user.nil? feature = @store.get(FEATURES, key) if feature.nil? @@ -146,6 +140,12 @@ def variation(key, user, default) return default end + unless user + @config.logger.error { "[LDClient] Must specify user" } + @event_processor.add_event(make_feature_event(feature, user, nil, default, default)) + return default + end + begin res = evaluate(feature, user, @store, @config.logger) if !res[:events].nil? @@ -158,30 +158,11 @@ def variation(key, user, default) @config.logger.debug { "[LDClient] Result value is null in toggle" } value = default end - @event_processor.add_event( - kind: "feature", - key: key, - user: user, - variation: res[:variation], - value: value, - default: default, - version: feature[:version], - trackEvents: feature[:trackEvents], - debugEventsUntilDate: feature[:debugEventsUntilDate] - ) + @event_processor.add_event(make_feature_event(feature, user, res[:variation], value, default)) return value rescue => exn @config.logger.warn { "[LDClient] Error evaluating feature flag: #{exn.inspect}. \nTrace: #{exn.backtrace}" } - @event_processor.add_event( - kind: "feature", - key: key, - user: user, - value: default, - default: default, - version: feature[:version], - trackEvents: feature[:trackEvents], - debugEventsUntilDate: feature[:debugEventsUntilDate] - ) + @event_processor.add_event(make_feature_event(feature, user, nil, default, default)) return default end end @@ -258,6 +239,20 @@ def sanitize_user(user) end end - private :evaluate, :log_exception, :sanitize_user + def make_feature_event(flag, user, variation, value, default) + { + kind: "feature", + key: flag[:key], + user: user, + variation: variation, + value: value, + default: default, + version: flag[:version], + trackEvents: flag[:trackEvents], + debugEventsUntilDate: flag[:debugEventsUntilDate] + } + end + + private :evaluate, :log_exception, :sanitize_user, :make_feature_event end end diff --git a/spec/fixtures/feature.json b/spec/fixtures/feature.json index 0001e990..dd44b404 100644 --- a/spec/fixtures/feature.json +++ b/spec/fixtures/feature.json @@ -32,6 +32,6 @@ true, false ], - "trackEvents": false, + "trackEvents": true, "deleted":false } \ No newline at end of file diff --git a/spec/ldclient_spec.rb b/spec/ldclient_spec.rb index 1db6028e..405e0d53 100644 --- a/spec/ldclient_spec.rb +++ b/spec/ldclient_spec.rb @@ -57,11 +57,46 @@ def event_processor variation: 0, value: true, default: "default", - trackEvents: false, + trackEvents: true, debugEventsUntilDate: nil )) client.variation(feature[:key], user, "default") end + + it "queues a feature event for an existing feature when user is nil" do + config.feature_store.init({ LaunchDarkly::FEATURES => {} }) + config.feature_store.upsert(LaunchDarkly::FEATURES, feature) + expect(event_processor).to receive(:add_event).with(hash_including( + kind: "feature", + key: feature[:key], + version: feature[:version], + user: nil, + variation: nil, + value: "default", + default: "default", + trackEvents: true, + debugEventsUntilDate: nil + )) + client.variation(feature[:key], nil, "default") + end + + it "queues a feature event for an existing feature when user key is nil" do + config.feature_store.init({ LaunchDarkly::FEATURES => {} }) + config.feature_store.upsert(LaunchDarkly::FEATURES, feature) + bad_user = { name: "Bob" } + expect(event_processor).to receive(:add_event).with(hash_including( + kind: "feature", + key: feature[:key], + version: feature[:version], + user: bad_user, + variation: nil, + value: "default", + default: "default", + trackEvents: true, + debugEventsUntilDate: nil + )) + client.variation(feature[:key], bad_user, "default") + end end describe '#secure_mode_hash' do From 2ce49710fa9f8b293e56045a97831cd98383215e Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Thu, 26 Apr 2018 16:41:33 -0700 Subject: [PATCH 31/34] use our own lightweight expiring cache instead of moneta --- ldclient-rb.gemspec | 2 +- lib/ldclient-rb.rb | 1 + lib/ldclient-rb/expiring_cache.rb | 76 +++++++++++++++++++++++++++++++ lib/ldclient-rb/redis_store.rb | 21 ++++----- spec/expiring_cache_spec.rb | 76 +++++++++++++++++++++++++++++++ 5 files changed, 164 insertions(+), 12 deletions(-) create mode 100644 lib/ldclient-rb/expiring_cache.rb create mode 100644 spec/expiring_cache_spec.rb diff --git a/ldclient-rb.gemspec b/ldclient-rb.gemspec index 5df44a25..4c6e8eeb 100644 --- a/ldclient-rb.gemspec +++ b/ldclient-rb.gemspec @@ -26,7 +26,6 @@ Gem::Specification.new do |spec| spec.add_development_dependency "codeclimate-test-reporter", "~> 0" spec.add_development_dependency "redis", "~> 3.3.5" spec.add_development_dependency "connection_pool", ">= 2.1.2" - spec.add_development_dependency "moneta", "~> 1.0.0" if RUBY_VERSION >= "2.0.0" spec.add_development_dependency "rake", "~> 10.0" spec.add_development_dependency "rspec_junit_formatter", "~> 0.3.0" @@ -34,6 +33,7 @@ Gem::Specification.new do |spec| spec.add_development_dependency "rake", "12.1.0" # higher versions of rake fail to install in JRuby 1.7 end + spec.add_development_dependency "timecop", "~> 0.9.1" spec.add_runtime_dependency "json", [">= 1.8", "< 3"] if RUBY_VERSION >= "2.1.0" diff --git a/lib/ldclient-rb.rb b/lib/ldclient-rb.rb index ce943d13..28a1de01 100644 --- a/lib/ldclient-rb.rb +++ b/lib/ldclient-rb.rb @@ -2,6 +2,7 @@ require "ldclient-rb/evaluation" require "ldclient-rb/ldclient" require "ldclient-rb/cache_store" +require "ldclient-rb/expiring_cache" require "ldclient-rb/memoized_value" require "ldclient-rb/in_memory_store" require "ldclient-rb/config" diff --git a/lib/ldclient-rb/expiring_cache.rb b/lib/ldclient-rb/expiring_cache.rb new file mode 100644 index 00000000..6d8c48f8 --- /dev/null +++ b/lib/ldclient-rb/expiring_cache.rb @@ -0,0 +1,76 @@ + +module LaunchDarkly + # A thread-safe cache with maximum number of entries and TTL. + # Adapted from https://github.com/SamSaffron/lru_redux/blob/master/lib/lru_redux/ttl/cache.rb + # under MIT license with the following changes: + # * made thread-safe + # * removed many unused methods + # * reading a key does not reset its expiration time, only writing + class ExpiringCache + def initialize(max_size, ttl) + @max_size = max_size + @ttl = ttl + @data_lru = {} + @data_ttl = {} + @lock = Mutex.new + end + + def [](key) + @lock.synchronize do + ttl_evict + @data_lru[key] + end + end + + def []=(key, val) + @lock.synchronize do + ttl_evict + + @data_lru.delete(key) + @data_ttl.delete(key) + + @data_lru[key] = val + @data_ttl[key] = Time.now.to_f + + if @data_lru.size > @max_size + key, _ = @data_lru.first # hashes have a FIFO ordering in Ruby + + @data_ttl.delete(key) + @data_lru.delete(key) + end + + val + end + end + + def delete(key) + @lock.synchronize do + ttl_evict + + @data_lru.delete(key) + @data_ttl.delete(key) + end + end + + def clear + @lock.synchronize do + @data_lru.clear + @data_ttl.clear + end + end + + private + + def ttl_evict + ttl_horizon = Time.now.to_f - @ttl + key, time = @data_ttl.first + + until time.nil? || time > ttl_horizon + @data_ttl.delete(key) + @data_lru.delete(key) + + key, time = @data_ttl.first + end + end + end +end diff --git a/lib/ldclient-rb/redis_store.rb b/lib/ldclient-rb/redis_store.rb index 0bbe8990..d79a898f 100644 --- a/lib/ldclient-rb/redis_store.rb +++ b/lib/ldclient-rb/redis_store.rb @@ -9,15 +9,14 @@ module LaunchDarkly # streaming API. Feature data can also be further cached in memory to reduce overhead # of calls to Redis. # - # To use this class, you must first have the `redis`, `connection-pool`, and `moneta` - # gems installed. Then, create an instance and store it in the `feature_store` - # property of your client configuration. + # To use this class, you must first have the `redis` and `connection-pool` gems + # installed. Then, create an instance and store it in the `feature_store` property + # of your client configuration. # class RedisFeatureStore begin require "redis" require "connection_pool" - require "moneta" REDIS_ENABLED = true rescue ScriptError, StandardError REDIS_ENABLED = false @@ -38,7 +37,7 @@ class RedisFeatureStore # def initialize(opts = {}) if !REDIS_ENABLED - raise RuntimeError.new("can't use RedisFeatureStore because one of these gems is missing: redis, connection_pool, moneta") + raise RuntimeError.new("can't use RedisFeatureStore because one of these gems is missing: redis, connection_pool") end @redis_opts = opts[:redis_opts] || Hash.new if opts[:redis_url] @@ -60,9 +59,9 @@ def initialize(opts = {}) # Moneta can also be used as a wrapper for Redis, but it doesn't support the Redis # hash operations that we use. if @expiration_seconds > 0 - @cache = Moneta.new(:LRUHash, expires: true, threadsafe: true, max_count: @capacity) + @cache = ExpiringCache.new(@capacity, @expiration_seconds) else - @cache = Moneta.new(:Null) # a stub that caches nothing + @cache = nil end @stopped = Concurrent::AtomicBoolean.new(false) @@ -92,7 +91,7 @@ def self.default_prefix end def get(kind, key) - f = @cache[cache_key(kind, key)] + f = @cache.nil? ? nil : @cache[cache_key(kind, key)] if f.nil? @logger.debug { "RedisFeatureStore: no cache hit for #{key} in '#{kind[:namespace]}', requesting from Redis" } f = with_connection do |redis| @@ -139,7 +138,7 @@ def delete(kind, key, version) end def init(all_data) - @cache.clear + @cache.clear if !@cache.nil? count = 0 with_connection do |redis| all_data.each do |kind, items| @@ -174,7 +173,7 @@ def initialized? def stop if @stopped.make_true @pool.shutdown { |redis| redis.close } - @cache.clear + @cache.clear if !@cache.nil? end end @@ -213,7 +212,7 @@ def get_redis(kind, redis, key) end def put_cache(kind, key, value) - @cache.store(cache_key(kind, key), value, expires: @expiration_seconds) + @cache[cache_key(kind, key)] = value if !@cache.nil? end def update_with_versioning(kind, new_item) diff --git a/spec/expiring_cache_spec.rb b/spec/expiring_cache_spec.rb new file mode 100644 index 00000000..ed021c34 --- /dev/null +++ b/spec/expiring_cache_spec.rb @@ -0,0 +1,76 @@ +require 'timecop' + +describe LaunchDarkly::ExpiringCache do + subject { LaunchDarkly::ExpiringCache } + + before(:each) do + Timecop.freeze(Time.now) + end + + after(:each) do + Timecop.return + end + + it "evicts entries based on TTL" do + c = subject.new(3, 300) + c[:a] = 1 + c[:b] = 2 + + Timecop.freeze(Time.now + 330) + + c[:c] = 3 + + expect(c[:a]).to be nil + expect(c[:b]).to be nil + expect(c[:c]).to eq 3 + end + + it "evicts entries based on max size" do + c = subject.new(2, 300) + c[:a] = 1 + c[:b] = 2 + c[:c] = 3 + + expect(c[:a]).to be nil + expect(c[:b]).to eq 2 + expect(c[:c]).to eq 3 + end + + it "does not reset LRU on get" do + c = subject.new(2, 300) + c[:a] = 1 + c[:b] = 2 + c[:a] + c[:c] = 3 + + expect(c[:a]).to be nil + expect(c[:b]).to eq 2 + expect(c[:c]).to eq 3 + end + + it "resets LRU on put" do + c = subject.new(2, 300) + c[:a] = 1 + c[:b] = 2 + c[:a] = 1 + c[:c] = 3 + + expect(c[:a]).to eq 1 + expect(c[:b]).to be nil + expect(c[:c]).to eq 3 + end + + it "resets TTL on put" do + c = subject.new(3, 300) + c[:a] = 1 + c[:b] = 2 + + Timecop.freeze(Time.now + 330) + c[:a] = 1 + c[:c] = 3 + + expect(c[:a]).to eq 1 + expect(c[:b]).to be nil + expect(c[:c]).to eq 3 + end +end From 072217d0d63706295fb9997e88cfad9853a7bd02 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Fri, 27 Apr 2018 10:34:35 -0700 Subject: [PATCH 32/34] rm unnecessary instance vars and obsolete comment --- lib/ldclient-rb/redis_store.rb | 11 ++++------- 1 file changed, 4 insertions(+), 7 deletions(-) diff --git a/lib/ldclient-rb/redis_store.rb b/lib/ldclient-rb/redis_store.rb index d79a898f..3729ca6b 100644 --- a/lib/ldclient-rb/redis_store.rb +++ b/lib/ldclient-rb/redis_store.rb @@ -53,13 +53,10 @@ def initialize(opts = {}) @prefix = opts[:prefix] || RedisFeatureStore.default_prefix @logger = opts[:logger] || Config.default_logger - @expiration_seconds = opts[:expiration] || 15 - @capacity = opts[:capacity] || 1000 - # We're using Moneta only to provide expiration behavior for the in-memory cache. - # Moneta can also be used as a wrapper for Redis, but it doesn't support the Redis - # hash operations that we use. - if @expiration_seconds > 0 - @cache = ExpiringCache.new(@capacity, @expiration_seconds) + expiration_seconds = opts[:expiration] || 15 + capacity = opts[:capacity] || 1000 + if expiration_seconds > 0 + @cache = ExpiringCache.new(capacity, expiration_seconds) else @cache = nil end From 7358fac18751d973d9f5f33ac1677b06a581e98b Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Mon, 30 Apr 2018 12:34:06 -0700 Subject: [PATCH 33/34] include variation index in events and bump schema version to 3 --- lib/ldclient-rb/events.rb | 7 ++++++- spec/events_spec.rb | 7 ++++--- 2 files changed, 10 insertions(+), 4 deletions(-) diff --git a/lib/ldclient-rb/events.rb b/lib/ldclient-rb/events.rb index ca7d6412..96db3f46 100644 --- a/lib/ldclient-rb/events.rb +++ b/lib/ldclient-rb/events.rb @@ -7,6 +7,7 @@ module LaunchDarkly MAX_FLUSH_WORKERS = 5 + CURRENT_SCHEMA_VERSION = 3 class NullEventProcessor def add_event(event) @@ -298,7 +299,7 @@ def run(sdk_key, config, client, payload, formatter) req.headers["Authorization"] = sdk_key req.headers["User-Agent"] = "RubyClient/" + LaunchDarkly::VERSION req.headers["Content-Type"] = "application/json" - req.headers["X-LaunchDarkly-Event-Schema"] = "2" + req.headers["X-LaunchDarkly-Event-Schema"] = CURRENT_SCHEMA_VERSION.to_s req.body = body req.options.timeout = config.read_timeout req.options.open_timeout = config.connect_timeout @@ -348,6 +349,7 @@ def make_output_event(event) value: event[:value] } out[:default] = event[:default] if event.has_key?(:default) + out[:variation] = event[:variation] if event.has_key?(:variation) out[:version] = event[:version] if event.has_key?(:version) out[:prereqOf] = event[:prereqOf] if event.has_key?(:prereqOf) if @inline_users || is_debug @@ -403,6 +405,9 @@ def make_summary_event(summary) value: cval[:value], count: cval[:count] } + if !ckey[:variation].nil? + c[:variation] = ckey[:variation] + end if ckey[:version].nil? c[:unknown] = true else diff --git a/spec/events_spec.rb b/spec/events_spec.rb index 4c4e1f94..cbce1fbe 100644 --- a/spec/events_spec.rb +++ b/spec/events_spec.rb @@ -257,7 +257,7 @@ } fe2 = { kind: "feature", key: "flagkey2", version: 22, user: user, - variation: 1, value: "value2", default: "default2" + variation: 2, value: "value2", default: "default2" } @ep.add_event(fe1) @ep.add_event(fe2) @@ -273,13 +273,13 @@ flagkey1: { default: "default1", counters: [ - { version: 11, value: "value1", count: 1 } + { version: 11, variation: 1, value: "value1", count: 1 } ] }, flagkey2: { default: "default2", counters: [ - { version: 22, value: "value2", count: 1 } + { version: 22, variation: 2, value: "value2", count: 1 } ] } } @@ -409,6 +409,7 @@ def feature_event(e, flag, debug, inline_user) kind: debug ? "debug" : "feature", creationDate: e[:creationDate], key: flag[:key], + variation: e[:variation], version: flag[:version], value: e[:value] } From 11c23b53b5d6f05bc191002c310f6a4c377149d1 Mon Sep 17 00:00:00 2001 From: Eli Bishop Date: Fri, 4 May 2018 14:40:38 -0700 Subject: [PATCH 34/34] don't build in JRuby 1.7 --- .circleci/config.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.circleci/config.yml b/.circleci/config.yml index f81e736b..c94d18e4 100644 --- a/.circleci/config.yml +++ b/.circleci/config.yml @@ -54,7 +54,7 @@ jobs: machine: image: circleci/classic:latest environment: - - RUBIES: "ruby-2.1.9 ruby-2.0.0 ruby-1.9.3 jruby-1.7.22 jruby-9.0.5.0" + - RUBIES: "ruby-2.1.9 ruby-2.0.0 ruby-1.9.3 jruby-9.0.5.0" steps: - run: sudo apt-get -q update - run: sudo apt-get -qy install redis-server