OpenSCAP Error 500 uploading completed report

Problem:
Foreman install without Katello on CentOS 7 together with OpenSCAP plugin/proxy. Running a scan completes successfully, report makes it from client to proxy but error received on report upload "Report not uploaded from proxy to Foreman server, cause: Failed to upload to Foreman, saving in spool. Failed with: 500 “Internal Server Error”.

Could use some pointers on what log files might assist tracking this down, nothing of note seen in /var/log/foreman/production.log or /var/log/foreman-proxy. Maybe I dont have the right debug values.

Policies configured correctly with SCAP content. Data accessible and downloaded correctly by client during puppet run together with configuration files.

Previous class configuration issues from here OpenSCAP plugin / puppet classes, what am I doing wrong or missing? overcome by “puppet module install” instead of rpm as described. Docs scrutinised accordingly and I belive all configured OK, classes show up correctly, can allocate to host group with settings etc and config files are propagated correctly to clients.

Report makes it from remote client to Foreman server but not ingested, kicked out to /var/spool/foreman-proxy/arf//… instead.

Seen previous issue on “Error 500” with a workaround of creating a second organisation and location, this does not appear to work in this instance.

For me, a little confused from OpenSCAP document but I feel I have the correct configuration. Most of the documentation refers to using the Katello proxy and port (9090) which utilises the Katello consumer certs not puppet certs. As Katello isnt in use I believe the cert chains utilised would be from the Puppet CA which I think are configured correctly. I understand the correct proxy port to use without Katello would be 8443 (tried the puppet proxy port 8140, didnt work)

Example version is 2.1, this behaviour seems to display on 2.0 as well.

Expected outcome:
I believe that the Foreman server should successfully process the report, ingest accordingly and present for viewing in the console.

Foreman and Proxy versions:

rpm -qa | grep foreman | sort

foreman-2.1.0-0.22.rc3.el7.noarch
foreman-cli-2.1.0-0.22.rc3.el7.noarch
foreman-client-release-2.1.0-0.4.rc3.el7.noarch
foreman-debug-2.1.0-0.22.rc3.el7.noarch
foreman-dynflow-sidekiq-2.1.0-0.22.rc3.el7.noarch
foreman-installer-2.1.0-0.3.rc3.el7.noarch
foreman-postgresql-2.1.0-0.22.rc3.el7.noarch
foreman-proxy-2.1.0-0.2.rc3.el7.noarch
foreman-release-2.1.0-0.4.rc3.el7.noarch
foreman-release-scl-7-3.el7.noarch
foreman-selinux-2.1.0-0.2.rc3.el7.noarch
foreman-service-2.1.0-0.22.rc3.el7.noarch
foreman-vmware-2.1.0-0.22.rc3.el7.noarch
puppet-foreman_scap_client-0.4.0-1.el7.noarch
rubygem-foreman_maintain-0.6.5-1.el7.noarch
rubygem-foreman_scap_client-0.4.6-2.el7.noarch
tfm-rubygem-foreman_fog_proxmox-0.10.2-1.fm2_1.el7.noarch
tfm-rubygem-foreman_openscap-3.0.0-1.fm2_1.el7.noarch
tfm-rubygem-foreman_remote_execution-3.3.2-1.fm2_1.el7.noarch
tfm-rubygem-foreman_remote_execution_core-1.3.0-1.el7.noarch
tfm-rubygem-foreman-tasks-2.0.1-1.fm2_1.el7.noarch
tfm-rubygem-foreman-tasks-core-0.3.4-1.fm2_1.el7.noarch
tfm-rubygem-hammer_cli_foreman-2.1.1-1.el7.noarch

rpm -qa | grep scap | sort

openscap-1.2.17-9.el7.x86_64
openscap-scanner-1.2.17-9.el7.x86_64
perl-Pod-Escapes-1.04-295.el7.noarch
puppet-foreman_scap_client-0.4.0-1.el7.noarch
rubygem-foreman_scap_client-0.4.6-2.el7.noarch
scap-security-guide-0.1.46-11.el7.centos.noarch
tfm-rubygem-foreman_openscap-3.0.0-1.fm2_1.el7.noarch
tfm-rubygem-openscap-0.4.9-3.el7.noarch
tfm-rubygem-smart_proxy_openscap-0.7.2-6.fm2_1.el7.noarch

Distribution and version:
CentOS 7.8.2003

Other relevant data:

foreman_scap_client classes overrides applied as follows:

fetch remote resources = true
port = 8443
server = <myforemanserver.fqdn>

Generated /etc/foreman_scap_client/config.yml on example client.

DO NOT EDIT THIS FILE MANUALLY

IT IS MANAGED BY PUPPET

Foreman proxy to which reports should be uploaded

:server: ‘myforemanserver.fqdn’
:port: 8443

Timeout for sending reports to proxy

:timeout: 60

Should --fetch-remote-resources be added to oscap xccdf eval command

:fetch_remote_resources: true

HTTP proxy server for downloading remote resources

:http_proxy_server:
:http_proxy_port:

SSL specific options

Client CA file.

It could be Puppet CA certificate (e.g., ‘/var/lib/puppet/ssl/certs/ca.pem’)

