Bug #17811

LDAP authentication SSL failures are not reported in an understandable way down the stack

Added by Tomáš Strachota 6 months ago. Updated 29 days ago.

Status:New
Priority:Normal
Assigned To:Dominik Hlavac Duran
Category:Authentication
Target version:Team Marek backlog
Difficulty: Bugzilla link:1357832
Found in release: Pull request:
Story points-
Velocity based estimate-

Description

Description of problem:

LDAP authentication failures are ofter reported as failures in other components of the stack, making it hard to spot and work on.

hammer -d -u test host list
...
[ INFO 2016-12-21T09:35:56 API] GET /api/hosts
[DEBUG 2016-12-21T09:35:56 API] Params: {
        "page" => 1,
    "per_page" => 1000
}
[DEBUG 2016-12-21T09:35:56 API] Headers: {
    :params => {
            "page" => 1,
        "per_page" => 1000
    }
}
[DEBUG 2016-12-21T09:35:56 API] Using authenticator: HammerCLIForeman::Api::InteractiveBasicAuth
[ERROR 2016-12-21T09:35:56 API] 500 Internal Server Error
[DEBUG 2016-12-21T09:35:56 API] {
    "error" => {
        "message" => "SSL_connect SYSCALL returned=5 errno=0 state=SSLv3 read finished A" 
    }
}
[ERROR 2016-12-21T09:35:56 Exception] SSL_connect SYSCALL returned=5 errno=0 state=SSLv3 read finished A
SSL_connect SYSCALL returned=5 errno=0 state=SSLv3 read finished A
[ERROR 2016-12-21T09:35:56 Exception] 

RestClient::InternalServerError (500 Internal Server Error):
    /usr/local/rvm/gems/ruby-2.3.0/gems/rest-client-2.0.0/lib/restclient/abstract_response.rb:223:in `exception_with_response'
    /usr/local/rvm/gems/ruby-2.3.0/gems/rest-client-2.0.0/lib/restclient/abstract_response.rb:103:in `return!'
    /usr/local/rvm/gems/ruby-2.3.0/gems/apipie-bindings-0.0.19/lib/apipie_bindings/api.rb:332:in `block in rest_client_call_block'
    /usr/local/rvm/gems/ruby-2.3.0/gems/rest-client-2.0.0/lib/restclient/request.rb:858:in `process_result'
    /usr/local/rvm/gems/ruby-2.3.0/gems/rest-client-2.0.0/lib/restclient/request.rb:776:in `block in transmit'
    /usr/local/rvm/rubies/ruby-2.3.0/lib/ruby/2.3.0/net/http.rb:853:in `start'
    /usr/local/rvm/gems/ruby-2.3.0/gems/rest-client-2.0.0/lib/restclient/request.rb:766:in `transmit'
    /usr/local/rvm/gems/ruby-2.3.0/gems/rest-client-2.0.0/lib/restclient/request.rb:215:in `execute'
    /usr/local/rvm/gems/ruby-2.3.0/gems/rest-client-2.0.0/lib/restclient/request.rb:52:in `execute'
    /usr/local/rvm/gems/ruby-2.3.0/gems/rest-client-2.0.0/lib/restclient/resource.rb:51:in `get'
    /usr/local/rvm/gems/ruby-2.3.0/gems/apipie-bindings-0.0.19/lib/apipie_bindings/api.rb:313:in `call_client'
    /usr/local/rvm/gems/ruby-2.3.0/gems/apipie-bindings-0.0.19/lib/apipie_bindings/api.rb:229:in `http_call'
    /usr/local/rvm/gems/ruby-2.3.0/gems/apipie-bindings-0.0.19/lib/apipie_bindings/api.rb:179:in `call_action'
    /usr/local/rvm/gems/ruby-2.3.0/gems/apipie-bindings-0.0.19/lib/apipie_bindings/api.rb:174:in `call'
    /usr/local/rvm/gems/ruby-2.3.0/gems/apipie-bindings-0.0.19/lib/apipie_bindings/resource.rb:21:in `call'
    /root/hammer/hammer-cli/lib/hammer_cli/apipie/command.rb:43:in `send_request'
    /root/hammer/hammer-cli-foreman/lib/hammer_cli_foreman/commands.rb:161:in `send_request'
    /root/hammer/hammer-cli-foreman/lib/hammer_cli_foreman/commands.rb:251:in `send_request'
    /root/hammer/hammer-cli-foreman/lib/hammer_cli_foreman/commands.rb:286:in `retrieve_all'
    /root/hammer/hammer-cli-foreman/lib/hammer_cli_foreman/commands.rb:270:in `execute'
    /usr/local/rvm/gems/ruby-2.3.0/gems/clamp-1.1.1/lib/clamp/command.rb:63:in `run'
    /root/hammer/hammer-cli/lib/hammer_cli/abstract.rb:24:in `run'
    /usr/local/rvm/gems/ruby-2.3.0/gems/clamp-1.1.1/lib/clamp/subcommand/execution.rb:11:in `execute'
    /usr/local/rvm/gems/ruby-2.3.0/gems/clamp-1.1.1/lib/clamp/command.rb:63:in `run'
    /root/hammer/hammer-cli/lib/hammer_cli/abstract.rb:24:in `run'
    /usr/local/rvm/gems/ruby-2.3.0/gems/clamp-1.1.1/lib/clamp/subcommand/execution.rb:11:in `execute'
    /usr/local/rvm/gems/ruby-2.3.0/gems/clamp-1.1.1/lib/clamp/command.rb:63:in `run'
    /root/hammer/hammer-cli/lib/hammer_cli/abstract.rb:24:in `run'
    /usr/local/rvm/gems/ruby-2.3.0/gems/clamp-1.1.1/lib/clamp/command.rb:132:in `run'
    ./bin/hammer:125:in `<main>'

