Out of Memory - process "analog"

Support & Bugs
1

Hello Piwik team,
I would like to ask what I can do with my Piwik install(s) as we have two running on one domain it is kind of hard too know what install is causing the issue, but mainly they are setup the same way.

For some reason it seems that sometimes the serverload on my cPanel Server is skyrocketing, until it reaches level near where the server gets unresponsive.

In the night it happened again, this time it was an OOM for the process “analog”.
Process Total Virtual Memory: 3451900kB
Process Anonymous Resident Set Size: 253512kB
Process File Resident Set Size: 28kB
Process OOM Score: 437
Memory Used: 3.57 GB
Memory Available: 124 MB
Memory Installed: 3.69 GB
Load Information: 193.18 115.88 50.84
[1637172.799637] [28859] 99 28859 1535 11 0 0 0 suphp
[1637172.799639] [28860] 99 28860 1535 11 1 0 0 suphp
[1637172.799641] [28861] 0 28861 40751 2579 1 0 0 child - abortin
[1637172.799644] [28862] 0 28862 40751 2582 1 0 0 lfd - (child) c
[1637172.799646] [28863] 99 28863 1535 10 1 0 0 suphp
[1637172.799648] [28864] 99 28864 1535 11 1 0 0 suphp
[1637172.799650] [28866] 99 28866 1535 10 0 0 0 suphp
[1637172.799652] [28867] 97 28867 7462 81 1 0 0 auth
[1637172.799655] Out of memory: Kill process 25331 (analog) score 437 or sacrifice child
[1637172.799676] Killed process 25331, UID 621, (analog) total-vm:3451900kB, anon-rss:253512kB, file-rss:28kB

Shortly after that came an other message:
Notification Type: hang ???
Service: chkservd
Memory Used: 3.41 GB
Memory Available: 292 MB
Memory Installed: 3.69 GB
Load Information: 308.09 276.88 177.28

Both install use the stable release and are up to date.

Piwik 1
Visits: ~18.500
Pageviews: ~32.500
Settings: Archive if shown in Browser: Yes, archive every 10 Seconds (needs to be changed to 3600)
Delete old Logs: Yes + Delete if older than 30 days
Remove old Archives: Yes + Remove if older than 3 Month, keep basic stats
Keep Data for Yearly + Monthly
Removal of old Data: Weekly
Database Size: 1,2G

Piwik 2
Visits: ~4.500
Pageviews: ~12.000
Settings: Archive if shown in Browser: Yes, archive every 3600 Seconds
Delete old Logs: Yes + Delete if older than 30 days
Remove old Archives: Yes + Remove if older than 3 Month, keep basic stats
Keep Data for Yearly + Monthly
Removal of old Data: Weekly
Database Size: 314.3M

So I guess it will properbly the more huge one that causes the problem, will it be solved by simply changing the Settings to archive every 3600 seconds?! … That would be kind of strange, as the problems were when noone used Piwik, so no achiving was started (thats how I understood it at least, Archiving only if Piwik opened with Browser)

Having every now and then the server load up to the point where nothing goes anymore isn’t really what I wanted, so every help is really appreciated!

2

I suggest setting up cron archiving: How to Set up Auto-Archiving of Your Reports - Analytics Platform - Matomo
This will allow you to check the output. It also gives you full control over the timing (when the archiving process starts).

3

I had set for all counters a Cron now that should run every 12 hours. Result was that the past two days the counted Users dropped by 30 and 20 Percent.

0 0,12 * * * /usr/local/bin/php -f /home/XXXXXXXX/public_html/analytics/console core:archive --url=analytics.XXXXXXXX.com > /home/XXXXXXXX/public_html/analytics/log/piwik-archive-output.log

I have changed just now the Cronjob to every hour, to see if that makes any difference. But it seems really like there is something wrong? The code should fit, as the log is generated successfully in all Piwik Installs.

Suggestions are highly welcome!

----------------------SHORTENED LOG--------------------

