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

Add logging and an admin notice for Legacy REST API usages #41804

Merged
merged 11 commits into from Dec 20, 2023

Conversation

Konamiman
Copy link
Contributor

@Konamiman Konamiman commented Nov 30, 2023

Changes proposed in this Pull Request:

In order to help users determine how the Legacy REST API is used on its site in the context of its removal in WooCommerce 9.0, this pull request adds a helper tool that introduces two mechanisms:

  1. Logging (in log files with a dedicated name) usages of the Legacy REST API, including API version, request route, user agent (when available) and date.
  2. Displaying an admin notice with summary information about the requests received.

image

Internally, a transient named wc_legacy_rest_api_usages (with a lifetime of two weeks) is kept with the date of the first access, the total accesses count, and the different user agents registered.

The notice will not show, and logging won't happen, if any of these is true:

  • The separate Legacy REST API extension is installed and active.
  • The Legacy REST API is disabled.
  • The transient with usages data is not available.

Additionally, it's possible to deactivate the writing of the log entry by having the woocommerce_log_legacy_rest_api_usages filter return false.

How to test the changes in this Pull Request:

To test the changes in this pull request you need to perform requests to at least one endpoint of the Legacy REST API using Postman, curl or your favorite HTTP request tool. For example: http://localhost/wc-api/v3/orders.

  1. Install the Legacy REST API plugin but don't activate it. If you have it already installed and active, deactivate it.

  2. Enable the Legacy REST API (in WooCommerce - Settings - Advanced - Legacy API) if it's not active.

  3. Perform two Legacy REST API requests specifying different user agents, and then one more without user agent header.

  4. Go to the logs page, verify that the notice has appeared and displays correct information (it should say that it has recognized threee accesses from two different known user agents) and that the log file has been created with the appropriate entries (the log file name starts with legacy_rest_api_usages).

  5. Check the transient file contents with wp transient get 'wc_legacy_rest_api_usages', then delete it with wp transient delete wc_legacy_rest_api_usages to simulate the transient expiration.

  6. Reload any admin page. See how the notice has disappeared.

  7. Perform yet another Legacy REST API request and reload any admin page, see how the notice is there again but its data has been reset (first date is current date and access count is 1).

  8. Verify that disabling the Legacy REST API in settings makes the notice disappear, and enabling it again makes the notice appear again.

  9. Activate the Legacy REST API plugin and reload the admin page, the notice has now disappeared. Verify also that Legacy REST API usages are no longer logged.

  10. Deactivate the Legacy REST API plugin and reload the admin page, the notice will appear again and logging of new Legacy REST API usages will resume.

  11. Dismiss the notice by clicking its "dismiss" link, it will no longer appear regardless of new Legacy REST API usages or extension activation or deactivation. If you want to undo the dismissal run this: wp user meta delete <your user id> "dismissed_legacy_api_usages_detected_notice"

  12. Verify that Legacy REST API usages stop being logged (even without the extension active) when you add the following code: add_filter('woocommerce_log_legacy_rest_api_usages', '__return_false');

Changelog entry

  • Automatically create a changelog entry from the details below.

Significance

  • Patch
  • Minor
  • Major

Type

  • Fix - Fixes an existing bug
  • Add - Adds functionality
  • Update - Update existing functionality
  • Dev - Development related task
  • Tweak - A minor adjustment to the codebase
  • Performance - Address performance issues
  • Enhancement - Improvement to existing functionality

Message

Comment

@github-actions github-actions bot added the plugin: woocommerce Issues related to the WooCommerce Core plugin. label Nov 30, 2023
Copy link
Contributor

github-actions bot commented Nov 30, 2023

Test Results Summary

Commit SHA: 4defc2e

Test 🧪Passed ✅Failed 🚨Broken 🚧Skipped ⏭️Unknown ❔Total 📊Duration ⏱️
API Tests25900202610m 37s
E2E Tests258003026114m 17s

To view the full API test report, click here.
To view the full E2E test report, click here.
To view all test reports, visit the WooCommerce Test Reports Dashboard.

@Konamiman Konamiman requested review from a team and jorgeatorres and removed request for a team November 30, 2023 11:30
Copy link
Contributor

Hi @jorgeatorres,

Apart from reviewing the code changes, please make sure to review the testing instructions as well.

You can follow this guide to find out what good testing instructions should look like:
https://github.com/woocommerce/woocommerce/wiki/Writing-high-quality-testing-instructions

Copy link
Member

@jorgeatorres jorgeatorres left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hi @Konamiman!

Thanks for submitting this one! 💯. There are some formatting issues that need to be addressed, but on an initial look, things seem to be working as expected.

