Date.today not corresponding to the actual date

Question

I noticed a very strange issue in my logs with regards to the current time when using Date.today method. Basically, I have a cron job (using clockwork) that runs every night at 00:00, to check which subscriptions are due, so that it tries to automatically renew them. The job executes a method which in turn executes a query, as follows:

where("date(active_until) <= ?", Date.today)

Most times this executes correctly. However, from my log observations, it seems that there are times when Date.today does not correspond to the actual date. Pulled from my logs:

Note: The dates are in the future because I was manually setting the time to test whether this executes correctly.

D, [2016-05-01T00:00:00.015901 #21699] DEBUG -- :   Subscription Load (2.6ms)  SELECT "subscriptions".* FROM "subscriptions" WHERE date(active_until) <= '2016-04-30'

D, [2016-05-02T00:00:00.011130 #21721] DEBUG -- :   Subscription Load (2.2ms)  SELECT "subscriptions".* FROM "subscriptions" WHERE date(active_until) <= '2016-05-02'

If you look at the first case, you will see that the statement was executed at 2016-05-01T00:00:00.015901, while Date.today produced 2016-04-30. The second case is obviously correct since the log date corresponds to the Date.today.

The biggest issue is that I am not able to reproduce it. The only thing I see from my logs is that it has happened 3 out of 24 times. What could be the issues here? Is it possible that Rails is somehow caching the input parameters to the query?

My Ruby version is: ruby 2.2.1p85 (2015-02-26 revision 49769) [x86_64-linux]

My Rails version is: 4.2.1

Answer 1

Make sure in your config/application.rb file that your timee zone is set to the actual time zone you are testing in:

For PST we use:

config.time_zone = 'Pacific Time (US & Canada)'

To get a list of timezone strings useable by rails run this command:

rake time:zones:all

You can also give it a more specific locale. For USA:

rake time:zones:us

Answer 2

As this happens around midnight I believe it is a timing issue where the log file is updated slightly after the script that generates the entry has been executed. Might be load related as the logging facility is separate from the script sending the log entry.