Apacheの異常終了(一応解決)

 Apacheがエラーを出しまくっていたので、調査。最終的にはZend Framework/Smarty上に組んだサイトをとめたら現象が起きなくなった。

環境

  • FreeBSD 9.0
  • Apache 2.2.22
  • PHP 5.4.3
  • Perl 5.14.2
  • Zend Framework 1.5.3
  • Smarty 2.6.20

エラーの状況

  • Webサーバのカーネルログ上に、日々次のようなエラーが大量に残る。signal 11とはつまり、segmentation fault。
    +pid 83466 (httpd), uid 80: exited on signal 11
    +pid 83470 (httpd), uid 80: exited on signal 11
    +pid 83459 (httpd), uid 80: exited on signal 11
  •  Apacheのログには、次のようなエラーが残る。分類は [info]。
    (57)Socket is not connected: core_output_filter: writing data to the network
    (32)Broken pipe: core_output_filter: writing data to the network

    おそらく、segmentation faultと原因は一緒と推測される。というか、segmentation faultでサーバが落ちてしまうことが原因となって、このエラーが出るのだろう。

  • Webページをアクセスすると、空白のページが出力されることがある。毎回そうなるわけではなく、何度かリロードすると正しく表示される。空白のページになるのは、Zend Framework 1.5.3+Smarty 2.6.20で作成したページのみ。WordPress 3.3.2ではそのような問題は出ない。