I do have some thoughts/questions/ideas on the many steps to enable some monitoring that this adds:

  • I think ideally we would have some monitoring on by default so we start capturing things as soon as possible without having to enable anything. Even if we now have the ability to point users to these new settings, we've already lost an opportunity to detect some usage after WC has been updated.
  • Even if people enable logging, there's still no way to quickly confirm that the legacy REST API is being used, so I think we definitely need to surface that on this settings screen but ideally also in the SSR.
  • Writing to the log file might be considered "heavy" in the context of a REST API request so I understand why we would want to make it a setting, but IMHO there's something we could do regardless of logging: we could use a transient or option to at least be able to quickly tell users whether the legacy REST API is even being used (and least up to that point) and ask them to enable logging/monitoring if they want more details.
  • I get that we don't want to clutter log files, but maybe that's not a bad thing as that reflects the real usage on the site. We're also not enabling this by default, so it's something merchants can disable if cluttering becomes a problem. If I enable logging of something and only see a "random" selection of what I expected to see, that's weird too.

I'm not a usability expert but I think the ideal situation would be something like this:

  • We record # of uses of the legacy REST API and maybe relevant dates (first/last use) without necessarily storing more info. This is enabled by default and not controlled by any setting.
  • With the above we at least detect usage and are able to provide useful info as soon as we have it. For example, on the settings screen we could use this to display how many times the legacy REST API has been used since X day and also include this info in the SSR.
  • I'd advocate for logging-on-by-default (maybe controlled by a filter instead of a setting) but this proves too problematic, I'd still think consolidating both settings into just one: "Monitor usage of legacy REST API endpoints" would be clearer and tidier.
  • I'm not sure if the admin notice should appear everywhere (though we could make it dismissible) but in any case, I don't think it should be optional.

What are your thoughts on the above? These are clearly not technical issues with your code, but more usability-related. If you prefer we bring this to the team and brainstorm together, let me know.

@Konamiman
Copy link
Contributor Author

Konamiman commented Dec 1, 2023

@jorgeatorres This pull request is basically created in response to the "I have the legacy REST API enabled and I don't know why" comments in the API removal announcement post, so the idea was to announce the availability of the logging mechanism as a comment in that post (and possibly in an additional dedicated post too). That's why it's disabled by default: the idea is that whoever needs it will enable it, and everyone else won't be "disturbed" (otherwise I bet there would be complaints in the opposite direction: "Yes I know my legacy REST API is in use, why am I being nagged about it?")

I'd still think consolidating both settings into just one: "Monitor usage of legacy REST API endpoints" would be clearer and tidier

I made two settings because I considered that there will be people who wants to be able to check logs, but don't want an admin notice to be always visible in the admin area. Or the other way around: they want to see a notice just to check if the API is being used at all, bu they aren't interested in logs.

we could use a transient or option to at least be able to quickly tell users whether the legacy REST API is even being used

That option already exists. What we could do is add a "enable logging if you want more details" link in the notice, provided that logging isn't already enabled.

I get that we don't want to clutter log files, but maybe that's not a bad thing as that reflects the real usage on the site

We are already storing the total usage count for each combination of user agent and route, maybe it's just a matter of making this more visible somehow?

f you prefer we bring this to the team and brainstorm together, let me know.

That's a good idea indeed.

@barryhughes
Copy link
Member

I tend to agree with the direction of @jorgeatorres's thoughts.

The amount of feedback we received over here took me by surprise, but I'm glad people took the time to share their concerns because now we know lots of less-technical (or simply busy) users need additional support as we press ahead with the Legacy REST API removal.

So the idea was to announce the availability of the logging mechanism as a comment in that post (and possibly in an additional dedicated post too).

Definitely—we should continue to communicate loudly. Even so, the reality is not everyone reads the developer blog (which is part of the reason I was surprised at the volume of feedback we received, largely from non-developers).

Yes I know my legacy REST API is in use, why am I being nagged about it?

We certainly could receive this sort of feedback ... but so long as there is a means of dismissing the notice, I think that's fine.

For those who don't read the developer blog and don't have a reason to visit WooCommerce ▸ Settings ▸ Advanced ▸ Legacy API, though, the risk is they will be caught unawares. All that to say, I strongly feel the notice should be enabled by default.

@jorgeatorres
Copy link
Member

jorgeatorres commented Dec 8, 2023

Based on the discussion so far, and thinking we want to provide data as soon as possible so that customers can take action, I'd like to propose we take a slightly different approach (which we can obviously refine/adjust):

  • No new settings are added.
  • We start detecting and logging requests to the legacy REST API as soon as possible. I don't think it's worth trying to "reduce" the number requests in the logs, not only because it gives a false idea of usage but also because it means we have to keep track of things in a (possibly huge) option which doesn't look very scalable either.
  • The transient/option doesn't need to contain information about all different requests. I propose we only store the following info: date of first request we've detected, the total number of requests and the date or details of the last one.
  • On the settings screen we use the info above to display something like "N requests were detected since X. Last one was on Z. Check logs (link) for details."
  • The admin notice is not controlled by a setting and is on by default. As soon as we detect legacy requests, we display the admin notice, which should include links to the docs, logs and details about the total number of requests and date of the last one.
    • Maybe we define some threshold here. For example, if no legacy request has been made in X days, we no longer display the admin notice, but info is still available on the settings screen.
    • We make the notice (partially) dismissible so that admins can hide it. We could provide buttons like "Ignore for/remind me in X days" or even one to fully disable logging and dismiss.
  • If the legacy plugin is installed, no logging takes place and no admin notice is displayed.

