Bug #17811

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

Added by Tomáš Strachota 10 months ago. Updated 3 months ago.

Status:Closed
Priority:Normal
Assigned To:Dominik Hlavac Duran
Category:Authentication
Target version:Team Marek Iteration 18
Difficulty: Bugzilla link:1357832
Found in release: Pull request:https://github.com/theforeman/foreman/pull/4668
Story points-
Velocity based estimate-
Release1.16.0Release relationshipAuto

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.


Related issues

Related to Foreman - Bug #11153: Traceback when LDAP authentication password is incorrect Ready For Testing 07/20/2015

Associated revisions

Revision 01b7dbb5
Added by Dominik Hlavac Duran 3 months ago

Fixes #17811 - Improve error message LDAP fail

History

#1 Updated by Tomáš Strachota 10 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 5 months ago

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

#3 Updated by Marek Hulán 5 months ago

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

#4 Updated by Dominik Hlavac Duran 5 months ago

  • Assigned To set to Dominik Hlavac Duran

#5 Updated by The Foreman Bot 3 months ago

  • Status changed from New to Ready For Testing
  • Pull request https://github.com/theforeman/foreman/pull/4668 added

#6 Updated by Marek Hulán 3 months ago

  • Related to Bug #11153: Traceback when LDAP authentication password is incorrect added

#7 Updated by Marek Hulán 3 months ago

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

#8 Updated by Marek Hulán 3 months ago

  • Release set to 1.16.0

#9 Updated by Dominik Hlavac Duran 3 months ago

  • Status changed from Ready For Testing to Closed
  • % Done changed from 0 to 100

Also available in: Atom PDF