Segment processing seems to always start from beginning of time

rmoesbergen · August 28, 2015, 6:24am

Hi,

In our piwik archiving logs I found this:

DEBUG [2015-08-28 05:00:55] Earliest created time of segment ‘customVariableName1==Not-Bot’ w/ idSite = 8 is found to be 2015-05-21.
DEBUG [2015-08-28 05:00:55] process_new_segments_from set to beginning_of_time or cannot recognize value
DEBUG [2015-08-28 05:00:55] Earliest created time of segment ‘customVariableName1==Bot’ w/ idSite = 8 is found to be 2015-06-08.
DEBUG [2015-08-28 05:00:55] process_new_segments_from set to beginning_of_time or cannot recognize value

I read this as: piwik is trying to determine where in time it should start processing new visits for a certain segment. It finds the right date, but somehow the next step ‘cannot recognize value’, and start over from the beginning of time. Since this is a pretty large site (around 1,5M pageviews per day), processing takes > 12 hours and eats up 40G of memory… is this a bug? The job is purely cpu-bound, almost no mysql processing, the php jobs take up all the memory and cpu time.

matthieu · September 15, 2015, 4:12am

Hi there,

Feel free to try again installing with the latest 2.15.0 beta version which includes many fixes and improvements, see: I would like to test early beta and RC releases, how do I enable automatic updates to use these development versions? - Analytics Platform - Matomo

If you still have a problem, please create an issue on our tracker GitHub - matomo-org/piwik: Liberating Web Analytics. Star us on Github? +1. Matomo is the leading open alternative to Google Analytics that gives you full control over your data. Matomo lets you easily collect data from websites, apps & the IoT and visualise this data and extract insights. Privacy is built-in. We love Pull Requests!

rmoesbergen · December 14, 2015, 8:08am

Hi,

We temporarily worked around this issue by adding (much) more memory to the machine. We’re currently at 96GB used for the archive run process. Why is piwik archiving eating up such enormous amounts of memory? Today, even with 96GB of memory and php memory_limit set to ‘-1’, we still get this error:

ERROR [2015-12-13 23:58:25] Got invalid response from API request: ?module=API&method=API.get&idSite=8&period=year&date=last3&format=php&trigger=archivephp. The response was empty. This usually means a server error. This solution to this error is generally to increase the value of ‘memory_limit’ in your php.ini file. Please check your Web server Error Log file for more details.
ERROR [2015-12-14 05:47:17] 1 total errors during this script execution, please investigate and try and fix these errors.

Also in the kernel logging we can see:
[1582438.409156] Out of memory: Kill process 2405 (php) score 243 or sacrifice child
[1582438.409255] Killed process 2405, UID 0, (php) total-vm:28264828kB, anon-rss:27341440kB, file-rss:36kB

rmoesbergen · December 14, 2015, 8:10am

Forgot to mention we’ve upgraded to version 2.15.0

MeTRoPoL · December 16, 2015, 9:21pm

Forgot to mention we’ve upgraded to version 2.15.0

Thank You…

matthieu · December 23, 2015, 1:21am

Yes segments are processed since beginning of time, this is the system default in Piwik, see: piwik/global.ini.php at 2.15.0 · matomo-org/piwik · GitHub

it can be customised in your config file

rmoesbergen · January 4, 2016, 7:51am

Hi Matthieu,
I found this setting and had already set it to:

process_new_segments_from = “segment_creation_time”

Still, the archiving process uses >96GB of memory. What can I do to reduce the amount of memory used?

matthieu · January 18, 2016, 1:29am

How many visits/actions do you get per month?

What PHP version do you use?

rmoesbergen · January 18, 2016, 7:42am

In December we had:

Total: 5,305,303 visits, 138,933,739 pageviews, 134,424,868 actions

November:
Total: 4,112,026 visits, 144,533,077 pageviews, 139,780,378 actions

I’m using PHP 5.6.10

matthieu · January 26, 2016, 4:07am

Could you paste here the output of your ./console core:archive command? (stripping awayany possible sensitive info)

rmoesbergen · January 26, 2016, 8:14am

The total output for all sites is 800Kb, so I’ll just paste the output for the site that takes the most time/resources:

