Implement session::get_last_query_context()

[Krzmbrzl]

Fixes #678
Fixes #1027

[Krzmbrzl]

@vadz do you think we need a way to disable parameter logging? Compared to the overhead of the actual DB query the logging of parameters is likely insignificant but maybe you have a scenario in mind in which this might become important?

[vadz]

@vadz do you think we need a way to disable parameter logging? Compared to the overhead of the actual DB query the logging of parameters is likely insignificant but maybe you have a scenario in mind in which this might become important?

The only 2 potential problems I can think about are:

1. Logging sensitive information, e.g. if you store passwords or credit card numbers in the database.
2. Logging too much data and flooding the logs with useless information.

But it looks like both could be addressed by overriding add_query_parameter()?

[Krzmbrzl]

But it looks like both could be addressed by overriding add_query_parameter()?

Yes.

Also, parameters are not logged persistently. They only live to the next query execution. That is still not good for sensitive information of course. Just wanted to clarify.

[Krzmbrzl]

Just to be explicit about it: from my POV this PR is done

[vadz]

Thanks for your work on this, but after rereading it carefully, I've realized that, in addition to various small remarks below, I have a more global question (and I'm really sorry for completely missing your question about this originally): with this change we now impose some extra overhead for all queries, even if it's not needed at all. Granted, this overhead is not huge, but I'm not sure it's completely negligible neither, considering that there may be a lot of parameters in a query (I'm sure I have some with a few dozens in my own code). Have you tried to measure it by chance?

I don't know if we can avoid this by only returning the query context on demand, i.e. only when/if logger::get_last_query_context() is called, but it looks like it should be possible, or am I missing some reason it isn't?

In any case, after we decide on their final shape, the new APIs need to be mentioned in at least docs/api/client.md and docs/logging.md (we probably need to have a new section about logging parameter values in the latter).

Thanks again!

[vadz]

Not that important, but I'd make this change

Suggested change

	std::string name;
	std::string value;
	const std::string name;
	const std::string value;

to be explicit about the fact that they never change.

[Krzmbrzl]

I think here is the wrong place to do this. This should be encoded in the place that actually uses an instance of this struct by making that specific instance const.

Additionally, having const members can have unintended side-effects like a disabled (by default) assignment operator. That's why I usually don't like having const members 🤔

[Krzmbrzl]

I don't know if we can avoid this by only returning the query context on demand, i.e. only when/if logger::get_last_query_context() is called, but it looks like it should be possible, or am I missing some reason it isn't?

I don't think we have access to the last executed statement, do we? And without access to that, how do you want to obtain the last used parameters?
Always saving them on use seemed like the only way to pull this off, but if I missed something, I'm open to suggestions.

Granted, this overhead is not huge, but I'm not sure it's completely negligible neither, considering that there may be a lot of parameters in a query (I'm sure I have some with a few dozens in my own code). Have you tried to measure it by chance?

I didn't measure it. My gut tells me that any DB call will take significantly longer than logging a tens, even hundreds of parameters but that's just guessing.

I was thinking of whether there might be a semantic such as

sql.enable_query_context_logging(true);

to have a way to explicitly toggle the behavior to opt in or out of this feature.
If we have that, we only have to decide on the default being on or off.

[Krzmbrzl]

@vadz what do you think of the above suggestion?

[vadz]

@vadz what do you think of the above suggestion?

Sorry for the delay, I still didn't have time to look at this properly, but maybe you can answer my question without spending any time on it:

Could we store a pointer to the statement being executed in the session? Or do we need to get the query context after the statement has been already destroyed?

[Krzmbrzl]

do we need to get the query context after the statement has been already destroyed?

I think we do need this functionality. Imo the context is most useful when young some sort of error handling (for the error message) and at this point the executed statement is usually destroyed already (as to my understanding the statement only lives until it has been executed).

[vadz]

But couldn't we fill the context in rethrow_current_exception_with_context(), just as we do now?

[Krzmbrzl]

I don't think so. When we use the rethrow, we are still within the statement (which is therefore still alive). However, we need to be able to access the context even when the statement has already been destroyed (as we want to be able to access the context whenever we access the last query, which is independent of the statement object).

And also, we don't want to have the context available only when there is an error while executing the statement.

[vadz]

I thought we could fill the context stored in the session, but do it only when an exception happens. What prevents us from doing it?

This doesn't help if we want to have the context even without the exception, of course, but IME this is mostly useful when an error occurs, logging successful executions doesn't seem very interesting...

But, in principle, we could also pass some

enum class LogContext
{
  Never,
  Always,
  OnError
};

to enable_query_context_logging() to make this maximally configurable, with OnError only doing it in rethrow_current_exception_with_context().

[Krzmbrzl]

 successful executions doesn't seem very interesting...

I disagree. There are soft errors that arise from the semantics which happen even though the query was successful. In fact, this is the primary use case for me as the exception message in case of a DB error already contains the parameters.
In my case the example is the execution of a query which I expect to produce data. So if the query produces the empty set, that is an error that I want to report even though the query itself ran fine and didn't throw an exception.

But, in principle, we could also pass some

enum class LogContext { Never, Always, OnError };

to enable_query_context_logging() to make this maximally configurable, with OnError only doing it in rethrow_current_exception_with_context()

Works for me 👍

[vadz]

Would you be willing to implement this LogContext proposal? TIA!

[Krzmbrzl]

Yes absolutely! I just didn't find the time to do so yet.

[vadz]

Yes absolutely! I just didn't find the time to do so yet.

No problem at all, I just wanted to check if you were waiting for something from me.