[----] I, [2018-09-12T16:56:07.005408 #2349:8dcf6b0] INFO -- : MIQ(MiqLdap#bind) Binding to LDAP: Host: [], User: []... [----] I, [2018-09-12T16:56:07.008039 #2349:8dcf6b0] INFO -- : MIQ(MiqLdap#bind) Binding to LDAP: Host: [], User: []... successful [----] I, [2018-09-12T16:56:07.012068 #2349:8dcf6b0] INFO -- : MIQ(Base.authenticate) userid: [] - User successfully validated by LDAP [----] I, [2018-09-12T16:56:07.015631 #2349:8dcf6b0] INFO -- : MIQ(MiqLdap#initialize) Server Settings: {:basedn=>nil, :bind_dn=>nil, :bind_pwd=>nil, :bind_timeout=>30, :follow_referrals=>false, :get_direct_groups=>true, :group_memberships_max_depth=>2, :ldaphost=>["", ""], :ldapport=>"389", :mode=>"ldap", :search_timeout=>30, :user_suffix=>nil, :user_type=>"samaccountname", :amazon_key=>nil, :amazon_secret=>nil, :default_group_for_users=>"EvmGroup-user", :domain_prefix=>"", :local_login_disabled=>false, :saml_enabled=>false, :sso_enabled=>false, :user_proxies=>[{}], :httpd_role=>false, :amazon_role=>false, :ldap_role=>false} [----] I, [2018-09-12T16:56:07.016434 #2349:8dcf6b0] INFO -- : MiqLdap.connection: Resolved host [] has these IP Address: [""] [----] I, [2018-09-12T16:56:07.016500 #2349:8dcf6b0] INFO -- : MiqLdap.connection: Connecting to IP Address [] [----] I, [2018-09-12T16:56:07.017016 #2349:8dcf6b0] INFO -- : options: {:auth=>{:basedn=>nil, :bind_dn=>nil, :bind_pwd=>nil, :bind_timeout=>30, :follow_referrals=>false, :get_direct_groups=>true, :group_memberships_max_depth=>2, :ldaphost=>["", ""], :ldapport=>"389", :mode=>"ldap", :search_timeout=>30, :user_suffix=>nil, :user_type=>"samaccountname", :amazon_key=>nil, :amazon_secret=>nil, :default_group_for_users=>"EvmGroup-user", :domain_prefix=>"", :local_login_disabled=>false, :saml_enabled=>false, :sso_enabled=>false, :user_proxies=>[{}], :httpd_role=>false, :amazon_role=>false, :ldap_role=>false}, :host=>"", :port=>"389"} [----] I, [2018-09-12T16:56:07.017112 #2349:8dcf6b0] INFO -- : MIQ(MiqLdap#bind) Binding to LDAP: Host: [], User: []... [----] E, [2018-09-12T16:56:07.017920 #2349:8dcf6b0] ERROR -- : MIQ(MiqLdap#bind) Binding to LDAP: Host: [], User: [], 'Invalid binding information' [----] E, [2018-09-12T16:56:07.020832 #2349:8dcf6b0] ERROR -- : [NoMethodError]: undefined method `get_user_object' for nil:NilClass Method:[block in method_missing] [----] E, [2018-09-12T16:56:07.021009 #2349:8dcf6b0] ERROR -- : /var/www/miq/vmdb/app/models/authenticator/ldap.rb:48:in `create_user_from_ldap' /var/www/miq/vmdb/app/models/authenticator/ldap.rb:24:in `autocreate_user' /var/www/miq/vmdb/app/models/authenticator/base.rb:66:in `authenticate' /var/www/miq/vmdb/app/models/user.rb:160:in `authenticate' /opt/rh/cfme-gemset/bundler/gems/cfme-api-7ef52af0e035/app/controllers/api/base_controller/authentication.rb:20:in `block in require_api_user_or_token' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_controller/metal/http_authentication.rb:97:in `authenticate' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_controller/metal/http_authentication.rb:87:in `authenticate_with_http_basic' /opt/rh/cfme-gemset/bundler/gems/cfme-api-7ef52af0e035/app/controllers/api/base_controller/authentication.rb:20:in `require_api_user_or_token' /opt/rh/cfme-gemset/gems/activesupport-5.0.6/lib/active_support/callbacks.rb:382:in `block in make_lambda' /opt/rh/cfme-gemset/gems/activesupport-5.0.6/lib/active_support/callbacks.rb:150:in `block (2 levels) in halting_and_conditional' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/abstract_controller/callbacks.rb:12:in `block (2 levels) in ' /opt/rh/cfme-gemset/gems/activesupport-5.0.6/lib/active_support/callbacks.rb:151:in `block in halting_and_conditional' /opt/rh/cfme-gemset/gems/activesupport-5.0.6/lib/active_support/callbacks.rb:454:in `block in call' /opt/rh/cfme-gemset/gems/activesupport-5.0.6/lib/active_support/callbacks.rb:454:in `each' /opt/rh/cfme-gemset/gems/activesupport-5.0.6/lib/active_support/callbacks.rb:454:in `call' /opt/rh/cfme-gemset/gems/activesupport-5.0.6/lib/active_support/callbacks.rb:101:in `__run_callbacks__' /opt/rh/cfme-gemset/gems/activesupport-5.0.6/lib/active_support/callbacks.rb:750:in `_run_process_action_callbacks' /opt/rh/cfme-gemset/gems/activesupport-5.0.6/lib/active_support/callbacks.rb:90:in `run_callbacks' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/abstract_controller/callbacks.rb:19:in `process_action' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_controller/metal/rescue.rb:20:in `process_action' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action' /opt/rh/cfme-gemset/gems/activesupport-5.0.6/lib/active_support/notifications.rb:164:in `block in instrument' /opt/rh/cfme-gemset/gems/activesupport-5.0.6/lib/active_support/notifications/instrumenter.rb:21:in `instrument' /opt/rh/cfme-gemset/gems/activesupport-5.0.6/lib/active_support/notifications.rb:164:in `instrument' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_controller/metal/instrumentation.rb:30:in `process_action' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_controller/metal/params_wrapper.rb:248:in `process_action' /opt/rh/cfme-gemset/gems/activerecord-5.0.6/lib/active_record/railties/controller_runtime.rb:18:in `process_action' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/abstract_controller/base.rb:126:in `process' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_controller/metal.rb:190:in `dispatch' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_controller/metal.rb:262:in `dispatch' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_dispatch/routing/route_set.rb:50:in `dispatch' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_dispatch/routing/route_set.rb:32:in `serve' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_dispatch/journey/router.rb:39:in `block in serve' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_dispatch/journey/router.rb:26:in `each' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_dispatch/journey/router.rb:26:in `serve' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_dispatch/routing/route_set.rb:727:in `call' /opt/rh/cfme-gemset/gems/secure_headers-3.0.3/lib/secure_headers/middleware.rb:10:in `call' /opt/rh/cfme-gemset/gems/rack-2.0.3/lib/rack/etag.rb:25:in `call' /opt/rh/cfme-gemset/gems/rack-2.0.3/lib/rack/conditional_get.rb:25:in `call' /opt/rh/cfme-gemset/gems/rack-2.0.3/lib/rack/head.rb:12:in `call' /opt/rh/cfme-gemset/gems/rack-2.0.3/lib/rack/session/abstract/id.rb:232:in `context' /opt/rh/cfme-gemset/gems/rack-2.0.3/lib/rack/session/abstract/id.rb:226:in `call' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_dispatch/middleware/cookies.rb:613:in `call' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_dispatch/middleware/callbacks.rb:38:in `block in call' /opt/rh/cfme-gemset/gems/activesupport-5.0.6/lib/active_support/callbacks.rb:97:in `__run_callbacks__' /opt/rh/cfme-gemset/gems/activesupport-5.0.6/lib/active_support/callbacks.rb:750:in `_run_call_callbacks' /opt/rh/cfme-gemset/gems/activesupport-5.0.6/lib/active_support/callbacks.rb:90:in `run_callbacks' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_dispatch/middleware/callbacks.rb:36:in `call' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_dispatch/middleware/remote_ip.rb:79:in `call' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_dispatch/middleware/debug_exceptions.rb:49:in `call' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_dispatch/middleware/show_exceptions.rb:31:in `call' /opt/rh/cfme-gemset/gems/railties-5.0.6/lib/rails/rack/logger.rb:36:in `call_app' /opt/rh/cfme-gemset/gems/railties-5.0.6/lib/rails/rack/logger.rb:26:in `call' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_dispatch/middleware/request_id.rb:24:in `call' /opt/rh/cfme-gemset/gems/rack-2.0.3/lib/rack/method_override.rb:22:in `call' /opt/rh/cfme-gemset/gems/rack-2.0.3/lib/rack/runtime.rb:22:in `call' /opt/rh/cfme-gemset/gems/activesupport-5.0.6/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' /opt/rh/cfme-gemset/gems/actionpack-5.0.6/lib/action_dispatch/middleware/executor.rb:12:in `call' /opt/rh/cfme-gemset/gems/rack-2.0.3/lib/rack/sendfile.rb:111:in `call' /opt/rh/cfme-gemset/gems/railties-5.0.6/lib/rails/engine.rb:522:in `call' /opt/rh/rh-ruby23/root/usr/share/gems/gems/puma-3.7.1/lib/puma/configuration.rb:232:in `call' /opt/rh/rh-ruby23/root/usr/share/gems/gems/puma-3.7.1/lib/puma/server.rb:578:in `handle_request' /opt/rh/rh-ruby23/root/usr/share/gems/gems/puma-3.7.1/lib/puma/server.rb:415:in `process_client' /opt/rh/rh-ruby23/root/usr/share/gems/gems/puma-3.7.1/lib/puma/server.rb:275:in `block in run' /opt/rh/rh-ruby23/root/usr/share/gems/gems/puma-3.7.1/lib/puma/thread_pool.rb:120:in `block in spawn_thread' [----] I, [2018-09-12T16:56:21.119846 #2242:e7f108] INFO -- : MIQ(MiqScheduleWorker::Runner#do_work) Number of scheduled items to be processed: 4.