Project

General

Profile

Actions

Bug #10231

closed

"undefined method `[]' for nil:NilClass (NoMethodError)" problem synching repo's

Added by Jorick Astrego almost 9 years ago. Updated over 5 years ago.

Status:
Resolved
Priority:
High
Assignee:
-
Category:
Repositories
Target version:
Difficulty:
Triaged:
Yes
Fixed in Releases:
Found in Releases:

Description

I have a daily sync plan but every day a random repo gets stuck and and other repo's remain in a neverending sync status. The error I see in the sync overview is this:

undefined method `[]' for nil:NilClass (NoMethodError) /opt/rh/ruby193/root/usr/share/gems/gems/katello-2.1.2/app/lib/actions/pulp/repository/presenters/abstract_sync_presenter.rb:52:in `task_result' /opt/rh/ruby193/root/usr/share/gems/gems/katello-2.1.2/app/lib/actions/pulp/repository/presenters/abstract_sync_presenter.rb:56:in `task_result_details' /opt/rh/ruby193/root/usr/share/gems/gems/katello-2.1.2/app/lib/actions/pulp/repository/presenters/yum_presenter.rb:84:in `task_details' /opt/rh/ruby193/root/usr/share/gems/gems/katello-2.1.2/app/lib/actions/pulp/repository/presenters/yum_presenter.rb:120:in `cancelled?' /opt/rh/ruby193/root/usr/share/gems/gems/katello-2.1.2/app/lib/actions/pulp/repository/presenters/yum_presenter.rb:30:in `humanized_details' /opt/rh/ruby193/root/usr/share/gems/gems/katello-2.1.2/app/lib/actions/pulp/repository/presenters/abstract_sync_presenter.rb:23:in `humanized_output' /opt/rh/ruby193/root/usr/share/gems/gems/katello-2.1.2/app/lib/actions/helpers/presenter.rb:21:in `humanized_output' /opt/rh/ruby193/root/usr/share/gems/gems/katello-2.1.2/app/lib/actions/helpers/presenter.rb:45:in `map' /opt/rh/ruby193/root/usr/share/gems/gems/katello-2.1.2/app/lib/actions/helpers/presenter.rb:45:in `humanized_output' /opt/rh/ruby193/root/usr/share/gems/gems/katello-2.1.2/app/lib/actions/helpers/presenter.rb:21:in `humanized_output' /opt/rh/ruby193/root/usr/share/gems/gems/foreman-tasks-0.6.10/app/models/foreman_tasks/task/dynflow_task.rb:72:in `get_humanized' /opt/rh/ruby193/root/usr/share/gems/gems/foreman-tasks-0.6.10/app/models/foreman_tasks/task/dynflow_task.rb:53:in `humanized' /opt/rh/ruby193/root/usr/share/gems/gems/katello-2.1.2/app/controllers/katello/sync_management_controller.rb:81:in `format_sync_progress' /opt/rh/ruby193/root/usr/share/gems/gems/katello-2.1.2/app/controllers/katello/sync_management_controller.rb:57:in `block in sync_status' /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/relation/delegation.rb:6:in `map' /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/relation/delegation.rb:6:in `map' /opt/rh/ruby193/root/usr/share/gems/gems/katello-2.1.2/app/controllers/katello/sync_management_controller.rb:57:in `sync_status' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/implicit_render.rb:4:in `send_action' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/base.rb:167:in `process_action' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rendering.rb:10:in `process_action' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/callbacks.rb:18:in `block in process_action' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:603:in `block (2 levels) in run_2142572655563027608__process_action__1720234113896349882__callbacks' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in conditional_callback_around_11362' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:326:in `around' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:310:in `_callback_around_3087' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_11362' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:580:in `block in _run_2142572655563027608__process_action__1720234113896349882__callbacks' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in conditional_callback_around_11361' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:326:in `around' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:310:in `_callback_around_13' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_11361' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:414:in `_run_2142572655563027608__process_action__1720234113896349882__callbacks' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_process_action_callbacks' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/callbacks.rb:17:in `process_action' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rescue.rb:29:in `process_action' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:30:in `block in process_action' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `block in instrument' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications/instrumenter.rb:20:in `instrument' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `instrument' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:29:in `process_action' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/params_wrapper.rb:207:in `process_action' /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/railties/controller_runtime.rb:18:in `process_action' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/base.rb:121:in `process' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/rendering.rb:45:in `process' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:203:in `dispatch' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rack_delegation.rb:14:in `dispatch' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:246:in `block in action' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in `dispatch' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:36:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:68:in `block in call' /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `each' /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:600:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/engine.rb:479:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/railtie/configurable.rb:30:in `method_missing' /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:68:in `block in call' /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `each' /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:600:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/apipie-rails-0.2.6/lib/apipie/extractor/recorder.rb:97:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/apipie-rails-0.2.6/lib/apipie/middleware/checksum_in_headers.rb:27:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/best_standards_support.rb:17:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/etag.rb:23:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/conditionalget.rb:25:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/head.rb:14:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/params_parser.rb:21:in `call' /usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:9:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/flash.rb:242:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:205:in `context' /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:200:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/cookies.rb:339:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/query_cache.rb:64:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/connection_adapters/abstract/connection_pool.rb:473:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `_run__2989097509605985023__call__1292538919985333051__callbacks' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_call_callbacks' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:27:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/remote_ip.rb:31:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/show_exceptions.rb:56:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/katello-2.1.2/lib/katello/middleware/silenced_logger.rb:29:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/request_id.rb:22:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/methodoverride.rb:21:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/runtime.rb:17:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/cache/strategy/local_cache.rb:72:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/lock.rb:15:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:136:in `forward' /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:245:in `fetch' /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:185:in `lookup' /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:66:in `call!' /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:51:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/engine.rb:479:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/application.rb:223:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/railtie/configurable.rb:30:in `method_missing' /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/builder.rb:134:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:64:in `block in call' /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:49:in `each' /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:49:in `call' /usr/lib/ruby/gems/1.8/gems/passenger-4.0.18/lib/phusion_passenger/rack/thread_handler_extension.rb:77:in `process_request' /usr/lib/ruby/gems/1.8/gems/passenger-4.0.18/lib/phusion_passenger/request_handler/thread_handler.rb:140:in `accept_and_process_next_request' /usr/lib/ruby/gems/1.8/gems/passenger-4.0.18/lib/phusion_passenger/request_handler/thread_handler.rb:108:in `main_loop' /usr/lib/ruby/gems/1.8/gems/passenger-4.0.18/lib/phusion_passenger/request_handler.rb:441:in `block (3 levels) in start_threads' /opt/rh/ruby193/root/usr/share/gems/gems/logging-1.8.1/lib/logging/diagnostic_context.rb:323:in `call' /opt/rh/ruby193/root/usr/share/gems/gems/logging-1.8.1/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context'

