fixes #15863 - add short request UUID to logs

[domcleal]

New middleware stores the request ID (either from X-Request-ID or a
UUID generated by Rails) in the logger's thread storage. A short UUID is
now logged by default to minimise size of the log messages.

---

Generates log messages such as:

$ egrep "33b38af1.*(Started|Completed)" log/development.log 
2016-07-27T15:38:43 33b38af1 [app] [I] Started GET "/" for 127.0.0.1 at 2016-07-27 15:38:43 +0100
2016-07-27T15:38:45 33b38af1 [app] [I] Completed 200 OK in 1978ms (Views: 1695.6ms | ActiveRecord: 18.5ms)

[ohadlevy]

perfect timing for my ha setup at https://github.com/ohadlevy/foreman-docker-compose thanks @domcleal - however does it make more sense to use session id vs request id? e.g. if you would like to follow a user requests across servers - afaiu this changes every time you access foreman?

[lzap]

Well, both are quite valuable and in the future we want to send structured logs into journal. Since we are dropping EL6 soon, this will enable us to send as much info as we want.

[domcleal]

Yes, session ID is preferable, I've updated the PR to use that by default. Both are stored and the request ID is used if the session ID is missing (i.e. first request without cookies).

[lzap]

An interesting idea: Can we send the UUID (whatever this will be) to Smart Proxy HTTP requests in a header? This way we can make similar change in Smart Proxy and log both Foreman request/session UUID and it's own request UUID.

[lzap]

We already have our log buffer feature and theoretically we could show logs from particular transaction in the Foreman UI, we are that close from that!

[ohadlevy]

@lzap it makes sense, you probably want to include also the effective foreman user (e.g. for api requests and because the uuid means nothing besides the foreman logs).
if we had a foreman own session - like https://github.com/blog/1661-modeling-your-app-s-user-session) that would make it even more interesting :)

[ohadlevy]

merged as d97deb4 thanks @domcleal

[lzap]

Ok, an unit test would be plus, but whatever.

I filed http://projects.theforeman.org/issues/15876 and http://projects.theforeman.org/issues/15877 to track the idea.

[lzap]

Damn, these are dupes. I'd love to complain on RedMine searching capabilities, but @domcleal is able to find tickets, so it must be me... ;-)

[iNecas]

What's the benefit of having the session here vs. request id? The issue here is with user performing multiple requests at the same time. Also using the session id as a shared UI between other services that are called as part of the request is limiting, as you can't group the log messages by user requests.

[iNecas]

I see @ohadlevy had the idea of using session id here: could we revisit this: I find this not that useful as having always request id there

[iNecas]

Let's discuss on #4410

[iNecas]

The user is now being logged in as part of #4385