抽象ソケットアドレス abstract socket address

抽象ソケットアドレス abstract socket address について 2011年にエントリを書いていた

d.hatena.ne.jp

しばらく存在を忘れていたのだけど、社内 slack に話題が上がって思い出した。以下のような UNXI ソケットの亜種である。

abstract (抽象): 抽象ソケットアドレスは、 sun_path[0] がヌルバイト ('\0') であることから区別できる。 sun_path の残りの全バイトによりソケットの「名前」が定義される (名前中のヌルバイトには特別な意味はない)。 この名前はファイルシステムのパス名とは何の関係もない。 この名前空間におけるソケットのアドレスは、 sun_path の残りのバイトで表される。 getsockname(2), getpeername(2), accept(2) が抽象ソケットのアドレスを返す際には、その長さは sizeof(struct sockaddr_un) であり、 sun_path に抽象名前空間の名前が格納される。 ソケットの抽象名前空間は Linux による拡張であり、移植性はない。

Man page of UNIX

straec でトレースした場合

strace では @ 付きで表示される

vagrant@vagrant:~$ strace -econnect socat - abstract-connect:"hoge"
connect(5, {sa_family=AF_LOCAL, sun_path=@"hoge"}, 7) = -1 ECONNREFUSED (Connection refused)

うっかり @ ナルト を見落としてしまいそう

strace の実装

sockaddr.c に表示のロジックが書いてあります

static void
print_sockaddr_data_un(const void *const buf, const int addrlen)
{
        const struct sockaddr_un *const sa_un = buf;
        const int un_len = addrlen > (int) sizeof(*sa_un)
                           ? (int) sizeof(*sa_un) : addrlen;
        const int path_len = un_len - SIZEOF_SA_FAMILY;

        tprints("sun_path="); 
        if (sa_un->sun_path[0]) {
                print_quoted_string(sa_un->sun_path, path_len + 1,
                                    QUOTE_0_TERMINATED);
        } else {
                tprints("@"); 👈
                print_quoted_string(sa_un->sun_path + 1, path_len - 1, 0); 
        }   
}

ユースケース

web アプリケーションを作ってる時は特に必要とされるユースケースを見出せない。特殊なミドルウェアを実装する際に便利な使い方ができそう ( 社内 slack では D-Bbus の話題としてとりあげられていた ).

ファイルシステムに依存しないソケットとして扱える一方、セキュリティモデルはどう扱うべきなのだろうか

【まとめ】CentOS7 で glibc をアップデート後、 mod_php + httpd の logrotate (reload ) が失敗する: /lib64/libresolv.so.2: symbol __h_errno, version GLIBC_PRIVATE not defined in file libc.so.6 with link time reference

3つのエントリで問題を追いかけたのでまとめ

追いかけていた問題

httpd + mod_php で glibc をアップデート後、 logrotate 時に以下のログを出して失敗する問題を追っていた

Graceful restart requested, doing restart httpd: Syntax error on line 39 of /etc/httpd/conf/httpd.conf: Syntax error on line 1 of /etc/httpd/conf.modules.d/php7.load: /lib64/libresolv.so.2: symbol __h_errno, version GLIBC_PRIVATE not defined in file libc.so.6 with link time reference

hiboma.hatenadiary.jp

１つめのエントリで、再現の手順とコードをまとめた

hiboma.hatenadiary.jp

2つめのエントリで、原因を分析した

hiboma.hatenadiary.jp

3つめのエントリで、問題を起こす glibc のバージョンやパッチ・コミットログを追った

まとめと感想

• コンテナ環境に移行することで glibc のアップデートでこのような問題にも遭遇しなくなり、ナレッジの価値が薄れていくかもしれない
• 一方で、コンテナを提供するレイヤを扱う人や、依然として非コンテナ ( VM や オンプレーサーバー) で動き続ける環境では 上記にまとめた内容やデバッグ方法が何らかの形で役に立ってくれるとよいなと思ってる

【Vol.3 変更履歴の追跡】CentOS7 で glibc をアップデート後、 mod_php + httpd の logrotate (reload ) が失敗する: /lib64/libresolv.so.2: symbol __h_errno, version GLIBC_PRIVATE not defined in file libc.so.6 with link time reference

hiboma.hatenadiary.jp

hiboma.hatenadiary.jp

上記エントリの続きです

前回まで調べていたこと

• CentOS7 で glibc をアップデート後、 mod_php + httpd の logrotate (reload ) が失敗するのを調べていた
• 失敗する際に以下のログを出す

Graceful restart requested, doing restart httpd: Syntax error on line 39 of /etc/httpd/conf/httpd.conf: Syntax error on line 1 of /etc/httpd/conf.modules.d/php7.load: /lib64/libresolv.so.2: symbol __h_errno, version GLIBC_PRIVATE not defined in file libc.so.6 with link time reference

