statsig-io / ruby-sdk

Statsig server SDK for Ruby
ISC License
4 stars 5 forks source link

Can not send log event with Statsig.log_event in Production #2

Closed NerdyBoyCool closed 2 years ago

NerdyBoyCool commented 3 years ago

Hi! Thanks for this sdk.

I wrote the program which sends a custom log event to statsig metrics. the program looks like it's working fine in "development". (I confirmed the log in statsig dashboard.)

But, I deployed it to "production" and checked it, I couldn't confirm it in dashboard. I put some logger in my application to investigate, but every logs are the same as the dev. (Statsig.log_event just returns "nil".)

I can't investigate the reason any more. Are there any actions that need to be taken to investigate the cause?

SDK version: 1.6.2 Ruby version: 3.0.2

By the way, I read ruby-sdk source, I found this line. https://github.com/statsig-io/ruby-sdk/blob/27ff7f3ff379854ea899a1e1ba3c863c009f0721/lib/network.rb#L90 I think it should return value or do something in this rescue block, because if it do noting in this block, we can't know what happened when post_logs raise error.

My Application Code

  1. Initialize Statsig
    
    if Rails.env.production? || Rails.env.sandbox?
    tier = Rails.env.sandbox? ? "staging" : Rails.env
    options = StatsigOptions.new({ "tier" => tier })
    Statsig.initialize(Rails.application.credentials.statsig_server_secret_key, options)
    end

