Slow loading - php spends 58s waiting


(Pierre Ozoux) #1

I’m using the latest fpm docker image.
and there is something strange: here are some loading time from my browser:

index.php?module=Dashboard&action=embeddedIndex&idDashboard=1&idSite=1&period=day&date=yesterday&showtitle=1&random=2038
89 ms
index.php?date=yesterday&module=Live&action=widget&widget=1&idSite=1&period=day
138 ms
index.php?date=yesterday&module=Referrers&action=getSearchEngines&widget=1&isFooterExpandedInDashboard=true&viewDataTable=graphPie&columns[]=nb_visits&columns_to_display[]=nb_visits&idSite=1&period=day
175915 ms
index.php?date=yesterday&module=DevicesDetection&action=getBrowsers&widget=1&idSite=1&period=day
175941 ms
index.php?date=yesterday&module=UserCountryMap&action=visitorMap&widget=1&idSite=1&period=day
117700 ms
index.php?date=yesterday&module=VisitsSummary&action=getEvolutionGraph&columns[]=nb_visits&columns[]=nb_uniq_visitors&columns[]=nb_pageviews&columns[]=nb_keywords&widget=1&columns_to_display[]=nb_visits&columns_to_display[]=nb_uniq_visitors&columns_to_display[]=nb_pageviews&columns_to_display[]=nb_keywords&forceView=1&viewDataTable=graphEvolution&idSite=1&period=day
58650 ms
index.php?date=yesterday&module=Referrers&action=getWebsites&widget=1&idSite=1&period=day
58598 ms

So it looks like, there is something that prevent php to execute during ~58s.

I have the cron activated, the dashboard generation is off. I moved MySQL to SSD, it doesn’t help. I checked mysql, and it looks like idle. The server cpu, memory and swap are fine.
I put the site behind a login wall, to see if somebody was maybe hammering some endpoints, but didn’t change anything.
I tried with the apache version of the docker image, still the same.
I also tried the nginx config recommended, no luck.
I cleaned the database of data older than 6months (now the db size is ~600MB).

I activated custom variables, and conversion tracking some months ago, so this could be it?
But where is this php spending time? And why 58s? It looks like a timeout to me, but actually, I get the result after 58s.

If you could tell me how to activate more logging, I’d be really happy!


(Richard) #2

Hey,
It is just a suggestion, but you may experience the downside of not caching reports - if these loading times occur everytime you reload your dashboard, then that would be an indicator that the needed reports are re-calculated instead of fetched from a cache.
This shouldn’t happen, since yesterdays reports will not change, so you shoud get to see quick loading reports from the cache after having processed them once.
To access the report cache settings, see Recalulate data for goal graph
Long loading times on the very first request for a certain period can take that long if there is a lot of data to evaluate, that really depends on your server capacities.


(Pierre Ozoux) #3

This is already configured.
This morning, I installed redis, and configured it to be the main cache, but still the same issue.
I’m sure there is a timeout somewhere. Something that takes ~50s to timeout.


#4

I have the cron activated, the dashboard generation is off.

Just to be sure by this you mean the browser archiving is disabled?


(Peterbo) #5

Which version are you on exactly? Does this happen on every pageload in the Piwik backend or just sometimes / arbitrarily? I have experienced similar issues as well, so it would be very interesting to get to the bottom of this.


(Pierre Ozoux) #6

@thomas_matomo yes the browser archiving is disabled.
@peterbo I have the latest version.

I experience this everywhere where there is a graph to display.


(Matthieu Aubry) #7

Hi Pierre,
I have couple questions

  1. What is the content of your config.ini.php (please remove all passwords/salt/hostnames)

  2. Do you always get approximately 55-60s wait? or is it sometimes 30s or less, or more?


(Pierre Ozoux) #8

Thanks for offering help!
Yes, always ~55s.
I’ll actually try to update an other piwik that I have, I think it doesn’t have this issue, and the setup is the same.
I’ll try to update each version and see if I can pin the problem to one version. (I’m not sure, but I think it is worth trying)

; <?php exit; ?> DO NOT REMOVE THIS LINE
; file automatically generated or modified by Matomo; you can manually override the default values in global.ini.php by redefining them in this file.
[database]
host = "db"
dbname = "piwik"
tables_prefix = "piwik_"

[General]
session_save_handler = "dbtable"
noreply_email_address = "stats@indie.host"
proxy_client_headers[] = "HTTP_X_FORWARDED_FOR"
trusted_hosts[] = "stats.indie.host"

[mail]
transport = "smtp"
port = 587
host = "mail.indie.host"
type = "Plain"
username = "stats@indie.host"
encryption = "tls"

[Cache]
backend = redis

[RedisCache]
host = "redis"
port = 6379
timeout = 0.0
password = ""
database = 14
; In case you are using queued tracking: Make sure to configure a different database! Otherwise queued requests might
; be flushed

