Topic: execution expired error

Hi,

Appreciate your help in advance.

One of our production servers today started throwing this errors when a user was unable to do a transaction. When traced through the logs, this is what I found. Can anyone tell me what is the sole reason for this error?

I thought it is because of memcache in my jruby environment but there is a timeout happening too.

Here is the error log:

execution expired [GUID: NTXXXXXXXXXXXXXX][Action: user_transactions/create][Service: App/app-web-web][Level: INFO] /opt/myapp/webapps/appweb/WEB-INF/gems/gems/httpclient-2.1.5.2/lib/httpclient/session.rb:675:in `initialize'/opt/myapp/webapps/appweb/WEB-INF/gems/gems/httpclient-2.1.5.2/lib/httpclient/session.rb:675:in `new'/opt/myapp/webapps/appweb/WEB-INF/gems/gems/httpclient-2.1.5.2/lib/httpclient/session.rb:675:in `create_socket'/opt/myapp/webapps/appweb/WEB-INF/gems/gems/httpclient-2.1.5.2/lib/httpclient/session.rb:632:in `connect'/opt/myapp/webapps/appweb/WEB-INF/gems/gems/httpclient-2.1.5.2/lib/httpclient/timeout.rb:128:in `timeout'/opt/myapp/webapps/appweb/WEB-INF/gems/gems/httpclient-2.1.5.2/lib/httpclient/session.rb:631:in `connect'/opt/myapp/webapps/appweb/WEB-INF/gems/gems/httpclient-2.1.5.2/lib/httpclient/session.rb:522:in `query'/opt/myapp/webapps/appweb/WEB-INF/gems/gems/httpclient-2.1.5.2/lib/httpclient/session.rb:147:in `query'/opt/myapp/webapps/appweb/WEB-INF/gems/gems/httpclient-2.1.5.2/lib/httpclient.rb:953:in `do_get_block'/opt/myapp/webapps/appweb/WEB-INF/gems/gems/httpclient-2.1.5.2/lib/httpclient.rb:765:in `do_request'/opt/myapp/webapps/appweb/WEB-INF/gems/gems/httpclient-2.1.5.2/lib/httpclient.rb:848:in `protect_keep_alive_disconnected'/opt/myapp/webapps/appweb/WEB-INF/gems/gems/httpclient-2.1.5.2/lib/httpclient.rb:764:in `do_request'/opt/myapp/webapps/appweb/WEB-INF/gems/gems/httpclient-2.1.5.2/lib/httpclient.rb:666:in `request'/opt/myapp/webapps/appweb/WEB-INF/gems/gems/httpclient-2.1.5.2/lib/httpclient.rb:596:in `post'/opt/myapp/webapps/appweb/WEB-INF/lib/silos_send_endpoint.rb:81:in `make_api_call'/opt/myapp/webapps/appweb/WEB-INF/lib/silos_send_endpoint.rb:41:in `send_message'/opt/myapp/webapps/appweb/WEB-INF/lib/silos_send_endpoint.rb:71:in `call'/opt/myapp/webapps/appweb/WEB-INF/lib/silos_send_endpoint.rb:71:in `send_message'/opt/myapp/webapps/appweb/WEB-INF/lib/scripts_endpoint.rb:21:in `deliver'/opt/myapp/webapps/appweb/WEB-INF/app/models/scripts_order.rb:51:in `send_message'/opt/myapp/webapps/appweb/WEB-INF/app/models/scripts_order.rb:24:in `step'/opt/myapp/webapps/appweb/WEB-INF/app/models/scripts_order.rb:49:in `send_message'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/activerecord/lib/active_record/associations/association_proxy.rb:215:in `method_missing'/opt/myapp/webapps/appweb/WEB-INF/app/controllers/user_transactions_controller.rb:391:in `create_and_send_user_medication'/opt/myapp/webapps/appweb/WEB-INF/app/controllers/user_transactions_controller.rb:164:in `create'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/base.rb:1333:in `perform_action'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/filters.rb:617:in `call_filters'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/filters.rb:638:in `run_before_filters'/opt/myapp/webapps/appweb/WEB-INF/lib/core_extensions/logging_filter.rb:45:in `filter'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/activesupport/lib/active_support/callbacks.rb:185:in `evaluate_method'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/filters.rb:186:in `call'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/filters.rb:635:in `run_before_filters'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/filters.rb:615:in `call_filters'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/filters.rb:610:in `perform_action_with_filters'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/benchmarking.rb:68:in `perform_action_with_benchmark'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/activesupport/lib/active_support/core_ext/benchmark.rb:17:in `ms'file:/opt/myapp/webapps/appweb/WEB-INF/lib/jruby-stdlib-1.5.6.jar!/META-INF/jruby.home/lib/ruby/1.8/benchmark.rb:308:in `realtime'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/activesupport/lib/active_support/core_ext/benchmark.rb:17:in `ms'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/benchmarking.rb:68:in `perform_action_with_benchmark'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/rescue.rb:160:in `perform_action_with_rescue'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/flash.rb:151:in `perform_action_with_flash'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/base.rb:532:in `process'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/filters.rb:606:in `process_with_filters'/opt/myapp/webapps/appweb/WEB-INF/gems/gems/compass-0.10.6/lib/compass/app_integration/rails/actionpack2/action_controller.rb:7:in `process_with_compass'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/base.rb:391:in `process'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/base.rb:386:in `call'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/routing/route_set.rb:438:in `call'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/dispatcher.rb:87:in `dispatch'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/dispatcher.rb:121:in `_call'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/dispatcher.rb:130:in `build_middleware_stack'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/activerecord/lib/active_record/query_cache.rb:29:in `call'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/activerecord/lib/active_record/query_cache.rb:29:in `call'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/activerecord/lib/active_record/connection_adapters/abstract/query_cache.rb:34:in `cache'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/activerecord/lib/active_record/query_cache.rb:9:in `cache'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/activerecord/lib/active_record/query_cache.rb:28:in `call'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb:361:in `call'/opt/myapp/webapps/appweb/WEB-INF/gems/gems/haml-3.0.24/lib/sass/plugin/rack.rb:41:in `call'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/string_coercion.rb:25:in `call'/opt/myapp/webapps/appweb/WEB-INF/gems/gems/rack-1.1.0/lib/rack/head.rb:9:in `call'/opt/myapp/webapps/appweb/WEB-INF/gems/gems/rack-1.1.0/lib/rack/methodoverride.rb:24:in `call'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/params_parser.rb:15:in `call'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/railties/lib/rails/rack/metal.rb:47:in `call'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/session/cookie_store.rb:100:in `call'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/failsafe.rb:26:in `call'/opt/myapp/webapps/appweb/WEB-INF/gems/gems/rack-1.1.0/lib/rack/lock.rb:11:in `call'/opt/myapp/webapps/appweb/WEB-INF/vendor/rails/actionpack/lib/action_controller/dispatcher.rb:106:in `call'file:/opt/myapp/webapps/appweb/WEB-INF/lib/jruby-rack-1.0.4.jar!/rack/adapter/rails.rb:36:in `serve_rails'file:/opt/myapp/webapps/appweb/WEB-INF/lib/jruby-rack-1.0.4.jar!/rack/adapter/rails.rb:41:in `call'file:/opt/myapp/webapps/appweb/WEB-INF/lib/jruby-rack-1.0.4.jar!/jruby/rack/rails.rb:188:in `call'file:/opt/myapp/webapps/appweb/WEB-INF/lib/jruby-rack

Regards.
Keshav.