@Konamiman @barryhughes: what do you think of this possible implementation?

@Konamiman
Copy link
Contributor Author

I don't think it's worth trying to "reduce" the number requests in the logs

We need some kind of rate limiting, or the logs can easily get flooded.

The transient/option doesn't need to contain information about all different requests. I propose we only store the following info: date of first request we've detected, the total number of requests and the date or details of the last one.

If we don't store information about the endpoints hit, at least we should keep a list of user agents to help with the "why do I have the legacy API active" cases.

The admin notice is not controlled by a setting and is on by default.

I guarantee you that part of the Woo users will complain about the "noise" and will request the notice to be removed. I'd leave the setting in place, but agreed, it can be on by default.

Also I still see value in having separate settings for the logging and the notice. Once the admin is aware that the legacy API is in use, they can disable the notice, but still keep the logging on to collect user agents information over time.

@jorgeatorres
Copy link
Member

jorgeatorres commented Dec 11, 2023

We need some kind of rate limiting, or the logs can easily get flooded.

I think you might be right and I'm just underestimating the number of requests that might hit those deprecated endpoints.

How about we make this a 2-week transient instead? We can define the time interval, but that's an example.
That way we can still rate limit logging, detect usage (to be displayed on the settings screen or to trigger the notice), but at least if nothing has happened in a given period (say because the merchant updated or disabled those integrations) the transient will fade away from the site, as opposed to a normal option.

Also, not sure why need to store "the last" request. Couldn't we just use the other transient? I don't think the notice needs to be particularly about the last usage. As long as we have the other transient we know there's been some usage in X days and we can display a notice (even if a bit more generic). The details can be found in the logs.

I guarantee you that part of the Woo users will complain about the "noise" and will request the notice to be removed. I'd leave the setting in place, but agreed, it can be on by default.

I agree, that's why I proposed we make it dismissible. As in, it contains a button like "Dismiss" or "Ignore for X days". It achieves the same thing, but we don't have to add yet another setting just for that.

Also I still see value in having separate settings for the logging and the notice. Once the admin is aware that the legacy API is in use, they can disable the notice, but still keep the logging on to collect user agents information over time.

I might be missing something but if we make reasonable use of the transient and logging, we could be logging useful information (with no flooding) without the need to expose new settings. Allowing users to dismiss the notice would be pretty much the same as "disabling the notice" but with no user-facing setting involved.

Those new settings would be useful if we want to let people disable everything, but I don't think we should allow that. The whole point is precisely to let them know about this.

If absolutely necessary we could offer a filter to turn everything off, but my preference would be that installing the legacy plugin has that same effect. As long as merchants haven't done anything, we should be logging and possibly displaying the notice.

What do you think?

@barryhughes
Copy link
Member

We need some kind of rate limiting, or the logs can easily get flooded.

I think you might be right and I'm just underestimating the number of requests that might hit those deprecated endpoints.

On a number of occasions we've seen 'real' floods that stem from a warning or error being triggered in some code path leading to many-warnings-per-request ... and the logging system has generally held up admirably (albeit, it becomes hard to find information in all the noise).

Whereas, here, there would be a hard maximum of one log entry per request (and I assume only a subset of all requests would be legacy REST API requests). My instinct then is that logging everything will not be problematic, and we don't need to engineer around it.

That said, there's clearly a range of different feelings on this, and we also don't have perfect foresight, some compromise like you're suggesting sounds pretty reasonable, fwiw.

@Konamiman
Copy link
Contributor Author

So if I understood correctly the summary of the suggested changes is:

  1. No settings, dismissable notice instead.
  2. Store usages in a transient instead of an option, still keyed by user agent and endpoint (or maybe only by user agent?) and with counts.
  3. The expiration date of the transient "resets" when a new API request is detected, so it will truly disappear only if there is no API activity.
  4. The notice will only appear if the transient still exists. It could say something like "Legacy REST API usages detected, total X usages from Y user agents, last one was (date), see the logs (link)" and maybe also "The Legacy REST API will be removed, see (blog post link)".
  5. No log, not notice, no nothing if the extension is installed.

How about we make this a 2-week transient instead? We can define the time interval, but that's an example.
That way we can still rate limit logging

