ncbo / ontologies_api_ruby_client

A Ruby client for accessing NCBO's hypermedia api
Other
2 stars 6 forks source link

Add option to disable invalidate cache for all if wanted #9

Closed syphax-bouazzouni closed 2 years ago

syphax-bouazzouni commented 2 years ago

We had this issue https://github.com/agroportal/documentation/issues/190 at Agroportal

And it was caused by Timeout due to the function invalidate cache when adding or updating a submission, see the fullstack trace below

F, [2022-02-11T12:31:57.620895 #31058] FATAL -- : Faraday::TimeoutError (Problem retrieving:
http://data.agroportal.lirmm.fr/submissions?include=all&include_status=READY
Error: read timeout reached
/srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/excon-0.91.0/lib/excon/socket.rb:286:in `select_with_timeout'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/excon-0.91.0/lib/excon/socket.rb:196:in `rescue in read_nonblock'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/excon-0.91.0/lib/excon/socket.rb:177:in `read_nonblock'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/excon-0.91.0/lib/excon/socket.rb:65:in `readline'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/excon-0.91.0/lib/excon/response.rb:64:in `block in parse'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/excon-0.91.0/lib/excon/response.rb:63:in `loop'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/excon-0.91.0/lib/excon/response.rb:63:in `parse'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/excon-0.91.0/lib/excon/middlewares/response_parser.rb:7:in `response_call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/excon-0.91.0/lib/excon/connection.rb:456:in `response'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/excon-0.91.0/lib/excon/connection.rb:287:in `request'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/faraday-excon-1.1.0/lib/faraday/adapter/excon.rb:31:in `block in call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/faraday-1.4.3/lib/faraday/adapter.rb:53:in `connection'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/faraday-excon-1.1.0/lib/faraday/adapter/excon.rb:31:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/faraday-1.4.3/lib/faraday/request/url_encoded.rb:25:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/faraday-1.4.3/lib/faraday/request/multipart.rb:30:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/bundler/gems/ontologies_api_ruby_client-3e9e1fa7c199/lib/ontologies_api_client/middleware/faraday-object-cache.rb:63:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/bundler/gems/ontologies_api_ruby_client-3e9e1fa7c199/lib/ontologies_api_client/middleware/faraday-last-updated.rb:16:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/bundler/gems/ontologies_api_ruby_client-3e9e1fa7c199/lib/ontologies_api_client/middleware/faraday-slices.rb:16:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/bundler/gems/ontologies_api_ruby_client-3e9e1fa7c199/lib/ontologies_api_client/middleware/faraday-user-apikey.rb:16:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/faraday-1.4.3/lib/faraday/rack_builder.rb:154:in `build_response'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/faraday-1.4.3/lib/faraday/connection.rb:495:in `run_request'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/faraday-1.4.3/lib/faraday/connection.rb:199:in `get'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/bundler/gems/ontologies_api_ruby_client-3e9e1fa7c199/lib/ontologies_api_client/http.rb:63:in `get'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/bundler/gems/ontologies_api_ruby_client-3e9e1fa7c199/lib/ontologies_api_client/collection.rb:43:in `entry_point'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/bundler/gems/ontologies_api_ruby_client-3e9e1fa7c199/lib/ontologies_api_client/collection.rb:56:in `all'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/bundler/gems/ontologies_api_ruby_client-3e9e1fa7c199/lib/ontologies_api_client/models/ontology_submission.rb:28:in `all'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/bundler/gems/ontologies_api_ruby_client-3e9e1fa7c199/lib/ontologies_api_client/read_write.rb:95:in `invalidate_cache'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/bundler/gems/ontologies_api_ruby_client-3e9e1fa7c199/lib/ontologies_api_client/read_write.rb:14:in `save'
        /srv/ontoportal/bioportal_web_ui/releases/20220210085106/app/controllers/submissions_controller.rb:45:in `create'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/abstract_controller/base.rb:194:in `process_action'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_controller/metal/rendering.rb:30:in `process_action'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/abstract_controller/callbacks.rb:42:in `block in process_action'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:132:in `run_callbacks'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/abstract_controller/callbacks.rb:41:in `process_action'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_controller/metal/rescue.rb:22:in `process_action'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_controller/metal/instrumentation.rb:34:in `block in process_action'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/activesupport-5.2.6/lib/active_support/notifications.rb:168:in `block in instrument'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/activesupport-5.2.6/lib/active_support/notifications/instrumenter.rb:23:in `instrument'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/activesupport-5.2.6/lib/active_support/notifications.rb:168:in `instrument'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_controller/metal/instrumentation.rb:32:in `process_action'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_controller/metal/params_wrapper.rb:256:in `process_action'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/activerecord-5.2.6/lib/active_record/railties/controller_runtime.rb:24:in `process_action'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/abstract_controller/base.rb:134:in `process'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionview-5.2.6/lib/action_view/rendering.rb:32:in `process'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_controller/metal.rb:191:in `dispatch'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_controller/metal.rb:252:in `dispatch'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_dispatch/routing/route_set.rb:52:in `dispatch'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_dispatch/routing/route_set.rb:34:in `serve'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_dispatch/journey/router.rb:52:in `block in serve'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_dispatch/journey/router.rb:35:in `each'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_dispatch/journey/router.rb:35:in `serve'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_dispatch/routing/route_set.rb:840:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/turnout-2.5.0/lib/rack/turnout.rb:25:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/tempfile_reaper.rb:15:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/etag.rb:27:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/conditional_get.rb:40:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/head.rb:12:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_dispatch/http/content_security_policy.rb:18:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:266:in `context'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:260:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_dispatch/middleware/cookies.rb:670:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:98:in `run_callbacks'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_dispatch/middleware/debug_exceptions.rb:61:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/railties-5.2.6/lib/rails/rack/logger.rb:38:in `call_app'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/railties-5.2.6/lib/rails/rack/logger.rb:26:in `block in call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/activesupport-5.2.6/lib/active_support/tagged_logging.rb:71:in `block in tagged'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/activesupport-5.2.6/lib/active_support/tagged_logging.rb:28:in `tagged'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/activesupport-5.2.6/lib/active_support/tagged_logging.rb:71:in `tagged'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/railties-5.2.6/lib/rails/rack/logger.rb:26:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_dispatch/middleware/request_id.rb:27:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/method_override.rb:24:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/runtime.rb:22:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/activesupport-5.2.6/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/actionpack-5.2.6/lib/action_dispatch/middleware/executor.rb:14:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/sendfile.rb:110:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/rack-mini-profiler-2.3.3/lib/mini_profiler/profiler.rb:249:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/railties-5.2.6/lib/rails/engine.rb:524:in `call'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/railties-5.2.6/lib/rails/railtie.rb:190:in `public_send'
        /srv/ontoportal/bioportal_web_ui/shared/bundle/ruby/2.6.0/gems/railties-5.2.6/lib/rails/railtie.rb:190:in `method_missing'
        /usr/share/ruby/vendor_ruby/phusion_passenger/rack/thread_handler_extension.rb:107:in `process_request'
        /usr/share/ruby/vendor_ruby/phusion_passenger/request_handler/thread_handler.rb:157:in `accept_and_process_next_request'
        /usr/share/ruby/vendor_ruby/phusion_passenger/request_handler/thread_handler.rb:110:in `main_loop'
        /usr/share/ruby/vendor_ruby/phusion_passenger/request_handler.rb:419:in `block (3 levels) in start_threads'
        /usr/share/ruby/vendor_ruby/phusion_passenger/utils.rb:113:in `block in create_thread_and_abort_on_exception'):
F, [2022-02-11T12:31:57.621145 #31058] FATAL -- :   
F, [2022-02-11T12:31:57.621243 #31058] FATAL -- : app/controllers/submissions_controller.rb:45:in `create'

The problem

The problem is why the function invalidate_cache is doing an self.class.all(invalidate_cache: true) when doing a save or update. In our case (at Agrportal) the self.class.all(invalidate_cache: true) for submissions take a lot of time than it causes a request time out.

Our solution

Add the option to not call to self.class.all(invalidate_cache: true) in the invalidate_cache

graybeal commented 2 years ago

@syphax-bouazzouni @jvendetti Sorry, I have a naive question as I was compiling our clear caching issues. As I haven't studied the code, please consider this a curiosity question, not a critique. (Read: A really short answer is fine if the question isn't helpful.)

