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 )

も教えてもらった

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

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

  • 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

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

バグレポートを探す

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 さん、過去の事例共有ありがとうございます