Add performance counters to ConsoleSubsriber

[rubenrubiob]

Here is a PR to close #1157

Some things to take into consideration:

• When working with time, it is a good approach to keep its call after an interface. However, I did not want to overengineer the Stopwatch by creating an interface that could mock the calls to hrtime such as a Clock. Thus, in the tests, I check the execution flows rather than values.
• I used the string sec as measure unit, because it is the same the progress bar component uses.
• I changed a little bit the output messages to make them more consistent when they incorporate the measure unit.

I am open to change whatever you believe is needed.

Thank you!

[dbrumann]

Thanks for the PR. I will have a closer look soon, but from a quick glance this looks great 👍

[patrickkusebauch]

Also, you are now getting uncovered dependencies when running deptrac on itself. Please add the newly added files to deptrac config and configure the correct dependencies.

  Uncovered   Qossmic\Deptrac\Supportive\Console\Subscriber\ConsoleSubscriber has uncovered dependency on Qossmic\Deptrac\Supportive\Time\Stopwatch                    
              /home/patrick/PhpstormProjects/deptrac2/src/Supportive/Console/Subscriber/ConsoleSubscriber.php:26                                                       
  Uncovered   Qossmic\Deptrac\Supportive\Console\Subscriber\ConsoleSubscriber has uncovered dependency on Qossmic\Deptrac\Supportive\Time\StopwatchException           
              /home/patrick/PhpstormProjects/deptrac2/src/Supportive/Console/Subscriber/ConsoleSubscriber.php:47                                                       
  Uncovered   Qossmic\Deptrac\Supportive\Console\Subscriber\ConsoleSubscriber has uncovered dependency on Qossmic\Deptrac\Supportive\Time\StopwatchException           
              /home/patrick/PhpstormProjects/deptrac2/src/Supportive/Console/Subscriber/ConsoleSubscriber.php:62                                                       
  Uncovered   Qossmic\Deptrac\Supportive\Console\Subscriber\ConsoleSubscriber has uncovered dependency on Qossmic\Deptrac\Supportive\Time\StopwatchException           
              /home/patrick/PhpstormProjects/deptrac2/src/Supportive/Console/Subscriber/ConsoleSubscriber.php:93                                                       
  Uncovered   Qossmic\Deptrac\Supportive\Console\Subscriber\ConsoleSubscriber has uncovered dependency on Qossmic\Deptrac\Supportive\Time\StopwatchException           
              /home/patrick/PhpstormProjects/deptrac2/src/Supportive/Console/Subscriber/ConsoleSubscriber.php:105                                                      
  Uncovered   Qossmic\Deptrac\Supportive\Console\Subscriber\ConsoleSubscriber has uncovered dependency on Qossmic\Deptrac\Supportive\Time\StopwatchException           
              /home/patrick/PhpstormProjects/deptrac2/src/Supportive/Console/Subscriber/ConsoleSubscriber.php:120                                                      
  Uncovered   Qossmic\Deptrac\Supportive\Console\Subscriber\ConsoleSubscriber has uncovered dependency on Qossmic\Deptrac\Supportive\Time\StopwatchException           
              /home/patrick/PhpstormProjects/deptrac2/src/Supportive/Console/Subscriber/ConsoleSubscriber.php:130    

patrick@thinkpad ~/PhpstormProjects/deptrac2 (main)$ php deptrac.php debug:unassigned
/src/Supportive/Time/Period.php
/src/Supportive/Time/StartedPeriod.php
/src/Supportive/Time/Stopwatch.php
/src/Supportive/Time/StopwatchException.php
Qossmic\Deptrac\Supportive\Time\Period
Qossmic\Deptrac\Supportive\Time\StartedPeriod
Qossmic\Deptrac\Supportive\Time\Stopwatch
Qossmic\Deptrac\Supportive\Time\StopwatchException

[patrickkusebauch]

And can you please make the coloring of the output consistent? Sometimes you get it as regular output, other times as <info>

[patrickkusebauch]

From docs, hrtime() can return false:

"Returns false on failure."

You do not have that path covered.

[rubenrubiob]

