Bug 1731861 - Uploading facts when host is in build mode does log error at info or higher
Summary: Uploading facts when host is in build mode does log error at info or higher
Alias: None
Product: Red Hat Satellite
Classification: Red Hat
Component: Provisioning
Version: 6.5.0
Hardware: Unspecified
OS: Unspecified
Target Milestone: 6.6.0
Assignee: Lukas Zapletal
QA Contact: Peter Dragun
Depends On:
Blocks: 1122832
TreeView+ depends on / blocked
Reported: 2019-07-22 08:45 UTC by Peter Vreman
Modified: 2019-10-22 19:50 UTC (History)
4 users (show)

Fixed In Version: foreman-
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Last Closed: 2019-10-22 19:50:18 UTC
Target Upstream Version:

Attachments (Terms of Use)

System ID Priority Status Summary Last Updated
Foreman Issue Tracker 27556 Normal Closed Uploading facts when host is in build mode does log error at info or higher 2020-03-27 23:34:11 UTC

Description Peter Vreman 2019-07-22 08:45:38 UTC
Description of problem:
I had a problem to get facts uploaded in satellite. The request was not completed, but there is no reason written what is wrong.

[crash/LI] root@li-lc-2224:~# grep 4403a209 /var/log/foreman/production.log
2019-07-22T08:18:04 [I|app|4403a209] Processing by Api::V2::HostsController#facts as JSON
2019-07-22T08:18:04 [I|app|4403a209]   Parameters: {"facts"=>"[FILTERED]", "name"=>"li-lc-1681.hag.hilti.com", "certname"=>"li-lc-1681.hag.hilti.com", "apiv"=>"v2", "host"=>{"certname"=>"li-lc-1681.hag.hilti.com", "name"=>"li-lc-1681.hag.hilti.com"}}
2019-07-22T08:18:04 [I|app|4403a209] Completed 422 Unprocessable Entity in 23ms (Views: 0.3ms | ActiveRecord: 3.2ms)

Only when i enabled debug logging i was able to find the root cause (the system was in build mode and then it is not allowed):
[crash/LI] root@li-lc-2224:~# grep 2fead00e /var/log/foreman/production.log
2019-07-22T08:22:46 [I|app|2fead00e] Processing by Api::V2::HostsController#facts as JSON
2019-07-22T08:22:46 [I|app|2fead00e]   Parameters: {"facts"=>"[FILTERED]", "name"=>"li-lc-1681.hag.hilti.com", "certname"=>"li-lc-1681.hag.hilti.com", "apiv"=>"v2", "host"=>{"certname"=>"li-lc-1681.hag.hilti.com", "name"=>"li-lc-1681.hag.hilti.com"}}
2019-07-22T08:22:46 [D|app|2fead00e] Importer Katello::RhsmFactImporter does not implement authorized_smart_proxy_features.
2019-07-22T08:22:46 [D|app|2fead00e] Examining client certificate to extract dn and sans
2019-07-22T08:22:46 [D|app|2fead00e] Client sent certificate with subject 'li-lc-2224.hag.hilti.com' and subject alt names '["li-lc-2224.hag.hilti.com", "fibssat6c.hag.hilti.com"]'
2019-07-22T08:22:46 [D|app|2fead00e] Verifying request from ["li-lc-2224.hag.hilti.com", "fibssat6c.hag.hilti.com"] against ["li-lc-2224.hag.hilti.com"]
2019-07-22T08:22:47 [D|app|2fead00e] Body: {"message":"ERF42-9911 [Foreman::Exception]: Host is pending for Build"}
2019-07-22T08:22:47 [I|app|2fead00e] Completed 422 Unprocessable Entity in 244ms (Views: 0.6ms | ActiveRecord: 34.7ms)

Requiring debug mode to see the reason for an error is not good. It should always write the error at least at level info when returning '422 Unprocessable Entity'

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

How reproducible:

Steps to Reproduce:
1. Set host to build=true
2. Upload facts
3. What the production.log at level INFO

Actual results:
No root cause why facts upload is failing

Expected results:
Root cause (host is in build mode) is written at least at level INFO

Additional info:

Comment 3 Peter Vreman 2019-07-22 09:34:20 UTC

--- controllers/api/v2/hosts_controller.rb.190722-1     2019-06-26 11:52:05.460091801 +0000
+++ controllers/api/v2/hosts_controller.rb      2019-07-22 09:18:28.300754718 +0000
@@ -289,6 +289,7 @@
         state = @host.import_facts(factshash, detected_proxy)
         process_response state
       rescue ::Foreman::Exception => e
+        logger.info("Facts processing failed: #{e.to_s}")
         render_message(e.to_s, :status => :unprocessable_entity)

Comment 5 Marek Hulan 2019-08-08 15:10:17 UTC
Created redmine issue https://projects.theforeman.org/issues/27556 from this bug

Comment 6 Bryan Kearney 2019-08-09 10:05:37 UTC
Upstream bug assigned to lzap@redhat.com

Comment 7 Bryan Kearney 2019-08-09 10:05:39 UTC
Upstream bug assigned to lzap@redhat.com

Comment 8 Bryan Kearney 2019-08-28 08:05:42 UTC
Moving this bug to POST for triage into Satellite 6 since the upstream issue https://projects.theforeman.org/issues/27556 has been resolved.

Comment 10 Peter Dragun 2019-09-18 12:53:58 UTC
Verified on Satellite 6.6 snap 20.1. Reason is now written at warning level.

2019-09-18T08:47:07 [W|app|e3967e5b] ERF42-9911 [Foreman::Exception]: Host is pending for Build

Comment 11 Bryan Kearney 2019-10-22 19:50:18 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.


Note You need to log in before you can comment on or make changes to this bug.