Display correct elapsed time with Roadrunner

Joel-Jensen commented 4 months ago

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

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 commented 4 months ago

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

Joel-Jensen commented 4 months ago

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).

Going by $elapsed < 1.0 seems like a dangerous pattern to go by.
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
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 commented 4 months ago

@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

laravel / octane