Movatterモバイル変換


[0]ホーム

URL:


Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly

Sign up
Appearance settings

[RateLimiter] Fix DateInterval normalization#58757

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to ourterms of service andprivacy statement. We’ll occasionally send you account related emails.

Already on GitHub?Sign in to your account

Merged
nicolas-grekas merged 1 commit intosymfony:5.4fromdanydev:rate-limiter-dst-fix
Nov 5, 2024

Conversation

danydev
Copy link
Contributor

@danydevdanydev commentedNov 4, 2024
edited
Loading

QA
Branch?5.4
Bug fix?yes
New feature?no
Deprecations?no
Issuesn.a.
LicenseMIT

This PR fixes a nasty bug (actually 2 different bugs) that caused our API to be unavailable for more than 24 hours. We needed to apply a manual mitigation to resolve the issue (see more below).

Specifically, the PR fixes a bug that causes the wrong calculation of the TTL keys containing the information of the rate limits for afixed window limiter.
By doing so, our API consumers that respected the limit, actually were (wrongly) blocked by the RateLimiter, because the RateLimiter relies on the fact that the keys expire after the window defined by the configuration, so by using a wrong TTL, it ends up to a wrong evaluation of the consumed tokens.
To make it even worse, the TTL is reset at its original value every time a new rate limiter evaluation occurs for that key, so since our clients continued to do the requests (that without the bug would be accepted) the "denial of service" lasted indefinitely until we manually removed all the affected keys in Redis.

Bug 1
Prerequisites:

  • Using as global php timezone one that has DST (in our caseEurope/Rome)
  • Executing code within one hour from the switch CEST->CET or in other words between27 October 2024 2:00AM CEST and27 October 2024 2:59AM CEST (e.g.27 October 2024 2:02AM CEST)
  • Using a fixed window rate limiter
  • Doing the 1st request for a given key (so that the TTL is calculated and set)
  • Using PHP >= 8.1 (read more in the next comment)

Bug 2
Prerequisites:

  • Using as global php timezone one that has DST (in our caseEurope/Rome)
  • Executing code in a CEST time where by adding the rate limiter interval the time goes to CEST, (e.g.27 October 2024 2:50AM CEST using an rate limiter interval of 20 minutes)
  • Using a fixed window rate limiter
  • Doing the 1st request for a given key (so that the TTL is calculated and set)
  • Using PHP >= 8.3 (read more in the next comment)

Those bugs are caused by a php behaviour that it's not optimal nor intuitive, I feel likeBug 1 could be defined as a PHP bug, whileBug 2 is intended behaviour, anyway it's like this, and we need to deal with it at the application level.

@carsonbot
Copy link

Hey!

I see that this is your first PR. That is great! Welcome!

Symfony has acontribution guide which I suggest you to read.

