Bug 1845489

Summary: Audit page shows "auditable id / Host2" for "Host1" but Host2 does not exist or deleted from the all hosts
Product: Red Hat Satellite Reporter: Ranjan Kumar <rankumar>
Component: Audit LogAssignee: Shimon Shtein <sshtein>
Status: CLOSED ERRATA QA Contact: Peter Ondrejka <pondrejk>
Severity: high Docs Contact:
Priority: high    
Version: 6.10.4CC: alfvega, arivera, aruzicka, casl, dezw, inecas, jbhatia, orabin
Target Milestone: 6.13.0Keywords: Triaged
Target Release: UnusedFlags: orabin: needinfo-
Hardware: All   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2023-05-03 13:20:33 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:
Attachments:
Description Flags
Web UI screenshot none

Description Ranjan Kumar 2020-06-09 11:27:18 UTC
Description of problem:  Go to "Monitor"->"Audits", and search for "host = host1.example.com". Few audit entry list of the host contains the auditable id / host2.example.com.

Here host2.example.com does not exist and according to the customer it is deleted.

This result creates confusion
1. While searching for host1 it gives references for host2
2. Even if above records are correct. There is should tooltip to explain why the host2 reference is coming up and what happened to host2.

Screenshot attached.

Version-Release number of selected component (if applicable): Satellite 6.6


How reproducible: Not Reproducible


Additional info:
# hammer audit list --search="host=host1.example.com"
-------|---------------------|----------------|-------------------|--------|------------|---------------
ID     | AT                  | IP             | USER              | ACTION | AUDIT TYPE | AUDIT RECORD
-------|---------------------|----------------|-------------------|--------|------------|---------------
208294 | 2020/05/14 12:52:30 | ip1            | foreman_admin     | update | Host::Base | 1580         <-- The UI shows this records 
208071 | 2020/05/13 06:02:16 |                | foreman_admin     | update | Host::Base | 1580             as 1580 / host2.example.com
207678 | 2020/05/12 19:41:58 |                | foreman_admin     | update | Host::Base | 1580
207374 | 2020/05/11 14:03:29 |                | foreman_admin     | update | Host::Base | 1580
207370 | 2020/05/11 13:57:21 |                | foreman_admin     | update | Host::Base | 1580
207359 | 2020/05/11 13:56:24 | ip2            | foreman_admin     | update | Host::Base | 1580
207358 | 2020/05/11 13:56:20 | ip3            | user              | create | Host::Base | 1580
198460 | 2020/02/14 10:23:12 | IP             | foreman_api_admin | update | Host::Base | host1.example.com
198451 | 2020/02/14 10:19:17 | ip             | foreman_admin     | update | Host::Base | host1.example.com
198447 | 2020/02/14 10:19:04 | ip             | reguser           | create | Host::Base | host1.example.com
188766 | 2019/11/05 16:29:57 |                | foreman_admin     | update | Host::Base | 1580
-------|---------------------|----------------|-------------------|--------|------------|---------------

 cat << FIX | foreman-rake console
>   a = Audit.find_by_id 208294
>   a.associated
>   a = Audit.find_by_id 207370
>   a.associated
>   a = Audit.find_by_id 208071
>   a.associated
>   a = Audit.find_by_id 207359
>   a.associated
>   a = Audit.find_by_id 207358
>   a.associated
>   a = Audit.find_by_id 188766
>   a.associated
> FIX
Loading production environment (Rails 5.2.1)
Switch to inspect mode.
  a = Audit.find_by_id 208294
#<Audited::Audit id: 208294, auditable_id: 1580, auditable_type: "Host::Base", user_id: 1, user_type: nil, username: "Anonymous Admin", action: "update", audited_changes: {"uuid"=>["33a48bca-1f4d-400f-899f-da7a9a186854", nil]}, version: 11, comment: nil, associated_id: 1652, associated_type: "Host::Base", request_uuid: "fbe777e3-9c3c-4e82-ba4f-880eca169328", created_at: "2020-05-14 18:52:30", remote_address: "ip", auditable_name: "1580", associated_name: "host2.example.com">
  a.associated
