Apache mod_proxy によるリバースプロキシが遅いのでソースコードを追って調べる #Apache

発端

Apache の mod_proxy と mod_ssl によるリバースプロキシでレスポンスを返すまでに1分ほど時間がかかるので原因を調べる

今回の環境

CentOS Linux 8

$ cat /etc/centos-release
CentOS Linux release 8.1.1911 (Core)

Apache HTTP Server 2.4.37

$ dnf list installed | grep httpd
centos-logos-httpd.noarch     80.5-2.el8                              @AppStream
httpd.x86_64                  2.4.37-16.module_el8.1.0+256+ae790463   @AppStream
httpd-filesystem.noarch       2.4.37-16.module_el8.1.0+256+ae790463   @AppStream
httpd-tools.x86_64            2.4.37-16.module_el8.1.0+256+ae790463   @AppStream

APR (Apache Portable Runtime) 1.6.3

$ dnf list installed | grep apr
apr.x86_64                    1.6.3-9.el8   @AppStream
apr-util.x86_64               1.6.1-6.el8   @AppStream
apr-util-bdb.x86_64           1.6.1-6.el8   @AppStream
apr-util-openssl.x86_64       1.6.1-6.el8   @AppStream

Apache のログレベルを設定する

Apache ではモジュール毎にログレベルを指定できる。

core - Apache HTTP Server Version 2.4

LogLevel info ssl:warn
LogLevel info mod_ssl.c:warn
LogLevel info ssl_module:warn

今回の原因は mod_ssl と mod_proxy にあると思ったのでこの2つの Apache モジュールについてのみ trace6 レベルを指定して多くのログを出力するように設定する。

httpd.conf の LogLevel ディレクティブを以下のように修正した。

LogLevel warn ssl:trace6 proxy:trace6

Apache を再起動して設定を反映させる。

$ apachectl configtest
Syntax OK

$ sudo systemctl restart httpd

Apache のエラーログを確認する

Apache のエラーログを確認すると、「HTTPS: fam 10 socket created to connect to」の後に「The timeout specified has expired」と接続タイムアウトを起こしていた。ここで1分ほどかかっている。

その後「HTTPS: fam 2 socket created to connect to」ですぐに接続できていた。

[proxy:trace2] proxy_util.c(3012): HTTPS: fam 10 socket created to connect to foobar.example.com
[proxy:debug] proxy_util.c(3037): (70007)The timeout specified has expired: AH00957: HTTPS: attempt to connect to [XXXX:XXXX:XXXX:XXXX::XXXX]:443 (foobar.example.com) failed
[proxy:trace2] proxy_util.c(3012): HTTPS: fam 2 socket created to connect to foobar.example.com
[proxy:debug] proxy_util.c(3046): AH02824: HTTPS: connection established with XXX.XXX.XXX.XXX:443 (foobar.example.com)

ログに出力されている IP アドレスを見ると「fam 10 socket」のときは IPv6 で接続しようとして接続タイムアウトし、「fam 2 socket」のときは IPv4 で接続しているように見える。

fam 10 socket, fam 2 socket とは何か

わからんヽ(*´∀｀)ノ

さっぱりわからないので調べる。

mod_proxy のソースコードを確認する

Apache 2.4.37 のソースコードから modules/proxy/proxy_util.c を抜き出して調べる。Apache のエラーログを見ると3012行目でログを出力しているようなのでその周辺を見る。

backend_addr->family が「fam 10 socket」や「fam 2 socket」の数字部分に当たる。

ap_log_error(APLOG_MARK, APLOG_TRACE2, 0, s,
             "%s: fam %d socket created to connect to %s",
             proxy_function, backend_addr->family, worker->s->hostname_ex);

backend_addr は何か？付近の行を見ると apr_sockaddr_t 構造体であることがわかる。

