search

matomo-org / matomo

Empowering People Ethically with the leading open source alternative to Google Analytics that gives you full control over your data. Matomo lets you easily collect data from websites & apps and visualise this data and extract insights. Privacy is built-in. Liberating Web Analytics. Star us on Github? +1. And we love Pull Requests!
https://matomo.org/
GNU General Public License v3.0
19.83k stars 2.64k forks source link

Got empty response from API request without any logging information #18889

Open dieisraels opened 2 years ago

dieisraels commented 2 years ago

The archiving process occasionally has empty API response over and over again:

DEBUG [2022-03-04 17:03:19] 18494  Running command: /opt/plesk/php/8.0/bin/php -q -d memory_limit=12G -d error_log=/var/www/vhosts/***/logs/error_log_cli /var/www/vhosts/***/httpdocs/console climulti:request -q --matomo-domain='***' --superuser 'module=API&method=CoreAdminHome.archiveReports&idSite=1&period=week&date=2022-02-28&format=json&segment=pageUrl%3D%40%25252FCCBT%25252F%2CpageUrl%3D%40.CCBT%25252F%2CpageUrl%3D%40%25252FCCBT.%2CpageUrl%3D%40.CCBT.&trigger=archivephp&skipArchiveSegmentToday=1&pid=519c9642b824b4c1f01b1c5d2a33c5b24fe128fd97750556ce40c6fb72cf004aa8af8d1b10d51a77eaac7826f68372c8d5800&runid=18494'  > /var/www/vhosts/***/httpdocs/tmp/climulti/519c9642b824b4c1f01b1c5d2a33c5b24fe128fd97750556ce40c6fb72cf004aa8af8d1b10d51a77eaac7826f68372c8d5800.output 2>&1 &
DEBUG [2022-03-04 17:03:19] 18494  Running command: /opt/plesk/php/8.0/bin/php -q -d memory_limit=12G -d error_log=/var/www/vhosts/***/logs/error_log_cli /var/www/vhosts/***/httpdocs/console climulti:request -q --matomo-domain='***' --superuser 'module=API&method=CoreAdminHome.archiveReports&idSite=1&period=week&date=2022-02-28&format=json&segment=pageUrl%3D%40%25252FCUVS%25252F%2CpageUrl%3D%40.CUVS%25252F%2CpageUrl%3D%40%25252FCUVS.%2CpageUrl%3D%40.CUVS.&trigger=archivephp&skipArchiveSegmentToday=1&pid=caa2a4b7c6775526600af6138cdc52dc3231cf778c5445ab26fc1de2584cf4b0981fe3d3d45d1281612643447c593ca102601&runid=18494'  > /var/www/vhosts/***/httpdocs/tmp/climulti/caa2a4b7c6775526600af6138cdc52dc3231cf778c5445ab26fc1de2584cf4b0981fe3d3d45d1281612643447c593ca102601.output 2>&1 &
DEBUG [2022-03-04 17:03:19] 18494  Running command: /opt/plesk/php/8.0/bin/php -q -d memory_limit=12G -d error_log=/var/www/vhosts/***/logs/error_log_cli /var/www/vhosts/***/httpdocs/console climulti:request -q --matomo-domain='***' --superuser 'module=API&method=CoreAdminHome.archiveReports&idSite=1&period=week&date=2022-02-28&format=json&segment=pageUrl%3D%40%25252FFCB%25252F%2CpageUrl%3D%40.FCB%25252F%2CpageUrl%3D%40%25252FFCB.%2CpageUrl%3D%40.FCB.%2CpageUrl%3D%40%25252FPCB%25252F%2CpageUrl%3D%40.PCB%25252F%2CpageUrl%3D%40%25252FPCB.%2CpageUrl%3D%40.PCB.&trigger=archivephp&skipArchiveSegmentToday=1&pid=973b2bfe6f7adb381fa8c0b9fb6dc345df462e6a3507d288bf7b791038920e7411e977a9078d8895eb59e7e046f0e9956a692&runid=18494'  > /var/www/vhosts/***/httpdocs/tmp/climulti/973b2bfe6f7adb381fa8c0b9fb6dc345df462e6a3507d288bf7b791038920e7411e977a9078d8895eb59e7e046f0e9956a692.output 2>&1 &
DEBUG [2022-03-04 17:03:19] 18494  Running command: /opt/plesk/php/8.0/bin/php -q -d memory_limit=12G -d error_log=/var/www/vhosts/***/logs/error_log_cli /var/www/vhosts/***/httpdocs/console climulti:request -q --matomo-domain='***' --superuser 'module=API&method=CoreAdminHome.archiveReports&idSite=1&period=week&date=2022-02-28&format=json&segment=pageUrl%3D%40%25252FNAV%25252F%2CpageUrl%3D%40.NAV%25252F%2CpageUrl%3D%40%25252FNAV.%2CpageUrl%3D%40.NAV.&trigger=archivephp&skipArchiveSegmentToday=1&pid=d839fce085bd2b21b51811ffd0046a42c324004cdde946ce4b15391fca6577509413de85e697019e171ce2374981a9747d303&runid=18494'  > /var/www/vhosts/***/httpdocs/tmp/climulti/d839fce085bd2b21b51811ffd0046a42c324004cdde946ce4b15391fca6577509413de85e697019e171ce2374981a9747d303.output 2>&1 &
DEBUG [2022-03-04 17:03:19] 18494  Running command: /opt/plesk/php/8.0/bin/php -q -d memory_limit=12G -d error_log=/var/www/vhosts/***/logs/error_log_cli /var/www/vhosts/***/httpdocs/console climulti:request -q --matomo-domain='***' --superuser 'module=API&method=CoreAdminHome.archiveReports&idSite=1&period=week&date=2022-02-28&format=json&segment=pageUrl%3D%40%25252FTR%25252F%2CpageUrl%3D%40.TR%25252F%2CpageUrl%3D%40%25252FTR.%2CpageUrl%3D%40.TR.&trigger=archivephp&skipArchiveSegmentToday=1&pid=6da6ebbc4fa3656ac1d71073ceb82e27b12f37522bcf3738e01f83e499d39d0c536d4f55753e1ada26f06a66b15f34df6b084&runid=18494'  > /var/www/vhosts/***/httpdocs/tmp/climulti/6da6ebbc4fa3656ac1d71073ceb82e27b12f37522bcf3738e01f83e499d39d0c536d4f55753e1ada26f06a66b15f34df6b084.output 2>&1 &
DEBUG [2022-03-04 17:03:19] 18494  Running command: /opt/plesk/php/8.0/bin/php -q -d memory_limit=12G -d error_log=/var/www/vhosts/***/logs/error_log_cli /var/www/vhosts/***/httpdocs/console climulti:request -q --matomo-domain='***' --superuser 'module=API&method=CoreAdminHome.archiveReports&idSite=1&period=week&date=2022-02-28&format=json&segment=pageUrl%3D%40%25252FCARS%25252F%2CpageUrl%3D%40.CARS%25252F%2CpageUrl%3D%40%25252FCARS.%2CpageUrl%3D%40.CARS.&trigger=archivephp&skipArchiveSegmentToday=1&pid=36ee011f21d20d3de3ea1ff719a38077c96baa326cdca66fbcca62f3f33220b695ff90262a24399f108fcf914c7cbfd66e735&runid=18494'  > /var/www/vhosts/***/httpdocs/tmp/climulti/36ee011f21d20d3de3ea1ff719a38077c96baa326cdca66fbcca62f3f33220b695ff90262a24399f108fcf914c7cbfd66e735.output 2>&1 &
INFO [2022-03-04 17:03:31] 18494  Archived website id 1, period = week, date = 2022-02-28, segment = 'pageUrl=@%2FCCBT%2F,pageUrl=@.CCBT%2F,pageUrl=@%2FCCBT.,pageUrl=@.CCBT.', 46 visits found. Time elapsed: 12.514s
INFO [2022-03-04 17:03:31] 18494  ''
INFO [2022-03-04 17:03:31] 18494  ''
INFO [2022-03-04 17:03:31] 18494  Archived website id 1, period = week, date = 2022-02-28, segment = 'pageUrl=@%2FNAV%2F,pageUrl=@.NAV%2F,pageUrl=@%2FNAV.,pageUrl=@.NAV.', 153 visits found. Time elapsed: 12.515s
INFO [2022-03-04 17:03:31] 18494  Archived website id 1, period = week, date = 2022-02-28, segment = 'pageUrl=@%2FTR%2F,pageUrl=@.TR%2F,pageUrl=@%2FTR.,pageUrl=@.TR.', 127 visits found. Time elapsed: 12.515s
INFO [2022-03-04 17:03:31] 18494  Archived website id 1, period = week, date = 2022-02-28, segment = 'pageUrl=@%2FCARS%2F,pageUrl=@.CARS%2F,pageUrl=@%2FCARS.,pageUrl=@.CARS.', 96 visits found. Time elapsed: 12.515s