nil
  a = Audit.find_by_id 207370
#<Audited::Audit id: 207370, auditable_id: 1580, auditable_type: "Host::Base", user_id: 1, user_type: nil, username: "Anonymous Admin", action: "update", audited_changes: {"installable_security_errata_count"=>[0, 36], "installable_enhancement_errata_count"=>[0, 8], "installable_bugfix_errata_count"=>[0, 106], "applicable_rpm_count"=>[0, 432], "upgradable_rpm_count"=>[0, 432]}, version: 7, comment: nil, associated_id: 1652, associated_type: "Host::Base", request_uuid: "ce1dc204-7c8a-45ee-9659-442c5a45fe14", created_at: "2020-05-11 19:57:21", remote_address: nil, auditable_name: "1580", associated_name: "host2.example.com">
  a.associated
nil
  a = Audit.find_by_id 208071
#<Audited::Audit id: 208071, auditable_id: 1580, auditable_type: "Host::Base", user_id: 1, user_type: nil, username: "Anonymous Admin", action: "update", audited_changes: {"installable_security_errata_count"=>[1, 0], "installable_bugfix_errata_count"=>[12, 0], "applicable_rpm_count"=>[58, 0], "upgradable_rpm_count"=>[58, 0]}, version: 10, comment: nil, associated_id: 1652, associated_type: "Host::Base", request_uuid: "1d565380-11c7-4de0-a3d1-1712a5358a06", created_at: "2020-05-13 12:02:16", remote_address: nil, auditable_name: "1580", associated_name: "host2.example.com">
  a.associated
nil
  a = Audit.find_by_id 207359
#<Audited::Audit id: 207359, auditable_id: 1580, auditable_type: "Host::Base", user_id: 1, user_type: nil, username: "Anonymous Admin", action: "update", audited_changes: {"uuid"=>[nil, "33a48bca-1f4d-400f-899f-da7a9a186854"]}, version: 6, comment: nil, associated_id: 1652, associated_type: "Host::Base", request_uuid: "1753c0d4-6121-4893-a138-c9802b4993f1", created_at: "2020-05-11 19:56:24", remote_address: "ip", auditable_name: "1580", associated_name: "host2.example.com">
  a.associated
nil
  a = Audit.find_by_id 207358
#<Audited::Audit id: 207358, auditable_id: 1580, auditable_type: "Host::Base", user_id: 26, user_type: nil, username: "user", action: "create", audited_changes: {"host_id"=>1652, "uuid"=>nil, "content_view_id"=>2, "lifecycle_environment_id"=>2, "kickstart_repository_id"=>nil, "content_source_id"=>1, "installable_security_errata_count"=>0, "installable_enhancement_errata_count"=>0, "installable_bugfix_errata_count"=>0, "applicable_rpm_count"=>0, "upgradable_rpm_count"=>0, "applicable_module_stream_count"=>0, "upgradable_module_stream_count"=>0}, version: 5, comment: nil, associated_id: 1652, associated_type: "Host::Base", request_uuid: "xxx", created_at: "2020-05-11 19:56:20", remote_address: "ip", auditable_name: "1580", associated_name: "host2.example.com">
  a.associated
nil
  a = Audit.find_by_id 188766
#<Audited::Audit id: 188766, auditable_id: 1580, auditable_type: "Host::Base", user_id: 1, user_type: nil, username: "Anonymous Admin", action: "update", audited_changes: {"purpose_role"=>[nil, ""], "purpose_usage"=>[nil, ""]}, version: 1, comment: nil, associated_id: 1502, associated_type: "Host::Base", request_uuid: "93db7d35-2dcc-49d9-ae64-dfe876a99de6", created_at: "2019-11-05 23:29:57", remote_address: nil, auditable_name: "1580", associated_name: "host3.example.com">
  a.associated
