theforeman / foreman_hooks

Run custom hook scripts on Foreman events
http://m0dlx.com/blog/Extending_Foreman_quickly_with_hook_scripts.html
GNU General Public License v3.0
56 stars 50 forks source link

config_report hook generates log warning #56

Open wiad opened 6 years ago

wiad commented 6 years ago

I created a hook script for the 'config_report' object: config/hooks/config_report/after_create/10-test.sh

The hook script works (check report status and sends update to our monitoring system via REST api), but in the foreman log (production.log) I get a warning for every host:

2018-06-20 07:58:49 a742dbf8 [app] [W] Unable to render lxserv1330.example.com / 2018-06-20 07:58:21 UTC (ConfigReport) using RABL: Cannot find rabl template 'api/v2/configreports/show' within registered (["/usr/share/foreman/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_snapshot_management-1.1.0/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.4/app/views", "/usr/share/foreman/app/views"]) view paths!

I also noticed that the second argument to the hook script ($2), which should be hostname, in fact is: lxserv1330.example.com / 2018-06-20 07:58:21 UTC (for the host in the log output above)

which seems wrong to me. As I said, the script works, I get the config report json data correctly, but the warning messages in the log is worrying.

pruchai commented 6 years ago

Same issue here. Foreman 1.17.1 with foreman_hooks 0.3.14

wiad commented 4 years ago

Still getting these on 2.1.1, would be nice if it could be resolved since it clutters the log file.

lzap commented 4 years ago

Show me the whole transaction, grep request id e.g. a742dbf8

danoe commented 4 years ago

In my foreman 2.1.3 install:

tfm-rubygem-foreman_hooks-0.3.16-2.fm2_1.el7.noarch

I only have one hook script: config/hooks/config_report/after_create/10-slack_report.py

production.log:2020-10-19T14:39:32 [I|app|f7045cb2] Started POST "/api/config_reports" for 127.0.0.1 at 2020-10-19 14:39:32 -0700
production.log:2020-10-19T14:39:32 [I|app|f7045cb2] Processing by Api::V2::ConfigReportsController#create as JSON
production.log:2020-10-19T14:39:32 [I|app|f7045cb2]   Parameters: {"config_report"=>"[FILTERED]", "apiv"=>"v2"}
production.log:2020-10-19T14:39:32 [I|app|f7045cb2] Scanning report with: Foreman::PuppetReportScanner
production.log:2020-10-19T14:39:32 [W|app|f7045cb2] Unable to render     server01.fqdn / 2020-10-19 21:39:06 UTC (ConfigReport) using RABL: Cannot find rabl template 'api/v2/configreports/show' within registered (["/usr/share/foreman/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_templates-9.0.1/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-3.3.7/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/puppetdb_foreman-5.0.0/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_openscap-4.0.2/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_discovery-16.1.2/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/engines/bastion/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-2.0.2/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_docker-5.0.0/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-dsl-2.2.2/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.17/app/views", "/usr/share/foreman/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_discovery-16.1.2/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_templates-9.0.1/app/views"]) view paths!
production.log:2020-10-19T14:39:33 [I|app|f7045cb2] Imported report for     server01.fqdn in 678.0 ms, status refreshed in 23.5 ms
production.log:2020-10-19T14:39:33 [I|app|f7045cb2]   Rendering api/v2/config_reports/create.json.rabl
production.log:2020-10-19T14:39:33 [I|app|f7045cb2]   Rendered api/v2/config_reports/create.json.rabl (Duration: 25.4ms | Allocations: 14388)
production.log:2020-10-19T14:39:33 [I|app|f7045cb2] Completed 201 Created in 771ms (Views: 24.2ms | ActiveRecord: 84.0ms | Allocations: 233943)
lzap commented 4 years ago

@ehelms does this trigger something for you? I mean, we have just identified a similar problem (with the root node) and I am seeing the same warning here: "Unable to render server01.fqdn / 2020-10-19 21:39:06 UTC (ConfigReport) using RABL: Cannot find rabl template 'api/v2/configreports/show' within registered".

But why it tries to find "api/v2/configreports/show" and not "api/v2/config_report"? Also the show.json.rabl file is present and have never been missing. I don't understand. Eventually it finds it: "Rendered api/v2/config_reports/create.json.rabl".

Does this connect for you with anything you were researching while working on that root JSON issue the other day?

ehelms commented 4 years ago

The source of the problem is a chunk of Foreman hooks code. The code attempts to use the show RABL template as part of the rendering output and calculates what the path should be:

https://github.com/theforeman/foreman_hooks/blob/4fc1977e446bae65a42219c7dc8ff1ad10315313/lib/foreman_hooks/util.rb#L20

However, this is incorrectly calculating it and leads to the warning we see:

irb(main):007:0> "ConfigReport".downcase.tableize
=> "configreports"

There is no need to downcase the class name as tableize can handle this correctly as we can see:

irb(main):008:0> "ConfigReport".tableize
=> "config_reports"
lzap commented 4 years ago

Thank you! Could you guys file a PR and I will happily merge the fix for the problem @ehelms analyzed.

idl0r commented 2 years ago

This still happens in 3.2.x:

API controllers newer than Apipie cache! Run apipie:cache rake task to regenerate cache.
2022-05-20T10:05:49 [I|app|e1c36201] Started POST "/api/config_reports" for 192.168.110.114 at 2022-05-20 10:05:49 +0200
2022-05-20T10:05:49 [I|app|e1c36201] Processing by Api::V2::ConfigReportsController#create as JSON
2022-05-20T10:05:49 [I|app|e1c36201]   Parameters: {"config_report"=>"[FILTERED]", "apiv"=>"v2"}
2022-05-20T10:05:49 [I|app|e1c36201] Scanning report with: Foreman::PuppetReportScanner
2022-05-20T10:05:49 [W|app|e1c36201] Unable to render s002199.example.com / 2022-05-20 08:05:25 UTC (ConfigReport) using RABL: Cannot find rabl template 'api/v2/configreports/show' within registered (["/usr/share/foreman/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_dhcp_browser-0.0.8/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/puppetdb_foreman-5.0.0/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_puppet-3.0.6/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-6.0.1/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-dsl-2.4.0/app/views", "/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.17/app/views", "/usr/share/foreman/app/views"]) view paths!
2022-05-20T10:05:49 [I|app|e1c36201] Imported report for s002199.example.com in 150.4 ms, status refreshed in 59.6 ms
2022-05-20T10:05:49 [I|app|e1c36201]   Rendering api/v2/config_reports/create.json.rabl
2022-05-20T10:05:49 [I|app|e1c36201]   Rendered api/v2/config_reports/create.json.rabl (Duration: 4.4ms | Allocations: 5861)
2022-05-20T10:05:49 [I|app|e1c36201] Completed 201 Created in 242ms (Views: 5.5ms | ActiveRecord: 112.1ms | Allocations: 29757)

Foreman version: 3.2.0
Plugins: 
 - foreman-tasks 6.0.1
 - foreman_column_view 0.4.0
 - foreman_dhcp_browser 0.0.8
 - foreman_hooks 0.3.17
 - foreman_puppet 3.0.6
 - puppetdb_foreman 5.0.0

The problem here seems to be triggered somehwere in https://github.com/theforeman/foreman/blob/9c94e1a062c9356cda0ee313ec867af1c9b7c31e/app/services/report_importer.rb#L164 Not sure how it is related to the hooks.