FreeIPA realm: 'SASL Bind failed' when creating host

Problem:
It’s been a long time since I initially set up FreeIPA realm integration, and since then Foreman has been upgraded several times. Creating hosts is something I’m only now getting round to, as Katello fulfilled the initial requirement just fine.

I’m trying to resolve this error when creating a new host:

**Unable to save**
* Failed to create test-u22.sub.domain.com's realm entry: ERF12-5287 [ProxyAPI::ProxyException]: Unable to create realm entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fm01.sub.domain.com:9090/realm/SUB.DOMAIN.COM

Digging into the issue I found this link: ERF12-5287 - Foreman. Which mentions rerunning foreman-prepare-realm. Doing so is fine until the end when the following error is shown:

SASL Bind failed
    Local error: SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure.  Minor code may provide more information (KDC has no support for encryption type)
Failed to bind to server!
Failed to get keytab

However, testing the keytab succeeds, the keytab is not expired, nor are there any errors about the keytab in the production or proxy logs. As the Foreman server is a FreeIPA client and I can authenticate as an IPA user I know Kerberos between the Foreman server and the FreeIPA servers is unaffected.

Related proxy.log entry:

2024-02-14T10:53:08 d36f7208 [W] Error details for Unknown realm SUB.DOMAIN.COM: <Exception>: Unknown realm SUB.DOMAIN.COM

Expected outcome:

No realm errors.

Foreman and Proxy versions:

Foreman & Proxy: v3.9.1

Foreman and Proxy plugin versions:

Name Version
foreman-tasks 9.0.1
foreman_fog_proxmox 0.15.0
foreman_puppet 6.1.1
foreman_remote_execution 12.0.5
katello 4.11.0
smart proxy plugin - DHCP 3.9.1
smart proxy plugin - DNS 3.9.1
smart proxy plugin - Dynflow 0.9.1
smart proxy plugin - External IPAM 0.1.4
smart proxy plugin - Content 3.2.0
smart proxy plugin - Realm 3.9.1
smart proxy plugin - Script 0.10.3
smart proxy plugin - TFTP 3.9.1

Distribution and version:

CentOS 8 stream

Other relevant data:
Smart proxy log:

