Hammer import classes fails after upgrade

dj_kill · May 4, 2022, 6:57am

Problem:
After upgrade from 1.24.2 to 3.2 (1.24->2.0-2.1->2.2->2.3->2.4->2.5->3.0->3.1->3.2) at least one hammer cli command is failing.

hammer proxy import-classes --id 1 --puppet-environment sbx
returns 502

Expected outcome:
Classes imported correctly.

Foreman and Proxy versions:

foreman.noarch                            3.2.0-1.el7
foreman-cli.noarch                        3.2.0-1.el7
foreman-debug.noarch                      3.2.0-1.el7
foreman-dynflow-sidekiq.noarch            3.2.0-1.el7
foreman-ec2.noarch                        3.2.0-1.el7
foreman-installer.noarch                  1:3.2.0-1.el7
foreman-installer-katello.noarch          1:3.2.0-1.el7
foreman-libvirt.noarch                    3.2.0-1.el7
foreman-ovirt.noarch                      3.2.0-1.el7
foreman-postgresql.noarch                 3.2.0-1.el7
foreman-proxy.noarch                      3.2.0-1.el7
foreman-release.noarch                    3.2.0-1.el7
foreman-release-scl.noarch                7-3.el7
foreman-selinux.noarch                    3.2.0-1.el7
foreman-service.noarch                    3.2.0-1.el7
katello.noarch                            4.4.0-1.el7
katello-ca-consumer-dapmgmtsbx01.dap.noarch
katello-certs-tools.noarch                2.8.2-1.el7
katello-client-bootstrap.noarch           1.7.8-1.el7
katello-common.noarch                     4.4.0-1.el7
katello-debug.noarch                      4.4.0-1.el7
katello-default-ca.noarch                 1.0-1
katello-repos.noarch                      4.4.0-1.el7
katello-selinux.noarch                    4.0.2-1.el7
katello-server-ca.noarch                  1.0-1
katello-service.noarch                    3.14.1-1.el7

Distribution and version:
CentOS 7

[root@dapmgmtsbx01 ~]# cat /etc/centos-release
CentOS Linux release 7.9.2009 (Core)
[root@dapmgmtsbx01 ~]# uname -a
Linux dapmgmtsbx01.dap 3.10.0-1160.53.1.el7.x86_64 #1 SMP Fri Jan 14 13:59:45 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux

Other relevant data:
Foreman production log doesn’t show any errors:

