Make WordPress Core

Opened 6 years ago

Closed 5 years ago

Last modified 4 years ago

#42151 closed enhancement (fixed)

Create a filter to add information to query data saved when SAVEQUERIES is true

Reported by: crazyjaco's profile CrazyJaco Owned by: pento's profile pento
Milestone: 5.3 Priority: normal
Severity: normal Version:
Component: Database Keywords: has-patch has-dev-note
Focuses: Cc:

Description

When SAVEQUERIES is set to true in wp-config.php, an array gets created and all queries to the database get logged to that array with the query, elapsed time, and stack trace.

It would be nice if there was a filter here to add other elements to this array on a per query basis.

For instance, if I were using a plugin like ElasticPress, I would like to use this filter to add in a value that might say "Query served by ElasticPress" or something to that affect.

Attachments (8)

42151.diff (681 bytes) - added by CrazyJaco 6 years ago.
First pass.
42151.2.diff (826 bytes) - added by CrazyJaco 6 years ago.
Second pass
42151.3.diff (1.2 KB) - added by CrazyJaco 6 years ago.
3rd pass. Added public helper method
42151.4.diff (1.2 KB) - added by CrazyJaco 6 years ago.
Fixing a bug.
42151.5.diff (1.2 KB) - added by CrazyJaco 5 years ago.
Refreshed Patch for WordPress 5.3
42151.6.diff (2.7 KB) - added by pento 5 years ago.
42151.7.diff (2.6 KB) - added by pento 5 years ago.
42151.8.diff (2.3 KB) - added by CrazyJaco 5 years ago.
Updated patch with @johnbillion's feedback

Download all attachments as: .zip

Change History (35)

#1 @CrazyJaco
6 years ago

I will have a patch for this shortly.

@CrazyJaco
6 years ago

First pass.

#2 @CrazyJaco
6 years ago

  • Keywords has-patch added

#3 @johnbillion
6 years ago

  • Component changed from Query to Database
  • Keywords 2nd-opinion added
  • Version trunk deleted

Thanks for the patch, @CrazyJaco.

I think this is a bit of a risky change. The idea behind the saved queries and the associated debugging data is that a debugging plugin can make assumptions about what data is present in the wpdb::$queries property. If a filter is added here, then that (somewhat weak) contract is broken.

I wonder if it would be better to add an extra element to the stored query data, the value of which is a filterable array of "extra" and arbitrary information relating to the query. That way a debugging plugin can use an expose that information as it wishes, but without the need to worry about which data is present in the stored queries and in what order.

Related: #41956

#4 @CrazyJaco
6 years ago

@johnbillion Thank you for the reply! I was thinking about this last night and came to a similar realization. If two plugins added an element each to the array, they wouldn't know which element in the array was necessarily their piece of data since it is not an associative array. Changing it to one would be a breaking change so that is out of the question.

Are you suggestion something like this:

<?php
QueryData[0] => query syntax
QueryData[1] => elapsed time,
QueryData[2] => stacktrace,
Querydata[3] => apply_filter( Array( 
      custom_meta_key_1 => custom_meta_value_1,
      custom_meta_key_2 => custom_meta_value_2
    )
  )

so that QueryData[3] is just set to an empty filterable associative array?

#5 @johnbillion
6 years ago

  • Keywords needs-patch added; has-patch removed

Yeah I think that makes the most sense. A note in the documentation for the filter could be added which recommends that associative keys are used in the array.

@CrazyJaco
6 years ago

Second pass

#6 @CrazyJaco
6 years ago

  • Keywords has-patch added; needs-patch removed

@johnbillion Added an updated patch. Let me know what you think.

Testing this with a test plugin works as I would expect, except for the first query that gets run, but I think that query might fire before plugins are loaded. All other queries show the new meta data added by my test plugin.

This is the first query:
SELECT option_name, option_value FROM wp_options WHERE autoload = 'yes'

#7 @johnbillion
6 years ago

A plugin in mu-plugins should be able to catch every query. Patch looks good, I'll review properly a bit later.

#8 @CrazyJaco
6 years ago

Thank you for your time and attention!

#9 @CrazyJaco
6 years ago

Hey @johnbillion, just checking in to see if you have had a moment to review this patch/ticket properly.

Thanks!

#10 @CrazyJaco
6 years ago

  • Keywords needs-refresh added; 2nd-opinion has-patch removed

This ticket has sat for a while and after some thought I think the call to log a query should be extracted into a method in the class so it can be called elsewhere.