2024-02-14T10:53:08 d36f7208 [I] Started POST /realm/SUB.DOMAIN.COM/
2024-02-14T10:53:08 d36f7208 [E] Unknown realm SUB.DOMAIN.COM
2024-02-14T10:53:08 d36f7208 [W] Error details for Unknown realm SUB.DOMAIN.COM: <Exception>: Unknown realm SUB.DOMAIN.COM
/usr/share/foreman-proxy/modules/realm_freeipa/provider.rb:56:in `check_realm'
/usr/share/foreman-proxy/modules/realm_freeipa/provider.rb:70:in `create'
/usr/share/foreman-proxy/modules/realm/realm_api.rb:13:in `block in <class:Api>'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1697:in `call'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1697:in `block in compile!'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1030:in `block (3 levels) in route!'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1049:in `route_eval'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1030:in `block (2 levels) in route!'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1078:in `block in process_route'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1076:in `catch'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1076:in `process_route'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1028:in `block in route!'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1025:in `each'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1025:in `route!'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1147:in `block in dispatch!'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1119:in `block in invoke'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1119:in `catch'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1119:in `invoke'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1142:in `dispatch!'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:956:in `block in call!'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1119:in `block in invoke'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1119:in `catch'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1119:in `invoke'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:956:in `call!'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:945:in `call'
/usr/share/foreman-proxy/lib/proxy/log.rb:101:in `call'
/usr/share/foreman-proxy/lib/proxy/request_id_middleware.rb:11:in `call'
/usr/share/gems/gems/rack-protection-2.2.4/lib/rack/protection/xss_header.rb:18:in `call'
/usr/share/gems/gems/rack-protection-2.2.4/lib/rack/protection/path_traversal.rb:16:in `call'
/usr/share/gems/gems/rack-protection-2.2.4/lib/rack/protection/json_csrf.rb:26:in `call'
/usr/share/gems/gems/rack-protection-2.2.4/lib/rack/protection/base.rb:50:in `call'
/usr/share/gems/gems/rack-protection-2.2.4/lib/rack/protection/base.rb:50:in `call'
/usr/share/gems/gems/rack-protection-2.2.4/lib/rack/protection/frame_options.rb:31:in `call'
/usr/share/gems/gems/rack-2.2.8/lib/rack/null_logger.rb:11:in `call'
/usr/share/gems/gems/rack-2.2.8/lib/rack/head.rb:12:in `call'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/show_exceptions.rb:22:in `call'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:218:in `call'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:2004:in `call'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1564:in `block in call'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1780:in `synchronize'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1564:in `call'
/usr/share/gems/gems/rack-2.2.8/lib/rack/urlmap.rb:74:in `block in call'
/usr/share/gems/gems/rack-2.2.8/lib/rack/urlmap.rb:58:in `each'
/usr/share/gems/gems/rack-2.2.8/lib/rack/urlmap.rb:58:in `call'
/usr/share/gems/gems/rack-2.2.8/lib/rack/builder.rb:244:in `call'
/usr/share/gems/gems/rack-2.2.8/lib/rack/handler/webrick.rb:95:in `service'
/usr/share/gems/gems/webrick-1.8.1/lib/webrick/httpserver.rb:140:in `service'
/usr/share/gems/gems/webrick-1.8.1/lib/webrick/httpserver.rb:96:in `run'
/usr/share/gems/gems/webrick-1.8.1/lib/webrick/server.rb:310:in `block in start_thread'
/usr/share/gems/gems/logging-2.3.1/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2024-02-14T10:53:08 d36f7208 [W] Unknown realm SUB.DOMAIN.COM: <Exception>: Unknown realm SUB.DOMAIN.COM
/usr/share/foreman-proxy/modules/realm_freeipa/provider.rb:56:in `check_realm'
/usr/share/foreman-proxy/modules/realm_freeipa/provider.rb:70:in `create'
/usr/share/foreman-proxy/modules/realm/realm_api.rb:13:in `block in <class:Api>'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1697:in `call'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1697:in `block in compile!'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1030:in `block (3 levels) in route!'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1049:in `route_eval'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1030:in `block (2 levels) in route!'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1078:in `block in process_route'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1076:in `catch'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1076:in `process_route'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1028:in `block in route!'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1025:in `each'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1025:in `route!'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1147:in `block in dispatch!'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1119:in `block in invoke'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1119:in `catch'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1119:in `invoke'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1142:in `dispatch!'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:956:in `block in call!'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1119:in `block in invoke'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1119:in `catch'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1119:in `invoke'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:956:in `call!'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:945:in `call'
/usr/share/foreman-proxy/lib/proxy/log.rb:101:in `call'
/usr/share/foreman-proxy/lib/proxy/request_id_middleware.rb:11:in `call'
/usr/share/gems/gems/rack-protection-2.2.4/lib/rack/protection/xss_header.rb:18:in `call'
/usr/share/gems/gems/rack-protection-2.2.4/lib/rack/protection/path_traversal.rb:16:in `call'
/usr/share/gems/gems/rack-protection-2.2.4/lib/rack/protection/json_csrf.rb:26:in `call'
/usr/share/gems/gems/rack-protection-2.2.4/lib/rack/protection/base.rb:50:in `call'
/usr/share/gems/gems/rack-protection-2.2.4/lib/rack/protection/base.rb:50:in `call'
/usr/share/gems/gems/rack-protection-2.2.4/lib/rack/protection/frame_options.rb:31:in `call'
/usr/share/gems/gems/rack-2.2.8/lib/rack/null_logger.rb:11:in `call'
/usr/share/gems/gems/rack-2.2.8/lib/rack/head.rb:12:in `call'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/show_exceptions.rb:22:in `call'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:218:in `call'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:2004:in `call'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1564:in `block in call'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1780:in `synchronize'
/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1564:in `call'
/usr/share/gems/gems/rack-2.2.8/lib/rack/urlmap.rb:74:in `block in call'
/usr/share/gems/gems/rack-2.2.8/lib/rack/urlmap.rb:58:in `each'
/usr/share/gems/gems/rack-2.2.8/lib/rack/urlmap.rb:58:in `call'
/usr/share/gems/gems/rack-2.2.8/lib/rack/builder.rb:244:in `call'
/usr/share/gems/gems/rack-2.2.8/lib/rack/handler/webrick.rb:95:in `service'
/usr/share/gems/gems/webrick-1.8.1/lib/webrick/httpserver.rb:140:in `service'
/usr/share/gems/gems/webrick-1.8.1/lib/webrick/httpserver.rb:96:in `run'
/usr/share/gems/gems/webrick-1.8.1/lib/webrick/server.rb:310:in `block in start_thread'
/usr/share/gems/gems/logging-2.3.1/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2024-02-14T10:53:08 d36f7208 [I] Finished POST /realm/SUB.DOMAIN.COM/ with 400 (8.25 ms)

