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

[CrazyJaco]

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.

[CrazyJaco]

I will have a patch for this shortly.

[CrazyJaco]

First pass.

[johnbillion]

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

[CrazyJaco]

@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?

[johnbillion]

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]

Second pass

[CrazyJaco]

@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'

[johnbillion]

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

[CrazyJaco]

Thank you for your time and attention!

[CrazyJaco]

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

Thanks!

[CrazyJaco]

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]

3rd pass. Added public helper method

[CrazyJaco]

Uploaded new patch.

[CrazyJaco]

Fixing a bug.

[desrosj]

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

[pento]

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

[CrazyJaco]

Refreshed Patch for WordPress 5.3

[CrazyJaco]

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

[pento]

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?

[CrazyJaco]

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.

[johnbillion]

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.

[CrazyJaco]

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]

Updated patch with @johnbillion's feedback

[CrazyJaco]

Patch refreshed.
Please review @pento @johnbillion

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

[pento]

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.

[ocean90]

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.

[desrosj]

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/