In the tomcat6 log, I see this error at the same time. Restarting tomcat6 and cancelling the current synching tasks fixes it for a while. Manual synching of a lot of repo's leads to the same error.

INFO: Server startup in 18682 ms
Apr 21, 2015 5:47:43 PM org.apache.catalina.loader.WebappClassLoader loadClass
INFO: Illegal access: this web application instance has been stopped already. Could not load com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask. The eventual following stack trace is caused by an error thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access, and has no functional impact.
java.lang.IllegalStateException
at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1369)
at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1329)
at com.mchange.v2.resourcepool.BasicResourcePool.checkIdleResources(BasicResourcePool.java:1481)
at com.mchange.v2.resourcepool.BasicResourcePool.access$2000(BasicResourcePool.java:32)
at com.mchange.v2.resourcepool.BasicResourcePool$CheckIdleResourcesTask.run(BasicResourcePool.java:1964)
at java.util.TimerThread.mainLoop(Timer.java:555)
at java.util.TimerThread.run(Timer.java:505)

Exception in thread "Timer-1" java.lang.NoClassDefFoundError: com/mchange/v2/resourcepool/BasicResourcePool$AsyncTestIdleResourceTask
at com.mchange.v2.resourcepool.BasicResourcePool.checkIdleResources(BasicResourcePool.java:1481)
at com.mchange.v2.resourcepool.BasicResourcePool.access$2000(BasicResourcePool.java:32)
at com.mchange.v2.resourcepool.BasicResourcePool$CheckIdleResourcesTask.run(BasicResourcePool.java:1964)
at java.util.TimerThread.mainLoop(Timer.java:555)
at java.util.TimerThread.run(Timer.java:505)
Caused by: java.lang.ClassNotFoundException: com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask
at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1483)
at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1329)
... 5 more

Actions #1

Updated by Jorick Astrego almost 9 years ago

Got things going again. There were a lot of "Actions::Katello::Repository::NodeMetadataGenerate" tasks running without ending. I rebooted the machine and they ended up paused. Then I resumed them one by one and I can sync the repos again.

Actions #2

Updated by Eric Helms almost 9 years ago

The NodeMetadataGenerate tasks are getting a slight re-work, and we have an open issue for 2.2.1 to better handle timeouts for them http://projects.theforeman.org/issues/10295

Actions #3

Updated by Eric Helms almost 9 years ago

  • translation missing: en.field_release set to 51
  • Triaged changed from No to Yes

Going to set this to 2.2.1 and see if it still occurs after the final release.

Actions #4

Updated by Eric Helms almost 9 years ago

  • Status changed from New to Need more information

Jorick,

Are you still seeing this with the 2.2 release?

Actions #5

Updated by Eric Helms almost 9 years ago

  • translation missing: en.field_release changed from 51 to 55
Actions #6

Updated by Jorick Astrego almost 9 years ago

No, it looks ok so far ;-)

I had to force unlock some of the old sync tasks to get things going though

Actions #7

Updated by Eric Helms almost 9 years ago

  • Status changed from Need more information to Resolved
  • translation missing: en.field_release changed from 55 to 51

Moving to resolved -- if you still see the issue down the road please re-open. Thanks!

Actions

Also available in: Atom PDF