Small: Log requests body

[fflorent]

This PR brings 2 things to improve a little bit the debugging:

• It ensures that the value of GRIST_LOG_SKIP_HTTP is read as a boolean (it defaults to true in the main entrypoint, which seems safe);
• It introduces a new env variable, GRIST_LOG_HTTP_BODY, which logs the content of the request bodies, I do not document this variable on purpose because of its potential security like logging passwords or api keys (though we may find a way to redact these values, I propose to iterate);

Here is how it is rendered with both GRIST_LOG_SKIP_HTTP=false and GRIST_LOG_HTTP_BODY=true :

2024-03-27 15:59:54.648 localhost:8484 POST /o/docs/api/docs/hs5JXzp5NbQM/tables/Table1/records {"records":[{"fields":{"Foo":"heloooo","Foo2":"1"}}]} 200 20.833 ms - 22

And how it is rendered with just GRIST_LOG_SKIP_HTTP=false:

2024-03-27 15:57:16.728 localhost:8484 POST /o/docs/api/docs/hs5JXzp5NbQM/tables/Table1/records  200 22.478 ms - 22

[jonathanperret]

Hmm, I don't know if this is intentional, but it looks to me like this will log { … path: "/whatever", body: {}, status: 200, … } when body logging is disabled, and { … path: "/whatever", body: "body-content", status: 200, … } when enabled. Having body switch from being a string to an (empty) object doesn't seem correct.

My earlier suggestion was to use object spreading to make body go away entirely when not enabled:

Suggested change

	body: shouldLogBody ? tokens.body(req, res) : {},
	...(shouldLogBody ? { body: tokens.body(req, res) } : {}),

[fflorent]

You're right, thanks!

[fflorent]

That being said, while it should work when logging in JSON, it still prints {} when logging in plain text:

2024-03-28 18:20:45.193 localhost:8484 GET /o/docs/api/orgs/0/workspaces?includeSupport=1 {} 304 39.934 ms - -

[jonathanperret]

Err, this is quite weird, how would a change to the JSON logging impact the plain text logger?

[fflorent]

It doesn't, it seems like the JSON and the plain text logger are different things.

But whereas what you suggested removes the body when we enable logging in JSON, it still prints {} when the plain text logging is enabled.

Unless we find a way to skip the body here:
https://github.com/gristlabs/grist-core/pull/913/files#diff-cc10ec0f715f5f40f94fcf195753f0052aede521998746b91689ce96b9a30055R420-R421

If I am correct, Nginx in this case prints a - when no values exist, maybe we could do the same?

[jonathanperret]

Here's what I'm observing when running your branch (with GRIST_LOG_SKIP_HTTP=false and GRIST_HOSTED_VERSION unset in all cases), when doing a POST to / with body {"x":1} :

• with GRIST_LOG_HTTP_BODY=false:

localhost:8484 POST /  404 3.977 ms - 2347

No {} here, but note that there's a double space here between / and 404, which you could get rid of by tweaking the template to include the space before :body inside the conditional.

• with GRIST_LOG_HTTP_BODY=true GRIST_HOSTED_VERSION=:

localhost:8484 POST / {"x":"1"} 404 12.982 ms - 2347

The body is correctly printed here. However if I do a request without a body, e.g. GET / this is printed:

localhost:8484 GET / {} 302 8.375 ms - 51

In fact, if I do a POST with a non-JSON request body I also get {} printed. And "body": "{}" if I enable JSON logging with GRIST_HOSTED_VERSION=true (btw that variable might also benefit from consistent application of isAffirmative — it is referenced three times through the code, but only once with isAffirmative).

Maybe JSON.stringify(req.body) is not the best way to get at the body for logging? Or maybe it's fine since there's not much point in logging non-JSON bodies?

[fflorent]

I think I have come up with a solution for your remark here, what do you think?
9035859

[fflorent]

btw that variable might also benefit from consistent application of isAffirmative — it is referenced three times through the code, but only once with isAffirmative

Also done in 0e2af49