Your question was

The problem is why the function invalidate_cache is doing an self.class.all(invalidate_cache: true) when doing a save or update.

I assume the reason for the function doing self.class.all(invalidate_cache) is because the self has been changed, and so the cache for self is no longer valid, and so we want that cache to be invalidated so that it is recached on the next request. In which case removing this call means the cache will in fact continue to represent old information, which is a problem. What am I missing?

Assuming we do want the cache to be invalidated when self has changed, the original call seems like an appropriate way to do it. In which case the problem should be stated as "there is a problem when invalidating the cache which may be preventing the invalidation from correctly taking place, so we need to troubleshoot the error and confirm that the cache is correctly invalidated" (presumably what the retrieval was trying to do).

syphax-bouazzouni commented 2 years ago

Hi @graybeal,

I think that the best to understand the issue, is by an example :

Let's assume that we have in our store 4 submissions [sub_1, sub_2, sub_3, and sub_4]

With the way, it was implemented if we update sub_3 it will :

  1. First, invalidate the cache for all the submissions (the self.class.all(invalidate_cache: true) line). So sub_1, sub_2, sub_3, and sub_4 will be invalidated.
  2. Then it invalidates the sub_3 (the HTTP.get(self.id, invalidate_cache: true)line )
syphax-bouazzouni commented 2 years ago

And about these clear caching issues do you have open any tracker about it, we would be interested to follow it because I think we have the same issues.

jvendetti commented 2 years ago

These are the only ones I'm aware of:

https://github.com/ncbo/bioportal-project/issues/62 https://github.com/ncbo/bioportal-project/issues/193 https://github.com/ncbo/ontologies_api_ruby_client/issues/2