Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Visits not inserted in log_visit and no errors triggered (unknown reason) #13755

Closed
mattab opened this issue Nov 23, 2018 · 18 comments
Closed

Visits not inserted in log_visit and no errors triggered (unknown reason) #13755

mattab opened this issue Nov 23, 2018 · 18 comments
Labels
answered For when a question was asked and we referred to forum or answered it. Waiting for user feedback Indicates the Matomo team is waiting for feedback from the author or other users.

Comments

@mattab
Copy link
Member

mattab commented Nov 23, 2018

Reported in https://forum.matomo.org/t/no-longer-logging-vists-piwik-php-called/29700/3

We can see in the tracker debug output that the Visit insertion seems to have occured, but actually failed:


DEBUG: array (
DEBUG:   'idvisitor' => '1db1ff046f15737f',
DEBUG:   'config_id' => '5c6948980cd42fd4',
DEBUG:   'location_ip' => 'xxx.xxx.xx.0',
DEBUG:   'idsite' => 1,
DEBUG:   'visit_first_action_time' => '2018-09-05 19:48:42',
[....]
DEBUG: )
DEBUG: Executing Piwik\Plugins\CoreHome\Tracker\VisitRequestProcessor::recordLogs()...
DEBUG: Executing Piwik\Plugins\Actions\Tracker\ActionsRequestProcessor::recordLogs()...
DEBUG: Inserted new action:
DEBUG: array (
DEBUG:   'idvisit' => 0,
DEBUG:   'idsite' => 1,
DEBUG:   'idvisitor' => '1db1ff046f15737f',

Here we see that 'idvisit' => 0, so it seems the log_visit insert went wrong? it is reproducible for this user and hasn't worked since months ago. Maybe the problem is a corrupted log_visit table but it could be anything really..

Suggested steps:

  • In the tracker debug log, let's add at the end the output of SHOW WARNINGS query so we can maybe learn about some hidden problems
  • maybe we need to double check in the code that we catch all possible errors/warnings from MySQL inserts during tracker
  • in the tracker code could we add a check if idvisit == 0 then we can exit with an error and not record the data? this way it's more likely these problems will be detected.
  • what do you think?
@mattab mattab added Bug For errors / faults / flaws / inconsistencies etc. Major Indicates the severity or impact or benefit of an issue is much higher than normal but not critical. labels Nov 23, 2018
@mattab mattab modified the milestones: 3.9.0, 3.10.0 Nov 23, 2018
@tyler71
Copy link

tyler71 commented Nov 24, 2018

Posted as requested from forum.

core/Profiler.php was patched and debug set to 1

Which DB Driver do you use (PDO or MYSQLI?)?

adapter = "MYSQLI"

Yes it is still occurring in 3.7.0.

With your patch I did not see any errors after specifically "Show warnings (SQL)" but here is the result

DEBUG: Debug enabled - Input parameters:
DEBUG: array (
DEBUG:   'action_name' => '',
DEBUG:   'idsite' => '1',
DEBUG:   'rec' => '1',
DEBUG:   'r' => '158468',
DEBUG:   'h' => '19',
DEBUG:   'm' => '9',
DEBUG:   's' => '18',
DEBUG:   'url' => 'https://www.mydomain.org/',
DEBUG:   '_id' => '60b9440dabe74582',
DEBUG:   '_idts' => '1543028958',
DEBUG:   '_idvc' => '1',
DEBUG:   '_idn' => '0',
DEBUG:   '_refts' => '0',
DEBUG:   '_viewts' => '1543028958',
DEBUG:   'cs' => 'windows-1252',
DEBUG:   'send_image' => '1',
DEBUG:   'pdf' => '0',
DEBUG:   'qt' => '0',
DEBUG:   'realp' => '0',
DEBUG:   'wma' => '0',
DEBUG:   'dir' => '0',
DEBUG:   'fla' => '1',
DEBUG:   'java' => '0',
DEBUG:   'gears' => '0',
DEBUG:   'ag' => '0',
DEBUG:   'cookie' => '1',
DEBUG:   'res' => '1920x1080',
DEBUG:   'gt_ms' => '48',
DEBUG:   'pv_id' => 'Xs27md',
DEBUG: )
DEBUG: Current datetime: 2018-11-24 03:10:05
DEBUG: Executing Piwik\Plugins\CoreHome\Tracker\VisitRequestProcessor::manipulateRequest()...
DEBUG: Executing Piwik\Plugins\IntranetMeasurable\Tracker\RequestProcessor::manipulateRequest()...
DEBUG: Executing Piwik\Plugins\Actions\Tracker\ActionsRequestProcessor::manipulateRequest()...
DEBUG: Executing Piwik\Plugins\Goals\Tracker\GoalsRequestProcessor::manipulateRequest()...
DEBUG: Executing Piwik\Plugins\SitesManager\Tracker\SitesManagerRequestProcessor::manipulateRequest()...
DEBUG: Executing Piwik\Plugins\PrivacyManager\Tracker\RequestProcessor::manipulateRequest()...
DEBUG: Executing Piwik\Plugins\Heartbeat\Tracker\PingRequestProcessor::manipulateRequest()...
DEBUG: Executing Piwik\Plugins\CoreHome\Tracker\VisitRequestProcessor::processRequestParams()...
DEBUG: DoNotTrack header not found
DEBUG: Matching visitors with: visitorId=60b9440dabe74582 OR configId=e8649634bc0fc22b
DEBUG: The visitor was not matched with an existing visitor...
DEBUG: Executing Piwik\Plugins\IntranetMeasurable\Tracker\RequestProcessor::processRequestParams()...
DEBUG: Executing Piwik\Plugins\Actions\Tracker\ActionsRequestProcessor::processRequestParams()...
DEBUG: (this is not a Site Search request)
DEBUG: Excluding parameters "fepaction,gclid,fb_xd_fragment,fb_comment_id,phpsessid,jsessionid,sessionid,aspsessionid,doing_wp_cron,sid,pk_vid,pk_cpn,pk_campaign,piwik_campaign,utm_campaign,utm_source,utm_medium,pk_kwd,pk_keyword,piwik_kwd,utm_term" from URL
DEBUG: Action is a PAGE_URL,
DEBUG:                 Action name =  ,
DEBUG:                 Action URL = https://www.mydomain.org/
DEBUG: Executing Piwik\Plugins\Goals\Tracker\GoalsRequestProcessor::processRequestParams()...
DEBUG: Executing Piwik\Plugins\SitesManager\Tracker\SitesManagerRequestProcessor::processRequestParams()...
DEBUG: Executing Piwik\Plugins\PrivacyManager\Tracker\RequestProcessor::processRequestParams()...
DEBUG: Executing Piwik\Plugins\Heartbeat\Tracker\PingRequestProcessor::processRequestParams()...
DEBUG: Executing Piwik\Plugins\CoreHome\Tracker\VisitRequestProcessor::afterRequestProcessed()...
DEBUG: Visitor IP (was: 168.xxx.xx.33) has been anonymized: 168.xxx.xx.0
DEBUG: Executing Piwik\Plugins\IntranetMeasurable\Tracker\RequestProcessor::afterRequestProcessed()...
DEBUG: Executing Piwik\Plugins\Actions\Tracker\ActionsRequestProcessor::afterRequestProcessed()...
DEBUG: Executing Piwik\Plugins\Goals\Tracker\GoalsRequestProcessor::afterRequestProcessed()...
DEBUG: Executing Piwik\Plugins\SitesManager\Tracker\SitesManagerRequestProcessor::afterRequestProcessed()...
DEBUG: Executing Piwik\Plugins\PrivacyManager\Tracker\RequestProcessor::afterRequestProcessed()...
DEBUG: Executing Piwik\Plugins\Heartbeat\Tracker\PingRequestProcessor::afterRequestProcessed()...
DEBUG: New Visit (IP = xxx.xxx.xx.0)
DEBUG: Following dimensions have been collected from plugins: idsite, user_id, visit_first_action_time, visit_first_action_time, visit_goal_buyer, visit_goal_converted, idvisit, location_ip, visit_last_action_time, visit_last_action_time, visit_last_action_time, visit_last_action_time, visit_last_action_time, visit_last_action_time, visit_last_action_time, visit_last_action_time, visit_last_action_time, visit_last_action_time, visit_last_action_time, visitor_days_since_first, visitor_days_since_order, idvisitor, visitor_returning, visitor_count_visits, visit_entry_idaction_name, visit_entry_idaction_url, visit_exit_idaction_name, visit_exit_idaction_url, visit_total_actions, visit_total_interactions, visit_total_searches, , referer_keyword, referer_name, referer_type, referer_url, , location_browser_lang, config_browser_engine, config_browser_name, config_browser_version, config_device_brand, config_device_model, config_device_type, config_os, config_os_version, visitor_localtime, visitor_localtime, visitor_days_since_last, config_resolution, config_cookie, config_director, config_flash, config_gears, config_java, config_pdf, config_quicktime, config_realplayer, config_silverlight, config_windowsmedia, , visit_total_time, location_city, location_country, location_latitude, location_longitude, location_provider, location_region, location_provider
DEBUG: GEO: Found IP xxx.xxx.xx.33 location (provider 'geoip_php'): array (
DEBUG:   'country_code' => 'US',
DEBUG:   'region_code' => 'CA',
DEBUG:   'city_name' => 'Los Angeles',
DEBUG:   'area_code' => 213,
DEBUG:   'lat' => xx.058,
DEBUG:   'long' => -xx.27800000000001,
DEBUG:   'postal_code' => '90017',
DEBUG:   'continent_code' => 'amn',
DEBUG:   'continent_name' => 'Intl_Continent_amn',
DEBUG:   'country_name' => 'Unknown',
DEBUG:   'region_name' => 'California',
DEBUG: )
DEBUG: array (
DEBUG:   'idvisitor' => '60b9440dabe74582',
DEBUG:   'config_id' => 'e8649634bc0fc22b',
DEBUG:   'location_ip' => 'xxx.xxx.xx.0',
DEBUG:   'idsite' => 1,
DEBUG:   'visit_first_action_time' => '2018-11-24 03:10:05',
DEBUG:   'visit_goal_buyer' => 0,
DEBUG:   'visit_goal_converted' => 0,
DEBUG:   'visit_last_action_time' => '2018-11-24 03:10:05',
DEBUG:   'visitor_days_since_first' => '0',
DEBUG:   'visitor_days_since_order' => 0,
DEBUG:   'visitor_returning' => 0,
DEBUG:   'visitor_count_visits' => 1,
DEBUG:   'visit_entry_idaction_name' => 0,
DEBUG:   'visit_entry_idaction_url' => 440,
DEBUG:   'visit_exit_idaction_name' => 0,
DEBUG:   'visit_exit_idaction_url' => 440,
DEBUG:   'visit_total_actions' => 1,
DEBUG:   'visit_total_interactions' => 1,
DEBUG:   'visit_total_searches' => 0,
DEBUG:   'referer_keyword' => NULL,
DEBUG:   'referer_name' => NULL,
DEBUG:   'referer_type' => 1,
DEBUG:   'referer_url' => '',
DEBUG:   'location_browser_lang' => 'en-us',
DEBUG:   'config_browser_engine' => 'Gecko',
DEBUG:   'config_browser_name' => 'FF',
DEBUG:   'config_browser_version' => '63.0',
DEBUG:   'config_device_brand' => '',
DEBUG:   'config_device_model' => 'generic desktop',
DEBUG:   'config_device_type' => 0,
DEBUG:   'config_os' => 'UBT',
DEBUG:   'config_os_version' => '',
DEBUG:   'visitor_localtime' => '19:09:18',
DEBUG:   'visitor_days_since_last' => '0',
DEBUG:   'config_resolution' => '1920x1080',
DEBUG:   'config_cookie' => 1,
DEBUG:   'config_director' => 0,
DEBUG:   'config_flash' => 1,
DEBUG:   'config_gears' => 0,
DEBUG:   'config_java' => 0,
DEBUG:   'config_pdf' => 0,
DEBUG:   'config_quicktime' => 0,
DEBUG:   'config_realplayer' => 0,
DEBUG:   'config_silverlight' => 0,
DEBUG:   'config_windowsmedia' => 0,
DEBUG:   'visit_total_time' => 0,
DEBUG:   'location_city' => 'Los Angeles',
DEBUG:   'location_country' => 'us',
DEBUG:   'location_latitude' => '34.058',
DEBUG:   'location_longitude' => '-118.278',
DEBUG:   'location_region' => 'CA',
DEBUG:   'location_provider' => 'Ip',
DEBUG: )
DEBUG: Executing Piwik\Plugins\CoreHome\Tracker\VisitRequestProcessor::recordLogs()...
DEBUG: Executing Piwik\Plugins\IntranetMeasurable\Tracker\RequestProcessor::recordLogs()...
DEBUG: Executing Piwik\Plugins\Actions\Tracker\ActionsRequestProcessor::recordLogs()...
DEBUG: Inserted new action:
DEBUG: array (
DEBUG:   'idvisit' => 0,
DEBUG:   'idsite' => 1,
DEBUG:   'idvisitor' => '60b9440dabe74582',
DEBUG:   'idaction_url' => '440',
DEBUG:   'idaction_url_ref' => 0,
DEBUG:   'idaction_name_ref' => 0,
DEBUG:   'server_time' => '2018-11-24 03:10:05',
DEBUG:   'idpageview' => 'Xs27md',
DEBUG:   'interaction_position' => 1,
DEBUG:   'time_spent_ref_action' => 0,
DEBUG:   'idaction_name' => 0,
DEBUG:   'custom_float' => '48',
DEBUG:   'idlink_va' => 316964,
DEBUG: )
DEBUG: Executing Piwik\Plugins\Goals\Tracker\GoalsRequestProcessor::recordLogs()...
DEBUG: Executing Piwik\Plugins\SitesManager\Tracker\SitesManagerRequestProcessor::recordLogs()...
DEBUG: Executing Piwik\Plugins\PrivacyManager\Tracker\RequestProcessor::recordLogs()...
DEBUG: Executing Piwik\Plugins\Heartbeat\Tracker\PingRequestProcessor::recordLogs()...
DEBUG: -> Scheduled tasks not running in Tracker: Browser archiving is disabled.
DEBUG: Nothing to notice => default behaviour
DEBUG: End of the page.
DEBUG: Show warnings (SQL):
DEBUG: array (
)
DEBUG: <hr /><strong>Breakdown by query</strong><br/>Executed <b>9</b> times in <b>3.1ms</b>  (average = <b>0.3ms</b>) <pre>  connect</pre>Executed <b>4</b> times in <b>2.4ms</b>  (average = <b>0.6ms</b>) <pre>  SELECT option_value, option_name FROM `piwik_option` WHERE autoload = 1</pre>Executed <b>1</b> time in <b>0.8ms</b>  <pre>  SELECT MIN(idaction) as idaction, type, name FROM piwik_log_action WHERE ( hash = CRC32('mydomain.org/') AND name = 'mydomain.org/' AND type = '1' ) GROUP BY type, hash, name</pre>Executed <b>1</b> time in <b>0.8ms</b>  <pre> SELECT MIN(idaction) as idaction, type, name FROM piwik_log_action WHERE ( hash = CRC32('2015 Kindle Paperwhite - LED Strain') AND name = '2015 Kindle Paperwhite - LED Strain' AND type = '4' ) OR ( hash = CRC32('ledstrain.org/d/56-2015-kindle-paperwhite') AND name = 'ledstrain.org/d/56-2015-kindle-paperwhite' AND type = '1' ) GROUP BY type, hash, name</pre>Executed <b>1</b> time in <b>0.8ms</b>  <pre>  SELECT option_value FROM `piwik_option` WHERE option_name = 'SearchEngineDefinitions'</pre>Executed <b>1</b> time in <b>0.8ms</b>  <pre>  SHOW COLUMNS FROM `piwik_log_visit`</pre>Executed <b>1</b> time in <b>0.7ms</b>  <pre>  SELECT MIN(idaction) as idaction, type, name FROM piwik_log_action WHERE ( hash = CRC32('Agency Complaints – Global Adoption News') AND name = 'Agency Complaints – Global Adoption News' AND type = '4' ) OR ( hash = CRC32('adoptionland.org/category/agency_complaints/') AND name = 'adoptionland.org/category/agency_complaints/' AND type = '1' ) GROUP BY type, hash, name</pre>Executed <b>1</b> time in <b>0.7ms</b>  <pre>  SHOW COLUMNS FROM `piwik_log_link_visit_action`</pre>Executed <b>2</b> times in <b>0.6ms</b>  (average = <b>0.3ms</b>) <pre>  SELECT option_name, option_value FROM `piwik_option` WHERE option_name LIKE 'report_to_invalidate_1_2018-11-23%'</pre>Executed <b>1</b> time in <b>0.6ms</b>  <pre> SHOW COLUMNS FROM `piwik_log_conversion`</pre>Executed <b>2</b> times in <b>0.6ms</b>  (average = <b>0.3ms</b>) <pre> SELECT url FROM piwik_site_url WHERE idsite = '4'</pre>Executed <b>1</b> time in <b>0.6ms</b>  <pre>  INSERT INTO `piwik_option` (option_name, option_value, autoload) VALUES ('report_to_invalidate_4_2018-11-23_2593', '1', '0') </pre>Executed <b>1</b> time in <b>0.5ms</b>  <pre>  INSERT INTO `piwik_option` (option_name, option_value, autoload) VALUES ('report_to_invalidate_1_2018-11-23_4830', '1', '0') </pre>Executed <b>4</b> times in <b>0.5ms</b>  (average = <b>0.1ms</b>) <pre>  SELECT option_value FROM `piwik_option` WHERE option_name = 'SitesManager_SearchCategoryParameters'</pre>Executed <b>4</b> times in <b>0.5ms</b>  (average = <b>0.1ms</b>) <pre>  SELECT option_value FROM `piwik_option` WHERE option_name = 'SitesManager_ExcludedUserAgentsGlobal'</pre>Executed <b>4</b> times in <b>0.5ms</b>  (average = <b>0.1ms</b>) <pre>  SELECT option_value FROM `piwik_option` WHERE option_name = 'SitesManager_SearchKeywordParameters'</pre>Executed <b>4</b> times in <b>0.5ms</b>  (average = <b>0.1ms</b>) <pre> SELECT option_value FROM `piwik_option` WHERE option_name = 'SitesManager_ExcludedIpsGlobal'</pre>Executed <b>4</b> times in <b>0.5ms</b>  (average = <b>0.1ms</b>) <pre> SELECT option_value FROM `piwik_option` WHERE option_name = 'SitesManager_KeepURLFragmentsGlobal'</pre>Executed <b>4</b> times in <b>0.4ms</b>  (average = <b>0.1ms</b>) <pre>  SELECT option_value FROM `piwik_option` WHERE option_name = 'SitesManager_ExcludedQueryParameters'</pre>Executed <b>4</b> times in <b>0.4ms</b>  (average = <b>0.1ms</b>) <pre> SELECT option_value FROM `piwik_option` WHERE option_name = 'SitesManager_EnableSiteSpecificUserAgentExclude'</pre>Executed <b>4</b> times in <b>0.4ms</b>  (average = <b>0.1ms</b>) <pre>  SELECT MIN(idaction) as idaction, type, name FROM piwik_log_action WHERE ( hash = CRC32('Global Adoption News – Adoptionland') AND name = 'Global Adoption News – Adoptionland' AND type = '4' ) OR ( hash = CRC32('adoptionland.org/') AND name = 'adoptionland.org/' AND type = '1' ) GROUP BY type, hash, name</pre>Executed <b>2</b> times in <b>0.4ms</b>  (average = <b>0.2ms</b>) <pre>  SELECT * FROM piwik_goal WHERE idsite IN (1) AND deleted = 0</pre>Executed <b>4</b> times in <b>0.3ms</b>  (average = <b>0.1ms</b>) <pre> SELECT * FROM piwik_site WHERE idsite = '1'</pre>Executed <b>2</b> times in <b>0.3ms</b>  (average = <b>0.2ms</b>) <pre>  UPDATE `piwik_option` SET option_value = '1', autoload = '0' WHERE option_name = 'report_to_invalidate_4_2018-11-23_2593'</pre>Executed <b>1</b> time in <b>0.3ms</b>  <pre>  SELECT option_value FROM `piwik_option` WHERE option_name = 'lastTrackerCronRun'</pre>Executed <b>1</b> time in <b>0.3ms</b>  <pre> SELECT option_name, option_value FROM `piwik_option` WHERE option_name LIKE 'report_to_invalidate_4_2018-11-23%'</pre>Executed <b>2</b> times in <b>0.3ms</b>  (average = <b>0.2ms</b>) <pre> SELECT * FROM piwik_goal WHERE idsite IN (4) AND deleted = 0</pre>Executed <b>1</b> time in <b>0.3ms</b>  <pre> SELECT option_value FROM `piwik_option` WHERE option_name = 'usercountry.location_provider'</pre>Executed <b>4</b> times in <b>0.2ms</b>  (average = <b>0.1ms</b>) <pre>  SELECT * FROM piwik_site WHERE idsite = '4'</pre>Executed <b>1</b> time in <b>0.2ms</b>  <pre>SELECT option_value FROM `piwik_option` WHERE option_name = 'PrivacyManager.useAnonymizedIpForVisitEnrichment'</pre>Executed <b>2</b> times in <b>0.2ms</b>  (average = <b>0.1ms</b>) <pre> SELECT login FROM piwik_access WHERE idsite = '1' AND access = 'admin'</pre>Executed <b>1</b> time in <b>0.2ms</b>  <pre> SELECT option_value FROM `piwik_option` WHERE option_name = 'PrivacyManager.ipAnonymizerEnabled'</pre>Executed <b>1</b> time in <b>0.2ms</b>  <pre> SELECT option_value FROM `piwik_option` WHERE option_name = 'PrivacyManager.ipAddressMaskLength'</pre>Executed <b>1</b> time in <b>0.1ms</b>  <pre> SELECT option_value FROM `piwik_option` WHERE option_name = 'PrivacyManager.anonymizeUserId'</pre>Executed <b>2</b> times in <b>0.1ms</b>  (average = <b>0.1ms</b>) <pre> SELECT url FROM piwik_site_url WHERE idsite = '1'</pre>Executed <b>1</b> time in <b>0.1ms</b>  <pre>  SELECT option_value FROM `piwik_option` WHERE option_name = 'PrivacyManager.doNotTrackEnabled'</pre>Executed <b>1</b> time in <b>0.1ms</b>  <pre> SELECT option_value FROM `piwik_option` WHERE option_name = 'PrivacyManager.anonymizeOrderId'</pre>Executed <b>2</b> times in <b>0.1ms</b>  (average = <b>0.1ms</b>) <pre>  SELECT login FROM piwik_access WHERE idsite = '1' AND access = 'write'</pre>Executed <b>2</b> times in <b>0.1ms</b>  (average = <b>0.1ms</b>) <pre> SELECT login FROM piwik_access WHERE idsite = '4' AND access = 'admin'</pre>Executed <b>2</b> times in <b>0.1ms</b>  (average = <b>0.1ms</b>) <pre> SELECT * FROM piwik_user WHERE login IN ('applefire') ORDER BY login ASC</pre>Executed <b>2</b> times in <b>0.1ms</b>  (average = <b>0.1ms</b>) <pre> SELECT login FROM piwik_access WHERE idsite = '4' AND access = 'write'</pre>
DEBUG: array (
DEBUG:   'PIWIK_SESSID' => 'c8pmgd1b3p6qoq2j6jhsak6f43',
DEBUG: )
DEBUG: Time elapsed: 0.076s

@tsteur
Copy link
Member

tsteur commented Nov 25, 2018

Show warnings would need to be executed after each query or not? Not just at the end...

@tsteur
Copy link
Member

tsteur commented Mar 17, 2019

@tyler71 before we invest any time in this please let us know your MySQL version and show create table matomo_log_visit(orpiwik_log_visit`).

Does it record this page view when you open the URL? https://$DOMAIN/piwik.php?rec=1&idsite=1&action_name=foo
Ideally you would give us view access to your system in order to help you.

@mattab mattab removed this from the 3.11.0 milestone Mar 20, 2019
@tyler71
Copy link

tyler71 commented Apr 4, 2019

show create table
https://gist.github.com/tyler71/ad318f40bb00417ea1f1d2a19c101ee4

The page view is not recorded when opened with browsers.
wget shows the pixel image is downloaded

Ideally you would give us view access to your system in order to help you.

Like a account in my matomo instance?

@tsteur
Copy link
Member

tsteur commented Apr 4, 2019

Do other things work in your Matomo instance such as creating a scheduled report? Updating password, or making any change to settings in Admin => General Settings?

I'm thinking on this instance maybe autocommit is disabled or so.

@tyler71
Copy link

tyler71 commented Apr 4, 2019

I updated my password and it worked fine

Attempting to navigate around the site is now resulting in a error in specific areas (Visits in real time, visits logs, etc)

Oops… there was a problem during the request. Maybe the server had a temporary issue, or maybe you requested a report with too much data. Please try again. If this error occurs repeatedly please contact your Matomo administrator for assistance. 

Nginx Error logs reveal this:

sudo tail -fn0 /var/log/nginx/error.log
2019/04/04 13:29:50 [error] 521#521: *34435 FastCGI sent in stderr: "PHP message: PHP Fatal error:  Allowed memory size of 134217728 bytes exhausted (tried to allocate 20480 bytes) in /html/piwik/libs/Zend/Db/Statement/Mysqli.php on line 304" while reading response header from upstream, client: xx.xx.x.xx, server: my.foobardomain.com, request: "POST /index.php?date=2019-03-29,2019-04-04&module=Live&action=widget&widget=1&disableLink=0&idSite=4&period=range HTTP/1.1", upstream: "fastcgi://unix:/var/run/php7-fpm.services.sock:", host: "my.foobardomain.com"
2019/04/04 13:29:50 [error] 528#528: *34427 FastCGI sent in stderr: "PHP message: PHP Fatal error:  Allowed memory size of 134217728 bytes exhausted (tried to allocate 20480 bytes) in /html/piwik/libs/Zend/Db/Statement/Mysqli.php on line 304" while reading response header from upstream, client: xx.xx.x.xx, server: my.foobardomain.com, request: "POST /index.php?period=range&idSite=4&segment=&date=last3&format=json&showRawMetrics=1&module=API&method=Live.getLastVisitsDetails&filter_limit=100&showColumns=latitude%2Clongitude%2Cactions%2ClastActionTimestamp%2CvisitLocalTime%2Ccity%2Ccountry%2CcountryCode%2CreferrerType%2CreferrerName%2CreferrerTypeName%2CbrowserIcon%2CoperatingSystemIcon%2CdeviceType%2CdeviceModel%2CcountryFlag%2CidVisit%2CactionDetails%2CcontinentCode%2Cactions%2Csearches%2CgoalConversions%2CvisitorId%2CuserId&minTimestamp=0 HTTP/1.1", upstream: "fastcgi://unix:/var/run/php7-fpm.services.sock:", host: "my.foobardomain.com"

Memory leak?

Edit:
I also currently have 0 visits being shown so this is occuring on both 0 visits and on reports of older visits (eg 2017)

@tsteur
Copy link
Member

tsteur commented Apr 5, 2019

You definitely want to increase your memory limit to say 256MB or even 512MB. 128MB can be quite low.

@tyler71
Copy link

tyler71 commented Apr 7, 2019

Attempting to navigate around the site is now resulting in a error in specific areas (Visits in real time, visits logs, etc)

Changed to 256MB resolved the above error

Unfortunately, no visits are recording still

@tsteur
Copy link
Member

tsteur commented Apr 7, 2019

Ideally you would give us view access to your system in order to help you.

Like a account in my matomo instance?

We would ideally need a login for your Matomo instance, plus access to the code on the server so we can investigate the issue.

@mattab mattab removed the Major Indicates the severity or impact or benefit of an issue is much higher than normal but not critical. label Apr 25, 2019
@mattab
Copy link
Member Author

mattab commented Jul 1, 2019

Hi @tyler71 are you still experiencing this issue? If so, be great if you can reach out to us via: http://matomo.org/contact/
and we'll follow up and investigate with you. Thanks!

@mattab mattab added the Waiting for user feedback Indicates the Matomo team is waiting for feedback from the author or other users. label Jul 1, 2019
@genachka
Copy link

@mattab not sure if I'm having the same issue, but after upgrading to 3.11.0 from 3.9 2 days ago none of my new visits are being recorded for any of my sites. I'm running in docker (via crazymax/matomo:3.11.0 container) and traefik (via traefik 1.7.14 container) and mariadb (via mariadb:10.4.7 container). Console log shows that the requests come in but it's as if they aren't being stored in database. I'm using a cron sidecar and it reports no issues doing archive. I tried to manually update the database on console as well as archive (always now says no new visits) and no errors reported.

@tsteur
Copy link
Member

tsteur commented Aug 15, 2019

I recommend you check in matomo_log_visit table (name depends on your table prefix) whether there are actually recent visits coming in (sort by idvisit and keep refereshing the table). If not, you will want to debug the tracker: https://developer.matomo.org/api-reference/tracking-api#debugging-the-tracker

@genachka
Copy link

@tsteur thanks for your suggestions. Looks like last written was on the 13th right before I upgraded.

@genachka
Copy link

  1. I left the database container at 10.4.7 but restored the database I had with 3.9.1 and reverted matomo container to 3.9.1 and the cron sidecar to 3.9.1 and it started writing to the database.
  2. I then upgraded both containers to 3.11.0 and same results (nothing new being written to db).
  3. I left the database container at 10.4.7 but restored the database I had with 3.9.1 and set matomo container to 3.10.0 and the cron sidecar to 3.10.0 and it started writing to the database too.
  4. I then upgraded both containers to 3.11.0 and same results (nothing new being written to db).
    So appears to be something with the 3.11.0 upgrade... :( Going to 3.10.0 for now.

@mattab
Copy link
Member Author

mattab commented Aug 16, 2019

@genachka can you follow instructions at https://developer.matomo.org/api-reference/tracking-api#debugging-the-tracker and see what is the output message in debug mode?

@genachka
Copy link

@mattab just to follow up here, I didn't have the chance to do as you suggested so I just left it running on the reverted 3.10.0 until 3.12.0 was released. I upgraded to 3.12.0 without the issues. Maybe it was something with the crazymax/matomo:3.11.0 container or something in the Matomo 3.11.0 code. But all good now.

Running without issues for almost a week on with the following containers:

  • traefik:1.7.19
  • crazymax/matomo:3.12.0
  • Matomo:3.12.0
  • MariaDB:10.4.8
  • PHP:7.3.11

@tsteur
Copy link
Member

tsteur commented Nov 14, 2019

Great to know it works now. Thanks

@tsteur tsteur closed this as completed Nov 14, 2019
@tsteur tsteur added answered For when a question was asked and we referred to forum or answered it. and removed Bug For errors / faults / flaws / inconsistencies etc. labels Nov 14, 2019
@mattab
Copy link
Member Author

mattab commented Nov 14, 2019

Thanks for the update! I'll close the ticket now as we haven't got more reports since.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
answered For when a question was asked and we referred to forum or answered it. Waiting for user feedback Indicates the Matomo team is waiting for feedback from the author or other users.
Projects
None yet
Development

No branches or pull requests

4 participants