Action table for type '12' was not found during Actions archiving

[JanST123]

Hi, I started using Piwik a week ago, tracking 2 websites. The archiving cron runs every hour.

Now I recognized that the archiving stopped working for one of the two websites 4 days ago. It worked for both websites before (see the screenshot: https://drive.google.com/file/d/0B7Ss7W8DbUYtNm9rOFkzbUxFMTQ/view?usp=sharing)

Here is the full output from the archiving job:

root@server1:/var/www/piwik.xxxxxx.de/piwik# /var/www/piwik.jstmail.de/piwik/console core:archive --url=https://piwik.xxxxxx.de

INFO [2017-04-18 13:31:13] ---------------------------
INFO [2017-04-18 13:31:13] INIT
INFO [2017-04-18 13:31:13] Running Piwik 3.0.3 as Super User
INFO [2017-04-18 13:31:13] ---------------------------
INFO [2017-04-18 13:31:13] NOTES
INFO [2017-04-18 13:31:13] - Reports for today will be processed at most every 150 seconds. You can change this value in Piwik UI > Settings > General Settings.
INFO [2017-04-18 13:31:13] - Reports for the current week/month/year will be refreshed at most every 3600 seconds.
INFO [2017-04-18 13:31:13] - Archiving was last executed without error 4 days 2 hours ago
INFO [2017-04-18 13:31:13] - Will process 2 other websites because the last time they were archived was on a different day (in the website's timezone) , IDs: 1, 2
INFO [2017-04-18 13:31:13] - Will process 1 other websites because some old data reports have been invalidated (eg. using the Log Import script) , IDs: 2
INFO [2017-04-18 13:31:13] ---------------------------
INFO [2017-04-18 13:31:13] START
INFO [2017-04-18 13:31:13] Starting Piwik reports archiving...
INFO [2017-04-18 13:31:13] Day has finished for website id 1 since last run
INFO [2017-04-18 13:31:13] Will pre-process for website id = 1, period = day, date = last10
INFO [2017-04-18 13:31:13] - pre-processing all visits
INFO [2017-04-18 13:31:14] Archived website id = 1, period = day, 0 segments, 749 visits in last 10 days, 107 visits today, Time elapsed: 0.810s
INFO [2017-04-18 13:31:14] Will pre-process for website id = 1, period = week, date = last2
INFO [2017-04-18 13:31:14] - pre-processing all visits
INFO [2017-04-18 13:31:15] Archived website id = 1, period = week, 0 segments, 749 visits in last 2 weeks, 259 visits this week, Time elapsed: 0.628s
INFO [2017-04-18 13:31:15] Will pre-process for website id = 1, period = month, date = last2
INFO [2017-04-18 13:31:15] - pre-processing all visits
INFO [2017-04-18 13:31:15] Archived website id = 1, period = month, 0 segments, 749 visits in last 2 months, 749 visits this month, Time elapsed: 0.720s
INFO [2017-04-18 13:31:15] Will pre-process for website id = 1, period = year, date = last2
INFO [2017-04-18 13:31:15] - pre-processing all visits
INFO [2017-04-18 13:31:16] Archived website id = 1, period = year, 0 segments, 749 visits in last 2 years, 749 visits this year, Time elapsed: 0.599s
INFO [2017-04-18 13:31:16] Archived website id = 1, 4 API requests, Time elapsed: 2.763s [1/2 done]
INFO [2017-04-18 13:31:16] Day has finished for website id 2 since last run
INFO [2017-04-18 13:31:16] Will pre-process for website id = 2, period = day, date = last10
INFO [2017-04-18 13:31:16] - pre-processing all visits
ERROR [2017-04-18 13:31:17] Got invalid response from API request: ?module=API&method=API.get&idSite=2&period=day&date=last10&format=php&trigger=archivephp. Response was 'a:2:{s:6:"result";s:5:"error";s:7:"message";s:93:"Action table for type '12' was not found during Actions archiving. - caused by plugin Actions";}'
ERROR [2017-04-18 13:31:17] Empty or invalid response '' for website id 2, Time elapsed: 0.377s, skipping
INFO [2017-04-18 13:31:17] Done archiving!
INFO [2017-04-18 13:31:17] ---------------------------
INFO [2017-04-18 13:31:17] SUMMARY
INFO [2017-04-18 13:31:17] Total visits for today across archived websites: 107
INFO [2017-04-18 13:31:17] Archived today's reports for 1 websites
INFO [2017-04-18 13:31:17] Archived week/month/year for 1 websites
INFO [2017-04-18 13:31:17] Skipped 1 websites
INFO [2017-04-18 13:31:17] - 0 skipped because no new visit since the last script execution
INFO [2017-04-18 13:31:17] - 0 skipped because existing daily reports are less than 150 seconds old
INFO [2017-04-18 13:31:17] - 0 skipped because existing week/month/year periods reports are less than 3600 seconds old
INFO [2017-04-18 13:31:17] - 1 skipped because got an error while querying reporting API
INFO [2017-04-18 13:31:17] Total API requests: 4
INFO [2017-04-18 13:31:17] done: 1/2 50%, 107 vtoday, 1 wtoday, 1 wperiods, 4 req, 3341 ms, 2 errors.
INFO [2017-04-18 13:31:17] Time elapsed: 3.341s
INFO [2017-04-18 13:31:17] ---------------------------
INFO [2017-04-18 13:31:17] SCHEDULED TASKS
INFO [2017-04-18 13:31:17] Starting Scheduled tasks...
INFO [2017-04-18 13:31:17] done
INFO [2017-04-18 13:31:17] ---------------------------
INFO [2017-04-18 13:31:17] ---------------------------
INFO [2017-04-18 13:31:17] SUMMARY OF ERRORS
INFO [2017-04-18 13:31:17] Error: Got invalid response from API request: ?module=API&method=API.get&idSite=2&period=day&date=last10&format=php&trigger=archivephp. Response was 'a:2:{s:6:"result";s:5:"error";s:7:"message";s:93:"Action table for type '12' was not found during Actions archiving. - caused by plugin Actions";}'
INFO [2017-04-18 13:31:17] Error: Empty or invalid response '' for website id 2, Time elapsed: 0.377s, skipping
ERROR [2017-04-18 13:31:17] 2 total errors during this script execution, please investigate and try and fix these errors.

Edit: This is the system summary. System-check is all green. I did not install any additional plugins. If you need additional information please ask. :)

1 Benutzer 4 Segmente 2 Websites 43 aktivierte Plugins Piwik-Version: 3.0.3 MySQL-Version: 5.5.54 PHP-Version: 7.0.18-1~dotdeb+8.1

[sgiehl]

Did you change anything on that day? Maybe added a plugin or changed the tracking code to track additional stuff? Can you see visits tracked in the real time log?

[JanST123]

No I didn't changed anything on that day. Neither on server side nor on tracking side.

I can still see all the visits in the realtime log.

[mattab]

Can you check that the Events plugin is activated for you?

[JanST123]

Hi @mattab, yes - the Plugin is enabled.

[mattab]

@JanST123 have you experienced this issue again, or was it just a one-off?

[JanST123]

Hi @mattab , yes this issue still occurs. I'm just workarounding it by adding a "return;" statement before the Exception is thrown in plugins/Actions/ArchivingHelper.php. I guess due to this workaround I will miss some data, but the Archiving is working again (until the next Piwik update). I'm currently on Piwik 3.0.4

366         if (is_null($currentTable)) {
367 return;
368             throw new \Exception("Action table for type '$actionType' was not found during Actions archiving.");
369         }

I can provide you with a database dump, if it can help you debugging this issue.

[mattab]

Ok thanks for confirming. We will investigate in the next few weeks, and may ask for a DB dump if needed then. cc @sgiehl would be great to understand and tackle that issue sometime soon (we can move to next release if we don't make it in this one)

[sgiehl]

@JanST123 I'll try to tackle that issue. Could you please send a database dump to stefan@piwik.org. That might make it easier to reproduce the issue. Thx.

[JanST123]

@sgiehl You've got mail :)

[sgiehl]

@JanST123 thx. will have a look

[sgiehl]

Ok. I was able to identify the problem and why the archiving fails. The archiving query generated in Actions Archiver returns some entries with action type 12, which is event name. Those entries should imho be excluded by log_link_visit_action.idaction_event_category IS NULL, but seems there are some entries without event category. Fixing the query should be easy, but additionally we should investigate how those entries were created in the first place, as they might somehow be not correct.

[JanST123]

That may happen because of my event tracking implementation where the category is always the search term the user recently entered. It should not happen that events are tracked without search term/when no search is active - but I could imagine that it can happen somehow.

[tsteur]

Maybe event_category could be set to an empty string when not passed and event_name is given?

[sgiehl]

Thought of something similar. But actually it's not empty string, as _paq.push(['trackEvent', '', 'action', 'name']); won't trigger any tracking. It seems to happen for category strings filled with one or more whitespaces, as they are truncated here. @tsteur should we do the trim() in js tracker already and discard trackings with an empty/whitespace category?

[tsteur]

It needs to be fixed in core to have it fixed for all trackers. However, we should trim the category in the tracker and throw an error there as well and not even send the request to Piwik.

Wouldn't we need to return return '' instead of return false there? Alternatively, we could throw an InvalidRequestParameterException as it looks like a category is mandatory. Or we could remove the trim but that might be confusing when no value is disabled in the reporting (we could however apply the trim with a filter in the API and display message like "No text provided").

The doc says "e_c" must not be empty in https://developer.piwik.org/api-reference/tracking-api which actually applies to a category with whitespace. I would personally remove the trim as I don't think there should be such logic but also happy with any solution. Removing the trim might screw the data for people who have been tracking with leading / trailing whitespace so maybe throwing an InvalidRequestParameterException and mentioning the trim in the docs could be better.

https://github.com/piwik/piwik/blob/3.x-dev/plugins/Events/Actions/ActionEvent.php#L38 would probably stay as it is.

[sgiehl]

@tsteur proposed some changes to fix that. Maybe you could have a short look.