Add new system check: Check all expected table & columns a plugin expects to exist actually exist #16865

narfk · 2020-12-02T13:42:44Z

with the default Tracking Code (Backend) i got this error with the new 4.0.0 Version.
In 3.14.1 this works fine.

<script type="text/javascript">
  var _paq = window._paq = window._paq || [];
  _paq.push(['trackPageView']);
  _paq.push(['enableLinkTracking']);
  (function() {
    var u="https://statistics.domain.dd/piwik/";
    _paq.push(['setTrackerUrl', u+'matomo.php']);
    _paq.push(['setSiteId', '2']);
    var d=document, g=d.createElement('script'), s=d.getElementsByTagName('script')[0];
    g.type='text/javascript'; g.async=true; g.src=u+'matomo.js'; s.parentNode.insertBefore(g,s);
  })();
</script>

Header
Status400
Bad Request
VersionHTTP/1.1
Transferred1.13 KB (410 B size)
Referrer Policystrict-origin-when-cross-origin

While is was inspecting matomo.js i found setRequestMethod.
So i tried this.

<script type="text/javascript">
  var _paq = window._paq = window._paq || [];
  _paq.push(['setRequestMethod', 'GET']);
  _paq.push(['trackPageView']);
  _paq.push(['enableLinkTracking']);
  (function() {
    var u="https://statistics.domain.dd/piwik/";
    _paq.push(['setTrackerUrl', u+'matomo.php']);
    _paq.push(['setSiteId', '2']);
    var d=document, g=d.createElement('script'), s=d.getElementsByTagName('script')[0];
    g.type='text/javascript'; g.async=true; g.src=u+'matomo.js'; s.parentNode.insertBefore(g,s);
  })();
</script>

without any results.
Its still a POST and i got a bad request.

The URL in the networkinspector looks weird for a POST
https://statistics.domain.dd/piwik/matomo.phhp?action_name=title&idsite=2&rec=1&r=944278&h=14&m=29&s=34&url=...

Any advices?

The text was updated successfully, but these errors were encountered:

sgiehl · 2020-12-02T14:25:33Z

I don't think that has something to do with the POST request method. Matomo tries to use sendBeacon if that is available, which uses POST by default.

Maybe try enabling the debugging for tracking by setting

[Tracker]
debug = 1

in your config.ini.php

After that a tracking request should have debugging details as response. Maybe that helps to identify the problem.

tsteur · 2020-12-02T21:07:43Z

@narfk you may want to try _paq.push(['disableAlwaysUseSendBeacon']) if send beacon is causing any issues.

Meanwhile I have created a PR to automatically disable send beacon when forcing GET request method.

The POST URL by default includes all URL parameters so if there's a redirect then the parameters don't get lost. This is to avoid basically a regression as usually all webservers support POST.

By forcing POST request method those URL parameters would be gone and then they would be sent as a proper POST request.

narfk · 2020-12-03T06:47:11Z

_paq.push(['disableAlwaysUseSendBeacon']) forces a GET request. but with the same result => 400 bad request.

[Tracker]
debug = 1

I got this error with in Debugmode (_Error query: SQLSTATE[42S22]: Column not found: 1054 Unknown column 'last_idlink_va' in 'field list'). It doesn't matter if this is a GET or POST request

