Skip to content
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 our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Display correct elapsed time with Roadrunner #865

Merged
merged 3 commits into from
Mar 27, 2024

Conversation

Joel-Jensen
Copy link
Contributor

@Joel-Jensen Joel-Jensen commented Mar 26, 2024

Problem

After the latest release of Roadrunner v2023.3.12 all the timestamps are in ms without any unit.

All since log entries are now always shown as milliseconds

This makes the current timestamps 1000 times too big.

See debug statement below
image

Solution

I propose to just remove the calculation function. I'm not sure however how you handle backwards compatibility or you just want to bump the min-version?

Environment

Fresh install with:
Laravel: v11.0.7
Octane: v2.3.5
Roadrunner: v2023.3.12

@taylorotwell
Copy link
Member

Is there a way to do this gracefully so older versions don't now display the incorrect time?

@Joel-Jensen
Copy link
Contributor Author

Joel-Jensen commented Mar 26, 2024

I'm afraid I don't have any good suggestions for that right now. This is the output from v2023.3.11 (on main without these changes).
image

  1. Going by $elapsed < 1.0 seems like a dangerous pattern to go by.
  2. We could ask the binary what version it's running ./rr -v, although we have to parse that version which also seems a bit messy? Could however be used in future similar breaking changes, if that's not changed too.
    rr version 2023.3.11 (build time: 2024-02-15T19:52:34+0000, go1.22.0), OS: darwin, arch: arm64
  3. Alternatively, also in need of parsing, is to read one of the startup messages from the process
    [INFO] RoadRunner server started; version: 2023.3.11, buildtime: 2024-02-15T19:52:34+0000

Sorry, don't have any better ideas right now. New to both Roadrunner and Octane.

@Joel-Jensen
Copy link
Contributor Author

@taylorotwell Found it, don't know how I missed it yesterday...

< v2023.3.12 returns a float while v2023.3.12 have hardcoded everything to int64. Let's just check that instead.

I would typically go with ctype_digit($elapsed) but I saw in laravel/framework that you use filter_var($elapsed, FILTER_VALIDATE_INT) !== false, so went that way.

Some tests

Normal request
v2023.3.12

$elapsed 92
200    GET / .................................................. 92.00 ms

v2023.3.11

$elapsed 0.120976917
200    GET / .................................................. 120.98 ms

v2023.3.0

$elapsed 0.102209208
200    GET / .................................................. 102.21 ms

Request with 1s delay
v2023.3.12

$elapsed 1170
200    GET / .................................................. 1170.00 ms

v2023.3.11

$elapsed 1.099059292
200    GET / .................................................. 1099.06 ms

v2023.3.0

$elapsed 1.105720083
200    GET / .................................................. 1105.72 ms

@taylorotwell taylorotwell merged commit a2436fd into laravel:2.x Mar 27, 2024
12 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants