Add support for microseconds in Stopwatch #23223

javiereguiluz · 2017-06-19T09:46:12Z

Q	A
Branch?	3.4
Bug fix?	no
New feature?	yes
BC breaks?	no?
Deprecations?	no
Tests pass?	yes
Fixed tickets	#18756
License	MIT
Doc PR	-

Stopwatch component already supports microseconds (and nanoseconds, etc.) ... but the problem is that it converts the millisecond times to integers, so anything smaller to 1 millisecond is lost. This PR changes that to fix issues like the one explained in #18756.

Before

After

keradus · 2017-06-19T09:55:26Z

src/Symfony/Component/Stopwatch/StopwatchPeriod.php

        $this->memory = memory_get_usage(true);
    }

    /**
     * Gets the relative time of the start of the period.
     *
-     * @return int The time (in milliseconds)
+     * @return float The time (in milliseconds)
     */
    public function getStartTime()


changing output of this is BC breaker, and for one that like to write in new php in strict mode, it will crash his software.

<?php declare(strict_types=1); function NON_STRICTLY_TYPEHINTED_SYMFONY_METHOD___getStartTime_org() { return 123; } function NON_STRICTLY_TYPEHINTED_SYMFONY_METHOD___getStartTime_new() { return 123.456; } function USER_FUNCTION_THAT_CONSUMES_SYMFONY_OUTPUT(int $a) { echo $a; } USER_FUNCTION_THAT_CONSUMES_SYMFONY_OUTPUT(NON_STRICTLY_TYPEHINTED_SYMFONY_METHOD___getStartTime_org()); // OK USER_FUNCTION_THAT_CONSUMES_SYMFONY_OUTPUT(NON_STRICTLY_TYPEHINTED_SYMFONY_METHOD___getStartTime_new()); // Fatal error: Uncaught TypeError: Argument 1 passed to USER_FUNCTION_THAT_CONSUMES_SYMFONY_OUTPUT() must be of the type integer, float given

keradus · 2017-06-19T09:56:50Z

while i do really like the idea, it's bc breaker, as proven

javiereguiluz · 2017-06-19T09:57:55Z

@keradus it's a BC break ... that's why I submitted to 3.4 branch ... should I submit it instead to 4.0?

keradus · 2017-06-19T10:32:59Z

3.4 is for features, not bc breakers, isn't it ?
i would go either with clean solution for 4.0, or future-compat layer on 3.4

keradus · 2017-06-19T10:33:42Z

BC breaks? no?

vs

it's a BC break ... that's why ....

fabpot · 2017-06-19T13:48:42Z

We cannot break BC in 4.0 without a migration path from 3.4. So target master would not change anything. What we need to do instead is to add an argument to those methods to get the value as a float and return a casted int if not.

keradus · 2017-06-19T13:51:15Z

that's why I requested future-compat layer :)

SenseException · 2017-06-19T10:55:19Z

src/Symfony/Component/Stopwatch/StopwatchPeriod.php

-        $this->start = (int) $start;
-        $this->end = (int) $end;
+        $this->start = $start;
+        $this->end = $end;


Next to the previous mentioned BC break in the issue, no type cast will also be error prone.

javiereguiluz · 2017-06-19T15:47:55Z

I've made some changes. Please tell me if I'm going in the right direction. Thanks!

ogizanagi · 2017-06-19T18:27:25Z

src/Symfony/Component/Stopwatch/StopwatchPeriod.php

     */
-    public function __construct($start, $end)
+    public function __construct($start, $end /*, $useMicroPrecision = false*/)


No need to keep this commented, as it's still optional since you're adding a default value. So it won't break BC. (However you could add the bool typehint commented for 4.0)

Indeed, especially for a constructor method.

fabpot · 2017-06-19T18:53:51Z

LGTM but as is, it does not really help as the profiling still won't get the more precise time, right?

javiereguiluz · 2017-06-19T18:57:03Z

Not sure if this is what was asked for in #18756 ... but the screenshots in the PR are real: now we see details for < 0ms events.

fabpot · 2017-06-19T19:04:29Z

How does it work? Where are you passing true to get sub-millisecond precision? Default is false.

keradus · 2017-06-19T19:13:23Z

src/Symfony/Component/Stopwatch/StopwatchPeriod.php

-        }
-
+        $this->start = $morePrecision ? $start : (int) $start;
+        $this->end = $morePrecision ? $end : (int) $end;


do we care about detecting invalid inputs, eg arrays ?

javiereguiluz · 2017-06-19T19:32:10Z

@fabpot I understand your comment now. I had forgotten to commit the change that enables more precision 😊

ogizanagi · 2017-06-19T20:05:44Z

src/Symfony/Component/Stopwatch/StopwatchEvent.php

@@ -177,7 +177,7 @@ public function getDuration()

        for ($i = 0; $i < $left; ++$i) {
            $index = $stopped + $i;
-            $periods[] = new StopwatchPeriod($this->started[$index], $this->getNow());
+            $periods[] = new StopwatchPeriod($this->started[$index], $this->getNow(), true);


This also makes the StopwatchEvent::getStartTime(), ::getEndTime() and ::getDuration() return int|float, right?
So I fear it won't be enough to ensure BC :/ You'll need to be able to configure the $morePrecision flag higher.

Or, wouldn't it be possible to simply add the flag to the three methods mentioned above, to either return an int (default) or a float (more precision): public function getStartTime(/*bool $morePrecision = false*/) instead (and always store floats in the private StopwatchPeriod properties)?

adding param to method is BC breaker.
you are thinking more about StopWatchPreciseEvent

Indeed, except if the new arg is commented until 4.0, and implementations not having it trigger deprecations. StopWatchPreciseEvent could be a solution, but you still need a simple way to say you want to use it, higher in the Stopwatch API, without affecting existing code, as it may impact other consumers.

If I get you right - if whole param would be commented, then the way to retrieve it would be to func_get_args.
Big 👎 from my side to that practices.

We already use this "practice" for BC reasons in quite a lot of places in Symfony core.

@keradus See all func_get_arg instances in Symfony. This practice is actually pretty novel in terms of providing new APIs without causing BC breaks.

And those only are the remaining ones in the master branch.

@keradus Using func_get_args/func_num_args() is the only way to have proper upgrade paths when adding an argument to a method.
They can make the code less readable for a period, but that's for making it better at the end, that is what BC layers are all about.

See e.g.
https://github.com/symfony/symfony/blob/3.3/src/Symfony/Bundle/FrameworkBundle/Translation/Translator.php#L61
https://github.com/symfony/symfony/blob/3.3/src/Symfony/Component/HttpFoundation/Request.php#L597
https://github.com/symfony/symfony/blob/3.3/src/Symfony/Component/DependencyInjection/Definition.php#L805
Worst: https://github.com/symfony/symfony/blob/af4703f6f209a9abc387f81b98e00fad46b89a38/src/Symfony/Bundle/SecurityBundle/Security/FirewallMap.php#L25..#L106

All of these have been removed from master already, and I guess we're all happy about what the changes involving those layers will provide.

keradus · 2017-06-20T09:32:21Z

src/Symfony/Component/Stopwatch/StopwatchPeriod.php

     */
-    public function __construct($start, $end)
+    public function __construct($start, $end, /* bool */ $morePrecision = false)


bool here is no longer needed

I'm skeptical about this practice of adding commented type hints, especially when it just duplicates the docblock

nicolas-grekas · 2017-07-03T10:00:59Z

src/Symfony/Component/Stopwatch/StopwatchPeriod.php

-        $this->start = (int) $start;
-        $this->end = (int) $end;
+        $this->start = $morePrecision ? $start : (int) $start;
+        $this->end = $morePrecision ? $end : (int) $end;


missing cast to float IMHO

nicolas-grekas

with minor comments

too quick

nicolas-grekas · 2017-07-03T10:07:02Z

Approval dismissed, sorry :)
I'm not sure we should really care about the "BC break". Let's return float all the time, WDYT?

IF we happen to really want to have the "BC" flag, then the implementation is partial: we cannot have these hardcoded true when instantiating StopwatchPeriod. StopwatchEvent must also have the flag, etc. transitively.

keradus · 2017-07-03T10:13:55Z

I'm not sure we should really care about the "BC break". Let's return float all the time, WDYT?

and that's the bc breaker, and I show how it breaks my code. please do respect SEMVER or officially say project is no longer following it.

robfrawley · 2017-07-03T11:49:22Z

