The output should actually explain the behavior:

INFO [2020-12-03 06:38:20] 18083 - Reports for today will be processed at most every 600 seconds. You can change this value in Matomo UI > Settings > General Settings.
INFO [2020-12-03 06:38:20] 18083 - Archiving was last executed without error 1 min 38s ago

Seems the archiving did run shortly before, so it's skipped...

It has not been running for close to 16 hours now. I just copy & pasted recently ran core:archive.

Then there might be an error while archiving. Could you look up an older run that maybe had errors?

Where I can find the log that contains this error?

Thanks

If you don't have logs of older archiving runs you may simply trigger it manually on command line ./console core:archive

There is no error :( with the normal cron run.

INFO [2020-12-03 09:00:01] 9742 ---------------------------
INFO [2020-12-03 09:00:01] 9742 INIT
INFO [2020-12-03 09:00:01] 9742 Running Matomo 4.0.3 as Super User
INFO [2020-12-03 09:00:01] 9742 ---------------------------
INFO [2020-12-03 09:00:01] 9742 NOTES
INFO [2020-12-03 09:00:01] 9742 - Async process archiving supported, using CliMulti.
INFO [2020-12-03 09:00:01] 9742 - Reports for today will be processed at most every 600 seconds. You can change this value in Matomo UI > Settings > General Settings.
INFO [2020-12-03 09:00:01] 9742 - Archiving was last executed without error 10 min 0s ago
INFO [2020-12-03 09:00:01] 9742 ---------------------------
INFO [2020-12-03 09:00:01] 9742 START
INFO [2020-12-03 09:00:01] 9742 Starting Matomo reports archiving...
INFO [2020-12-03 09:00:01] 9742 Start processing archives for site 1.
INFO [2020-12-03 09:00:01] 9742 Finished archiving for site 1, 0 API requests, Time elapsed: 0.001s [1 / 1 done]
INFO [2020-12-03 09:00:01] 9742 Done archiving!
INFO [2020-12-03 09:00:01] 9742 ---------------------------
INFO [2020-12-03 09:00:01] 9742 SUMMARY
INFO [2020-12-03 09:00:01] 9742 Processed 0 archives.
INFO [2020-12-03 09:00:01] 9742 Total API requests: 0
INFO [2020-12-03 09:00:01] 9742 done: 0 req, 156 ms, no error
INFO [2020-12-03 09:00:01] 9742 Time elapsed: 0.156s
INFO [2020-12-03 09:00:01] 9742 ---------------------------
INFO [2020-12-03 09:00:01] 9742 SCHEDULED TASKS
INFO [2020-12-03 09:00:02] 9742 Starting Scheduled tasks...
INFO [2020-12-03 09:00:02] 9742 Scheduler: executing task Piwik\Plugins\CustomJsTracker\Tasks.updateTracker...
INFO [2020-12-03 09:00:02] 9742 Scheduler: finished. Time elapsed: 0.001s
INFO [2020-12-03 09:00:02] 9742 Scheduler: executing task Piwik\Plugins\PrivacyManager\Tasks.deleteLogData...
INFO [2020-12-03 09:00:02] 9742 Scheduler: finished. Time elapsed: 0.002s
INFO [2020-12-03 09:00:02] 9742 Scheduler: executing task Piwik\Plugins\PrivacyManager\Tasks.anonymizePastData...
INFO [2020-12-03 09:00:02] 9742 Scheduler: finished. Time elapsed: 0.000s
INFO [2020-12-03 09:00:02] 9742 Scheduler: executing task Piwik\Plugins\QueuedTracking\Tasks.notifyQueueSize...
INFO [2020-12-03 09:00:02] 9742 Scheduler: finished. Time elapsed: 0.001s
INFO [2020-12-03 09:00:02] 9742 done
INFO [2020-12-03 09:00:02] 9742 ---------------------------

But it is logging visits to the database

Hi @valmedia we're planning to release Matomo 4.0.4 in the next 24 hours. The update might fix this issue. Let us know if that's not the case and we'll reopen and investigate further.

If you could otherwise run ./console core:archive -vvv and send the output then I can also have a quick look already in case it becomes clear it's something else.

@tsteur

INFO [2020-12-04 03:01:13] 12868 ---------------------------
INFO [2020-12-04 03:01:13] 12868 INIT
INFO [2020-12-04 03:01:13] 12868 Running Matomo 4.0.3 as Super User
INFO [2020-12-04 03:01:13] 12868 ---------------------------
INFO [2020-12-04 03:01:13] 12868 NOTES
INFO [2020-12-04 03:01:13] 12868 - Async process archiving supported, using CliMulti.
INFO [2020-12-04 03:01:13] 12868 - Reports for today will be processed at most every 600 seconds. You can change this value in Matomo UI > Settings > General Settings.
INFO [2020-12-04 03:01:13] 12868 - Archiving was last executed without error 1 min 12s ago
INFO [2020-12-04 03:01:13] 12868 ---------------------------
INFO [2020-12-04 03:01:13] 12868 START
INFO [2020-12-04 03:01:13] 12868 Starting Matomo reports archiving...
DEBUG [2020-12-04 03:01:13] 12868 Applying queued rearchiving...
INFO [2020-12-04 03:01:13] 12868 Start processing archives for site 1.
DEBUG [2020-12-04 03:01:13] 12868 Invalidations currently exist for idSite 1, skipping invalidating for now...
DEBUG [2020-12-04 03:01:13] 12868 Found invalidation for segment that does not have auto archiving enabled, skipping: 46
DEBUG [2020-12-04 03:01:13] 12868 Found invalidation for segment that does not have auto archiving enabled, skipping: 41
DEBUG [2020-12-04 03:01:13] 12868 Found invalidation for segment that does not have auto archiving enabled, skipping: 34
DEBUG [2020-12-04 03:01:13] 12868 Found invalidation for segment that does not have auto archiving enabled, skipping: 31
DEBUG [2020-12-04 03:01:13] 12868 Found invalidation for segment that does not have auto archiving enabled, skipping: 47
DEBUG [2020-12-04 03:01:13] 12868 Found invalidation for segment that does not have auto archiving enabled, skipping: 42
DEBUG [2020-12-04 03:01:13] 12868 Found invalidation for segment that does not have auto archiving enabled, skipping: 35
DEBUG [2020-12-04 03:01:13] 12868 Found invalidation for segment that does not have auto archiving enabled, skipping: 32
DEBUG [2020-12-04 03:01:13] 12868 Found invalidation for segment that does not have auto archiving enabled, skipping: 49
DEBUG [2020-12-04 03:01:13] 12868 Found invalidation for segment that does not have auto archiving enabled, skipping: 44
DEBUG [2020-12-04 03:01:13] 12868 Found invalidation for segment that does not have auto archiving enabled, skipping: 38
DEBUG [2020-12-04 03:01:13] 12868 Found invalidation for segment that does not have auto archiving enabled, skipping: 37
DEBUG [2020-12-04 03:01:13] 12868 Found invalidation for segment that does not have auto archiving enabled, skipping: 50
DEBUG [2020-12-04 03:01:13] 12868 Found invalidation for segment that does not have auto archiving enabled, skipping: 45
DEBUG [2020-12-04 03:01:13] 12868 Found invalidation for segment that does not have auto archiving enabled, skipping: 40
DEBUG [2020-12-04 03:01:13] 12868 Found invalidation for segment that does not have auto archiving enabled, skipping: 39
DEBUG [2020-12-04 03:01:13] 12868 No next invalidated archive.
INFO [2020-12-04 03:01:13] 12868 Finished archiving for site 1, 0 API requests, Time elapsed: 0.002s [1 / 1 done]
DEBUG [2020-12-04 03:01:13] 12868 No more sites left to archive, stopping.
INFO [2020-12-04 03:01:13] 12868 Done archiving!
INFO [2020-12-04 03:01:13] 12868 ---------------------------
INFO [2020-12-04 03:01:13] 12868 SUMMARY
INFO [2020-12-04 03:01:13] 12868 Processed 0 archives.
INFO [2020-12-04 03:01:13] 12868 Total API requests: 0
INFO [2020-12-04 03:01:13] 12868 done: 0 req, 120 ms, no error
INFO [2020-12-04 03:01:13] 12868 Time elapsed: 0.120s
INFO [2020-12-04 03:01:13] 12868 ---------------------------
INFO [2020-12-04 03:01:13] 12868 SCHEDULED TASKS
DEBUG [2020-12-04 03:01:13] 12868 28 scheduled tasks loaded
INFO [2020-12-04 03:01:13] 12868 Starting Scheduled tasks...
DEBUG [2020-12-04 03:01:13] 12868 Executing tasks with priority 0:
DEBUG [2020-12-04 03:01:13] 12868 Executing tasks with priority 1:
DEBUG [2020-12-04 03:01:13] 12868 Executing tasks with priority 2:
DEBUG [2020-12-04 03:01:13] 12868 Executing tasks with priority 3:
DEBUG [2020-12-04 03:01:13] 12868 Executing tasks with priority 4:
DEBUG [2020-12-04 03:01:13] 12868 Executing tasks with priority 5:
DEBUG [2020-12-04 03:01:13] 12868 Executing tasks with priority 6:
DEBUG [2020-12-04 03:01:13] 12868 Task Piwik\Plugins\CustomJsTracker\Tasks.updateTracker is scheduled to run again for 2020-12-04.
INFO [2020-12-04 03:01:13] 12868 Scheduler: executing task Piwik\Plugins\CustomJsTracker\Tasks.updateTracker...
INFO [2020-12-04 03:01:13] 12868 Scheduler: finished. Time elapsed: 0.001s
DEBUG [2020-12-04 03:01:13] 12868 Executing tasks with priority 7:
DEBUG [2020-12-04 03:01:13] 12868 Executing tasks with priority 8:
DEBUG [2020-12-04 03:01:13] 12868 Executing tasks with priority 9:
DEBUG [2020-12-04 03:01:13] 12868 Task Piwik\Plugins\PrivacyManager\Tasks.deleteLogData is scheduled to run again for 2020-12-04.
INFO [2020-12-04 03:01:13] 12868 Scheduler: executing task Piwik\Plugins\PrivacyManager\Tasks.deleteLogData...
INFO [2020-12-04 03:01:13] 12868 Scheduler: finished. Time elapsed: 0.002s
DEBUG [2020-12-04 03:01:13] 12868 Task Piwik\Plugins\PrivacyManager\Tasks.anonymizePastData is scheduled to run again for 2020-12-04.
INFO [2020-12-04 03:01:13] 12868 Scheduler: executing task Piwik\Plugins\PrivacyManager\Tasks.anonymizePastData...
INFO [2020-12-04 03:01:13] 12868 Scheduler: finished. Time elapsed: 0.001s
DEBUG [2020-12-04 03:01:13] 12868 Executing tasks with priority 10:
DEBUG [2020-12-04 03:01:13] 12868 Executing tasks with priority 11:
DEBUG [2020-12-04 03:01:13] 12868 Executing tasks with priority 12:
DEBUG [2020-12-04 03:01:13] 12868 Task Piwik\Plugins\QueuedTracking\Tasks.notifyQueueSize is scheduled to run again for 2020-12-04.
INFO [2020-12-04 03:01:13] 12868 Scheduler: executing task Piwik\Plugins\QueuedTracking\Tasks.notifyQueueSize...
INFO [2020-12-04 03:01:13] 12868 Scheduler: finished. Time elapsed: 0.001s
INFO [2020-12-04 03:01:13] 12868 done
INFO [2020-12-04 03:01:13] 12868 ---------------------------

Thanks!

Thanks for this. It looks like there are some "hanging" invalidations maybe. Any chance you could execute this SQL query

select * from archive_invalidations where `status` != 0

You might need to replace archive_invalidations eg with piwik_archive_invalidations or matomo_archive_invalidations depending on your DB prefix.

Could you paste the returned result of the query?

@tsteur Looking forward to it.

select * from archive_invalidations where status != 0

It is showing nothing.

This is the data in the table

Hi @valmedia it seems you maybe created a segment and there's a longer queue to be finished before other reports will be archived again. This will quite likely be fixed in 4.0.5 when we still continue to process other archives as well even when not all other ones are processed yet fyi @diosmosis

@tsteur

I notice the archive is being processed but the data is not being displayed on the dashboard. The latest report I can get is only yesterday. Could this be a timezone difference causing this? My server is saving data with GMT but my display setting is set as +8.

I have the same problem since yesterday and the fresh update to 4.04 doesn't bring any change, but triggering archiving by browser works.

This concerns only one site:

./console core:archive -vvv --force-idsites 13
INFO [2020-12-04 11:38:12] 10690 ---------------------------
INFO [2020-12-04 11:38:12] 10690 INIT
INFO [2020-12-04 11:38:12] 10690 Running Matomo 4.0.4 as Super User
INFO [2020-12-04 11:38:12] 10690 ---------------------------
INFO [2020-12-04 11:38:12] 10690 NOTES
INFO [2020-12-04 11:38:13] 10690 - Async process archiving supported, using CliMulti.
INFO [2020-12-04 11:38:13] 10690 - Reports for today will be processed at most every 500 seconds. You can change this value in Matomo UI > Settings > General Settings.
INFO [2020-12-04 11:38:13] 10690 - Archiving was last executed without error 1 min 43s ago
INFO [2020-12-04 11:38:13] 10690 - Will process 1 websites (--force-idsites)
INFO [2020-12-04 11:38:13] 10690 - Will process specified sites: 13
INFO [2020-12-04 11:38:13] 10690 ---------------------------
INFO [2020-12-04 11:38:13] 10690 START
INFO [2020-12-04 11:38:13] 10690 Starting Matomo reports archiving...
DEBUG [2020-12-04 11:38:13] 10690 Applying queued rearchiving...
INFO [2020-12-04 11:38:13] 10690 Start processing archives for site 13.
DEBUG [2020-12-04 11:38:13] 10690 Invalidations currently exist for idSite 13, skipping invalidating for now...
DEBUG [2020-12-04 11:38:13] 10690 Found invalidation for segment that does not have auto archiving enabled, skipping: 5156
DEBUG [2020-12-04 11:38:13] 10690 Found invalidation for segment that does not have auto archiving enabled, skipping: 5157
DEBUG [2020-12-04 11:38:13] 10690 Found invalidation for segment that does not have auto archiving enabled, skipping: 5159
DEBUG [2020-12-04 11:38:13] 10690 Found invalidation for segment that does not have auto archiving enabled, skipping: 5160
DEBUG [2020-12-04 11:38:13] 10690 No next invalidated archive.
INFO [2020-12-04 11:38:13] 10690 Finished archiving for site 13, 0 API requests, Time elapsed: 0.004s [1 / 1 done]
DEBUG [2020-12-04 11:38:13] 10690 No more sites left to archive, stopping.
INFO [2020-12-04 11:38:13] 10690 Done archiving!
INFO [2020-12-04 11:38:13] 10690 ---------------------------
INFO [2020-12-04 11:38:13] 10690 SUMMARY
INFO [2020-12-04 11:38:13] 10690 Processed 0 archives.
INFO [2020-12-04 11:38:13] 10690 Total API requests: 0
INFO [2020-12-04 11:38:13] 10690 done: 0 req, 461 ms, no error
INFO [2020-12-04 11:38:13] 10690 Time elapsed: 0.461s
INFO [2020-12-04 11:38:13] 10690 ---------------------------
INFO [2020-12-04 11:38:13] 10690 SCHEDULED TASKS
DEBUG [2020-12-04 11:38:13] 10690 29 scheduled tasks loaded
INFO [2020-12-04 11:38:13] 10690 Starting Scheduled tasks...
DEBUG [2020-12-04 11:38:13] 10690 Executing tasks with priority 0:
DEBUG [2020-12-04 11:38:13] 10690 Executing tasks with priority 1:
DEBUG [2020-12-04 11:38:13] 10690 Executing tasks with priority 2:
DEBUG [2020-12-04 11:38:13] 10690 Executing tasks with priority 3:
DEBUG [2020-12-04 11:38:13] 10690 Executing tasks with priority 4:
DEBUG [2020-12-04 11:38:13] 10690 Executing tasks with priority 5:
DEBUG [2020-12-04 11:38:13] 10690 Executing tasks with priority 6:
DEBUG [2020-12-04 11:38:13] 10690 Executing tasks with priority 7:
DEBUG [2020-12-04 11:38:13] 10690 Executing tasks with priority 8:
DEBUG [2020-12-04 11:38:13] 10690 Executing tasks with priority 9:
DEBUG [2020-12-04 11:38:13] 10690 Executing tasks with priority 10:
DEBUG [2020-12-04 11:38:13] 10690 Executing tasks with priority 11:
DEBUG [2020-12-04 11:38:13] 10690 Executing tasks with priority 12:
INFO [2020-12-04 11:38:13] 10690 done
INFO [2020-12-04 11:38:13] 10690 ---------------------------

And
select * from matomo_archive_invalidations where status != 0
shows nothing.

Same problem here with 4.0.4. It worked with 4.0.0 (or at least a beta version). Luckily triggering archiving by browser works for us too.

@wcz-txp @BigBerny for one of the segments that isn't being archived, could you post a screenshot of the segment editor for that segment? (Or select the row of the segment in the segment table and post the result?)

I'm not sure, what you mean.
This is a screenshot of matomo_archive_invalidations

And this is this segment 5156

It affects all segments here including "All visits"

@wcz-txp there is a table called segment which has information on each segment. I don't need this, though I think I see the problem in your case. I'll reply when I put a fix up.

@BigBerny So then nothing is being archived for you? I assumed you were having segment archiving trouble like other users. Can you post the output of running the command, ./console -vvv core:archive?

Will do. But as I said, it works when I trigger archiving with the browser. So I don't know if archiving itself is the problem.

I changed a segment from pre-processed to not-pro-processed a few days ago. Not sure if this is when it stopped working.

@BigBerny

I changed a segment from pre-processed to not-pro-processed a few days ago.

Yes, this is definitely the cause, also the cause of @wcz-txp's experience. This will be fixed by this change: #16895 which will be in the next release.

Problem solved after updating to 4.05. Thanks a lot!

Great to hear @wcz-txp cheers @diosmosis