Skip to content

Commit

Permalink
Add performance logging under a --debug-performance flag
Browse files Browse the repository at this point in the history
  • Loading branch information
muglug committed Jul 30, 2020
1 parent ad1920c commit 6919e88
Show file tree
Hide file tree
Showing 7 changed files with 121 additions and 22 deletions.
21 changes: 21 additions & 0 deletions src/Psalm/Internal/Analyzer/FunctionLikeAnalyzer.php
Original file line number Diff line number Diff line change
Expand Up @@ -557,8 +557,29 @@ function (FunctionLikeParameter $p) {
]);
}

$time = \microtime(true);

$project_analyzer = $statements_analyzer->getProjectAnalyzer();

$statements_analyzer->analyze($function_stmts, $context, $global_context, true);

if (!$context->collect_initializations
&& !$context->collect_mutations
&& $project_analyzer->debug_performance
&& $cased_method_id
) {
$traverser = new PhpParser\NodeTraverser;

$node_counter = new \Psalm\Internal\PhpVisitor\NodeCounterVisitor();
$traverser->addVisitor($node_counter);
$traverser->traverse($function_stmts);

if ($node_counter->count > 5) {
$time_taken = \microtime(true) - $time;
$codebase->analyzer->addFunctionTiming($cased_method_id, $time_taken / $node_counter->count);
}
}

$this->examineParamTypes($statements_analyzer, $context, $codebase);

