Movatterモバイル変換


[0]ホーム

URL:


Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly

Sign up
Appearance settings

[HttpKernel] Garbage collection in LoggerDataCollector took about 50% of all execution time#23620

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 ourterms of service andprivacy statement. We’ll occasionally send you account related emails.

Already on GitHub?Sign in to your account

Closed
vtsykun wants to merge1 commit intosymfony:3.4fromvtsykun:patch-logger-collector

Conversation

@vtsykun
Copy link
Contributor

QA
Branch?3.4
Bug fix?yes
New feature?no
BC breaks?no
Deprecations?no
Tests pass?-
Fixed tickets-
LicenseMIT
Doc PR-

When save the profiler, the methodLoggerDataCollector:lateCollect called for each sub-request on the same sets of logs. For example I profile page with 70 sub-requests and 7k logshttps://blackfire.io/profiles/bc726df2-ec8d-4f1b-bc1b-5b09a1f3f141/graph

After apply my fix I get more 80% performance
selection_061

Thanks,
Vladimir

@linaori
Copy link
Contributor

Is this also the case on 3.2+? Because here I saw massive performance issues in dev mode, but have been unable to trace the cause.

@nicolas-grekas
Copy link
Member

nicolas-grekas commentedJul 23, 2017
edited
Loading

This patch cannot be merged as is because it forces one single list of logs, thus defeats the purpose of using objects for scope isolation.
Yet, as I understand the issue, all sub-requests have the same logs, and we still serialize them several times?
Also, which exact Symfony version was the profile done with? Can you try v3.3.5 if that was an earlier version?

@vtsykun
Copy link
ContributorAuthor

I profile v3.3.5 and get same resulthttps://blackfire.io/profiles/76d6907f-ef47-4c5f-9fea-9a73c926e2f1/graph.
Yes, all sub-requests have the same logs, and we still serialize them several times.
It problems also exist on v2.8.* Our application used 2.8.13. We noticed that debug toolbar not showing (error not found 404) on some heavy pages. The reason was that serialize and collects logs for each sub-request take a lot of time. Then we could not find a more correct solution than thishttps://github.com/orocrm/platform/blob/master/src/Oro/Bundle/LoggerBundle/DataCollector/LoggerDataCollector.php

@nicolas-grekas
Copy link
Member

What's the effect of this patch?