2022-05-04T08:35:43 [I|app|280520fd] Started GET "/api/locations?search=name+%3D+%22Default+Location%22&per_page=1000&page=1" for 172.16.2.5 at 2022-05-04 08:35:43 +0200
2022-05-04T08:35:43 [I|app|280520fd] Processing by Api::V2::LocationsController#index as JSON
2022-05-04T08:35:43 [I|app|280520fd]   Parameters: {"search"=>"name = \"Default Location\"", "per_page"=>"1000", "page"=>"1", "apiv"=>"v2", "location"=>{}}
2022-05-04T08:35:43 [I|app|280520fd] Authorized user admin(Admin User)
2022-05-04T08:35:43 [I|app|280520fd]   Rendering api/v2/taxonomies/index.json.rabl within api/v2/layouts/index_layout
2022-05-04T08:35:43 [I|app|280520fd]   Rendered api/v2/taxonomies/index.json.rabl within api/v2/layouts/index_layout (Duration: 12.5ms | Allocations: 6460)
2022-05-04T08:35:43 [I|app|280520fd] Completed 200 OK in 118ms (Views: 16.8ms | ActiveRecord: 14.8ms | Allocations: 21611)
2022-05-04T08:35:43 [I|app|ddc5ce76] Started GET "/katello/api/organizations?search=name+%3D+%22Default+Organization%22&per_page=1000&page=1" for 172.16.2.5 at 2022-05-04 08:35:43 +0200
2022-05-04T08:35:43 [I|app|ddc5ce76] Processing by Katello::Api::V2::OrganizationsController#index as JSON
2022-05-04T08:35:43 [I|app|ddc5ce76]   Parameters: {"search"=>"name = \"Default Organization\"", "per_page"=>"1000", "page"=>"1", "api_version"=>"v2", "organization"=>{}}
2022-05-04T08:35:43 [I|app|ddc5ce76] Authorized user admin(Admin User)
2022-05-04T08:35:43 [I|app|ddc5ce76]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.4.0.2/app/views/katello/api/v2/organizations/index.json.rabl within api/v2/layouts/index_layout
2022-05-04T08:35:43 [I|app|ddc5ce76]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.4.0.2/app/views/katello/api/v2/organizations/index.json.rabl within api/v2/layouts/index_layout (Duration: 4.1ms | Allocations: 2933)
2022-05-04T08:35:43 [I|app|ddc5ce76] Completed 200 OK in 98ms (Views: 7.1ms | ActiveRecord: 11.3ms | Allocations: 14806)
2022-05-04T08:35:43 [I|app|01b16159] Started GET "/foreman_puppet/api/environments?search=name+%3D+%22sbx%22&per_page=1000&page=1" for 172.16.2.5 at 2022-05-04 08:35:43 +0200
2022-05-04T08:35:43 [I|app|01b16159] Processing by ForemanPuppet::Api::V2::EnvironmentsController#index as JSON
2022-05-04T08:35:43 [I|app|01b16159]   Parameters: {"search"=>"name = \"sbx\"", "per_page"=>"1000", "page"=>"1", "apiv"=>"v2", "environment"=>{}}
2022-05-04T08:35:43 [I|app|01b16159] Authorized user admin(Admin User)
2022-05-04T08:35:43 [I|app|01b16159]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_puppet-3.0.5/app/views/foreman_puppet/api/v2/environments/index.json.rabl within api/v2/layouts/index_layout
2022-05-04T08:35:43 [I|app|01b16159]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_puppet-3.0.5/app/views/foreman_puppet/api/v2/environments/index.json.rabl within api/v2/layouts/index_layout (Duration: 4.9ms | Allocations: 1952)
2022-05-04T08:35:43 [I|app|01b16159] Completed 200 OK in 103ms (Views: 8.1ms | ActiveRecord: 10.8ms | Allocations: 13980)
2022-05-04T08:35:43 [I|app|7d433254] Started POST "/api/environments/2/smart_proxies/1/import_puppetclasses" for 172.16.2.5 at 2022-05-04 08:35:43 +0200
2022-05-04T08:35:43 [I|app|7d433254] Processing by Api::V2::SmartProxiesController#import_puppetclasses as JSON
2022-05-04T08:35:43 [I|app|7d433254]   Parameters: {"location_id"=>2, "organization_id"=>1, "dryrun"=>false, "apiv"=>"v2", "environment_id"=>"2", "id"=>"1", "smart_proxy"=>{}}
2022-05-04T08:35:43 [I|app|7d433254] Authorized user admin(Admin User)

Hammer in verbose mode also not really helpful:

[DEBUG 2022-05-04T08:35:43 API] Using authenticator: HammerCLIForeman::Api::InteractiveBasicAuth
[ERROR 2022-05-04T08:50:43 API] 502 Bad Gateway
[DEBUG 2022-05-04T08:50:43 API] "<!DOCTYPE HTML PUBLIC \"-//IETF//DTD HTML 2.0//EN\">\n<html><head>\n<title>502 Proxy Error</title>\n</head><body>\n<h1>Proxy Error</h1>\n<p>The proxy server received an invalid\r\nresponse from an upstream server.<br />\r\nThe proxy server could not handle the request <em><a href=\"/api/environments/2/smart_proxies/1/import_puppetclasses\">POST&nbsp;/api/environments/2/smart_proxies/1/import_puppetclasses</a></em>.<p>\nReason: <strong>Error reading from remote server</strong></p></p>\n</body></html>\n"
[DEBUG 2022-05-04T08:50:43 Exception] Using exception handler HammerCLIForeman::ExceptionHandler#handle_general_exception
[ERROR 2022-05-04T08:50:43 Exception] Error: 502 Bad Gateway
Error: 502 Bad Gateway

All services are up and running as they should. At least no errors in the logs or in GUI.
Puppet runs and reports are in Foreman.
puppetserver and puppetdb are installed on the same server as Foreman.
What else I can check?

dj_kill · May 4, 2022, 8:20am

Looks like this is related to any puppet class imports:

