Easiest way to do an EXPLAIN

[sobri909]

I'm doing a bunch of performance tuning this week, and am at the point where I want to EXPLAIN a bunch of queries, to make sure I'm not doing anything dumb with indexes etc.

But so far I haven't found a tidy way to get EXPLAIN results via GRDB.

This is an example of my current attempts:

let query = "EXPLAIN SELECT * FROM LocomotionSample WHERE timelineItemId = '5F7E4537-74A0-48A0-9E75-A2F29BF5BD6' AND deleted = 0 ORDER BY date"
try! Stalker.store.pool.read { db in
    if let row = try Row.fetchOne(db, query) {
        print("EXPLAIN: \(row)")
    }
}

Which results in this:

EXPLAIN: [addr:0 opcode:"Init" p1:0 p2:76 p3:0 p4:"" p5:"00" comment:NULL]

I suspect there's more detail in there that I can extract, but I haven't stumbled onto a way to find it yet. (I'm poking about in the Row code now, but not sure if that's the right place to look).

Do you have any tips, to save me from fumbling around like an idiot for too much longer? 😂

Thanks!

[sobri909]

It also comes to mind that it might be useful to have an explicit method for explains. Maybe something like this:

let query = "SELECT * FROM LocomotionSample WHERE timelineItemId = '5F7E4537-74A0-48A0-9E75-A2F29BF5BD6' AND deleted = 0 ORDER BY date"
try! Stalker.store.pool.read { db in
    let explanation = db.explain(query)
    print("\(explanation)")   
}

With the result object being maybe a dict of some sort, or string, or ... well, I'm not sure yet, because I haven't got as far as seing what SQLite's explains look like. Heh.

[sobri909]

Oh dear lord. I just realised it's not one row, it's multiple rows. And they are far from human readable.

try! Stalker.store.pool.read { db in
    let rows = try Row.fetchAll(db, query)
    for row in rows {
        print("EXPLAIN: \(row)")
    }
}

EXPLAIN: [addr:0 opcode:"Init" p1:0 p2:76 p3:0 p4:"" p5:"00" comment:NULL]
EXPLAIN: [addr:1 opcode:"SorterOpen" p1:1 p2:25 p3:0 p4:"k(1,B)" p5:"00" comment:NULL]
EXPLAIN: [addr:2 opcode:"OpenRead" p1:0 p2:13 p3:0 p4:"23" p5:"00" comment:NULL]
EXPLAIN: [addr:3 opcode:"OpenRead" p1:2 p2:113150 p3:0 p4:"k(2,,)" p5:"02" comment:NULL]
[ ... ]
EXPLAIN: [addr:78 opcode:"Goto" p1:0 p2:1 p3:0 p4:"" p5:"00" comment:NULL]

This is more wordy than I expected. And less readable than I expected.

A human readable parser for these results probably would be worthwhile.

[sobri909]

Oh interesting! SQLite has two levels of EXPLAIN. There's plain EXPLAIN, which is the super low level results seen above, then there's EXPLAIN QUERY PLAN, which is high level human readable.

So if I change my test query to EXPLAIN QUERY PLAN the results are:

EXPLAIN: [selectid:0 order:0 from:0 detail:"SEARCH TABLE LocomotionSample USING INDEX LocomotionSample_on_deleted (deleted=?)"]
EXPLAIN: [selectid:0 order:0 from:0 detail:"USE TEMP B-TREE FOR ORDER BY"]

(which tells me that something isn't right, because it hasn't used the most important index).

Anyway, yeah, I've learnt something today! And it also seems like there's probably some value in having a method for db.explain(query) and/or db.explainQueryPlan(query). Just to make these results more accessible. I'd put together a PR, but it looks like I'm first going to have to dive into figuring out why my super simple query isn't using the most obvious index. Sigh.

[sobri909]

Okay, so the conclusion I've come to is that the "easiest way" to explain a query is to do this:

try! pool.read { db in
    for explain in try Row.fetchAll(db, "EXPLAIN QUERY PLAN " + query) {
        print("EXPLAIN: \(explain)")
    }
}

Which produces a human readable explanation of how you messed up your indexes (or how SQLite badly planned its use of your entirely sensible indexes 😡).

It's not really complex enough to justify its own db.explain() method, I think. And I definitely don't have time to do a PR with an implementation.

I think the most it could deserve is a one liner example in the docs, to save idiots like me from hunting around and getting it wrong a bunch of times 😏