PROXY_DECLARE(int) ap_proxy_connect_backend(const char *proxy_function,
                                            proxy_conn_rec *conn,
                                            proxy_worker *worker,
                                            server_rec *s)
{
    apr_status_t rv;
    int loglevel;
    apr_sockaddr_t *backend_addr = conn->addr;

apr_sockaddr_t 構造体は APR (Apache Portable Runtime) というライブラリで定義されているもので、ドキュメントを参照するとソケットアドレスタイプを表していることがわかる。

Apache Portable Runtime: apr_sockaddr_t Struct Reference

APRs socket address type, used to ensure protocol independence

family 変数の項目には「The family」としか説明が載っていない。

apr_int32_t apr_sockaddr_t::family
The family

APR (Apache Portable Runtime) のソースコードを確認する

ソースコードを追っていくと apr_sockaddr_t 構造体の family 変数には APR_INET や APR_INET6 がセットされているのがわかる。

apr-1.6.3 のソースコードから include/apr_network_io.h を抜き出す。
AF_INET と AF_INET6 の値を APR_INET と APR_INET6 で定義しなおしている。

/**
 * @def APR_INET
 * Not all platforms have these defined, so we'll define them here
 * The default values come from FreeBSD 4.1.1
 */
#define APR_INET     AF_INET

#if APR_HAVE_IPV6
/** @def APR_INET6
* IPv6 Address Family. Not all platforms may have this defined.
*/

#define APR_INET6    AF_INET6
#endif

ソケットのアドレス・ファミリー (IBM i 7.3)

socket() API 上のアドレス・ファミリー・パラメーター (address_family) によって、ソケット API で使用するアドレス構造の形式が決まります。

アドレス・ファミリー・プロトコルは、ネットワーク内のあるアプリケーションから別のアプリケーションへ (または、同じシステム内のあるプロセスから別のプロセスへ) アプリケーション・データを移送できるようにします。アプリケーションは、ソケットのプロトコル・パラメーターにネットワーク・トランスポート・プロバイダーを指定します。

AF_INET アドレス・ファミリー
このアドレス・ファミリーは、同一システムまたは異なるシステム上で実行される複数のプロセス間で、プロセス間通信を行えるようにします。

AF_INET6 アドレス・ファミリー
このアドレス・ファミリーは、インターネット・プロトコルバージョン 6 (IPv6) をサポートします。AF_INET6 アドレス・ファミリーは、128 ビット (16 バイト) のアドレスを使用します。

/usr/include/ 以下のソースコードを確認する

Man page of SOCKET

これはどのプロトコルファミリー (protocol family) を通信に使用するかを指定する。これらのファミリーは <sys/socket.h> に定義されている。

CentOS Linux 8 にて /usr/include/sys/socket.h を確認する。

/* This operating system-specific header file defines the SOCK_*, PF_*,
   AF_*, MSG_*, SOL_*, and SO_* constants, and the `struct sockaddr',
   `struct msghdr', and `struct linger' types.  */
#include <bits/socket.h>

/usr/include/bits/socket.h を確認する。
AF_INET と AF_INET6 が定義されていて、それぞれ PF_INET と PF_INET6 の値をセットしている。

/* Address families.  */
#define AF_UNSPEC       PF_UNSPEC
#define AF_LOCAL        PF_LOCAL
#define AF_UNIX         PF_UNIX
#define AF_FILE         PF_FILE
#define AF_INET         PF_INET
#define AF_AX25         PF_AX25
#define AF_IPX          PF_IPX
#define AF_APPLETALK    PF_APPLETALK
#define AF_NETROM       PF_NETROM
#define AF_BRIDGE       PF_BRIDGE
#define AF_ATMPVC       PF_ATMPVC
#define AF_X25          PF_X25
#define AF_INET6        PF_INET6

ここで PF_INET が 2 で、PF_INET6 が 10 なのがわかる。

/* Protocol families.  */
#define PF_UNSPEC       0       /* Unspecified.  */
#define PF_LOCAL        1       /* Local to host (pipes and file-domain).  */
#define PF_UNIX         PF_LOCAL /* POSIX name for PF_LOCAL.  */
#define PF_FILE         PF_LOCAL /* Another non-standard name for PF_LOCAL.  */
#define PF_INET         2       /* IP protocol family.  */
#define PF_AX25         3       /* Amateur Radio AX.25.  */
#define PF_IPX          4       /* Novell Internet Protocol.  */
#define PF_APPLETALK    5       /* Appletalk DDP.  */
#define PF_NETROM       6       /* Amateur radio NetROM.  */
#define PF_BRIDGE       7       /* Multiprotocol bridge.  */
#define PF_ATMPVC       8       /* ATM PVCs.  */
#define PF_X25          9       /* Reserved for X.25 project.  */
#define PF_INET6        10      /* IP version 6.  */

fam 10 socket, fam 2 socket とは何か

これで、Apache のエラーログに出力されていた
「HTTPS: fam 10 socket created to connect to」
「HTTPS: fam 2 socket created to connect to」
の 10 と 2 の値が、PF_INET6 と PF_INET であることがわかった。

「fam 10 socket」は IPv6 接続で、
「fam 2 socket」は IPv4 接続ということになる。

Apache エラーログを再び確認する

「HTTPS: fam 10 socket created to connect to」の後に接続タイムアウトを起こしていた。ここでは IPv6 で接続しようとして何らかの要因で接続できなかったようだ。

その後「HTTPS: fam 2 socket created to connect to」ですぐに接続できていた。こちらは IPv4 ではすぐに接続できたのだろうということがわかる。

[proxy:trace2] proxy_util.c(3012): HTTPS: fam 10 socket created to connect to foobar.example.com
[proxy:debug] proxy_util.c(3037): (70007)The timeout specified has expired: AH00957: HTTPS: attempt to connect to [XXXX:XXXX:XXXX:XXXX::XXXX]:443 (foobar.example.com) failed
[proxy:trace2] proxy_util.c(3012): HTTPS: fam 2 socket created to connect to foobar.example.com
[proxy:debug] proxy_util.c(3046): AH02824: HTTPS: connection established with XXX.XXX.XXX.XXX:443 (foobar.example.com)

結論

IPv6 で接続しようとして何らかの要因で接続できず1分ほど待たされる
その後 IPv4 で接続してすぐにレスポンスが返される
IPv6 で接続がうまくいかない問題は別途調査が必要・・・