core dumpの生成

  • /usr/local/etc/apache22/httpd.confに次の行を追加して、様子を見てみる。でもcoreが残らない。
    CoreDumpDirectory /tmp
  • ulimit -cで設定されているcoreファイルサイズの上限を超えるとcoreファイルが出力されないらしい。ulimit -cでサイズを確認し、必要に応じてunlimitedに設定する。
    ulimit -c unlimited

    確認したところ、unlimitedだった。

  • sysctlで、kern.sugid_coredumpが1に設定されていないとcoreが出力されないらしい。
    sysctl kern.sugid_coredump=1
  • Apacheを再起動。
    service apache22 restart

    これで/tmpの下にhttpd.coreが出力されるようになった。

 coreの解析

  • gdbで開いてみる。
    # gdb /usr/local/sbin/httpd -c /tmp/httpd.core
    GNU gdb 6.1.1 [FreeBSD]
    Copyright 2004 Free Software Foundation, Inc.
    GDB is free software, covered by the GNU General Public License, and you are
    welcome to change it and/or distribute copies of it under certain conditions.
    Type "show copying" to see the conditions.
    There is absolutely no warranty for GDB.  Type "show warranty" for details.
    This GDB was configured as "i386-marcel-freebsd"...
    Core was generated by `httpd'.
    Program terminated with signal 11, Segmentation fault.
    Reading symbols from /lib/libm.so.5...done.
    ・・・・・(略)・・・・・
    #0  0x2900a906 in zend_std_object_get_class (object=0x1c)
        at /usr/src/php-5.4.3/Zend/zend_object_handlers.c:1456
    1456    {
    [New Thread 28804300 (LWP 159614/httpd)]
    (gdb) where
    #0  0x2900a906 in zend_std_object_get_class (object=0x1c)
        at /usr/src/php-5.4.3/Zend/zend_object_handlers.c:1456
    #1  0x2901c7da in execute (op_array=0x0) at zend_vm_execute.h:410
    #2  0x28feb7a4 in zend_execute_scripts (type=8, retval=0x0, file_count=3)
        at /usr/src/php-5.4.3/Zend/zend.c:1272
    #3  0x28f8f0b9 in php_execute_script (primary_file=0xbfbfe950)
        at /usr/src/php-5.4.3/main/main.c:2473
    #4  0x29088a4e in php_handler (r=0x289ea110)
        at /usr/src/php-5.4.3/sapi/apache2handler/sapi_apache2.c:667
    #5  0x08076f39 in ap_run_handler (r=0x289ea110) at config.c:157
    #6  0x0807a20e in ap_invoke_handler (r=0x289ea110) at config.c:376
    #7  0x0808519a in ap_internal_redirect (new_uri=0x289ea100 "/index.php",
        r=0x289e8058) at http_request.c:554
    #8  0x287db390 in handler_redirect (r=0x289e8058) at mod_rewrite.c:4843
    #9  0x08076f39 in ap_run_handler (r=0x289e8058) at config.c:157
    #10 0x0807a20e in ap_invoke_handler (r=0x289e8058) at config.c:376
    #11 0x08085320 in ap_process_request (r=0x289e8058) at http_request.c:282
    #12 0x0808243b in ap_process_http_connection (c=0x289de1f0) at http_core.c:190
    #13 0x0807e219 in ap_run_process_connection (c=0x289de1f0) at connection.c:43
    #14 0x0808a3b1 in child_main (child_num_arg=Variable "child_num_arg" is not available.
    ) at prefork.c:667
    #15 0x0808a697 in make_child (s=0x28819f10, slot=7) at prefork.c:768
    #16 0x0808b047 in ap_mpm_run (_pconf=0x28818018, plog=0x28846018, s=0x28819f10)
        at prefork.c:903
    #17 0x0806424b in main (argc=679567384, argv=0x289dc018) at main.c:753
    (gdb)
    

試行錯誤

  • スタックトレースの中にmod_writeがあるので、.htaccessの設定を見てみる。ZendFramework用に次のように設定してあった。
    RewriteCond %{REQUEST_FILENAME} !-f
    RewriteRule ^(.*)$ /index.php [L,QSA]
    

    これを、次のように書き換えてみて様子を見る。

    RewriteCond %{REQUEST_FILENAME} !-f
    RewriteRule ^.*$ index.php [L,QSA]

    → segmentation faultは解消されない。

  • Zend Frameworkを1.5.3 → 1.11.11にアップデート。
    → segmentation faultは解消されない。ただし、微妙にトレース内容が変化。
    ・・・・・(略)・・・・・
    #0  0x2919af3d in zend_std_write_property (object=0x2a2999f8,
        member=0x29d358bc, value=0x2a296254, key=0x29d358bc)
        at /usr/src/php-5.4.3/Zend/zend_object_handlers.c:520
    520             property_info = zend_get_property_info_quick(zobj->ce, member, (zobj->ce->__set != NULL), key TSRMLS_CC);
    [New Thread 28804300 (LWP 100396/httpd)]
    (gdb) where
    #0  0x2919af3d in zend_std_write_property (object=0x2a2999f8,
        member=0x29d358bc, value=0x2a296254, key=0x29d358bc)
        at /usr/src/php-5.4.3/Zend/zend_object_handlers.c:520
    #1  0x291a85ca in zend_assign_to_object (retval=0x0, object_ptr=0x2964f208,
        property_name=0x29d358bc, value_type=4, value_op=0x29d361f0,
        Ts=0x289ffda4, opcode=136, key=0x29d358bc)
        at /usr/src/php-5.4.3/Zend/zend_execute.c:738
    #2  0x291ac739 in ZEND_ASSIGN_OBJ_SPEC_UNUSED_CONST_HANDLER (
        execute_data=0x289ffd24) at zend_vm_execute.h:22249
    #3  0x291aa38a in execute (op_array=0x29d35300) at zend_vm_execute.h:410
    #4  0x29179354 in zend_execute_scripts (type=8, retval=0x0, file_count=3)
        at /usr/src/php-5.4.3/Zend/zend.c:1272
    #5  0x2911cc69 in php_execute_script (primary_file=0xbfbfe950)
        at /usr/src/php-5.4.3/main/main.c:2473
    #6  0x292165fe in php_handler (r=0x29c8de58)
        at /usr/src/php-5.4.3/sapi/apache2handler/sapi_apache2.c:667
    #7  0x08076f39 in ap_run_handler (r=0x29c8de58) at config.c:157
    #8  0x0807a20e in ap_invoke_handler (r=0x29c8de58) at config.c:376
    #9  0x0808519a in ap_internal_redirect (new_uri=0x29c8de48 "/index.php",
        r=0x29c90058) at http_request.c:554
    #10 0x287d4380 in handler_redirect (r=0x29c90058) at mod_rewrite.c:4843
    #11 0x08076f39 in ap_run_handler (r=0x29c90058) at config.c:157
    #12 0x0807a20e in ap_invoke_handler (r=0x29c90058) at config.c:376
    #13 0x08085320 in ap_process_request (r=0x29c90058) at http_request.c:282
    #14 0x0808243b in ap_process_http_connection (c=0x289e61f0) at http_core.c:190
    #15 0x0807e219 in ap_run_process_connection (c=0x289e61f0) at connection.c:43
    #16 0x0808a3b1 in child_main (child_num_arg=Variable "child_num_arg" is not available.
    ) at prefork.c:667
    #17 0x0808a697 in make_child (s=0x28819f10, slot=7) at prefork.c:768
    #18 0x0808b047 in ap_mpm_run (_pconf=0x28818018, plog=0x28846018, s=0x28819f10)
        at prefork.c:903
    #19 0x0806424b in main (argc=679567384, argv=0x289e4018) at main.c:753
    (gdb)
  • Smarty 2.6.20 → 2.6.26にアップデートしてみる。
    → segmentation faultは解消されない。ただし、微妙にトレース内容が再び変化。SimpleXMLで落ちているように見える。
    ・・・・・(略)・・・・・
    #0  sxe_prop_dim_read (object=Variable "object" is not available.
    )
        at /usr/src/php-5.4.3/ext/simplexml/simplexml.c:291
    291                     attr = node ? node->properties : NULL;
    [New Thread 28804300 (LWP 100067/httpd)]
    (gdb) where
    #0  sxe_prop_dim_read (object=Variable "object" is not available.
    )
        at /usr/src/php-5.4.3/ext/simplexml/simplexml.c:291
    #1  0x291dcba0 in zend_fetch_dimension_address_read (result=0x28a01dcc,
        container_ptr=Variable "container_ptr" is not available.
    ) at /usr/src/php-5.4.3/Zend/zend_execute.c:1334
    #2  0x291de520 in ZEND_FETCH_DIM_R_SPEC_VAR_CONST_HANDLER (
        execute_data=0x28a01c98) at zend_vm_execute.h:12862
    #3  0x291aa38a in execute (op_array=0x2a1cb158) at zend_vm_execute.h:410
    #4  0x29179354 in zend_execute_scripts (type=8, retval=0x0, file_count=3)
        at /usr/src/php-5.4.3/Zend/zend.c:1272
    #5  0x2911cc69 in php_execute_script (primary_file=0xbfbfe950)
        at /usr/src/php-5.4.3/main/main.c:2473
    #6  0x292165fe in php_handler (r=0x29c8a018)
        at /usr/src/php-5.4.3/sapi/apache2handler/sapi_apache2.c:667
    #7  0x08076f39 in ap_run_handler (r=0x29c8a018) at config.c:157
    #8  0x0807a20e in ap_invoke_handler (r=0x29c8a018) at config.c:376
    #9  0x0808519a in ap_internal_redirect (new_uri=0x29c91f98 "/index.php",
        r=0x29c8e058) at http_request.c:554
    #10 0x287d4380 in handler_redirect (r=0x29c8e058) at mod_rewrite.c:4843
    #11 0x08076f39 in ap_run_handler (r=0x29c8e058) at config.c:157
    #12 0x0807a20e in ap_invoke_handler (r=0x29c8e058) at config.c:376
    #13 0x08085320 in ap_process_request (r=0x29c8e058) at http_request.c:282
    #14 0x0808243b in ap_process_http_connection (c=0x289e61f0) at http_core.c:190
    #15 0x0807e219 in ap_run_process_connection (c=0x289e61f0) at connection.c:43
    #16 0x0808a3b1 in child_main (child_num_arg=Variable "child_num_arg" is not available.
    ) at prefork.c:667
    #17 0x0808a697 in make_child (s=0x28819f10, slot=4) at prefork.c:768
    #18 0x0808b047 in ap_mpm_run (_pconf=0x28818018, plog=0x28846018, s=0x28819f10)
        at prefork.c:903
    #19 0x0806424b in main (argc=679567384, argv=0x289e4018) at main.c:753
    (gdb)
    
  • Smartyを3.1.10に上げるにはコーディングの見直しが必要らしいので、保留。SmartyかZend Frameworkのいずれかが原因と思われるも、これ以上の調査は今のところできない。
  • PHP 5.4.4にアップグレード。(2012-06-15)
    2台あるWebサーバーのうち、zend_objects_clone_membersでsegmentation faultを起こしていた方は異常終了しなくなった。しかし、メインで動かしている方は、相変わらずzend_std_object_get_classで落ちる。
  • PHP 5.4.5にアップグレード。(2012-07-31)
    変化なし。
  • Zend FrameworkおよびSmartyを使ったサイトの運用を停止したところ、現象が起きなくなった。いずれかのパッケージに原因があると思われるも、いずれのパッケージも今後使うことはなさそうなので、調査はこれにて終了。(2014-06-16)

cf. 「インフラエンジニアがSegmentation fault をなんとか治してみる」 (メモとかそんな感じなやつ)