The cron process outputs the following error message in that case:

ERROR [2022-03-04 17:03:31] 18494  Got invalid response from API request: ?module=API&method=CoreAdminHome.archiveReports&idSite=1&period=week&date=2022-02-28&format=json&segment=pageUrl%3D%40%25252FCUVS%25252F%2CpageUrl%3D%40.CUVS%25252F%2CpageUrl%3D%40%25252FCUVS.%2CpageUrl%3D%40.CUVS.&trigger=archivephp&skipArchiveSegmentToday=1. 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 [2022-03-04 17:03:31] 18494  Error unserializing the following response from ?module=API&method=CoreAdminHome.archiveReports&idSite=1&period=week&date=2022-02-28&format=json&segment=pageUrl%3D%40%25252FCUVS%25252F%2CpageUrl%3D%40.CUVS%25252F%2CpageUrl%3D%40%25252FCUVS.%2CpageUrl%3D%40.CUVS.&trigger=archivephp&skipArchiveSegmentToday=1: ''
ERROR [2022-03-04 17:03:31] 18494  Got invalid response from API request: ?module=API&method=CoreAdminHome.archiveReports&idSite=1&period=week&date=2022-02-28&format=json&segment=pageUrl%3D%40%25252FFCB%25252F%2CpageUrl%3D%40.FCB%25252F%2CpageUrl%3D%40%25252FFCB.%2CpageUrl%3D%40.FCB.%2CpageUrl%3D%40%25252FPCB%25252F%2CpageUrl%3D%40.PCB%25252F%2CpageUrl%3D%40%25252FPCB.%2CpageUrl%3D%40.PCB.&trigger=archivephp&skipArchiveSegmentToday=1. 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 [2022-03-04 17:03:31] 18494  Error unserializing the following response from ?module=API&method=CoreAdminHome.archiveReports&idSite=1&period=week&date=2022-02-28&format=json&segment=pageUrl%3D%40%25252FFCB%25252F%2CpageUrl%3D%40.FCB%25252F%2CpageUrl%3D%40%25252FFCB.%2CpageUrl%3D%40.FCB.%2CpageUrl%3D%40%25252FPCB%25252F%2CpageUrl%3D%40.PCB%25252F%2CpageUrl%3D%40%25252FPCB.%2CpageUrl%3D%40.PCB.&trigger=archivephp&skipArchiveSegmentToday=1: ''