INFO [2016-01-25 17:00:01] ---------------------------
INFO [2016-01-25 17:00:01] INIT
INFO [2016-01-25 17:00:01] Running Piwik 2.15.0 as Super User
INFO [2016-01-25 17:00:01] ---------------------------
INFO [2016-01-25 17:00:01] NOTES
INFO [2016-01-25 17: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-01-25 17:00:01] - Reports for the current week/month/year will be refreshed at most every 3600 seconds.
INFO [2016-01-25 17:00:01] - Archiving was last executed without error 6 hours 55 min ago
INFO [2016-01-25 17:00:01] ---------------------------
INFO [2016-01-25 17:00:01] START
INFO [2016-01-25 17:00:01] Starting Piwik reports archiving…
…
INFO [2016-01-25 17:01:09] - tracking data found for website id 8 (between 2016-01-25 10:04:48 and 2016-01-25 18:01:09)
INFO [2016-01-25 17:01:09] Will pre-process for website id = 8, period = day, date = last2
INFO [2016-01-25 17:01:09] - pre-processing all visits
DEBUG [2016-01-25 17:01:09] /usr/local/php56/bin/php -q /var/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=day&date=last2&format=php&trigger=archivephp&pid=a9e62afaa61547e185640f912abfb332fd8777230e8c7a2b1e51afc3966361ef4b58351556fd6ec0df46f0a2afd926f5c5ee0’ > /var/www/piwik/html/tmp/climulti/a9e62afaa61547e185640f912abfb332fd8777230e8c7a2b1e51afc3966361ef4b58351556fd6ec0df46f0a2afd926f5c5ee0.output 2>&1 &
DEBUG [2016-01-25 17:07:32] Earliest created time of segment ‘customVariableName1==Not-Bot’ w/ idSite = 8 is found to be 2015-05-21. Latest edit time is found to be 2015-11-23.
DEBUG [2016-01-25 17:07:32] process_new_segments_from set to segment_creation_time, oldest date to process is 2015-05-21
DEBUG [2016-01-25 17:07:32] Earliest created time of segment ‘customVariableName1==Bot’ w/ idSite = 8 is found to be 2015-06-08. Latest edit time is found to be 2015-12-23.
DEBUG [2016-01-25 17:07:32] process_new_segments_from set to segment_creation_time, oldest date to process is 2015-06-08
INFO [2016-01-25 17:07:32] - pre-processing segment 1/2 customVariableName1==Not-Bot
DEBUG [2016-01-25 17:07:33] /usr/local/php56/bin/php -q /var/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=day&date=last2&format=php&segment=customVariableName1%3D%3DNot-Bot&trigger=archivephp&pid=1246537fb094504e02031af8b1c5e84740c76fead4be1a80ac77faa685f534eac81d6a674074a66f96fff32fa866cb30c73c0’ > /var/www/piwik/html/tmp/climulti/1246537fb094504e02031af8b1c5e84740c76fead4be1a80ac77faa685f534eac81d6a674074a66f96fff32fa866cb30c73c0.output 2>&1 &
INFO [2016-01-25 17:07:33] - pre-processing segment 2/2 customVariableName1==Bot
DEBUG [2016-01-25 17:07:33] /usr/local/php56/bin/php -q /var/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=day&date=last2&format=php&segment=customVariableName1%3D%3DBot&trigger=archivephp&pid=09adfe7cd2c8708bf3dfd32bc5563d08804107b72d95799ca9e51e3adb58f1f9dbc26a7988981c4a21cdef480ba378633f961’ > /var/www/piwik/html/tmp/climulti/09adfe7cd2c8708bf3dfd32bc5563d08804107b72d95799ca9e51e3adb58f1f9dbc26a7988981c4a21cdef480ba378633f961.output 2>&1 &
INFO [2016-01-25 17:12:13] Archived website id = 8, period = day, 2 segments, 0 visits in last 2 days, 0 visits today, Time elapsed: 663.538s
INFO [2016-01-25 17:12:13] Will pre-process for website id = 8, period = week, date = last2
INFO [2016-01-25 17:12:13] - pre-processing all visits
DEBUG [2016-01-25 17:12:13] Earliest created time of segment ‘customVariableName1==Not-Bot’ w/ idSite = 8 is found to be 2015-05-21. Latest edit time is found to be 2015-11-23.
DEBUG [2016-01-25 17:12:13] process_new_segments_from set to segment_creation_time, oldest date to process is 2015-05-21
DEBUG [2016-01-25 17:12:13] Earliest created time of segment ‘customVariableName1==Bot’ w/ idSite = 8 is found to be 2015-06-08. Latest edit time is found to be 2015-12-23.
DEBUG [2016-01-25 17:12:13] process_new_segments_from set to segment_creation_time, oldest date to process is 2015-06-08
DEBUG [2016-01-25 17:12:13] /usr/local/php56/bin/php -q /var/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=week&date=last2&format=php&trigger=archivephp&pid=187835b4d60197bfec813257f50b215f66cb9fcf60305ce526d9657bedad19847e48d7c0ddfe403638d1df8f121bc075ee6c0’ > /var/www/piwik/html/tmp/climulti/187835b4d60197bfec813257f50b215f66cb9fcf60305ce526d9657bedad19847e48d7c0ddfe403638d1df8f121bc075ee6c0.output 2>&1 &
INFO [2016-01-25 17:12:13] - pre-processing segment 1/2 customVariableName1==Not-Bot
DEBUG [2016-01-25 17:12:13] /usr/local/php56/bin/php -q /var/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=week&date=last2&format=php&segment=customVariableName1%3D%3DNot-Bot&trigger=archivephp&pid=ca98117d66967ad7396fa64ee7e08ff61a41a44279f2af30579f9d71a2fe6d881876387b2de226f7de4d027f279178777d561’ > /var/www/piwik/html/tmp/climulti/ca98117d66967ad7396fa64ee7e08ff61a41a44279f2af30579f9d71a2fe6d881876387b2de226f7de4d027f279178777d561.output 2>&1 &
INFO [2016-01-25 17:12:13] - pre-processing segment 2/2 customVariableName1==Bot
DEBUG [2016-01-25 17:12:13] /usr/local/php56/bin/php -q /var/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=week&date=last2&format=php&segment=customVariableName1%3D%3DBot&trigger=archivephp&pid=a4908780a1b42e4e4e16e46ca0f3a3bf397d5c12ee6f445388eb52315c119c5d8093d5669b3f2a5678451c6d62359f6d5de12’ > /var/www/piwik/html/tmp/climulti/a4908780a1b42e4e4e16e46ca0f3a3bf397d5c12ee6f445388eb52315c119c5d8093d5669b3f2a5678451c6d62359f6d5de12.output 2>&1 &
INFO [2016-01-25 17:12:25] Archived website id = 8, period = week, 2 segments, 366883 visits in last 2 weeks, 33350 visits this week, Time elapsed: 12.508s
INFO [2016-01-25 17:12:25] Will pre-process for website id = 8, period = month, date = last2
INFO [2016-01-25 17:12:25] - pre-processing all visits
DEBUG [2016-01-25 17:12:25] Earliest created time of segment ‘customVariableName1==Not-Bot’ w/ idSite = 8 is found to be 2015-05-21. Latest edit time is found to be 2015-11-23.
DEBUG [2016-01-25 17:12:25] process_new_segments_from set to segment_creation_time, oldest date to process is 2015-05-21
DEBUG [2016-01-25 17:12:25] Earliest created time of segment ‘customVariableName1==Bot’ w/ idSite = 8 is found to be 2015-06-08. Latest edit time is found to be 2015-12-23.
DEBUG [2016-01-25 17:12:25] process_new_segments_from set to segment_creation_time, oldest date to process is 2015-06-08
DEBUG [2016-01-25 17:12:25] /usr/local/php56/bin/php -q /var/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=month&date=last2&format=php&trigger=archivephp&pid=6ab0506cd54c8663494d4757a51f963274871ea24a659278d6ff436ecb42bfa4ff00fb450ef44e92a7e456505b6095fd34110’ > /var/www/piwik/html/tmp/climulti/6ab0506cd54c8663494d4757a51f963274871ea24a659278d6ff436ecb42bfa4ff00fb450ef44e92a7e456505b6095fd34110.output 2>&1 &
INFO [2016-01-25 17:12:25] - pre-processing segment 1/2 customVariableName1==Not-Bot
DEBUG [2016-01-25 17:12:25] /usr/local/php56/bin/php -q /var/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=month&date=last2&format=php&segment=customVariableName1%3D%3DNot-Bot&trigger=archivephp&pid=618afbf1e707619836b26febfbbf95936a30e8e15b5943b5792cc43ef18896d6b6a468caa0836db57673aa2c496dc100fd7a1’ > /var/www/piwik/html/tmp/climulti/618afbf1e707619836b26febfbbf95936a30e8e15b5943b5792cc43ef18896d6b6a468caa0836db57673aa2c496dc100fd7a1.output 2>&1 &
INFO [2016-01-25 17:12:25] - pre-processing segment 2/2 customVariableName1==Bot
DEBUG [2016-01-25 17:12:25] /usr/local/php56/bin/php -q /var/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=month&date=last2&format=php&segment=customVariableName1%3D%3DBot&trigger=archivephp&pid=d3d6338d6f40a541e7b4aace90fd483b46b6f3f35aa57545060141cf5edec10f4b245d833fa352518eca850f6ddba4d1a4d32’ > /var/www/piwik/html/tmp/climulti/d3d6338d6f40a541e7b4aace90fd483b46b6f3f35aa57545060141cf5edec10f4b245d833fa352518eca850f6ddba4d1a4d32.output 2>&1 &
INFO [2016-01-25 18:08:16] Archived website id = 8, period = month, 2 segments, 2173159 visits in last 2 months, 1042044 visits this month, Time elapsed: 3351.397s
INFO [2016-01-25 18:08:16] Will pre-process for website id = 8, period = year, date = last2
INFO [2016-01-25 18:08:16] - pre-processing all visits
DEBUG [2016-01-25 18:08:16] Earliest created time of segment ‘customVariableName1==Not-Bot’ w/ idSite = 8 is found to be 2015-05-21. Latest edit time is found to be 2015-11-23.
DEBUG [2016-01-25 18:08:16] process_new_segments_from set to segment_creation_time, oldest date to process is 2015-05-21
DEBUG [2016-01-25 18:08:16] Start date of archiving request period (2015-01-01) is older than configured oldest date to process for the segment.
DEBUG [2016-01-25 18:08:16] Archiving request date range changed to 2015-05-21,2016-12-31 w/ period year.
DEBUG [2016-01-25 18:08:16] Earliest created time of segment ‘customVariableName1==Bot’ w/ idSite = 8 is found to be 2015-06-08. Latest edit time is found to be 2015-12-23.
DEBUG [2016-01-25 18:08:16] process_new_segments_from set to segment_creation_time, oldest date to process is 2015-06-08
DEBUG [2016-01-25 18:08:16] Start date of archiving request period (2015-01-01) is older than configured oldest date to process for the segment.
DEBUG [2016-01-25 18:08:16] Archiving request date range changed to 2015-06-08,2016-12-31 w/ period year.
DEBUG [2016-01-25 18:08:16] /usr/local/php56/bin/php -q /var/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=year&date=last2&format=php&trigger=archivephp&pid=1eb93b0531309179c8426b147a45a74378847e5f06575c1d1e97401ffc287ce51c2cb8450454c2b9e91a1918dd8ac68c68300’ > /var/www/piwik/html/tmp/climulti/1eb93b0531309179c8426b147a45a74378847e5f06575c1d1e97401ffc287ce51c2cb8450454c2b9e91a1918dd8ac68c68300.output 2>&1 &
INFO [2016-01-25 18:08:16] - pre-processing segment 1/2 customVariableName1==Not-Bot
DEBUG [2016-01-25 18:08:17] /usr/local/php56/bin/php -q /var/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=year&date=2015-05-21,2016-12-31&format=php&segment=customVariableName1%3D%3DNot-Bot&trigger=archivephp&pid=96c5600080e32e7e2ba14d12b23527a30f21780d072bcdeb5abd0088fde21ebf41489cffeb4478dc38bf5400f15ea12769f61’ > /var/www/piwik/html/tmp/climulti/96c5600080e32e7e2ba14d12b23527a30f21780d072bcdeb5abd0088fde21ebf41489cffeb4478dc38bf5400f15ea12769f61.output 2>&1 &
INFO [2016-01-25 18:08:17] - pre-processing segment 2/2 customVariableName1==Bot
DEBUG [2016-01-25 18:08:17] /usr/local/php56/bin/php -q /var/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=year&date=2015-06-08,2016-12-31&format=php&segment=customVariableName1%3D%3DBot&trigger=archivephp&pid=4e1ab6558bb607b7e1ae0669157b091416b8ce64b0b9123e25891caac0c98189992abcf013f999c985e585a1e4729be2f79f2’ > /var/www/piwik/html/tmp/climulti/4e1ab6558bb607b7e1ae0669157b091416b8ce64b0b9123e25891caac0c98189992abcf013f999c985e585a1e4729be2f79f2.output 2>&1 &
INFO [2016-01-25 18:27:50] Archived website id = 8, period = year, 2 segments, 1042044 visits in last 2 years, 1042044 visits this year, Time elapsed: 1173.831s
INFO [2016-01-25 18:27:50] Will pre-process for website id = 8, period = range, date = previous30
INFO [2016-01-25 18:27:50] - pre-processing all visits
DEBUG [2016-01-25 18:27:50] /usr/local/php56/bin/php -q /var/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=range&date=previous30&format=php&trigger=archivephp&pid=3e19668d21eea16ae0e855f86bb51d6faf43495e2fa3a0b12d2f410d99a65987474f861bc220d1c99f0c3cd3d135fa50939e0’ > /var/www/piwik/html/tmp/climulti/3e19668d21eea16ae0e855f86bb51d6faf43495e2fa3a0b12d2f410d99a65987474f861bc220d1c99f0c3cd3d135fa50939e0.output 2>&1 &
INFO [2016-01-25 18:27:51] Archived website id = 8, period = range, 0 segments, 1172712 visits in previous 30 ranges, 1172712 visits this range, Time elapsed: 0.569s
INFO [2016-01-25 18:27:51] Will pre-process for website id = 8, period = range, date = last30
INFO [2016-01-25 18:27:51] - pre-processing all visits
DEBUG [2016-01-25 18:27:51] /usr/local/php56/bin/php -q /var/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=range&date=last30&format=php&trigger=archivephp&pid=1f3c347cd866db5a6d8eed1d7b09007325da09376321069d98c20d1724aa1376ce2b8cec69c9a727eb7da052621e8bb480eb0’ > /var/www/piwik/html/tmp/climulti/1f3c347cd866db5a6d8eed1d7b09007325da09376321069d98c20d1724aa1376ce2b8cec69c9a727eb7da052621e8bb480eb0.output 2>&1 &
INFO [2016-01-25 19:23:59] Archived website id = 8, period = range, 0 segments, 1194708 visits in last 30 ranges, 1194708 visits this range, Time elapsed: 3368.000s
INFO [2016-01-25 19:23:59] Archived website id = 8, 14 API requests, Time elapsed: 8569.849s [6/151 done]
…
INFO [2016-01-25 20:48:12] Done archiving!
INFO [2016-01-25 20:48:12] ---------------------------
INFO [2016-01-25 20:48:12] SUMMARY
INFO [2016-01-25 20:48:12] Total visits for today across archived websites: 194111
INFO [2016-01-25 20:48:12] Archived today’s reports for 104 websites
INFO [2016-01-25 20:48:12] Archived week/month/year for 104 websites
INFO [2016-01-25 20:48:12] Skipped 47 websites
INFO [2016-01-25 20:48:12] - 47 skipped because no new visit since the last script execution
INFO [2016-01-25 20:48:12] - 0 skipped because existing daily reports are less than 3600 seconds old
INFO [2016-01-25 20:48:12] - 0 skipped because existing week/month/year periods reports are less than 3600 seconds old
INFO [2016-01-25 20:48:12] Total API requests: 932
INFO [2016-01-25 20:48:12] done: 104/151 69%, 194111 vtoday, 104 wtoday, 104 wperiods, 932 req, 13690544 ms, no error
INFO [2016-01-25 20:48:12] Time elapsed: 13690.544s
INFO [2016-01-25 20:48:12] ---------------------------
INFO [2016-01-25 20:48:12] SCHEDULED TASKS
DEBUG [2016-01-25 20:48:12] 21 scheduled tasks loaded
INFO [2016-01-25 20:48:12] Starting Scheduled tasks…
DEBUG [2016-01-25 20:48:12] Executing tasks with priority 0:
DEBUG [2016-01-25 20:48:12] Executing tasks with priority 1:
DEBUG [2016-01-25 20:48:12] Executing tasks with priority 2:
DEBUG [2016-01-25 20:48:12] Executing tasks with priority 3:
DEBUG [2016-01-25 20:48:12] Executing tasks with priority 4:
DEBUG [2016-01-25 20:48:12] Executing tasks with priority 5:
DEBUG [2016-01-25 20:48:12] Executing tasks with priority 6:
DEBUG [2016-01-25 20:48:12] Executing tasks with priority 7:
DEBUG [2016-01-25 20:48:12] Executing tasks with priority 8:
DEBUG [2016-01-25 20:48:12] Executing tasks with priority 9:
DEBUG [2016-01-25 20:48:12] Executing tasks with priority 10:
DEBUG [2016-01-25 20:48:12] Executing tasks with priority 11:
DEBUG [2016-01-25 20:48:12] Executing tasks with priority 12:
INFO [2016-01-25 20:48:12] done
INFO [2016-01-25 20:48:12] ---------------------------

