(2.16.2.) Core:Archive empty response over CLI

Hi!

I am having a problem with core:archive function. When running over PHP CLI I am gettitng ‘Empty or invalid response’. Running script over CGI works but it is running very slowly and a yearly, montly or weekly report somethime causes to overload server which has 8GB memory installed.

As I was looking for solution to my problem there were recommendations to run core:archive script over CLI if possible as running core:archive over CGI doesn’t work properly. Is this true? I don’t know why script is getting empty response. Any solutions?

Server version: Apache/2.4.6 (CentOS)
PHP 5.5.38 (cli) (built: Jul 20 2016 15:51:27)
Piwik - 2.16.2 (database was upgraded from 2.1.0 - with no errors).
memory_limit => 512M => 512M

Rows from Piwik System Check. Everything is marked as OK.

PHP version >= 5.3.3	 5.5.38 
PDO extension	 
PDO\MYSQL extension	 
MYSQLI extension	 

Other required extensions	 
 zlib 
 SPL 
 iconv 
 json 
 mbstring 
 Reflection 

Required functions	 
 debug_backtrace 
 create_function 
 eval 
 gzcompress 
 gzuncompress 
 pack 

Required PHP configuration (php.ini)	 session.auto_start=0 
Directories with write access	 
 /zpiwik/piwik-updated/tmp 
 /zpiwik/piwik-updated/tmp/assets 
 /zpiwik/piwik-updated/tmp/cache 
 /zpiwik/piwik-updated/tmp/climulti 
 /zpiwik/piwik-updated/tmp/latest 
 /zpiwik/piwik-updated/tmp/logs 
 /zpiwik/piwik-updated/tmp/sessions 
 /zpiwik/piwik-updated/tmp/tcpdf 
 /zpiwik/piwik-updated/tmp/templates_c 

Tracker status	 
Memory limit	 512M 
Time zone	 
Open URL	 curl 
PageSpeed disabled	 
GD > 2.x + Freetype (graphics)	 

Other extensions	 
 json 
 libxml 
 dom 
 SimpleXML 
Other functions	 shell_exec 
 set_time_limit 
 mail 
 parse_ini_file 
 glob 
 gzopen 
Filesystem	 
Archive Cron	 Managing processes via CLI: Ok 
Database abilities	 LOAD DATA INFILE 
Geolocation	 
Update over HTTPS	 

Example for site:8002 over CLI:

sudo -u apache php /[path]/console core:archive --url=https://[piwik_url]/ --force-idsites=8002 -vvv > tmp_file

ERROR [2016-08-10 11:27:59] Got invalid response from API request: ?module=API&method=API.get&idSite=8002&period=day&date=last2&format=php&trigger=archivephp. The response was empty. This usually means a server error. A solution to this error is generally to increase the value of 'memory_limit' in your php.ini file.  For more information and the error message please check in your PHP CLI error log file. As this core:archive command triggers PHP processes over the CLI, you can find where PHP CLI logs are stored by running this command: php -i | grep error_log
ERROR [2016-08-10 11:27:59] Empty or invalid response '' for website id 8002, Time elapsed: 0.666s, skipping
ERROR [2016-08-10 11:27:59] 2 total errors during this script execution, please investigate and try and fix these errors.

                                                                                                 
  [Exception]                                                                                    
  2 total errors during this script execution, please investigate and try and fix these errors.  
                                                                                                 