• 前回のエントリまでで再現を取ることができた

本エントリのサマリ

前回のまとめに「glibc をアップデートすると再現する」とさらっと書いているが、「glibc をどのバージョンから、どのバージョンにアップデートすると再現するの?」 をさらに調べて本エントリにまとめている。さらに __h_errno の変更がどういった経緯で入ったのかも調べた

• 問題となる __h_errno シンボルは、 CentOS 7.5.1804 でリリースされた glibc-2.17-222.el7.x86_64.rpm から登場する
• それ以前は h_errno というシンボルだっただった
• h_errno --> __h_errno への変更は、 glibc upstream が POSIX 2008 の変更に追随するためのパッチを取り込んだことによる

というサマリです

1. 調査: RPM をダウンロード, 展開, シンボルを調べる

http://mirror.centos.org と http://vault.centos.org から RPM をダウンロードして展開、libc.so.6 のシンボルを地道に見ていく作業で調べた

cd /tmp
mkdir glibc-2.17-196
cd    glibc-2.17-196
wget http://vault.centos.org/7.4.1708/os/x86_64/Packages/glibc-2.17-196.el7.x86_64.rpm
rpm2cpio glibc-2.17-196.el7.x86_64.rpm  | cpio -idv
nm ./lib64/libc.so.6 | grep h_errno$

CentOS7.4.1708: glibc-2.17-196.el7.x86_64.rpm

$ nm ./lib64/libc.so.6 | grep h_errno$
000000000000007c b __libc_h_errno
000000000000007c B h_errno

http://vault.centos.org/7.4.1708/os/x86_64/Packages/glibc-2.17-196.el7.x86_64.rpm

CentOS7.4.1708: glibc-2.17-196.el7_4.2.x86_64.rpm

$ nm ./lib64/libc.so.6 | grep h_errno$
000000000000007c b __libc_h_errno
000000000000007c B h_errno

http://vault.centos.org/7.4.1708/updates/x86_64/Packages/glibc-2.17-196.el7_4.2.x86_64.rpm

CentOS7.5.1804: glibc-2.17-222.el7.x86_64.rpm

$ nm ./lib64/libc.so.6 | grep h_errno$
000000000000008c B __h_errno 👈
000000000000008c b __libc_h_errno

これだー!!!!!

http://vault.centos.org/7.5.1804/os/x86_64/Packages/glibc-2.17-222.el7.x86_64.rpm

表にまとめてみましょう

リリース	バージョン	__h_errno の有無
7.4.1708	glibc-2.17-196.el7.x86_64.rpm	x
7.4.1708	glibc-2.17-196.el7_4.2.x86_64.rpm	x
7.5.1804	glibc-2.17-222.el7.x86_64.rpm 👈	o
7.6.1810	glibc-2.17-260.el7.x86_64	o
7.6.1810	glibc-2.17-260.el7_6.3.x86_64	o

👈 をつけた CentOS7.5.1804 glibc-2.17-222.el7.x86_64.rpm から __h_errno が登場する

__h_errno の有無 が x から o の バージョンにアップデートすると、このエントリで追いかけている問題を踏んでしまうと絞り込める (実際には全部のケースで試していないので推論です)

2. 深追い: __h_errno に変更したパッチを探す

CentOS 7.5.1804 glibc-2.17-222.el7 のどういったパッチが入ったことで h_errno が __h_errno に変更されたのかを調べていく

SRPM を展開して探す

古い SRPM は vault.centos.org から探し出します

$ wget https://vault.centos.org/7.5.1804/os/Source/SPackages/glibc-2.17-222.el7.src.rpm
$ rpm -ivh glibc-2.17-222.el7.src.rpm

で、適当に grep して以下を見つけました

~/rpmbuild/SOURCES/glibc-rh677316-h_errno.patch

パッチの中身は下記の通りです

Partial backport of this upstream commit:

commit 9acacaa02f3b75fddc07a56f3d848df45281a5de
Author: Joseph Myers <joseph@codesourcery.com>
Date:   Fri Jun 12 10:10:18 2015 +0000

    Fix h_errno namespace (bug 18520).

The linknamespace test changes in conform/Makefile are not included here
because glibc 2.17 did not have these tests.

diff --git a/include/netdb.h b/include/netdb.h
index b6d7b90bbf8abd2e..6a6dca9ef57aaa37 100644
--- a/include/netdb.h
+++ b/include/netdb.h
@@ -8,7 +8,7 @@
 #  if IS_IN (libc)
 #   define h_errno __libc_h_errno
 #  else
-#   define h_errno h_errno    /* For #ifndef h_errno tests.  */
+#   define h_errno __h_errno
 #  endif
 extern __thread int h_errno attribute_tls_model_ie;
 # endif /* IS_IN_LIB */