matthieu · January 26, 2016, 9:17am

I don’t see the memory error in this output - could you send me the output that shows where it memory fails?

rmoesbergen · January 26, 2016, 10:50am

The last time it failed this was logged:

INFO [2016-01-02 05:28:04] Scheduler: executing task Piwik\Plugins\CoreAdminHome\Tasks.optimizeArchiveTable…
INFO [2016-01-02 05:28:05] Scheduler: finished. Time elapsed: 0.660s
DEBUG [2016-01-02 05:28:05] Task Piwik\Plugins\CoreUpdater\Tasks.sendNotificationIfUpdateAvailable is scheduled to run again for 2016-01-03.
INFO [2016-01-02 05:28:05] Scheduler: executing task Piwik\Plugins\CoreUpdater\Tasks.sendNotificationIfUpdateAvailable…
INFO [2016-01-02 05:28:05] Scheduler: finished. Time elapsed: 0.001s
INFO [2016-01-02 05:28:05] done
INFO [2016-01-02 05:28:05] ---------------------------
INFO [2016-01-02 05:28:05] ---------------------------
INFO [2016-01-02 05:28:05] SUMMARY OF ERRORS
INFO [2016-01-02 05:28:05] Error: Got invalid response from API request: ?module=API&method=API.get&idSite=8&period=year&date=last2&format=php&trigger=archivephp. The response was empty. This usually means a server error. This solution to this error is generally to increase the value of ‘memory_limit’ in your php.ini file. Please check your Web server Error Log file for more details.

