@wmnnd opened this Issue on July 18th 2018

Hi there,

I am currently experiencing an odd bug on my Matomo (3.5.1) installation. A few days ago, one of the sites stopped failing when the daily Cron job was run. The error did not coincide with any changes on my part nor with a Matomo update.

Unfortunately, I am unable to find any way to debug this issue. There are no errors in my error log. The memory_limit is -1 and the server has 16 GB of RAM available (and we’re talking only a couple of thousand page views) for the site in question.

I’ve also tried running the API url in the browser, but all I get is the default server 500 error page. No useful logged errors either.

Here is the output from the CLI:

$ php console core:archive -vvv --force-idsites=1
INFO [2018-07-18 16:27:14] 23081  ---------------------------
INFO [2018-07-18 16:27:14] 23081  INIT
INFO [2018-07-18 16:27:14] 23081  Running Matomo 3.5.1 as Super User
INFO [2018-07-18 16:27:14] 23081  ---------------------------
INFO [2018-07-18 16:27:14] 23081  NOTES
INFO [2018-07-18 16:27:14] 23081  - Reports for today will be processed at most every 1800 seconds. You can change this value in Matomo UI > Settings > General Settings.
INFO [2018-07-18 16:27:14] 23081  - Reports for the current week/month/year will be requested at most every 3600 seconds.
INFO [2018-07-18 16:27:14] 23081  - Archiving was last executed without error 2 hours 13 min ago
INFO [2018-07-18 16:27:14] 23081  - Will process 1 websites (--force-idsites)
INFO [2018-07-18 16:27:14] 23081  ---------------------------
INFO [2018-07-18 16:27:14] 23081  START
INFO [2018-07-18 16:27:14] 23081  Starting Matomo reports archiving...
INFO [2018-07-18 16:27:14] 23081  Will pre-process for website id = 1, period = day, date = last52
INFO [2018-07-18 16:27:14] 23081  - pre-processing all visits
DEBUG [2018-07-18 16:27:14] 23081  /usr/bin/php5 -q  /var/www/piwik/console climulti:request -q --piwik-domain='' --superuser 'module=API&method=API.get&idSite=1&period=day&date=last52&format=php&trigger=archivephp&pid=e32[…]940' > /var/www/piwik/tmp/climulti/e3[…]940.output 2>&1 &
ERROR [2018-07-18 16:27:15] 23081  Got invalid response from API request: ?module=API&method=API.get&idSite=1&period=day&date=last52&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 [2018-07-18 16:27:15] 23081  Empty or invalid response '' for website id 1, Time elapsed: 1.361s, skipping
INFO [2018-07-18 16:27:15] 23081  Done archiving!
INFO [2018-07-18 16:27:15] 23081  ---------------------------
INFO [2018-07-18 16:27:15] 23081  SUMMARY
INFO [2018-07-18 16:27:15] 23081  Total visits for today across archived websites: 0
INFO [2018-07-18 16:27:15] 23081  Archived today's reports for 0 websites
INFO [2018-07-18 16:27:15] 23081  Archived week/month/year for 0 websites
INFO [2018-07-18 16:27:15] 23081  Skipped 31 websites
INFO [2018-07-18 16:27:15] 23081  - 0 skipped because no new visit since the last script execution
INFO [2018-07-18 16:27:15] 23081  - 0 skipped because existing daily reports are less than 1800 seconds old
INFO [2018-07-18 16:27:15] 23081  - 0 skipped because existing week/month/year periods reports are less than 3600 seconds old
INFO [2018-07-18 16:27:15] 23081  - 1 skipped because got an error while querying reporting API
INFO [2018-07-18 16:27:15] 23081  Total API requests: 0
INFO [2018-07-18 16:27:15] 23081  done: 0/1 0%, 0 vtoday, 0 wtoday, 0 wperiods, 0 req, 1363 ms, 2 errors.
INFO [2018-07-18 16:27:15] 23081  Time elapsed: 1.364s
INFO [2018-07-18 16:27:15] 23081  ---------------------------
INFO [2018-07-18 16:27:15] 23081  SCHEDULED TASKS
DEBUG [2018-07-18 16:27:15] 23081  16 scheduled tasks loaded
INFO [2018-07-18 16:27:15] 23081  Starting Scheduled tasks... 
DEBUG [2018-07-18 16:27:15] 23081  Executing tasks with priority 0:
DEBUG [2018-07-18 16:27:15] 23081  Executing tasks with priority 1:
DEBUG [2018-07-18 16:27:15] 23081  Executing tasks with priority 2:
DEBUG [2018-07-18 16:27:15] 23081  Executing tasks with priority 3:
DEBUG [2018-07-18 16:27:15] 23081  Executing tasks with priority 4:
DEBUG [2018-07-18 16:27:15] 23081  Executing tasks with priority 5:
DEBUG [2018-07-18 16:27:15] 23081  Executing tasks with priority 6:
DEBUG [2018-07-18 16:27:15] 23081  Executing tasks with priority 7:
DEBUG [2018-07-18 16:27:15] 23081  Executing tasks with priority 8:
DEBUG [2018-07-18 16:27:15] 23081  Executing tasks with priority 9:
DEBUG [2018-07-18 16:27:15] 23081  Executing tasks with priority 10:
DEBUG [2018-07-18 16:27:15] 23081  Executing tasks with priority 11:
DEBUG [2018-07-18 16:27:15] 23081  Executing tasks with priority 12:
INFO [2018-07-18 16:27:15] 23081  done
INFO [2018-07-18 16:27:15] 23081  ---------------------------
INFO [2018-07-18 16:27:15] 23081  ---------------------------
INFO [2018-07-18 16:27:15] 23081  SUMMARY OF ERRORS
INFO [2018-07-18 16:27:15] 23081  Error: Got invalid response from API request: ?module=API&method=API.get&idSite=1&period=day&date=last52&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
INFO [2018-07-18 16:27:15] 23081  Error: Empty or invalid response '' for website id 1, Time elapsed: 1.361s, skipping
ERROR [2018-07-18 16:27:15] 23081  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 /var/www/piwik/core/CronArchive.php:530
 Piwik\CronArchive->logFatalError() at /var/www/piwik/core/CronArchive.php:523
 Piwik\CronArchive->end() at /var/www/piwik/core/CronArchive.php:302
 Piwik\CronArchive->Piwik\{closure}() at /var/www/piwik/core/Access.php:469
 Piwik\Access::doAsSuperUser() at /var/www/piwik/core/CronArchive.php:303
 Piwik\CronArchive->main() at /var/www/piwik/plugins/CoreConsole/Commands/CoreArchiver.php:27
 Piwik\Plugins\CoreConsole\Commands\CoreArchiver->execute() at /var/www/piwik/vendor/symfony/console/Symfony/Component/Console/Command/Command.php:257
 Symfony\Component\Console\Command\Command->run() at /var/www/piwik/vendor/symfony/console/Symfony/Component/Console/Application.php:874
 Symfony\Component\Console\Application->doRunCommand() at /var/www/piwik/vendor/symfony/console/Symfony/Component/Console/Application.php:195
 Symfony\Component\Console\Application->doRun() at n/a:n/a
 call_user_func() at /var/www/piwik/core/Console.php:80
 Piwik\Console->Piwik\{closure}() at /var/www/piwik/core/Access.php:469
 Piwik\Access::doAsSuperUser() at /var/www/piwik/core/Console.php:81
 Piwik\Console->doRun() at /var/www/piwik/vendor/symfony/console/Symfony/Component/Console/Application.php:126
 Symfony\Component\Console\Application->run() at /var/www/piwik/console:27

Here is piwik.log, but it doesn’t seem to contain any errors:
https://gist.github.com/wmnnd/a9fdd530fea063dd8a061ef546f12d5e

The archiving works fine for all other sites.

I’m running PHP 5.5.9 (FastCGI); the Matomo system check shows no errors other than the LOAD DATA INFILE warning.

Do you have any suggestions on how to further debug this or what the reason for this issue could be?
If this turns out to be a bug, I’d be happy to work on a PR.

@fdellwing commented on July 18th 2018 Contributor

Not sure if it helps you, but apply this change an check if it helps: #13114

@wmnnd commented on July 18th 2018

@fdellwing Thank you for pointing this out.
Unfortunately, this doesn’t seem to be related. I had already tried to apply this patch before (and just re-tried it again), but it does not change the behavior described here. Neither the CLI output nor the log are different with the patch.

@mattab commented on August 28th 2018 Member

@wmnnd I recommend you try upgrade to latest PHP7 as this could maybe fix the issue?

Powered by GitHub Issue Mirror