#<Host::Managed id: 1502, name: "host3.example.com", last_compile: "2020-05-24 23:03:29", last_report: "2020-05-27 17:54:47", updated_at: "2020-05-27 17:54:52", created_at: "2019-09-23 19:17:22", root_pass: nil, architecture_id: 1, operatingsystem_id: 1, environment_id: 2, ptable_id: nil, medium_id: nil, build: false, comment: nil, disk: nil, installed_at: nil, model_id: 1, hostgroup_id: 9, owner_id: 34, owner_type: "User", enabled: true, puppet_ca_proxy_id: 1, managed: true, use_image: nil, image_file: nil, uuid: nil, compute_resource_id: nil, puppet_proxy_id: 1, certname: "xxx", image_id: nil, organization_id: 3, location_id: 4, type: "Host::Managed", otp: nil, realm_id: nil, compute_profile_id: nil, provision_method: nil, grub_pass: "", global_status: 0, lookup_value_matcher: "fqdn=host3.example.com", discovery_rule_id: nil, openscap_proxy_id: nil, pxe_loader: nil, initiated_at: nil, build_errors: nil>

Comment 3 Charles Slivkoff 2022-01-12 20:58:17 UTC
This appears to still be an issue with Satellite 6.9.  

The "off-by-one" error in the returned entries does not occur for all entries, but by my observations of my satellite with ~1200 content hosts, I would estimate it at about 50%.

Comment 4 Charles Slivkoff 2022-02-17 16:45:36 UTC
Confirmed this is still occurring on 6.10.2

Comment 5 Charles Slivkoff 2022-02-17 16:52:11 UTC
Created attachment 1861731 [details]
Web UI screenshot

The searched value is NOT what is returned.

Comment 6 Charles Slivkoff 2022-02-17 18:49:08 UTC
Also, note that the result listed host DOES exist in the case that I provided.

Comment 7 arivera 2022-02-18 14:39:43 UTC
I can confirm this bug is present on Satellite 6.9.8 and Satellite 6.10.2.
I don't know why Red Hat considers an audit log bug a low priority issue. This problem has been lingering for a few versions now, fix it.

Comment 8 Charles Slivkoff 2022-04-19 22:50:34 UTC
Can someone please update the Version to reflect this still being an issue with 6.10.4?

This bug makes the audit of hosts unreliable and of no practical value.

Comment 10 Charles Slivkoff 2022-05-17 14:39:23 UTC
With the feature returning inconsistent and erroneous content, it can not be depended upon.

If this is not going to be fixed, then the feature should be disabled and removed from the product.

Comment 12 Charles Slivkoff 2022-05-20 13:02:01 UTC
After some investigation into the audits table, I found there were several rows which contained auditable_name entries that did not sync with that of the auditable_id.  

The values found in the auditable_name column for rows (where associated_type='Host::Base') are almost always strings matching the integer values in auditable_id.  

For a small set (23 rows from my DB using the below query), I found auditable_name strings that are host FQDNs, not strings matching the integers in auditable_id.  Most of these also are references to hosts which have been removed in the past 90 days (likely related to the weekly run of `foreman-rake audits:expire`).  

I used this query to return this data:

foreman=# select hosts.name,audits.auditable_name,hosts.id,auditable_id from hosts,audits where ( hosts.id=audits.auditable_id and audits.associated_type like 'Host::Base' ) order by auditable_name desc \g

Comment 13 Shimon Shtein 2022-06-29 13:54:13 UTC
Created redmine issue https://projects.theforeman.org/issues/35132 from this bug

Comment 14 Bryan Kearney 2022-06-29 16:02:07 UTC
Upstream bug assigned to sshtein

Comment 15 Bryan Kearney 2022-06-29 16:02:09 UTC
Upstream bug assigned to sshtein

Comment 17 Bryan Kearney 2022-08-02 08:02:07 UTC
Moving this bug to POST for triage into Satellite since the upstream issue https://projects.theforeman.org/issues/35132 has been resolved.

Comment 19 Peter Ondrejka 2023-01-16 10:27:14 UTC
Verified on Satellite 6.13 sn 6, the code changes are in, and I wasn't able to reproduce the original issue

Comment 22 errata-xmlrpc 2023-05-03 13:20:33 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 (Important: Satellite 6.13 Release), 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-2023:2097