production.log:

2024-02-14T10:53:08 [I|app|d36f7208] Add realm entry for new host test-u22.sub.domain.com
2024-02-14T10:53:09 [W|app|d36f7208] Failed to create test-u22.sub.domain.com's realm entry: ERF12-5287 [ProxyAPI::ProxyException]: Unable to create realm entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fm01.sub.domain.com:9090/realm/SUB.DOMAIN.COM
2024-02-14T10:53:09 [I|app|d36f7208] Backtrace for 'Failed to create test-u22.sub.domain.com's realm entry: ERF12-5287 [ProxyAPI::ProxyException]: Unable to create realm entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fm01.sub.domain.com:9090/realm/SUB.DOMAIN.COM' error (ProxyAPI::ProxyException): ERF12-5287 [ProxyAPI::ProxyException]: Unable to create realm entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fm01.sub.domain.com:9090/realm/SUB.DOMAIN.COM
 d36f7208 | /usr/share/foreman/app/services/proxy_api/realm.rb:14:in `rescue in create'
 d36f7208 | /usr/share/foreman/app/services/proxy_api/realm.rb:11:in `create'
 d36f7208 | /usr/share/foreman/app/models/concerns/orchestration/realm.rb:34:in `set_realm'
 d36f7208 | /usr/share/foreman/app/models/concerns/orchestration.rb:227:in `execute'
 d36f7208 | /usr/share/foreman/app/models/concerns/orchestration.rb:152:in `block in process'
 d36f7208 | /usr/share/foreman/app/models/concerns/orchestration.rb:144:in `each'
 d36f7208 | /usr/share/foreman/app/models/concerns/orchestration.rb:144:in `process'
 d36f7208 | /usr/share/foreman/app/models/concerns/orchestration.rb:44:in `around_save_orchestration'
 d36f7208 | /usr/share/gems/gems/activesupport-6.1.7.6/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
 d36f7208 | /usr/share/gems/gems/activesupport-6.1.7.6/lib/active_support/callbacks.rb:137:in `run_callbacks'
 d36f7208 | /usr/share/gems/gems/activesupport-6.1.7.6/lib/active_support/callbacks.rb:824:in `_run_save_callbacks'
 d36f7208 | /usr/share/gems/gems/activerecord-6.1.7.6/lib/active_record/callbacks.rb:457:in `create_or_update'
 d36f7208 | /usr/share/gems/gems/activerecord-6.1.7.6/lib/active_record/timestamp.rb:126:in `create_or_update'
 d36f7208 | /usr/share/gems/gems/activerecord-6.1.7.6/lib/active_record/persistence.rb:474:in `save'
 d36f7208 | /usr/share/gems/gems/activerecord-6.1.7.6/lib/active_record/validations.rb:47:in `save'
 d36f7208 | /usr/share/gems/gems/activerecord-6.1.7.6/lib/active_record/transactions.rb:298:in `block in save'
 d36f7208 | /usr/share/gems/gems/activerecord-6.1.7.6/lib/active_record/transactions.rb:354:in `block in with_transaction_returning_status'
 d36f7208 | /usr/share/gems/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/database_statements.rb:320:in `block in transaction'
 d36f7208 | /usr/share/gems/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/transaction.rb:319:in `block in within_new_transaction'
 d36f7208 | /usr/share/gems/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
 d36f7208 | /usr/share/gems/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
 d36f7208 | /usr/share/gems/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
 d36f7208 | /usr/share/gems/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
 d36f7208 | /usr/share/gems/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
 d36f7208 | /usr/share/gems/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/transaction.rb:317:in `within_new_transaction'
 d36f7208 | /usr/share/gems/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/database_statements.rb:320:in `transaction'
 d36f7208 | /usr/share/gems/gems/activerecord-6.1.7.6/lib/active_record/transactions.rb:350:in `with_transaction_returning_status'
 d36f7208 | /usr/share/gems/gems/activerecord-6.1.7.6/lib/active_record/transactions.rb:298:in `save'
 d36f7208 | /usr/share/gems/gems/activerecord-6.1.7.6/lib/active_record/suppressor.rb:44:in `save'
 d36f7208 | /usr/share/foreman/app/models/concerns/foreman/sti.rb:26:in `save'
 d36f7208 | /usr/share/foreman/app/controllers/hosts_controller.rb:100:in `create'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/abstract_controller/base.rb:228:in `process_action'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_controller/metal/rendering.rb:30:in `process_action'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/abstract_controller/callbacks.rb:42:in `block in process_action'
 d36f7208 | /usr/share/gems/gems/activesupport-6.1.7.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
 d36f7208 | /usr/share/foreman/app/controllers/concerns/foreman/controller/timezone.rb:10:in `set_timezone'
 d36f7208 | /usr/share/gems/gems/activesupport-6.1.7.6/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
 d36f7208 | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread'
 d36f7208 | /usr/share/gems/gems/activesupport-6.1.7.6/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
 d36f7208 | /usr/share/foreman/app/controllers/concerns/foreman/controller/topbar_sweeper.rb:12:in `set_topbar_sweeper_controller'
 d36f7208 | /usr/share/gems/gems/activesupport-6.1.7.6/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
 d36f7208 | /usr/share/gems/gems/audited-5.4.2/lib/audited/sweeper.rb:16:in `around'
 d36f7208 | /usr/share/gems/gems/activesupport-6.1.7.6/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
 d36f7208 | /usr/share/gems/gems/audited-5.4.2/lib/audited/sweeper.rb:16:in `around'
 d36f7208 | /usr/share/gems/gems/activesupport-6.1.7.6/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
 d36f7208 | /usr/share/gems/gems/activesupport-6.1.7.6/lib/active_support/callbacks.rb:137:in `run_callbacks'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/abstract_controller/callbacks.rb:41:in `process_action'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_controller/metal/rescue.rb:22:in `process_action'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_controller/metal/instrumentation.rb:34:in `block in process_action'
 d36f7208 | /usr/share/gems/gems/activesupport-6.1.7.6/lib/active_support/notifications.rb:203:in `block in instrument'
 d36f7208 | /usr/share/gems/gems/activesupport-6.1.7.6/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
 d36f7208 | /usr/share/gems/gems/activesupport-6.1.7.6/lib/active_support/notifications.rb:203:in `instrument'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_controller/metal/instrumentation.rb:33:in `process_action'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_controller/metal/params_wrapper.rb:249:in `process_action'
 d36f7208 | /usr/share/gems/gems/activerecord-6.1.7.6/lib/active_record/railties/controller_runtime.rb:27:in `process_action'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/abstract_controller/base.rb:165:in `process'
 d36f7208 | /usr/share/gems/gems/actionview-6.1.7.6/lib/action_view/rendering.rb:39:in `process'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_controller/metal.rb:190:in `dispatch'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_controller/metal.rb:254:in `dispatch'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/routing/route_set.rb:50:in `dispatch'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/routing/route_set.rb:33:in `serve'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/journey/router.rb:50:in `block in serve'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/journey/router.rb:32:in `each'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/journey/router.rb:32:in `serve'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/routing/route_set.rb:842:in `call'
 d36f7208 | /usr/share/gems/gems/katello-4.11.0/lib/katello/middleware/organization_created_enforcer.rb:18:in `call'
 d36f7208 | /usr/share/gems/gems/katello-4.11.0/lib/katello/middleware/event_daemon.rb:10:in `call'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/static.rb:24:in `call'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/static.rb:24:in `call'
 d36f7208 | /usr/share/gems/gems/apipie-dsl-2.6.1/lib/apipie_dsl/static_dispatcher.rb:67:in `call'
 d36f7208 | /usr/share/gems/gems/apipie-rails-1.2.3/lib/apipie/static_dispatcher.rb:68:in `call'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/static.rb:24:in `call'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/static.rb:24:in `call'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/static.rb:24:in `call'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/static.rb:24:in `call'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/static.rb:24:in `call'
 d36f7208 | /usr/share/foreman/lib/foreman/middleware/libvirt_connection_cleaner.rb:9:in `call'
 d36f7208 | /usr/share/foreman/lib/foreman/middleware/telemetry.rb:10:in `call'
 d36f7208 | /usr/share/gems/gems/apipie-rails-1.2.3/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
 d36f7208 | /usr/share/gems/gems/rack-2.2.8/lib/rack/tempfile_reaper.rb:15:in `call'
 d36f7208 | /usr/share/gems/gems/rack-2.2.8/lib/rack/etag.rb:27:in `call'
 d36f7208 | /usr/share/gems/gems/rack-2.2.8/lib/rack/conditional_get.rb:40:in `call'
 d36f7208 | /usr/share/gems/gems/rack-2.2.8/lib/rack/head.rb:12:in `call'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/http/permissions_policy.rb:22:in `call'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/http/content_security_policy.rb:19:in `call'
 d36f7208 | /usr/share/foreman/lib/foreman/middleware/logging_context_session.rb:22:in `call'
 d36f7208 | /usr/share/gems/gems/rack-2.2.8/lib/rack/session/abstract/id.rb:266:in `context'
 d36f7208 | /usr/share/gems/gems/rack-2.2.8/lib/rack/session/abstract/id.rb:260:in `call'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/cookies.rb:697:in `call'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'
 d36f7208 | /usr/share/gems/gems/activesupport-6.1.7.6/lib/active_support/callbacks.rb:98:in `run_callbacks'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/actionable_exceptions.rb:18:in `call'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/debug_exceptions.rb:29:in `call'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
 d36f7208 | /usr/share/gems/gems/railties-6.1.7.6/lib/rails/rack/logger.rb:37:in `call_app'
 d36f7208 | /usr/share/gems/gems/railties-6.1.7.6/lib/rails/rack/logger.rb:28:in `call'
 d36f7208 | /usr/share/gems/gems/sprockets-rails-3.4.2/lib/sprockets/rails/quiet_assets.rb:13:in `call'
 d36f7208 | /usr/share/foreman/lib/foreman/middleware/logging_context_request.rb:11:in `call'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
 d36f7208 | /usr/share/gems/gems/request_store-1.5.1/lib/request_store/middleware.rb:19:in `call'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/request_id.rb:26:in `call'
 d36f7208 | /usr/share/gems/gems/katello-4.11.0/lib/katello/prevent_json_parsing.rb:12:in `call'
 d36f7208 | /usr/share/gems/gems/rack-2.2.8/lib/rack/method_override.rb:24:in `call'
 d36f7208 | /usr/share/gems/gems/rack-2.2.8/lib/rack/runtime.rb:22:in `call'
 d36f7208 | /usr/share/gems/gems/activesupport-6.1.7.6/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/executor.rb:14:in `call'
 d36f7208 | /usr/share/gems/gems/rack-2.2.8/lib/rack/sendfile.rb:110:in `call'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/ssl.rb:77:in `call'
 d36f7208 | /usr/share/gems/gems/actionpack-6.1.7.6/lib/action_dispatch/middleware/host_authorization.rb:142:in `call'
 d36f7208 | /usr/share/gems/gems/secure_headers-6.5.0/lib/secure_headers/middleware.rb:11:in `call'
 d36f7208 | /usr/share/gems/gems/railties-6.1.7.6/lib/rails/engine.rb:539:in `call'
 d36f7208 | /usr/share/gems/gems/railties-6.1.7.6/lib/rails/railtie.rb:207:in `public_send'
 d36f7208 | /usr/share/gems/gems/railties-6.1.7.6/lib/rails/railtie.rb:207:in `method_missing'
 d36f7208 | /usr/share/gems/gems/rack-2.2.8/lib/rack/urlmap.rb:74:in `block in call'
 d36f7208 | /usr/share/gems/gems/rack-2.2.8/lib/rack/urlmap.rb:58:in `each'
 d36f7208 | /usr/share/gems/gems/rack-2.2.8/lib/rack/urlmap.rb:58:in `call'
 d36f7208 | /usr/share/gems/gems/puma-6.4.0/lib/puma/configuration.rb:272:in `call'
 d36f7208 | /usr/share/gems/gems/puma-6.4.0/lib/puma/request.rb:100:in `block in handle_request'
 d36f7208 | /usr/share/gems/gems/puma-6.4.0/lib/puma/thread_pool.rb:378:in `with_force_shutdown'
 d36f7208 | /usr/share/gems/gems/puma-6.4.0/lib/puma/request.rb:99:in `handle_request'
 d36f7208 | /usr/share/gems/gems/puma-6.4.0/lib/puma/server.rb:443:in `process_client'
 d36f7208 | /usr/share/gems/gems/puma-6.4.0/lib/puma/server.rb:241:in `block in run'
 d36f7208 | /usr/share/gems/gems/puma-6.4.0/lib/puma/thread_pool.rb:155:in `block in spawn_thread'
 d36f7208 | /usr/share/gems/gems/logging-2.3.1/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2024-02-14T10:53:09 [W|app|d36f7208] Rolling back due to a problem: [#<Orchestration::Task:0x00007fb6148f78d0 @name="Create realm entry for test-u22.sub.domain.com", @id="Create realm entry for test-u22.sub.domain.com", @status="failed", @priority=1, @action=[#<Host::Managed id: nil, name: "test-u22.sub.domain.com", last_compile: nil, last_report: nil, updated_at: nil, created_at: nil, root_pass: nil, architecture_id: 1, operatingsystem_id: 8, ptable_id: 134, medium_id: 18, build: true, comment: "", disk: "", installed_at: nil, model_id: nil, hostgroup_id: 6, owner_id: 5, owner_type: "User", enabled: true, puppet_ca_proxy_id: nil, managed: true, use_image: nil, image_file: nil, uuid: nil, compute_resource_id: 1, puppet_proxy_id: nil, certname: nil, image_id: nil, organization_id: 1, location_id: 2, type: "Host::Managed", otp: nil, realm_id: 3, compute_profile_id: 2, provision_method: "build", grub_pass: nil, global_status: 0, lookup_value_matcher: [FILTERED], pxe_loader: "Grub2 UEFI", initiated_at: nil, build_errors: nil, creator_id: nil>, :set_realm], @created=1707904388.9350636, @timestamp=2024-02-14 09:53:09.000403587 UTC>]
2024-02-14T10:53:09 [I|app|d36f7208] Processed 1 tasks from queue 'Host::Managed Main', completed 0/14
2024-02-14T10:53:09 [E|app|d36f7208] Task 'Create realm entry for test-u22.sub.domain.com' *failed*
2024-02-14T10:53:09 [E|app|d36f7208] Task 'Set up compute instance test-u22.sub.domain.com' *canceled*
2024-02-14T10:53:09 [E|app|d36f7208] Task 'Query instance details for test-u22.sub.domain.com' *canceled*
2024-02-14T10:53:09 [E|app|d36f7208] Task 'Create DHCP Settings for test-u22.sub.domain.com' *canceled*
2024-02-14T10:53:09 [E|app|d36f7208] Task 'Create IPv4 DNS record for test-u22.sub.domain.com' *canceled*
2024-02-14T10:53:09 [E|app|d36f7208] Task 'Create Reverse IPv4 DNS record for test-u22.sub.domain.com' *canceled*
2024-02-14T10:53:09 [E|app|d36f7208] Task 'Creating IPv4 in External IPAM for test-u22.sub.domain.com' *canceled*
2024-02-14T10:53:09 [E|app|d36f7208] Task 'Creating IPv4 in External IPAM for ' *canceled*
2024-02-14T10:53:09 [E|app|d36f7208] Task 'Deploy TFTP PXELinux config for test-u22.sub.domain.com' *canceled*
2024-02-14T10:53:09 [E|app|d36f7208] Task 'Deploy TFTP PXEGrub2 config for test-u22.sub.domain.com' *canceled*
2024-02-14T10:53:09 [E|app|d36f7208] Task 'Deploy TFTP PXEGrub config for test-u22.sub.domain.com' *canceled*
2024-02-14T10:53:09 [E|app|d36f7208] Task 'Deploy TFTP iPXE config for test-u22.sub.domain.com' *canceled*
2024-02-14T10:53:09 [E|app|d36f7208] Task 'Fetch TFTP boot files for test-u22.sub.domain.com' *canceled*
2024-02-14T10:53:09 [E|app|d36f7208] Task 'Power up compute instance test-u22.sub.domain.com' *canceled*
2024-02-14T10:53:09 [E|app|d36f7208] Failed to save: Failed to create test-u22.sub.domain.com's realm entry: ERF12-5287 [ProxyAPI::ProxyException]: Unable to create realm entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fm01.sub.domain.com:9090/realm/SUB.DOMAIN.COM
2024-02-14T10:53:09 [I|app|d36f7208]   Rendered hosts/new.html.erb within layouts/application (Duration: 444.5ms | Allocations: 479721)
2024-02-14T10:53:09 [I|app|d36f7208]   Rendered layouts/base.html.erb (Duration: 15.6ms | Allocations: 23906)
2024-02-14T10:53:09 [I|app|d36f7208]   Rendered layout layouts/application.html.erb (Duration: 466.0ms | Allocations: 515200)
2024-02-14T10:53:09 [I|app|d36f7208] Completed 200 OK in 727ms (Views: 446.1ms | ActiveRecord: 36.9ms | Allocations: 578896)

I suspect this happens since the latest ipa-server update. With the latest version the user ticket requires PAC information which is only added if the user has a SID assigned, i.e. an ipaNTSecurityIdentifier.

If you have access to redhat solutions:

The log file krb5kdc.log on the IPA server will contain errors with tag “S4U2PROXY_EVIDENCE_TKT_WITHOUT_PAC” each time you have tried.

We have added the objectClass ipaNTUserAttrs to the realm-proxy user and assigned a ipaNTSecurityIdentifier. After that the realm-proxy can get a ticket with pac information and it’s working again…

You may be able to run

# ipa config-mod --enable-sid --add-sids

to add sids to all users, but this only works if all uids and gids in your directory have numbers in the id-range configured for the ipa server.

1 Like

Thank you for the suggestion.

I don’t see any “*_PAC” errors in ‘krb5kdc.log’, and all users can authenticate fine including the account used by foreman-proxy:

user@fm01:~$ KRB5_TRACE=/dev/stdout sudo -u foreman-proxy kinit foreman-admin@DOMAIN.COM -k -t /etc/foreman-proxy/freeipa.keytab

user@fm01:~$ sudo -u foreman-proxy klist
Ticket cache: KCM:992:29270
Default principal: foreman-admin@DOMAIN.COM

Valid starting     Expires            Service principal
14/02/24 14:29:21  15/02/24 14:23:30  krbtgt/DOMAIN.COM@DOMAIN.COM

I’m not sure if this is significant but FreeIPA runs on Fedora 37.

user@ipa:~$ ipa --version
VERSION: 4.10.1, API_VERSION: 2.251

kinit isn’t the problem. Use the IPA API with the ticket you have got is.

After the kinit, run something like ipa host-find and see if that works.

Either way, the krb5kdc.log will contain a message for each ticket issued or failed. When you get the error in foreman there must be a log message in krb5kdc.log indicating the reason why it failed.

1 Like

After creating an account for redhat solutions, I’m going through matches for “KDC has no support for encryption type”, but so far have found nothing helpful yet.

user@fm01:~$ sudo klist -k -e /etc/foreman-proxy/freeipa.keytab
Keytab name: FILE:/etc/foreman-proxy/freeipa.keytab
KVNO Principal
---- --------------------------------------------------------------------------
   2 foreman-admin@DOMAIN.COM (aes256-cts-hmac-sha1-96)
   2 foreman-admin@DOMAIN.COM (aes128-cts-hmac-sha1-96)

That seems to work fine:

user@fm01:~$ KRB5_TRACE=/dev/stdout sudo -u foreman-proxy ipa host-find
ipa: ERROR: Could not create log_dir '/usr/share/foreman-proxy/.ipa/log'
ipa: WARNING: Failed to write schema: [Errno 13] Permission denied: '/usr/share/foreman-proxy/.cache'
ipa: WARNING: Failed to write server info: [Errno 13] Permission denied: '/usr/share/foreman-proxy/.cache'
ipa: WARNING: Search result has been truncated: Configured size limit exceeded
-----------------
100 hosts matched
-----------------
  Host name: xyz.sub.domain.com
  [...]

I’m not seeing these logs on the IPA servers. I did a packet capture while creating a host and there’s no Kerberos traffic to be seen at all… The only thing I see when trying to create a host is Foreman completing a DNS lookup, no Kerberos.

Oh, sorry. I have initially looked at the production.log and noticed the error message I have seen before and assumed…

However, the proxy log says the reason why it fails in your case:

You don’t seem to have a realm SUB.DOMAIN.COM configured in foreman. Although it does make me wonder, how it came up with that to begin with.

Indeed, but the realm is there. However, I can’t remember if realms can be auto-detected or must be manually created.

I tried to create a host without configuring a realm for it and got a similar error but for DHCP, so I think I have an underlying issue here that’s affecting both and possibly more…

You must configure each realm. It must appear in the Web GUI, Infrastructure - Realms list.

So the “none found” message can be ignored and realms must be added manually.