What’s more fun than bugs? Bugs involving time! And none are so fascinating as bugs involving daylight saving time.
With Daylight saving time almost upon us again, I thought it would be fun to revisit this bug my team and I stumbled across last fall.
When subscribing a customer to a monthly plan in our billing system, we calculate the date of the customer’s next bill by adding 30 days to their current time, and using that to create a subscription on Stripe.
However, at some point in October, we started to see this fail:
Stripe::InvalidRequestError: billing_cycle_anchor cannot be later than next natural billing date (1669817382) for plan
When comparing the “natural billing date” to the time we sent the request, it was indeed more than 30 days in the future – by exactly an hour. Curious!
In the code, we were doing something roughly like this to calculate the billing date:
subscription.started_at + 30.days
started_at is a
Time object, and we’re using the
ActiveSupport::Duration helpers to advance that time by exactly 30 days. So what’s the issue?
I fired up a console and started poking at this particular line of code to learn how it behaved.
First, a sanity-check: I want to make sure I know that
.days is giving me what I expect:
$> Time.parse("2022-10-15 12:00:00 -0700") + 1.day => 2022-10-16 12:00:00 -0700 $> Time.parse("2022-10-15 12:00:00 -0700") + (1 * 24 * 60 * 60) => 2022-10-16 12:00:00 -0700
Ok, good! I get the same answer if I add the total number of seconds in a day. Makes sense.
Now, what happens if I do the same thing, but add 30 days?
$> Time.parse("2022-10-15 12:00:00 -0700") + 30.days => 2022-11-14 12:00:00 -0800 $> Time.parse("2022-10-15 12:00:00 -0700") + (30 * 24 * 60 * 60) => 2022-11-14 11:00:00 -0800
Aha! There’s our bug. Depending on whether I use a
Duration object or plain old seconds, I get a different answer. This feels like a daylight saving issue, since we’re crossing the boundary here, and our two times disagree by exactly an hour.
Next, I want to confirm that this has something to do with crossing the daylight saving boundary. Let’s try the same test, but using a time that’s right before the boundary. Daylight saving ended on November 6, 2022 at 2am, so let’s start from 1 second before and add 1 day:
$> Time.parse("2022-11-06 01:59:59 -0700") + 1.day => 2022-11-07 01:59:59 -0800 $> Time.parse("2022-11-06 01:59:59 -0700") + (1 * 24 * 60 * 60) => 2022-11-07 00:59:59 -0800
Still behaves the same. So we can confidently say that when crossing the DST boundary, adding a Duration to a timestamp yields a different time than adding a number of seconds.
So which of the two answers above is correct?
It’s easier to answer that question with a shorter duration, so let’s work with plain seconds:
$> Time.parse("2022-11-06 01:59:59 -0700") + 5 => 2022-11-06 01:00:04 -0800
This makes sense:
Numbers don’t lie, but it seems like
ActiveSupport::Duration may be stretching the truth in this case.
So why does
1.day behave so differently?
In order to explain the bug, we need some context on what happens when we add these two values together. Remember, since everything in Ruby is an object, an operation like
2 + 1 is really invoking the
+ method on
2, and passing
1 as an argument.
ActiveSupport implements methods like
Duration objects so that you can add two of them together:
$> 1.day + 1.day => 2 days
That’s all fine and good when you have two
Duration objects, or at least when a
Duration object is the receiver (on the left-hand side of the operation). But we’ve got a plain ol’ Ruby class on the left:
Time.parse("2022-11-06 01:59:59 -0700") + 1.day
Here, we know the
+ method is being invoked on our
Time object, yet somehow it knows what to do with an
ActiveSupport::Duration. How is that possible? Let’s introspect
+ and see where it takes us:
$> Time.now.method(:+) => #<Method: Time#+(plus_with_duration)(other) /ruby/gems/2.7.0/gems/activesupport-184.108.40.206/lib/active_support/core_ext/time/calculations.rb:261> # active_support/core_ext/time/calculations.rb:261
Hey, look! A monkey patch! 🙈
def plus_with_duration(other) #:nodoc: if ActiveSupport::Duration === other other.since(self) else plus_without_duration(other) end end alias_method :plus_without_duration, :+ alias_method :+, :plus_with_duration
Here, ActiveSupport has hooked into
+ to customize the path taken if the value being added is a
Duration class. Otherwise, we can fall back on the original
This is the point where I break out a debugger like pry to step through the code and see where it takes me. After
#since and following the code path, I end up here:
time_advanced_by_date = change(year: d.year, month: d.month, day: d.day)
Well, that’s interesting. Just looking at that method call, I can see that we’re dropping the hour, minute and second. And since I’m investigating a bug relating to an incorrect hour offset, this really piques my curiosity.
Let’s step down one more level into
#change, which lives in another monkey-patch on the
def change(options) new_year = options.fetch(:year, year) new_month = options.fetch(:month, month) new_day = options.fetch(:day, day) new_hour = options.fetch(:hour, hour) new_min = options.fetch(:min, options[:hour] ? 0 : min) new_sec = options.fetch(:sec, (options[:hour] || options[:min]) ? 0 : sec) new_offset = options.fetch(:offset, nil) ... if new_offset ::Time.new(new_year, new_month, new_day, new_hour, new_min, new_sec, new_offset) elsif utc? ::Time.utc(new_year, new_month, new_day, new_hour, new_min, new_sec) elsif zone ::Time.local(new_year, new_month, new_day, new_hour, new_min, new_sec) else ::Time.new(new_year, new_month, new_day, new_hour, new_min, new_sec, utc_offset) end
change is finally the method which returns a new
Time object based on the results of the operation. Ultimately, we’re calling some variant of
Time.new, providing all-new values for the year, month, etc.
And where do we get all these new values?
new_hour = options.fetch(:hour, hour)
If we didn’t pass it in from the arguments, then we fall back to the existing
sec value on the current
In other words, given our initial
Time object of
Time.parse("2022-11-06 01:59:59 -0700"), we’re going to add
1.day to the date only, then pin
01:59:59 on the end of it.
And there’s our bug!
Ultimately, the workaround on our side was a simple 5-character change: do our math with seconds instead of a
subscription.started_at + 30.days.to_i
I was also curious to see if others had run into it, and sure enough, this bug had been reported a few months prior. It was fixed shortly afterwards in edge Rails, although it does seem like there’s still some discrepancies when doing arithmetic around the DST boundary. My takeaway: when in doubt, stick with plain ol’ seconds.
I always have a hard … ahem, time … wrapping my head around time-related bugs. This one was a fun opportunity to dive in and get to the bottom of a hairy problem.
Thanks for reading!