search

Pierre-Lannoy / wp-decalog

Capture and log events, metrics and traces on your site. Make WordPress observable - finally!
https://perfops.one/
GNU General Public License v3.0
64 stars 8 forks source link

WP Core AJAX Calls to wp_ajax_sample_permalink are wrongly logged as critical #23

Closed JanThiel closed 2 years ago

JanThiel commented 2 years ago

Describe the bug Happy new year :-)

We have reproducible "Critical" Error log entries in Datadog for this AJAX endpoint. It seems that you already added some code to catch this in the past (2y ago) which doesn't seem to work (anymore?).

https://github.com/Pierre-Lannoy/wp-decalog/blob/bece37854f9fb31e2784336930a2bbc3a9893a3a/includes/listeners/class-corelistener.php#L1223-L1227

🟥 Critical [0] Permalink:

WP Core handles AJAX Calls in wp_die slightly different than other calls by defaulting to status 200 instead of 0. Maybe it's a good idea to replicate this handling and add a check for wp_doing_ajax() to your wp_die_handler instead of the hack in there? Then: If is ajax, only log an error if the $args['code'] is > 400 ?

What do you think?

To Reproduce Steps to reproduce the behavior:

  1. Open any "New " like "New Post"
  2. Enter something into the title and leave the input field
  3. Check your DEV tools for ajax calls. It should return "Permalink: " with status 200
  4. Check your Logs, you should have a critical with exactly this content ("Permalink: ") with code "0"

Expected behavior Log Permalink calls / WP AJAX calls with status code 0 as debug instead of critical.

Screenshots image

Environment (please complete the following information):

Pierre-Lannoy commented 2 years ago

Hello @JanThiel … And happy new year too!

Haha. You're right, the analyse of wp_die() is a pain in the ass : there's not a "standardised" way to use it in WP (just search on how it is used, even in the core, you will be shocked). And of course, you're right too, it should be better handled on the DecaLog side. I will fix it (with a more shock-proof method) for the next release.

BTW, I'm not able to reproduce it on fresh 5.8.3 install, do you use something specific as editor?

JanThiel commented 2 years ago

@Pierre-Lannoy Good catch! We use the Classic Editor Plugin and thus the classic editor for our sites instead of Gutenberg. This might explain the difference. And yea, I agree that wp_die is neither designed nor used very straight forward. When I saw the wp_die calls in the ajax call with no status code set I expected the error in there.

Pierre-Lannoy commented 2 years ago

Ahahaha. This is driving me completely crazy… I'm definitely unable to reproduce it, even if I understand well the root cause of the issue I should face :/ Furthermore, I'm not even able to find the right wp_die() call in 5.9… I know you're currently with 5.8, but do you plan to update to 5.9 in some weeks?

JanThiel commented 2 years ago

Don't go mad ;-)

It is this ajax endpoint: https://github.com/WordPress/WordPress/blob/dbc8d76a9f0fb15bd5546ce5d4dd78a8f497ae2f/wp-admin/includes/ajax-actions.php#L1975

It is also there in the WP5.9 branch.

You should be able to easily trigger this using Postman or any browser DEV tools :-)

But anyway isn't this just one source of this issue? As I believe all AJAX calls that terminate with wp_die will falsly trigger the wrong log level?

Pierre-Lannoy commented 2 years ago

As I believe all AJAX calls that terminate with wp_die will falsly trigger the wrong log level?

Of course. And you're right. And the quick solution is to write separate handlers with a debug-only handler for Ajax calls. But I do not understand how you get this as, from my understanding, the wp_ajax_sample_permalink() is a "dead-end" code.

Nevermind. I'm going to sleep on it and will see if I'm more intelligent at the end of the week 🤣

I any case, you can count on a solution (and a new 3.4 version) before the end of the next week.

JanThiel commented 2 years ago

Let me help you with this - again - mind blowing 🤯 (not in a good way) design decission of WordPress and one more reason why the AJAX stuff belongs to the past:

Here is the "reference": https://github.com/WordPress/WordPress/blob/270f2011f8ec7265c3f4ddce39c77ef5b496ed1c/wp-admin/admin-ajax.php#L89

And this is the ajax listener registration: https://github.com/WordPress/WordPress/blob/270f2011f8ec7265c3f4ddce39c77ef5b496ed1c/wp-admin/admin-ajax.php#L164

Magic-Auto-Instantiation 🦄 ... not easy to find and 100% no IDE support...

In any way: Thanks for your amazing support as usual :-) And most important: Don't feel rushed. We lived with and ignored the critical log statements for some time now. Some more weeks do not hurt ;-)

Pierre-Lannoy commented 2 years ago

Ahhhhh. Yes, that's it! Thank you so much :sweat_smile:

Don't worry, there is no excessive pressure: the new version should be available soon in any case. My only point was to include a fix for your issue, and now, I think it would be possible.

Thanks again.

Pierre-Lannoy commented 2 years ago

The 3.4 version embed a fix for your this bug. I close this issue but don't hesitate to reopen it if needed.

Thanks again for your amazing reports.