Log queries including bind arguments and execution time

[mehcode]

TRACE sqlx::query > SELECT …, elapsed: 0.04ms

    SELECT foo, bar, baz
    FROM this_table_over_here
    WHERE foo = $1 AND bar = $2
    ORDER BY baz

    $1 = 50
    $2 = 694

TRACE sqlx::query > INSERT INTO table_name …, elapsed: 12.04ms

Log format is very "let's figure out what we think looks best". Use log. We should new line + indent like error stack traces for the query body. Not sure how to nicely show the bind arguments.

[shssoichiro]

I'd like to work on this, since this is a feature I'd really like to have. On top of this, would it be a consideration to have increasing log levels for slow queries? E.g. if a query is slower than 1000ms, log at INFO and if slower than 3000ms, log at WARN? (Simply using the WARN level with one threshold is also an option.)

[mehcode]

That makes complete sense. I agree with a WARN with some threshold. We don't need to make it configurable, at least in the beginning.

[shssoichiro]

I have a basic cross-database POC. Things that still need to be done:

1. Format the SQL queries, this means writing a SQL formatter library in Rust. I couldn't find one that had an open-source license.
2. Accurately parse the query type. I did a very naive approach of just taking the first word for the POC.
3. Print the arguments. This is hard at the moment because there's no consistent way to get the arguments for each database (PG for example stores them in raw binary.)

I'll continue working on this, I at least want to have 1 and 2 ready before PR'ing. I think that printing arguments can come later if needed.

[mehcode]

Format the SQL queries

I think we can assume the queries are reasonably formatted?

Accurately parse the query type

Do we need this? Looking back at my example, I see how I'm showing that. I really meant more like take the first X characters from the query and add a "..." at the end.

Print the arguments

Yeah... this probably needs a get method or similar added to Arguments. I can add this and we can improve the logging after.

[shssoichiro]

The queries seem to come in as the user inputted them. Which may be reasonably formatted or may be all on one line, depending on how the user chose to write their strings.

If formatting the queries is less important, then that can be a feature that comes later, same with improving query type parsing if the naive approach works fine for now.

[evanjs]

No rush or anything, but is there anything that can be done to help this along?

Picking this library up without binding arguments--let alone query logging in general--has proved to be a sticking point for me, especially with custom data types.

Doubt there's anything major I can help with, but it might be helpful to get a snapshot of the current state regardless.

[frederikhors]

Hi people, can you help me understand how to log query with parameters for debugging purposes? #2259

[sify21]

Hi people, can you help me understand how to log query with parameters for debugging purposes? #2259

You can change postgres setting and restart. In data/postgresql.conf file, change the log_statement setting to 'all'

[frederikhors]

You can change postgres setting and restart. In data/postgresql.conf file, change the log_statement setting to 'all'

Yeah, I know. I would like to log in my rust tracing infos...