foreach ($storage->params as $offset => $function_param) {
Expand Down
5 changes: 5 additions & 0 deletions src/Psalm/Internal/Analyzer/ProjectAnalyzer.php
Original file line number Diff line number Diff line change
Expand Up @@ -135,6 +135,11 @@ class ProjectAnalyzer
*/
public $debug_lines = false;

/**
* @var bool
*/
public $debug_performance = false;

/**
* @var bool
*/
Expand Down
4 changes: 4 additions & 0 deletions src/Psalm/Internal/Analyzer/StatementsAnalyzer.php
Original file line number Diff line number Diff line change
Expand Up @@ -151,6 +151,10 @@ public function analyze(
Context $global_context = null,
$root_scope = false
) {
if (!$stmts) {
return;
}

// hoist functions to the top
$this->hoistFunctions($stmts);

Expand Down
63 changes: 41 additions & 22 deletions src/Psalm/Internal/Codebase/Analyzer.php
Original file line number Diff line number Diff line change
Expand Up @@ -46,6 +46,7 @@
* file_references_to_missing_class_members: array<string, array<string,bool>>,
* mixed_counts: array<string, array{0: int, 1: int}>,
* mixed_member_names: array<string, array<string, bool>>,
* function_timings: array<string, float>,
* file_manipulations: array<string, FileManipulation[]>,
* method_references_to_class_members: array<string, array<string,bool>>,
* method_references_to_missing_class_members: array<string, array<string,bool>>,
Expand Down Expand Up @@ -108,6 +109,13 @@ class Analyzer
*/
private $count_mixed = true;

/**
* Used to store debug performance data
*
* @var array<string, float>
*/
private $function_timings = [];

/**
* We analyze more files than we necessarily report errors in
*
Expand Down Expand Up @@ -316,7 +324,7 @@ function (string $file_path) : bool {
}
}

private function doAnalysis(ProjectAnalyzer $project_analyzer, int $pool_size, bool $rerun = false) : void
private function doAnalysis(ProjectAnalyzer $project_analyzer, int $pool_size) : void
{
$this->progress->start(count($this->files_to_analyze));

Expand Down Expand Up @@ -426,7 +434,7 @@ function () {
},
$analysis_worker,
/** @return WorkerData */
function () use ($rerun) {
function () {
$project_analyzer = ProjectAnalyzer::getInstance();
$codebase = $project_analyzer->getCodebase();
$analyzer = $codebase->analyzer;
Expand All @@ -438,22 +446,23 @@ function () use ($rerun) {
return [
'issues' => IssueBuffer::getIssuesData(),
'fixable_issue_counts' => IssueBuffer::getFixableIssues(),
'nonmethod_references_to_classes' => $rerun ? [] : $file_reference_provider->getAllNonMethodReferencesToClasses(),
'method_references_to_classes' => $rerun ? [] : $file_reference_provider->getAllMethodReferencesToClasses(),
'file_references_to_class_members' => $rerun ? [] : $file_reference_provider->getAllFileReferencesToClassMembers(),
'method_references_to_class_members' => $rerun ? [] : $file_reference_provider->getAllMethodReferencesToClassMembers(),
'file_references_to_missing_class_members' => $rerun ? [] : $file_reference_provider->getAllFileReferencesToMissingClassMembers(),
'method_references_to_missing_class_members' => $rerun ? [] : $file_reference_provider->getAllMethodReferencesToMissingClassMembers(),
'method_param_uses' => $rerun ? [] : $file_reference_provider->getAllMethodParamUses(),
'mixed_member_names' => $rerun ? [] : $analyzer->getMixedMemberNames(),
'file_manipulations' => $rerun ? [] : FileManipulationBuffer::getAll(),
'mixed_counts' => $rerun ? [] : $analyzer->getMixedCounts(),
'analyzed_methods' => $rerun ? [] : $analyzer->getAnalyzedMethods(),
'file_maps' => $rerun ? [] : $analyzer->getFileMaps(),
'class_locations' => $rerun ? [] : $file_reference_provider->getAllClassLocations(),
'class_method_locations' => $rerun ? [] : $file_reference_provider->getAllClassMethodLocations(),
'class_property_locations' => $rerun ? [] : $file_reference_provider->getAllClassPropertyLocations(),
'possible_method_param_types' => $rerun ? [] : $analyzer->getPossibleMethodParamTypes(),
'nonmethod_references_to_classes' => $file_reference_provider->getAllNonMethodReferencesToClasses(),
'method_references_to_classes' => $file_reference_provider->getAllMethodReferencesToClasses(),
'file_references_to_class_members' => $file_reference_provider->getAllFileReferencesToClassMembers(),
'method_references_to_class_members' => $file_reference_provider->getAllMethodReferencesToClassMembers(),
'file_references_to_missing_class_members' => $file_reference_provider->getAllFileReferencesToMissingClassMembers(),
'method_references_to_missing_class_members' => $file_reference_provider->getAllMethodReferencesToMissingClassMembers(),
'method_param_uses' => $file_reference_provider->getAllMethodParamUses(),
'mixed_member_names' => $analyzer->getMixedMemberNames(),
'file_manipulations' => FileManipulationBuffer::getAll(),
'mixed_counts' => $analyzer->getMixedCounts(),
'function_timings' => $analyzer->getFunctionTimings(),
'analyzed_methods' => $analyzer->getAnalyzedMethods(),
'file_maps' => $analyzer->getFileMaps(),
'class_locations' => $file_reference_provider->getAllClassLocations(),
'class_method_locations' => $file_reference_provider->getAllClassMethodLocations(),
'class_property_locations' => $file_reference_provider->getAllClassPropertyLocations(),
'possible_method_param_types' => $analyzer->getPossibleMethodParamTypes(),
'taint_data' => $codebase->taint,
'unused_suppressions' => $codebase->track_unused_suppressions ? IssueBuffer::getUnusedSuppressions() : [],
'used_suppressions' => $codebase->track_unused_suppressions ? IssueBuffer::getUsedSuppressions() : [],
Expand Down Expand Up @@ -486,10 +495,6 @@ function () use ($rerun) {
$codebase->taint->addThreadData($pool_data['taint_data']);
}

if ($rerun) {
continue;
}

$codebase->file_reference_provider->addNonMethodReferencesToClasses(
$pool_data['nonmethod_references_to_classes']
);
Expand All @@ -514,6 +519,7 @@ function () use ($rerun) {
$this->addMixedMemberNames(
$pool_data['mixed_member_names']
);
$this->function_timings += $pool_data['function_timings'];
$codebase->file_reference_provider->addClassLocations(
$pool_data['class_locations']
);
Expand Down Expand Up @@ -1145,6 +1151,19 @@ public function getMixedCounts()
return array_intersect_key($this->mixed_counts, $all_deep_scanned_files);
}

/**
* @return array<string, float>
*/
public function getFunctionTimings()
{
return $this->function_timings;
}

public function addFunctionTiming(string $function_id, float $time_per_node) : void
{
$this->function_timings[$function_id] = $time_per_node;
}

/**
* @return void
*/
Expand Down
23 changes: 23 additions & 0 deletions src/Psalm/Internal/PhpVisitor/NodeCounterVisitor.php
Original file line number Diff line number Diff line change
@@ -0,0 +1,23 @@
<?php
namespace Psalm\Internal\PhpVisitor;

use PhpParser;

/**
* @internal
*/
class NodeCounterVisitor extends PhpParser\NodeVisitorAbstract implements PhpParser\NodeVisitor
{
/** @var int */
public $count = 0;

/**
* @param PhpParser\Node $node
*
* @return null|int
*/
public function enterNode(PhpParser\Node $node)
{
$this->count++;
}
}
22 changes: 22 additions & 0 deletions src/Psalm/IssueBuffer.php
Original file line number Diff line number Diff line change
Expand Up @@ -633,6 +633,28 @@ function (IssueData $d1, IssueData $d2) : int {
echo $codebase->analyzer->getNonMixedStats();
echo "\n";
}

if ($project_analyzer->debug_performance) {
echo '-----------------' . "\n";
echo 'Slow-to-analyze functions' . "\n";
echo '-----------------' . "\n\n";

$function_timings = $codebase->analyzer->getFunctionTimings();

\arsort($function_timings);

$i = 0;

foreach ($function_timings as $function_id => $time) {
if (++$i > 10) {
break;
}

echo $function_id . ': ' . \round(1000 * $time, 2) . 'ms per node' . "\n";
}

echo "\n";
}
}
}

Expand Down
5 changes: 5 additions & 0 deletions src/psalm.php
Original file line number Diff line number Diff line change
Expand Up @@ -80,6 +80,7 @@
'config:',
'debug',
'debug-by-line',
'debug-performance',
'debug-emitted-issues',
'diff',
'diff-methods',
Expand Down Expand Up @@ -624,6 +625,10 @@ function ($arg) {
$project_analyzer->debug_lines = true;
}

if (array_key_exists('debug-performance', $options)) {
$project_analyzer->debug_performance = true;
}

if ($config->find_unused_code) {
$find_unused_code = 'auto';
}
Expand Down

0 comments on commit 6919e88

Please sign in to comment.