No longer logging vists; piwik.php called


#1

My install is not tracking visits anymore after (I believe) I upgraded it a few days ago.
It’s been working for a few years now but I went through and fixed some small issues listed here but don’t think they mattered much

https://matomo.org/faq/troubleshooting/faq_58/

  • Disabled 3rd party plugins (just 1 but no change)
  • SSL fully verified and working
  • Fresh browser with all do not track / adblock disabled or uninstalled.

My nginx server logs show that piwik.js is loaded and then calls piwik.php at my hosting site (using https).
I feel like this should then be logged

xx.xxx.xxx.xxx - [04/Sep/2018:18:03:47 -0700] 200 "GET /piwik.js HTTP/1.1" "65697" "0.000" "https://domain.tld/2982/10-red-flags-that-your-xxxxxxx-xxxxxxx-xxxxxxx-xxxxxxx-xxxxxxx/" "my_piwik_site.com" "Mozilla/5.0 (Linux; Android 8.0.0; SM-G950U Build/R16NW; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/68.0.3440.91 Mobile Safari/537.36 [FB_IAB/FB4A;FBAV/187.0.0.43.81;]"
xx.xxx.xxx.xxx - [04/Sep/2018:18:03:48 -0700] 200 "GET /piwik.php?action_name=10%20Red%20Flags%20That%20Your%20xxxxxxx%20xxxxxxx%20xxxxxxx%20xxxxxxx%20xxxxxxx%20%E2%80%93%20xxxxxxx%20xxxxxxx%20News&idsite=1&rec=1&r=044778&h=19&m=3&s=47&url=https%3A%2F%2Fdomain.tld%2F2982%2F10-red-flags-that-your-xxxxxxx-xxxxxxx-xxxxxxx-xxxxxxx-xxxxxxx%2F&urlref=https%3A%2F%2Flm.xxxxxxx.com%2F&_id=2e31a16f6efd70f1&_idts=1536109427&_idvc=1&_idn=0&_refts=1536109427&_viewts=1536109427&_ref=https%3A%2F%2Flm.facebook.com%2F&send_image=1&cookie=1&res=360x740&gt_ms=737&pv_id=dljmMR HTTP/1.1" "272" "0.273" "https://domain.tld/2982/10-red-flags-that-your-xxxxxxx-xxxxxxx-xxxxxxx-xxxxxxx-xxxxxxx/" "my_piwik_site.com" "Mozilla/5.0 (Linux; Android 8.0.0; SM-G950U Build/R16NW; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/68.0.3440.91 Mobile Safari/537.36 [FB_IAB/FB4A;FBAV/187.0.0.43.81;]"

Because it is calling piwik.js and then piwik.php with the correct info (with a 200 response) I would figure piwik (matomo) would then update the visitor log. But that doesn’t happen.


(Lukas Winkler) #2

Hi,

The easiest way is to enable debugging temporarily:
https://developer.matomo.org/api-reference/tracking-api#debugging-the-tracker

This way the /piwik.php request will respond with a verbose log that explains why it isn’t saved.


#3

I mimicked a piwik.php request with curl with debug=1 enabled (and then disabled it)
Still nothing is being tracked on all sites. Unfortunately, I’m unable to identify any leads in the debug. Perhaps I’m missing something?

