ec-cube icon indicating copy to clipboard operation
ec-cube copied to clipboard

Output maillog - メールログの出力

Open nanasess opened this issue 8 years ago • 8 comments

\Silex\Provider\SwiftmailerServiceProvider は、メールログの出力をサポートしてないので、 EC-CUBE 側で用意したい。

nanasess avatar Sep 02 '15 10:09 nanasess

実装してみましたが、 segmentation fault で落ちてしまう模様 https://github.com/nanasess/ec-cube/commit/3a83c1cfc42b5e88329ec04d3a1c66bfc9b4cd23

SwiftMailer の transportStopped Event で落ちているようです.

https://github.com/swiftmailer/swiftmailer/blob/5.x/lib/classes/Swift/Transport/AbstractSmtpTransport.php#L224

nanasess avatar Nov 30 '15 10:11 nanasess

See also, refs https://github.com/swiftmailer/swiftmailer/issues/636

nanasess avatar Nov 30 '15 11:11 nanasess

リフレクションを使用して、 Swift_Events_TransportChangeEvent を除外してみましたが、 https://github.com/nanasess/ec-cube/commit/10c0dbd8ef44170b2b07811e7dcfe39fed339fe5

travis-ci で segmentation fault が発生してしまいます。 https://travis-ci.org/nanasess/ec-cube/builds/93914057

以下のように、 SwiftMailer 単体で試してみると問題なし。

class Swift_Smoke_LoggerSmokeTest extends SwiftMailerSmokeTestCase
{
    public function testLogger()
    {
        $mailer = $this->_getMailer();
        $logger = new \Swift_Plugins_Loggers_EchoLogger();
        $mailer->registerPlugin(new \Swift_Plugins_LoggerPlugin($logger));
        $message = Swift_Message::newInstance()
            ->setSubject('[Swift Mailer] BasicSmokeTest')
            ->setFrom(array(SWIFT_SMOKE_EMAIL_ADDRESS => 'Swift Mailer'))
            ->setTo(SWIFT_SMOKE_EMAIL_ADDRESS)
            ->setBody('One, two, three, four, five...'.PHP_EOL.
                'six, seven, eight...'
                )
            ;
        $this->assertEquals(1, $mailer->send($message),
            '%s: The smoke test should send a single message'
            );
    }
}

Silex + SwiftMailer の組み合せで問題が発生していると思われますが、原因不明ですので実装を保留します。

nanasess avatar Nov 30 '15 11:11 nanasess

実装してみましたが、 segmentation fault で落ちてしまう模様

ユニットテストで Faker::realText() を使用しつつ、 Monolog::TestHandler を使用している箇所で segmentation fault が発生している模様です。 Faker::realText()explode() を使用して、大量の要素(26,000以上)の配列を生成し、 Monolog::TestHandler がメモリ上の何らかの配列の操作をする(バッファリングする?)ことで、 segmentation fault が発生しているものと思われます。

  • ~~Faker::realText()Faker::text に変更することで正常実行される~~
  • ~~Monolog::TestHandler の処理は特殊なものではなく、実運用時に発生する可能性は少ないと考えられる~~

~~上記の理由から Faker::text へ変更し、ログ出力の実装を進めます~~

TestSuite を実行すると、後半で segmentation fault が発生してしまいますので Monolog::TestHandler の実装が原因かも :worried:

Monolog::TestHandler は、 Silex\Provider\MonologServiceProvider でコールされている Symfony\Bridge\Monolog\Handler\DebugHandler の継承元である。 TestHandler::write() にて、ログの内容を配列に代入する実装となっているが、この部分に問題がありそう。 ~~Monolog\Handler\StreamHandler のように、即座にストリームへ書き込んでやれば segmentation fault は発生しない。~~ StreamHandler を使用しても segmentation fault になるケースあり。

nanasess avatar Jul 21 '16 07:07 nanasess

stack trace を見てみましたが、現象としては、こちらが近いです。 https://bugs.php.net/bug.php?id=70007 https://bugs.php.net/bug.php?id=64827

循環参照が大量にできるとだめっぽい https://bugs.php.net/bug.php?id=63635

nanasess avatar Jul 22 '16 02:07 nanasess

このデストラクタの stop() で、イベントハンドラがコールされると segmentation fault になるっぽいです https://github.com/swiftmailer/swiftmailer/blob/5.x/lib/classes/Swift/Transport/AbstractSmtpTransport.php#L494

nanasess avatar Jul 27 '16 09:07 nanasess

いろいろ調べてみたところ、 大量の循環参照が生成された後の GC で segmentation fault になる模様です。 (gc_collect_cycle() の返り値が 6万を越えたあとに segfault になるのを確認しました) いくつかの複合要因が考えられますが、 DI コンテナである Pimple も、 Symfony も Doctrine も大量の循環参照を発生させており、更にそれらの内部で配列をコピーするようなロジックが引き金になっていると思われます。

ちなみに、 Pimple 2.1.0 では C の extension が用意されており、これらの対策をしているのではないかと思われます。(何故 C extension を開発したのかというドキュメントは見つけられませんでした。。。) https://github.com/silexphp/Pimple/tree/v2.1.0/ext/pimple

根本的には、 Zend Optimizer のバグを踏んでいるのだと思いますが、 EC-CUBE 側でどうにか回避するのは難しいかもしれません。 (PHP5.3-7.0 まですべてのバージョンで発生します)

nanasess avatar Aug 02 '16 09:08 nanasess

現状PHPの問題で対応しきれないため、参考資料、document扱いとしてリリースマイルストーンから外します。

Yangsin avatar Nov 25 '16 07:11 Yangsin