2. Custom Statsig User Class (Because we should set custom user property every sending log.)
```rb

# frozen_string_literal: true

class StatsigUserEntity
  include ActiveModel::Model

  attr_accessor :user_id :user

  def initialize(user_id:)
    @user_id = user_id
    @user = statsig_user
  end

  private

  def statsig_user
    user = User.find(user_id)
    return if user.nil?

    StatsigUser.new({
      "user_id" => user.id,
      "custom" => user_properties(user),
    })
  end

  def user_properties(user)
    {
      # custom user_properties, etc user.name, user.age
    }
  end
end
  1. I use ApplicationJob(In Rails https://guides.rubyonrails.org/active_job_basics.html) Active Job is a framework for declaring jobs and making them run on a variety of queuing backends.

class TrackStatsigEventJob < ApplicationJob
  queue_as :default

  before_enqueue {|job| Rails.logger.info("#{job.class.name.underscore}.enqueue: #{job.inspect}") }

  def perform(attributes)
    statsig_user = StatsigUserEntity.new(user_id: attributes[:user_id], ip: attributes[:ip]).user
    return if statsig_user.nil?

    if Rails.env.production? || Rails.env.sandbox?
      # in my production log, this method just returns "nil"
      Statsig.log_event(statsig_user, attributes[:event_type], attributes[:value], attributes[:event_properties])
    else
      Rails.logger.info attributes # for local info
    end
  end
end

Thanks for Reading!

tore-statsig commented 3 years ago

Hi @NerdyBoyCool - thanks for the report.

I see you set the environment like this:

tier = Rails.env.sandbox? ? "staging" : Rails.env

What is that Rails.env in production? Can you explicitly set the environment to "production" in production (looks like you have an explicit check for Rails.env.production?

The logstream will only show "development" and "staging" logs with the toggle on. When it's toggled off, it will only show logs for which the tier is unset or equal to "production"

NerdyBoyCool commented 3 years ago

The logstream will only show "development" and "staging" logs with the toggle on. When it's toggled off, it will only show logs for which the tier is unset or equal to "production"

Yes, I know the system. Outside of a production environment, I toggled on to confirm "development" and "sandbox" data.

What is that Rails.env in production?

In Production, Rails.env is "production".

In order to make sure that it was working correctly in the development environment, we used this code during the development.

if true
  tier = Rails.env.sandbox? ? "staging" : Rails.env
  options = StatsigOptions.new({ "tier" => tier })
  Statsig.initialize(Rails.application.credentials.statsig_server_secret_key, options)
end
class TrackStatsigEventJob < ApplicationJob
  queue_as :default

  def perform(attributes)
    # ~~~~~~~~

    if true # in developing to confirm log in toggled dashboard
      # in my production log, this method just returns "nil"
      Statsig.log_event(statsig_user, attributes[:event_type], attributes[:value], attributes[:event_properties])
    else
      Rails.logger.info attributes # for local info
    end
  end
end

And I've tried other thing. In developing, I set tier to "production", and then I confirmed a log in dashboard. At that time, I could confirm it.

But, after deployed, I couldn't confirm it. (the application is running on AWS ECS Fargate.)

tore-statsig commented 3 years ago

If everything is working locally and then not in production, my guess it it has to do with your production environment.

It looks like AWS ECS Fargate is a serverless solution, which can complicate things a bit. Statsig serverside/multiuser SDKs are primarily intended for long running webservers. That being said, there should be a way to make this workable for you.

Is there a lifecycle event when the container is exiting that you can hook into, and call Statsig.shutdown() in order to force flush events to Statsig? The SDK batches up to 500 events, or for a minute at a time, before sending events to the server. If you're using Statsig in a script, or shorter process, you need to ensure you call shutdown() to cleanup background threads and force flush logs to Statsig.

The alternative is a network issue, where statsig is not reachable from your application - have you verified that gates are evaluating correctly in the production environment, just logs are missing?

NerdyBoyCool commented 3 years ago

Thanks for reply.

I checked the feature gates like this.

  def check_gate(user) # user is StatsigUser
    if Statsig.check_gate(user, 'onboarding')
      Rails.logger.info("GateIsOpen:onboarding #{user.inspect}")
    else
      Rails.logger.info("GateIsClosed:onboarding #{user.inspect}")
    end
    if Statsig.check_gate(user, 'new_design')
      Rails.logger.info("GateIsOpen:new_design #{user.inspect}")
    else
      Rails.logger.info("GateIsClosed:new_design #{user.inspect}")
    end
  end

the Both Rails.logger puts "GateIsClosed". As you noted, there seems to be a problem with the network.

There is no immediate consideration, but I would like to continue my investigation.

I would also like to examine the handling of container termination as another issue.

jkw-statsig commented 3 years ago

In that case your initialize call probably has failed as well due to errors. As you noticed earlier we aren't doing anything with network errors right now, which isn't very convenient for debugging purposes. We are working on a version which will let you specify a callback that will be called with an error if there is one during initialize. Will let you know once it's ready to test in case it helps with your investigation.

jkw-statsig commented 3 years ago

Hey @NerdyBoyCool - we just published a new beta version (1.7.0.beta.1) of the SDK that allows you to pass a 3rd parameter when calling initialize to specify a callback function to be called when there is an error during initialization, which makes a network request to download your feature gates and experiments configs. You can do something like this to see if you hit any error.

Statsig.initialize(Rails.application.credentials.statsig_server_secret_key, options, (-> (e) {
      // log the error to investigate
 }))

You can install with

gem install statsig -v 1.7.0.beta.1 --pre

Hopefully this can help you understand the problem better!

NerdyBoyCool commented 3 years ago

@jkw-statsig Thank you for your helping 👍 👍 👍 I think that version will make it easier to my investigate.

NerdyBoyCool commented 3 years ago

Hi Statsig Members.

I tried new version ruby-sdk, and confirmed application logs. But, It did not output anything.

tier = Rails.env.sandbox? ? "staging" : Rails.env
options = StatsigOptions.new({ "tier" => tier })
Statsig.initialize(Rails.application.credentials.statsig_server_secret_key, options, (->(e) {
  Rails.logger.info("Statsig ERROR is nil?: #{e.nil?}")
  Rails.logger.info("[Statsig ERROR]: #{e}")
}),)
2021-10-13 06:21:24.061898 I [43:62780] Rails -- Statsig ERROR is nil?: true
2021-10-13 06:21:24.063499 I [43:62780] Rails -- [Statsig ERROR]: 

After that, I confirmed feature gate again. ( https://github.com/statsig-io/ruby-sdk/issues/2#issuecomment-940753914 ) I realized that I forgot to set a email to StatsigUser. The reason why I couldn't confirm that the feature gates was open before was because I hadn't set up an email address. (We have set the gates for a particular email address.)

2021-10-12 08:55:10.286865  Rails -- GateIsOpen:onboarding #<StatsigUser:0x000055ed9d204230 @statsig_environment={"tier"=>"staging"}, @user_id="xxx", @email="kurt@timetreeapp.com", @ip="xxx", @user_agent=nil, @country=nil, @locale=nil, @app_version=nil, @custom={~~omission~~}, @private_attributes=nil>

From this result, I think the network problem has been solved.

vijaye-statsig commented 3 years ago

Thanks @NerdyBoyCool. Glad things are working now.

NerdyBoyCool commented 3 years ago

@vijaye-statsig I forgot to add the current situation. We have confirmed that it is not a network problem, but the event of not being able to send the log itself is still ongoing.

If this is a problem only for us, I will use the HTTP API instead of the SDK. Can I ask questions about the HTTP API at slack community?

vijaye-statsig commented 3 years ago

Ahh, sorry I misunderstood. I'll keep this issue open. Please do feel free to ask in the Slack community - you'll get faster responses there.

jkw-statsig commented 3 years ago

@NerdyBoyCool good to know the gate checks are working for you now.

On the issue about logs not coming through, did you call the shutdown when your app/server exits? Our SDK flushes events only once per minute so if your app exits before then they might not get flushed. Calling shutdown will force it to flush one last time when your app exits.

Also make sure the user you provide is a valid StatsigUser with a userID

NerdyBoyCool commented 3 years ago

Hi, I have not tried "shutdown" yet. I will do it.

Also make sure the user you provide is a valid StatsigUser with a userID

Yes, I confirmed it. I supposed the id is valid.

By the way, I tried HTTP API in Staging Server, and I confirmed the logs in Statsig Dashboard.

jkw-statsig commented 2 years ago

Closing the issue given that the SDK has been working correctly.