@keradus The "BC break" is limited to use of declare(strict_types=1);, correct? Why can't we just change to float returns for this component for the 4.x release?

keradus · 2017-07-03T12:11:52Z

not, it's not only limited to declare(strict_types=1), one could also check the types himself in php5 as well, eg using https://github.com/webmozart/assert

Changing return type in 4.0 is fine, as 4.0 is not yet released and 4.0 is dedicated place for BC breakers.
Changing return type in non-MAJOR release is BC breaker.

http://symfony.com/doc/current/contributing/code/bc.html

Change return type No

robfrawley · 2017-07-03T13:09:14Z

~~Why would you be making type assertions against external (non-project) code?~~ Anyway, as I said: I think we should change the return type for 4.x and leave as-is for the 3.x releases without any of these precision flags adding complexity to the code.

stof · 2017-07-03T13:32:13Z

@robfrawley assertion could be on the argument of one of your methods, and you could be using the output of the component as input for your code.

keradus · 2017-07-03T21:10:44Z

@robfrawley , exactly as @stof said

javiereguiluz · 2017-07-06T07:40:57Z

I've updated this PR to follow @ogizanagi's comments.

ogizanagi

The collectors should be updated to use the new flag when using getters.

ogizanagi · 2017-07-06T07:59:46Z

src/Symfony/Component/Stopwatch/CHANGELOG.md

@@ -5,3 +5,5 @@ CHANGELOG
 -----

 * added the `Stopwatch::reset()` method
+ * allowed to measure sub-millisecond times by introducing a third argument to


The changelog entry needs to be updated too :)

ogizanagi · 2017-07-06T08:02:10Z

src/Symfony/Component/Stopwatch/StopwatchEvent.php

@@ -97,7 +97,7 @@ public function stop()
            throw new \LogicException('stop() called but start() has not been called before.');
        }

-        $this->periods[] = new StopwatchPeriod(array_pop($this->started), $this->getNow());
+        $this->periods[] = new StopwatchPeriod(array_pop($this->started), $this->getNow(), true);


The third argument is not used anymore (same below)

ogizanagi · 2017-07-06T08:03:43Z

