Updated: Comment #5
Problem/Motivation
The checkbox for "Show other queries run during render" does nothing. The code is based on the $conf['dev_query'] variable from Drupal 6.
Steps to reproduce
- Visit
/admin/structure/views/settings - Check "Show other queries run during render..."
- Edit a view; click the preview button.
Expected result: "other" queries should be visible.
Actual result: No other queries are shown.
Proposed resolution
Port code to use Database::startLog() feature of DBTNG.
Remaining tasks
Patch needs review.
User interface changes
In this patch, the logging is started earlier (at the very top of view::render()). Waiting until after the execute phase ends up omitting many queries from the log.
As a result, the log includes the main query, so rather than two sections ("Query" and "Other Queries"), the layout has been tweaked to show "all queries". In the future, I would like to reuse the "placeholder / argument / explain" grid in the Devel module. However I believe at the moment that isn't possible without some minor changes to Devel.
API changes
N/A
Original report by david_garcia_garcia
So, I am writting a filter handler that, itself, runs a few queries. In order to be able to properly debug what's going on in 3d party deployments to help people troubleshoot I'd thought to enable the option in Views Options that says "show additional queries".
So, I noticed that the queries issued by the filter were not showing, and that is OK because the filter is built before the call to:
start_query_capture()
So I thought, maybe I can call that from the Handler so that it starts tracking queries before my handler does it's job. Still no additional queries shown.
Investigating, the start_query_capture() states:
db_query() stores the queries that it runs in global $queries,
* bit only if dev_query is set to true.
After looking into it deeper to see why additional queries were not shown, I ended up no where: there is not a single call or condition in the whole of drupal core to the $conf['dev_query'] (except in start_query_capture() and end_query_capture()). Queries are not tracked.
I might be missing something, but to me this looks like and old broken feature, so I said to myself, well, maybe instead of fixing or implementing this broken thing, I can simply populate the views->additional_queries manually from my module, but what a surprise, the end_query_capture() method is completely ingnoring any preexisting values in that property and overriding it with what it expects to find in the global $query:
$this->additional_queries = $temp;
Easy fix: if a module wants to output debugging information about the queries it runs, let it do so by the means of additional_queries, to be able to do so, replace the previous statement with:
$this->additional_queries = array_merge(empty($this->additional_queries) ? array() : $this->additional_queries,empty($temp) ? array() : $temp);
| Comment | File | Size | Author |
|---|---|---|---|
| #16 | views-fix-other-queries-2191287.patch | 7.07 KB | david_garcia |
| #13 | views-fix-other-queries-2191287.patch | 6.97 KB | david_garcia |
| #11 | view-fix-other-queries-2191287.patch | 6.96 KB | david_garcia |
| #5 | 2191287_5.patch | 5.25 KB | grendzy |
| #3 | views-merge-preexisting-additional-queries-2191287.patch | 416 bytes | david_garcia |
Comments
Comment #1
david_garcia commentedComment #3
david_garcia commentedLet's try again...
Comment #4
grendzy commented$conf['dev_query']was an old Drupal 6 variable, and it was removed when DBTNG was committed to core. It seems likely this feature has not ever worked on the D7 branches.I tested the the patch in #3, and it did not restore the "show additional queries" functionality.
Comment #5
grendzy commentedComment #6
twardnw commentedWow, had no idea that so much info was not being output.
Patch applies clean, and indeed it is now showing me a LOT more queries that are being run.
Comment #7
jojonaloha commentedThe patch in #5 looks good to me. Tested with Views 7.x-3.7, displays many more queries when the box is checked and only the main query when it isn't.
Comment #8
svajlenka commentedPatch #5 applies fine, and works. Setting as RTBC, I'd love to see this get committed soon.
Comment #9
david_garcia commentedI was just looking into this:
- Queries are printed with unreplaced placeholders, to improve debugging experience that should be done.
- When printing query information, in Drupal 7 we have additional information available besides query and execution time including the calling function/context, that would also help a lot debugging, we have the oportuninity to include this now.
Both of these are easy to accomplish, I'll try to propose new patch.
Comment #10
grendzy commenteddavid_garcia_garcia: I agree the placeholder, caller, etc information is highly desirable. If you can improve this patch, great!
The devel module has a wonderful function for displaying this info:
devel_query_table(). What I propose is using this function when it's available, rather than reimplementing another query log printer. When devel is unavailable, Views would fall back to a more simplistic display. The greatest advantage ofdevel_query_table()is it offers an AJAX interface for EXLAIN.There is a problem however,
devel_query_table()can't currently be used in this context, because it relies on a single shared Javascript valueDrupal.settings.devel.request_id. I think it's a small change to convert the request ID to a DOM attribute, which then allows multiple query logs to be displayed within the same page.So, my proposal is to commit an interim solution first, then work on improving
devel_query_table(), then finally leveraging that function in Views.Comment #11
david_garcia commentedComment #12
grendzy commentedStray tabs here, otherwise looks good. Can you please re-roll?
Comment #13
david_garcia commentedComment #14
david_garcia commentedComment #15
grendzy commentedOne more quibble, I'm seeing some notices with the latest patch:
Comment #16
david_garcia commentedSorry for the back and forth, I made some arbitrary code movement without testing.... Hope to be more lucky this time.
Comment #17
david_garcia commentedComment #18
grendzy commentedAll good, back to RTBC.
Comment #19
david_garcia commented¿Does this still apply in D8?
Comment #20
lendudeChecked how D8 does this:
Timing is what it says on the D8 tin, 'during view rendering':
So this should probably stay in the Views 7.x-3.x queue (and not the Drupal core queue for D8 Views). Moving it back to 7.x-3.x