diff --git a/README.md b/README.md index a062c62..28aff22 100644 --- a/README.md +++ b/README.md @@ -87,6 +87,14 @@ This method is from [lexbor](https://github.com/kostya/lexbor), so if you want t puts page.css("h1").first.inner_text ``` +### Logging + +For activation, simply setup the log to `:debug` level + +```crystal +Log.setup("mechanize", :debug) +``` + ## Contributing 1. Fork it () diff --git a/spec/log_spec.cr b/spec/log_spec.cr new file mode 100644 index 0000000..184a198 --- /dev/null +++ b/spec/log_spec.cr @@ -0,0 +1,18 @@ +require "./spec_helper" +require "log/spec" + +describe "Mechanize logging" do + it "emit logs" do + Log.capture("mechanize") do |logs| + agent = Mechanize.new + agent.user_agent = "Firefox" + page = agent.get("http://example.com/form") + + logs.check(:debug, "GET: http://example.com/form") + logs.check(:debug, "request-header: User-Agent => Firefox") + logs.check(:debug, "status: HTTP/1.1 200 OK") + logs.check(:debug, "response-header: Content-length => 291") + logs.check(:debug, "response-header: Connection => close") + end + end +end diff --git a/src/mechanize.cr b/src/mechanize.cr index bbec91a..18c54b1 100644 --- a/src/mechanize.cr +++ b/src/mechanize.cr @@ -1,3 +1,4 @@ +require "log" require "uri" require "http/client" require "lexbor" @@ -32,6 +33,7 @@ require "./mechanize/errors/*" # ``` class Mechanize VERSION = "0.2.0" + Log = ::Log.for(self) USER_AGENT = { "Mechanize" => "Mechanize/#{VERSION} Crystal/#{Crystal::VERSION} (https://github.com/Kanezoh/mechanize.cr)", @@ -250,6 +252,9 @@ class Mechanize cur_page = form.page || (current_page unless history.empty?) request_data = form.request_data + + Log.debug { "query: #{request_data.inspect}" } + content_headers = ::HTTP::Headers{ "Content-Type" => form.enctype, "Content-Length" => request_data.size.to_s, diff --git a/src/mechanize/http/agent.cr b/src/mechanize/http/agent.cr index c7fe6f9..c8905a3 100644 --- a/src/mechanize/http/agent.cr +++ b/src/mechanize/http/agent.cr @@ -32,6 +32,7 @@ class Mechanize response = http_request(uri, method, params) body = response.not_nil!.body page = response_parse(response, body, uri) + response_log(response) # save cookies save_response_cookies(response, uri, page) @@ -46,6 +47,8 @@ class Mechanize redirect_url = response.headers["location"] uri = resolve_url(redirect_url, referer) + Log.debug { "follow redirect to: #{uri.to_s}" } + # Make sure we are not copying over the POST headers from the original request headers.delete("Content-MD5") headers.delete("Content-Type") @@ -56,6 +59,8 @@ class Mechanize # send http request private def http_request(uri, method, params) : ::HTTP::Client::Response? + request_log(uri, method) + case uri.scheme.not_nil!.downcase when "http", "https" case method @@ -206,6 +211,7 @@ class Mechanize private def save_cookies(uri, header_cookies) host = uri.host header_cookies.each do |cookie| + Log.debug { "saved cookie: #{cookie.name}=#{cookie.value}" } cookie.origin = host request_cookies << cookie end @@ -220,6 +226,26 @@ class Mechanize end valid_cookies end + + private def request_log(uri, method) + Log.debug { "#{method.to_s.upcase}: #{uri.to_s}" } + + request_headers.each do |key, values| + value = values.size == 1 ? values.first : values + Log.debug { "request-header: #{key} => #{value}" } + end + end + + private def response_log(response) + return unless response + + Log.debug { "status: #{response.version} #{response.status_code} #{response.status_message}" } + + response.headers.each do |key, values| + value = values.size == 1 ? values.first : values + Log.debug { "response-header: #{key} => #{value}" } + end + end end end end