Exception trace:
 () at /zpiwik/piwik-updated/core/CronArchive.php:496
 Piwik\CronArchive->logFatalError() at /zpiwik/piwik-updated/core/CronArchive.php:489
 Piwik\CronArchive->end() at /zpiwik/piwik-updated/core/CronArchive.php:291
 Piwik\CronArchive->Piwik\{closure}() at /zpiwik/piwik-updated/core/Access.php:469
 Piwik\Access::doAsSuperUser() at /zpiwik/piwik-updated/core/CronArchive.php:292
 Piwik\CronArchive->main() at /zpiwik/piwik-updated/plugins/CoreConsole/Commands/CoreArchiver.php:27
 Piwik\Plugins\CoreConsole\Commands\CoreArchiver->execute() at /zpiwik/piwik-updated/vendor/symfony/console/Symfony/Component/Console/Command/Command.php:257
 Symfony\Component\Console\Command\Command->run() at /zpiwik/piwik-updated/vendor/symfony/console/Symfony/Component/Console/Application.php:874
 Symfony\Component\Console\Application->doRunCommand() at /zpiwik/piwik-updated/vendor/symfony/console/Symfony/Component/Console/Application.php:195
 Symfony\Component\Console\Application->doRun() at n/a:n/a
 call_user_func() at /zpiwik/piwik-updated/core/Console.php:79
 Piwik\Console->Piwik\{closure}() at /zpiwik/piwik-updated/core/Access.php:469
 Piwik\Access::doAsSuperUser() at /zpiwik/piwik-updated/core/Console.php:80
 Piwik\Console->doRun() at /zpiwik/piwik-updated/vendor/symfony/console/Symfony/Component/Console/Application.php:126
 Symfony\Component\Console\Application->run() at /zpiwik/piwik-updated/console:27

tmp_file:

