Rails - Koala / Faraday Gems Execution Expired Error

Question

I am working on a rails application that uses Koala gem (v2.2) and Faraday (0.9.2). It seems like a lot of the facebook requests are erroring out with execution required and Im not sure why. Here is a stack trace. I would be grateful on help on how to troubleshoot this issue,

Here is the code snippet, it either fails on oauth.get_app_access_token or app_graph.debug_token

oauth = Koala::Facebook::OAuth.new(Rails.application.config.facebook_app_id,
                                   Rails.application.config.facebook_app_secret,
                                   nil)

app_access_token = oauth.get_app_access_token # fails here
app_graph = Koala::Facebook::API.new(app_access_token)
token_info = app_graph.debug_token(atoken) # or fails here

Here is the error:

ERROR: execution expired 
 /usr/lib/ruby/1.9.2/net/http.rb:644:in `initialize' 
 /usr/lib/ruby/1.9.2/net/http.rb:644:in `open' 
 /usr/lib/ruby/1.9.2/net/http.rb:644:in `block in connect' 
 /usr/lib/ruby/1.9.2/net/http.rb:644:in `connect' 
 /usr/lib/ruby/1.9.2/net/http.rb:637:in `do_start' 
 /usr/lib/ruby/1.9.2/net/http.rb:626:in `start' 
 /usr/lib/ruby/1.9.2/net/http.rb:1168:in `request' 
 /usr/lib/ruby/gems/1.9.2/gems/faraday-0.9.2/lib/faraday/adapter/net_http.rb:82:in `perform_request' 
 /usr/lib/ruby/gems/1.9.2/gems/faraday-0.9.2/lib/faraday/adapter/net_http.rb:40:in `block in call' 
 /usr/lib/ruby/gems/1.9.2/gems/faraday-0.9.2/lib/faraday/adapter/net_http.rb:87:in `with_net_http_connection' 
 /usr/lib/ruby/gems/1.9.2/gems/faraday-0.9.2/lib/faraday/adapter/net_http.rb:32:in `call' 
 /usr/lib/ruby/gems/1.9.2/gems/faraday-0.9.2/lib/faraday/request/url_encoded.rb:15:in `call' 
 /usr/lib/ruby/gems/1.9.2/gems/faraday-0.9.2/lib/faraday/request/multipart.rb:14:in `call' 
 /usr/lib/ruby/gems/1.9.2/gems/faraday-0.9.2/lib/faraday/rack_builder.rb:139:in `build_response' 
 /usr/lib/ruby/gems/1.9.2/gems/faraday-0.9.2/lib/faraday/connection.rb:377:in `run_request' 
 /usr/lib/ruby/gems/1.9.2/gems/faraday-0.9.2/lib/faraday/connection.rb:177:in `post' 
 /usr/lib/ruby/gems/1.9.2/gems/koala-2.2.0/lib/koala/http_service.rb:113:in `make_request' 
 /usr/lib/ruby/gems/1.9.2/gems/koala-2.2.0/lib/koala.rb:64:in `make_request' 
 /usr/lib/ruby/gems/1.9.2/gems/koala-2.2.0/lib/koala/oauth.rb:306:in `fetch_token_string' 
 /usr/lib/ruby/gems/1.9.2/gems/koala-2.2.0/lib/koala/oauth.rb:258:in `get_token_from_server' 
 /usr/lib/ruby/gems/1.9.2/gems/koala-2.2.0/lib/koala/oauth.rb:189:in `get_app_access_token_info' 
 /usr/lib/ruby/gems/1.9.2/gems/koala-2.2.0/lib/koala/oauth.rb:199:in `get_app_access_token' 

Answer 1

This is /lib/faraday/adapter/net_http.rb:82:in 'perform_request' method where the execution is expired

  def perform_request(http, env)
    if :get == env[:method] and !env[:body]
      # prefer `get` to `request` because the former handles gzip (ruby 1.9)
      http.get env[:url].request_uri, env[:request_headers]
    else
      # In your case you execture http.request
      http.request create_request(env)
    end
  end

This is the Ruby Documentation Net::HTTP.request method, I underline

Returns an HTTPResponse object.

which is the res in the method and will be based on the Net::HTTPResponse ruby class

Also I would focus on how the request is made, because I believe some parameters are being passed incorrectly and this is the reason the response take so long. So we should focus on the request body, header and all the other information.

# File net/http.rb, line 1421
def request(req, body = nil, &block)  # :yield: +response+
  unless started?
    start {
      req['connection'] ||= 'close'
      return request(req, body, &block)
    }
  end
  if proxy_user()
    req.proxy_basic_auth proxy_user(), proxy_pass() unless use_ssl?
  end
  req.set_body_internal body
  res = transport_request(req, &block)
  if sspi_auth?(res)
    sspi_auth(req)
    res = transport_request(req, &block)
  end
  res
end

So what about printing some additional log information in your production server log, you can open this files /usr/lib/ruby/1.9.2/net/http.rb:1168:in 'request' and /usr/lib/ruby/gems/1.9.2/gems/faraday-0.9.2/lib/faraday/adapter/net_http.rb:82:in 'perform_request', to write some puts statements on some variable that should output in your production log.

You also need to make sure that the rails app log is configured to print them.