Accessing Rails Environment Variables

[dehjli85]

I'm trying to use good_jobs to run a set of jobs that send emails. We have different environments set up (i.e. prod, test, dev), and we only want to have the emails sent when running the job in the prod environment. Our email sending services allows us to append a flag (as JSON) on email requests to indicate whether it's a sandbox request vs. a real request, so in our dev/test environments, we use add this flag, and in our production environment we don't.

For some reason, these jobs we've written seem to be running properly (they get recorded in the good_jobs table, and appropriate changes are recorded in our database), but the emails aren't actually getting sent (we've verified with our provider they aren't getting sent real requests). I suspect the reason is because the good_jobs processes isn't able to access/read the environment variables we have set up properly, since everything in the jobs seems to be working except the actual emails going out.

Is there a good/easy way to verify whether the environment variables are being accessed properly?

For reference, our code looks like something like this:

add_sandbox_flag if ENV['RAILS_ENV'] == 'production' 

[bensheldon]

@dehjli85 that's strange! Are you running the $ good_job command line tool, or are you running GoodJob async within the web browser? Can you say more about what you're running and how you're initializing it?

Either way, the Rails environment will be initialized, so you can make a Rails initializer that does something like:

# config/initializers/debug_env.rb
puts "RAILS_ENV: #{ENV['RAILS_ENV']}"

[dehjli85]

Yes, we're using the good_job command line tool, and initiating it as follows:

bundle exec good_job start --enable-cron --daemonize --pidfile=/var/pids/good_job.pid

The job that we're running just makes some database queries and runs some simple updates. The email that gets sent out is strictly just a confirmation that the job executed, and reports any errors that happened along the way.

This is all happening on an AWS EC2 instance if that makes any difference.

Is there a standard place that we should be logging to or that already gets logged? If not, we can try to use a custom logger to see if we can identify what's happening.

[bensheldon]

Hmmm. You can use the standard Rails.logger to log output.

How are you setting environment variables in your other Rails processes? e.g. are they set in the shell environment, or are you using something like foreman/dotenv?

[dehjli85]

We deploy our app on AWS using Elastic Beanstalk. They have a GUI for setting environment variables.

We have a deployment script that calls the good_job start command. We use environment variables to determine whether to execute that line of code (to distinguish deployment between webapp and worker), and it seems to be working properly because we can see the pid getting created and the process in the good_jobs_processes table. The deploy script looks like this:

if [ "$USE_GOOD_JOB" == "true" ]; then
  echo "Starting GoodJob"
  cd $EB_APP_CURRENT_DIR
  su -s /bin/bash -c "bundle exec good_job start --enable-cron --daemonize --pidfile=/var/pids/good_job.pid" $EB_APP_USER
  GOOD_JOB_PID=`cat /var/pids/good_job.pid`
fi

I'm noticing that when I SSH into the EC2 instance, start the rails console, and call MyJob.perform_now, then it sends the email out as I would expect. However, if I call MyJob.perform_later then it does not. Similarly, if I try to schedule the job using cron, it also does not. This lead me to believe that the process that's running the jobs asynchronously is not reading the environment variables as I would expect.

In the job I'm trying to run, I tried adding some logging to see if it's an environment variable issue, and I am now more perplexed... I basically did the following:

def perform
    logger = Logger.new('log/job.log')
    logger.info "Starting job"
    logger.info "RAILS_ENV: #{ENV['RAILS_ENV']}"
    logger.info "EMAIL_ENV: #{ENV['EMAIL_ENV']}"
    run_job
    logger.info "job complete, sending email"
    send_status_email(true)
  end

When I call MyJob.perform_now, it writes to that log file as I would expect, but when I call MyJob.perform_later, nothing gets written to the log file. But there is a new entry in the good_jobs table for both of those job, and there's no error reported.

So what I thought might be an environment variable issue, now seems to point to the job perhaps not even being run when it's call asynchronously...

[bensheldon]

That makes sense.

Calling .perform_now bypasses the ActiveJob adapter (GoodJob) entirely, so there shouldn't be anything in the good_jobs table if you call .perform_now.

The issue here could simply be that when you call .perform_later (which does hit the adapter/GoodJob) your job is not being executed by GoodJob. Is there a value in the finished_at column of good_jobs? If not, that would imply the job isn't being executed.

Are you setting config.good_job.on_thread_error = -> (exception) { # log the exception or report it } ? That might be another thing to look at.

Also, if might set up the GoodJob Dashboard, which could give you insight into what's happening too.

[dehjli85]

There are values in the finished_at column of the good_jobs table. Let me try adding the on_thread_error got to try and see if anything gets logged there.

When is the error column of the good_jobs table supposed to be populated? I'm getting null values for every entry, so I'm curious when things do get reported there.

I don't have the GoodJob Dashboard set up yet.

I created a separate environment in AWS ElasticBeanstalk, and things seem to be working there (emails getting sent), so I'm starting to suspect this is not an issue with GoodJob, but on our deployment. I'm also able to get logs working now, so working through those see differences between what's happening in our prod environment versus this staging environment I created.