DEBUG: Debug enabled - Input parameters: 
DEBUG: array (
DEBUG:   'action_name' => 'My Sites News – mydomain',
DEBUG:   'idsite' => '1',
DEBUG:   'rec' => '1',
DEBUG:   'r' => '466869',
DEBUG:   'h' => '12',
DEBUG:   'm' => '44',
DEBUG:   's' => '38',
DEBUG:   'url' => 'https://mydomain.org/',
DEBUG:   '_id' => '1db1ff046f15737f',
DEBUG:   '_idts' => '1536176518',
DEBUG:   '_idvc' => '1',
DEBUG:   '_idn' => '0',
DEBUG:   '_refts' => '0',
DEBUG:   '_viewts' => '1536176518',
DEBUG:   'send_image' => '1',
DEBUG:   'pdf' => '1',
DEBUG:   'qt' => '0',
DEBUG:   'realp' => '0',
DEBUG:   'wma' => '0',
DEBUG:   'dir' => '0',
DEBUG:   'fla' => '0',
DEBUG:   'java' => '0',
DEBUG:   'gears' => '0',
DEBUG:   'ag' => '0',
DEBUG:   'cookie' => '1',
DEBUG:   'res' => '1920x1080',
DEBUG:   'gt_ms' => '505',
DEBUG:   'pv_id' => 'ZBlvWR',
DEBUG: )
DEBUG: Current datetime: 2018-09-05 19:48:42
DEBUG: Executing Piwik\Plugins\CoreHome\Tracker\VisitRequestProcessor::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=1db1ff046f15737f OR configId=5c6948980cd42fd4
DEBUG: The visitor was not matched with an existing visitor...
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 =  My Sites News – mydomain,
DEBUG:                 Action URL = https://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: xxx.xxx.xx.xx) has been anonymized: xxx.xxx.xx.0
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.xx location (provider 'geoip_php'): array (
DEBUG:   'country_code' => 'US',
DEBUG:   'region_code' => 'xx',
DEBUG:   'city_name' => 'Los Angeles',
DEBUG:   'area_code' => xxx,
DEBUG:   'lat' => xx.058,
DEBUG:   'long' => -xxx.278,
DEBUG:   'postal_code' => 'xxxxxx',
DEBUG:   'continent_code' => 'amn',
DEBUG:   'continent_name' => 'Intl_Continent_amn',
DEBUG:   'country_name' => 'Unknown',
DEBUG:   'region_name' => 'California',
DEBUG: )
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:   'visit_goal_buyer' => 0,
DEBUG:   'visit_goal_converted' => 0,
DEBUG:   'visit_last_action_time' => '2018-09-05 19:48:42',
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' => 7828,
DEBUG:   'visit_entry_idaction_url' => 1318,
DEBUG:   'visit_exit_idaction_name' => 7828,
DEBUG:   'visit_exit_idaction_url' => 1318,
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' => '',
DEBUG:   'config_browser_engine' => '',
DEBUG:   'config_browser_name' => 'UNK',
DEBUG:   'config_browser_version' => '7.38',
DEBUG:   'config_device_brand' => '',
DEBUG:   'config_device_model' => '',
DEBUG:   'config_device_type' => NULL,
DEBUG:   'config_os' => 'UNK',
DEBUG:   'config_os_version' => 'UNK',
DEBUG:   'visitor_localtime' => '12:44:38',
DEBUG:   'visitor_days_since_last' => '0',
DEBUG:   'config_resolution' => '1920x1080',
DEBUG:   'config_cookie' => 1,
DEBUG:   'config_director' => 0,
DEBUG:   'config_flash' => 0,
DEBUG:   'config_gears' => 0,
DEBUG:   'config_java' => 0,
DEBUG:   'config_pdf' => 1,
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' => 'xx.058',
DEBUG:   'location_longitude' => '-xxx.278',
DEBUG:   'location_region' => 'CA',
DEBUG:   'location_provider' => 'Ip',
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',
DEBUG:   'idaction_url' => '1318',
DEBUG:   'idaction_url_ref' => 0,
DEBUG:   'idaction_name_ref' => 0,
DEBUG:   'server_time' => '2018-09-05 19:48:42',
DEBUG:   'idpageview' => 'ZBlvWR',
DEBUG:   'interaction_position' => 1,
DEBUG:   'time_spent_ref_action' => 0,
DEBUG:   'idaction_name' => '7828',
DEBUG:   'custom_float' => '505',
DEBUG:   'idlink_va' => 283774,
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: <hr /><strong>Breakdown by query</strong><br/>Executed <b>4</b> times in <b>1.6ms</b>  (average = <b>0.4ms</b>) <pre>	connect</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('My Sites News – mydomain') AND name = 'My Sites News – mydomain' AND type = '4' ) OR ( hash = CRC32('mydomain.org/') AND name = 'mydomain.org/' AND type = '1' ) GROUP BY type, hash, name</pre>
DEBUG: array (
DEBUG: )
DEBUG: Time elapsed: 0.038s