diff --git a/inet/herrno.c b/inet/herrno.c
index 1802d0e00563839a..0cd84445190728b3 100644
--- a/inet/herrno.c
+++ b/inet/herrno.c
@@ -24,7 +24,7 @@
 /* We need to have the error status variable of the resolver
    accessible in the libc.  */
 
-__thread int h_errno;
-extern __thread int __libc_h_errno __attribute__ ((alias ("h_errno")))
+__thread int __h_errno;
+extern __thread int __libc_h_errno __attribute__ ((alias ("__h_errno")))
   attribute_hidden;
 #define h_errno __libc_h_errno
diff --git a/nptl/herrno.c b/nptl/herrno.c
index c0488e4f6754873f..5056e3df88211123 100644
--- a/nptl/herrno.c
+++ b/nptl/herrno.c
@@ -23,12 +23,12 @@
 
 /* We need to have the error status variable of the resolver
    accessible in the libc.  */
-extern __thread int h_errno;
+extern __thread int __h_errno;
 
 
 /* When threaded, h_errno may be a per-thread variable.  */
 int *
 __h_errno_location (void)
 {
-  return &h_errno;
+  return &__h_errno;
 }
diff --git a/resolv/Versions b/resolv/Versions
index 93faf1e2f5faac79..152ef3f68f9a8b48 100644
--- a/resolv/Versions
+++ b/resolv/Versions
@@ -26,7 +26,7 @@ libc {
   GLIBC_PRIVATE {
     __gai_sigqueue;
 
-    h_errno; __resp;
+    __h_errno; __resp;
 
     __res_maybe_init; __res_iclose;
   }

コミットログが短い!!!1

3. オリジナナルのコミット/チケット/issue を探す

SRPM に含まれる libc-rh677316-h_errno.patch は、コミットログの詳細を削っているため変更の理由や文脈がよくわからない.　地道にググって探し出します

Fix h_errno namespace (bug 18520). を手がかりに調べいくと下記がヒットする

• https://sourceware.org/bugzilla/show_bug.cgi?format=multiple&id=18520
• http://thread.gmane.org/gmane.comp.lib.glibc.alpha/52266

上記からコミットログを転載する

 The 2008 edition of POSIX removed h_errno, but some functions still
bring in references to the h_errno external symbol.  As this symbol is
not a part of the public ABI (only __h_errno_location is), this patch
fixes this by renaming the GLIBC_PRIVATE TLS symbol to __h_errno.

Tested for x86_64 and x86 (testsuite, and comparison of installed
shared libraries).  Disassembly of all shared libraries using h_errno
changes because of the renaming (and changes to associated TLS / GOT
offsets in some cases); disassembly of libpthread on x86_64 changes
more substantially because the enlargement of .dynsym affects
subsequent addresses.

2015-06-11  Joseph Myers  

    [BZ #18520]
    * inet/herrno.c (h_errno): Rename to __h_errno.
    (__libc_h_errno): Define as alias of __h_errno not h_errno.
    * include/netdb.h [IS_IN_LIB && !IS_IN (libc)] (h_errno): Define
    to __h_errno instead of h_errno.
    * nptl/herrno.c (h_errno): Rename to __h_errno.
    (__h_errno_location): Refer to __h_errno not h_errno.
    * resolv/Versions (h_errno): Rename to __h_errno.
    * conform/Makefile (test-xfail-XOPEN2K8/grp.h/linknamespace):
    Remove variable.
    (test-xfail-XOPEN2K8/pwd.h/linknamespace): Likewise.

なるほど? Google 翻訳を載せておきます

POSIXの2008年版はh_errnoを削除しました、しかし、いくつかの関数はまだh_errno外部シンボルへの参照を持ち込みます。このシンボルはパブリックABIの一部ではないため（h_errno_locationのみ）、GLIBC_PRIVATE TLSシンボルの名前をh_errnoに変更することでこれを修正します。

x86_64とx86用にテスト済み（testsuite、およびインストール済み共有ライブラリの比較）。 h_errnoを使用したすべての共有ライブラリの逆アセンブリは、名前の変更（および場合によっては関連するTLS / GOTオフセットの変更）によって変更されます。 x86_64でのlibpthreadの逆アセンブリは、.dynsymの拡大が後続のアドレスに影響を与えるため、より大幅に変更されます。

glibc upstream が POSIX 2008 に追随するための変更だったのだと理解した

GLIBC_PRIVATE TLS とは?

GLIBC_PRIVATE についてはここを読んだ

https://groups.google.com/forum/#!topic/uk.comp.os.linux/PX3rstGtZRQ

GLIBC_PRIVATE is the version given to symbols exported by the GNU C library only for the purpose of communicating with other parts of the library.

関数のスコープを glibc 内でのみに閉じる用途で使うものぽい. あと TLS は Thread Locl Storage かなぁ.

readelf で確認する

$ readelf -a ./lib64/libc.so.6  | grep h_errno
  1483: 000000000000007c     4 TLS     GLOBAL DEFAULT   23 h_errno@@GLIBC_PRIVATE
  1928: 0000000000110390    17 FUNC    GLOBAL DEFAULT   12 __h_errno_location@@GLIBC_2.2.5
  3875: 000000000000007c     4 TLS     LOCAL  DEFAULT   23 __libc_h_errno
  5135: 0000000000110390    17 FUNC    LOCAL  DEFAULT   12 __GI___h_errno_location
  6483: 0000000000110390    17 FUNC    GLOBAL DEFAULT   12 __h_errno_location
  7573: 000000000000007c     4 TLS     GLOBAL DEFAULT   23 h_errno

$ readelf -a ./lib64/libc.so.6  | grep h_errno
  1495: 000000000000008c     4 TLS     GLOBAL DEFAULT   23 h_errno@GLIBC_PRIVATE
  1859: 000000000000008c     4 TLS     GLOBAL DEFAULT   23 __h_errno@@GLIBC_PRIVATE
  1946: 0000000000118cf0    17 FUNC    GLOBAL DEFAULT   12 __h_errno_location@@GLIBC_2.2.5
  3925: 000000000000008c     4 TLS     LOCAL  DEFAULT   23 __libc_h_errno
  5213: 0000000000118cf0    17 FUNC    LOCAL  DEFAULT   12 __GI___h_errno_location
  6580: 0000000000118cf0    17 FUNC    GLOBAL DEFAULT   12 __h_errno_location
  7075: 000000000000008c     4 TLS     GLOBAL DEFAULT   23 __h_errno
  7147: 000000000000008c     4 TLS     GLOBAL DEFAULT   23 h_errno@GLIBC_PRIVATE 👈

4. POSIX 2008 とは何なのか?

さて、先のコミットログで 2008 edition of POSIX についての記述があったのでさらに調べる

まず見つけたのは gethostbyname(3) の man ページである

POSIX.1-2008 では gethostbyname(), gethostbyaddr(), h_errno の仕様が削除されている。 代わりに、 getaddrinfo(3) と getnameinfo(3) の使用が推奨されている。

getaddrinfo() 関数は、 gethostbyname(3) と getservbyname(3) の機能をまとめて一つのインターフェースにしたものであるが、 これらの関数と違い、 getaddrinfo() はリエントラントであり、 getaddrinfo() を使うことでプログラムは IPv4 と IPv6 の違いに関する依存関係を なくすことができる。

https://linuxjm.osdn.jp/html/LDP_man-pages/man3/gethostbyname.3.html

さらにググっていくと POSIX のページと思われる http://pubs.opengroup.org/onlinepubs/9699919799.2008edition/ を見つけた

h_errno

Applications are recommended not to use this error return code. Previously it was set by the gethostbyaddr() and gethostbyname() functions.

POSIX で変更が入った理由が良く分からないが、IPv4/IPv6 の話周りを整えるためなんだろうか?

まとめ

• glibc のパッチまで踏み込んで追いかけた
• glibc のメンテナさんはは 上位のアプリケーションで問題が出ないように実装を進めてくれているのだろうが、今回のように不具合として踏んでしまうケースもあるのだろうなぁ
• glibc や POSIX の変更なんぞを普段全く気にすることなく生きている

参考

• Qiita @koara-local - RPMをインストールせずにカレントディレクトリ以下に展開する
• Fix h_errno namespace (bug 18520)
• getaddrinfo
• Geek なぺーじ - getaddrinfo

【Vol2. 原因分析】 CentOS7 で glibc をアップデート後、 mod_php + httpd の logrotate (reload ) が失敗する: /lib64/libresolv.so.2: symbol __h_errno, version GLIBC_PRIVATE not defined in file libc.so.6 with link time reference

hiboma.hatenadiary.jp

の続き。

本エントリのサマリ

• CentOS7 で httpd + mod_php が起動している
• glibc のアップデートをすると __h_errno シンボルが増える
• httpd の reload をしても httpd プロセスが古い glibc を参照しつづており、libphp5 -> libresolv.so が依存する __h_errno シンボルを解決できない
• 結果、httpd が reload 失敗 する

という現象をおった. 以下はその詳細

前回のログを調べ直す

前回のエントリでは下記のログを調べていた

/lib64/libresolv.so.2: symbol __h_errno, version GLIBC_PRIVATE not defined in file libc.so.6 with link time reference

symbol __h_errno が未定義だと言っているので、素直にそのシンボルを調べ直した

__h_errnor のシンボルを調査する

glibc のアップデート前後でシンボルを採取して比較してみたところ、アップデート後に __h_errno のシンボルが増えていた

glibc アップデート前

再現を取った時のバージョンは glibc-2.17-196.el7.x86_64

$ nm          /lib64/libresolv.so.2 | grep __h_errno

$ objdump -Tt /lib64/libresolv.so.2 | grep __h_errno

$ nm /lib64/libc.so.6 | grep __h_errno
0000000000110390 t __GI___h_errno_location
0000000000110390 T __h_errno_location

$ objdump -Tt /lib64/libc.so.6  | grep __h_errno
0000000000110390 l     F .text 0000000000000011              __GI___h_errno_location
0000000000110390 g     F .text 0000000000000011              __h_errno_location
0000000000110390 g    DF .text 0000000000000011  GLIBC_2.2.5 __h_errno_location

glibc アップデート後

再現を取った時のバージョンは glibc-2.17-196.el7.x86_64.

$ nm /lib64/libresolv.so.2 | grep __h_errno
                U __h_errno@@GLIBC_PRIVATE

$ objdump -Tt /lib64/libresolv.so.2  | grep __h_errno
0000000000000000         *UND* 0000000000000000              __h_errno@@GLIBC_PRIVATE 👈
0000000000000000      D  *UND* 0000000000000000  GLIBC_PRIVATE __h_errno 👈

$ nm /lib64/libc.so.6 | grep __h_errno
0000000000117ff0 t __GI___h_errno_location
000000000000008c B __h_errno 👈
0000000000117ff0 T __h_errno_location

$ objdump -Tt /lib64/libc.so.6  | grep __h_errno
0000000000117ff0 l     F .text  0000000000000011              __GI___h_errno_location
0000000000117ff0 g     F .text  0000000000000011              __h_errno_location
000000000000008c g       .tbss  0000000000000004              __h_errno 👈
000000000000008c g    D  .tbss  0000000000000004  GLIBC_PRIVATE __h_errno 👈
0000000000117ff0 g    DF .text  0000000000000011  GLIBC_2.2.5 __h_errno_location

👈 に指した __h_errno が増えている

httpd を起動してる状態で glibc をアップデートすると何が起きるか

httpd を起動してる状態で glibc をアップデートすると何が起きているか? lsof で見るとわかるのだが、httpd は古い libc.so と libresolv.so を参照し続けている

$ sudo lsof -p $(pgrep httpd | head -1) | grep -e libresolv -e libc-2.17
httpd   2843 root  DEL    REG              253,0           33566307 /usr/lib64/libresolv-2.17.so;5c530fe7
httpd   2843 root  DEL    REG              253,0           33562151 /usr/lib64/libc-2.17.so;5c530fe7

• DEL = ファイルシステムからパスは消えているが、参照カウントが残っているのでファイルの実体は残っている
• 古い .so を参照し続けるのは、(確か) RPM が rename(2) で新しい glibc に置き換えるから.

pmap(3) でもよい

mmap(2) している仮想アドレスも把握したいのであれば pmap(3) を使う

$ sudo pmap -p $(pgrep httpd | head -1) | grep -e libresolv -e libc-2.17
00007f193f553000     88K r-x-- /usr/lib64/libresolv-2.17.so;5c530fe7 (deleted)
00007f193f569000   2048K ----- /usr/lib64/libresolv-2.17.so;5c530fe7 (deleted)
00007f193f769000      4K r---- /usr/lib64/libresolv-2.17.so;5c530fe7 (deleted)
00007f193f76a000      4K rw--- /usr/lib64/libresolv-2.17.so;5c530fe7 (deleted)
00007f194b9d3000   1760K r-x-- /usr/lib64/libc-2.17.so;5c530fe7 (deleted)
00007f194bb8b000   2048K ----- /usr/lib64/libc-2.17.so;5c530fe7 (deleted)
00007f194bd8b000     16K r---- /usr/lib64/libc-2.17.so;5c530fe7 (deleted)
00007f194bd8f000      8K rw--- /usr/lib64/libc-2.17.so;5c530fe7 (deleted)

観測: httpd を realod すると?

httpd を reload する際の strace をとると、古い /lib64/libresolv.so.2 や libphp5.so をアンロード ( munmap(2) )し、再度ロードするのが観測できる

アンロードの様子

reload している際に munmap(2) で観測できる

/* strace で munmap だけに絞り込んでいる */

munmap(0x7f67113ac000, 1052672)         = 0
munmap(0x7f67114ad000, 266240)          = 0
munmap(0x7f671135d000, 323584)          = 0
munmap(0x7f6703797000, 6742568)         = 0
munmap(0x7f6703305000, 2584736)         = 0
munmap(0x7f67030ec000, 2198200)         = 0
munmap(0x7f6702d82000, 3575896)         = 0

要注意なのが、 httpd の reload 時に glibc はアンロードされないのだ

再ロードの様子

/* strace で open, mmap だけに絞り込んでいる */

16:50:58 open("/etc/httpd/modules/libphp5.so", O_RDONLY|O_CLOEXEC) = 8</usr/lib64/httpd/modules/libphp5.so> <0.000008>
16:50:58 mmap(NULL, 6742568, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 8</usr/lib64/httpd/modules/libphp5.so>, 0) = 0x7fcc710b6000 <0.000007>
16:50:58 mmap(0x7fcc71676000, 606208, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 8</usr/lib64/httpd/modules/libphp5.so>, 0x3c0000) = 0x7fcc71676000 <0.000008>
16:50:58 mmap(0x7fcc7170a000, 107048, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fcc7170a000 <0.000009>
16:50:58 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 8</etc/ld.so.cache> <0.000009>
16:50:58 mmap(NULL, 19484, PROT_READ, MAP_PRIVATE, 8</etc/ld.so.cache>, 0) = 0x7fcc7ee1b000 <0.000006>
16:50:58 open("/lib64/libresolv.so.2", O_RDONLY|O_CLOEXEC) = 8</usr/lib64/libresolv-2.17.so> <0.000008>

...

httpd が etc/httpd/modules/libphp5.so を dleopen(3) して、ld.so が依存の共有ライブラリを解決していく

時系列の整頓

調べたことを時系列に起こす

1. httpd + mod_php が起動している

2. glibc をアップデートする

httpd は 古い glibc を参照し続ける

2. httpd を reload する

httpd の親プロセスは pid を変えずに reload を始める

• httpd の親プロセスは 古い glibc を参照したまま libphp5.so をロードし直す
• libphp5.so をロードする際に、依存している /lib64/libresolv.so.2 をロードする
• /lib64/libresolv.so をロードする際に symbol __h_errno を解決しようとするが、 httpd は古い glibc を参照したまま であり、古い glibc では __h_errno を解決できない

エラーとして扱われ、上位の httpd 層まで伝播して Syntax Error となる

ということだろうか? とアタリをつけた

LD_DEBUG=symbols,bindings で追いかける

LD_DEBUG オプションの存在を思い出したので、これでデバッグログをとり確認を取った

/* sudo vim /etc/sysconfig/httpd */
LD_DEBUG=symbols,bindings

LD_DEBUG 環境変数をセットして再現をとりなおすと /var/log/httpd/error_log に大量のログがでてくる

      2841:  symbol=__h_errno;  lookup in file=/usr/sbin/httpd [0]
      2841: symbol=__h_errno;  lookup in file=/lib64/libpcre.so.1 [0]
      2841: symbol=__h_errno;  lookup in file=/lib64/libselinux.so.1 [0]
      2841: symbol=__h_errno;  lookup in file=/lib64/libaprutil-1.so.0 [0]
      2841: symbol=__h_errno;  lookup in file=/lib64/libcrypt.so.1 [0]
      2841: symbol=__h_errno;  lookup in file=/lib64/libexpat.so.1 [0]
      2841: symbol=__h_errno;  lookup in file=/lib64/libdb-5.3.so [0]
      2841: symbol=__h_errno;  lookup in file=/lib64/libapr-1.so.0 [0]
      2841: symbol=__h_errno;  lookup in file=/lib64/libpthread.so.0 [0]
      2841: symbol=__h_errno;  lookup in file=/lib64/libdl.so.2 [0]
👉    2841:   symbol=__h_errno;  lookup in file=/lib64/libc.so.6 [0]
🔥    2841:   /lib64/libresolv.so.2: error: relocation error: symbol __h_errno, version GLIBC_PRIVATE not defined in file libc.so.6 with link time reference (fatal)

ダイナミックリンカ? が __h_errno のシンボルを順に探していく様子、 /lib64/libc.so.6 で lookup が失敗しているのがトレースできた

まとめ

• 当初は別のバグを疑ってかかっていて、シンボルを調べることをしなかった ( 同僚である zipper が最初にそれを指摘してくれていたのだがスルーしてしまった)
• 特殊な条件が重なって怒るので「バグ」とも言えない、びみょーな不具合だなぁ

CentOS7 で glibc をアップデート後、 mod_php + httpd の logrotate (reload ) が失敗する: /lib64/libresolv.so.2: symbol __h_errno, version GLIBC_PRIVATE not defined in file libc.so.6 with link time reference

CentOS7 で glibc をアップデート後、mod_php + httpd の logrotate(reload) に失敗する という内容を追いかけるエントリです

(追記)

社内で共有してみたところ、前に踏んだ && 対応してたという事例もあがってきた。よくある問題なのかなぁ

経緯

社内の同僚から「Apache が logrotate 時にコケて困った」という相談を受けてログを見ていた

エラーログ

CentOS7 のホストで、こんなログがでていたと教えてもらった (これはリアルなログ)

[Sun Jan 27 03:36:01.359870 2019] [mpm_prefork:notice] [pid 32379] AH00171: Graceful restart requested, doing restart httpd: Syntax error on line 39 of /etc/httpd/conf/httpd.conf: Syntax error on line 1 of /etc/httpd/conf.modules.d/php7.load: Cannot load modules/libphp7.so into server: /lib64/libresolv.so.2: symbol __h_errno, version GLIBC_PRIVATE not defined in file libc.so.6 with link time reference

付随する情報として

• このログを出して logrotate 時の reload が失敗して httpd プロセスが死んでしまう
• 改めて systemctrl start httpd すると何事もなく起動する
• 複数のホストで発生した ( production, staging 環境 etc )

も教えてもらった

何が問題か? 推論を立てていく

エラーログや glibc の yum アップデートの時刻をまとめてみたところ

• httpd + mod_php が起動している状態だった
• glibc をアップデートしていた
• 早朝の logrotate 時に冒頭のエラーを引き起こしていた

を突き止めた

以上を元にして Vagrant で再現を試みた

再現コード

このブログを書いている時点では、以下の Vagrantfile で再現が取れる

# -*- mode: ruby -*-

Vagrant.configure("2") do |config|
  config.vm.box = "centos/7"
  config.vm.provision "shell", inline: <<-SHELL
yum install -y httpd php lsof gdb
systemctl start httpd
yum install -y glibc
rpm -q glibc
rpm -q httpd
systemctl reload httpd.service
cat /var/log/httpd/error_log
SHELL
end

上記を Vagrantfile として書いて vagrant up 実行で冒頭のエラーログを再現できる

再現時のログ

[vagrant@localhost ~]$ sudo cat /var/log/httpd/error_log
[Tue Jan 29 15:52:05.240309 2019] [core:notice] [pid 2832] SELinux policy enabled; httpd running as context system_u:system_r:httpd_t:s0
[Tue Jan 29 15:52:05.240883 2019] [suexec:notice] [pid 2832] AH01232: suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)
AH00558: httpd: Could not reliably determine the server's fully qualified domain name, using localhost.localdomain. Set the 'ServerName' directive globally to suppress this message
[Tue Jan 29 15:52:05.254153 2019] [auth_digest:notice] [pid 2832] AH01757: generating secret for digest authentication ...
[Tue Jan 29 15:52:05.254796 2019] [lbmethod_heartbeat:notice] [pid 2832] AH02282: No slotmem from mod_heartmonitor
[Tue Jan 29 15:52:05.264794 2019] [mpm_prefork:notice] [pid 2832] AH00163: Apache/2.4.6 (CentOS) PHP/5.4.16 configured -- resuming normal operations
[Tue Jan 29 15:52:05.264816 2019] [core:notice] [pid 2832] AH00094: Command line: '/usr/sbin/httpd -D FOREGROUND'
🔥 [Tue Jan 29 15:53:02.467917 2019] [mpm_prefork:notice] [pid 2832] AH00171: Graceful restart requested, doing restart
httpd: Syntax error on line 56 of /etc/httpd/conf/httpd.conf: Syntax error on line 6 of /etc/httpd/conf.modules.d/10-php.conf: Cannot load modules/libphp5.so into server: /lib64/libresolv.so.2: symbol __h_errno, version GLIBC_PRIVATE not defined in file libc.so.6 with link time reference

再現した環境で、問題に関係しそうなパッケージのバージョンは以下の通りになる

• glibc-2.17-196.el7.x86_64 (アップデート前)
• glibc-2.17-260.el7.x86_64 (アップデート後)
• httpd-2.4.6-88.el7.centos.x86_64
• php-5.4.16-46.el7.x86_64

バグレポートを探す

bugzilla.redhat.com

上記のバグレポートが本エントリに書かれたのとほぼ一緒の内容だ。が、SL7 パッケージの不具合報告を RedHat に投げているので取り扱ってもらえていない ...

glibc を深追いする (未解決)

glibc-2.17-260.el7.src.rpm でエラーメッセージの出所を探る. with link time reference をキーワードにした. glibc の _dl_lookup_symbol_x() がエラーの出どころだった

/* Search loaded objects' symbol tables for a definition of the symbol
   UNDEF_NAME, perhaps with a requested version for the symbol.

   We must never have calls to the audit functions inside this function
   or in any function which gets called.  If this would happen the audit
   code might create a thread which can throw off all the scope locking.  */
lookup_t
internal_function
_dl_lookup_symbol_x (const char *undef_name, struct link_map *undef_map,
                     const ElfW(Sym) **ref,
                     struct r_scope_elem *symbol_scope[],
                     const struct r_found_version *version,
                     int type_class, int flags, struct link_map *skip_map)
{

...


  /* Search the relevant loaded objects for a definition.  */
  for (size_t start = i; *scope != NULL; start = 0, ++scope)
    {
      int res = do_lookup_x (undef_name, new_hash, &old_hash, *ref,
                             &current_value, *scope, start, version, flags,
                             skip_map, type_class, undef_map);
      if (res > 0)
        break;

      if (__builtin_expect (res, 0) < 0 && skip_map == NULL)
        {
          /* Oh, oh.  The file named in the relocation entry does not
             contain the needed symbol.  This code is never reached
             for unversioned lookups.  */
          assert (version != NULL);
          const char *reference_name = undef_map ? undef_map->l_name : NULL;

          /* XXX We cannot translate the message.  */
          _dl_signal_cerror (0, (reference_name[0]
                                 ? reference_name
                                 : (rtld_progname ?: "<main program>")),
                             N_("relocation error"),
                             make_string ("symbol ", undef_name, ", version ",
                                          version->name,
                                          " not defined in file ",
                                          version->filename,
                                          " with link time reference", 👈
                                          res == -2
                                          ? " (no version symbols)" : ""));
          *ref = NULL;
          return 0;
        }
    }

dlopen(3) の内部実装の箇所で、おそらく、動的リンク( relocation? ) する際にシンボル定義の探索をしているような処理に思うのだけど.

glibc は強すぎて全然分からない ...

まとめ

一過性の障害なので エラーの詳細をじっくりと時間をかけて解析したいモチベーションが無いかもしれない.

まずは別の環境でどうやって回避するか、かなぁ ...

お疲れ様です

zipper とボブさん、レポートありがとうございました && 対応お疲れ様です sugy さん、過去の事例共有ありがとうございます

『組織事故』『組織事故とレジリエンス』ジェームズ・リーズン(著) 📚

年末年始に以下の著作を購入し読んでいた。書評を書くほどまでには咀嚼できていないので、書籍の内容の紹介は一切ない。御了承を :)

組織事故―起こるべくして起こる事故からの脱出

組織事故とレジリエンス―人間は事故を起こすのか、危機を救うのか

どちらも同じ著者で重複する内容もあるのだが、翻訳・構成・挿絵がカッチリと書かれているのは古い方の『組織事故』の方だなという印象

日々イベント 🔥

現在 GMOペパボのセキュリティ対策室なる組織で業務をしているのだが、日々 大小のイベント ( セキュリティ ≒ 機密性・完全性 を脅かすもの以外にも、いわゆる障害 ≒ 可用性を脅かすものも何でも ) に遭遇している。

対策していても何か起きてしまったら どうするか?

組織を脅かすイベントが起きる前に十全に対策を重ねておくのは当然だ!!!1 そりゃそうだねと断ったうえで ...

そうではあっても避けようもない何らかのイベントは起きてしまうもので、では どうすれば 組織が迅速にイベントの発生を検知し、組織がイベントにより平衡を失った状態からリカバリーし、組織がイベントの損失を学習・アクションに転換していけるのか? というテーマでコミットできないかなぁと考えている

... とまぁ、そんなこともあっていろいろ読んでみるかと、冒頭の書籍を手にした次第

次に読みたい

下記の書籍も私の興味に答えてくれそうな中身っぽいので 次、手に取ろうと画策している

レジリエンスエンジニアリング―概念と指針

「レジリエンス」という単語がややバズワード感あるので心配になるが、そういう本では無いようだ

---

ところで Google SRE 本の Postmortem Culture: Learning from Failure は 失敗(障害) から学習を達成するためのプラクティスとして よく知られたものだろう。

弊社でも 昨年初めより Postmortem を取り入れていて、ゆっくりと時間をかけて技術者の中で文化・プロセスとして根付いて来ているのを実感している ( 偉そうに書いたが私が提案・推進した訳じゃないので かしこ )

landing.google.com

Postmortem もそうなんだけど、なかなかこういった組織的な文化・プロセス作りは一人で発起しても進まないもの。会社の中で取り組んでいくなら同士を募って進めたいところ。

『組織事故』『レジリエンスエンジニアリング』誰か一緒に読まない?

時坂峠 〜 都民の森 〜 風張峠 〜 奥多摩 🚴‍♂️

10/28(日) の記録。しばらく体調や天候にめぐまれずロングで走れて無かったけど、 久々に距離と獲得標高をしっかりと稼いで走ってきた

走行距離 165km, 獲得標高 1714m