[Plugins]
Plugins[] = "CorePluginsAdmin"
Plugins[] = "CoreAdminHome"
Plugins[] = "CoreHome"
Plugins[] = "WebsiteMeasurable"
Plugins[] = "Diagnostics"
Plugins[] = "CoreVisualizations"
Plugins[] = "Proxy"
Plugins[] = "API"
Plugins[] = "Widgetize"
Plugins[] = "Transitions"
Plugins[] = "LanguagesManager"
Plugins[] = "Actions"
Plugins[] = "Dashboard"
Plugins[] = "MultiSites"
Plugins[] = "Referrers"
Plugins[] = "UserLanguage"
Plugins[] = "DevicesDetection"
Plugins[] = "Goals"
Plugins[] = "Ecommerce"
Plugins[] = "SEO"
Plugins[] = "Events"
Plugins[] = "UserCountry"
Plugins[] = "VisitsSummary"
Plugins[] = "VisitFrequency"
Plugins[] = "VisitTime"
Plugins[] = "VisitorInterest"
Plugins[] = "RssWidget"
Plugins[] = "Feedback"
Plugins[] = "Monolog"
Plugins[] = "Login"
Plugins[] = "UsersManager"
Plugins[] = "SitesManager"
Plugins[] = "Installation"
Plugins[] = "CoreUpdater"
Plugins[] = "CoreConsole"
Plugins[] = "ScheduledReports"
Plugins[] = "UserCountryMap"
Plugins[] = "Live"
Plugins[] = "PrivacyManager"
Plugins[] = "ImageGraph"
Plugins[] = "Annotations"
Plugins[] = "Overlay"
Plugins[] = "Insights"
Plugins[] = "Morpheus"
Plugins[] = "Contents"
Plugins[] = "BulkTracking"
Plugins[] = "Resolution"
Plugins[] = "DevicePlugins"
Plugins[] = "Heartbeat"
Plugins[] = "Intl"
Plugins[] = "UserId"
Plugins[] = "CustomPiwikJs"
Plugins[] = "Provider"

[PluginsInstalled]
PluginsInstalled[] = "Login"
PluginsInstalled[] = "CoreAdminHome"
PluginsInstalled[] = "Monolog"
PluginsInstalled[] = "Intl"
PluginsInstalled[] = "CorePluginsAdmin"
PluginsInstalled[] = "CoreHome"
PluginsInstalled[] = "WebsiteMeasurable"
PluginsInstalled[] = "CoreVisualizations"
PluginsInstalled[] = "Proxy"
PluginsInstalled[] = "API"
PluginsInstalled[] = "Widgetize"
PluginsInstalled[] = "Transitions"
PluginsInstalled[] = "LanguagesManager"
PluginsInstalled[] = "Actions"
PluginsInstalled[] = "Dashboard"
PluginsInstalled[] = "MultiSites"
PluginsInstalled[] = "Referrers"
PluginsInstalled[] = "Events"
PluginsInstalled[] = "UserCountry"
PluginsInstalled[] = "VisitsSummary"
PluginsInstalled[] = "VisitFrequency"
PluginsInstalled[] = "VisitTime"
PluginsInstalled[] = "VisitorInterest"
PluginsInstalled[] = "CoreConsole"
PluginsInstalled[] = "ImageGraph"
PluginsInstalled[] = "Annotations"
PluginsInstalled[] = "SegmentEditor"
PluginsInstalled[] = "Insights"
PluginsInstalled[] = "Morpheus"
PluginsInstalled[] = "Contents"
PluginsInstalled[] = "Heartbeat"
PluginsInstalled[] = "UserId"
PluginsInstalled[] = "CustomPiwikJs"
PluginsInstalled[] = "Diagnostics"
PluginsInstalled[] = "ExamplePlugin"
PluginsInstalled[] = "UserLanguage"
PluginsInstalled[] = "DevicesDetection"
PluginsInstalled[] = "Goals"
PluginsInstalled[] = "Ecommerce"
PluginsInstalled[] = "SEO"
PluginsInstalled[] = "ExampleAPI"
PluginsInstalled[] = "RssWidget"
PluginsInstalled[] = "Feedback"
PluginsInstalled[] = "UsersManager"
PluginsInstalled[] = "SitesManager"
PluginsInstalled[] = "Installation"
PluginsInstalled[] = "CoreUpdater"
PluginsInstalled[] = "ScheduledReports"
PluginsInstalled[] = "UserCountryMap"
PluginsInstalled[] = "Live"
PluginsInstalled[] = "PrivacyManager"
PluginsInstalled[] = "MobileMessaging"
PluginsInstalled[] = "Overlay"
PluginsInstalled[] = "BulkTracking"
PluginsInstalled[] = "Resolution"
PluginsInstalled[] = "DevicePlugins"
PluginsInstalled[] = "Marketplace"
PluginsInstalled[] = "ProfessionalServices"
PluginsInstalled[] = "DBStats"
PluginsInstalled[] = "Provider"

(Pierre Ozoux) #9

I found the issue…

This is the responsible commit:

And a friend of mine noticed the same on a rather modern rails app:

So now, the question is why ajax call fails on HAProxy when http2 is activated?
I’ll investigate on my side, but if you have ideas, I’d gladly take them :slight_smile:


(Pierre Ozoux) #10

There was a bug in HAProxy.

Updating to latest fixed the issue!