#4

I reverted the database and files to a time where tracking was working.
However, still nothing is being tracked at all.
It’s not working over about 10 sites and I’m really not sure what the next step is

I don’t see any errors in the debug output that I could use to followup on.
Any advice?


#5

I hate to bump my issue, but this continues to affect me.
I have no idea what to do next. It’s been running fine for years until about a month ago


(Peterbo) #6

Data seems to be tracked correctly. Perhaps archiving is somehow not triggered correctly. Do you have recent data in the visitor log report?


#7

No recent data. At least since Aug 28th (across all websites)

Recent data log showing no results

I run archiving with cron every 30 min

/usr/bin/php /var/www/foobar/console core:archive --url=my.domain.tld
INFO [2018-10-08 13:55:52] 5312  ---------------------------
INFO [2018-10-08 13:55:52] 5312  INIT
INFO [2018-10-08 13:55:52] 5312  Running Matomo 3.6.0 as Super User
INFO [2018-10-08 13:55:52] 5312  ---------------------------
INFO [2018-10-08 13:55:52] 5312  NOTES
INFO [2018-10-08 13:55:52] 5312  - Reports for today will be processed at most every 800 seconds. You can change this value in Matomo UI > Settings > General Settings.
INFO [2018-10-08 13:55:52] 5312  - Reports for the current week/month/year will be requested at most every 3600 seconds.
INFO [2018-10-08 13:55:52] 5312  - Archiving was last executed without error 25 min 49s ago
INFO [2018-10-08 13:55:52] 5312  ---------------------------
INFO [2018-10-08 13:55:52] 5312  START
INFO [2018-10-08 13:55:52] 5312  Starting Matomo reports archiving...
INFO [2018-10-08 13:55:52] 5312  - no new tracking data for website id 1 since 2018-10-08 13:30:03 UTC (since the last successful archiving)
INFO [2018-10-08 13:55:52] 5312  Skipped website id 1 as archiving is not needed
INFO [2018-10-08 13:55:52] 5312  - no new tracking data for website id 2 since 2018-10-08 13:30:03 UTC (since the last successful archiving)
INFO [2018-10-08 13:55:52] 5312  Skipped website id 2 as archiving is not needed
INFO [2018-10-08 13:55:52] 5312  - no new tracking data for website id 3 since 2018-10-08 13:30:03 UTC (since the last successful archiving)
INFO [2018-10-08 13:55:52] 5312  Skipped website id 3 as archiving is not needed
INFO [2018-10-08 13:55:52] 5312  - no new tracking data for website id 4 since 2018-10-08 13:30:03 UTC (since the last successful archiving)
INFO [2018-10-08 13:55:52] 5312  Skipped website id 4 as archiving is not needed
INFO [2018-10-08 13:55:52] 5312  - no new tracking data for website id 6 since 2018-10-08 13:30:03 UTC (since the last successful archiving)
INFO [2018-10-08 13:55:52] 5312  Skipped website id 6 as archiving is not needed
INFO [2018-10-08 13:55:52] 5312  - no new tracking data for website id 8 since 2018-10-08 13:30:03 UTC (since the last successful archiving)
INFO [2018-10-08 13:55:52] 5312  Skipped website id 8 as archiving is not needed
INFO [2018-10-08 13:55:52] 5312  - no new tracking data for website id 9 since 2018-10-08 13:30:03 UTC (since the last successful archiving)
INFO [2018-10-08 13:55:52] 5312  Skipped website id 9 as archiving is not needed 
INFO [2018-10-08 13:55:52] 5312  - no new tracking data for website id 10 since 2018-10-08 13:30:03 UTC (since the last successful archiving)
INFO [2018-10-08 13:55:52] 5312  Skipped website id 10 as archiving is not needed
INFO [2018-10-08 13:55:52] 5312  Done archiving!
INFO [2018-10-08 13:55:52] 5312  ---------------------------
INFO [2018-10-08 13:55:52] 5312  SUMMARY
INFO [2018-10-08 13:55:52] 5312  Total visits for today across archived websites: 0
INFO [2018-10-08 13:55:52] 5312  Archived today's reports for 0 websites
INFO [2018-10-08 13:55:52] 5312  Archived week/month/year for 0 websites
INFO [2018-10-08 13:55:52] 5312  Skipped 8 websites
INFO [2018-10-08 13:55:52] 5312  - 8 skipped because no new visit since the last script execution
INFO [2018-10-08 13:55:52] 5312  - 0 skipped because existing daily reports are less than 800 seconds old
INFO [2018-10-08 13:55:52] 5312  - 0 skipped because existing week/month/year periods reports are less than 3600 seconds old
INFO [2018-10-08 13:55:52] 5312  Total API requests: 0
INFO [2018-10-08 13:55:52] 5312  done: 0/8 0%, 0 vtoday, 0 wtoday, 0 wperiods, 0 req, 330 ms, no error
INFO [2018-10-08 13:55:52] 5312  Time elapsed: 0.330s
INFO [2018-10-08 13:55:52] 5312  ---------------------------
INFO [2018-10-08 13:55:52] 5312  SCHEDULED TASKS
INFO [2018-10-08 13:55:52] 5312  Starting Scheduled tasks... 
INFO [2018-10-08 13:55:52] 5312  done
INFO [2018-10-08 13:55:52] 5312  ---------------------------