^[[32mINFO [2016-08-10 11:27:58]^[[39m ---------------------------
^[[32mINFO [2016-08-10 11:27:58]^[[39m INIT
^[[32mINFO [2016-08-10 11:27:58]^[[39m Running Piwik 2.16.2 as Super User
^[[32mINFO [2016-08-10 11:27:58]^[[39m ---------------------------
^[[32mINFO [2016-08-10 11:27:58]^[[39m NOTES
^[[32mINFO [2016-08-10 11:27:58]^[[39m - Reports for today will be processed at most every 3500 seconds. You can change this value in Piwik UI > Settings > General Settings.
^[[32mINFO [2016-08-10 11:27:58]^[[39m - Reports for the current week/month/year will be refreshed at most every 3600 seconds.
^[[32mINFO [2016-08-10 11:27:58]^[[39m - Archiving was last executed without error 29s ago
^[[32mINFO [2016-08-10 11:27:58]^[[39m - Will process 1 websites (--force-idsites)
^[[32mINFO [2016-08-10 11:27:58]^[[39m ---------------------------
^[[32mINFO [2016-08-10 11:27:58]^[[39m START
^[[32mINFO [2016-08-10 11:27:58]^[[39m Starting Piwik reports archiving...
^[[32mINFO [2016-08-10 11:27:58]^[[39m Will pre-process for website id = 8002, period = day, date = last2
^[[32mINFO [2016-08-10 11:27:58]^[[39m - pre-processing all visits
DEBUG [2016-08-10 11:27:58] /usr/bin/php -q  /zpiwik/piwik-updated/console climulti:request -q --piwik-domain='piwik[domain]' --superuser 'module=API&method=API.get&idSite=8002&period=day&date=last2&format=php&trigger=archivephp&pid=5e15c734126ea85a975012803060757290fea91568d77d69b32a83ab2de6e6525f855dfe0586170000000000000000000000' > /zpiwik/piwik-updated/tmp/climulti/5e15c734126ea85a975012803060757290fea91568d77d69b32a83ab2de6e6525f855dfe0586173f1577aa5409d1ca2715bb0.output 2>&1 &
^[[32mINFO [2016-08-10 11:27:59]^[[39m Done archiving!
^[[32mINFO [2016-08-10 11:27:59]^[[39m ---------------------------
^[[32mINFO [2016-08-10 11:27:59]^[[39m SUMMARY
^[[32mINFO [2016-08-10 11:27:59]^[[39m Total visits for today across archived websites: 0
^[[32mINFO [2016-08-10 11:27:59]^[[39m Archived today's reports for 0 websites
^[[32mINFO [2016-08-10 11:27:59]^[[39m Archived week/month/year for 0 websites
^[[32mINFO [2016-08-10 11:27:59]^[[39m Skipped 9200 websites
^[[32mINFO [2016-08-10 11:27:59]^[[39m - 0 skipped because no new visit since the last script execution
^[[32mINFO [2016-08-10 11:27:59]^[[39m - 0 skipped because existing daily reports are less than 3500 seconds old
^[[32mINFO [2016-08-10 11:27:59]^[[39m - 0 skipped because existing week/month/year periods reports are less than 3600 seconds old
^[[32mINFO [2016-08-10 11:27:59]^[[39m - 1 skipped because got an error while querying reporting API
^[[32mINFO [2016-08-10 11:27:59]^[[39m Total API requests: 0
^[[32mINFO [2016-08-10 11:27:59]^[[39m done: 0/1 0%, 0 vtoday, 0 wtoday, 0 wperiods, 0 req, 670 ms, 2 errors.
^[[32mINFO [2016-08-10 11:27:59]^[[39m Time elapsed: 0.671s
^[[32mINFO [2016-08-10 11:27:59]^[[39m ---------------------------
^[[32mINFO [2016-08-10 11:27:59]^[[39m SCHEDULED TASKS
DEBUG [2016-08-10 11:27:59] 30 scheduled tasks loaded
^[[32mINFO [2016-08-10 11:27:59]^[[39m Starting Scheduled tasks...
DEBUG [2016-08-10 11:27:59] Executing tasks with priority 0:
DEBUG [2016-08-10 11:27:59] Executing tasks with priority 1:
DEBUG [2016-08-10 11:27:59] Executing tasks with priority 2:
DEBUG [2016-08-10 11:27:59] Executing tasks with priority 3:
DEBUG [2016-08-10 11:27:59] Executing tasks with priority 4:
DEBUG [2016-08-10 11:27:59] Executing tasks with priority 5:
DEBUG [2016-08-10 11:27:59] Executing tasks with priority 6:
DEBUG [2016-08-10 11:27:59] Executing tasks with priority 7:
DEBUG [2016-08-10 11:27:59] Executing tasks with priority 8:
DEBUG [2016-08-10 11:27:59] Executing tasks with priority 9:
DEBUG [2016-08-10 11:27:59] Executing tasks with priority 10:
DEBUG [2016-08-10 11:27:59] Executing tasks with priority 11:
DEBUG [2016-08-10 11:27:59] Executing tasks with priority 12:
^[[32mINFO [2016-08-10 11:27:59]^[[39m done
^[[32mINFO [2016-08-10 11:27:59]^[[39m ---------------------------
^[[32mINFO [2016-08-10 11:27:59]^[[39m ---------------------------
^[[32mINFO [2016-08-10 11:27:59]^[[39m SUMMARY OF ERRORS
^[[32mINFO [2016-08-10 11:27:59]^[[39m Error: Got invalid response from API request: ?module=API&method=API.get&idSite=8002&period=day&date=last2&format=php&trigger=archivephp. The response was empty. This usually means a server error. A solution to this error is generally to increase the value of 'memory_limit' in your php.ini file.  For more information and the error message please check in your PHP CLI error log file. As this core:archive command triggers PHP processes over the CLI, you can find where PHP CLI logs are stored by running this command: php -i | grep error_log
^[[32mINFO [2016-08-10 11:27:59]^[[39m Error: Empty or invalid response '' for website id 8002, Time elapsed: 0.666s, skipping

Example for site:8002 over CGI

sudo -u apache php-cgi /[path]/console core:archive --url=https://[piwik_url]/ --force-idsites=8002 -vvv > tmp_file

tmp_file:

^[[32mINFO [2016-08-10 11:58:21]^[[39m ---------------------------
^[[32mINFO [2016-08-10 11:58:21]^[[39m INIT
^[[32mINFO [2016-08-10 11:58:21]^[[39m Running Piwik 2.16.2 as Super User
^[[32mINFO [2016-08-10 11:58:21]^[[39m ---------------------------
^[[32mINFO [2016-08-10 11:58:21]^[[39m NOTES
^[[32mINFO [2016-08-10 11:58:21]^[[39m - Reports for today will be processed at most every 3500 seconds. You can change this value in Piwik UI > Settings > General Settings.
^[[32mINFO [2016-08-10 11:58:21]^[[39m - Reports for the current week/month/year will be refreshed at most every 3600 seconds.
^[[32mINFO [2016-08-10 11:58:21]^[[39m - Archiving was last executed without error 32s ago
^[[32mINFO [2016-08-10 11:58:21]^[[39m - Will process 1 websites (--force-idsites)
^[[32mINFO [2016-08-10 11:58:21]^[[39m ---------------------------
^[[32mINFO [2016-08-10 11:58:21]^[[39m START
^[[32mINFO [2016-08-10 11:58:21]^[[39m Starting Piwik reports archiving...
^[[32mINFO [2016-08-10 11:58:21]^[[39m Will pre-process for website id = 8002, period = day, date = last2
^[[32mINFO [2016-08-10 11:58:21]^[[39m - pre-processing all visits
DEBUG [2016-08-10 11:58:21] Execute HTTP API request: https://piwik[domain]/?module=API&method=API.get&idSite=8002&period=day&date=last2&format=php&trigger=archivephp&token_auth=removed
^[[32mINFO [2016-08-10 11:58:22]^[[39m Archived website id = 8002, period = day, 0 segments, 0 visits in last 2 days, 0 visits today, Time elapsed: 0.482s
^[[32mINFO [2016-08-10 11:58:22]^[[39m Will pre-process for website id = 8002, period = week, date = last2
^[[32mINFO [2016-08-10 11:58:22]^[[39m - pre-processing all visits
DEBUG [2016-08-10 11:58:22] Execute HTTP API request: https://piwik[domain]/?module=API&method=API.get&idSite=8002&period=week&date=last2&format=php&trigger=archivephp&token_auth=removed
^[[32mINFO [2016-08-10 11:58:22]^[[39m Archived website id = 8002, period = week, 0 segments, 635 visits in last 2 weeks, 631 visits this week, Time elapsed: 0.331s
^[[32mINFO [2016-08-10 11:58:22]^[[39m Will pre-process for website id = 8002, period = month, date = last2
^[[32mINFO [2016-08-10 11:58:22]^[[39m - pre-processing all visits
DEBUG [2016-08-10 11:58:22] Execute HTTP API request: https://piwik[domain]/?module=API&method=API.get&idSite=8002&period=month&date=last2&format=php&trigger=archivephp&token_auth=removed
^[[32mINFO [2016-08-10 11:58:22]^[[39m Archived website id = 8002, period = month, 0 segments, 641 visits in last 2 months, 635 visits this month, Time elapsed: 0.341s
^[[32mINFO [2016-08-10 11:58:22]^[[39m Will pre-process for website id = 8002, period = year, date = last2
^[[32mINFO [2016-08-10 11:58:22]^[[39m - pre-processing all visits
DEBUG [2016-08-10 11:58:22] Execute HTTP API request: https://piwik[domain]/?module=API&method=API.get&idSite=8002&period=year&date=last2&format=php&trigger=archivephp&token_auth=removed
^[[32mINFO [2016-08-10 11:58:23]^[[39m Archived website id = 8002, period = year, 0 segments, 685 visits in last 2 years, 685 visits this year, Time elapsed: 0.320s
^[[32mINFO [2016-08-10 11:58:23]^[[39m Archived website id = 8002, 4 API requests, Time elapsed: 1.501s [1/1 done]
^[[32mINFO [2016-08-10 11:58:23]^[[39m Done archiving!
^[[32mINFO [2016-08-10 11:58:23]^[[39m ---------------------------
^[[32mINFO [2016-08-10 11:58:23]^[[39m SUMMARY
^[[32mINFO [2016-08-10 11:58:23]^[[39m Total visits for today across archived websites: 0
^[[32mINFO [2016-08-10 11:58:23]^[[39m Archived today's reports for 1 websites
^[[32mINFO [2016-08-10 11:58:23]^[[39m Archived week/month/year for 1 websites
^[[32mINFO [2016-08-10 11:58:23]^[[39m Skipped 9199 websites
^[[32mINFO [2016-08-10 11:58:23]^[[39m - 0 skipped because no new visit since the last script execution
^[[32mINFO [2016-08-10 11:58:23]^[[39m - 0 skipped because existing daily reports are less than 3500 seconds old
^[[32mINFO [2016-08-10 11:58:23]^[[39m - 0 skipped because existing week/month/year periods reports are less than 3600 seconds old
^[[32mINFO [2016-08-10 11:58:23]^[[39m Total API requests: 4
^[[32mINFO [2016-08-10 11:58:23]^[[39m done: 1/1 100%, 0 vtoday, 1 wtoday, 1 wperiods, 4 req, 1505 ms, no error
^[[32mINFO [2016-08-10 11:58:23]^[[39m Time elapsed: 1.505s
^[[32mINFO [2016-08-10 11:58:23]^[[39m ---------------------------
^[[32mINFO [2016-08-10 11:58:23]^[[39m SCHEDULED TASKS
DEBUG [2016-08-10 11:58:23] 30 scheduled tasks loaded
^[[32mINFO [2016-08-10 11:58:23]^[[39m Starting Scheduled tasks...
DEBUG [2016-08-10 11:58:23] Executing tasks with priority 0:
DEBUG [2016-08-10 11:58:23] Executing tasks with priority 1:
DEBUG [2016-08-10 11:58:23] Executing tasks with priority 2:
DEBUG [2016-08-10 11:58:23] Executing tasks with priority 3:
DEBUG [2016-08-10 11:58:23] Executing tasks with priority 4:
DEBUG [2016-08-10 11:58:23] Executing tasks with priority 5:
DEBUG [2016-08-10 11:58:23] Executing tasks with priority 6:
DEBUG [2016-08-10 11:58:23] Executing tasks with priority 7:
DEBUG [2016-08-10 11:58:23] Executing tasks with priority 8:
DEBUG [2016-08-10 11:58:23] Executing tasks with priority 9:
DEBUG [2016-08-10 11:58:23] Executing tasks with priority 10:
DEBUG [2016-08-10 11:58:23] Executing tasks with priority 11:
DEBUG [2016-08-10 11:58:23] Executing tasks with priority 12:
^[[32mINFO [2016-08-10 11:58:23]^[[39m done

Testing curl with auth_token:

curl --request POST ‘https://piwik[domain]/index.php?module=API&method=API.get&idSite=8002&period=day&date=last52&format=php&trigger=archivephp&token_auth=XXXXXXXXXXXXXX’

is getting me answer as it should.

a:52:{s:10:"2016-06-20";a:0:{}s:10:"2016-06-21";a:0:{}s:10:"2016-06-22";a:0:{}s:10:"2016-06-23";a:0:{}s:10:"2016-06-24";a:0:{}s:10:"2016-06-25";a:0:{}s:10:"2016-06-26";a:0:{}s:10:"2016-06-27";a:0:{}s:10:"2016-06-28";a:0:{}s:10:"2016-06-29";a:0:{}s:10:"2016-06-30";a:0:{}s:10:"2016-07-01";a:0:{}s:10:"2016-07-02";a:0:{}s:10:"2016-07-03";a:0:{}s:10:"2016-07-04";a:0:{}s:10:"2016-07-05";a:0:{}s:10:"2016-07-06";a:0:{}s:10:"2016-07-07";a:0:{}s:10:"2016-07-08";a:0:{}s:10:"2016-07-09";a:0:{}s:10:"2016-07-10";a:0:{}s:10:"2016-07-11";a:0:{}s:10:"2016-07-12";a:0:{}s:10:"2016-07-13";a:36:{s:16:"nb_uniq_visitors";d:1;s:9:"nb_visits";d:1;s:8:"nb_users";i:0;s:10:"nb_acti [...]

PHP CLI log is empty (tmp/php_errors.log). Setting around error logging:
php -i | grep error

display_errors => STDOUT => STDOUT
display_startup_errors => Off => Off
error_append_string => no value => no value
error_log => /tmp/php_errors.log => /tmp/php_errors.log
error_prepend_string => no value => no value
error_reporting => 32767 => 32767
html_errors => Off => Off
ignore_repeated_errors => Off => Off
log_errors => On => On
log_errors_max_len => 1024 => 1024
track_errors => Off => Off
xmlrpc_error_number => 0 => 0
xmlrpc_errors => Off => Off

What happens if you run the DEBUG command directly ie. /usr/bin/php -q /zpiwik/piwik-updated/console climulti:request -q --piwik-domain='piwik[domain]' --superuser 'module=API&method=API.get&idSite=8002&period=day&date=last2&format=php&trigger=archivephp&pid=5e15c734126ea85a975012803060757290fea91568d77d69b32a83ab2de6e6525f855dfe0586170000000000000000000000'

Nothing happens. Command is just executed and finished without any kind of response - error/success message.