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

Jump to bottom

Race condition when deleting site might result in "Failed to invalidate archived reports: An unexpected website was found in the request" #16204

Closed
jbrule opened this issue Jul 13, 2020 · 10 comments
Closed

Race condition when deleting site might result in "Failed to invalidate archived reports: An unexpected website was found in the request" #16204

jbrule opened this issue Jul 13, 2020 · 10 comments
Labels
Bug For errors / faults / flaws / inconsistencies etc.
Milestone
Backlog (Help wan...

Comments

@jbrule
Copy link

jbrule commented Jul 13, 2020

When archiving via cron we keep getting this message about website 115. It looks like it has been deleted and no longer exists in Matomo. Other various sites have been deleted but do not cause such an error. Any ideas?

INFO [2020-07-07 16:35:31] 47726  Archived website id = 3690, period = day, 0 segments, 133483 visits in last 52 days, 1979 visits today, Time elapsed: 5.569s
INFO [2020-07-07 16:35:31] 47726  - Will invalidate archived reports for 2020-03-10 for following websites ids: 115
INFO [2020-07-07 16:35:31] 47726  Failed to invalidate archived reports: An unexpected website was found in the request: website id was set to '115' .
INFO [2020-07-07 16:35:31] 47726  Will pre-process for website id = 3690, period = week, date = last2
INFO [2020-07-07 16:35:31] 47726  - pre-processing all visits
INFO [2020-07-07 16:35:32] 47726  Archived website id = 3690, period = week, 0 segments, 22694 visits in last 2 weeks, 5651 visits this week, Time elapsed: 1.659s
INFO [2020-07-07 16:35:33] 47726  - Will invalidate archived reports for 2020-03-10 for following websites ids: 115
INFO [2020-07-07 16:35:33] 47726  Failed to invalidate archived reports: An unexpected website was found in the request: website id was set to '115' .
INFO [2020-07-07 16:35:33] 47726  Will pre-process for website id = 3690, period = month, date = last2
INFO [2020-07-07 16:35:33] 47726  - pre-processing all visits
INFO [2020-07-07 16:35:35] 47726  Archived website id = 3690, period = month, 0 segments, 98786 visits in last 2 months, 15035 visits this month, Time elapsed: 2.462s
INFO [2020-07-07 16:35:35] 47726  - Will invalidate archived reports for 2020-03-10 for following websites ids: 115
INFO [2020-07-07 16:35:35] 47726  Failed to invalidate archived reports: An unexpected website was found in the request: website id was set to '115' .
INFO [2020-07-07 16:35:35] 47726  Will pre-process for website id = 3690, period = year, date = last2
INFO [2020-07-07 16:35:35] 47726  - pre-processing all visits
INFO [2020-07-07 16:35:37] 47726  Archived website id = 3690, period = year, 0 segments, 396869 visits in last 2 years, 396532 visits this year, Time elapsed: 2.620s
INFO [2020-07-07 16:35:38] 47726  - Will invalidate archived reports for 2020-03-10 for following websites ids: 115
INFO [2020-07-07 16:35:38] 47726  Failed to invalidate archived reports: An unexpected website was found in the request: website id was set to '115' .
INFO [2020-07-07 16:35:38] 47726  Will pre-process for website id = 3690, period = range, date = last6
INFO [2020-07-07 16:35:38] 47726  - pre-processing all visits
INFO [2020-07-07 16:35:39] 47726  Archived website id = 3690, period = range, 0 segments, 0 visits in last 30 ranges, 0 visits this range, Time elapsed: 1.606s
INFO [2020-07-07 16:35:39] 47726  - Will invalidate archived reports for 2020-03-10 for following websites ids: 115
INFO [2020-07-07 16:35:39] 47726  Failed to invalidate archived reports: An unexpected website was found in the request: website id was set to '115' .
INFO [2020-07-07 16:35:39] 47726  Will pre-process for website id = 3690, period = range, date = last7
INFO [2020-07-07 16:35:39] 47726  - pre-processing all visits
INFO [2020-07-07 16:35:40] 47726  Archived website id = 3690, period = range, 0 segments, 16966 visits in last 7 ranges, 16966 visits this range, Time elapsed: 0.980s
INFO [2020-07-07 16:35:40] 47726  Archived website id = 3690, 6 API requests, Time elapsed: 14.901s [1539/1546 done]
@jbrule jbrule changed the title Failed to invalidate archived reports for deleted site Failed to invalidate archived reports: An unexpected website was found in the request Jul 13, 2020
@tsteur
Copy link
Member

tsteur commented Jul 13, 2020

@jbrule can you double check you're not calling the archive using some force-idsites parameter like --force-idsites=115,...? Can you share any other parameter that is being used when running core:archive?

@jbrule
Copy link
Author

jbrule commented Jul 14, 2020

Nope nothing like that. This is my complete cron entry

0 */4 * * * 		cd /var/www/production/matomo && scl enable rh-php72 "./console core:archive --url=https://webanalytics.****.edu/matomo" >> /var/www/production/logs/archive.log 2>&1

@tsteur
Copy link
Member

tsteur commented Jul 14, 2020

If you have database access can you run a SQL query like this:

select * from matomo_option where option_name like '%SharedSiteIdsToArchive%'

and check if the mentioned idSite is set there and remove it? Also can you double check the site is really removed by executing the query below?

select * from matomo_site where idsite = 115

You might need to rename the table prefix from matomo_ to your table prefix.

@jbrule
Copy link
Author

jbrule commented Jul 14, 2020

select * from piwik_option where option_name like '%SharedSiteIdsToArchive%' No rows returned

select * from piwik_site where idsite = 115 No rows returned

@tsteur
Copy link
Member

tsteur commented Jul 14, 2020

Thanks @jbrule very appreciated. Starting to understand things better.

Can you also run this query and check if there's anything related to 115?

select * from matomo_option where option_name like '%report_to_invalidate_%'

@jbrule
Copy link
Author

jbrule commented Jul 16, 2020

select * from piwik_option where option_name like '%report_to_invalidate_%'

"option_name","option_value","autoload"
"report_to_invalidate_115_2020-03-10_46451",1,0

@tsteur
Copy link
Member

tsteur commented Jul 16, 2020

Could you delete this entry? that seems to be causing the issue. We'll need to check if these entries already get deleted when deleting a site.

tsteur added a commit that referenced this issue Jul 16, 2020
@tsteur
Delete remembered archived only for one specific site when a site is …
63628d1 
…deleted

Noticed this while looking at #16204

When deleting idSite 11, then it would do basically `delete from option where option_name like '%report_to_invalidate_11%`

But this would also delete entries like `111`, `112`, etc.
@tsteur tsteur mentioned this issue Jul 16, 2020
Merged
@tsteur
Copy link
Member

tsteur commented Jul 16, 2020 •
edited

I just checked we are already deleting this entry when a site is deleted. There must have been a race condition. I'll keep this issue open to eventually look if we can have some additional cleanup script or some other way to prevent this.

Anyone reading this:

The workaround is to run a query like this:

delete from `matomo_option` where option_name like '%report_to_invalidate_IDSITE_%'

Where you need to replace IDSITE with the number of the idSite that is causing issues and matomo_ may need to be replaced with the actual table prefix. For example piwik_option or just option.

@tsteur tsteur added the Bug For errors / faults / flaws / inconsistencies etc. label Jul 16, 2020
@tsteur tsteur changed the title Failed to invalidate archived reports: An unexpected website was found in the request Race condition when deleting site might result in "Failed to invalidate archived reports: An unexpected website was found in the request" Jul 16, 2020
@tsteur tsteur added this to the Backlog (Help wanted) milestone Jul 16, 2020
diosmosis pushed a commit that referenced this issue Jul 17, 2020
@tsteur
Delete remembered archived only for one specific site when a site is …
8b66403 
…deleted (#16216)

Noticed this while looking at #16204

When deleting idSite 11, then it would do basically `delete from option where option_name like '%report_to_invalidate_11%`

But this would also delete entries like `111`, `112`, etc.
@jbrule
Copy link
Author

jbrule commented Jul 17, 2020

Resolved: I removed the (previously mentioned) row from piwik_options and the warning is no longer present when archiving.

@mattab
Copy link
Member

mattab commented Dec 14, 2023

Thanks for contributing to this issue. As it has been a few months since the last activity and we believe this is likely not an issue anymore, we will now close this. If that's not the case, please do feel free to either reopen this issue or open a new one. We will gladly take a look again!

@mattab mattab closed this as not planned Won't fix, can't repro, duplicate, stale Dec 14, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
Bug For errors / faults / flaws / inconsistencies etc.
Projects
None yet
Milestone
Backlog (Help wanted)
Development

No branches or pull requests
3 participants
@tsteur @mattab @jbrule