Faradayのログをきれいにしたり、通信時間などをログ出力する方法
※ Rails または ActiveSupportが必要
検索用キーワード: faraday change custom format log output url time elapsed
デフォルトのログ出力はあまりきれいではない
例えば以下のような感じ
I, [2015-03-23T18:25:52.041359 #10667] INFO -- : post http://localhost:3000/
D, [2015-03-23T18:25:52.041475 #10667] DEBUG -- request: User-Agent: "Faraday v0.9.1"
Content-Type: "application/x-www-form-urlencoded"
I, [2015-03-23T18:25:52.366326 #10667] INFO -- Status: 200
D, [2015-03-23T18:25:52.366479 #10667] DEBUG -- response: x-frame-options: "SAMEORIGIN"
x-xss-protection: "1; mode=block"
x-content-type-options: "nosniff"
content-type: "text/html; charset=utf-8"
etag: "W/\"505a83f220c02df2f85c3810cd9ceb38\""
cache-control: "max-age=0, private, must-revalidate"
x-request-id: "c4eb0384-12d5-43ae-8755-d516f02959c6"
x-runtime: "0.301850"
server: "WEBrick/1.3.1 (Ruby/2.1.2/2014-05-08)"
date: "Tue, 24 Mar 2015 01:25:52 GMT"
content-length: "7"
connection: "close"
set-cookie: "request_method=POST; path=/"
通常のデフォルトのログ出力の設定はconnectionを作成するところなどで、以下のように設定する
Faraday.new(:url => base_url) do |faraday|
...
faraday.response :logger
...
ログ出力を整形する
faraday_middlewareを追加
Gemfile
gem 'faraday_middleware'
gemの場合
mygem.gemspec
spec.add_dependency "faraday_middleware"
lib/mygem.rb
require "faraday_middleware"
faraday初期化時のオプション
connection(session)作成箇所やdefault optionsを指定している箇所で
Faraday.new(:url => base_url) do |faraday|
...
# faraday.response :logger
faraday.use FaradayMiddleware::Instrumentation
...
ログ出力設定 Active Support Instrumentation
Railsの場合、initializerなどで
config/initializers/faraday_logger.rb
if Rails.env.development?
ActiveSupport::Notifications.subscribe('request.faraday') do |name, starts, ends, _, env|
url = env[:url]
http_method = env[:method].to_s.upcase
duration = ends - starts
Rails.logger.debug "#{http_method} '#{url}' takes #{duration} seconds"
end
end
gemのテストなどではspec/support/faraday.rbなどに置けば良い
Active Support Instrumentation — Ruby on Rails Guides
FaradayMiddleware::Instrumentation
ログ出力の例
GET 'http://example.com/foo?abc=123' takes 0.100123 seconds
POST 'http://example.com/bar' takes 0.500086 seconds
使えそうな情報
> env.keys
[:method, :body, :url, :request, :request_headers, :ssl, :response, :response_headers, :status]
> env[:method]
:get
> env[:url].class
URI::HTTP
> env[:request_headers]
{"User-Agent"=>"Mozilla/5.0 ..."}
> env[:body]
"<HTML><HEAD><TITLE>..."
> env[:status] # env[:response].status
200
> env[:response_headers] # env[:response].headers
{"date"=>"Fri, 06 Feb 2015 14:13:31 GMT", "set-cookie"=>...}