アプリ開発ときどきアウトドア

主にJavaを使ったアプリ開発やトラブルシューティング等のノウハウ、キャンプや登山の紹介や体験談など。

1. システムエンジニアリング Java 実装技術

Apache HttpClientの通信内容をダンプ

投稿日:

アプリやミドルウェの動作の正常性確認や問題発生時の問題切り分けのために、HTTPリクエストやレスポンスのヘッダやボディを確認したい場合がある。Java系のアプリではApacheのHttpClientが使用されることが多いため、ここではApacheのHttpClientによる通信をダンプ(ロギング)する方法を説明します。
(ここではApache HttpClient 4.5を前提として説明します。HttpClientの場合、バージョンが変わるとAPI等が大きく変わる場合があるので、ここでの説明と異なる動作をする場合があります。)

HttpClientのロギング

ログ出力内容の種類

大きく分けて次の3種類のログを出力できます。
後述のログ出力例の設定例のように、使用するログ名を指定することで出力内容を変更できます。これらのログ名を全て含むorg.apache.httpを使うと全てのログを出力できます。

種類 説明 ログ名
Context Logging
(各クラスの内部動作)
HttpClientに含まれる各クラスの動作をログ出力します。ログを出力したいクラスの完全修飾クラス名を指定します。例えば、DefaultHttpClientのログを出力したい場合、org.apache.http.impl.client.DefaultHttpClientを指定します。HttpClientのクラスは慣例的にorg.apache.http.impl.clientというログ名を含んでいるので、このログ名を指定すれば全てのクラスのログを出力できます。 org.apache.http.impl.client
Wire Logging
(通信内容全て)
HTTPリクエスト/HTTPレスポンスのヘッダとボディを出力します。1回の通信毎に大量のログが出力されるので、ログの肥大化や性能劣化に注意が必要です。 org.apache.http.wire
HTTP header Logging
(HTTPヘッダのみ)
HTTPリクエスト/HTTPレスポンスのヘッダのみを出力します。 org.apache.http.headers

ログ出力先

HttpClientはログ出力にCommons Loggingを使用しており、Log4jやjava.util.Loggingへの出力の他に、Commons Loggingに含まれるSimpleLogを使ってログを出力できます。
SimpleLogは簡単に使用できるので、以降ではこのSimpleLogを使用する前提で説明します。
Log4j, java.util.Loggingを使用する場合は、HttpClientのリファレンスを参照のこと。

設定方法

SimpleLogを使ってログ出力する場合、システムプロパティ(Java起動時の-Dオプション)としてパラメータを指定するか、クラスパス上に配置された”simplelog.properties”ファイルで指定します。使用できるプロパティは次の通りです。
詳細はjavadocを参照のこと。

プロパティ名(*1) 説明 既定値
defaultlog 既定のログレベル(*2)
log.xxxxxで個別の指定がない限り、ここで指定したログレベル以上のログが出力されます。
info
log.xxxxx ログ名xxxxxに対するログレベル(*2)
例えばlog.Xyz=traceと指定した場合、defaultLogの設定に関わらず、Xyzからのログはtrace以上を出力します。
(既定のログレベル)
showlogname ログ名を出力するかを指定
下記showShortLognameの値によって出力形式が異なる。
false
showShortLogname ログ名を出力する際、短縮表示するかを指定
trueの場合は”RequestAuthCache”、falseの場合は”org….protocol.RequestAuthCache”のように完全なログ名が出力される。
true
showdatetime 日時を出力するかを指定
出力形式は下記dateTimeFormatで指定する。
false
dateTimeFormat 日時出力時の書式を指定
(SimpleDateFormat書式)
yyyy/MM/dd HH:mm:ss:SSS zzz
*1: 先頭に”org.apache.commons.logging.simplelog.“を付ける前提です。
*2: ログレベルは”trace”, “debug”, “info”, “warn”, “error”, “fatal”のいずれか。

(参考)
eclipseでアプリケーションとして実行時にシステムプロパティとしてパラメータを指定する場合は、実行対象のクラスファイルを右クリックし、[実行]-[実行の構成]で実行構成ウインドウを表示します。[Javaアプリケーション]を選択して必須事項を入力し、[引数]タブでシステムプロパティを指定します。

