Attachment 900772 Details for Bug 1103151 – production.log trace with debug on.

production.log trace with debug on.

production.log (text/x-log), 16.31 KB, created by Lee Yarwood on 2014-05-30 11:38:13 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Lee Yarwood

Created: 2014-05-30 11:38:13 UTC

Size: 16.31 KB

patch

obsolete

>10139 Started GET "/foreman_tasks/tasks/aa5694b0-6b69-40ab-8bb8-6a751ada855a" for 192.168.110.1 at 2014-05-30 07:09:22 -0400
>10140 Client connected.
>10141 Connected to server.
>10142 Processing by ForemanTasks::TasksController#show as */*
>10143   Parameters: {"id"=>"aa5694b0-6b69-40ab-8bb8-6a751ada855a"}
>10144   ^[[1m^[[35mUser Load (0.5ms)^[[0m  SELECT "users".* FROM "users" WHERE "users"."id" = $1 LIMIT 1  [["id", 1]]
>10145 Setting current user thread-local variable to admin
>10146   ^[[1m^[[36mSetting Load (0.4ms)^[[0m  ^[[1mSELECT "settings".* FROM "settings" WHERE "settings"."name" = 'authorize_login_delegation' ORDER BY name LIMIT 1^[[0m
>10147   ^[[1m^[[35mSetting Load (0.2ms)^[[0m  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'idle_timeout' ORDER BY name LIMIT 1
>10148   ^[[1m^[[36mForemanTasks::Task Load (0.3ms)^[[0m  ^[[1mSELECT "foreman_tasks_tasks".* FROM "foreman_tasks_tasks" WHERE "foreman_tasks_tasks"."id" = $1 LIMIT 1^[[0m  [["id", "aa5694b0-6b69-40ab-8bb8-6a751ada855a"]]
>10149 
>10150 
>10151 Started GET "/unattended/provision?token=82892021-907e-462b-a0b5-8210b0a3d1e7" for ::1 at 2014-05-30 07:09:22 -0400
>10152   ^[[1m^[[35mSetting Load (0.3ms)^[[0m  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'dynflow_enable_console' ORDER BY name LIMIT 1
>10153   ^[[1m^[[36mUser Load (0.5ms)^[[0m  ^[[1mSELECT "users".* FROM "users" INNER JOIN "foreman_tasks_locks" ON "users"."id" = "foreman_tasks_locks"."resource_id" WHERE "foreman_tasks_locks"."task_id" = 'aa5694b0-6b69-40ab-8bb8-6a751ada855a' AND "foreman_tasks_locks"."      resource_type" = 'User' ORDER BY firstname LIMIT 1^[[0m
>10154   ^[[1m^[[35mForemanTasks::Lock Load (0.1ms)^[[0m  SELECT "foreman_tasks_locks".* FROM "foreman_tasks_locks" WHERE "foreman_tasks_locks"."task_id" = 'aa5694b0-6b69-40ab-8bb8-6a751ada855a'
>10155   Rendered /opt/rh/ruby193/root/usr/share/gems/gems/foreman-tasks-0.5.5/app/views/foreman_tasks/tasks/show.html.erb within layouts/application (124.2ms)
>10156 Processing by UnattendedController#provision as */*
>10157   Parameters: {"token"=>"82892021-907e-462b-a0b5-8210b0a3d1e7"}
>10158   ^[[1m^[[35mHost::Managed Load (1.7ms)^[[0m  SELECT hosts.* FROM "hosts" INNER JOIN "tokens" ON "tokens"."host_id" = "hosts"."id" WHERE "hosts"."type" IN ('Host::Managed') AND "tokens"."value" = '82892021-907e-462b-a0b5-8210b0a3d1e7' AND (expires >= '2014-05-30 11      :09:22') LIMIT 1
>10159   ^[[1m^[[36mSetting Load (0.3ms)^[[0m  ^[[1mSELECT "settings".* FROM "settings" WHERE "settings"."name" = 'use_gravatar' ORDER BY name LIMIT 1^[[0m
>10160   Rendered home/_user_dropdown.html.erb (10.6ms)
>10161 Read fragment views/tabs_and_title_records-1 (0.1ms)
>10162   Rendered home/_org_switcher.html.erb (0.4ms)
>10163   Rendered home/_submenu.html.erb (3.1ms)
>10164   Rendered home/_submenu.html.erb (2.8ms)
>10165   Rendered home/_submenu.html.erb (2.0ms)
>10166   Rendered home/_submenu.html.erb (2.0ms)
>10167   Rendered home/_submenu.html.erb (1.2ms)
>10168   Rendered home/_submenu.html.erb (2.2ms)
>10169 Write fragment views/tabs_and_title_records-1 (0.8ms)
>10170   Rendered home/_topbar.html.erb (88.8ms)
>10171   Rendered layouts/base.html.erb (93.1ms)
>10172 Completed 200 OK in 382ms (Views: 285.7ms | ActiveRecord: 6.2ms)
>10173   ^[[1m^[[36mOperatingsystem Load (0.4ms)^[[0m  ^[[1mSELECT "operatingsystems".* FROM "operatingsystems" WHERE "operatingsystems"."id" = 1 ORDER BY operatingsystems.name LIMIT 1^[[0m
>10174 Found 525400fce06e.example.com
>10175   ^[[1m^[[35mSetting Load (0.4ms)^[[0m  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'manage_puppetca' ORDER BY name LIMIT 1
>10176   ^[[1m^[[36mSmartProxy Load (0.3ms)^[[0m  ^[[1mSELECT "smart_proxies".* FROM "smart_proxies" WHERE "smart_proxies"."id" = 1 ORDER BY smart_proxies.name LIMIT 1^[[0m
>10177   ^[[1m^[[35mSetting Load (0.3ms)^[[0m  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'ssl_certificate' ORDER BY name LIMIT 1
>10178   ^[[1m^[[36mSetting Load (0.2ms)^[[0m  ^[[1mSELECT "settings".* FROM "settings" WHERE "settings"."name" = 'ssl_ca_file' ORDER BY name LIMIT 1^[[0m
>10179   ^[[1m^[[35mSetting Load (0.2ms)^[[0m  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'ssl_priv_key' ORDER BY name LIMIT 1
>10180 Remove puppet certificate for 525400fce06e.example.com
>10181   ^[[1m^[[36mSetting Load (0.6ms)^[[0m  ^[[1mSELECT "settings".* FROM "settings" WHERE "settings"."name" = 'use_uuid_for_certificates' ORDER BY name LIMIT 1^[[0m
>10182 Adding autosign entry for 525400fce06e.example.com
>10183   ^[[1m^[[35mPtable Load (0.4ms)^[[0m  SELECT "ptables".* FROM "ptables" WHERE "ptables"."id" = 7 ORDER BY ptables.name LIMIT 1
>10184   ^[[1m^[[36mSetting Load (0.3ms)^[[0m  ^[[1mSELECT "settings".* FROM "settings" WHERE "settings"."name" = 'safemode_render' ORDER BY name LIMIT 1^[[0m
>10185   ^[[1m^[[35mArchitecture Load (0.3ms)^[[0m  SELECT "architectures".* FROM "architectures" WHERE "architectures"."id" = 1 LIMIT 1
>10186   ^[[1m^[[36mMedium Load (0.3ms)^[[0m  ^[[1mSELECT "media".* FROM "media" WHERE "media"."id" = 7 ORDER BY media.name LIMIT 1^[[0m
>10187 Operation FAILED: bad URI(absolute but no path): http://
>10188 /opt/rh/ruby193/root/usr/share/ruby/uri/common.rb:146:in `split'
>10189 /opt/rh/ruby193/root/usr/share/ruby/uri/common.rb:211:in `parse'
>10190 /opt/rh/ruby193/root/usr/share/ruby/uri/common.rb:747:in `parse'
>10191 /usr/share/foreman/app/models/operatingsystem.rb:107:in `medium_vars_to_uri'
>10192 /usr/share/foreman/app/models/operatingsystem.rb:103:in `medium_uri'
>10193 /usr/share/foreman/app/models/operatingsystems/redhat.rb:8:in `mediumpath'
>10194 /usr/share/foreman/app/controllers/unattended_controller.rb:213:in `kickstart_attributes'
>10195 /usr/share/foreman/app/controllers/unattended_controller.rb:183:in `load_template_vars'
>10196 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:575:in `block (3 levels) in _run__2197962609456080826__process_action__41550271371118848__callbacks'
>10197 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_6966'
>10198 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:326:in `around'
>10199 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:310:in `_callback_around_2189'
>10200 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_6966'
>10201 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:526:in `block (2 levels) in _run__2197962609456080826__process_action__41550271371118848__callbacks'
>10202 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_6965'
>10203 /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:33:in `clear_thread'
>10204 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_6965'
>10205 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:415:in `block in _run__2197962609456080826__process_action__41550271371118848__callbacks'
>10206 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_6964'
>10207 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:326:in `around'
>10208 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:310:in `_callback_around_13'
>10209 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_6964'
>10210 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:414:in `_run__2197962609456080826__process_action__41550271371118848__callbacks'
>10211 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'
>10212 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_process_action_callbacks'
>10213 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'
>10214 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/callbacks.rb:17:in `process_action'
>10215 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rescue.rb:29:in `process_action'
>10216 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:30:in `block in process_action'
>10217 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `block in instrument'
>10218 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
>10219 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `instrument'
>10220 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:29:in `process_action'
>10221 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/params_wrapper.rb:207:in `process_action'
>10222 /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
>10223 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/base.rb:121:in `process'
>10224 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/rendering.rb:45:in `process'
>10225 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:203:in `dispatch'
>10226 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rack_delegation.rb:14:in `dispatch'
>10227 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:246:in `block in action'
>10228 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in `call'
>10229 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in `dispatch'
>10230 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:36:in `call'
>10231 /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:68:in `block in call'
>10232 /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `each'
>10233 /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `call'
>10234 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:600:in `call'
>10235 /opt/rh/ruby193/root/usr/share/gems/gems/apipie-rails-0.1.2/lib/apipie/static_dispatcher.rb:65:in `call'
>10236 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in `call'
>10237 /opt/rh/ruby193/root/usr/share/gems/gems/apipie-rails-0.1.2/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
>10238 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/best_standards_support.rb:17:in `call'
>10239 /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/etag.rb:23:in `call'
>10240 /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/conditionalget.rb:25:in `call'
>10241 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/head.rb:14:in `call'
>10242 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/params_parser.rb:21:in `call'
>10243 /usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:9:in `call'
>10244 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/flash.rb:242:in `call'
>10245 /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:205:in `context'
>10246 /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:200:in `call'
>10247 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/cookies.rb:339:in `call'
>10248 /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/query_cache.rb:64:in `call'
>10249 /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/connection_adapters/abstract/connection_pool.rb:473:in `call'
>10250 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
>10251 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `_run__3142966463933648451__call__34694390599730244__callbacks'
>10252 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'
>10253 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_call_callbacks'
>10254 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'
>10255 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:27:in `call'
>10256 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/remote_ip.rb:31:in `call'
>10257 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call'
>10258 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'
>10259 /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:26:in `call_app'
>10260 /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:16:in `call'
>10261 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/request_id.rb:22:in `call'
>10262 /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/methodoverride.rb:21:in `call'
>10263 /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/runtime.rb:17:in `call'
>10264 /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/cache/strategy/local_cache.rb:72:in `call'
>10265 /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/lock.rb:15:in `call'
>10266 /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in `call'
>10267 /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:136:in `forward'
>10268 /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:245:in `fetch'
>10269 /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:185:in `lookup'
>10270 /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:66:in `call!'
>10271 /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:51:in `call'
>10272 /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/engine.rb:479:in `call'
>10273 /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/application.rb:223:in `call'
>10274 /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/railtie/configurable.rb:30:in `method_missing'
>10275 /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/builder.rb:134:in `call'
>10276 /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:64:in `block in call'
>10277 /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:49:in `each'
>10278 /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:49:in `call'
>10279 /usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/rack/thread_handler_extension.rb:77:in `process_request'
>10280 /usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler/thread_handler.rb:140:in `accept_and_process_next_request'
>10281 /usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler/thread_handler.rb:108:in `main_loop'
>10282 /usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler.rb:441:in `block (3 levels) in start_threads'
>10283 Completed 500 Internal Server Error in 1393ms
>10284 
>10285 NameError (uninitialized constant MultiJson::LoadError):
>10286   lib/middleware/catch_json_parse_errors.rb:10:in `rescue in call'
>10287   lib/middleware/catch_json_parse_errors.rb:8:in `call'
>10288 
>10289 
>10290 
>10291

Actions: View

Attachments on bug 1103151: 900771 | 900772