Or (recommended for client reporting to Katello) subscription manager CA file, (e.g., ‘/etc/rhsm/ca/katello-server-ca.pem’)

:ca_file: ‘/etc/puppetlabs/puppet/ssl/certs/ca.pem’

Client host certificate.

It could be Puppet agent host certificate (e.g., ‘/var/lib/puppet/ssl/certs/myhost.example.com.pem’)

Or (recommended for client reporting to Katello) consumer certificate (e.g., ‘/etc/pki/consumer/cert.pem’)

:host_certificate: ‘/etc/puppetlabs/puppet/ssl/certs/.pem’

Client private key

It could be Puppet agent private key (e.g., ‘/var/lib/puppet/ssl/private_keys/myhost.example.com.pem’)

Or (recommended for client reporting to Katello) consumer private key (e.g., ‘/etc/pki/consumer/key.pem’)

:host_private_key: ‘/etc/puppetlabs/puppet/ssl/private_keys/.pem’

policy (key is id as in Foreman)

1:
:profile: ‘xccdf_org.ssgproject.content_profile_standard’
:content_path: ‘/var/lib/openscap/content/3e1654fd14a5352d65294db555710bfda5cad1a942209e2d787ea7940035616e.xml’

Download path

A path to download SCAP content from proxy

:download_path: ‘/compliance/policies/1/content/3e1654fd14a5352d65294db555710bfda5cad1a942209e2d787ea7940035616e’
:tailoring_path: ‘’
:tailoring_download_path: ‘’

Entry found in production.log after much searching:
Grateful for any suggestions as to whats occuring; maybe I’m missing an important variable not set or maybe proxy entry wrong, not sure all I know is its not 9090 as I don’t have Katello deployed.