I think it's safe to say this one's resolved! Closing 😊

[groue]

Hello @sobri909!

It's good to see you enjoy the SQLite documentation! Writing GRDB has been a quite interesting journey for me too 😉

You know already everything. I'll just highlight this part of the doc:

The output from EXPLAIN and EXPLAIN QUERY PLAN is intended for interactive analysis and troubleshooting only. The details of the output format are subject to change from one release of SQLite to the next. Applications should not use EXPLAIN or EXPLAIN QUERY PLAN since their exact behavior is variable and only partially documented.

This means that GRDB can not parse the output of those queries. We're bound to deal with raw rows, whose format depends on the SQLite version actually used (it changes with every iOS/macOS release, regardless of GRDB version).

Now, [col1:value1 col2:value2 ...] is a fine debugging output for GRDB rows, except when you want to inspect multiple ones. As you noticed, this is unparsable by any regular human being:

// My eyes are bleeding
[addr:0 opcode:"Init" p1:0 p2:76 p3:0 p4:"" p5:"00" comment:NULL]
[addr:1 opcode:"SorterOpen" p1:1 p2:25 p3:0 p4:"k(1,B)" p5:"00" comment:NULL]
[addr:2 opcode:"OpenRead" p1:0 p2:13 p3:0 p4:"23" p5:"00" comment:NULL]
[addr:3 opcode:"OpenRead" p1:2 p2:113150 p3:0 p4:"k(2,,)" p5:"02" comment:NULL]
[ ... ]
[addr:78 opcode:"Goto" p1:0 p2:1 p3:0 p4:"" p5:"00" comment:NULL]

Compare with sqlite CLI output:

sqlite> EXPLAIN QUERY PLAN ...
addr  opcode        p1    p2    p3    p4        p5  comment
----  ------------  ----  ----  ----  --------  --  -------
0     Init          0     76    0               00         
1     SorterOpen    1     25    0     k(1,B)    00         
2     OpenRead      0     13    0     23        00         
...

I'm not saying that the sequence of virtual machine instructions is easy to read, but at least you could send this output to D. Richard Hipp without insulting him 😅

So... maybe we could:

1. Get inspiration from the SQLite CLI, and enhance GRDB with a better tooling for inspecting raw rows. This would enhance the legibility of all queries, including EXPLAIN and EXPLAIN QUERY PLAN. Will it be new Swift APIs to run inside application code, with a way to dump results somewhere? Will it be some lldb helper? All options are interesting.

2. Extend FetchRequest protocol with explain and explainQueryPlan methods, which would derive new requests:

   let request = Player.filter(Column("email") == "arthur@example.com")
   try dbQueue.read { db in
       // explainRequest would be of type SQLRequest<Row>
       let explainRequest = try request.explain(db)
       explainRequest.sql // "EXPLAIN SELECT * FROM players WHERE email = 'arthur@example.com'"
       let dump = try explainRequest.fetchResultsAsString(db)
       print(dump)
   }

Such extensions can already be written with public GRDB APIs: anybody can write them in a custom extension, polish them until they look usable enough, and submit a PR.

Suggestions are welcome!

[sobri909]

This means that GRDB can not parse the output of those queries. We're bound to deal with raw rows, whose format depends on the SQLite version actually used

Yeah, that was going to be my next argument against a db.explain() method too. It would be a nightmare to maintain, because it would have to track every SQLite version change, and potentially break in ugly ways on a new release.

I'm not saying that the sequence of virtual machine instructions is easy to read ...

I started reading through that and mentally parsing the opcodes before I stopped myself and thought "Wait a minute ... is this really what's expected?! I must be doing this the hard way." 😂

Extend FetchRequest protocol with explain and explainQueryPlan methods

Yeah, that was the line of thinking I was going down too. Although I was seeing it on Database instead. But there's no reason for it to be that low level. [Edit: And I also need to start using FetchRequest in my own code anyway.]

I think the simplest (and most version change tolerant) approach would be just to wrap up the Row values in a pretty formatted table, similar to the CLI output, as you already suggested.

If I run into another terribly planned query this week, I might try to write it myself! But I suspect I've solved my one nasty bottleneck already, so I might not be able to justify the time 😞

Anyway, it's a fun idea for a rainy day 😄

[groue]

Totally! And it's always fun to explore future directions even if we can't jump in right away!