[root@dapmgmtsbx01 pulp]# curl -kvX POST -H "Content-Type: application/json" -u "admin:HIDDEN" -d '{"location_id": 2, "organization_id": 1,  "dryrun":false}' https://dapmgmtsbx01.dap/api/environments/2/smart_proxies/1/import_puppetclasses
* About to connect() to dapmgmtsbx01.dap port 443 (#0)
*   Trying 172.16.2.5...
* Connected to dapmgmtsbx01.dap (172.16.2.5) port 443 (#0)
* Initializing NSS with certpath: sql:/etc/pki/nssdb
* skipping SSL peer certificate verification
* NSS: client certificate not found (nickname not specified)
* SSL connection using TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
* Server certificate:
*       subject: CN=dapmgmtsbx01.dap,OU=SomeOrgUnit,O=Katello,ST=North Carolina,C=US
*       start date: Apr 14 18:15:43 2020 GMT
*       expire date: Jan 17 18:15:43 2038 GMT
*       common name: dapmgmtsbx01.dap
*       issuer: CN=dapmgmtsbx01.dap,OU=SomeOrgUnit,O=Katello,L=Raleigh,ST=North Carolina,C=US
* Server auth using Basic with user 'admin'
> POST /api/environments/2/smart_proxies/1/import_puppetclasses HTTP/1.1
> Authorization: Basic HIDDEN
> User-Agent: curl/7.29.0
> Host: dapmgmtsbx01.dap
> Accept: */*
> Content-Type: application/json
> Content-Length: 57
>
* upload completely sent off: 57 out of 57 bytes

< HTTP/1.1 502 Proxy Error
< Date: Wed, 04 May 2022 08:03:05 GMT
< Server: Apache
< Content-Length: 490
< Content-Type: text/html; charset=iso-8859-1
<
<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>502 Proxy Error</title>
</head><body>
<h1>Proxy Error</h1>
<p>The proxy server received an invalid
response from an upstream server.<br />
The proxy server could not handle the request <em><a href="/api/environments/2/smart_proxies/1/import_puppetclasses">POST&nbsp;/api/environments/2/smart_proxies/1/import_puppetclasses</a></em>.<p>
Reason: <strong>Error reading from remote server</strong></p></p>
</body></html>
* Connection #0 to host dapmgmtsbx01.dap left intact

Same story via Foreman UI.

I’ve played with

 # (optional) enable or disable environment class cache
    environment-class-cache-enabled: true

in puppetserver.conf and timeouts in HTTPD settings. Same results.

dj_kill · May 4, 2022, 8:39am

And puppet server itself returns everything correctly:

[root@dapmgmtsbx01 pulp]# curl --cert /etc/puppetlabs/puppet/ssl/certs/dapmgmtsbx01.dap.pem \
> --key /etc/puppetlabs/puppet/ssl/private_keys/dapmgmtsbx01.dap.pem \
> --cacert /etc/puppetlabs/puppet/ssl/ca/ca_crt.pem \
> -kv https://dapmgmtsbx01.dap:8140/puppet/v3/environment_classes?environment=production
* About to connect() to dapmgmtsbx01.dap port 8140 (#0)
*   Trying 172.16.2.5...
* Connected to dapmgmtsbx01.dap (172.16.2.5) port 8140 (#0)
* Initializing NSS with certpath: sql:/etc/pki/nssdb
* skipping SSL peer certificate verification
* NSS: client certificate from file
*       subject: CN=dapmgmtsbx01.dap
*       start date: Apr 20 18:07:43 2020 GMT
*       expire date: Apr 20 18:07:43 2025 GMT
*       common name: dapmgmtsbx01.dap
*       issuer: CN=Puppet CA: dapmgmtsbx01.dap
* SSL connection using TLS_RSA_WITH_AES_256_CBC_SHA256
* Server certificate:
*       subject: CN=dapmgmtsbx01.dap
*       start date: Apr 20 18:07:43 2020 GMT
*       expire date: Apr 20 18:07:43 2025 GMT
*       common name: dapmgmtsbx01.dap
*       issuer: CN=Puppet CA: dapmgmtsbx01.dap
> GET /puppet/v3/environment_classes?environment=production HTTP/1.1
> User-Agent: curl/7.29.0
> Host: dapmgmtsbx01.dap:8140
> Accept: */*
>
< HTTP/1.1 200 OK
< Date: Wed, 04 May 2022 08:37:45 GMT
< ETag: 1c4c943a0f9bf38527469d95e6ef03021025cd6849bc636307b5667f5d0181b1
< Content-Type: application/json
< X-Puppet-Version: 6.26.0
< Vary: Accept-Encoding, User-Agent
< Transfer-Encoding: chunked
<
{"files":[{"classes":[],"path":"/etc/puppetlabs/code/environments/production/manifests/site.pp"},{"classes":[],"path":"/etc/puppetlabs/code/environments/production/modules/apache/manifests/balancer.pp"},{"classes":[],"path":"/etc/puppetlabs/code/environments/production/modules/apache/manifests/balancermember.pp"},{"classes":[{"name":"apache::confd::no_accf","params":[]}],"path":"/etc/puppetlabs/code/environments/production/modules/apache/manifests/confd/no_accf.pp"},{"classes":[],"path":"/etc/puppetlabs/code/environments/production/modules/apache/manifests/custom_config.pp"},{"classes":[{"name":"apache::default_confd_files","params":[{"default_literal":true,"default_source":"true","name":"all"}]}],"path":"/etc/puppetlabs/code/environments/production/modules/apache/manifests/default_confd_files.pp"},{"classes":[{"name":"apache::default_mods","params":[{"default_literal":true,"default_source":"true","name":"all"},{"default_source":"undef","name":"mods"},{"default_source":"$::apache::apache_version","name":"apache_version"}
......

nadjaheitmann · May 11, 2022, 8:48am

This looks like a bug with the routes. I will open an issue for this.
Can you please try to curl the request like this:

curl -kvX POST -H "Content-Type: application/json" -u "admin:HIDDEN" -d '{"location_id": 2, "organization_id": 1,  "dryrun":false}' https://dapmgmtsbx01.dap/api/smart_proxies/1/environments/2/import_puppetclasses

nadjaheitmann · May 11, 2022, 9:58am

I have re-tested and now routes are working fine for me. Can you still re-test, please?

dj_kill · May 11, 2022, 12:45pm

Doesn’t help. Same error

[root@dapmgmtsbx01 ~]# curl -kvX POST -H "Content-Type: application/json" -u "admin:HIDDEN" -d '{"location_id": 2, "organization_id": 1,  "dryrun":false}' https://dapmgmtsbx01.dap/api/smart_proxies/1/environments/2/import_puppetclasses
* About to connect() to dapmgmtsbx01.dap port 443 (#0)
*   Trying 172.16.2.5...
* Connected to dapmgmtsbx01.dap (172.16.2.5) port 443 (#0)
* Initializing NSS with certpath: sql:/etc/pki/nssdb
* skipping SSL peer certificate verification
* NSS: client certificate not found (nickname not specified)
* SSL connection using TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
* Server certificate:
*       subject: CN=dapmgmtsbx01.dap,OU=SomeOrgUnit,O=Katello,ST=North Carolina,C=US
*       start date: Apr 14 18:15:43 2020 GMT
*       expire date: Jan 17 18:15:43 2038 GMT
*       common name: dapmgmtsbx01.dap
*       issuer: CN=dapmgmtsbx01.dap,OU=SomeOrgUnit,O=Katello,L=Raleigh,ST=North Carolina,C=US
* Server auth using Basic with user 'admin'
> POST /api/smart_proxies/1/environments/2/import_puppetclasses HTTP/1.1
> Authorization: Basic YWRtaW46UzRBRm9OWTh1b3pDMmNYUUN2Nlh6cVJObHdpb2tSdUtBc0VzdXRSMlFxbz0=
> User-Agent: curl/7.29.0
> Host: dapmgmtsbx01.dap
> Accept: */*
> Content-Type: application/json
> Content-Length: 57
>
* upload completely sent off: 57 out of 57 bytes
< HTTP/1.1 502 Proxy Error
< Date: Wed, 11 May 2022 12:23:14 GMT
< Server: Apache
< Content-Length: 490
< Content-Type: text/html; charset=iso-8859-1
<
<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>502 Proxy Error</title>
</head><body>
<h1>Proxy Error</h1>
<p>The proxy server received an invalid
response from an upstream server.<br />
The proxy server could not handle the request <em><a href="/api/smart_proxies/1/environments/2/import_puppetclasses">POST&nbsp;/api/smart_proxies/1/environments/2/import_puppetclasses</a></em>.<p>
Reason: <strong>Error reading from remote server</strong></p></p>
</body></html>
* Connection #0 to host dapmgmtsbx01.dap left intact

What do I miss?

nadjaheitmann · May 11, 2022, 12:49pm

Is there any log on the smart proxy side?

dj_kill · May 12, 2022, 9:08am

I don’t see any lines in /var/log/foreman-proxy/proxy.log appearing in the moment of curl:

2022-05-12T11:06:29 7ce4b3f1 [I] Started GET /v2/features
2022-05-12T11:06:29 7ce4b3f1 [I] Finished GET /v2/features with 200 (96.33 ms)
2022-05-12T11:06:31 86ce1854 [I] Started GET /v2/features
2022-05-12T11:06:31 86ce1854 [I] Finished GET /v2/features with 200 (81.72 ms)
2022-05-12T11:06:34 a7ca6f59 [I] Started GET /v2/features
2022-05-12T11:06:34 a7ca6f59 [I] Finished GET /v2/features with 200 (75.66 ms)
2022-05-12T11:06:37 20f1d80f [I] Started GET /v2/features
2022-05-12T11:06:37 20f1d80f [I] Finished GET /v2/features with 200 (77.31 ms)

nadjaheitmann · May 17, 2022, 6:54am

I tested your request and for me, it works just fine (curl command). Maybe some timeout on the server side? The request takes some time to proceed?

dj_kill · June 1, 2022, 5:53am

So, small update on this.

We have 2nd production system running the same, but on RedHat (first is on CentOS).
After same update (from same version to same version) same issue appears and your solution with curl works fine.

Yesterday I tried to update system to freshly released 3.2.1 and thigs get worse: qpidd won’t start anymore complaining about certificates and if I try to login with LDAP users The Foreman also throw “proxy timeout error”. With built-in admin everything looks “green”.

May this be related?

nadjaheitmann · June 1, 2022, 10:33am

Did you check this?

dj_kill · June 1, 2022, 12:12pm

Yes, sure. This was a fist link in google.

Actually qpidd is starting up now: I delete certificate from nssdb with certtool, run installer with --certs-update-all and now qpidd is running.

After that I’ve noticed that on LDAP configuration page LDAPS checkbox disappear. With that checkbox I can login to the system with LDAP users as well for now.

curl command provided earlier doesn’t work still, but from proxy logs I see it doing something now:

2022-06-01T14:11:08 103ecffe [W] Puppet server classes cache is disabled, classes retrieval can be slow.
2022-06-01T14:11:13 103ecffe [I] Finished GET /puppet/environments/ftr_keycloak/classes with 200 (5113.31 ms)
2022-06-01T14:11:13 103ecffe [I] Started GET /puppet/environments/ftr_ciam_migration/classes
2022-06-01T14:11:13 103ecffe [W] Puppet server classes cache is disabled, classes retrieval can be slow.
2022-06-01T14:11:19 103ecffe [I] Finished GET /puppet/environments/ftr_ciam_migration/classes with 200 (6242.72 ms)
2022-06-01T14:11:19 103ecffe [I] Started GET /puppet/environments/amfo_vlpc_prd/classes
2022-06-01T14:11:19 103ecffe [W] Puppet server classes cache is disabled, classes retrieval can be slow.

I’m little bit curious why it complain about cache since:

[root@dapmgmtsbx01 ~]# cat /etc/puppetlabs/puppetserver/conf.d/puppetserver.conf | grep environment-class-cache
    environment-class-cache-enabled: true
[root@dapmgmtsbx01 ~]#

dj_kill · June 1, 2022, 12:19pm

And hammer still fails:

[root@dapmgmtsbx01 ~]# hammer proxy import-classes --id 1 --puppet-environment sbx
Error: Timed out reading data from server

nadjaheitmann · June 1, 2022, 2:40pm

@Marek_Hulan Any idea what is going on here?

dj_kill · June 13, 2022, 2:41pm

So, for now we have two identical servers with identical history and upgrade path.
Both of them now even on 3.2.1
“Small” difference between them is that one on CentOS 7 and puppet classes not working at all and second is on RedHat and puppet classes are fine via curl and not working via hammer.

Any ideas what to check? Does it worth to upgrade to 3.3.0 to fix this?

sofe · September 29, 2023, 9:49am

Hello there
I hitting the same problem with an even older set up I’ve been given:
foreman 2.1.4
I am trying to update it.
updating modules brought up “rails_cache_store:” setting in /etc/foreman/setting.yaml
as well as many other things which does not seem related.
Have you find what was the issue/ how to correct it ?
cheers,

Centos7
3.10.0-1160.83.1.el7.x86_64
puppetserver version: 6.20.0
puppet --version
6.28.0