Shopify Question posted in
The Shopify help center can be found here.

Running rake tasks from crontab – Shopify

I have run into a problem that I can’t imagine a solution for, and has had me stuck for a week. I have the following two lines in sudo crontab -e.

* * * * * echo "crontab can log to reports" >> /var/log/mazer-reports.log
* * * * * /bin/bash -l -c 'cd /home/deploy/shopify_pull_and_store && /home/deploy/.rbenv/shims/bundle exec rake run_split_accounting_after_close_master >> /var/log/mazer-reports.log'

Here is what my ‘mazer-reports.log’ looks like after 10 or so minutes:

crontab can log to reports
crontab can log to reports
crontab can log to reports
crontab can log to reports
crontab can log to reports
crontab can log to reports
crontab can log to reports
crontab can log to reports
crontab can log to reports
crontab can log to reports
crontab can log to reports

So, the first command is triggering, and logging fine. However, the second command is neither logging, nor triggering the appropriate rake task (the effects of the task are not seen in my Rails app). Furthermore, I know there is nothing wrong with the command, because if I just take the command itself and run it in my console:

/bin/bash -l -c 'cd /home/deploy/shopify_pull_and_store && /home/deploy/.rbenv/shims/bundle exec rake run_split_accounting_after_close_master >> /var/log/mazer-reports.log'

Then I get the following appended to my ‘mazer-reports.log’, which is correct:

   (0.8ms)  SELECT MAX("delayed_jobs"."priority") FROM "delayed_jobs" WHERE "delayed_jobs"."queue" = $1  [["queue", "RunReports"]]
   [ActiveJob]    (0.1ms)  BEGIN
   [ActiveJob]   SQL (0.4ms)  INSERT INTO "delayed_jobs" ("handler", "run_at", "queue", "created_at", "updated_at") VALUES ($1, $2, $3, $4, $5) RETURNING "id"  
   [["handler", "--- !ruby/object:ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrappernjob_data:n  job_class: RunReportsSplitMasterJobn  job_id: 79333d26-4917-4226-8d86-8fef481c86d0n  provider_job_id: n  queue_name: RunReportsn  priority: n  arguments: []n  executions: 0n  locale: enn"], ["run_at", "2019-01-04 22:06:35.189280"], ["queue", "RunReports"], ["created_at", "2019-01-04 22:06:35.189369"], ["updated_at", "2019-01-04 22:06:35.189369"]]
   [ActiveJob]    (0.5ms)  COMMIT
   [ActiveJob] Enqueued RunReportsSplitMasterJob (Job ID: 79333d26-4917-4226-8d86-8fef481c86d0) to DelayedJob(RunReports)

And also I can see the effects of the task being triggered on my rails application, where I couldn’t see it from crontab, so this can’t just be a logging problem. crontab doesn’t like the command at all. Here is the output of sudo grep CRON /var/log/syslog:

Jan  4 22:12:01 shopify-inventory-reports CRON[24417]: (root) CMD (echo "crontab can log to reports" >> /var/log/mazer-reports.log)
Jan  4 22:12:03 shopify-inventory-reports CRON[24415]: (CRON) info (No MTA installed, discarding output)
Jan  4 22:13:01 shopify-inventory-reports CRON[24453]: (root) CMD (/bin/bash -l -c 'cd /home/deploy/shopify_pull_and_store && /home/deploy/.rbenv/shims/bundle exec rake run_split_accounting_after_close_master >> /var/log/mazer-reports.log')
Jan  4 22:13:01 shopify-inventory-reports CRON[24454]: (root) CMD (echo "crontab can log to reports" >> /var/log/mazer-reports.log)
Jan  4 22:13:03 shopify-inventory-reports CRON[24452]: (CRON) info (No MTA installed, discarding output)
Jan  4 22:14:01 shopify-inventory-reports CRON[24490]: (root) CMD (/bin/bash -l -c 'cd /home/deploy/shopify_pull_and_store && /home/deploy/.rbenv/shims/bundle exec rake run_split_accounting_after_close_master >> /var/log/mazer-reports.log')
Jan  4 22:14:01 shopify-inventory-reports CRON[24491]: (root) CMD (echo "crontab can log to reports" >> /var/log/mazer-reports.log)
Jan  4 22:14:04 shopify-inventory-reports CRON[24489]: (CRON) info (No MTA installed, discarding output)
Jan  4 22:15:01 shopify-inventory-reports CRON[24528]: (root) CMD (/bin/bash -l -c 'cd /home/deploy/shopify_pull_and_store && /home/deploy/.rbenv/shims/bundle exec rake run_split_accounting_after_close_master >> /var/log/mazer-reports.log')

You can see from there that cron is running both commands every minute (as it should), and is not posting an error to syslog on the command which appears to be doing nothing. Quite confusing!

I am running rails 5, puma, and rbenv on an Ubuntu 18 install. All of those things are installed on a sudoer user called deploy. Below is the output of ls -l /var/log/mazer-reports.log:

-rw-rw-rw- 1 root root 1543 Jan  4 22:10 mazer-reports.log

