Bug 1412186
| Summary: | [RFE] Track what user executed remote job in the production.log | ||
|---|---|---|---|
| Product: | Red Hat Satellite | Reporter: | Michal Dekan <mdekan> |
| Component: | Remote Execution | Assignee: | Ivan Necas <inecas> |
| Status: | CLOSED ERRATA | QA Contact: | Marek Hulan <mhulan> |
| Severity: | medium | Docs Contact: | |
| Priority: | medium | ||
| Version: | 6.2.4 | CC: | bbuckingham, bkearney, inecas, jcallaha, ktordeur, mdekan, mhulan, mmccune, oshtaier, rbobek |
| Target Milestone: | Unspecified | Keywords: | FutureFeature, Triaged |
| Target Release: | Unused | ||
| Hardware: | x86_64 | ||
| OS: | Linux | ||
| Whiteboard: | |||
| Fixed In Version: | Doc Type: | If docs needed, set a value | |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2018-02-21 12:37:44 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: | |||
Created redmine issue http://projects.theforeman.org/issues/18949 from this bug I've proposed a change to include info about the user performing the actions inside the production.log, that would apply for all logged messages, not only for remote execution. I'm waiting for feedback of other core contributors. Upstream bug assigned to inecas Upstream bug assigned to inecas There is one issue with the proposed solution: the info about the user get logged, but unfortunately, we don't have this information at the time the parameters are being logged, which leads to this kind of logs: 2017-03-17T15:13:50 23eeb21c [app] [I] Started GET "/" for 127.0.0.1 at 2017-03-17 15:13:50 +0100 2017-03-17T15:13:50 23eeb21c [app] [I] Processing by DashboardController#index as HTML 2017-03-17T15:13:50 23eeb21c [user:skoroadmin] [app] [I] Rendered dashboard/index.html.erb within layouts/application (88.7ms) 2017-03-17T15:13:50 23eeb21c [user:skoroadmin] [app] [I] Rendered common/_searchbar.html.erb (5.2ms) 2017-03-17T15:13:50 23eeb21c [user:skoroadmin] [app] [I] Rendered layouts/_application_content.html.erb (6.3ms) 2017-03-17T15:13:51 23eeb21c [user:skoroadmin] [app] [I] Rendered home/_user_dropdown.html.erb (5.6ms) 2017-03-17T15:13:51 23eeb21c [user:skoroadmin] [app] [I] Rendered home/_organization_dropdown.html.erb (4.7ms) 2017-03-17T15:13:51 23eeb21c [user:skoroadmin] [app] [I] Rendered home/_location_dropdown.html.erb (5.2ms) 2017-03-17T15:13:51 23eeb21c [user:skoroadmin] [app] [I] Rendered home/_org_switcher.html.erb (11.1ms) 2017-03-17T15:13:51 23eeb21c [user:skoroadmin] [app] [I] Rendered home/_submenu.html.erb (3.1ms) 2017-03-17T15:13:51 23eeb21c [user:skoroadmin] [app] [I] Rendered home/_submenu.html.erb (3.4ms) 2017-03-17T15:13:51 23eeb21c [user:skoroadmin] [app] [I] Rendered home/_submenu.html.erb (2.0ms) 2017-03-17T15:13:51 23eeb21c [user:skoroadmin] [app] [I] Rendered home/_submenu.html.erb (1.3ms) 2017-03-17T15:13:51 23eeb21c [user:skoroadmin] [app] [I] Rendered home/_submenu.html.erb (3.0ms) 2017-03-17T15:13:51 23eeb21c [user:skoroadmin] [app] [I] Rendered home/_topbar.html.erb (135.9ms) 2017-03-17T15:13:51 23eeb21c [user:skoroadmin] [app] [I] Rendered layouts/base.html.erb (768.2ms) 2017-03-17T15:13:51 23eeb21c [app] [I] Completed 200 OK in 987ms (Views: 874.0ms | ActiveRecord: 16.0ms) 2017-03-17T15:13:53 23eeb21c [app] [D] 2017-03-17T15:13:53 23eeb21c [app] [D] Notice the processing has not the '[user:skoroadmin]' prefix, and the same would apply for params. Would this format of log be sufficient?
```
2016-11-22 17:45:48 23eeb21c [app] [I] Parameters: {"utf8"=>"✓", "authenticity_token"=>"5fRSfJOibo8zREKH9Lfuft7Em2j53za777mxlCHrdbU=", "job_invocation"=>{"job_category"=>"Commands", "providers"=>{"SSH"=>{"job_template_id"=>"94", "job_templates"=>{"94"=>{"input_values"=>"[FILTERED]", "effective_user"=>""}, "125"=>{"input_values"=>"[FILTERED]", "effective_user"=>""}}}}, "description"=>"Run uptime", "description_override"=>"Run %{command}", "description_format"=>"Run %{command}", "concurrency_level"=>"", "time_span"=>""}, "targeting"=>{"bookmark_id"=>"", "search_query"=>"name = test1.example.com", "targeting_type"=>"static_query"}, "triggering"=>{"mode"=>"immediate", "start_at_raw"=>"2016-11-22 17:45", "start_before_raw"=>"", "input_type"=>"daily", "cronline"=>"", "days"=>"", "days_of_week"=>{"1"=>"0", "2"=>"0", "3"=>"0", "4"=>"0", "5"=>"0", "6"=>"0", "7"=>"0"}, "time"=>{"time(1i)"=>"2016", "time(2i)"=>"11", "time(3i)"=>"22", "time(4i)"=>"17", "time(5i)"=>"45"}, "max_iteration"=>"", "end_time_limited"=>"false", "end_time"=>{"end_time(3i)"=>"22", "end_time(2i)"=>"11", "end_time(1i)"=>"2016", "end_time(4i)"=>"17", "end_time(5i)"=>"45"}}, "commit"=>"Submit", "login" => "admin"}
2017-03-17T15:13:50 23eeb21c [app] [I] Current user: skoroadmin (regular user)
```
It doesn't seem to be feasible to get this information on one line, but the info can be grouped together by the session id (23eeb21c)
Moving this bug to POST for triage into Satellite 6 since the upstream issue http://projects.theforeman.org/issues/18949 has been resolved. Got the answer off this channel. As I understand correctly, having the user at the same line as Parameters are mentioned would be better, but the framework we are using and the lifecycle of handling a request doesn't allow us to do this short term (long term, there should be more work spend on better auditing facilities that would support this case better). The change to add info about current user into logging got merged upstream 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/RHSA-2018:0336 |
Description of problem: Customer is running Satellite 6.2 and would like to enable remote execution. However, customer wants to audit remote execution activity and needs to see this in a logfile somewhere. They need to see: - Who ran a remote execution job - What action they ran - Where they ran it - which target hosts /var/log/foreman/production.log shows what was ran and where it was run but it doesn't show who ran the job. Version-Release number of selected component (if applicable): Satellite 6.2.x How reproducible: 100% Steps to Reproduce: Execute any remote job and see the details being logged in to the production.log Actual results: Example from my test satellite instance shows the what and where but not the user (Run Uptime on test1.example.com) 2016-11-22 17:45:48 [app] [I] Parameters: {"utf8"=>"✓", "authenticity_token"=>"5fRSfJOibo8zREKH9Lfuft7Em2j53za777mxlCHrdbU=", "job_invocation"=>{"job_category"=>"Commands", "providers"=>{"SSH"=>{"job_template_id"=>"94", "job_templates"=>{"94"=>{"input_values"=>"[FILTERED]", "effective_user"=>""}, "125"=>{"input_values"=>"[FILTERED]", "effective_user"=>""}}}}, "description"=>"Run uptime", "description_override"=>"Run %{command}", "description_format"=>"Run %{command}", "concurrency_level"=>"", "time_span"=>""}, "targeting"=>{"bookmark_id"=>"", "search_query"=>"name = test1.example.com", "targeting_type"=>"static_query"}, "triggering"=>{"mode"=>"immediate", "start_at_raw"=>"2016-11-22 17:45", "start_before_raw"=>"", "input_type"=>"daily", "cronline"=>"", "days"=>"", "days_of_week"=>{"1"=>"0", "2"=>"0", "3"=>"0", "4"=>"0", "5"=>"0", "6"=>"0", "7"=>"0"}, "time"=>{"time(1i)"=>"2016", "time(2i)"=>"11", "time(3i)"=>"22", "time(4i)"=>"17", "time(5i)"=>"45"}, "max_iteration"=>"", "end_time_limited"=>"false", "end_time"=>{"end_time(3i)"=>"22", "end_time(2i)"=>"11", "end_time(1i)"=>"2016", "end_time(4i)"=>"17", "end_time(5i)"=>"45"}}, "commit"=>"Submit"} Expected results: Username which triggered remote execution job should be logged in to production.log There is an API call which can be used to retrieve info about remote execution job. It contains user_id field: ]# curl -H 'Content-Type: application/json' -k -u admin:xxx https://$(hostname -f)/api/v2/job_invocations/50 | json_reformat % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 100 675 0 675 0 0 1204 0 --:--:-- --:--:-- --:--:-- 1205 { "id": 50, "description": "Run ping google.com", "job_category": "Commands", "targeting_id": 50, "status": 1, "start_at": "2017-01-06 13:40:32 UTC", "status_label": "failed", "dynflow_task": { "id": "04efbb0f-9ff9-463c-8c29-7efc24f7b1a3", "state": "stopped" }, "succeeded": 0, "failed": 1, "pending": 0, "total": 1, "targeting": { "bookmark_id": null, "search_query": "name = mdekan-test2.sysmgmt.lan", "targeting_type": "static_query", "user_id": 3, "hosts": [ { "name": "mdekan-test2.sysmgmt.lan", "id": 169 } ] }, "template_invocations": [ { "template_id": 96, "template_name": "Run Command - SSH Default", "template_invocation_input_values": [ { "template_input_name": "command", "template_input_id": 7, "value": "ping google.com" } ] } ] } To get username for user_id 3 and check Login field: # hammer user info --id 3 Id: 3 Login: admin Name: Admin User Email: root Admin: yes Authorized by: Internal Locale: en Timezone: Last login: 2017/01/11 08:31:08 Default organization: Default Organization Default location: Default Location Roles: Anonymous User groups: snemeth_and_pals Locations: Default Location Organizations: Default Organization Created at: 2016/02/25 17:52:12 Updated at: 2017/01/11 08:31:08 Or API call # curl -H 'Content-Type: application/json' -k -u admin:xxx https://$(hostname -f)/api/v2/users/3 | json_reformat We could use either # hammer user info --id X or # curl -H 'Content-Type: application/json' -k -u admin:xxx https://$(hostname -f)/api/v2/users/X | json_reformat to add login field into parameters for the remote execution job to have the information which user was used to execute the remote job: 2016-11-22 17:45:48 [app] [I] Parameters: {"utf8"=>"✓", "authenticity_token"=>"5fRSfJOibo8zREKH9Lfuft7Em2j53za777mxlCHrdbU=", "job_invocation"=>{"job_category"=>"Commands", "providers"=>{"SSH"=>{"job_template_id"=>"94", "job_templates"=>{"94"=>{"input_values"=>"[FILTERED]", "effective_user"=>""}, "125"=>{"input_values"=>"[FILTERED]", "effective_user"=>""}}}}, "description"=>"Run uptime", "description_override"=>"Run %{command}", "description_format"=>"Run %{command}", "concurrency_level"=>"", "time_span"=>""}, "targeting"=>{"bookmark_id"=>"", "search_query"=>"name = test1.example.com", "targeting_type"=>"static_query"}, "triggering"=>{"mode"=>"immediate", "start_at_raw"=>"2016-11-22 17:45", "start_before_raw"=>"", "input_type"=>"daily", "cronline"=>"", "days"=>"", "days_of_week"=>{"1"=>"0", "2"=>"0", "3"=>"0", "4"=>"0", "5"=>"0", "6"=>"0", "7"=>"0"}, "time"=>{"time(1i)"=>"2016", "time(2i)"=>"11", "time(3i)"=>"22", "time(4i)"=>"17", "time(5i)"=>"45"}, "max_iteration"=>"", "end_time_limited"=>"false", "end_time"=>{"end_time(3i)"=>"22", "end_time(2i)"=>"11", "end_time(1i)"=>"2016", "end_time(4i)"=>"17", "end_time(5i)"=>"45"}}, "commit"=>"Submit", "login" => "admin"}