Logging SQL

[andrewthad]

With the scaffolded yesod site, the log output for SQL queries looks like this:

20/Feb/2015:11:18:22 -0500 [Debug#SQL] "SELECT \"draft_sales_order_line\".\"id\", \"draft_sales_order_line\".\"draft_id\", ...

I have truncated the line because it is very long. However, my point is that is it a Haskell-escaped string. This would be great if I was planning on sticking it in GHCi to replay the query, but I never do that. Moreover, I feel pretty confident that almost no one is doing that. I open up psql and copy the queries into that (after having to run a script to unescape C-style strings). It would be nice if the logs just printed the actual query. I'd like to see either one of two things:

1. Persistent's logging behavior being changed (I think this would be trivial).
2. The same thing but with optional buy-in.
   The line causing this behavior is right here: https://hackage.haskell.org/package/persistent-2.1.1.4/docs/src/Database-Persist-Sql-Raw.html#rawSql
   In the definition of rawQueryRes where we call show sql. Thanks for any feedback or consideration of this proposal.

[MaxGabriel]

Printing the actual query sounds better. I've often generated some SQL with an ORM and then pasted it into a MySQL/Postgres console, especially to run EXPLAIN on the query.

[snoyberg]

I've just pushed a commit to the persistent repo to address this. I haven't tested it myself in the scaffolding, but it should work as expected. @andrewthad if you can give this a go and let me know if it addresses your concern, I can release to Hackage.

[andrewthad]

I don't have an easy way to run it right now, but from looking at your commit I can tell that it does what I want. If you're ok with releasing it without me running it, then you could go ahead with that, but if you'd rather have someone check it, then I can do that that sometime tomorrow.

[snoyberg]

I'm fine waiting another day or two before releasing.

[andrewthad]

I just tried it out and it works. The only other thing I'll mention (because I just noticed this) is that the bit at the end that shows the source file containing the code that called the logger seems like it's sort of a waste, especially given that (1) all sql logs originate here and (2) None of the other server logs that yesod creates have source file information. But I'm content with it as is if that's not something you want to do. Here is the output I get from your a scaffolded site with your latest commit:

24/Feb/2015:11:26:34 -0500 [Debug#SQL] SELECT "id","ident","password" FROM "user" WHERE "ident"=?; [PersistText "andrew.thaddeus@gmail.com"] @(persistent-2.1.1.5:Database.Persist.Sql.Raw ./Database/Persist/Sql/Raw.hs:42:26)

[snoyberg]

Changing that location thing would be more invasive than it would seem, and would actually break a very useful feature: try using $logError in your app itself, and you'll see why it's present. Yes, in the case of library-generated data, it's useless.

I'll release this to Hackage now, thanks for checking it!

[andrewthad]

I wasn't suggesting that we redefine $logDebugS, only that we change the code in persistent to use logDebugN instead. But, it can wait for some other time. Not my most crucial concern.

[snoyberg]

Oh, that's a good idea, I hadn't thought of doing so. Let me test that out
now...

On Tue Feb 24 2015 at 6:45:24 PM andrewthad notifications@github.com
wrote:

I wasn't suggesting that we redefine $logDebugS, only that we change the
code in persistent to use logDebugN instead. But, it can wait for some
other time. Not my most crucial concern.

—
Reply to this email directly or view it on GitHub
#939 (comment).

[snoyberg]

Done :)

[andrewthad]

Sweet. Thanks for getting that in.