0

私が書いている API に奇妙な問題があります。API は他のサービスに対して http get リクエストを作成し、特定の状況でタイムアウトになりました。ほとんどの場合、別のサービスがオフまたは到達不能です。

システム全体を AWS で実行しようとしていますが、そこで API を実行すると、同じインスタンスのサービスにアクセスしようとすると頻繁にタイムアウトが発生します。API は ruby​​+sinatra で書かれています。Pythonの前身で問題が発生したことはありません。AWS インスタンスのコマンド ラインから他のサービスの URL をカールすると、タイムアウトが発生しません。API をローカル (AWS 上の他のサービス) で実行すると、毎回正常に動作します。

最初は、使用している http ライブラリである net/http ではないかと考えていましたが、ローカルでも問題があることが判明しました。open-uri または rest-client に切り替えると、すべてのローカルの問題が修正されましたが、AWS で実行すると、まだ 20% の確率でタイムアウトが発生します。

API は ruby​​+sinatra で、open-uri を使用して http リクエストを行います。他のサービスは ruby​​+sinatra または java です。私は 32 ビットの Amazon Linux スモール インスタンス、ruby 1.9.3、java 1.6 で実行しています。私のローカル マシンは、Ruby 1.9.3 と Java 1.6 を搭載した Snow Leopard を搭載した Mac です。

何が起こっているのかをさらに絞り込むためのアイデアやヒントはありますか?

更新: 大きなシナトラ アプリと小さなシナトラ アプリの動作が異なる!?

どちらもAWSで実行されている私のJavaサービスを呼び出すためのsinatraアプリのテストバージョン...正常に動作します。

require 'rubygems'
require 'uri'
require 'open-uri'
require 'sinatra'

set :port, 6969

get '/wtf' do
  xid = params[:xid]
  state = params[:state]
  service_addr = 'http://prod.myserver.com'
  rid = 'xxx'
  json = "{\"state\":\"#{state}\",\"sid\":\"0xac99d8929a89e6c01b56378336dec3a8L\",\"m\":\"set\",\"rid\":\"#{rid}\",\"id\":\"#{xid}\"}"

  paramStr = URI.escape("rid=#{rid}&id=#{xid}&json=#{json}")
  response = open(service_addr+"?"+paramStr)
  status = response.status[0]
  body = response.read

  body
end

より構造化されたシナトラ アプリとして Rack + で実行される大きなバージョンは、20% 以上の確率で失敗します。

require 'uri'
require 'open-uri'

class MyApp < Sinatra::Base

  get '/wtf' do
    xid = params[:xid]
    state = params[:state]
    service_addr = 'http://prod.myserver.com'
    rid = 'xxx'
    json = "{\"state\":\"#{state}\",\"sid\":\"0xac99d8929a89e6c01b56378336dec3a8L\",\"m\":\"set\",\"rid\":\"#{rid}\",\"id\":\"#{xid}\"}"

    paramStr = URI.escape("rid=#{rid}&id=#{xid}&json=#{json}")
    response = open(service_addr+"?"+paramStr)
    status = response.status[0]
    body = response.read

    body
  end

end

更新 2: mechanize を使用した詳細なエラー読み出し - 常にゲートウェイ タイムアウト

シンプルなバージョンでは、毎回動作します (タイムアウトなし)。複雑なバージョンについては、機械化が機能する場合と機能しない場合の読み出しを次に示します。

それが機能する場合：

