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

[LOG] Improve logs wording, add classname in log files #1103

Merged
merged 4 commits into from
Jan 8, 2025

Conversation

M0rgan01
Copy link
Contributor

@M0rgan01 M0rgan01 commented Jan 3, 2025

Questions Answers
Description? Improve logs wording, add classname in log files
Type? improvement
BC breaks? no
Deprecations? no
Fixed ticket? -
Sponsor company -
How to test? -

@M0rgan01 M0rgan01 added this to the 7.0.0 milestone Jan 3, 2025
@M0rgan01 M0rgan01 force-pushed the improve-log-wording branch 2 times, most recently from ac5fe41 to 57a6791 Compare January 6, 2025 09:04
@M0rgan01 M0rgan01 marked this pull request as ready for review January 6, 2025 09:17
@M0rgan01 M0rgan01 closed this Jan 6, 2025
@M0rgan01 M0rgan01 reopened this Jan 6, 2025
ga-devfront
ga-devfront previously approved these changes Jan 6, 2025
Copy link
Contributor

@ga-devfront ga-devfront left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

A small typo otherwise everything is good, thank you!

classes/Task/Backup/BackupFiles.php Outdated Show resolved Hide resolved
ga-devfront
ga-devfront previously approved these changes Jan 6, 2025
@M0rgan01
Copy link
Contributor Author

M0rgan01 commented Jan 7, 2025

@Quetzacoalt91

With classname (with dev branch) in seconde

  1. 72.21
  2. 67.57
  3. 68.83
  4. 69.28
  5. 68.72
  6. 68.43
  7. 69.23
  8. 70.80
  9. 68.67
  10. 73.84

Average: 69.76

With classname in seconde

  1. 68.54
  2. 71.46
  3. 67.55
  4. 68.26
  5. 70.99
  6. 74.65
  7. 69.34
  8. 71.15
  9. 68.11
  10. 69.54

Average: 69.96

test conditions: I use time command with the update:start command. 1.7.7.0 to 8.2.0 with https://github.com/PrestaShop/SeamlessUpgradeToolbox

Total logs for 1 update: 30 000
PHP version: 7.4

@Quetzacoalt91
Copy link
Member

Quetzacoalt91 commented Jan 7, 2025

I've created a task that only calls the logger in a reasonable way:

class Test extends AbstractTask
{
    const TASK_TYPE = TaskType::TASK_TYPE_UPDATE;

    /**
     * @throws Exception
     */
    public function run(): int
    {
        for ($i = 0 ; $i < 450 ; ++$i) {
            $this->logger->info($this->translator->trans(
                'Logger called'
            ));
        }

        $this->next = TaskName::TASK_UPDATE_COMPLETE;

        return ExitCode::SUCCESS;
    }
}

It takes 12 on the dev branch and 17 ms on this PR, which seems still acceptable.

When we profile it, getting the caller is taking ~13% of the script execution time and is flagged by Blackfire as an intensive node.
https://blackfire.io/profiles/77d55665-82d3-436d-a69e-bfdd7c9a0229/graph
image

And when focusing on this method on particular:
Capture d’écran du 2025-01-07 11-46-47
I'll suggest a small improvement on the subclass check, and this part should be unit tested to be future-proof.

Comment on lines 195 to 202
$trace = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS);

foreach ($trace as $frame) {
if (
isset($frame['class']) &&
!is_subclass_of($frame['class'], self::class) &&
$frame['class'] !== self::class
) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
$trace = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS);
foreach ($trace as $frame) {
if (
isset($frame['class']) &&
!is_subclass_of($frame['class'], self::class) &&
$frame['class'] !== self::class
) {
// We don't need the whole stack. The 5th level is enough to get
// the called of the logger but we keep a buffer in case it goes deeper.
$trace = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS, 8);
foreach ($trace as $frame) {
if (
isset($frame['class']) &&
strpos($frame['class'], __NAMESPACE__) === false
) {

Copy link

sonarqubecloud bot commented Jan 7, 2025

@Quetzacoalt91
Copy link
Member

2025-01-08-111321-backup.txt

2025-01-08-110915-update.txt

Caller class is properly reported in the log file.

@Quetzacoalt91 Quetzacoalt91 merged commit de56aee into PrestaShop:dev Jan 8, 2025
37 checks passed
@Quetzacoalt91 Quetzacoalt91 deleted the improve-log-wording branch January 8, 2025 10:16
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
Archived in project
Development

Successfully merging this pull request may close these issues.

4 participants