I don't get this part. How would we rate limit the logging by using the transient?

Two new settings are added (UI in the Legacy API settings page):

- woocommerce_legacy_api_log_enabled
- woocommerce_legacy_api_usage_notice_enabled

When any of the two are enabled, legacy API usages are stored
in two options, 'wc_legacy_rest_usages' and 'wc_legacy_rest_last_usage'.

'wc_legacy_rest_usages' is a dictionary keyed by user agent,
each entry is in turn a dictionary keyed by request route,
items are arrays containing first and last usage dates as well
as total usages count (API version is logged too but for simplicity
it's not used to key the data).

'wc_legacy_rest_last_usage' contains the entry for the last usage,
regardless of user agent and route. It's used to display the notice.

When 'woocommerce_legacy_api_usage_notice_enabled' is enabled,
and the 'wc_legacy_rest_last_usage' option exists, an admin notice
displaying its contents is shown.
@Konamiman Konamiman force-pushed the add-legacy-rest-api-usage-logging branch from e48f888 to 440c224 Compare December 18, 2023 09:57
- Remove settings
- Use a transient instead of an option for temporary data
- Store temporary data by user agent but not by route
- Make the admin notice dismissable
- Don't log now show the notice if the legacy REST API extension
  is installed and active
- Add a filter to explicitly disable the logging
@Konamiman Konamiman force-pushed the add-legacy-rest-api-usage-logging branch from 440c224 to a87fd2b Compare December 18, 2023 10:01
Copy link
Member

@jorgeatorres jorgeatorres left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hey @Konamiman!

Good job on this one 💯. It tests well and I really like how it's working and almost auto-magically thanks to the simplification in settings/etc. A few things:

  • There are a few PHPCS issues. I noticed a few and indicated those in the review, but there might be others. Not sure if the CI check is not picking those up, but maybe you can run it manually in the affected files.
  • I left some suggestions/comments here and there. Please let me know what you think.
  • Would it be too hard to also surface that there are legacy REST API usages in WC > Settings > Advanced > Legacy API? I know we have the notice, but if it's dismissed, there's no way to quickly check this unless you go looking for transients manually. Maybe a simple warning similar to the one we have about the legacy REST API removal.
    For clarity, I'm talking about this screen:
    Screenshot 2023-12-19 at 13 42 35

Other than that, I think we're almost done. Let me know what you think.

@Konamiman
Copy link
Contributor Author

Would it be too hard to also surface that there are legacy REST API usages in WC > Settings > Advanced > Legacy API? I know we have the notice, but if it's dismissed, there's no way to quickly check this unless you go looking for transients manually.

Rather than that I think we could simply extend the already existing message with "you can check Legacy REST API usages in the logs (link and log file name)".

@jorgeatorres
Copy link
Member

Rather than that I think we could simply extend the already existing message with "you can check Legacy REST API usages in the logs (link and log file name)".

This makes sense to me 👍

@Konamiman
Copy link
Contributor Author

There are a few PHPCS issues.

There's something really weird going on with the class-wc-legacy-api.php file: the only way to have it scanned by the linter locally is moving it outside the includes/legacy directory, then scanning it at its new location, then moving it back. I did and performed an automatic fix, there are more issues but I don't know if it's worth addressing these in this particular pull request.

Now it won't appear if the transient isn't available
or if the Legacy REST API is disabled (or if the Legacy REST API
extension is active, as before); but if the user hasn't
explicitly dismissed the notice it will appear again if the transient
is recreated or the Legacy REST API is enabled again.
@Konamiman Konamiman force-pushed the add-legacy-rest-api-usage-logging branch from e888ab2 to 4defc2e Compare December 20, 2023 08:52
@jorgeatorres jorgeatorres self-requested a review December 20, 2023 11:33
Copy link
Member

@jorgeatorres jorgeatorres left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM. Thanks for your hard work on this one @Konamiman! It turned out great.

@jorgeatorres jorgeatorres merged commit df17713 into trunk Dec 20, 2023
24 checks passed
@jorgeatorres jorgeatorres deleted the add-legacy-rest-api-usage-logging branch December 20, 2023 11:34
@github-actions github-actions bot added this to the 8.5.0 milestone Dec 20, 2023
@github-actions github-actions bot added the needs: analysis Indicates if the PR requires a PR testing scrub session. label Dec 20, 2023
@nigeljamesstevenson nigeljamesstevenson added needs: internal testing Indicates if the PR requires further testing conducted by Solaris status: analysis complete Indicates if a PR has been analysed by Solaris and removed needs: analysis Indicates if the PR requires a PR testing scrub session. labels Dec 20, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
needs: internal testing Indicates if the PR requires further testing conducted by Solaris plugin: woocommerce Issues related to the WooCommerce Core plugin. status: analysis complete Indicates if a PR has been analysed by Solaris
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

4 participants