Also, you are now getting uncovered dependencies when running deptrac on itself. Please add the newly added files to deptrac config and configure the correct dependencies.

  Uncovered   Qossmic\Deptrac\Supportive\Console\Subscriber\ConsoleSubscriber has uncovered dependency on Qossmic\Deptrac\Supportive\Time\Stopwatch                    
              /home/patrick/PhpstormProjects/deptrac2/src/Supportive/Console/Subscriber/ConsoleSubscriber.php:26                                                       
  Uncovered   Qossmic\Deptrac\Supportive\Console\Subscriber\ConsoleSubscriber has uncovered dependency on Qossmic\Deptrac\Supportive\Time\StopwatchException           
              /home/patrick/PhpstormProjects/deptrac2/src/Supportive/Console/Subscriber/ConsoleSubscriber.php:47                                                       
  Uncovered   Qossmic\Deptrac\Supportive\Console\Subscriber\ConsoleSubscriber has uncovered dependency on Qossmic\Deptrac\Supportive\Time\StopwatchException           
              /home/patrick/PhpstormProjects/deptrac2/src/Supportive/Console/Subscriber/ConsoleSubscriber.php:62                                                       
  Uncovered   Qossmic\Deptrac\Supportive\Console\Subscriber\ConsoleSubscriber has uncovered dependency on Qossmic\Deptrac\Supportive\Time\StopwatchException           
              /home/patrick/PhpstormProjects/deptrac2/src/Supportive/Console/Subscriber/ConsoleSubscriber.php:93                                                       
  Uncovered   Qossmic\Deptrac\Supportive\Console\Subscriber\ConsoleSubscriber has uncovered dependency on Qossmic\Deptrac\Supportive\Time\StopwatchException           
              /home/patrick/PhpstormProjects/deptrac2/src/Supportive/Console/Subscriber/ConsoleSubscriber.php:105                                                      
  Uncovered   Qossmic\Deptrac\Supportive\Console\Subscriber\ConsoleSubscriber has uncovered dependency on Qossmic\Deptrac\Supportive\Time\StopwatchException           
              /home/patrick/PhpstormProjects/deptrac2/src/Supportive/Console/Subscriber/ConsoleSubscriber.php:120                                                      
  Uncovered   Qossmic\Deptrac\Supportive\Console\Subscriber\ConsoleSubscriber has uncovered dependency on Qossmic\Deptrac\Supportive\Time\StopwatchException           
              /home/patrick/PhpstormProjects/deptrac2/src/Supportive/Console/Subscriber/ConsoleSubscriber.php:130    

patrick@thinkpad ~/PhpstormProjects/deptrac2 (main)$ php deptrac.php debug:unassigned
/src/Supportive/Time/Period.php
/src/Supportive/Time/StartedPeriod.php
/src/Supportive/Time/Stopwatch.php
/src/Supportive/Time/StopwatchException.php
Qossmic\Deptrac\Supportive\Time\Period
Qossmic\Deptrac\Supportive\Time\StartedPeriod
Qossmic\Deptrac\Supportive\Time\Stopwatch
Qossmic\Deptrac\Supportive\Time\StopwatchException

Done! I changed it in both deptrac.yaml and deptrac.config.php. However, I do not know if the last one is necessary or not.

And can you please make the coloring of the output consistent? Sometimes you get it as regular output, other times as <info>

Done!

From docs, hrtime() can return false:

"Returns false on failure."

You do not have that path covered.

When I check that path, with something like this:

public static function start(): self
{
    $now = hrtime(true);

    if (false === $now) {
        throw StopwatchException::hrtimeError();
    }

    return new self($now);
}

I get Psalm and PHPStan errors:

ERROR: TypeDoesNotContainType - src/Supportive/Time/Period.php:27:13 - int does not contain false (see https://psalm.dev/056)
        if (false === $now) {


ERROR: TypeDoesNotContainType - src/Supportive/Time/StartedPeriod.php:21:13 - int does not contain false (see https://psalm.dev/056)
        if (false === $now) {

 ------ ------------------------------------------------------------------------------------------ 
  Line   Supportive/Time/Period.php                                                                
 ------ ------------------------------------------------------------------------------------------ 
  27     Strict comparison using === between false and (float|int) will always evaluate to false.  
         💡 Because the type is coming from a PHPDoc, you can turn off this check by setting       
            treatPhpDocTypesAsCertain: false in your phpstan.neon.dist.                            
 ------ ------------------------------------------------------------------------------------------ 

 ------ ------------------------------------------------------------------------------------------ 
  Line   Supportive/Time/StartedPeriod.php                                                         
 ------ ------------------------------------------------------------------------------------------ 
  21     Strict comparison using === between false and (float|int) will always evaluate to false.  
         💡 Because the type is coming from a PHPDoc, you can turn off this check by setting       
            treatPhpDocTypesAsCertain: false in your phpstan.neon.dist.                            
 ------ ------------------------------------------------------------------------------------------

I suppose both tools treat it like it will never fail, even though the docs say it may return false. I was not able to find where they explain it, nor when hrtime could fail.

What shall I do in this case? Should I not check that path?

[dbrumann]

Ignoring false from hrtime() is fine for me. I can't imagine this happening and if it does, we can deal with it separately in a bug ticket and then ignore the phpstan/psalm warnings explictly.

[dbrumann]

Thanks again. This looks ready to be merged for me.

@patrickkusebauch since you had a few comments as well, I will wait for your response.

[patrickkusebauch]

Some of the tests are more headache than they are worth for my taste, but that can be attributed to personal preference, I guess. In reality, they will more than likely be fine.

[patrickkusebauch]

Lastly, I want to say, great job. I really mean it. Your help is appreciated, at least by me. Don't be deceived by me being harsh in my critique on the PR.

[rubenrubiob]

Lastly, I want to say, great job. I really mean it. Your help is appreciated, at least by me. Don't be deceived by me being harsh in my critique on the PR.

On the contrary, I appreciate your feedback, and thank you for it. Besides, in the end, you both are the maintainers of the project, so any PR should meet your expectations.

[patrickkusebauch]

👍 LGTM