Add SQL Logging in the debugging/development panel

[elpaso]

QGIS Enhancement: Add SQL Logging in the debugging/development panel

Date 2022/01/17

Author Alessandro Pasotti (@elpaso) (from an original idea and POC by @nyalldawson )

Contact elpaso at itopen dot it

maintainer @elpaso

Version QGIS 3.27

Summary

When debugging or developing a QGIS algorithm or a QGIS plugin and when investigating performances of a particular layer it is often useful to view the SQL commands that QGIS sends to the backend.

Proposed Solution

The current proposal will add a SQL section to the debugging/development panel where the SQL commands sent by the data provider and by the connections API will be logged, together with their execution time as measured by QGIS (i.e. in the client that sent the commands).

Following the same logic currently implemented in the network logger a [Record] button will be provided to enable the SQL command logging.

Affected Files

• All DB data provider implementations will need to send a message to the debugging logger in order to log the SQL command.
• All DB connection API providers will need to send a message to the debugging logger in order to log the SQL command.

Performance Implications

The impact on performances is negligible when the SQL logging is not active (which is the default), when the development/debugging tool is active and the SQL logging is enabled we can expect a very small (most probably negligible) impact due to the function call that sends the information to the logger.

To avoid an excessive flooding of logged commands MAX_LOGGED_REQUESTS will be also considered in the SQL logger.

Backwards Compatibility

None

Votes

(required)

[haubourg]

That would be a real killer feature ! In conjuction with this, it would be really nice to be able to overload provider connexions with some session variables so that you could change the DB behavior. Some options I wish I could change, for postgresql obviously, but

• client_min_message (to increase sql verbosity)
• max_worker_per_gather
• set role
• set search_path etc...

I'm probably out of the scope of this QEP, but I think it's worth mentionning how powerful for debugging this would be

[nyalldawson]

In case anyone is asking "isn't this a new feature?", here's my thoughts:

Personally, I do not think so. The motivation here is solely to provide better debugging tools for QGIS developers and power users to help us more easily identify and fix issues (and implement optimisations) with the database providers. Even though it's a user-facing change, debugging the queries is basically the only use case here, and this functionality is NOT designed to be a full replacement for any logging capabilities on the database itself.

Basically, it's intended just a (powerful!) tool for analysing the queries used by QGIS so that we can make the providers better.

(That said... there is SOME user-facing value here aside from the improved bug fixing/optimisations which will ultimately result. Since the log will record the execution time of all queries, an end user could use the log to identify slow queries on their database and use this information to add appropriate indices/other optimisations to their database. But that's really just a side-effect from the main use case of this change!)

disclaimer: I've worked with @elpaso on putting this proposal and a proof of concept together, but I won't be seeking any remuneration for that

[rduivenvoorde]

Nice.

Would the tool 'resolve' query params in case of calling procedures?

Context: I sometimes call stored procedures with a lot of params, and it is a hassle to recreate a working query from it... So a way to copy/paste a working url in another client like dbeaver would be cool (like the network debugging tool: being able to check requests and queries in another environment/browser is very handy). Especially seeing the full parameters is nice.

Or... maybe even have a way in QGIS (?via python client lib) to call the same query via another user?

Anyway: go go :-) this can start pretty 'simple' isn't it, and while on the way we will have/get a lot of other ideas :-)

[elpaso]

@rduivenvoorde before expectations get too high, the proposed implementation will consist in logging the SQL sent by QGIS data providers and QGIS connections API, that's all.

Whatever happens on the server will not be logged and the implementation must be backend-agnostic, so the best we can do is to log the plain SQL string sent to the server, for some DBs (e.g. for postgres) we will probably log separately the prepare and exec prepared instructions, the latter will most probably log arguments as well (probably cut at a certain length to prevent UI bloating).

[wonder-sk]

This sounds really good... not sure if it is in the scope, but it would be great if the providers could optionally report extra information - I am mainly thinking about time to get results and number of returned rows (both can indicate some anomalies such as fetching a lot of data, or very slow query)

[elpaso]

This sounds really good... not sure if it is in the scope, but it would be great if the providers could optionally report extra information - I am mainly thinking about time to get results and number of returned rows (both can indicate some anomalies such as fetching a lot of data, or very slow query)

The time will be available for sure, I'll have to check about the number of returned rows but I think it will be possible.