Server logs:

2016-12-21T09:38:05 8a2b9de4 [app] [I] Started GET "/api/hosts?page=1&per_page=1000" for fe80::5054:ff:fef5:1b57 at 2016-12-21 09:38:05 +0000 
2016-12-21T09:38:05 8a2b9de4 [app] [I] Processing by Api::V2::HostsController#index as JSON 
2016-12-21T09:38:05 8a2b9de4 [app] [I]   Parameters: {"page"=>"1", "per_page"=>"1000", "apiv"=>"v2", :host=>{}}
2016-12-21T09:38:05 8a2b9de4 [app] [W] Action failed 
 | OpenSSL::SSL::SSLError: SSL_connect SYSCALL returned=5 errno=0 state=SSLv3 read finished A 
 | /usr/local/rvm/gems/ruby-2.3.0/gems/net-ldap-0.15.0/lib/net/ldap.rb:1303:in `new_connection'
 | /usr/local/rvm/gems/ruby-2.3.0/gems/net-ldap-0.15.0/lib/net/ldap.rb:854:in `block in bind'
 | /usr/local/rvm/gems/ruby-2.3.0/gems/net-ldap-0.15.0/lib/net/ldap/instrumentation.rb:16:in `block in instrument'
 | /usr/local/rvm/gems/ruby-2.3.0/gems/activesupport-4.2.7.1/lib/active_support/notifications.rb:164:in `block in instrument'
 | /usr/local/rvm/gems/ruby-2.3.0/gems/activesupport-4.2.7.1/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
 | /usr/local/rvm/gems/ruby-2.3.0/gems/activesupport-4.2.7.1/lib/active_support/notifications.rb:164:in `instrument'
 | /usr/local/rvm/gems/ruby-2.3.0/gems/net-ldap-0.15.0/lib/net/ldap/instrumentation.rb:15:in `instrument'
 | /usr/local/rvm/gems/ruby-2.3.0/gems/net-ldap-0.15.0/lib/net/ldap.rb:848:in `bind'
 | /usr/local/rvm/gems/ruby-2.3.0/gems/ldap_fluff-0.4.4/lib/ldap_fluff/freeipa.rb:12:in `bind?
 | /usr/local/rvm/gems/ruby-2.3.0/gems/ldap_fluff-0.4.4/lib/ldap_fluff/generic.rb:58:in `service_bind'
 | /usr/local/rvm/gems/ruby-2.3.0/gems/ldap_fluff-0.4.4/lib/ldap_fluff/generic.rb:20:in `user_exists?
 | /usr/local/rvm/gems/ruby-2.3.0/gems/ldap_fluff-0.4.4/lib/ldap_fluff/ldap_fluff.rb:63:in `block in valid_user?
 | /usr/local/rvm/gems/ruby-2.3.0/gems/ldap_fluff-0.4.4/lib/ldap_fluff/ldap_fluff.rb:94:in `block in instrument'
 | /usr/local/rvm/gems/ruby-2.3.0/gems/activesupport-4.2.7.1/lib/active_support/notifications.rb:164:in `block in instrument'
 | /usr/local/rvm/gems/ruby-2.3.0/gems/activesupport-4.2.7.1/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
 | /usr/local/rvm/gems/ruby-2.3.0/gems/activesupport-4.2.7.1/lib/active_support/notifications.rb:164:in `instrument'
 | /usr/local/rvm/gems/ruby-2.3.0/gems/ldap_fluff-0.4.4/lib/ldap_fluff/ldap_fluff.rb:93:in `instrument'
 | /usr/local/rvm/gems/ruby-2.3.0/gems/ldap_fluff-0.4.4/lib/ldap_fluff/ldap_fluff.rb:62:in `valid_user?
 | /root/foreman/foreman/app/models/auth_sources/auth_source_ldap.rb:61:in `authenticate'
 | /root/foreman/foreman/app/models/user.rb:189:in `try_to_login'
 | /root/foreman/foreman/app/services/sso/basic.rb:10:in `block in authenticate!
 | /usr/local/rvm/gems/ruby-2.3.0/gems/actionpack-4.2.7.1/lib/action_controller/metal/http_authentication.rb:97:in `authenticate'
 | /usr/local/rvm/gems/ruby-2.3.0/gems/actionpack-4.2.7.1/lib/action_controller/metal/http_authentication.rb:87:in `authenticate_with_http_basic'
 | /root/foreman/foreman/app/services/sso/basic.rb:8:in `authenticate!
 | /root/foreman/foreman/app/services/sso/basic.rb:17:in `authenticated?
 | /root/foreman/foreman/app/controllers/concerns/foreman/controller/authentication.rb:62:in `sso_authentication'
 | /root/foreman/foreman/app/controllers/concerns/foreman/controller/authentication.rb:14:in `authenticate'
 | /root/foreman/foreman/app/controllers/api/base_controller.rb:156:in `authorize'
