Hide Forgot
Description of problem: ============================== Test automation is randomly getting failures in the web ui that look like a blank page with a sentence in the top left saying an unexpected lowlevel error occurred. Checking the production log, it looks like the puma server is crashing? on the back end (or gets a corrupted thread?), see the log snippet below. Version-Release number of selected component (if applicable): ================================ 5.7.0.6 How reproducible: ======================= 15% Steps to Reproduce: ========================== 1. None, its random 2. 3. Additional info: [----] I, [2016-10-24T00:16:50.462663 #16705:1543f20] INFO -- : Started POST "/ems_infra" for 127.0.0.1 at 2016-10-24 00:16:50 -0400 [----] I, [2016-10-24T00:16:50.463914 #16705:1543f20] INFO -- : Processing by EmsInfraController#create as */* [----] I, [2016-10-24T00:16:50.464041 #16705:1543f20] INFO -- : Parameters: {"utf8"=>"✓", "authenticity_token"=>"StixJZFSpKzdmEPY8dNZiIw7LxWLoY2BDv0xWY65IC/lBFFJLFjjAsadMPa6LZZ8hhbZFKKbNgu6DyvD7Fdirw==", "button"=>"add", "cred_type"=>"metrics", "name"=>"rhv40", "emstype"=>"rhevm", "zone"=>"default", "default_userid"=>"admin@internal", "default_password"=>"[FILTERED]", "default_verify"=>"[FILTERED]", "default_auth_status"=>"on", "default_hostname"=>"[FILTERED]", "default_api_port"=>"", "metrics_hostname"=>"[FILTERED]", "metrics_api_port"=>"5432", "metrics_userid"=>"ovirt_engine_history", "metrics_password"=>"[FILTERED]", "metrics_verify"=>"[FILTERED]", "metrics_auth_status"=>"on"} [----] I, [2016-10-24T00:16:50.590000 #16705:1543f20] INFO -- : Completed 200 OK in 126ms (Views: 1.2ms | ActiveRecord: 0.0ms) [----] I, [2016-10-24T00:16:51.141925 #16705:15425bc] INFO -- : Started GET "/favicon.ico" for 127.0.0.1 at 2016-10-24 00:16:51 -0400 [----] F, [2016-10-24T00:16:51.147265 #16705:15425bc] FATAL -- : [----] F, [2016-10-24T00:16:51.147338 #16705:15425bc] FATAL -- : ActionController::RoutingError (No route matches [GET] "/favicon.ico"): [----] F, [2016-10-24T00:16:51.147387 #16705:15425bc] FATAL -- : [----] F, [2016-10-24T00:16:51.147430 #16705:15425bc] FATAL -- : actionpack (5.0.0.1) lib/action_dispatch/middleware/debug_exceptions.rb:53:in `call' [----] F, [2016-10-24T00:16:51.147469 #16705:15425bc] FATAL -- : actionpack (5.0.0.1) lib/action_dispatch/middleware/show_exceptions.rb:31:in `call' [----] F, [2016-10-24T00:16:51.147506 #16705:15425bc] FATAL -- : railties (5.0.0.1) lib/rails/rack/logger.rb:36:in `call_app' [----] F, [2016-10-24T00:16:51.147542 #16705:15425bc] FATAL -- : railties (5.0.0.1) lib/rails/rack/logger.rb:26:in `call' [----] F, [2016-10-24T00:16:51.147578 #16705:15425bc] FATAL -- : request_store (1.3.1) lib/request_store/middleware.rb:9:in `call' [----] F, [2016-10-24T00:16:51.147614 #16705:15425bc] FATAL -- : actionpack (5.0.0.1) lib/action_dispatch/middleware/request_id.rb:24:in `call' [----] F, [2016-10-24T00:16:51.147650 #16705:15425bc] FATAL -- : rack (2.0.1) lib/rack/method_override.rb:22:in `call' [----] F, [2016-10-24T00:16:51.147700 #16705:15425bc] FATAL -- : rack (2.0.1) lib/rack/runtime.rb:22:in `call' [----] F, [2016-10-24T00:16:51.147750 #16705:15425bc] FATAL -- : activesupport (5.0.0.1) lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' [----] F, [2016-10-24T00:16:51.147789 #16705:15425bc] FATAL -- : actionpack (5.0.0.1) lib/action_dispatch/middleware/executor.rb:12:in `call' [----] F, [2016-10-24T00:16:51.147826 #16705:15425bc] FATAL -- : rack (2.0.1) lib/rack/sendfile.rb:111:in `call' [----] F, [2016-10-24T00:16:51.147862 #16705:15425bc] FATAL -- : railties (5.0.0.1) lib/rails/engine.rb:522:in `call' [----] F, [2016-10-24T00:16:51.147928 #16705:15425bc] FATAL -- : puma (3.3.0) lib/puma/configuration.rb:224:in `call' [----] F, [2016-10-24T00:16:51.147968 #16705:15425bc] FATAL -- : puma (3.3.0) lib/puma/server.rb:561:in `handle_request' [----] F, [2016-10-24T00:16:51.148005 #16705:15425bc] FATAL -- : puma (3.3.0) lib/puma/server.rb:406:in `process_client' [----] F, [2016-10-24T00:16:51.148042 #16705:15425bc] FATAL -- : puma (3.3.0) lib/puma/server.rb:271:in `block in run' [----] F, [2016-10-24T00:16:51.148078 #16705:15425bc] FATAL -- : puma (3.3.0) lib/puma/thread_pool.rb:111:in `call' [----] F, [2016-10-24T00:16:51.148113 #16705:15425bc] FATAL -- : puma (3.3.0) lib/puma/thread_pool.rb:111:in `block in spawn_thread' [----] F, [2016-10-24T00:16:51.148149 #16705:15425bc] FATAL -- : logging (2.1.0) lib/logging/diagnostic_context.rb:450:in `call' [----] F, [2016-10-24T00:16:51.148224 #16705:15425bc] FATAL -- : logging (2.1.0) lib/logging/diagnostic_context.rb:450:in `block in create_with_logging_context'
Joe, can you please look in to this? Thanks
Hi Dave, Can you please provide the evm.log and production.log when this happens? Or point me at an appliance for me to look at. I don't know why a missing route would cause the process to die. How often does this happen? Maybe it would be helpful to enable rails debug logging in the advanced setting in case it's a database connection issue: Change: :level_rails: info To: :level_rails: debug Then, wait until `tail -f log/production.log` starts showing debug messages. thanks
So we can't reproduce this, even on the build where we originally had multiple people hitting it, closing for now until we see it again.