Bug 1408420

Summary:	[RFE] Backport session/request id in logs
Product:	Red Hat Satellite	Reporter:	Lukas Zapletal <lzap>
Component:	Logging	Assignee:	satellite6-bugs <satellite6-bugs>
Status:	CLOSED ERRATA	QA Contact:	Roman Plevka <rplevka>
Severity:	low	Docs Contact:
Priority:	low
Version:	6.2.5	CC:	bkearney, cduryee, chrobert, egolov, ehelms, inecas, jcallaha, oshtaier, peter.vreman, rplevka, zhunting
Target Milestone:	Unspecified	Keywords:	FutureFeature, PrioBumpField, Triaged
Target Release:	Unused
Hardware:	x86_64
OS:	All
URL:	http://projects.theforeman.org/issues/15863
Whiteboard:
Fixed In Version:	foreman-1.11.0.72-1	Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:
Clones:	1426404 (view as bug list)		Environment:
Last Closed:	2017-05-01 13:57:17 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:
Bug Depends On:
Bug Blocks:	1122832, 1426404

Description Lukas Zapletal 2016-12-23 10:31:23 UTC

In upstream Foreman release, we include request and optionally session id in logs, so it will be much easier to match the specific request:

http://projects.theforeman.org/issues/15863

This small improvement would be very useful to backport into 6.2.

TRIAGE NOTES: Very small and standalone patch, zero risk.

DOCO NOTES: We need an upgrade note to make this new feature effective, logging.yaml must be modified:

 :pattern: "%d %.8X{session} [%c] [%.1l] %m\n"

Otherwise this won't be used

Comment 2 Bryan Kearney 2016-12-23 13:17:32 UTC

Moving this bug to POST for triage into Satellite 6 since the upstream issue http://projects.theforeman.org/issues/15863 has been resolved.

Comment 3 Chris Duryee 2017-02-09 06:13:55 UTC

This would make debugging slow requests a lot easier, the current log is difficult to read when there's a lot of activity.

Comment 5 Satellite Program 2017-02-23 21:10:35 UTC

Please add verifications steps for this bug to help QE verify

Comment 6 Ivan Necas 2017-03-24 09:25:29 UTC

*** Bug 1435563 has been marked as a duplicate of this bug. ***

Comment 9 Ivan Necas 2017-03-24 09:36:51 UTC

Verification steps:

1. preform requests
2. the logs are prefixed by a hash, that groups the requests
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
3. for web ui, the hash is determined by a session id: two different users have different hash
4. for API requests, the hash is unique per request.

Comment 10 Roman Plevka 2017-03-24 10:04:27 UTC

VERIFIED

for 6.2.9-1, the request ids are now logged as the 3rd field in production.log
Sat server also exposes this as a X-Request-Id in HTTP response.

2017-03-24 05:53:09 f67c1d8e [app] [I] Started HEAD "/api/v2/organizations" for 10.19.41.18 at 2017-03-24 05:53:09 -0400
2017-03-24 05:53:09 f67c1d8e [app] [I] Processing by Api::V2::OrganizationsController#index as JSON
2017-03-24 05:53:09 f67c1d8e [app] [I]   Parameters: {"apiv"=>"v2"}
2017-03-24 05:53:09 f67c1d8e [app] [I] Authorized user admin(Admin User)
2017-03-24 05:53:09 f67c1d8e [app] [I]   Rendered api/v2/taxonomies/index.json.rabl within api/v2/layouts/index_layout (5.7ms)
2017-03-24 05:53:09 f67c1d8e [app] [I] Completed 200 OK in 40ms (Views: 6.6ms | ActiveRecord: 14.4ms)

Comment 13 errata-xmlrpc 2017-05-01 13:57:17 UTC

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2017:1191

Comment 14 Peter Vreman 2017-05-02 14:11:34 UTC

*** Bug 1264827 has been marked as a duplicate of this bug. ***