--- a/src/Symfony/Component/HttpKernel/EventListener/ProfilerListener.php+++ b/src/Symfony/Component/HttpKernel/EventListener/ProfilerListener.php@@ -105,6 +105,10 @@ class ProfilerListener implements EventSubscriberInterface      public function onKernelTerminate(PostResponseEvent $event)     {+        if ($gc = gc_enabled()) {+            gc_disable();+        }+        try {             // attach children to parents             foreach ($this->profiles as $request) {                 // isset call should be removed when requestStack is required@@ -122,6 +126,11 @@ class ProfilerListener implements EventSubscriberInterface              $this->profiles = new \SplObjectStorage();             $this->parents = new \SplObjectStorage();+        } finally {+            if ($gc) {+                gc_enable();+            }+        }     }

@linaori
Copy link
Contributor

linaori commentedJul 23, 2017
edited
Loading

We've been experiencing similar issues on certain pages in 3.2, though it doesn't necessarily happen every request on that page, it simply gives an error opening the profile "randomly".

@nicolas-grekas
Copy link
Member

Wondering: what would be the downside of settingframework.profiler.only_master_requests to true?

@vtsykun
Copy link
ContributorAuthor

Of course it workframework.profiler.only_master_requests: true because hides cause of the problems.
After disable gc:https://blackfire.io/profiles/e0dc05e2-8769-4a29-a220-5228599e9c47/graph
I think we should not show the same list of logs for each sub-request and master request. For example if I open debug toolbar for doctrine query I will see different count of sql query for each sub-request, but not for logs toolbar.
I will try to implement this, It also should be fix performance because the same log will not be processed many times for each sub-request

@nicolas-grekas
Copy link
Member

nicolas-grekas commentedJul 24, 2017
edited
Loading

This won't fix the issue of having the logs serialized several times, yet it'd be really nice if you could revert that patch above (adding gc_disable), and try#23644 instead. What's the resulting profile?

@vtsykun
Copy link
ContributorAuthor

It is improve performance by execute time, but not memory
Comparison resulthttps://blackfire.io/profiles/compare/94da04c4-56a4-48f0-93fe-9a8b25fc28d0/graph

Thanks,
Vladimir

@nicolas-grekas
Copy link
Member

New profile welcomed, I pushed a new patch on#23644 :)

vtsykun reacted with thumbs up emoji

@vtsykun
Copy link
ContributorAuthor

It has improved performance for VarDumperhttps://blackfire.io/profiles/30521d32-392e-435a-8f01-af4492df0f55/graph
Thank you!

@nicolas-grekas
Copy link
Member

I don't understand the memory increase. Can you please do a last profile with the new patch on the PR see if it improves things?

@vtsykunvtsykun deleted the patch-logger-collector branchJuly 26, 2017 08:51
@vtsykun
Copy link
ContributorAuthor

fabpot added a commit that referenced this pull requestJul 28, 2017
…grekas)This PR was merged into the 3.3 branch.Discussion----------[VarDumper] Keep and reuse array stubs in memory| Q             | A| ------------- | ---| Branch?       | 3.3| Bug fix?      | yes| New feature?  | no| BC breaks?    | no| Deprecations? | no| Tests pass?   | yes| Fixed tickets | -| License       | MIT| Doc PR        | -(to be reviewed [ignoring whitespaces](https://github.com/symfony/symfony/pull/23683/files?w=1))As highlighted by@vtsykun in#23620, the patch in#23644 improves performance but increases the memory usage.The issue is that even a small `array($k => $v)` consumes more memory than a `new Stub()`.That's a shame, but since our small arrays have a low variety, we can keep them in a cache and leverage php's COW mechanism to reduce memory. Effectively, this creates a memory leak. But the leak is upper bounded by the data you had already in memory, since that's what is cloned. Looking at the numbers, it looks worth it:|   | 3.3.5 | +#23644 | +this PR| --- | --- | --- | ---| Wall Time    | 39.4s | 26.1s | ~~18.6s~~ 17.3s| Memory       | 391MB | 539MB | ~~217MB~~ 216MBhttps://blackfire.io/profiles/compare/846b58bc-7863-4502-9ca2-f82eebd4173f/graphCommits-------92fa55d [VarDumper] Keep and reuse array stubs in memory
nicolas-grekas added a commit that referenced this pull requestApr 20, 2018
…fferent sub-requests (vtsykun)This PR was merged into the 4.1-dev branch.Discussion----------[HttpKernel] LoggerDataCollector: splitting logs on different sub-requests| Q             | A| ------------- | ---| Branch?       | 4.1| Bug fix?      | yes| New feature?  | no| BC breaks?    | no| Deprecations? | no| Tests pass?   | -| Fixed tickets |#23620| License       | MIT| Doc PR        | -This PR fixed performance problem in dev mode and prevent logs serialize several times for each sub-request.STR:1) Install any symfony application v2.8-3.42) Create a simple page with 20-50 sub-requests and 5k-10k logs3) Open page in dev mode**Actual**- debug toolbar not open (404 not found)- sets of logs (in the logger debug panel) for different requests are same- log processing takes about 20-30s- gc also run about 50% of execution time**Expected**- Debug toolbar should be open- As developer, I want to see in logger panel only those logs that are relevant to the given sub-request### Profile and performanceTested on page with 7k logs and 70 sub-request.Comparison:- v3.3.5 - this patch:https://blackfire.io/profiles/compare/b1d410b3-c4a7-4778-9b6d-514f72193e28/graph- v3.3.5 - patch#23644https://blackfire.io/profiles/compare/d0715b04-7834-4981-8da2-9f1dcb2ef90c/graphCommits-------d0cb1de [HttpKernel] LoggerDataCollector: splitting logs on different sub-requests
Sign up for freeto join this conversation on GitHub. Already have an account?Sign in to comment

Reviewers

No reviews

Assignees

No one assigned

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

4 participants

@vtsykun@linaori@nicolas-grekas@carsonbot

[8]ページ先頭

©2009-2025 Movatter.jp