I, [2012-05-22T22:45:53.267464 #11610]  INFO -- : Net::HTTP::Get: /? ### big long get str
D, [2012-05-22T22:45:53.267587 #11610] DEBUG -- : request-header: accept => */*
D, [2012-05-22T22:45:53.267630 #11610] DEBUG -- : request-header: user-agent => Mechanize/2.5.1 Ruby/1.9.3p125 (http://github.com/tenderlove/mechanize/)
D, [2012-05-22T22:45:53.267676 #11610] DEBUG -- : request-header: accept-encoding => gzip,deflate,identity
D, [2012-05-22T22:45:53.267713 #11610] DEBUG -- : request-header: accept-charset => ISO-8859-1,utf-8;q=0.7,*;q=0.7
D, [2012-05-22T22:45:53.267750 #11610] DEBUG -- : request-header: accept-language => en-us,en;q=0.5
D, [2012-05-22T22:45:53.267787 #11610] DEBUG -- : request-header: host => prod.pixieplug.com:9001
I, [2012-05-22T22:45:53.341814 #11610]  INFO -- : status: Net::HTTPOK 1.1 200 OK
D, [2012-05-22T22:45:53.341916 #11610] DEBUG -- : response-header: content-type => application/json;charset=ISO-8859-1
D, [2012-05-22T22:45:53.341962 #11610] DEBUG -- : response-header: transfer-encoding => chunked
D, [2012-05-22T22:45:53.342009 #11610] DEBUG -- : response-header: server => Jetty(8.0.y.z-SNAPSHOT)
D, [2012-05-22T22:45:53.342137 #11610] DEBUG -- : Read 167 bytes (167 total)
98.247.240.63 - - [22/May/2012 22:45:53] "GET /wtf?xid=00:00:00:00:00:17&state=255 HTTP/1.1" 200 167 0.0777

そうでない場合:

I, [2012-05-22T22:46:23.665908 #11610]  INFO -- : Net::HTTP::Get: /?# long list of params
D, [2012-05-22T22:46:23.666014 #11610] DEBUG -- : request-header: accept => */*
D, [2012-05-22T22:46:23.666053 #11610] DEBUG -- : request-header: user-agent => Mechanize/2.5.1 Ruby/1.9.3p125 (http://github.com/tenderlove/mechanize/)
D, [2012-05-22T22:46:23.666090 #11610] DEBUG -- : request-header: accept-encoding => gzip,deflate,identity
D, [2012-05-22T22:46:23.666125 #11610] DEBUG -- : request-header: accept-charset => ISO-8859-1,utf-8;q=0.7,*;q=0.7
D, [2012-05-22T22:46:23.666161 #11610] DEBUG -- : request-header: accept-language => en-us,en;q=0.5
D, [2012-05-22T22:46:23.666233 #11610] DEBUG -- : request-header: host => prod.pixieplug.com:9001
I, [2012-05-22T22:46:28.675045 #11610]  INFO -- : status: Net::HTTPGatewayTimeOut 1.1 504 Gateway Timeout
D, [2012-05-22T22:46:28.675156 #11610] DEBUG -- : response-header: content-type => application/json;charset=ISO-8859-1
D, [2012-05-22T22:46:28.675195 #11610] DEBUG -- : response-header: transfer-encoding => chunked
D, [2012-05-22T22:46:28.675232 #11610] DEBUG -- : response-header: server => Jetty(8.0.y.z-SNAPSHOT)
D, [2012-05-22T22:46:28.675332 #11610] DEBUG -- : Read 48 bytes (48 total)
Mechanize::ResponseCodeError - 504 => Net::HTTPGatewayTimeOut for http://prod.pixieplug.com:9001/?# long list of params  -- unhandled response:
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/mechanize-2.5.1/lib/mechanize/http/agent.rb:304:in `fetch'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/mechanize-2.5.1/lib/mechanize.rb:407:in `get'
    /home/ec2-user/elphi-api/routes/sandbox.rb:15:in `block in <class:MyApp>'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/sinatra-1.3.2/lib/sinatra/base.rb:1212:in `call'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/sinatra-1.3.2/lib/sinatra/base.rb:1212:in `block in compile!'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/sinatra-1.3.2/lib/sinatra/base.rb:785:in `[]'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/sinatra-1.3.2/lib/sinatra/base.rb:785:in `block (3 levels) in route!'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/sinatra-1.3.2/lib/sinatra/base.rb:801:in `route_eval'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/sinatra-1.3.2/lib/sinatra/base.rb:785:in `block (2 levels) in route!'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/sinatra-1.3.2/lib/sinatra/base.rb:822:in `block in process_route'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/sinatra-1.3.2/lib/sinatra/base.rb:820:in `catch'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/sinatra-1.3.2/lib/sinatra/base.rb:820:in `process_route'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/sinatra-1.3.2/lib/sinatra/base.rb:784:in `block in route!'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/sinatra-1.3.2/lib/sinatra/base.rb:783:in `each'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/sinatra-1.3.2/lib/sinatra/base.rb:783:in `route!'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/sinatra-1.3.2/lib/sinatra/base.rb:886:in `dispatch!'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/sinatra-1.3.2/lib/sinatra/base.rb:719:in `block in call!'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/sinatra-1.3.2/lib/sinatra/base.rb:871:in `block in invoke'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/sinatra-1.3.2/lib/sinatra/base.rb:871:in `catch'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/sinatra-1.3.2/lib/sinatra/base.rb:871:in `invoke'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/sinatra-1.3.2/lib/sinatra/base.rb:719:in `call!'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/sinatra-1.3.2/lib/sinatra/base.rb:705:in `call'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-protection-1.2.0/lib/rack/protection/xss_header.rb:22:in `call'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-protection-1.2.0/lib/rack/protection/base.rb:47:in `call'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-protection-1.2.0/lib/rack/protection/base.rb:47:in `call'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-protection-1.2.0/lib/rack/protection/path_traversal.rb:16:in `call'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-protection-1.2.0/lib/rack/protection/json_csrf.rb:17:in `call'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-protection-1.2.0/lib/rack/protection/base.rb:47:in `call'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-protection-1.2.0/lib/rack/protection/xss_header.rb:22:in `call'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:205:in `context'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:200:in `call'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-1.4.1/lib/rack/logger.rb:15:in `call'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-1.4.1/lib/rack/head.rb:9:in `call'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-1.4.1/lib/rack/methodoverride.rb:21:in `call'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/sinatra-1.3.2/lib/sinatra/showexceptions.rb:21:in `call'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-1.4.1/lib/rack/lint.rb:48:in `_call'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-1.4.1/lib/rack/lint.rb:36:in `call'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-1.4.1/lib/rack/showexceptions.rb:24:in `call'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-1.4.1/lib/rack/commonlogger.rb:20:in `call'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-1.4.1/lib/rack/chunked.rb:43:in `call'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-1.4.1/lib/rack/content_length.rb:14:in `call'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/thin-1.3.1/lib/thin/connection.rb:80:in `block in pre_process'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/thin-1.3.1/lib/thin/connection.rb:78:in `catch'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/thin-1.3.1/lib/thin/connection.rb:78:in `pre_process'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/thin-1.3.1/lib/thin/connection.rb:53:in `process'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/thin-1.3.1/lib/thin/connection.rb:38:in `receive_data'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/eventmachine-0.12.10/lib/eventmachine.rb:256:in `run_machine'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/eventmachine-0.12.10/lib/eventmachine.rb:256:in `run'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/thin-1.3.1/lib/thin/backends/base.rb:61:in `start'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/thin-1.3.1/lib/thin/server.rb:159:in `start'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-1.4.1/lib/rack/handler/thin.rb:13:in `run'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-1.4.1/lib/rack/server.rb:265:in `start'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-1.4.1/lib/rack/server.rb:137:in `start'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/gems/rack-1.4.1/bin/rackup:4:in `<top (required)>'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/bin/rackup:19:in `load'
    /home/ec2-user/.rvm/gems/ruby-1.9.3-p125/bin/rackup:19:in `<main>'
98.247.240.63 - - [22/May/2012 22:46:28] "GET /wtf?xid=00:00:00:00:00:17&state=255 HTTP/1.1" 500 157221 5.1385
4

1 に答える 1

0

これは奇妙に見えるリクエストです。通常、json データはクエリ文字列ではなく投稿本文に入ります。ロガーを使用すると多くのデバッグ情報が得られるため、mechanize を使用してみましょう。問題がどこにあるかを確認するのに役立つ可能性があります。少しリファクタリングされたコード:

require 'sinatra/base'
require 'mechanize'
require 'logger'
require 'json'

class Myapp < Sinatra::Base

  AGENT = Mechanize.new
  AGENT.log = Logger.new $stdout

  get '/wtf' do
    rid, sid, xid, state = 'xxx', '0xac99d8929a89e6c01b56378336dec3a8L', params[:xid], params[:state]
    service_addr = 'http://prod.myserver.com/'
    json = {'state' => state, 'sid' => sid, 'm' => 'set', 'rid' => rid, 'id' => xid}.to_json
    response = AGENT.get service_addr, {:rid => rid, :id => xid, :json => json}
    response.body
  end

end
于 2012-05-22T09:08:19.277 に答える