I have increased the log level of Matomo to DEBUG, but there are no log entries for the API requests. I explicitly redirect the PHP error logging to a file. I have additionally checked the logging of PHP errors on the CLI this way and it works. However, the archiving process does not write errors to the PHP log.

It does not always abort the same API requests. At a later time the segmet could be processed.

What are my options for further error analysis? What could be reasons for API requests aborting?

Your Environment

sgiehl commented 2 years ago

Hi @dieisraels. Sorry to hear you are having issues with the archiving. Those segments on page urls are known to be a bit memory and time consuming, especially when they are not using an exact match. Are you using some custom configuration for [General] enable_segments_cache or enable_segments_subquery_cache?

dieisraels commented 2 years ago

No, I have not made any customizations to the above settings. I have made the following (possibly relevant) changes in the [Generic] section:

enabled_periods_UI = "day,week,month,year"
browser_archiving_disabled_enforce = 1
minimum_memory_limit_when_archiving = 4096
force_ssl = 1
datatable_archiving_maximum_rows_subtable_referrers = 500
datatable_archiving_maximum_rows_actions = 1000
datatable_archiving_maximum_rows_subtable_actions = 500
datatable_archiving_maximum_rows_events = 1000
datatable_archiving_maximum_rows_subtable_events = 100
DBX12 commented 2 years ago

However, the archiving process does not write errors to the PHP log. That is something I can confirm. My instance (4.8.0 on php 8.0.13) also does not log into the error log file. Running error_log("Test") creates the log file and writes the log line "Test" to it.