Update 1/6/2018: Romeo Ninov pointed out in a comment that I should consider the environmental variable in shell vs cronjob. Sure enough, the output of * * * * * /bin/bash -l -c 'echo $RAILS_ENV' >> /var/log/mazer-reports.log is blank, meaning rake wouldn’t know which rails environment to run in from crontab, when it needs to be production. To try and solve this, I put the environmental variable in the command itself in crontab like so:

 0 * * * * cd /home/deploy/shopify_pull_and_store && /home/deploy/.rbenv/shims/bundle exec rake RAILS_ENV=production run_split_accounting_after_close_master >> /var/log/mazer-reports.log`

However, this is still not fixing the problem. Command is still not firing, nor logging to the specified log file. Some other necessary rake environmental variable I am not thinking about? Systemd is already running puma with the application secret and database user and password. I never thought that rake would need such a thing, but tell me if I am wrong

Update 1/7/2018:
Ok, so clearly this is an environmental variable problem. I have created a seperate bash file called “run_accounting” as described in Romeo’s answer like so:

#!/bin/bash
source ~/.bashrc
echo "stuff from run_accounting bash" >> /var/log/mazer-reports.log
env >> /var/log/mazer-reports.log
cd /home/deploy/shopify_pull_and_store && /home/deploy/.rbenv/shims/bundle exec rake run_split_accounting_after_close_master >> /var/log/mazer-reports.log

Now, here is what is strange, if I hit sudo ./run_accounting from the terminal, the rake task triggers, and I get the following output in my mazer-reports.log:

stuff from run_accounting bash
SHELL=/bin/bash
TERM=xterm-256color
USER=root
SUDO_USER=deploy
SUDO_UID=1000
USERNAME=root
RACK_ENV=production
MAIL=/var/mail/root
PATH=/home/deploy/.rbenv/shims:/home/deploy/.rbenv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin
SECRET_KEY_BASE=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
PWD=/home/deploy
LANG=en_US.UTF-8
RBENV_SHELL=bash
SHLVL=1
SUDO_COMMAND=./run_accounting
HOME=/home/deploy
RAILS_ENV=production
LOGNAME=root
SHOPIFY_PULL_AND_STORE_DATABASE_USER=shopify_pull_and_store
LESSOPEN=| /usr/bin/lesspipe %s
SHOPIFY_PULL_AND_STORE_DATABASE_PASSWORD=XXXXXXXX
SUDO_GID=1000
LESSCLOSE=/usr/bin/lesspipe %s %s
_=/usr/bin/env
(0.6ms)  SELECT MAX("delayed_jobs"."priority") FROM "delayed_jobs" WHERE "delayed_jobs"."queue" = $1  [["queue", "RunReports"]]
[ActiveJob]    (0.1ms)  BEGIN
[ActiveJob]   SQL (0.9ms)  INSERT INTO "delayed_jobs" ("handler", "run_at", "queue", "created_at", "updated_at") VALUES ($1, $2, $3, $4, $5) RETURNING "id"  
[["handler", "--- !ruby/object:ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrappernjob_data:n  job_class: RunReportsSplitMasterJobn  job_id: 7dfd28bd-a47c-475d-9ccf-5a5d8ef756e7n  provider_job_id: n  queue_name: RunReportsn  priority: n  arguments: []n  executions: 0n  locale: enn"], ["run_at", "2019-01-07 18:02:57.355453"], ["queue", "RunReports"], ["created_at", "2019-01-07 18:02:57.355521"], ["updated_at", "2019-01-07 18:02:57.355521"]]
[ActiveJob]    (0.6ms)  COMMIT
[ActiveJob] Enqueued RunReportsSplitMasterJob (Job ID: 7dfd28bd-a47c-475d-9ccf-5a5d8ef756e7) to DelayedJob(RunReports)

BUT, with * * * * * /home/deploy/run_accounting in my crontab, the task doesn’t trigger, and I can see that the environmental variables needed were not loaded as seen below:

stuff from run_accounting bash
SHELL=/bin/sh
PATH=/usr/bin:/bin
PWD=/root
LANG=en_US.UTF-8
SHLVL=1
HOME=/root
LOGNAME=root
_=/usr/bin/env

Why does the bashrc source when running that bash script from the terminal, but not when running the same command from crontab?

Tags:

2

Answers


  1. 0

    Based on your comments seems like you need environment variables to be set. I will recommend next approach: create shell script which will include your command and source your .bashrc file:

    #!/bin/bash
. /home/deploy/.bashrc
# can be also
# . /home/deploy/.bash_profile
cd /home/deploy/shopify_pull_and_store && /home/deploy/.rbenv/shims/bundle exec rake run_split_accounting_after_close_master >> /var/log/mazer-reports.log

    You can try also instead of .bashrc to source .bash_profile

    And run this shell script in cron. Do not forget to make this script executable.

    P.S. Maybe you need to add also /home/deploy/.bash_profile
    In general is wise to add those files from the home folder of the user (root in this case). Please check in /etc/passwd where is the home of user root

    Login or Signup to reply.
  2. 0

    You could try to declare the environment variable before the bundle exec and use your project bin/bundle:

     0 * * * * cd /home/deploy/shopify_pull_and_store && RAILS_ENV=production bin/bundle exec rake run_split_accounting_after_close_master >> /var/log/mazer-reports.log

    Update 2019-01-07

    Try setting the route to your .bashrc like this:

    #!/bin/bash
source /home/deploy/.bashrc
echo "stuff from run_accounting bash" >> /var/log/mazer-reports.log
env >> /var/log/mazer-reports.log
cd /home/deploy/shopify_pull_and_store && /home/deploy/.rbenv/shims/bundle exec rake run_split_accounting_after_close_master >> /var/log/mazer-reports.log

    or like this:

    source ~deploy/.bashrc
    Login or Signup to reply.
Please signup or login to give your own answer.

Back To Top
Search