Hammer import classes fails after upgrade

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?

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.

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"}
......

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
1 Like

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

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?

Is there any log on the smart proxy side?

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)

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?