In short:

  • Always add tests
  • Keep backward compatibility (seehttps://symfony.com/bc).
  • Bug fixes must be submitted against the lowest maintained branch where they apply (seehttps://symfony.com/releases)
  • Features and deprecations must be submitted against the 7.2 branch.

Review the GitHub status checks of your pull request and try to solve the reported issues. If some tests are failing, try to see if they are failing because of this change.

When two Symfony core team members approve this change, it will be merged and you will become an official Symfony contributor!
If this PR is merged in a lower version branch, it will be merged up to all maintained branches within a few days.

I am going to sit back now and wait for the reviews.

Cheers!

Carsonbot

@danydev
Copy link
ContributorAuthor

danydev commentedNov 4, 2024
edited
Loading

Let's focus onBug 1 by looking at some code

<?phpdate_default_timezone_set('Europe/Rome');$now = new \DateTimeImmutable();echo 'now: ' . $now->format('Y-m-d H:i:s I') . ' (' . $now->getTimestamp() . ')' . PHP_EOL;$nowInUTC = $now->setTimezone(new \DateTimeZone('UTC'));echo 'now in UTC: ' . $nowInUTC->format('Y-m-d H:i:s'). PHP_EOL;$nowPlusOneMinute = new \DateTimeImmutable('+1 minutes');echo 'now plus 1 minute: ' . $nowPlusOneMinute->format('Y-m-d H:i:s I') . ' (' . $nowPlusOneMinute->getTimestamp() . ')' . PHP_EOL;$nowPlusOneMinuteInUTC = $nowPlusOneMinute->setTimezone(new \DateTimeZone('UTC'));echo 'now plus 1 minute in UTC: ' . $nowPlusOneMinuteInUTC->format('Y-m-d H:i:s') . ' (' . $nowPlusOneMinuteInUTC->getTimestamp() . ')' . PHP_EOL;$interval = $nowPlusOneMinute->diff($now);echo 'interval: ' . $interval->format('%h hours, %i minutes') . PHP_EOL;

So the output of this code executed in any time of the year (except for the interval of time I defined above) is:

// system date: Sat 26 Oct 2024 12:03:25 AM UTCnow: 2024-10-26 02:03:25 1now in UTC: 2024-10-26 00:03:25now plus 1 minute: 2024-10-26 02:04:25 1now plus 1 minute in UTC: 2024-10-26 00:04:25interval: 0 hours, 1 minutes

That's perfectly right, the output above is the expected one and perfectly as expected since$now and$nowPlusOneMinute are actually separated just by one minute.

Now let's see the same exact code executed when the time is between27 October 2024 2:00AM CEST and27 October 2024 2:59AM CEST, to do it, I move the system datetime to ~27 Oct 2:14AM CEST Europe/Rome

php 5.6Sun 27 Oct 2024 12:14:43 AM UTCnow: 2024-10-27 02:14:43 0 (1729991683)now in UTC: 2024-10-27 01:14:43now plus 1 minute: 2024-10-27 02:15:43 0 (1729991743)now plus 1 minute in UTC: 2024-10-27 01:15:43 (1729991743)interval: 0 hours, 1 minutesphp 7.4Sun 27 Oct 2024 12:14:43 AM UTCnow: 2024-10-27 02:14:44 0 (1729991684)now in UTC: 2024-10-27 01:14:44now plus 1 minute: 2024-10-27 02:15:44 0 (1729991744)now plus 1 minute in UTC: 2024-10-27 01:15:44 (1729991744)interval: 0 hours, 1 minutesphp 8.0Sun 27 Oct 2024 12:14:44 AM UTCnow: 2024-10-27 02:14:44 0 (1729991684)now in UTC: 2024-10-27 01:14:44now plus 1 minute: 2024-10-27 02:15:44 0 (1729991744)now plus 1 minute in UTC: 2024-10-27 01:15:44 (1729991744)interval: 0 hours, 1 minutesphp 8.1Sun 27 Oct 2024 12:14:44 AM UTCnow: 2024-10-27 02:14:44 1 (1729988084)now in UTC: 2024-10-27 00:14:44now plus 1 minute: 2024-10-27 02:15:44 0 (1729991744)now plus 1 minute in UTC: 2024-10-27 01:15:44 (1729991744)interval: 1 hours, 1 minutesphp 8.3Sun 27 Oct 2024 12:14:44 AM UTCnow: 2024-10-27 02:14:44 1 (1729988084)now in UTC: 2024-10-27 00:14:44now plus 1 minute: 2024-10-27 02:15:44 0 (1729991744)now plus 1 minute in UTC: 2024-10-27 01:15:44 (1729991744)interval: 1 hours, 1 minutes

A new notes to better grasp the problem:

  • As you see, the behaviour changes in different php versions 😓
  • You may think "well, it's just like the other one,$now and$nowPlusOneMinute diff by 1 minute", not really, they don't diff by one minute, if you print their difference, is 1 hour and 1 minute in PHP >= 8.1.
  • Look atnow plus 1 minute in UTC, it's "one hour and one minute" afternow in UTC. While the expectation is just one minute. This because php when using the modifier in the constructor doesn't pick the "current datetime", it picks the non-DST datetime (aka CET).
  • I laso printed the output ofdate before each script execution to reflect the OS date that I set to reproduce the bug
  • I formatted the date using theI letter, so you can observe where the problem is. TheI shows a 1 if the datetime is DST (aka CEST) and shows a 0 if it isn't. When executing$nowPlusOneMinute = new \DateTimeImmutable('+1 minute'); at 2:01AM CEST he decided to use as "base", not the real current time (the 2:01AM CEST), but the 2:01AM CET that is one hour after the current datetime. Indeed the "0" in the "now plus 1 minute" shows that PHP picked the non-DST time (aka CET) even though the real current datetime is DST (aka CEST).
  • I formatted the date both in Europe/Rome timezone (the one globally set by default) and also in UTC, the latter is just a way to make it easier to see where is the problem, since by looking at the datetime formatted as Europe/Rome makes harder to see the problem (in this case you need to look the "I" to see the problem, as explained in the previous point).

At this point, I hope you understand what's going on, let's see it the implication with the RateLimiter

For sake of simplicity let's say you have a RateLimiter configured like

policy: 'fixed_window'limit: 30interval: '1 minute'cache_pool: rate_limiter.cache

So the main thing here is that interval is "1 minute".

This is the original RateLimiter code pre-fix

return (new \DateTimeImmutable())->diff(new \DateTimeImmutable('+'.$interval));

If executed when the bug occurs (in the date interval I defined above) the first date would be the "real" current time, at which wediff the bugged date (that's "off by one hour" plus one minute)
If we print theDateInterval produced, like this:echo 'hours ' . $interval->h . ' min ' . $interval->i; we'll have as output:hours: 1 min 1 that's unexpected, it should have been just 1 minute.

Now this is going to be used as TTL of the Redis key, (seeWindow::getExpirationTime) and it's going to contain "1 hour" so even after 2 minutes where no-one is going to make requests, the RateLimiter could not help himself but checking against the data that is still there due to the wrong TTL, considering the tokens already consumed, and wrongly preventing the use of the resource protected by the rate limiter.

@danydev
Copy link
ContributorAuthor

danydev commentedNov 4, 2024
edited
Loading

Now let's focus onBug 2 by looking at some other code

<?phpdate_default_timezone_set('Europe/Rome');$now = new \DateTimeImmutable();echo 'now: ' . $now->format('Y-m-d H:i:s I') . ' (' . $now->getTimestamp() . ')' . PHP_EOL;$nowInUTC = $now->setTimezone(new \DateTimeZone('UTC'));echo 'now in UTC: ' . $nowInUTC->format('Y-m-d H:i:s'). PHP_EOL;$nowPlus65Minutes = new \DateTimeImmutable('+65 minutes');echo 'now plus 65 minutes: ' . $nowPlus65Minutes->format('Y-m-d H:i:s I') . ' (' . $nowPlus65Minutes->getTimestamp() . ')' . PHP_EOL;$nowPlus65MinutesInUTC = $nowPlus65Minutes->setTimezone(new \DateTimeZone('UTC'));echo 'now plus 65 minutes in UTC: ' . $nowPlus65MinutesInUTC->format('Y-m-d H:i:s') . ' (' . $nowPlus65MinutesInUTC->getTimestamp() . ')' . PHP_EOL;$interval = $nowPlus65Minutes->diff($now);echo 'interval: ' . $interval->format('%h hours, %i minutes') . PHP_EOL;

So the output of this code executed in any time of the year (except for the interval of time I defined above) is:

Sat 26 Oct 2024 12:29:26 AM UTCnow: 2024-10-26 02:29:26 1 (1729902566)now in UTC: 2024-10-26 00:29:26now plus 65 minutes: 2024-10-26 03:34:26 1 (1729906466)now plus 65 minutes in UTC: 2024-10-26 01:34:26 (1729906466)interval: 1 hours, 5 minutes

That's perfectly right, the output above is the expected one and perfectly as expected since$now and$nowPlus65MinutesInUTC are actually separated just by 65 minutes.

Now let's see the same exact code executed when the time is ~27 Oct 2:01AM CEST Europe/Rome, and interval is 65 minutes (so current time + interval > time when DST change)

php 5.6Sun 27 Oct 2024 12:01:05 AM UTCnow: 2024-10-27 02:01:05 0 (1729990865)now in UTC: 2024-10-27 01:01:05now plus 65 minutes: 2024-10-27 03:06:05 0 (1729994765)now plus 65 minutes in UTC: 2024-10-27 02:06:05 (1729994765)interval: 1 hours, 5 minutesphp 7.4Sun 27 Oct 2024 12:01:05 AM UTCnow: 2024-10-27 02:01:05 0 (1729990865)now in UTC: 2024-10-27 01:01:05now plus 65 minutes: 2024-10-27 03:06:05 0 (1729994765)now plus 65 minutes in UTC: 2024-10-27 02:06:05 (1729994765)interval: 1 hours, 5 minutesphp 8.0Sun 27 Oct 2024 12:01:05 AM UTCnow: 2024-10-27 02:01:05 0 (1729990865)now in UTC: 2024-10-27 01:01:05now plus 65 minutes: 2024-10-27 03:06:05 0 (1729994765)now plus 65 minutes in UTC: 2024-10-27 02:06:05 (1729994765)interval: 1 hours, 5 minutesphp 8.1Sun 27 Oct 2024 12:01:05 AM UTCnow: 2024-10-27 02:01:05 1 (1729987265)now in UTC: 2024-10-27 00:01:05now plus 65 minutes: 2024-10-27 03:06:05 0 (1729994765)now plus 65 minutes in UTC: 2024-10-27 02:06:05 (1729994765)interval: 1 hours, 5 minutesphp 8.3Sun 27 Oct 2024 12:01:05 AM UTCnow: 2024-10-27 02:01:05 1 (1729987265)now in UTC: 2024-10-27 00:01:05now plus 65 minutes: 2024-10-27 03:06:05 0 (1729994765)now plus 65 minutes in UTC: 2024-10-27 02:06:05 (1729994765)interval: 2 hours, 5 minutes

A new notes to better grasp the problem:

  • As you see, the behaviour changes in different php versions 😓
  • Look atnow plus 65 minutes in UTC, it's "two hours and five minutes" afternow in UTC in PHP 8.3. While the expectation is just "1 hour and 5 minutes". This because php when using the modifier in the constructor doesn't pick the "current datetime", it picks the non-DST datetime (aka CET).
  • I laso printed the output ofdate before each script execution to reflect the OS date that I set to reproduce the bug
  • I formatted the date both in Europe/Rome timezone (the one globally set by default) and also in UTC, the latter is just a way to make it easier to see where is the problem, since by looking at the datetime formatted as Europe/Rome makes harder to see the problem

@danydev
Copy link
ContributorAuthor

danydev commentedNov 4, 2024
edited
Loading

This comment analyzes the bugfix for 2 cases above.

Reference code that uses the same approach of the currently pushed fix.

<?phpdate_default_timezone_set('Europe/Rome');$now = new \DateTimeImmutable('now', new \DateTimeZone('UTC'));echo 'now: ' . $now->format('Y-m-d H:i:s I') . ' (' . $now->getTimestamp() . ')' . PHP_EOL;$nowPlusOneMinute = $now->modify('+1 minute');echo 'now plus 1 minute: ' . $nowPlusOneMinute->format('Y-m-d H:i:s I') . ' (' . $nowPlusOneMinute->getTimestamp() . ')' . PHP_EOL;$interval = $nowPlusOneMinute->diff($now);echo 'interval: ' . $interval->format('%h hours, %i minutes') . PHP_EOL;

output when executing 27 Oct 2024 2:10:02AM DST (so theBug 1 explained above)

php 5.6Sun 27 Oct 2024 12:10:02 AM UTCnow: 2024-10-27 00:10:02 0 (1729987802)now plus 1 minute: 2024-10-27 00:11:02 0 (1729987862)interval: 0 hours, 1 minutesphp 7.4Sun 27 Oct 2024 12:10:02 AM UTCnow: 2024-10-27 00:10:02 0 (1729987802)now plus 1 minute: 2024-10-27 00:11:02 0 (1729987862)interval: 0 hours, 1 minutesphp 8.0Sun 27 Oct 2024 12:10:02 AM UTCnow: 2024-10-27 00:10:02 0 (1729987802)now plus 1 minute: 2024-10-27 00:11:02 0 (1729987862)interval: 0 hours, 1 minutesphp 8.1Sun 27 Oct 2024 12:10:02 AM UTCnow: 2024-10-27 00:10:02 0 (1729987802)now plus 1 minute: 2024-10-27 00:11:02 0 (1729987862)interval: 0 hours, 1 minutesphp 8.3Sun 27 Oct 2024 12:10:03 AM UTCnow: 2024-10-27 00:10:03 0 (1729987803)now plus 1 minute: 2024-10-27 00:11:03 0 (1729987863)interval: 0 hours, 1 minutes

Comment: all good, all intervals are created correctly and diff by 1 minute in all php versions

Now let's verifyBug 2
Reference code that uses the same approach of the currently pushed fix.

<?phpdate_default_timezone_set('Europe/Rome');$now = new \DateTimeImmutable('now', new \DateTimeZone('UTC'));echo 'now: ' . $now->format('Y-m-d H:i:s I') . ' (' . $now->getTimestamp() . ')' . PHP_EOL;$nowPlus65Minutes = $now->modify('+65 minutes');echo 'now plus 65 minutes: ' . $nowPlus65Minutes->format('Y-m-d H:i:s I') . ' (' . $nowPlus65Minutes->getTimestamp() . ')' . PHP_EOL;$interval = $nowPlus65Minutes->diff($now);echo 'interval: ' . $interval->format('%h hours, %i minutes') . PHP_EOL;

output when executing 27 Oct 2024 2:12:15AM DST + using interval of 65 minutes that summed up to current time goes to > time when DST changes (so theBug 2 explained above)

php 5.6Sun 27 Oct 2024 12:12:15 AM UTCnow: 2024-10-27 00:12:16 0 (1729987936)now plus 65 minutes: 2024-10-27 01:17:16 0 (1729991836)interval: 1 hours, 5 minutesphp 7.4Sun 27 Oct 2024 12:12:16 AM UTCnow: 2024-10-27 00:12:16 0 (1729987936)now plus 65 minutes: 2024-10-27 01:17:16 0 (1729991836)interval: 1 hours, 5 minutesphp 8.0Sun 27 Oct 2024 12:12:16 AM UTCnow: 2024-10-27 00:12:16 0 (1729987936)now plus 65 minutes: 2024-10-27 01:17:16 0 (1729991836)interval: 1 hours, 5 minutesphp 8.1Sun 27 Oct 2024 12:12:16 AM UTCnow: 2024-10-27 00:12:16 0 (1729987936)now plus 65 minutes: 2024-10-27 01:17:16 0 (1729991836)interval: 1 hours, 5 minutesphp 8.3Sun 27 Oct 2024 12:12:16 AM UTCnow: 2024-10-27 00:12:16 0 (1729987936)now plus 65 minutes: 2024-10-27 01:17:16 0 (1729991836)interval: 1 hours, 5 minutes

Comment: all good, all intervals are created correctly and diff by 65 minutes in all php versions.

Copy link
Member

@nicolas-grekasnicolas-grekas left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others.Learn more.

Thanks for the detailed explanations.
Can this be tested?

@danydev
Copy link
ContributorAuthor

I explored several ways to try to create a unit test, but since the current datetime is not easily mockable, I couldn't find a way to create a test that fails on master and passes on this branch.

I could create a unit test that verifies that the expected TTL is created accordingly to the defined rate limiter interval, but that wouldn't validate specifically my case, it would pass on master as well.

@danydevdanydevforce-pushed therate-limiter-dst-fix branch 4 times, most recently from56514ac to2b0537cCompareNovember 5, 2024 11:49
@danydev
Copy link
ContributorAuthor

danydev commentedNov 5, 2024
edited
Loading

Thank you for your suggestions, I just did a followup with the unit test fixing the date when the bug occurs.

I think we should be okay now, the funny thing is that by changing the fix to be able to mock it, the bug was still there until I modified also the other point where we create the$now.
I think that's good, since actually it's better to create $now the same way, since we're going to compare them somehow

@@ -69,7 +69,11 @@ protected static function configureOptions(OptionsResolver $options): void
{
$intervalNormalizer = static function (Options $options, string $interval): \DateInterval {
try {
return (new \DateTimeImmutable())->diff(new \DateTimeImmutable('+'.$interval));
// Force UTC timezone, because we don't want to deal with quirks happening when modifying dates in case
// there is a default timezone with DST. Read more here https://github.com/symfony/symfony/pull/58757

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others.Learn more.

ah sorry I missed this one - we don't put references to github in the codebase - instead we put PR discussion in git notes (and git blame can help also)

Suggested change
// there is a default timezone with DST. Read more here https://github.com/symfony/symfony/pull/58757
// there is a default timezone with DST.

@danydevdanydevforce-pushed therate-limiter-dst-fix branch 2 times, most recently fromc842016 to9a52e7eCompareNovember 5, 2024 12:51
@danydev
Copy link
ContributorAuthor

danydev commentedNov 5, 2024
edited
Loading

@nicolas-grekas I'm bothering you just one last time.

After looking at thephp doc, I noticed the note

The timezone parameter and the current timezone are ignored when the datetime parameter either contains a UNIX timestamp (e.g. 946684800) or specifies a timezone (e.g. 2010-01-28T15:00:00+02:00).

So I think that's just "better" to not specify the timezone, since actually it's superfluous, in case of timestamps, PHP uses by default UTC.

If you agree, could you re-approve? Thank you

@nicolas-grekas
Copy link
Member

Thank you@danydev.

@nicolas-grekasnicolas-grekas merged commitd2ba257 intosymfony:5.4Nov 5, 2024
11 of 12 checks passed
Sign up for freeto join this conversation on GitHub. Already have an account?Sign in to comment
Reviewers

@nicolas-grekasnicolas-grekasnicolas-grekas approved these changes

Assignees
No one assigned
Projects
None yet
Milestone
5.4
Development

Successfully merging this pull request may close these issues.

3 participants
@danydev@carsonbot@nicolas-grekas

[8]ページ先頭

©2009-2025 Movatter.jp