src/Symfony/Component/Stopwatch/StopwatchPeriod.php

     */
    public function __construct($start, $end)
    {
-        $this->start = (int) $start;
-        $this->end = (int) $end;
+        $this->start = $start;


Shouldn't it be casted to float here to avoid issues with strict types ? (otherwise getters might return an int even with the $morePrecision flag to true)

yep. and currently, passing eg strings will cause odd working of method, while previously they would be converted in constructor already

javiereguiluz · 2017-07-06T08:14:51Z

After discussing it with @nicolas-grekas, we're proposing a different implementation for this feature.

ogizanagi · 2017-07-06T08:24:47Z

The issue I see with this new implementation over the flag in getters is that you'll probably update the debug.stopwatch service to use it, making it always return float, while someone might have reused this in it's own classes, with strict types enabled. So that's still a (edge but still) BC break to me.

fabpot · 2017-07-06T09:15:17Z

Thank you @javiereguiluz.

This PR was squashed before being merged into the 3.4 branch (closes #23223). Discussion ---------- Add support for microseconds in Stopwatch | Q | A | ------------- | --- | Branch? | 3.4 | Bug fix? | no | New feature? | yes | BC breaks? | no? | Deprecations? | no | Tests pass? | yes | Fixed tickets | #18756 | License | MIT | Doc PR | - Stopwatch component already supports microseconds (and nanoseconds, etc.) ... but the problem is that it converts the millisecond times to integers, so anything smaller to 1 millisecond is lost. This PR changes that to fix issues like the one explained in #18756. ### Before ![before-stopwatch](https://user-images.githubusercontent.com/73419/27279393-c745db54-54e4-11e7-8f26-01e2063604ce.png) ### After ![after-stopwatch](https://user-images.githubusercontent.com/73419/27279396-c8894dac-54e4-11e7-9a3a-bff027377047.png) Commits ------- 0db8d7f Add support for microseconds in Stopwatch

keradus · 2017-07-06T09:36:28Z

Great to see this without BC breakers ;)

…h (javiereguiluz) This PR was squashed before being merged into the 3.4 branch (closes #8146). Discussion ---------- Added a tip about the support of microseconds in Stopwatch This documents symfony/symfony#23223. See also https://symfony.com/blog/new-in-symfony-3-4-stopwatch-improvements. Commits ------- 24718a6 Added a tip about the support of microseconds in Stopwatch

carsonbot added Status: Needs Review Feature labels Jun 19, 2017

javiereguiluz added the Stopwatch label Jun 19, 2017

keradus reviewed Jun 19, 2017

View reviewed changes

SenseException reviewed Jun 19, 2017

View reviewed changes

ogizanagi reviewed Jun 19, 2017

View reviewed changes

keradus reviewed Jun 19, 2017

View reviewed changes

ogizanagi reviewed Jun 19, 2017

View reviewed changes

keradus reviewed Jun 20, 2017

View reviewed changes

nicolas-grekas reviewed Jul 3, 2017

View reviewed changes

nicolas-grekas previously approved these changes Jul 3, 2017

View reviewed changes

nicolas-grekas added this to the 3.4 milestone Jul 3, 2017

javiereguiluz added 7 commits July 6, 2017 09:42

Add support for microseconds in Stopwatch

25a7d35

Fixed code syntax

eaba9d3

Added a new $useMicroPrecision param

e002ff0

Added the CHANGELOG file for the component

a12fb57

Simplified the implementation

20f9e55

Use more precision by default

ce2b842

Moved the argument from constructor to methods

f734c2a

javiereguiluz force-pushed the fix_18756 branch from c6b222f to f734c2a Compare July 6, 2017 07:42

ogizanagi reviewed Jul 6, 2017

View reviewed changes

Proposed a new implementation

e0ca56e

Misc fixes

9c299c2

javiereguiluz added 3 commits July 6, 2017 10:28

Use more precision in the Stopwatch of the FrameworkBundle

24a5059

Use a real boolean argument

1355390

Fixed some tests

9061167

nicolas-grekas approved these changes Jul 6, 2017

View reviewed changes

fabpot approved these changes Jul 6, 2017

View reviewed changes

fabpot closed this Jul 6, 2017

This was referenced Jul 9, 2017

Microseconds in Stopwatch Component #18756

Closed

Added a tip about the support of microseconds in Stopwatch symfony/symfony-docs#8146

Closed

This was referenced Oct 18, 2017

Release v3.4.0-BETA1 #24609

Merged

Release v4.0.0-BETA1 #24612

Merged

Add support for microseconds in Stopwatch #23223

Add support for microseconds in Stopwatch #23223

Conversation

javiereguiluz commented Jun 19, 2017

Before

After

keradus Jun 19, 2017 • edited Loading

Choose a reason for hiding this comment

keradus commented Jun 19, 2017

javiereguiluz commented Jun 19, 2017

keradus commented Jun 19, 2017

keradus commented Jun 19, 2017

fabpot commented Jun 19, 2017

keradus commented Jun 19, 2017

Choose a reason for hiding this comment

javiereguiluz commented Jun 19, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

fabpot commented Jun 19, 2017

javiereguiluz commented Jun 19, 2017

fabpot commented Jun 19, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

javiereguiluz commented Jun 19, 2017

ogizanagi Jun 19, 2017 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ogizanagi Jun 20, 2017 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

nicolas-grekas left a comment

Choose a reason for hiding this comment

nicolas-grekas commented Jul 3, 2017

keradus commented Jul 3, 2017

robfrawley commented Jul 3, 2017

keradus commented Jul 3, 2017 • edited Loading

robfrawley commented Jul 3, 2017 • edited Loading

stof commented Jul 3, 2017

keradus commented Jul 3, 2017

javiereguiluz commented Jul 6, 2017

ogizanagi left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

javiereguiluz commented Jul 6, 2017

ogizanagi commented Jul 6, 2017 • edited Loading

fabpot commented Jul 6, 2017

keradus commented Jul 6, 2017

keradus Jun 19, 2017 •

edited

Loading

ogizanagi Jun 19, 2017 •

edited

Loading

ogizanagi Jun 20, 2017 •

edited

Loading

keradus commented Jul 3, 2017 •

edited

Loading

robfrawley commented Jul 3, 2017 •

edited

Loading

ogizanagi commented Jul 6, 2017 •

edited

Loading