Automattic / wp-calypso

The JavaScript and API powered WordPress.com
https://developer.wordpress.com
GNU General Public License v2.0
12.42k stars 1.99k forks source link

Editor: Permission Errors when trying to Update/Publish Post/Pages #45881

Closed KristinaKay closed 3 years ago

KristinaKay commented 4 years ago

We are receiving several reports of customers getting errors when trying to update or publish posts/page. Initial P2 #p2EDhh-19p-p2

HEs Warning P2: p7DVsv-9vm-p2

Systems P2: pMz3w-c2B-p2

Demographics: https://docs.google.com/spreadsheets/d/1dcsU96Q7ChdQGnest975BLG5HBXmysSPkQ6dEN0d-iU/edit?usp=sharing

Logging added here: D50847-code and D50934-code Logs: in kibana for feature : update_item_permissions_check_failure If a cookie is not set, it will not appear. If wp_api_sec is set and valid it will have the user id as value. If not valid it will have false as value. The rest cookies false values are a side effect only.

Screen Shot on 2020-11-09 at 16:06:11

Steps to reproduce

It's hard to say as all cases are different and not necessarily corrected in the same way. I am adding the comments from the original P2 here to have it all in one place.

https://wordpress.com/forums/topic/red-line-says-updating-failed-sorry-you-are-not-allowed-to-edit-this-post/

Action: since they’re having issues with “liking” posts, too, I’m wondering if it’s a login issue. I’m having them log out, clear cache, and log back in to see if that will help.

Otherwise, is this related to samesite browser cookie changes?

They also report this happening more widely with people they know:

This is not a solitary issue with just my blog. I run a group that attempts to post daily in November and the current problems makes it almost impossible to think about attempting this on the WordPress platform. A blogger in that group who is open to their blog being examined over this recurring error is behindthewillows.com.

@davemart-in @cathymcbride

blackjackkent commented 3 years ago

Oh, awesome, didn't realize someone had already gotten there ahead of me. :D Thanks. Will have a look.

adelineyaw commented 3 years ago

Another case #22576506-hc (Personal plan). I've asked them to clear their browser's cache and cookies.

blackjackkent commented 3 years ago

Looked up the logs from @cpapazoglou 's code using the blog ID from the case @adelineyaw just reported - definitely see that in this user's case, wp_api_sec did not appear to be set at all, not just invalid.

[{"_ga":false},{"G_ENABLED_IDPS":false},{"recognized_logins":false},{"wordpress_logged_in":false},{"wordpress_eli":false},{"_pin_unauth":false},{"_derived_epik":false},{"_wpndash":false},{"tk_qs":false},{"wpc_wpc":false},{"dcmsid":false},{"tk_tc":false}]
ccwalburn commented 3 years ago

I have another report here: 25400913-hc They are on the Premium plan.

davemart-in commented 3 years ago

@griffbrad is this an issue that the Calypso team might be able to lend a hand with? Reports continue to stream in. Each of the teams within the Manage Group have taken a pass at this and at this point it feels like we might be going in circles.

Heads up: @creativecoder, @kwight, @obenland

griffbrad commented 3 years ago

@Automattic/team-calypso can take a look, sure. Happy to help!

tyxla commented 3 years ago

Has anyone been able to reproduce the issue consistently on any site? We'd like to dig further, but we're having trouble reproducing it in the first place.

cpapazoglou commented 3 years ago

Has anyone been able to reproduce the issue consistently on any site? We'd like to dig further, but we're having trouble reproducing it in the first place.

Not really, that is the biggest problem of this issue. We are blindfolded!

jsnajdr commented 3 years ago

The cookie is only valid for 2 days, but it gets extended with every request to the API. Maybe there are some users who keep the editor opened for more than 2 days but without any interaction at all, so there are no API request extending the cookie expiration?

@mmtr The wp_api cookies are set when the REST proxy iframe is loaded, and are renewed whenever that iframe is reloaded. Issuing API requests doesn't reset the expiration timer. It's possible that the wp_api_sec cookie expires when the browser tab is open and active for 2 days.

And I confirmed that deleting the wp_api_sec cookie indeed leads to post save failing with that "Sorry you are not allowed" error.

I think it's almost certain that the bug is caused by the wp_api_sec cookie getting lost somehow. The expiration after 2 days is not likely though: I expect that it's removed by one of the many security mechanisms that filter cookies: SameSite, storage partitioning, some tracking prevention...

Yes, this is the case, but the thing I can't understand is why? How has someone got a valid auth cookie for wp-admin (and so can load the editor) but not for the API?

