@soukicz opened this Issue on April 23rd 2019 Contributor

Hi,
I am getting 100% CPU usage from tracking script on 3.9.1 with PHP 7.3. I have tried to disable tracking in config but CPU is still 100% (after webserver restart).
I have tried to run Blackfire on tracking script and it shows that 38% of time is spent on INI files parsing.
It seems pointless to parse the files on every request. Is it a bug or is it by design that there is no cache?

https://blackfire.io/profiles/b13eb852-e071-470f-8a96-d3690e5e5d9d/graph

@tsteur commented on April 23rd 2019 Member

There is no caching across requests on purpose. Ini parsing is fast compared to the whole tracking request. It looks like you weren't actually profiling a proper tracking request. At least I cannot find any queries to the DB etc and a lot of other calls that would be usually executed.

@soukicz commented on April 23rd 2019 Contributor

Yes, that percentage isn't relevant with normal request. But it is still pointless 6ms per request on i9-9900k CPU. That doesn't sound like a lot but for a file that is executed 500 times per second it sums up.

Do I undestand correctly that I shouldn't bother with pull request?

@tsteur commented on April 23rd 2019 Member

Right now we wouldn't really be interested. We could potentially use it optionally but people would need to remember to invalidate caches when changing the config file etc. and it gets more difficult when using multiple servers and you have maybe the config file in an EFS/shared drive and need to invalidate all local caches etc. A workaround could be to build the cache key based on the md5_file($configFile) or so. It's in general important to invalidate the cache as soon as the config changes especially when enabling maintenance mode / disable tracking as otherwise you risk running into big trouble.

Maybe check if you find there's a big performance improvement when caching eg content based on a key built with eg md5_file(). In general you really want to test the true performance of it though eg using the below code as profilers are always a bit of when some methods have a lot of calls in my experience (the ratio is more or less the same though).

    public function readFile($filename)
    {
        $timer = new Timer();
        $ini = $this->getContentOfIniFile($filename);

        $test = $this->readString($ini);
        echo $timer->getTimeMs() . 'ms'; exit;
    }

On my slow local computer, with a rather slow HD, it takes on average 3ms for me and it makes only 1% of total request time. I think on our production server it's also only about 1%.

@tsteur commented on April 23rd 2019 Member

On our production server it takes 0.4ms.

@fdellwing commented on April 24th 2019 Contributor

microtime(true) says it takes <0.1ms, so really not a long time at all.


It is getting called a lot of time while browsing the dashboard, because every widget loading does reread the INI file. At this point there might be optimization potential? Like only read the file one time per user interaction?

@soukicz commented on April 24th 2019 Contributor

It it possible that it depends on activated plugins? But I don't think that I have activated something that isn't active by default.

[Plugins]
Plugins[] = "CorePluginsAdmin"
Plugins[] = "CoreAdminHome"
Plugins[] = "CoreHome"
Plugins[] = "WebsiteMeasurable"
Plugins[] = "IntranetMeasurable"
Plugins[] = "Diagnostics"
Plugins[] = "CoreVisualizations"
Plugins[] = "Proxy"
Plugins[] = "API"
Plugins[] = "ExamplePlugin"
Plugins[] = "Widgetize"
Plugins[] = "Transitions"
Plugins[] = "LanguagesManager"
Plugins[] = "Actions"
Plugins[] = "Dashboard"
Plugins[] = "MultiSites"
Plugins[] = "Referrers"
Plugins[] = "UserLanguage"
Plugins[] = "DevicesDetection"
Plugins[] = "GeoIp2"
Plugins[] = "Goals"
Plugins[] = "Ecommerce"
Plugins[] = "SEO"
Plugins[] = "Events"
Plugins[] = "UserCountry"
Plugins[] = "VisitsSummary"
Plugins[] = "VisitFrequency"
Plugins[] = "VisitTime"
Plugins[] = "VisitorInterest"
Plugins[] = "ExampleAPI"
Plugins[] = "RssWidget"
Plugins[] = "Feedback"
Plugins[] = "Monolog"
Plugins[] = "Login"
Plugins[] = "TwoFactorAuth"
Plugins[] = "UsersManager"
Plugins[] = "SitesManager"
Plugins[] = "Installation"
Plugins[] = "CoreUpdater"
Plugins[] = "CoreConsole"
Plugins[] = "ScheduledReports"
Plugins[] = "UserCountryMap"
Plugins[] = "Live"
Plugins[] = "CustomVariables"
Plugins[] = "PrivacyManager"
Plugins[] = "ImageGraph"
Plugins[] = "Annotations"
Plugins[] = "MobileMessaging"
Plugins[] = "Overlay"
Plugins[] = "SegmentEditor"
Plugins[] = "Insights"
Plugins[] = "Morpheus"
Plugins[] = "Contents"
Plugins[] = "BulkTracking"
Plugins[] = "Resolution"
Plugins[] = "DevicePlugins"
Plugins[] = "Heartbeat"
Plugins[] = "Intl"
Plugins[] = "Marketplace"
Plugins[] = "ProfessionalServices"
Plugins[] = "UserId"
Plugins[] = "CustomPiwikJs"
Plugins[] = "DBStats"
Plugins[] = "DoNotTrack"
@tsteur commented on April 24th 2019 Member

It should for sure not depend in the number of activated plugins, and that's a normal number anyway (we have way more activated)

@tsteur commented on May 1st 2019 Member

just fyi: for some completely different reason quickly looked into possibility of caching the config and it's not even possible. The caching would need to be done in the ini reader or so... but the problem is we cannot cache content, because caching would require the config to be already loaded. Without the config, we cannot detect the tmp path for caches etc (especially important when using instanceIds).

@soukicz commented on May 1st 2019 Contributor

I was planning to use APC cache. Even 1-2s TTL would help a lot on high traffic sites - but I was operating with 6ms config loading time which was probably some weird issue only on my server.

This Issue was closed on April 23rd 2019
Powered by GitHub Issue Mirror