The way it currently works, you can't really log a query that goes to an external source (ElasticSearch) outside of the wordpress database and never makes it this far in the query call stack.

I will update the patch for feedback.

@CrazyJaco
6 years ago

3rd pass. Added public helper method

#11 @CrazyJaco
6 years ago

  • Keywords has-patch added; needs-refresh removed

Uploaded new patch.

@CrazyJaco
6 years ago

Fixing a bug.

This ticket was mentioned in Slack in #core by crazyjaco. View the logs.


6 years ago

#13 @SergeyBiryukov
6 years ago

  • Milestone changed from Awaiting Review to 5.0

#14 @pento
5 years ago

  • Milestone changed from 5.0 to 5.1

#15 @pento
5 years ago

  • Milestone changed from 5.1 to 5.2

This ticket was mentioned in Slack in #core by crazyjaco. View the logs.


5 years ago

#17 @desrosj
5 years ago

  • Keywords needs-testing added
  • Milestone changed from 5.2 to 5.3

This still needs feedback, testing, and a proper review. Punting to 5.3.

#18 @pento
5 years ago

  • Keywords needs-refresh added; needs-testing removed

I'm cool with this change. The patch needs refreshing to apply cleanly against trunk, but is otherwise good to go.

@CrazyJaco
5 years ago

Refreshed Patch for WordPress 5.3

#19 @CrazyJaco
5 years ago

  • Keywords needs-refresh removed

Patch refreshed. Let me know if anything looks off. Its been quite a while since I've created a patch.

@pento
5 years ago

@pento
5 years ago

#20 follow-up: @pento
5 years ago

Thank you for refreshing the patch, @CrazyJaco! 42151.7.diff makes a few adjustments to how it works:

  • Move the filter from ::do_query() to ::log_query(), so all calls to ::log_query() can be filtered.
  • Instead of filtering just the additional data, filter the entire log entry, rename the filter to log_query_data to match.
  • Additional documentation.

Does this change still work for you, @CrazyJaco?

@johnbillion: As one of my favourite consumers of wpdb::queries, do you foresee problems with this patch?

#21 @CrazyJaco
5 years ago

This still appears to achieve what I was hoping for.
Sure didn't notice the starting Unix timestamp was added in 5.1 until I looked a this patch.

No further changes from me on this one.
Thanks for reviewing the new patch.

#22 in reply to: ↑ 20 @johnbillion
5 years ago

Replying to pento:

@johnbillion: As one of my favourite consumers of wpdb::queries, do you foresee problems with this patch?

Thank you for your kind words. I enjoy consuming queries, in moderation.

I'm generally in favour of this patch, but I'd like to recommend some changes.

  1. The signature of the log_query() method could be improved by accepting each parameter individually instead of as an array, and then construct the data array inside log_query().
  2. Where log_query() is called within _do_query(), the $this->time_start parameter is missing. The above would help prevent this.
  3. I stand by my concerns in comment #3, filtering the entire data array seems risky. What's the use case for filtering the SQL, the time spent, the stack trace, and the start time? I would prefer a filter on just the "Custom query data" array.

#23 @CrazyJaco
5 years ago

I think the third point makes sense. If I had existing debugging plugins, they would likely not behave as I would have expected if those values were modified. This would essentially break backward compatibility for those plugins, no?

I will create a new patch to keep things moving along.

@CrazyJaco
5 years ago

Updated patch with @johnbillion's feedback

#24 @CrazyJaco
5 years ago

Patch refreshed.
Please review @pento @johnbillion

I was uncertain if I placed the filter comment in the right place.

#25 @pento
5 years ago

  • Owner set to pento
  • Status changed from new to assigned

Thank you for the patch update, @CrazyJaco!

I originally added the entire data array to the filter as it's useful to be able to obtain that data when running the filter. I agree that it's risky, though: I've modified the query to pass them as extra parameters, instead, so they can't be modified, just read.

#26 @ocean90
5 years ago

  • Resolution set to fixed
  • Status changed from assigned to closed

In 45635:

WPDB: Allow custom data to be added to logged queries.

This adds a new method, wpdb::log_query(), and a new filter, log_query_custom_data. The custom data is stored as a new element in each entry of the wpdb::$queries array.

Props CrazyJaco, johnbillion, pento.
Fixes #42151.

#27 @desrosj
4 years ago

  • Keywords has-dev-note added

Mentioned in the Miscellaneous Developer Focused Changes dev note for 5.3: https://make.wordpress.org/core/2019/10/15/miscellaneous-developer-focused-changes-in-5-3/

Note: See TracTickets for help on using tickets.