`[2020-12-03 06:10:15] piwik.DEBUG: Debug enabled - Input parameters: array () {"params":"array (...)"} {"class":"Piwik\\Tracker","request_id":"9d5f2"}

[2020-12-03 06:10:16] piwik.DEBUG: Current datetime: 2020-12-03 06:10:16 {"date":"2020-12-03 06:10:16"} {"class":"Piwik\\Tracker","request_id":"9d5f2"}

[2020-12-03 06:10:16] piwik.DEBUG: Website * tracker cache was re-created. [] {"class":"Piwik\\Tracker\\Cache","request_id":"9d5f2"}

[2020-12-03 06:10:16] piwik.DEBUG: Executing Piwik\Plugins\CoreHome\Tracker\VisitRequestProcessor::manipulateRequest()... [] {"class":"Piwik\\Common","request_id":"9d5f2"}

[2020-12-03 06:10:16] piwik.DEBUG: Executing Piwik\Plugins\Actions\Tracker\ActionsRequestProcessor::manipulateRequest()... [] {"class":"Piwik\\Common","request_id":"9d5f2"}

[2020-12-03 06:10:16] piwik.DEBUG: Executing Piwik\Plugins\Goals\Tracker\GoalsRequestProcessor::manipulateRequest()... [] {"class":"Piwik\\Common","request_id":"9d5f2"}

[2020-12-03 06:10:16] piwik.DEBUG: Executing Piwik\Plugins\Ecommerce\Tracker\EcommerceRequestProcessor::manipulateRequest()... [] {"class":"Piwik\\Common","request_id":"9d5f2"}

[2020-12-03 06:10:16] piwik.DEBUG: Executing Piwik\Plugins\SitesManager\Tracker\SitesManagerRequestProcessor::manipulateRequest()... [] {"class":"Piwik\\Common","request_id":"9d5f2"}

[2020-12-03 06:10:16] piwik.DEBUG: Executing Piwik\Plugins\PrivacyManager\Tracker\RequestProcessor::manipulateRequest()... [] {"class":"Piwik\\Common","request_id":"9d5f2"}

[2020-12-03 06:10:16] piwik.DEBUG: General tracker cache was re-created. [] {"class":"PrivacyManager","request_id":"9d5f2"}

[2020-12-03 06:10:16] piwik.DEBUG: Executing Piwik\Plugins\Heartbeat\Tracker\PingRequestProcessor::manipulateRequest()... [] {"class":"Piwik\\Common","request_id":"9d5f2"}

[2020-12-03 06:10:16] piwik.DEBUG: Executing Piwik\Plugins\PagePerformance\Tracker\PerformanceDataProcessor::manipulateRequest()... [] {"class":"Piwik\\Common","request_id":"9d5f2"}

[2020-12-03 06:10:16] piwik.DEBUG: Executing Piwik\Plugins\CustomDimensions\Tracker\CustomDimensionsRequestProcessor::manipulateRequest()... [] {"class":"Piwik\\Common","request_id":"9d5f2"}

[2020-12-03 06:10:16] piwik.DEBUG: Executing Piwik\Plugins\CustomVariables\Tracker\CustomVariablesRequestProcessor::manipulateRequest()... [] {"class":"Piwik\\Common","request_id":"9d5f2"}

[2020-12-03 06:10:16] piwik.DEBUG: Executing Piwik\Plugins\CoreHome\Tracker\VisitRequestProcessor::processRequestParams()... [] {"class":"Piwik\\Common","request_id":"9d5f2"}

[2020-12-03 06:10:17] piwik.DEBUG: DoNotTrack support is not enabled, skip check [] {"class":"PrivacyManager","request_id":"9d5f2"}

[2020-12-03 06:10:17] piwik.DEBUG: Matching visitors with: visitorId=xxx OR configId=8d8eb1f8c39499b2 [] {"class":"CoreHome","request_id":"9d5f2"}

[2020-12-03 06:10:17] piwik.DEBUG: Tracker encountered an exception: {ex} null {"class":"Piwik\\Tracker","request_id":"9d5f2"}

[2020-12-03 06:10:17] piwik.ERROR: Exception: /srv/www/DocRoot/piwik/core/Tracker/Db/Pdo/Mysql.php(238): Error query: SQLSTATE[42S22]: Column not found: 1054 Unknown column 'last_idlink_va' in 'field list' In query: SELECT visit_last_action_time, visit_first_action_time, idvisitor, idvisit, user_id, visit_exit_idaction_url, visit_exit_idaction_name, visitor_returning, visitor_seconds_since_first, visitor_seconds_since_order, visitor_count_visits, visit_goal_buyer, location_country, location_region, location_city, location_latitude, location_longitude, referer_name, referer_keyword, referer_type, idsite, profilable, visit_entry_idaction_url, visit_total_actions, visit_total_interactions, visit_total_searches, referer_url, config_browser_name, config_client_type, config_device_brand, config_device_model, config_device_type, visit_total_events, visit_total_time, location_ip, location_browser_lang, last_idlink_va, custom_var_k1, custom_var_v1, custom_var_k2, custom_var_v2, custom_var_k3, custom_var_v3, custom_var_k4, custom_var_v4, custom_var_k5, custom_var_v5  FROM piwik_log_visit FORCE INDEX (index_idsite_idvisitor)  WHERE idsite = ? AND visit_last_action_time <= ? AND idvisitor = ?                 ORDER BY visit_last_action_time DESC                 LIMIT 1 Parameters: array (   0 => *,   1 => '2020-12-03 06:40:16',   2 => '9�ù.xP£�', ) Error query: SQLSTATE[42S22]: Column not found: 1054 Unknown column 'last_idlink_va' in 'field list' In query: SELECT visit_last_action_time, visit_first_action_time, idvisitor, idvisit, user_id, visit_exit_idaction_url, visit_exit_idaction_name, visitor_returning, visitor_seconds_since_first, visitor_seconds_since_order, visitor_count_visits, visit_goal_buyer, location_country, location_region, location_city, location_latitude, location_longitude, referer_name, referer_keyword, referer_type, idsite, profilable, visit_entry_idaction_url, visit_total_actions, visit_total_interactions, visit_total_searches, referer_url, config_browser_name, config_client_type, config_device_brand, config_device_model, config_device_type, visit_total_events, visit_total_time, location_ip, location_browser_lang, last_idlink_va, custom_var_k1, custom_var_v1, custom_var_k2, custom_var_v2, custom_var_k3, custom_var_v3, custom_var_k4, custom_var_v4, custom_var_k5, custom_var_v5  FROM piwik_log_visit FORCE INDEX (index_idsite_idvisitor)  WHERE idsite = ? AND visit_last_action_time <= ? AND idvisitor = ?                 ORDER BY visit_last_action_time DESC                 LIMIT 1 Parameters: array (   0 => *,   1 => '2020-12-03 06:40:16',   2 => '9�ù.xP£�', ) #0 /srv/www/DocRoot/piwik/core/Tracker/Db/Pdo/Mysql.php(197): Piwik\Tracker\Db\Pdo\Mysql->query('SELECT visit_la...', Array) #1 /srv/www/DocRoot/piwik/core/Tracker/Model.php(458): Piwik\Tracker\Db\Pdo\Mysql->fetch('SELECT visit_la...', Array) #2 /srv/www/DocRoot/piwik/core/Tracker/Model.php(440): Piwik\Tracker\Model->fetchVisitor('SELECT visit_la...', 'FROM piwik_log_...', 'idsite = ? AND ...', Array) #3 /srv/www/DocRoot/piwik/core/Tracker/Model.php(401): Piwik\Tracker\Model->findVisitorByVisitorId('9\x17\xF9.xP\xA3\x15', 'SELECT visit_la...', 'FROM piwik_log_...', 'idsite = ? AND ...', Array) #4 /srv/www/DocRoot/piwik/core/Tracker/VisitorRecognizer.php(107): Piwik\Tracker\Model->findVisitor(*, '\x8D\x8E\xB1\xF8\xC3\x94\x99\xB2', '9\x17\xF9.xP\xA3\x15', false, Array, false, true, '2020-12-03 05:4...', '2020-12-03 06:4...') #5 /srv/www/DocRoot/piwik/plugins/CoreHome/Tracker/VisitRequestProcessor.php(118): Piwik\Tracker\VisitorRecognizer->findKnownVisitor('\x8D\x8E\xB1\xF8\xC3\x94\x99\xB2', Object(Piwik\Tracker\Visit\VisitProperties), Object(Piwik\Tracker\Request)) #6 /srv/www/DocRoot/piwik/core/Tracker/Visit.php(163): Piwik\Plugins\CoreHome\Tracker\VisitRequestProcessor->processRequestParams(Object(Piwik\Tracker\Visit\VisitProperties), Object(Piwik\Tracker\Request)) #7 /srv/www/DocRoot/piwik/core/Tracker.php(160): Piwik\Tracker\Visit->handle() #8 /srv/www/DocRoot/piwik/core/Tracker/Handler.php(55): Piwik\Tracker->trackRequest(Object(Piwik\Tracker\Request)) #9 /srv/www/DocRoot/piwik/core/Tracker.php(140): Piwik\Tracker\Handler->process(Object(Piwik\Tracker), Object(Piwik\Tracker\RequestSet)) #10 /srv/www/DocRoot/piwik/core/Tracker.php(115): Piwik\Tracker->track(Object(Piwik\Tracker\Handler), Object(Piwik\Tracker\RequestSet)) #11 /srv/www/DocRoot/piwik/piwik.php(73): Piwik\Tracker->main(Object(Piwik\Tracker\Handler), Object(Piwik\Tracker\RequestSet)) #12 /srv/www/DocRoot/piwik/matomo.php(13): include('/srv/www/DocRoo...') #13 {main} null {"class":"Piwik\\Tracker\\Handler","request_id":"9d5f2"}

while I was viewing at the code, i found some references in the CustomDimension plugin.
CustomDimenstion is the troublemaker. with deactivatet plugin the request works fine.

In my case this CustomDimenstion table looks like:

piwik_custom_dimensions (
idcustomdimension bigint(20) unsigned NOT NULL,
idsite bigint(20) unsigned NOT NULL,
name varchar(100) NOT NULL,
index smallint(5) unsigned NOT NULL,
scope varchar(10) NOT NULL,
active tinyint(3) unsigned NOT NULL DEFAULT '0',
extractions mediumtext NOT NULL,
case_sensitive tinyint(3) unsigned NOT NULL DEFAULT '1',
PRIMARY KEY (idcustomdimension,idsite),
UNIQUE KEY uniq_hash (idsite,scope,index)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4;

In my opinion the update script for 4.0.0 is wrong, not all tables/columns are created

sgiehl · 2020-12-03T07:19:54Z

@narfk Try removing the CustomDimensions plugin from config.ini.php. There should be an entry in the PluginsInstalled and Plugins section.
That should trigger the install of the plugin again, which should create the missing columns

narfk · 2020-12-03T07:30:39Z

@sgiehl This works in my Testenvironment. But There should be a dbUpdate-Script. I have a multiserver environment and this is not how it work. I cannot do this steps on every host.

sgiehl · 2020-12-03T07:38:09Z

Did you have the CustomDimensions plugin installed & activated before you did the update?

narfk · 2020-12-03T07:40:45Z

Nope. But i can remember that this plugin cames with the 4.0.0 db update script.
After Installing 4.0.0, CustomDimension was active by default.

sgiehl · 2020-12-03T07:44:17Z

Ok. That might be the reason. Seems the update might not trigger the plugin install if the plugin was not there before maybe.
Will investigate that.

narfk · 2020-12-03T07:51:57Z

Thanx!

sgiehl · 2020-12-03T08:06:49Z

Just installed a 3.14.1 and did an update to 4.0.3 using the UI updater. Custom Dimensions did not exist before, but was created with the update. The plugin was installed correctly and everything looks fine afterwards.

Did you do the update in the UI or using console command?

narfk · 2020-12-03T08:20:44Z

I was using the console command.

sgiehl · 2020-12-03T08:24:13Z

Ok. did you replace the files manually?

narfk · 2020-12-03T08:31:02Z

i was download the zip file with wget. but i created a new /piwik folder (and moved my configs).
the update command tooks arround 5-6 hours (the dbdump i made before was arround 50 gb).

sgiehl · 2020-12-03T08:49:24Z

Ok. Will try to reproduce it that way.
Was the CustomDimensions plugin marked as installed in your old config maybe?

narfk · 2020-12-03T09:45:15Z

No, it wasn't installed (in PluginDirectory).
Even nothing about it in the config files.

Findus23 · 2020-12-03T10:58:52Z

https://forum.matomo.org/t/error-1054-flooding-php-fpm-logs-after-upgrade-to-4-0-3/39619 seems to be having the same issue.

sgiehl · 2020-12-03T11:00:37Z

@narfk I'm not able to reproduce that behavior. Did a clean install of 3.14. Reused only the config file with a clean extract of 4.0.3 and ran update on console. All columns are created correctly and everything seems to work.
The only thing I could image is that Matomo somehow considered the plugin as already installed when the update tries to activate it. But not sure how that can happen (unless it's already in config, but not installed)

@tsteur Do you maybe have an idea? Would it maybe make sense to directly trigger installing the plugin maybe?

narfk · 2020-12-03T12:33:54Z

@sgiehl i was checking the config files before 4.0.0. nothing about the custom dimension plugin. maybe something happend during the update. at least the workaround (remove plugin, reactive plugin) seems to work. hopefully this won't happen in the live environment.

maybe something for the the system check?

tsteur · 2020-12-03T19:40:47Z

Thanks for all the troubleshooting work @narfk we'll probably not add something to the system check there for now as we'd need to put some new code into every plugin exposing what columns they expect to exist etc. I'll keep this open though for now as we might do it in the future.

ysard · 2020-12-21T04:04:23Z

Hi, same error here from 3.13.x (3.13.3 if I remember correctly) to 4.0.5.

First, just after the installation process (from the website, not from the console), I had errors on the dashboard, related to #16868.
As mentioned in the issue, this was resolved by:
ALTER TABLE log_conversion ADD COLUMN config_browser_name VARCHAR(40) NULL;

But after that PHP started to output a large amount of this error:

2020/12/20 11:19:07 [error] 2623#2623: *196 FastCGI sent in stderr: "PHP message: Error in Matomo (tracker): Error query: preparing query failed: Unknown column 'last_idlink_va' in 'field list' : SELECT visit_last_action_time, visit_first_action_time, idvisitor, idvisit, user_id, visit_exit_idaction_url, visit_exit_idaction_name, visitor_returning, visitor_seconds_since_first, visitor_seconds_since_order, visitor_count_visits, visit_goal_buyer, location_country, location_region, location_city, location_latitude, location_longitude, referer_name, referer_keyword, referer_type, idsite, profilable, visit_entry_idaction_url, visit_total_actions, visit_total_interactions, visit_total_searches, referer_url, config_browser_name, config_client_type, config_device_brand, config_device_model, config_device_type, visit_total_events, visit_total_time, location_ip, location_browser_lang, last_idlink_va FROM piwik_log_visit FORCE INDEX (index_idsite_idvisitor) WHERE idsite = ? AND visit_last_action_time <= ? AND idvisitor = ? ORDER BY visit_last_action_time DES" while reading response header from upstream, client: <client>, server: <domain_name>, request: "POST <url data>"

These errors are gone now by deactivating/reactivating the CustomDimensions plugin, thanks to this issue.

After that, the following missing columns were added in piwik_log_visit :

last_idlink_va  bigint(20) unsigned NULL
custom_dimension_1  varchar(255) NULL
custom_dimension_2  varchar(255) NULL
custom_dimension_3  varchar(255) NULL
custom_dimension_4  varchar(255) NULL
custom_dimension_5  varchar(255) NULL

Honestly I could not say if this plugin was activated before.
One thing is certain, I had added the support for more than 5 custom variables per query on this installation (FAQ related page: https://matomo.org/faq/how-to/faq_17931/). And by doing the manipulation for CustomDimensions I found that the CustomVariables plugin was disabled, which obviously was not the case before the update.

Before reactivation of CustomVariables:

./console customvariables:info
ERROR [2020-12-21 03:12:26] 20780  Uncaught exception: /var/www/html/piwik/vendor/symfony/console/Symfony/Component/Console/Application.php(501): There are no commands defined in the "customvariables" namespace.
There are no commands defined in the "customvariables" namespace.
                                                                     
  [InvalidArgumentException]                                         
  There are no commands defined in the "customvariables" namespace.

After:

./console customvariables:info

Your Piwik is configured for 6 custom variables.

Hope this helps you...

Findus23 · 2021-03-22T20:39:30Z

This might be the same as #11540 and #17211

mattab · 2023-12-11T17:42:01Z

Thanks for creating the issue. Closing as duplicate of #11540

tsteur added the Regression Indicates a feature used to work in a certain way but it no longer does even though it should. label Dec 2, 2020

tsteur added this to the 4.0.3 milestone Dec 2, 2020

tsteur self-assigned this Dec 2, 2020

tsteur mentioned this issue Dec 2, 2020

When forcing GET request method in JS tracker then disable send beacon #16870

Merged

9 tasks

tsteur changed the title ~~Request from matomo.js to matomo.php is a POST instead a GET that returns a bad request~~ Add new system check: Check all expected table & columns a plugin expects to exist actually exist Dec 3, 2020

tsteur modified the milestones: 4.0.3, Priority Backlog (Help wanted) Dec 3, 2020

tsteur added c: Platform For Matomo platform changes that aren't impacting any of our APIs but improve the core itself. and removed Regression Indicates a feature used to work in a certain way but it no longer does even though it should. labels Dec 3, 2020

tsteur removed their assignment May 20, 2021

mattab closed this as not planned Won't fix, can't repro, duplicate, stale Dec 11, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add new system check: Check all expected table & columns a plugin expects to exist actually exist #16865

Add new system check: Check all expected table & columns a plugin expects to exist actually exist #16865

narfk commented Dec 2, 2020 •

edited

sgiehl commented Dec 2, 2020

tsteur commented Dec 2, 2020

narfk commented Dec 3, 2020 •

edited

sgiehl commented Dec 3, 2020

narfk commented Dec 3, 2020

sgiehl commented Dec 3, 2020

narfk commented Dec 3, 2020 •

edited

sgiehl commented Dec 3, 2020

narfk commented Dec 3, 2020

sgiehl commented Dec 3, 2020

narfk commented Dec 3, 2020

sgiehl commented Dec 3, 2020

narfk commented Dec 3, 2020 •

edited

sgiehl commented Dec 3, 2020

narfk commented Dec 3, 2020

Findus23 commented Dec 3, 2020

sgiehl commented Dec 3, 2020

narfk commented Dec 3, 2020

tsteur commented Dec 3, 2020

ysard commented Dec 21, 2020

Findus23 commented Mar 22, 2021

mattab commented Dec 11, 2023

Add new system check: Check all expected table & columns a plugin expects to exist actually exist #16865

Add new system check: Check all expected table & columns a plugin expects to exist actually exist #16865

Comments

narfk commented Dec 2, 2020 • edited

sgiehl commented Dec 2, 2020

tsteur commented Dec 2, 2020

narfk commented Dec 3, 2020 • edited

sgiehl commented Dec 3, 2020

narfk commented Dec 3, 2020

sgiehl commented Dec 3, 2020

narfk commented Dec 3, 2020 • edited

sgiehl commented Dec 3, 2020

narfk commented Dec 3, 2020

sgiehl commented Dec 3, 2020

narfk commented Dec 3, 2020

sgiehl commented Dec 3, 2020

narfk commented Dec 3, 2020 • edited

sgiehl commented Dec 3, 2020

narfk commented Dec 3, 2020

Findus23 commented Dec 3, 2020

sgiehl commented Dec 3, 2020

narfk commented Dec 3, 2020

tsteur commented Dec 3, 2020

ysard commented Dec 21, 2020

Findus23 commented Mar 22, 2021

mattab commented Dec 11, 2023

narfk commented Dec 2, 2020 •

edited

narfk commented Dec 3, 2020 •

edited

narfk commented Dec 3, 2020 •

edited

narfk commented Dec 3, 2020 •

edited