(Lukas Winkler) #8

Hi,

Would it be possible, that you send me a private message with the link to the website where Matomo is tracked? Maybe we are overlooking something obvious.


#9

Certainly. I don’t know how to PM but I will look that up soon.
Are you requesting the url where Matoma is hosted, or one of the sites it is tracking?
For additional information during that time, by my check I have…

6 sites using wordpress piwik (matomo) plugin

and 2 sites using a Flarum (a forum) extension called Analytics
https://discuss.flarum.org/d/1983-flagrow-analytics-extension-tracking-user-visits


(Lukas Winkler) #10

Hi @Koo1,

PMs were disabled, but should now work (click on my profile picture).
I would like to know the URL of one of the sites that are tracked.


#11

Have you been able to find a resolution for this problem? We are on version 2.17.1 and we have the same symptoms. The piwik.php file is called, debug information doesn’t show anything wrong and the archiving is running on a cron. At a glance everything seems to work properly and piwik doesn’t report any problems.

The weird thing is that the debug log shows the queries been run and interact with some piwik tables and they do in fact get updated. The only table that the documentation says to watch for is piwik_log_visit and this table hasn’t been updated since October 29th on our side.


#12

No it was never resolved. I installed a brand new install as well and nothing was fixed.
One of my users ultimately went to Google Analytics.


#13

If you still can, have a look in the log_visit and log_link_visit_action table whether the request was recorded or not. It looks like it is. In this case double check idSites, archiving, etc.


#14

for the last recorded visit in log_visit (which matches the visitor log)
2018-08-28 16:41:03

log_link_visit_action still seems to be triggered interestingly.
2018-11-15 19:44:13

The idSite is correct (I’ve checked at least a dozen times and just now again)
How would I check archiving?

I run archiving with cron every 30 min
Archiving was last executed without error 25 min 49s ago

I posted this above, the output showed (I believe) that it is being run

In this case double check … etc.

I’ve already checked
https://matomo.org/faq/troubleshooting/faq_58/
Is there more things to check?