Project

General

Profile

Bug #10231

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

Added by Jorick Astrego about 7 years ago. Updated almost 4 years ago.

Status:
Resolved
Priority:
High
Assignee:
-
Category:
Repositories
Target version:
Difficulty:
Triaged:
Yes
Bugzilla link:
Pull request:
Fixed in Releases:
Found in Releases:
Red Hat JIRA:

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

History

#1 Updated by Jorick Astrego about 7 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.

#2 Updated by Eric Helms about 7 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

#3 Updated by Eric Helms about 7 years ago

  • Legacy Backlogs Release (now unused) 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.

#4 Updated by Eric Helms about 7 years ago

  • Status changed from New to Need more information

Jorick,

Are you still seeing this with the 2.2 release?

#5 Updated by Eric Helms about 7 years ago

  • Legacy Backlogs Release (now unused) changed from 51 to 55

#6 Updated by Jorick Astrego about 7 years ago

No, it looks ok so far ;-)

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

#7 Updated by Eric Helms about 7 years ago

  • Status changed from Need more information to Resolved
  • Legacy Backlogs Release (now unused) changed from 55 to 51

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

Also available in: Atom PDF