2020-07-02T04:42:41 [I|app|bac63ba5] Started POST “/api/v2/compliance/arf_reports/<myforemanserver.fqdn>/1/1593664957” for 127.0.0.1 at 2020-07-02 04:42:41 +0000
2020-07-02T04:42:41 [I|app|bac63ba5] Processing by Api::V2::Compliance::ArfReportsController#create as JSON
2020-07-02T04:42:41 [I|app|bac63ba5] Parameters: {“logs”=>"[FILTERED]", “digest”=>“c066644ce88aa912dc7d8c0ae05b0cb522881856afaddf278e6628bbb404e73f”, “metrics”=>{“passed”=>42, “failed”=>9, “othered”=>0}, “openscap_proxy_name”=>"<myforemanserver.fqdn>", “openscap_proxy_url”=>“https://<myforemanserver.fqdn>:8443”, “apiv”=>“v2”, “cname”=>"<myforemanserver.fqdn>", “policy_id”=>“1”, “date”=>“1593664957”, “arf_report”=>{“logs”=>"[FILTERED]", “digest”=>“c066644ce88aa912dc7d8c0ae05b0cb522881856afaddf278e6628bbb404e73f”, “metrics”=>{“passed”=>42, “failed”=>9, “othered”=>0}, “openscap_proxy_name”=>"<myforemanserver.fqdn>", “openscap_proxy_url”=>“https://<myforemanserver.fqdn>:8443”}}
2020-07-02T04:42:42 [W|app|bac63ba5] Action failed
2020-07-02T04:42:42 [I|app|bac63ba5] Rendering api/v2/errors/standard_error.json.rabl within api/v2/layouts/error_layout
2020-07-02T04:42:42 [I|app|bac63ba5] Rendered api/v2/errors/standard_error.json.rabl within api/v2/layouts/error_layout (Duration: 5.2ms | Allocations: 5810)
2020-07-02T04:42:42 [I|app|bac63ba5] Completed 500 Internal Server Error in 269ms (Views: 9.2ms | ActiveRecord: 7.8ms | Allocations: 242770)

Also found this nugget in /var/mail/foreman-proxy, originating from cron job that I believe is supposed to resubmit data in /var/spool/foreman-proxy/openscap.

seems to elicit a more descriptive error unsure as to cause or again whether I’m missing a required setting

From foreman-proxy@myforemanserver.fqdn Thu Jul 2 04:30:01 2020
Return-Path: foreman-proxy@myforemanserver.fqdn
X-Original-To: foreman-proxy
Delivered-To: foreman-proxy@myforemanserver.fqdn
Received: by myforemanserver.fqdn (Postfix, from userid 995)
id 4ED2E300078CF; Thu, 2 Jul 2020 04:30:01 +0000 (UTC)
From: “(Cron Daemon)” foreman-proxy@myforemanserver.fqdn
To: foreman-proxy@myforemanserver.fqdn
Subject: Cron foreman-proxy@myforemanserver smart-proxy-openscap-send >> /var/log/foreman-proxy/cron.log
Content-Type: text/plain; charset=UTF-8
Auto-Submitted: auto-generated
Precedence: bulk
X-Cron-Env: <XDG_SESSION_ID=c683>
X-Cron-Env: <XDG_RUNTIME_DIR=/run/user/995>
X-Cron-Env: <LANG=en_GB.UTF-8>
X-Cron-Env: <SHELL=/bin/sh>
X-Cron-Env: <HOME=/usr/share/foreman-proxy>
X-Cron-Env: <PATH=/usr/bin:/bin>
X-Cron-Env: <LOGNAME=foreman-proxy>
X-Cron-Env: <USER=foreman-proxy>
Message-Id: 20200702043001.4ED2E300078CF@myforemanserver.fqdn
Date: Thu, 2 Jul 2020 04:30:01 +0000 (UTC)

/usr/share/rubygems/rubygems/core_ext/kernel_require.rb:55:in require': /usr/share/foreman-proxy/lib/launcher.rb:81: syntax error, unexpected '.' (SyntaxError) Proxy::SETTINGS.tls_disabled_versions&.each do |version| ^ from /usr/share/rubygems/rubygems/core_ext/kernel_require.rb:55:in require’
from /usr/share/foreman-proxy/lib/smart_proxy_main.rb:4:in <top (required)>' from /usr/share/rubygems/rubygems/core_ext/kernel_require.rb:55:in require’
from /usr/share/rubygems/rubygems/core_ext/kernel_require.rb:55:in require' from /usr/bin/smart-proxy-openscap-send:16:in

Can you please change logging level to debug on foreman (see Foreman :: Manual) and try uploading the report again? looks like there is a stack trace that is being swallowed in the logs, which might give us more information on the actual root cause.

Hello,
Thanks for reading and thank you for the pointers on setting logging level, I had not seen that for looking!

production.log on foreman server from report submission time to Error 500 follows. Currently building an identical server with generic names for testing so I dont have to obfuscate a fqdn, although I believe the cert construct and all dns records are correct.

I would suppose the crux of it is the reported duplicate key violation but I would not currently have the knowledge to understand what this means.

2020-07-02T14:22:06 [I|app|087285b5] Started POST "/api/v2/compliance/arf_reports/myclient.fqdn/1/1593699722" for 127.0.0.1 at 2020-07-02 14:22:06 +0000
2020-07-02T14:22:06 [I|app|087285b5] Processing by Api::V2::Compliance::ArfReportsController#create as JSON
2020-07-02T14:22:06 [I|app|087285b5]   Parameters: {"logs"=>"[FILTERED]", "digest"=>"e00abea836445dd1a57a6fb9f0c41e6902a91611a39c38e5c202f39b85b83673", "metrics"=>{"passed"=>42, "failed"=>9, "othered"=>0}, "openscap_proxy_name"=>"myforemanserver.fqdn", "openscap_proxy_url"=>"https://myforemanserver.fqdn:8443", "apiv"=>"v2", "cname"=>"myclient.fqdn", "policy_id"=>"1", "date"=>"1593699722", "arf_report"=>{"logs"=>"[FILTERED]", "digest"=>"e00abea836445dd1a57a6fb9f0c41e6902a91611a39c38e5c202f39b85b83673", "metrics"=>{"passed"=>42, "failed"=>9, "othered"=>0}, "openscap_proxy_name"=>"myforemanserver.fqdn", "openscap_proxy_url"=>"https://myforemanserver.fqdn:8443"}}
2020-07-02T14:22:06 [D|app|087285b5] Client sent certificate with subject 'myforemanserver.fqdn' and subject alt names '["puppet", "myforemanserver.fqdn"]'
2020-07-02T14:22:06 [D|app|087285b5] CN and SANs were extracted from a client certificate.
2020-07-02T14:22:06 [D|app|087285b5] Verifying request from ["puppet", "myforemanserver.fqdn"] against ["myforemanserver.fqdn"]
2020-07-02T14:22:06 [W|app|087285b5] Action failed
2020-07-02T14:22:06 [D|app|087285b5] Backtrace for 'Action failed' error (ActiveRecord::RecordNotUnique): PG::UniqueViolation: ERROR:  duplicate key value violates unique constraint "index_scaptimony_asset_policies_on_asset_id_and_policy_id"
DETAIL:  Key (asset_id, policy_id)=(9, 1) already exists.

/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/postgresql_adapter.rb:675:in `async_exec_params'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/postgresql_adapter.rb:675:in `block (2 levels) in exec_no_cache'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/dependencies/interlock.rb:48:in `block in permit_concurrent_loads'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/dependencies/interlock.rb:47:in `permit_concurrent_loads'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/postgresql_adapter.rb:674:in `block in exec_no_cache'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract_adapter.rb:722:in `block (2 levels) in log'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract_adapter.rb:721:in `block in log'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract_adapter.rb:712:in `log'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/postgresql_adapter.rb:673:in `exec_no_cache'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/postgresql_adapter.rb:656:in `execute_and_clear'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/postgresql/database_statements.rb:98:in `exec_query'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/database_statements.rb:135:in `exec_insert'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/postgresql/database_statements.rb:132:in `exec_insert'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/database_statements.rb:166:in `insert'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/query_cache.rb:22:in `insert'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/persistence.rb:375:in `_insert_record'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/persistence.rb:932:in `_create_record'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/counter_cache.rb:166:in `_create_record'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/locking/optimistic.rb:70:in `_create_record'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/attribute_methods/dirty.rb:211:in `_create_record'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/callbacks.rb:331:in `block in _create_record'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:101:in `run_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:825:in `_run_create_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/callbacks.rb:331:in `_create_record'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/timestamp.rb:110:in `_create_record'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/persistence.rb:905:in `create_or_update'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/callbacks.rb:327:in `block in create_or_update'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:135:in `run_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:825:in `_run_save_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/callbacks.rb:327:in `create_or_update'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/timestamp.rb:128:in `create_or_update'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/persistence.rb:503:in `save!'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/validations.rb:53:in `save!'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/transactions.rb:318:in `block in save!'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/transactions.rb:375:in `block in with_transaction_returning_status'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/database_statements.rb:278:in `transaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/transactions.rb:212:in `transaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/transactions.rb:366:in `with_transaction_returning_status'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/transactions.rb:318:in `save!'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/suppressor.rb:48:in `save!'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/has_many_through_association.rb:77:in `save_through_record'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/has_many_through_association.rb:31:in `insert_record'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:426:in `block (2 levels) in concat_records'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:447:in `replace_on_target'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:285:in `add_to_target'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:424:in `block in concat_records'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:422:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:422:in `concat_records'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/has_many_association.rb:108:in `concat_records'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/has_many_through_association.rb:40:in `concat_records'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:120:in `block in concat'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:135:in `block in transaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/database_statements.rb:278:in `transaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/transactions.rb:212:in `transaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:134:in `transaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:120:in `concat'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/has_many_through_association.rb:21:in `concat'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:402:in `replace_records'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:253:in `block in replace'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:135:in `block in transaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/database_statements.rb:280:in `block in transaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/transaction.rb:280:in `block in within_new_transaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/transaction.rb:278:in `within_new_transaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/database_statements.rb:280:in `transaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/transactions.rb:212:in `transaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:134:in `transaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:253:in `replace'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:71:in `ids_writer'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/builder/collection_association.rb:65:in `policy_ids='
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_openscap-3.0.0/lib/foreman_openscap/helper.rb:5:in `get_asset'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_openscap-3.0.0/app/controllers/api/v2/compliance/arf_reports_controller.rb:98:in `find_resources_before_create'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:428:in `block in make_lambda'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:181:in `block (2 levels) in halting_and_conditional'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/abstract_controller/callbacks.rb:34:in `block (2 levels) in <module:Callbacks>'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:182:in `block in halting_and_conditional'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:513:in `block in invoke_before'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:513:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:513:in `invoke_before'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:110:in `block in run_callbacks'
/usr/share/foreman/app/controllers/api/v2/base_controller.rb:163:in `disable_json_root'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
/usr/share/foreman/app/controllers/concerns/foreman/controller/timezone.rb:10:in `set_timezone'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
/usr/share/foreman/app/controllers/concerns/foreman/controller/topbar_sweeper.rb:12:in `set_topbar_sweeper_controller'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/audited-4.9.0/lib/audited/sweeper.rb:14:in `around'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/audited-4.9.0/lib/audited/sweeper.rb:14:in `around'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:139:in `run_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/abstract_controller/callbacks.rb:41:in `process_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_controller/metal/rescue.rb:22:in `process_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_controller/metal/instrumentation.rb:33:in `block in process_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/notifications.rb:180:in `block in instrument'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/notifications.rb:180:in `instrument'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_controller/metal/instrumentation.rb:32:in `process_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_controller/metal/params_wrapper.rb:245:in `process_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/railties/controller_runtime.rb:27:in `process_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/abstract_controller/base.rb:136:in `process'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionview-6.0.3.1/lib/action_view/rendering.rb:39:in `process'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_controller/metal.rb:190:in `dispatch'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_controller/metal.rb:254:in `dispatch'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/routing/route_set.rb:50:in `dispatch'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/routing/route_set.rb:33:in `serve'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/routing/mapper.rb:18:in `block in <class:Constraints>'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/routing/mapper.rb:48:in `serve'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/journey/router.rb:49:in `block in serve'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/journey/router.rb:32:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/journey/router.rb:32:in `serve'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/routing/route_set.rb:834:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-dsl-2.2.2/lib/apipie_dsl/static_dispatcher.rb:67:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.17/lib/apipie/static_dispatcher.rb:66:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.17/lib/apipie/extractor/recorder.rb:137:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/static.rb:126:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/static.rb:126:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/static.rb:126:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/static.rb:126:in `call'
/usr/share/foreman/lib/foreman/middleware/telemetry.rb:10:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.17/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
/usr/share/foreman/lib/foreman/middleware/catch_json_parse_errors.rb:9:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.2/lib/rack/tempfile_reaper.rb:15:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.2/lib/rack/etag.rb:27:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.2/lib/rack/conditional_get.rb:40:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.2/lib/rack/head.rb:12:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/http/content_security_policy.rb:18:in `call'
/usr/share/foreman/lib/foreman/middleware/logging_context_session.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.2/lib/rack/session/abstract/id.rb:266:in `context'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.2/lib/rack/session/abstract/id.rb:260:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/cookies.rb:648:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:101:in `run_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/actionable_exceptions.rb:17:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/debug_exceptions.rb:32:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.1/lib/rails/rack/logger.rb:37:in `call_app'
/opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.1/lib/rails/rack/logger.rb:28:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/sprockets-rails-3.2.1/lib/sprockets/rails/quiet_assets.rb:13:in `call'
/usr/share/foreman/lib/foreman/middleware/logging_context_request.rb:11:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/request_id.rb:27:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.2/lib/rack/method_override.rb:24:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.2/lib/rack/runtime.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/executor.rb:14:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/static.rb:126:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.2/lib/rack/sendfile.rb:110:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/host_authorization.rb:76:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/secure_headers-6.3.0/lib/secure_headers/middleware.rb:11:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.1/lib/rails/engine.rb:527:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.1/lib/rails/railtie.rb:190:in `public_send'
/opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.1/lib/rails/railtie.rb:190:in `method_missing'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.2/lib/rack/urlmap.rb:74:in `block in call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.2/lib/rack/urlmap.rb:58:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.2/lib/rack/urlmap.rb:58:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/puma-4.3.3/lib/puma/configuration.rb:228:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/puma-4.3.3/lib/puma/server.rb:682:in `handle_request'
/opt/theforeman/tfm/root/usr/share/gems/gems/puma-4.3.3/lib/puma/server.rb:472:in `process_client'
/opt/theforeman/tfm/root/usr/share/gems/gems/puma-4.3.3/lib/puma/server.rb:328:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/puma-4.3.3/lib/puma/thread_pool.rb:134:in `block in spawn_thread'
/opt/theforeman/tfm/root/usr/share/gems/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2020-07-02T14:22:06 [I|app|087285b5]   Rendering api/v2/errors/standard_error.json.rabl within api/v2/layouts/error_layout
2020-07-02T14:22:06 [I|app|087285b5]   Rendered api/v2/errors/standard_error.json.rabl within api/v2/layouts/error_layout (Duration: 1.0ms | Allocations: 278)
2020-07-02T14:22:06 [I|app|087285b5] Completed 500 Internal Server Error in 183ms (Views: 4.8ms | ActiveRecord: 19.7ms | Allocations: 235602)

OK, really stupid question time, what tag did you use to format the log file better than I failed miserably to do? :grinning:

The preformatted text button, it’s the one that looks like “</>”. All you need to do is select the block of text and click that button (or manually indent with 4 spaces, but usually that requires more effort)

1 Like

The duplicate key violation is the reason why a report is not created, I’ll need to investigate why this is happening. Thank you for all the details.

1 Like

Excellent. To warn, please don’t rule out local configuration, eg me creating a policy, deleting, creating another one may have messed up any config…

Please let me know if you need further log files as with above guidance (grateful!) I can now a) set debug correctly b) format the log when pasting :grinning:

Thank you to all for the foreman!

2 Likes

Hello,
Wonder if I might enquire if any prelimiary findings or workaround discovered on this issue at all? To report, with a similar foreman-without-katello build this time on CentOS8, foreman version 2.1.0-1 the same symptoms occur, duplicate key entries in debug log.
Me = not a coder but happy to contribute funding to fix if applicable?
(original deleted significant mistype!)

2 Likes

Thanks for that!
For knowledge, would this be included in the nightly rpms so if I switched repo source to eg https://yum.theforeman.org/releases/nightly/el8/x86_64/ I could gain the fix and have at it?

Or could I simply overwrite the updated files

app/controllers/api/v2/compliance/arf_reports_controller.rb
lib/foreman_openscap/helper.rb

on my existing install and see it working?
Kindest regards

Either I’ve confused myself, I’m lacking some knowledge or missed something or I’m seeing it still not working quite correctly; I still get the error 500 report and the duplicate key entry in debug log. Entire install carried out on Centos8 minimal (no firewall, no selinux, /tmp not hardened with noexec) as follows. I separated the scap install as I received an error combining the whole lot, havent yet researched that. the below completes correctly.

yum install https://yum.puppet.com/puppet6-release-el-8.noarch.rpm
yum install https://yum.theforeman.org/releases/2.1/el8/x86_64/foreman-release.rpm
yum install foreman-installer
foreman-installer --verbose
foreman-installer --enable-foreman-cli-openscap --enable-foreman-plugin-openscap --enable-foreman-proxy-plugin-openscap --verbose
puppet module install theforeman-foreman_scap_client

I set classes correctly, imported scap content, created a policy, configuration makes it to client correctly.

To get the files referred to above fix#30353 I did
git clone https://github.com/theforeman/foreman_openscap.git

When I carried out a diff, it exposed 3 other files different to the installed files, I assume these are for other recent fixes:

diff app/ /usr/share/gems/gems/foreman_openscap-3.0.0/app/ -r

diff -r app/controllers/api/v2/compliance/scap_contents_controller.rb /usr/share/gems/gems/foreman_openscap-3.0.0/app/controllers/api/v2/compliance/scap_contents_controller.rb
54c54
<         process_response @scap_content.update(scap_content_params)
---
>         process_response @scap_content.update_attributes(scap_content_params)

diff -r app/controllers/api/v2/compliance/tailoring_files_controller.rb /usr/share/gems/gems/foreman_openscap-3.0.0/app/controllers/api/v2/compliance/tailoring_files_controller.rb
55c55
<         process_response @tailoring_file.update(tailoring_file_params)
---
>         process_response @tailoring_file.update_attributes(tailoring_file_params)

diff -r app/controllers/scap_contents_controller.rb /usr/share/gems/gems/foreman_openscap-3.0.0/app/controllers/scap_contents_controller.rb
36c36
<     if @scap_content.update(scap_content_params)
---
>     if @scap_content.update_attributes(scap_content_params)

diff -r app/controllers/tailoring_files_controller.rb /usr/share/gems/gems/foreman_openscap-3.0.0/app/controllers/tailoring_files_controller.rb
33c33
<     if @tailoring_file.update(tailoring_file_params)
---
>     if @tailoring_file.update_attributes(tailoring_file_params)

diff -r app/models/foreman_openscap/policy.rb /usr/share/gems/gems/foreman_openscap-3.0.0/app/models/foreman_openscap/policy.rb
70c70
<         errors.none? && update(params)
---
>         errors.none? && update_attributes(params)

Copying the two files referenced in the fix above together with the other 3 files for completeness does not appear to have changed anything, a report is not ingested to the foreman interface and still error 500 seen.

2020-07-09T22:00:01 [W|app|dd3e12c2] Action failed
2020-07-09T22:00:01 [D|app|dd3e12c2] Backtrace for 'Action failed' error (ActiveRecord::RecordNotUnique): PG::UniqueViolation: ERROR:  duplicate key value violates unique constraint "index_scaptimony_asset_policies_on_asset_id_and_policy_id"
DETAIL:  Key (asset_id, policy_id)=(2, 1) already exists.

/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/postgresql_adapter.rb:675:in `async_exec_params'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/postgresql_adapter.rb:675:in `block (2 levels) in exec_no_cache'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/dependencies/interlock.rb:48:in `block in permit_concurrent_loads'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/dependencies/interlock.rb:47:in `permit_concurrent_loads'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/postgresql_adapter.rb:674:in `block in exec_no_cache'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract_adapter.rb:722:in `block (2 levels) in log'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract_adapter.rb:721:in `block in log'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract_adapter.rb:712:in `log'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/postgresql_adapter.rb:673:in `exec_no_cache'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/postgresql_adapter.rb:656:in `execute_and_clear'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/postgresql/database_statements.rb:98:in `exec_query'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/database_statements.rb:135:in `exec_insert'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/postgresql/database_statements.rb:132:in `exec_insert'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/database_statements.rb:166:in `insert'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/query_cache.rb:22:in `insert'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/persistence.rb:375:in `_insert_record'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/persistence.rb:932:in `_create_record'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/counter_cache.rb:166:in `_create_record'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/locking/optimistic.rb:70:in `_create_record'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/attribute_methods/dirty.rb:211:in `_create_record'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/callbacks.rb:331:in `block in _create_record'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:101:in `run_callbacks'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:825:in `_run_create_callbacks'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/callbacks.rb:331:in `_create_record'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/timestamp.rb:110:in `_create_record'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/persistence.rb:905:in `create_or_update'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/callbacks.rb:327:in `block in create_or_update'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:135:in `run_callbacks'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:825:in `_run_save_callbacks'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/callbacks.rb:327:in `create_or_update'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/timestamp.rb:128:in `create_or_update'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/persistence.rb:503:in `save!'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/validations.rb:53:in `save!'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/transactions.rb:318:in `block in save!'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/transactions.rb:375:in `block in with_transaction_returning_status'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/database_statements.rb:278:in `transaction'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/transactions.rb:212:in `transaction'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/transactions.rb:366:in `with_transaction_returning_status'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/transactions.rb:318:in `save!'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/suppressor.rb:48:in `save!'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/has_many_through_association.rb:77:in `save_through_record'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/has_many_through_association.rb:31:in `insert_record'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:426:in `block (2 levels) in concat_records'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:447:in `replace_on_target'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:285:in `add_to_target'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:424:in `block in concat_records'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:422:in `each'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:422:in `concat_records'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/has_many_association.rb:108:in `concat_records'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/has_many_through_association.rb:40:in `concat_records'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:120:in `block in concat'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:135:in `block in transaction'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/database_statements.rb:278:in `transaction'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/transactions.rb:212:in `transaction'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:134:in `transaction'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:120:in `concat'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/has_many_through_association.rb:21:in `concat'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:402:in `replace_records'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:253:in `block in replace'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:135:in `block in transaction'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/database_statements.rb:280:in `block in transaction'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/transaction.rb:280:in `block in within_new_transaction'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/transaction.rb:278:in `within_new_transaction'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/database_statements.rb:280:in `transaction'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/transactions.rb:212:in `transaction'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:134:in `transaction'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:253:in `replace'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/collection_association.rb:71:in `ids_writer'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/associations/builder/collection_association.rb:65:in `policy_ids='
/usr/share/gems/gems/foreman_openscap-3.0.0/lib/foreman_openscap/helper.rb:5:in `get_asset'
/usr/share/gems/gems/foreman_openscap-3.0.0/app/controllers/api/v2/compliance/arf_reports_controller.rb:98:in `find_resources_before_create'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:428:in `block in make_lambda'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:181:in `block (2 levels) in halting_and_conditional'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/abstract_controller/callbacks.rb:34:in `block (2 levels) in <module:Callbacks>'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:182:in `block in halting_and_conditional'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:513:in `block in invoke_before'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:513:in `each'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:513:in `invoke_before'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:110:in `block in run_callbacks'
/usr/share/foreman/app/controllers/api/v2/base_controller.rb:163:in `disable_json_root'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
/usr/share/foreman/app/controllers/concerns/foreman/controller/timezone.rb:10:in `set_timezone'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
/usr/share/foreman/app/controllers/concerns/foreman/controller/topbar_sweeper.rb:12:in `set_topbar_sweeper_controller'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
/usr/share/gems/gems/audited-4.9.0/lib/audited/sweeper.rb:14:in `around'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
/usr/share/gems/gems/audited-4.9.0/lib/audited/sweeper.rb:14:in `around'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:139:in `run_callbacks'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/abstract_controller/callbacks.rb:41:in `process_action'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_controller/metal/rescue.rb:22:in `process_action'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_controller/metal/instrumentation.rb:33:in `block in process_action'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/notifications.rb:180:in `block in instrument'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/notifications.rb:180:in `instrument'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_controller/metal/instrumentation.rb:32:in `process_action'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_controller/metal/params_wrapper.rb:245:in `process_action'
/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/railties/controller_runtime.rb:27:in `process_action'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/abstract_controller/base.rb:136:in `process'
/usr/share/gems/gems/actionview-6.0.3.1/lib/action_view/rendering.rb:39:in `process'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_controller/metal.rb:190:in `dispatch'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_controller/metal.rb:254:in `dispatch'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/routing/route_set.rb:50:in `dispatch'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/routing/route_set.rb:33:in `serve'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/routing/mapper.rb:18:in `block in <class:Constraints>'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/routing/mapper.rb:48:in `serve'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/journey/router.rb:49:in `block in serve'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/journey/router.rb:32:in `each'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/journey/router.rb:32:in `serve'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/routing/route_set.rb:834:in `call'
/usr/share/gems/gems/apipie-dsl-2.2.2/lib/apipie_dsl/static_dispatcher.rb:67:in `call'
/usr/share/gems/gems/apipie-rails-0.5.17/lib/apipie/static_dispatcher.rb:66:in `call'
/usr/share/gems/gems/apipie-rails-0.5.17/lib/apipie/extractor/recorder.rb:137:in `call'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/static.rb:126:in `call'
/usr/share/foreman/lib/foreman/middleware/telemetry.rb:10:in `call'
/usr/share/gems/gems/apipie-rails-0.5.17/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
/usr/share/foreman/lib/foreman/middleware/catch_json_parse_errors.rb:9:in `call'
/usr/share/gems/gems/rack-2.2.2/lib/rack/tempfile_reaper.rb:15:in `call'
/usr/share/gems/gems/rack-2.2.2/lib/rack/etag.rb:27:in `call'
/usr/share/gems/gems/rack-2.2.2/lib/rack/conditional_get.rb:40:in `call'
/usr/share/gems/gems/rack-2.2.2/lib/rack/head.rb:12:in `call'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/http/content_security_policy.rb:18:in `call'
/usr/share/foreman/lib/foreman/middleware/logging_context_session.rb:22:in `call'
/usr/share/gems/gems/rack-2.2.2/lib/rack/session/abstract/id.rb:266:in `context'
/usr/share/gems/gems/rack-2.2.2/lib/rack/session/abstract/id.rb:260:in `call'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/cookies.rb:648:in `call'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:101:in `run_callbacks'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/actionable_exceptions.rb:17:in `call'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/debug_exceptions.rb:32:in `call'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
/usr/share/gems/gems/railties-6.0.3.1/lib/rails/rack/logger.rb:37:in `call_app'
/usr/share/gems/gems/railties-6.0.3.1/lib/rails/rack/logger.rb:28:in `call'
/usr/share/gems/gems/sprockets-rails-3.2.1/lib/sprockets/rails/quiet_assets.rb:13:in `call'
/usr/share/foreman/lib/foreman/middleware/logging_context_request.rb:11:in `call'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/request_id.rb:27:in `call'
/usr/share/gems/gems/rack-2.2.2/lib/rack/method_override.rb:24:in `call'
/usr/share/gems/gems/rack-2.2.2/lib/rack/runtime.rb:22:in `call'
/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/executor.rb:14:in `call'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/static.rb:126:in `call'
/usr/share/gems/gems/rack-2.2.2/lib/rack/sendfile.rb:110:in `call'
/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/host_authorization.rb:76:in `call'
/usr/share/gems/gems/secure_headers-6.3.0/lib/secure_headers/middleware.rb:11:in `call'
/usr/share/gems/gems/railties-6.0.3.1/lib/rails/engine.rb:527:in `call'
/usr/share/gems/gems/railties-6.0.3.1/lib/rails/railtie.rb:190:in `public_send'
/usr/share/gems/gems/railties-6.0.3.1/lib/rails/railtie.rb:190:in `method_missing'
/usr/share/gems/gems/rack-2.2.2/lib/rack/urlmap.rb:74:in `block in call'
/usr/share/gems/gems/rack-2.2.2/lib/rack/urlmap.rb:58:in `each'
/usr/share/gems/gems/rack-2.2.2/lib/rack/urlmap.rb:58:in `call'
/usr/share/gems/gems/puma-4.3.3/lib/puma/configuration.rb:228:in `call'
/usr/share/gems/gems/puma-4.3.3/lib/puma/server.rb:682:in `handle_request'
/usr/share/gems/gems/puma-4.3.3/lib/puma/server.rb:472:in `process_client'
/usr/share/gems/gems/puma-4.3.3/lib/puma/server.rb:328:in `block in run'
/usr/share/gems/gems/puma-4.3.3/lib/puma/thread_pool.rb:134:in `block in spawn_thread'
/usr/share/gems/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2020-07-09T22:00:01 [I|app|dd3e12c2]   Rendering api/v2/errors/standard_error.json.rabl within api/v2/layouts/error_layout
2020-07-09T22:00:01 [I|app|dd3e12c2]   Rendered api/v2/errors/standard_error.json.rabl within api/v2/layouts/error_layout (Duration: 1.7ms | Allocations: 196)
2020-07-09T22:00:01 [I|app|dd3e12c2] Completed 500 Internal Server Error in 84ms (Views: 6.0ms | ActiveRecord: 19.7ms | Allocations: 18473)

What please am I missing?

The fix should be in nightlies once it gets merged and built, however I’ll make a new release of foreman_openscap for 2.1 as well.

Those other files are fixing different issues. The following steps should pull the patch, apply and restart foreman service:

cd /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_openscap-3.0.0
wget https://patch-diff.githubusercontent.com/raw/theforeman/foreman_openscap/pull/439.patch
patch -p1 < 439.patch
systemctl restart foreman

Thank you for testing!

Hi, thank you for refreshing my knowledge on the use of patch, apologies when you dont work with it every day you end up asking simple questions…!
speaking of which,
the location specified seems different on mine although version 3.0.0 seems the same, per above this is a Centos 8 8.2.2004 build

I have
/usr/share/gems/gems/foreman_openscap-3.0.0/

Also

# dnf provides */foreman_openscap-3.0.0
Last metadata expiration check: 1:54:04 ago on Fri 10 Jul 2020 06:18:00 UTC.
rubygem-foreman_openscap-3.0.0-1.fm2_1.el8.noarch : Foreman plug-in for displaying OpenSCAP audit reports
Repo        : @System
Matched from:
Filename    : /usr/share/gems/gems/foreman_openscap-3.0.0

rubygem-foreman_openscap-3.0.0-1.fm2_1.el8.noarch : Foreman plug-in for displaying OpenSCAP audit reports
Repo        : foreman-plugins
Matched from:
Filename    : /usr/share/gems/gems/foreman_openscap-3.0.0

rubygem-foreman_openscap-doc-3.0.0-1.fm2_1.el8.noarch : Documentation for rubygem-foreman_openscap
Repo        : foreman-plugins
Matched from:
Filename    : /usr/share/gems/doc/foreman_openscap-3.0.0

Assuming this location doesnt make any difference whatsoever.

However, for me, reverting to install above before I manually copied files over then running the patch command in right location didnt in fact work, same error 500, same duplicate key entry in logs.
Sorry to take your time!

Apologies, I was testing on CentOS 7, the paths differ but it is a correct folder. It is interesting that it did not work for you, maybe I missed something. I’ll continue looking into this.

1 Like

Thanks. Not related to THIS error 500 but just to remind of noted difference between rpms and puppet module install for the scap classes.
… my end, I’ll spin up a CentOS 7 machine for thrills :slight_smile:
Thanks for your work!

Since my last I have built test CentOS 7 and 8 servers and clients.
Both servers the scap client was installed with puppet moduel install instead of from rpm per previous issues reported with rpm.

On Centos 7 I concur that the patch given fixes the upload report problem. Interestingly I have come to realise that the very first report executed after configuring was uploaded correctly, then failures occured.
Since patching the CentOS 7 server with patch given, all reports successfully make it into foreman.

On Centos 8, as above, the error 500 issue still appears to manifest itself after patching. Logs available if needed.

Hello, to report that for the RC1 build of foreman 2.2 this error seems to have crept back in.
To expand further on the explicit symptoms, the error appears to occur only first deletion of a report.

I belive it may be happening for 2.2 because the fix listed is missing from the currently published
rubygem-foreman_openscap-4.0.0-1.fm2_2.el8.noarch rpm in the 2.2 plugin repo.

I have manually patched the two files and reports upload correctly.

Grateful for another pair of eyes better than mine to validate!

I opened a packaging PR for the newer version to be included in 2.2:

1 Like