...
2016-12-21T09:38:05 8a2b9de4 [app] [I]   Rendered api/v2/errors/standard_error.json.rabl within api/v2/layouts/error_layout (0.5ms)
2016-12-21T09:38:05 8a2b9de4 [app] [I] Completed 500 Internal Server Error in 13ms (Views: 3.4ms | ActiveRecord: 0.9ms)

500 internal server error is misleading, if the ssl issue is on ldaps connection.

Version-Release number of selected component (if applicable):
foreman 1.14

Steps to Reproduce:
1. Perform an action (through Hammer, for example) that would trigger a SSL handshake
2. Have the server drop the connection
3. Inspect the error reported by the tool used (Hammer, for example)

Actual results:
Unuseful error message such as

2016-06-10 16:52:08 [I] Completed 500 Internal Server Error in 116ms (Views: 0.4ms | ActiveRecord: 0.9ms)

Expected results:
More useful error message, that points out the target LDAP server has dropped the connection or had problems completing the request.

History

#1 Updated by Tomáš Strachota 6 months ago

  • Subject changed from LDAP authentication SSL failures are not reported in an understandable way down the stack to LDAP authentication SSL failures are not reported in an understandable way down the stack
  • Category set to Authentication
  • Target version set to Team Marek backlog

#2 Updated by Marek Hulán about 1 month ago

  • Target version changed from Team Marek backlog to Team Marek Iteration 15

#3 Updated by Marek Hulán about 1 month ago

  • Target version changed from Team Marek Iteration 15 to Team Marek backlog

#4 Updated by Dominik Hlavac Duran 29 days ago

  • Assigned To set to Dominik Hlavac Duran

Also available in: Atom PDF