org.jsoup.HttpStatusExceptionをorg.slf4j.Logger#error(String, Throwable)の第二引数に渡してロギング(実装にはlogbackを利用)したら、URLとステータスコードが記録されなかった件


発生した現象

org.jsoup.HttpStatusException(これは内部でURLとステータスコードを持っている)をorg.slf4j.Logger#error(String, Throwable)の第二引数に渡してロギング(実装にはlogbackを利用)したら、URLとステータスコードが記録されなかった。

バージョン

  • jsoup: 1.7.2
  • slf4j-api: 1.6.5
  • logback-core: 1.0.6
  • logback-classic: 1.0.6

やりたいこと

org.jsoup.HttpStatusExceptionをロギングしたときにURLとステータスコードを記録したい(ですよね??)。

現象の再現コード

HttpStatusExceptionTest.java

package org.jsoup;

import java.io.IOException;
import java.net.URL;

import org.junit.Test;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class HttpStatusExceptionTest {

    @Test
    public void test() throws IOException {
        try {
            Jsoup.parse(new URL("http://google.co.jp/notfound"), 30000);
        } catch (HttpStatusException e) {
            Logger log = LoggerFactory.getLogger(HttpStatusExceptionTest.class);
            log.error("", e);
        }
    }

}

logback.xml

存在しない。

ログ出力

20:01:23.835 [main] ERROR org.jsoup.HttpStatusExceptionTest - 
org.jsoup.HttpStatusException: HTTP error fetching URL
    at org.jsoup.helper.HttpConnection$Response.execute(HttpConnection.java:537) ~[classes/:na]
    at org.jsoup.helper.HttpConnection$Response.execute(HttpConnection.java:534) ~[classes/:na]
    at org.jsoup.helper.HttpConnection$Response.execute(HttpConnection.java:493) ~[classes/:na]
    at org.jsoup.helper.HttpConnection.execute(HttpConnection.java:205) ~[classes/:na]
    at org.jsoup.helper.HttpConnection.get(HttpConnection.java:194) ~[classes/:na]
    at org.jsoup.Jsoup.parse(Jsoup.java:183) ~[classes/:na]
    ...

解決案(いずれかを行えば良い)

  • HttpStatusException#toStringがURLとステータスコードを出しているので、log.error(e.toString(), e);とする。 その時のログは以下の通り。
20:09:00.798 [main] ERROR org.jsoup.HttpStatusExceptionTest - org.jsoup.HttpStatusException: HTTP error fetching URL. Status=404, URL=http://www.google.co.jp/notfound
org.jsoup.HttpStatusException: HTTP error fetching URL
    at org.jsoup.helper.HttpConnection$Response.execute(HttpConnection.java:537) ~[classes/:na]
    at org.jsoup.helper.HttpConnection$Response.execute(HttpConnection.java:534) ~[classes/:na]
    at org.jsoup.helper.HttpConnection$Response.execute(HttpConnection.java:493) ~[classes/:na]
    at org.jsoup.helper.HttpConnection.execute(HttpConnection.java:205) ~[classes/:na]
    at org.jsoup.helper.HttpConnection.get(HttpConnection.java:194) ~[classes/:na]
    at org.jsoup.Jsoup.parse(Jsoup.java:183) ~[classes/:na]
    ...
  • 他のロギングライブラリを使う(slf4j-simple 1.7.12だとlog.error("", e)でURLとステータスコードが出力された)。

ポエム

  • Java的に言うとHttpStatusException#getMessageが詳細メッセージ(この場合だとURLとステータスコード)を返すように実装するのが筋がよい気がするがどうなんでしょう。
  • log.error("hogehoge", e)って結構使うので、もし使ってるライブラリのどれかが例外の詳細メッセージをtoStringで返していたらと思うと、logbackをプロダクションで使うのちょっと怖いです……
  • logbackのソース追ってたんですけど、filterAndLog_0_Or3Plusっていうメソッド名が怖かったので諦めました。ごめんなさい…