That’s all there is, because the process itself gets killed by the kernel (OOM). After this we added another 32G of memory to make it run. But it’s only a matter of time before the problem will re-occur.

matthieu · January 26, 2016, 11:43pm

could you send the whole output of the script, when it failed?

rmoesbergen · January 28, 2016, 1:01pm

This is the part where site 8 (the large one) is processed. As you can see there are large gaps in time, the process takes many hours and takes 50-80 Gb of memory.

INFO [2016-01-01 17:00:01] ---------------------------
INFO [2016-01-01 17:00:01] INIT
INFO [2016-01-01 17:00:01] Running Piwik 2.15.0 as Super User
INFO [2016-01-01 17:00:01] ---------------------------
INFO [2016-01-01 17:00:01] NOTES
INFO [2016-01-01 17: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-01-01 17:00:01] - Reports for the current week/month/year will be refreshed at most every 3600 seconds.
INFO [2016-01-01 17:00:01] - Archiving was last executed without error 15 hours 20 min ago
INFO [2016-01-01 17:00:01] - Will process 1 other websites because some old data reports have been invalidated (eg. using the Log Import script) , IDs: 8
INFO [2016-01-01 17:00:01] ---------------------------
INFO [2016-01-01 17:00:01] START
INFO [2016-01-01 17:00:01] Starting Piwik reports archiving…
INFO [2016-01-01 17:00:01] - no new tracking data for website id 1 (between 2016-01-01 01:39:07 and 2016-01-01 18:00:01)
INFO [2016-01-01 17:00:01] Skipped website id 1 as archiving is not needed
…
INFO [2016-01-01 17:01:00] - pre-processing segment 1/5 customVariableName1==Bot
INFO [2016-01-01 17:01:06] Archived website id = 7, 26 API requests, Time elapsed: 26.954s [5/149 done]
…
INFO [2016-01-01 17:01:06] Old report was invalidated for website id 8
INFO [2016-01-01 17:01:06] Will pre-process for website id = 8, period = day, date = last52
INFO [2016-01-01 17:01:06] - pre-processing all visits
DEBUG [2016-01-01 17:01:06] /usr/local/php56/bin/php -q /export/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=day&date=last52&format=php&trigger=archivephp&pid=d7c44350ff0724aae792237bc4d0017a797a36ce7933bf5ec041a9860dc435ca53e718a84514784d8e362b7fcb3dc7959f5c0’ > /export/www/piwik/html/tmp/climulti/d7c44350ff0724aae792237bc4d0017a797a36ce7933bf5ec041a9860dc435ca53e718a84514784d8e362b7fcb3dc7959f5c0.output 2>&1 &
DEBUG [2016-01-01 17:04:37] Earliest created time of segment ‘customVariableName1==Not-Bot’ w/ idSite = 8 is found to be 2015-05-21. Latest edit time is found to be 2015-11-23.
DEBUG [2016-01-01 17:04:37] process_new_segments_from set to segment_creation_time, oldest date to process is 2015-05-21
DEBUG [2016-01-01 17:04:37] Earliest created time of segment ‘customVariableName1==Bot’ w/ idSite = 8 is found to be 2015-06-08. Latest edit time is found to be 2015-12-23.
DEBUG [2016-01-01 17:04:37] process_new_segments_from set to segment_creation_time, oldest date to process is 2015-06-08
INFO [2016-01-01 17:04:37] - pre-processing segment 1/2 customVariableName1==Not-Bot
DEBUG [2016-01-01 17:04:37] /usr/local/php56/bin/php -q /export/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=day&date=last52&format=php&segment=customVariableName1%3D%3DNot-Bot&trigger=archivephp&pid=e31ddabd4822c63bb8f5375e71bec4c4e1998edbe9a95910eb6878240024fefa5ab69dfa3e8a5ed2190eae243b12d6b1c5ae0’ > /export/www/piwik/html/tmp/climulti/e31ddabd4822c63bb8f5375e71bec4c4e1998edbe9a95910eb6878240024fefa5ab69dfa3e8a5ed2190eae243b12d6b1c5ae0.output 2>&1 &
INFO [2016-01-01 17:04:37] - pre-processing segment 2/2 customVariableName1==Bot
DEBUG [2016-01-01 17:04:37] /usr/local/php56/bin/php -q /export/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=day&date=last52&format=php&segment=customVariableName1%3D%3DBot&trigger=archivephp&pid=be4678876abccf1272a3a89b900343f41835c38e024852659f7601c49b4444012e8ff7c7dd643eab21e730b52fc335a219cb1’ > /export/www/piwik/html/tmp/climulti/be4678876abccf1272a3a89b900343f41835c38e024852659f7601c49b4444012e8ff7c7dd643eab21e730b52fc335a219cb1.output 2>&1 &
INFO [2016-01-01 17:08:15] Archived website id = 8, period = day, 2 segments, 0 visits in last 52 days, 0 visits today, Time elapsed: 428.966s
INFO [2016-01-01 17:08:15] Will pre-process for website id = 8, period = week, date = last2
INFO [2016-01-01 17:08:15] - pre-processing all visits
DEBUG [2016-01-01 17:08:15] Earliest created time of segment ‘customVariableName1==Not-Bot’ w/ idSite = 8 is found to be 2015-05-21. Latest edit time is found to be 2015-11-23.
DEBUG [2016-01-01 17:08:15] process_new_segments_from set to segment_creation_time, oldest date to process is 2015-05-21
DEBUG [2016-01-01 17:08:15] Earliest created time of segment ‘customVariableName1==Bot’ w/ idSite = 8 is found to be 2015-06-08. Latest edit time is found to be 2015-12-23.
DEBUG [2016-01-01 17:08:15] process_new_segments_from set to segment_creation_time, oldest date to process is 2015-06-08
DEBUG [2016-01-01 17:08:15] /usr/local/php56/bin/php -q /export/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=week&date=last2&format=php&trigger=archivephp&pid=0fe817e7473b07616982e888fc6b506d0dba6f9c043609e0c5c7a21a350edaa2e54d89ab8234844d625f62c5c15a42bee8110’ > /export/www/piwik/html/tmp/climulti/0fe817e7473b07616982e888fc6b506d0dba6f9c043609e0c5c7a21a350edaa2e54d89ab8234844d625f62c5c15a42bee8110.output 2>&1 &
INFO [2016-01-01 17:08:15] - pre-processing segment 1/2 customVariableName1==Not-Bot
DEBUG [2016-01-01 17:08:15] /usr/local/php56/bin/php -q /export/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=week&date=last2&format=php&segment=customVariableName1%3D%3DNot-Bot&trigger=archivephp&pid=d3f767da223a368446a143c1658f058162f5539bd6c443fa7f93dfa71a2a8638691d98a8077686f74e3c8d3dd545b782051d1’ > /export/www/piwik/html/tmp/climulti/d3f767da223a368446a143c1658f058162f5539bd6c443fa7f93dfa71a2a8638691d98a8077686f74e3c8d3dd545b782051d1.output 2>&1 &
INFO [2016-01-01 17:08:15] - pre-processing segment 2/2 customVariableName1==Bot
DEBUG [2016-01-01 17:08:15] /usr/local/php56/bin/php -q /export/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=week&date=last2&format=php&segment=customVariableName1%3D%3DBot&trigger=archivephp&pid=52a9c30ec47637c79778ba2655f6826373b9567589616929bda8ce1c64f7accb7b45fa7f836d7c2540c13475e09d32678c0a2’ > /export/www/piwik/html/tmp/climulti/52a9c30ec47637c79778ba2655f6826373b9567589616929bda8ce1c64f7accb7b45fa7f836d7c2540c13475e09d32678c0a2.output 2>&1 &
INFO [2016-01-01 17:15:50] Archived website id = 8, period = week, 2 segments, 323683 visits in last 2 weeks, 136642 visits this week, Time elapsed: 455.361s
INFO [2016-01-01 17:15:50] Will pre-process for website id = 8, period = month, date = last2
INFO [2016-01-01 17:15:50] - pre-processing all visits
DEBUG [2016-01-01 17:15:50] Earliest created time of segment ‘customVariableName1==Not-Bot’ w/ idSite = 8 is found to be 2015-05-21. Latest edit time is found to be 2015-11-23.
DEBUG [2016-01-01 17:15:50] process_new_segments_from set to segment_creation_time, oldest date to process is 2015-05-21
DEBUG [2016-01-01 17:15:50] Earliest created time of segment ‘customVariableName1==Bot’ w/ idSite = 8 is found to be 2015-06-08. Latest edit time is found to be 2015-12-23.
DEBUG [2016-01-01 17:15:50] process_new_segments_from set to segment_creation_time, oldest date to process is 2015-06-08
DEBUG [2016-01-01 17:15:50] /usr/local/php56/bin/php -q /export/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=month&date=last2&format=php&trigger=archivephp&pid=ce19456816aee3b0d975e1643306417261d242d29309860ee3eeaec51a00debaa275e56dc0ca52f307ac0bc1f173858a38c60’ > /export/www/piwik/html/tmp/climulti/ce19456816aee3b0d975e1643306417261d242d29309860ee3eeaec51a00debaa275e56dc0ca52f307ac0bc1f173858a38c60.output 2>&1 &
INFO [2016-01-01 17:15:50] - pre-processing segment 1/2 customVariableName1==Not-Bot
DEBUG [2016-01-01 17:15:51] /usr/local/php56/bin/php -q /export/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=month&date=last2&format=php&segment=customVariableName1%3D%3DNot-Bot&trigger=archivephp&pid=6d8d281f0b78f2463775e3d3cbf255158bae364f8ff8aec5a1f9dafb2f044c06df588cc2ab6cf539a42c7fff557937dc41da1’ > /export/www/piwik/html/tmp/climulti/6d8d281f0b78f2463775e3d3cbf255158bae364f8ff8aec5a1f9dafb2f044c06df588cc2ab6cf539a42c7fff557937dc41da1.output 2>&1 &
INFO [2016-01-01 17:15:51] - pre-processing segment 2/2 customVariableName1==Bot
DEBUG [2016-01-01 17:15:51] /usr/local/php56/bin/php -q /export/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=month&date=last2&format=php&segment=customVariableName1%3D%3DBot&trigger=archivephp&pid=7fc3e79d4e52715f3df5a79f2b50d07beff44e08b2f050074d8c5413a0955d749989b13c0a311421a08dd633ffe99f9380e72’ > /export/www/piwik/html/tmp/climulti/7fc3e79d4e52715f3df5a79f2b50d07beff44e08b2f050074d8c5413a0955d749989b13c0a311421a08dd633ffe99f9380e72.output 2>&1 &
INFO [2016-01-01 17:16:32] Archived website id = 8, period = month, 2 segments, 1139062 visits in last 2 months, 7947 visits this month, Time elapsed: 41.900s
INFO [2016-01-01 17:16:32] Will pre-process for website id = 8, period = year, date = last2
INFO [2016-01-01 17:16:32] - pre-processing all visits
DEBUG [2016-01-01 17:16:32] Earliest created time of segment ‘customVariableName1==Not-Bot’ w/ idSite = 8 is found to be 2015-05-21. Latest edit time is found to be 2015-11-23.
DEBUG [2016-01-01 17:16:32] process_new_segments_from set to segment_creation_time, oldest date to process is 2015-05-21
DEBUG [2016-01-01 17:16:32] Start date of archiving request period (2015-01-01) is older than configured oldest date to process for the segment.
DEBUG [2016-01-01 17:16:32] Archiving request date range changed to 2015-05-21,2016-12-31 w/ period year.
DEBUG [2016-01-01 17:16:32] Earliest created time of segment ‘customVariableName1==Bot’ w/ idSite = 8 is found to be 2015-06-08. Latest edit time is found to be 2015-12-23.
DEBUG [2016-01-01 17:16:32] process_new_segments_from set to segment_creation_time, oldest date to process is 2015-06-08
DEBUG [2016-01-01 17:16:32] Start date of archiving request period (2015-01-01) is older than configured oldest date to process for the segment.
DEBUG [2016-01-01 17:16:32] Archiving request date range changed to 2015-06-08,2016-12-31 w/ period year.
DEBUG [2016-01-01 17:16:32] /usr/local/php56/bin/php -q /export/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=year&date=last2&format=php&trigger=archivephp&pid=83a5cb99cd0258ef5b1b096448f8d14d207736621b189c53007471b6413a38f9df5df35ad17f11de36e72d8f9b38fa22cb760’ > /export/www/piwik/html/tmp/climulti/83a5cb99cd0258ef5b1b096448f8d14d207736621b189c53007471b6413a38f9df5df35ad17f11de36e72d8f9b38fa22cb760.output 2>&1 &
INFO [2016-01-01 17:16:32] - pre-processing segment 1/2 customVariableName1==Not-Bot
DEBUG [2016-01-01 17:16:32] /usr/local/php56/bin/php -q /export/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=year&date=2015-05-21,2016-12-31&format=php&segment=customVariableName1%3D%3DNot-Bot&trigger=archivephp&pid=87207d52f2d2101c04fd0bf04ebad4bc18958110dc790aee19f5ad479823808092ff1ae4bea2ee2d787721f641f83d7b5aec1’ > /export/www/piwik/html/tmp/climulti/87207d52f2d2101c04fd0bf04ebad4bc18958110dc790aee19f5ad479823808092ff1ae4bea2ee2d787721f641f83d7b5aec1.output 2>&1 &
INFO [2016-01-01 17:16:32] - pre-processing segment 2/2 customVariableName1==Bot
DEBUG [2016-01-01 17:16:33] /usr/local/php56/bin/php -q /export/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=year&date=2015-06-08,2016-12-31&format=php&segment=customVariableName1%3D%3DBot&trigger=archivephp&pid=e6cc4af474c3972278a4c8acd09a1bf5bb836d695f7da8fe26f415fcd42b31f3f8cd0686344376673f4a18ee2aca10d8498d2’ > /export/www/piwik/html/tmp/climulti/e6cc4af474c3972278a4c8acd09a1bf5bb836d695f7da8fe26f415fcd42b31f3f8cd0686344376673f4a18ee2aca10d8498d2.output 2>&1 &
INFO [2016-01-02 02:37:55] Archived website id = 8, period = year, 2 segments, 0 visits in last 2 years, 0 visits this year, Time elapsed: 72206.322s
INFO [2016-01-02 02:37:55] Will pre-process for website id = 8, period = range, date = previous30
INFO [2016-01-02 02:37:55] - pre-processing all visits
DEBUG [2016-01-02 02:37:55] /usr/local/php56/bin/php -q /export/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=range&date=previous30&format=php&trigger=archivephp&pid=773bc3082cc9e609e241d72f0f1bfb8f0bd64585341f7513c54d46af01f4b9e1ea210a763cf9d2662993a010083ebba96cd10’ > /export/www/piwik/html/tmp/climulti/773bc3082cc9e609e241d72f0f1bfb8f0bd64585341f7513c54d46af01f4b9e1ea210a763cf9d2662993a010083ebba96cd10.output 2>&1 &
INFO [2016-01-02 03:41:39] Archived website id = 8, period = range, 0 segments, 1042189 visits in previous 30 ranges, 1042189 visits this range, Time elapsed: 3823.805s
INFO [2016-01-02 03:41:39] Will pre-process for website id = 8, period = range, date = last30
INFO [2016-01-02 03:41:39] - pre-processing all visits
DEBUG [2016-01-02 03:41:39] /usr/local/php56/bin/php -q /export/www/piwik/html/console climulti:request -q --piwik-domain=’’ --superuser ‘module=API&method=API.get&idSite=8&period=range&date=last30&format=php&trigger=archivephp&pid=3347b9f0f3fa7c729765566bb890d073b80ae376ba1671e70b2015c712a9dae8b4c1ac1a0b95d6e3a7144c0221e0b7c55b990’ > /export/www/piwik/html/tmp/climulti/3347b9f0f3fa7c729765566bb890d073b80ae376ba1671e70b2015c712a9dae8b4c1ac1a0b95d6e3a7144c0221e0b7c55b990.output 2>&1 &
INFO [2016-01-02 04:41:21] Archived website id = 8, period = range, 0 segments, 995051 visits in last 30 ranges, 995051 visits this range, Time elapsed: 3582.296s
INFO [2016-01-02 04:41:21] Archived website id = 8, 14 API requests, Time elapsed: 85081.702s [6/149 done]
INFO [2016-01-02 04:41:22] - tracking data found for website id 9 (between 2016-01-01 23:00:00 and 2016-01-02 05:41:22)
INFO [2016-01-02 04:41:22] Will pre-process for website id = 9, period = day, date = last2
…