出力例

  • HTTP POSTを行うサンプルプログラムを例題とし、ログ出力にはSimpleLogを使用する前提で、システムプロパティの設定例とログ出力例を記載します。
  • 下記の設定例では、本来は”2019/07/14 22:52:49:716 JST [DEBUG]…”等の日時項目が出力されますが、便宜上記載を割愛しています。
  • HTTPリクエスト(クライアント->サーバ)は”>>“、HTTPレスポンス(クライアント<-サーバ)は"<<“で表現されています。

出力例1:ヘッダ+コンテキスト

データ量が比較的多いボディ部を除外して全てのログを出力します。リファレンスにも記載がありますが、デバッグに最適なログ出力設定です。
  • プロパティ設定:
    -Dorg.apache.commons.logging.Log=org.apache.commons.logging.impl.SimpleLog
    -Dorg.apache.commons.logging.simplelog.showdatetime=true
    -Dorg.apache.commons.logging.simplelog.log.org.apache.http=DEBUG
    -Dorg.apache.commons.logging.simplelog.log.org.apache.http.wire=ERROR
    
    補足: org.apache.http=DEBUGは「全て出力」、org.apache.http.wire=ERRORは「ボディ部は除外」
  • ログ出力例:
    ...[DEBUG] RequestAddCookies - CookieSpec selected: default
    ...[DEBUG] RequestAddCookies - Cookie ...
    ...[DEBUG] RequestAuthCache - Auth cache not set in the context
    ...[DEBUG] PoolingHttpClientConnectionManager - Connection request: [route: {}->http://localhost:8080][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 20]
    ...[DEBUG] PoolingHttpClientConnectionManager - Connection leased: [id: 0][route: {}->http://localhost:8080][total kept alive: 0; route allocated: 1 of 2; total allocated: 1 of 20]
    ...[DEBUG] DefaultManagedHttpClientConnection - http-outgoing-0: set socket timeout to 0
    ...[DEBUG] MainClientExec - Executing request POST /xxx HTTP/1.1
    ...[DEBUG] MainClientExec - Target auth state: UNCHALLENGED
    ...[DEBUG] MainClientExec - Proxy auth state: UNCHALLENGED
    ...[DEBUG] headers - http-outgoing-0 >> POST /xxx HTTP/1.1
    ...[DEBUG] headers - http-outgoing-0 >> Content-Length: 28
    ...[DEBUG] headers - http-outgoing-0 >> Content-Type: application/x-www-form-urlencoded
    ...[DEBUG] headers - http-outgoing-0 >> Host: localhost:8080
    ...[DEBUG] headers - http-outgoing-0 >> Connection: Keep-Alive
    ...[DEBUG] headers - http-outgoing-0 >> User-Agent: Apache-HttpClient/4.5.9 (Java/1.8.0_181-1-redhat)
    ...[DEBUG] headers - http-outgoing-0 >> Cookie: xxx=xxx
    ...[DEBUG] headers - http-outgoing-0 >> Accept-Encoding: gzip,deflate
    ...[DEBUG] headers - http-outgoing-0 << HTTP/1.1 200 OK
    ...[DEBUG] headers - http-outgoing-0 << Connection: keep-alive
    ...[DEBUG] headers - http-outgoing-0 << Content-Type: text/html;charset=UTF-8
    ...[DEBUG] headers - http-outgoing-0 << Content-Length: 8072
    ...[DEBUG] headers - http-outgoing-0 << Date: Sun, 14 Jul 2019 13:46:08 GMT
    ...[DEBUG] MainClientExec - Connection can be kept alive indefinitely
    ...[DEBUG] PoolingHttpClientConnectionManager - Connection [id: 0][route: {}->http://localhost:8080] can be kept alive indefinitely
    ...[DEBUG] DefaultManagedHttpClientConnection - http-outgoing-0: set socket timeout to 0
    ...[DEBUG] PoolingHttpClientConnectionManager - Connection released: [id: 0][route: {}->http://localhost:8080][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 20]
    

出力例2:通信内容(ヘッダのみ)

  • プロパティ設定:
    -Dorg.apache.commons.logging.Log=org.apache.commons.logging.impl.SimpleLog
    -Dorg.apache.commons.logging.simplelog.showdatetime=true
    -Dorg.apache.commons.logging.simplelog.log.org.apache.http.headers=DEBUG
    
  • ログ出力例:
    ...[DEBUG] headers - http-outgoing-0 >> POST /xxx HTTP/1.1
    ...[DEBUG] headers - http-outgoing-0 >> Content-Length: 28
    ...[DEBUG] headers - http-outgoing-0 >> Content-Type: application/x-www-form-urlencoded
    ...[DEBUG] headers - http-outgoing-0 >> Host: localhost:8080
    ...[DEBUG] headers - http-outgoing-0 >> Connection: Keep-Alive
    ...[DEBUG] headers - http-outgoing-0 >> User-Agent: Apache-HttpClient/4.5.9 (Java/1.8.0_181-1-redhat)
    ...[DEBUG] headers - http-outgoing-0 >> Accept-Encoding: gzip,deflate
    ...[DEBUG] headers - http-outgoing-0 << HTTP/1.1 200 OK
    ...[DEBUG] headers - http-outgoing-0 << Connection: keep-alive
    ...[DEBUG] headers - http-outgoing-0 << Set-Cookie: xxx=xxx; path=/xxx
    ...[DEBUG] headers - http-outgoing-0 << Content-Type: text/html;charset=UTF-8
    ...[DEBUG] headers - http-outgoing-0 << Content-Length: 8734
    ...[DEBUG] headers - http-outgoing-0 << Date: Sun, 14 Jul 2019 14:13:41 GMT
    

出力例3:通信内容(ヘッダ+ボディ)

ヘッダとボディ内容を確認したい場合の例です。
org.apache.http.headersと併せて使用するとヘッダが重複して出てしまいます。

  • プロパティ設定:
    -Dorg.apache.commons.logging.Log=org.apache.commons.logging.impl.SimpleLog
    -Dorg.apache.commons.logging.simplelog.showdatetime=true
    -Dorg.apache.commons.logging.simplelog.log.org.apache.http.wire=DEBUG
    
  • ログ出力例:
    ...[DEBUG] wire - http-outgoing-0 >> "POST /xxx HTTP/1.1[\r][\n]"
    ...[DEBUG] wire - http-outgoing-0 >> "Content-Length: 28[\r][\n]"
    ...[DEBUG] wire - http-outgoing-0 >> "Content-Type: application/x-www-form-urlencoded[\r][\n]"
    ...[DEBUG] wire - http-outgoing-0 >> "Host: localhost:8080[\r][\n]"
    ...[DEBUG] wire - http-outgoing-0 >> "Connection: Keep-Alive[\r][\n]"
    ...[DEBUG] wire - http-outgoing-0 >> "User-Agent: Apache-HttpClient/4.5.9 (Java/1.8.0_181-1-redhat)[\r][\n]"
    ...[DEBUG] wire - http-outgoing-0 >> "Accept-Encoding: gzip,deflate[\r][\n]"
    ...[DEBUG] wire - http-outgoing-0 >> "[\r][\n]"
    ...[DEBUG] wire - http-outgoing-0 >> "username=vip&password=secret"
    ...[DEBUG] wire - http-outgoing-0 << "HTTP/1.1 200 OK[\r][\n]"
    ...[DEBUG] wire - http-outgoing-0 << "Connection: keep-alive[\r][\n]"
    ...[DEBUG] wire - http-outgoing-0 << "Set-Cookie: xxx=xxx; path=/xxx[\r][\n]"
    ...[DEBUG] wire - http-outgoing-0 << "Content-Type: text/html;charset=UTF-8[\r][\n]"
    ...[DEBUG] wire - http-outgoing-0 << "Content-Length: 8732[\r][\n]"
    ...[DEBUG] wire - http-outgoing-0 << "Date: Sun, 14 Jul 2019 14:20:46 GMT[\r][\n]"
    ...[DEBUG] wire - http-outgoing-0 << "[\r][\n]"
    ...[DEBUG] wire - http-outgoing-0 << "<?xml version='1.0' encoding='UTF-8' ?>[\n]"
    ...[DEBUG] wire - http-outgoing-0 << "<!DOCTYPE html>[\n]"
    ...[DEBUG] wire - http-outgoing-0 << "<html lang="ja" xmlns="http://www.w3.org/1999/xhtml" xmlns:og="http://ogp.me/ns#">[\n]"
    ...[DEBUG] wire - http-outgoing-0 << ...(応答内容)...
    ...[DEBUG] wire - http-outgoing-0 << "[0x9]</div></body>[\n]"
    ...[DEBUG] wire - http-outgoing-0 << "</html>"
    

参考:サンプルプログラム

HttpClientを使ってHTTP POSTするサンプルプログラムです。
使用するHttpClientはmavenで取得する前提であるため、pom.xmlで宣言します。
実行する場合はソースコード上のURLを適宜修正してください。

package test;

import java.io.IOException;
import java.util.ArrayList;
import java.util.List;

import org.apache.http.HttpEntity;
import org.apache.http.NameValuePair;
import org.apache.http.client.entity.UrlEncodedFormEntity;
import org.apache.http.client.methods.CloseableHttpResponse;
import org.apache.http.client.methods.HttpGet;
import org.apache.http.client.methods.HttpPost;
import org.apache.http.impl.client.CloseableHttpClient;
import org.apache.http.impl.client.HttpClients;
import org.apache.http.message.BasicNameValuePair;
import org.apache.http.util.EntityUtils;

/**
 * HttpClient Quick StartのHttpClient native APIを参考にしたサンプル
 */
public class HttpClientTest {

	public static void main(String[] args) throws Exception {

		CloseableHttpClient httpclient = HttpClients.createDefault();

		HttpPost httpPost = new HttpPost("http://localhost:8080/xxx");
		List<NameValuePair> nvps = new ArrayList<NameValuePair>();
		nvps.add(new BasicNameValuePair("username", "vip"));
		nvps.add(new BasicNameValuePair("password", "secret"));
		httpPost.setEntity(new UrlEncodedFormEntity(nvps));
		try (CloseableHttpResponse response2 = httpclient.execute(httpPost);) {
			HttpEntity entity2 = response2.getEntity();
			// do something useful with the response body
			// and ensure it is fully consumed
			EntityUtils.consume(entity2);
		}
	}

}
<project ...
...
	<dependencies>
		<dependency>
			<groupId>org.apache.httpcomponents</groupId>
			<artifactId>httpclient</artifactId>
			<version>4.5.9</version>
		</dependency>
	</dependencies>
...
</project>


(adsbygoogle = window.adsbygoogle || []).push({});


(adsbygoogle = window.adsbygoogle || []).push({});

-1. システムエンジニアリング, Java, 実装技術

執筆者:

関連記事

JavaEE7のJSF, Facelets, JSPの関係

JavaEEを使ったアプリ開発の際に、いつも気になるが後回しにしていたこと… HTML5への対応方法の調査等、今後の理解促進のために、調べてみた。 FaceletsとJSFとの関係は? J …

パスワード情報の保管方式の比較

Webアプリの開発でパスワードを使ったユーザ認証を設計・実装する機会がよくある。 後輩への説明や勉強会ネタとして、この辺の話を纏めてみようと思う。 概要 オンラインバンキングやネットショッピングのサイ …

Wildfly11のインストール

このサイトでWebアプリを公開したい。 仕事ではJBoss Enterprise Application Server(JBoss EAP)を使う機会が多いのでそれを使いたいがライセンス料がかかる。無 …

jQueryによるデフォルトボタンの実装

デフォルトボタンについて Webページ上でエンターキーを押した場合、そのページ上であらかじめ決められたボタンをクリックしたかのように処理を実行する仕組みがある。何らかのデータの検索を行うようなページは …

CentOS7のマルチホーム化

サイトの存在を隠しつつも、sftpサーバを公開し、後輩と1G以上のファイルのやりとりしたい。 パブリック側のIPアドレスを教えてしまうと、どこのサーバだろうかとブラウザで開いたりするとサイトの存在がわ …

プロフィール ゆっきーです。
都内でシステムエンジニアをやっています。
もっと詳細を見る