@pablinos There are multiple auth cookies for different parts of WordPress.com. For loading stuff from *.wordpress.com/wp-admin/*, the cookie is wordpress_sec, while public-api.wordpress.com request require wp_api_sec. While loading public-api.wordpress.com/wp-admin/rest-proxy, the first one is traded for the second one -- note how the proxy URL is in the intersection of both cookie's domains -- that's not an accident 🙂

So, it's possible to successfully load authenticated Gutenberg from a wp-admin URL and still fail at issuing REST requests.

Also, the wp-admin response includes some preloaded data from REST endpoints that the editor would be going to call anyway. That includes the post to be edited. So, the editor can load almost completely without touching a REST endpoint. Trying to save a change can plausibly be the first REST request that visibly fails.

It's interesting that this preloading seems to be broken when iframing Simple sites. When loading the editor in a Gutenframe, I get preload data only for the / REST path. The others are missing. That looks like a bug that should be fixed.

Another strange behavior I was while testing was when opening the editor on an Atomic site. Sometimes, from /posts pages, the edit links lead to Gutenframe (wordpress.com/post/...), sometimes they lead to wp-admin (atomic-example.blog/wp-admin/...). I've got both, rather randomly.

I've also seen a case where the Atomic site editor was initially iframed, then, because the inner frame didn't have auth cookies for atomic-example.blog, redirected to atomic-example.blog/wp-login, that page was refused by the browser because it had X-Frame-Options: DENY header, and few seconds later I was redirected from Calypso to wp-admin.

Is that wait-and-redirect flow intentional? I vaguely remember that @glendaviesnz worked on something similar maybe a year ago, related to Safari ITP.

I'm mentioning all this because bugs related to Gutenframe seem a bit too easy to find. Not a good sign when dealing with an intermittent issue like this one.

cpapazoglou commented 3 years ago

@jsnajdr let me mention, that all logs miss both wordpress_sec and wp_api_sec. Since a missing wordpress_sec leads to clearing the wp_api_sec (270ef-pb), I suppose that we need to find why wordpress_sec is missing in the first place.

blackjackkent commented 3 years ago

For the record, I just tried to edit the post I left open in the editor since Monday morning and did get an error, but not the same one reported in the issue - instead of "Sorry, you are not allowed to edit this post," I got "Updating failed. User cannot access this private blog."

(This was also reported in some of the subsequent reports above, i believe, so we may be onto something for a separate issue here as well. But I don't think it's the cause of the errors from the original report.)

jsnajdr commented 3 years ago

@blackjackkent For our purposes, I think we can treat both errors as one. If the wp_api_sec auth cookie is missing, then for private sites, the "cannot access this private blog" check is done first and therefore fails first. The "allowed to edit this post" check is done only after the first one passes. It's also more specific -- checks permissions for a specific post rather than the entire blog.

kwight commented 3 years ago

Another strange behavior I was while testing was when opening the editor on an Atomic site. Sometimes, from /posts pages, the edit links lead to Gutenframe (wordpress.com/post/...), sometimes they lead to wp-admin (atomic-example.blog/wp-admin/...). I've got both, rather randomly.

Not being compatible for Gutenframe can be for a number of reasons, yes:

noahtallen commented 3 years ago

Is that wait-and-redirect flow intentional

Yeah, plus one to what Kirk said, this is intentional. We also redirect to wp-admin if the iframe did not load successfully in 5 seconds:

https://github.com/Automattic/wp-calypso/blob/087dd974f0a0d610a282b985bd1bd7b06de27fb0/client/gutenberg/editor/calypsoify-iframe.tsx#L658-L685

We added that when troubleshooting issues with loading the iframe in ie11.

jsnajdr commented 3 years ago

let me mention, that all logs miss both wordpress_sec and wp_api_sec. Since a missing wordpress_sec leads to clearing the wp_api_sec, I suppose that we need to find why wordpress_sec is missing in the first place.

For a REST request to public-api.wordpress.com, it's expected that the wordpress_sec cookie is not sent. That cookie is scoped to *.wordpress.com/wp-admin. Only requests to /wp-admin, e.g., /wp-admin/post.php or /wp-admin/rest-proxy, are authenticated with that cookie.

REST requests need to have the wp_api_sec cookie and the Authorization: X-WPCOOKIE header.

The user was able to load the editor in frame, including the post content, and REST requests started failing only a while later. That means that the /wp-admin/post.php request was properly authenticated with wordpress_sec, and that the page managed to get the post content from REST, authenticated with wp_api_sec (the server preload doesn't work, so the post content must have been fetched with REST).

How could wp_api_sec suddenly disappear? There's one way: if we load another instance of the /wp-admin/rest-proxy iframe at some point, and that request is not properly authenticated with wordpress_sec, the request will reset the wp_api_sec cookie. That change applies to all other instances of the iframe, too. Calypso with Gutenframe loads at least three proxy iframes, and I see two of them in the iframed Gutenberg document:

Screenshot 2020-11-06 at 14 09 59

One of them is coming from the code that intercepts apiFetch requests, rewrites their paths and sends them to the proxy. I don't know who loads the other one.

How could a proxy iframe be loaded without wordpress_sec auth? The browser can reject to send the cookie because of SameSite restrictions.

First, SameSite=None is added by the server only if the User-Agent header matches certain browsers and version ranges. If the server thinks the User-Agent is not eligible, SameSite=None won't be set.

Second, with Gutenframe, we are dealing with several nested iframes that make requests:

- wordpress.com (Calypso in my browser)
  - jsnajdr-test-blog.wordpress.com/wp-admin/post.php (Gutenberg in iframe)
    - public-api.wordpress.com/wp-admin/rest-proxy (REST proxy inside Gutenberg)
      - public-api.wordpress.com/wp/v2/sites/... (REST requests issued by the proxy)

We need that the wordpress_sec cookie is sent with the /wp-admin/rest-proxy request, and that the wp_api_sec cookie is sent with the /wp/v2/sites REST request.

That happens only if either:

But imagine that the server finds the User-Agent ineligible and doesn't set SameSite=None.

And that one of the iframes in the chain is outside *.wordpress.com. That frequently happens for widgets loaded from widgets.wp.com, or maybe also static.wp.com. If we load such a widget into iframe and it loads the REST proxy iframe, the wordpress_sec cookie (without SameSite=None) won't be send because the samesite conditions are not satisfied. The server will send a wp_api_sec reset in response, resetting the cookie even for eligible frames.

Or we can load iframed Gutenberg not from the compatible jsnajdr-test-blog.wordpress.com domain, but from a custom domain like jsnajdr-test-blog.blog. That can happen for Atomic sites that don't have the *.wordpress.com unmapped address.

More logging: @cpapazoglou There are two useful bits of information we could add to the update_item_permissions_check_failure:

That could give us further insight whether the theory I'm laying out in this comment is true. I.e., that SameSite=None is sometimes not set and that the REST frame loaded from non-wordpress.com origin can reset the wp_api_sec cookie for everyone else.

blackjackkent commented 3 years ago

@jsnajdr I've opened a diff at D52402-code to add the features you requested to the log. Please have a look at it when you can! (@cpapazoglou , I followed the same testing instructions that you provided in D50847-code but was not actually seeing my logs show up even though I could see my local logging executing the code; not sure if something's wrong there or not, but if you could verify as well I would appreciate it.)

I'm out Monday but will follow up Tuesday on this unless someone else has commandeered it by then.

eduardozulian commented 3 years ago

For the record, another case in 3435042-zen

formosattic commented 3 years ago

+1 3464186-zen

dolgelukkig commented 3 years ago

Another case in #186218-hc Simple site, Premium plan

adelineyaw commented 3 years ago

8000252-hc (Personal plan)

User was seeing "can't create posts as this user" in Chrome but then when they switched to Safari, they didn't have any issues.

kylemcph commented 3 years ago

14108444-hc (Personal plan)

Operating system: OS X 10.15.7 Browser: Chrome 86

kylemcph commented 3 years ago

25547391-hc (Personal plan)

poojashetty18 commented 3 years ago

Another case #23833186-hc. Followed up here: #3483929-zd

They're on a Personal plan, browser is chrome, issue happens in Calypso and in wp-admin.

as-esu commented 3 years ago

3476919-zen another case. Safari browser ( Personal plan ). "Sorry, you are not allowed to edit this post".

blackjackkent commented 3 years ago

D52402-code has been deployed adding new logging info as described by @jsnajdr - hopefully some extra context can be gleaned from that.

jsnajdr commented 3 years ago

Thanks @blackjackkent for adding the logging. I haven't found anything groundbreaking there yet. Just a few observations:

When I tried to simulate the "update post" error by deleting the wp_api_sec cookie and getting my action logged in Logstash, I didn't succeed. I got the expected error in the UI and in the REST response:

Screenshot 2020-11-19 at 13 56 25

But there is nothing with my blog_id in Kibana. Can anyone reproduce that? This looks almost like there is another place in the codebase that can throw the same error, but with no logging code attached. I was not sandboxed, simply accessing the production servers through proxy.

The browsers from the parsed User-Agent header look fine: it's almost always Chrome 86.

Unrelated: in some of the failed requests, the origin is "https:\/\/wordpress.com\/?trashed=1&ids=9" which is weird. That's not a valid origin and the request fails because of that. The log record reports a valid wp_api_sec.

If we don't find anything, I think the next step is to add some logging to the rest-proxy/index.php script that sets the wp_api_* cookies and log whether it successfully authenticated the iframe or not.

cpapazoglou commented 3 years ago

When I tried to simulate the "update post" error by deleting the wp_api_sec cookie and getting my action logged in Logstash, I didn't succeed. I got the expected error in the UI and in the REST response:

@jsnajdr I am afraid that

User cannot access this private blog.

is an other error (maybe related)! Is your blog private? Could you try from a public one?

jsnajdr commented 3 years ago

@cpapazoglou Of course, it's a different error 🤦 It's related -- and I set my testing blog to private when researching the comment in https://github.com/Automattic/wp-calypso/issues/45881#issuecomment-722608678

I see my error in Logstash now when the blog is back to public.

AtrumGeost commented 3 years ago

Got another report here:

3505717-zd-woothemes

gwensmithx commented 3 years ago

Another reported here: #3503389-zd and customer would like to know once this is solved. I'll mark this for my own followup though I have a large list of GH followups so I'm giving the customer the ticket number to reference as well for an update.

adelineyaw commented 3 years ago

18401728-hc - User refuses to clear their browser's cache or cookies and they're not willing to switch browsers in the interim.

carinapilar commented 3 years ago

Got another one on #21999946-hc - Worked on incognito on Chrome, suggested clearing the cache.

sophiegyo commented 3 years ago

Got another one on #21999946-hc - Worked on incognito on Chrome, suggested clearing the cache.

I ended up with #21999946-hc

Browser: Google chrome Version 85.0.4183.83 (Official Build) (64-bit) OS: Catalina 10.15.6

Is it me or does this regularly happen specifically with Chrome, but not other browsers?

metabreakr commented 3 years ago

6245514-hc

mpmedialab commented 3 years ago

another case here 3513706-zen

KristinaKay commented 3 years ago

Got another one on #21999946-hc - Worked on incognito on Chrome, suggested clearing the cache.

I ended up with #21999946-hc

Browser: Google chrome Version 85.0.4183.83 (Official Build) (64-bit) OS: Catalina 10.15.6

Is it me or does this regularly happen specifically with Chrome, but not other browsers?

It does look like this is very much an issue with Chrome.

KristinaKay commented 3 years ago

Another report: #3517971-zen

Using Chrome on Windows

ktyfuller604 commented 3 years ago

Another report: #26170919-hc

Chrome Version 87.0.4280.88 on Windows

First reported: November 13, 2020

JoshuaGoode commented 3 years ago

Reported on 9729068-hc

Chrome 87.0 on Windows 10.0.0

gwensmithx commented 3 years ago

Another report #24684882-hc

Chrome Version 87.0.4280.88 (Official Build) (64-bit)

marianearchimbaud commented 3 years ago

Reported here too: 3554486-zd Using Chrome on a mac

The user also mentioned that while visiting its page, they clicked on the 3 dots of the WordPress.com action bar, clicked on log in, but they seemed to be kicked off, and never able to log in

sophiegyo commented 3 years ago

Possible case in 26259705-hc - different error message but likely same related cookie problem.

This is the error they got: "you are not allowed to post with the provided terms?" I could find absolutely nothing in MGS but it sounds related. The site was previouly AT, now Simple.

They were using Chrome on a Mac too; Chrome 87.0 on Mac OS X 10.12.6 according to HC but I didn't get any further detail than that.

cathymcbride commented 3 years ago

@sophiegyo I'm not sure that is the same issue? See: https://core.trac.wordpress.org/ticket/46297

rinazrina commented 3 years ago

Another report: #3576635-zen

metabreakr commented 3 years ago

26621899-hc

Chrome 87.0 on Windows 10.0.0

clickysteve commented 3 years ago

I just received an error similar to what @sophiegyo reported above:

"Publishing failed. Sorry, you are not allowed to assign the provided terms."

The post published, irrespective of the error. I am on Mac on 10.15.5 OSX and Chrome. Only 'weird' thing I did in the post was include a More block.

Screenshot 2021-01-04 at 10 33 13
clickysteve commented 3 years ago

I just received an error similar to what @sophiegyo reported above:

"Publishing failed. Sorry, you are not allowed to assign the provided terms."

The post published, irrespective of the error. I am on Mac on 10.15.5 OSX and Chrome. Only 'weird' thing I did in the post was include a More block.

Just noting that it appears the Categories and Tags selection was not saved on publication. I had to go in and update this again, which now seems to have stuck.

liviopv commented 3 years ago

Another: 482162-hc

marianearchimbaud commented 3 years ago

26686978-hc another case here. Suggested them to clear the browser's cache, or use another browser

metabreakr commented 3 years ago

18693933-hc

Simple site. Safari 14.0 on Mac OS X 10.15.6. Suggested they clear cache/switch browsers.