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

Concurrently running archivers can trigger scheduled tasks multiple times #19287

Closed
Starker3 opened this issue May 30, 2022 · 3 comments
Closed
Labels
duplicate For issues that already existed in our issue tracker and were reported previously.

Comments

@Starker3
Copy link
Contributor

When users have a high number of sites or a lot of data, it can be expected to have two (Or more) concurrently running core:archive tasks that could take several hours to all complete.

In the case where a user has a high number of sites where each site is relatively low volume or a high number of sites where each site takes roughly the same amount of time to complete we can run into a situation where two concurrently running archivers finish at exactly the same time.

For example in this case where a user had two concurrently running core:archive tasks, one started an hour after the other. We can see here that they both finished at roughly the same time:

INFO [2022-05-15 00:29:43] 3017001  Done archiving!
INFO [2022-05-15 00:29:43] 3017001  ---------------------------
INFO [2022-05-15 00:29:43] 3017001  SUMMARY
INFO [2022-05-15 00:29:43] 3017001  Processed 2049 archives.
INFO [2022-05-15 00:29:43] 3017001  Total API requests: 2049
INFO [2022-05-15 00:29:43] 3017001  done: 2049 req, 3101515 ms, no error
INFO [2022-05-15 00:29:43] 3017001  Time elapsed: 3101.515s
INFO [2022-05-15 00:29:43] 3017001  ---------------------------
INFO [2022-05-15 00:29:43] 3017001  SCHEDULED TASKS
INFO [2022-05-15 00:29:43] 3017001  Starting Scheduled tasks... 

INFO [2022-05-15 00:29:46] 2897212  Done archiving!
INFO [2022-05-15 00:29:46] 2897212  ---------------------------
INFO [2022-05-15 00:29:46] 2897212  SUMMARY
INFO [2022-05-15 00:29:46] 2897212  Processed 4258 archives.
INFO [2022-05-15 00:29:46] 2897212  Total API requests: 4258
INFO [2022-05-15 00:29:46] 2897212  done: 4258 req, 6704938 ms, no error
INFO [2022-05-15 00:29:46] 2897212  Time elapsed: 6704.938s
INFO [2022-05-15 00:29:46] 2897212  ---------------------------
INFO [2022-05-15 00:29:46] 2897212  SCHEDULED TASKS

We can then end up with a situation where they execute the exact same scheduled tasks at the same exact time causing things such as duplicate email reports to be sent:

INFO [2022-05-15 00:33:32] 2897212  Scheduler: finished. Time elapsed: 225.650s
INFO [2022-05-15 00:33:32] 3017001  Scheduler: finished. Time elapsed: 228.735s
INFO [2022-05-15 00:33:32] 3017001  Scheduler: executing task Piwik\Plugins\Login\Tasks.cleanupBruteForceLogs...
INFO [2022-05-15 00:33:32] 2897212  Scheduler: executing task Piwik\Plugins\Login\Tasks.cleanupBruteForceLogs...
INFO [2022-05-15 00:33:32] 2897212  Scheduler: finished. Time elapsed: 0.004s
INFO [2022-05-15 00:33:32] 3017001  Scheduler: finished. Time elapsed: 0.004s
INFO [2022-05-15 00:33:32] 2897212  Scheduler: executing task Piwik\Plugins\TwoFactorAuth\Tasks.cleanupTwoFaCodesUsedRecently...
INFO [2022-05-15 00:33:32] 3017001  Scheduler: executing task Piwik\Plugins\TwoFactorAuth\Tasks.cleanupTwoFaCodesUsedRecently...
INFO [2022-05-15 00:33:32] 2897212  Scheduler: finished. Time elapsed: 0.001s
INFO [2022-05-15 00:33:32] 3017001  Scheduler: finished. Time elapsed: 0.001s
INFO [2022-05-15 00:33:32] 2897212  Scheduler: executing task Piwik\Plugins\UsersManager\Tasks.cleanupExpiredTokens...
INFO [2022-05-15 00:33:32] 3017001  Scheduler: executing task Piwik\Plugins\UsersManager\Tasks.cleanupExpiredTokens...
INFO [2022-05-15 00:33:32] 2897212  Scheduler: finished. Time elapsed: 0.022s
INFO [2022-05-15 00:33:32] 3017001  Scheduler: finished. Time elapsed: 0.024s
INFO [2022-05-15 00:33:32] 2897212  Scheduler: executing task Piwik\Plugins\UsersManager\Tasks.setUserDefaultReportPreference...
INFO [2022-05-15 00:33:32] 3017001  Scheduler: executing task Piwik\Plugins\UsersManager\Tasks.setUserDefaultReportPreference...
INFO [2022-05-15 00:33:32] 3017001  Scheduler: finished. Time elapsed: 0.135s
INFO [2022-05-15 00:33:32] 3017001  Scheduler: executing task Piwik\Plugins\ScheduledReports\API.sendReport_3...
INFO [2022-05-15 00:33:33] 2897212  Scheduler: finished. Time elapsed: 0.149s
INFO [2022-05-15 00:33:33] 2897212  Scheduler: executing task Piwik\Plugins\ScheduledReports\API.sendReport_3...
@Starker3 Starker3 added the Potential Bug Something that might be a bug, but needs validation and confirmation it can be reproduced. label May 30, 2022
@tsteur
Copy link
Member

tsteur commented Nov 30, 2023

We've had a similar issue where we received the same alert email 8! times.
refs matomo-org/plugin-CustomAlerts#155

@tsteur
Copy link
Member

tsteur commented Nov 30, 2023

Maybe this one is a duplicate of #17868

@Stan-vw
Copy link
Contributor

Stan-vw commented Dec 7, 2023

Closing, as it's a duplicate of #17868

@sgiehl sgiehl added duplicate For issues that already existed in our issue tracker and were reported previously. and removed Potential Bug Something that might be a bug, but needs validation and confirmation it can be reproduced. labels Jan 5, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
duplicate For issues that already existed in our issue tracker and were reported previously.
Projects
None yet
Development

No branches or pull requests

5 participants