The Log looks a bit like this, I have shortened it a bit, as it was 900+ Lines:
INFO [2016-03-18 11:00:01] --------------------------- INFO [2016-03-18 11:00:01] INIT INFO [2016-03-18 11:00:01] Running Piwik 2.16.0 as Super User INFO [2016-03-18 11:00:01] --------------------------- INFO [2016-03-18 11:00:01] NOTES INFO [2016-03-18 11:00:01] - Reports for today will be processed at most every 3600 seconds. You can change this value in Piwik UI > Settings > General Settings. INFO [2016-03-18 11:00:01] - Reports for the current week/month/year will be refreshed at most every 3600 seconds. INFO [2016-03-18 11:00:01] - Archiving was last executed without error 11 hours 55 min ago INFO [2016-03-18 11:00:01] Will invalidate archived reports for 2016-03-18 for following websites ids: 108,124,12,137,138,139,140,141,142,1,20,25,26,28,29,37,48,55,5,67,69,6,71,72,73,77,78,79,81,83,84,86,91 INFO [2016-03-18 11:00:03] - Will process 35 other websites because some old data reports have been invalidated (eg. using the Log Import script) , IDs: 25, 66, 78, 130, 137, 141, 108, 124, 12, 138, 139, 140, 142, 1, 20, 26, 28, 29, 37, 48, 55, 5, 67, 69, 6, 71, 72, 73, 77, 79, 81, 83, 84, 86, 91 INFO [2016-03-18 11:00:03] --------------------------- INFO [2016-03-18 11:00:03] START INFO [2016-03-18 11:00:03] Starting Piwik reports archiving... INFO [2016-03-18 11:00:03] Old report was invalidated for website id 1 INFO [2016-03-18 11:00:03] Will pre-process for website id = 1, period = day, date = last52 INFO [2016-03-18 11:00:03] - pre-processing all visits INFO [2016-03-18 11:00:05] Archived website id = 1, period = day, 0 segments, 0 visits in last 52 days, 0 visits today, Time elapsed: 1.937s INFO [2016-03-18 11:00:05] Will pre-process for website id = 1, period = week, date = last2 INFO [2016-03-18 11:00:05] - pre-processing all visits INFO [2016-03-18 11:00:06] Archived website id = 1, period = week, 0 segments, 1414 visits in last 2 weeks, 596 visits this week, Time elapsed: 1.438s INFO [2016-03-18 11:00:06] Will pre-process for website id = 1, period = month, date = last2 INFO [2016-03-18 11:00:06] - pre-processing all visits INFO [2016-03-18 11:00:13] Archived website id = 5, period = year, 0 segments, 1654 visits in last 2 years, 1654 visits this year, Time elapsed: 1.002s INFO [2016-03-18 11:00:13] Archived website id = 5, 4 API requests, Time elapsed: 4.131s [2/72 done] INFO [2016-03-18 11:00:14] Old report was invalidated for website id 6 INFO [2016-03-18 11:00:14] Will pre-process for website id = 6, period = day, date = last52 INFO [2016-03-18 11:00:14] - pre-processing all visits INFO [2016-03-18 11:00:15] Archived website id = 6, period = day, 0 segments, 0 visits in last 52 days, 0 visits today, Time elapsed: 1.389s INFO [2016-03-18 11:00:15] Will pre-process for website id = 6, period = week, date = last2 INFO [2016-03-18 11:00:15] - pre-processing all visits INFO [2016-03-18 11:00:21] Archived website id = 6, period = year, 0 segments, 28329 visits in last 2 years, 28329 visits this year, Time elapsed: 2.034s INFO [2016-03-18 11:00:21] Archived website id = 6, 4 API requests, Time elapsed: 7.177s [3/72 done] INFO [2016-03-18 11:00:21] - no new tracking data for website id 7 (between 2016-03-17 23:04:56 and 2016-03-18 12:00:21) INFO [2016-03-18 11:00:21] Skipped website id 7 as archiving is not needed INFO [2016-03-18 11:00:21] - tracking data found for website id 11 (between 2016-03-17 23:04:56 and 2016-03-18 12:00:21) INFO [2016-03-18 11:00:21] Will pre-process for website id = 11, period = day, date = last2 INFO [2016-03-18 11:00:21] - pre-processing all visits INFO [2016-03-18 11:00:28] Archived website id = 12, period = month, 0 segments, 4032 visits in last 2 months, 1551 visits this month, Time elapsed: 1.395s INFO [2016-03-18 11:00:28] Will pre-process for website id = 12, period = year, date = last2 INFO [2016-03-18 11:00:28] - pre-processing all visits INFO [2016-03-18 11:04:46] Archived website id = 142, period = month, 0 segments, 911 visits in last 2 months, 331 visits this month, Time elapsed: 0.952s INFO [2016-03-18 11:04:46] Will pre-process for website id = 142, period = year, date = last2 INFO [2016-03-18 11:04:46] - pre-processing all visits INFO [2016-03-18 11:04:47] Archived website id = 142, period = year, 0 segments, 1644 visits in last 2 years, 1644 visits this year, Time elapsed: 0.848s INFO [2016-03-18 11:04:47] Archived website id = 142, 4 API requests, Time elapsed: 3.727s [71/72 done] INFO [2016-03-18 11:04:47] - no new tracking data for website id 143 (between 2016-03-17 23:04:56 and 2016-03-18 12:04:47) INFO [2016-03-18 11:04:47] Skipped website id 143 as archiving is not needed INFO [2016-03-18 11:04:47] Done archiving! INFO [2016-03-18 11:04:47] --------------------------- INFO [2016-03-18 11:04:47] SUMMARY INFO [2016-03-18 11:04:47] Total visits for today across archived websites: 5004 INFO [2016-03-18 11:04:47] Archived today's reports for 59 websites INFO [2016-03-18 11:04:47] Archived week/month/year for 59 websites INFO [2016-03-18 11:04:47] Skipped 13 websites INFO [2016-03-18 11:04:47] - 13 skipped because no new visit since the last script execution INFO [2016-03-18 11:04:47] - 0 skipped because existing daily reports are less than 3600 seconds old INFO [2016-03-18 11:04:47] - 0 skipped because existing week/month/year periods reports are less than 3600 seconds old INFO [2016-03-18 11:04:47] Total API requests: 236 INFO [2016-03-18 11:04:47] done: 59/72 82%, 5004 vtoday, 59 wtoday, 59 wperiods, 236 req, 284088 ms, no error INFO [2016-03-18 11:04:47] Time elapsed: 284.089s INFO [2016-03-18 11:04:47] --------------------------- INFO [2016-03-18 11:04:47] SCHEDULED TASKS INFO [2016-03-18 11:04:47] Starting Scheduled tasks... INFO [2016-03-18 11:04:47] Scheduler: executing task Piwik\Plugins\CoreAdminHome\Tasks.purgeOutdatedArchives... INFO [2016-03-18 11:04:47] Purging archives in 102 archive tables. INFO [2016-03-18 11:04:47] Deleted 201 rows in archive tables (numeric + blob) for 2016-01-15. INFO [2016-03-18 11:04:52] Deleted 25404 rows in archive tables (numeric + blob) for 2016-03-15. INFO [2016-03-18 11:04:52] Scheduler: finished. Time elapsed: 5.041s INFO [2016-03-18 11:04:52] Scheduler: executing task Piwik\Plugins\UsersManager\Tasks.setUserDefaultReportPreference... INFO [2016-03-18 11:04:52] Scheduler: finished. Time elapsed: 0.004s INFO [2016-03-18 11:04:52] Scheduler: executing task Piwik\Plugins\CoreAdminHome\Tasks.purgeInvalidatedArchives... INFO [2016-03-18 11:04:52] Found 823 invalidated archives safe to delete in piwik_archive_numeric_2016_03. INFO [2016-03-18 11:04:57] Found 296 invalidated archives safe to delete in piwik_archive_numeric_2016_01. INFO [2016-03-18 11:05:01] Scheduler: finished. Time elapsed: 8.873s INFO [2016-03-18 11:05:01] Scheduler: executing task Piwik\Plugins\PrivacyManager\Tasks.deleteReportData... INFO [2016-03-18 11:05:01] Scheduler: finished. Time elapsed: 0.007s INFO [2016-03-18 11:05:01] Scheduler: executing task Piwik\Plugins\PrivacyManager\Tasks.deleteLogData... INFO [2016-03-18 11:05:01] Scheduler: finished. Time elapsed: 0.001s INFO [2016-03-18 11:05:01] Scheduler: executing task Piwik\Plugins\CorePluginsAdmin\Tasks.clearAllCacheEntries... INFO [2016-03-18 11:05:01] Scheduler: finished. Time elapsed: 0.084s INFO [2016-03-18 11:05:01] Scheduler: executing task Piwik\Plugins\CorePluginsAdmin\Tasks.sendNotificationIfUpdatesAvailable... INFO [2016-03-18 11:05:01] Scheduler: finished. Time elapsed: 0.001s INFO [2016-03-18 11:05:01] Scheduler: executing task Piwik\Plugins\CoreAdminHome\Tasks.optimizeArchiveTable... INFO [2016-03-18 11:05:01] Scheduler: finished. Time elapsed: 0.327s INFO [2016-03-18 11:05:01] Scheduler: executing task Piwik\Plugins\CoreUpdater\Tasks.sendNotificationIfUpdateAvailable... INFO [2016-03-18 11:05:01] Scheduler: finished. Time elapsed: 0.001s INFO [2016-03-18 11:05:01] done INFO [2016-03-18 11:05:01] ---------------------------

Edit: It seems like the change to hourly Cron ‘helped’ somewhat… It seems like I would hae to fine either the right time to have the Cron running like an hour before I usually check, or I have to let it run hourly to have more like realtime stats…
All i have to hope now is that the spikes in serverload are now gone.

4

Well, there it was again, the usual Server OOM Process Shutdown Kill byebye…

Normal Values
Server Load: 0.623535 (2 CPUs)
Ram Usage: 28.82% (1,115,448 of 3,870,880)
Swap Used: 10.21% (409,800 of 4,014,072)

OOM With
Server Load: 88.23 62.43 29.05
Memory Used: 3.45 G of 3.69 GB

Looking further into a solution I came across… Redis Server + Extension and the QueuedTracking Plugin.

I have asked the guys from assistanz if they are able to get it up and running on my cPanel server, so that I can try to use this to help fight the Problems I have.

That would mean that Piwik eats up ~2.6G Ram when it is processing all logs from a day?

Does someone could give me any advice here?

Kind Regards

Edit: On Server 1 it got already added and seems to be running (unchanged Settings besides of enabling the Queue) Server 2 will follow in some moments.