Month: August 2017

[Laravel5.1踩雷紀錄] 進行整合測試發生1205 Lock wait timeout exceeded; try restarting transaction

前陣子不知道為什麼在我的Laravel app進行整合測試的時候開始出現這個錯誤，而且隨著TestCase開始慢慢增加，問題就越來越嚴重！因為這造成我們在跑測試的時候花費非常多的時間！而且會因為Lock wait timeout導致無法測完某個TestCase就failure

使用情境

版本：

  • PHP 7.0
  • PHPUnit 5.7
  • Laravel 5.1
  • MySQL 5.6

執行phpunit進行測試

vendor/bin/phpunit --stop-on-failure

跑了一部份的TestCase就出現

PDOException: SQLSTATE[HY000]: General error: 1205 Lock wait timeout exceeded; try restarting transaction

如果把上面的錯誤訊息直接丟去問Google大神，那找到的解法可能無法解決這個情境發生的問題，因為有太多的原因會造成Lock wait timeout還好這個情況是在測試時發生的，需要確認的因素單純很多，其實追根究底Lock wait timeout exceeded就是transaction一直在等待等到timeout，如果我們可以觀察目前transaction的狀態那一定可以幫助我們釐清這個問題

在MySQL內建資料庫information_schema的INNODB_TRX 資料表可以讓我們觀察目前正在執行或等待的transaction

The INNODB_TRX table contains information about every transaction (excluding read-only transactions) currently executing inside InnoDB, including whether the transaction is waiting for a lock, when the transaction started, and the SQL statement the transaction is executing, if any.

MySQL Documentation

從這張gif看就可以很明顯的發現，隨著測試開始進行時transaction的數量竟然慢慢飆高，而且一直都在running的狀態

因為我是用Laravel提供的DatabaseTransactions Trait，照理來說跑完某個Test就要rollback才對，但竟然沒有！實際去看DatabaseTransactions.php也確實有rollback，有趣的是它在beforeApplicationDestroyed的時候才執行

    public function beginDatabaseTransaction()
    {
        $this->app->make('db')->beginTransaction();

        $this->beforeApplicationDestroyed(function () {
            $this->app->make('db')->rollBack();
        });
    }

在從beforeApplicationDestroyed()找到vendor/laravel/framework/src/Illuminate/Foundation/Testing/TestCase.php這隻檔案

abstract class TestCase extends PHPUnit_Framework_TestCase
{
    use ApplicationTrait, AssertionsTrait, CrawlerTrait;

    /**
     * The callbacks that should be run before the application is destroyed.
     *
     * @var array
     */
    protected $beforeApplicationDestroyedCallbacks = [];

    /**
     * Creates the application.
     *
     * Needs to be implemented by subclasses.
     *
     * @return \Symfony\Component\HttpKernel\HttpKernelInterface
     */
    abstract public function createApplication();

    /**
     * Setup the test environment.
     *
     * @return void
     */
    public function setUp()
    {
        if (! $this->app) {
            $this->refreshApplication();
        }
    }

    /**
     * Clean up the testing environment before the next test.
     *
     * @return void
     */
    public function tearDown()
    {
        if ($this->app) {
            foreach ($this->beforeApplicationDestroyedCallbacks as $callback) {
                call_user_func($callback);
            }

            $this->app->flush();

            $this->app = null;
        }

        if (property_exists($this, 'serverVariables')) {
            $this->serverVariables = [];
        }

        if (class_exists('Mockery')) {
            Mockery::close();
        }
    }

    /**
     * Register a callback to be run before the application is destroyed.
     *
     * @param  callable  $callback
     * @return void
     */
    protected function beforeApplicationDestroyed(callable $callback)
    {
        $this->beforeApplicationDestroyedCallbacks[] = $callback;
    }
}

看完以上的程式碼應該就可以瞭解DatabaseTransactions Trait的運作流程

  1. 在呼叫beginDatabaseTransaction()的時候, 開啟transaction並將rollback callback存入beforeApplicationDestroyedCallbacks陣列
  2. 在呼叫tearDown()的時候才會取出rollback callback執行

到目前為止幾乎可以確定是transaction開啟後但沒有rollback，重新去檢查之後才發現某些TestCase覆寫了tearDown method卻沒有呼叫parent::tearDown()

public function tearDown()
{
    //some code here.
}

改成

public function tearDown()
{
    parent::tearDown();
    //some code here.
}

就可以讓transaction rollback

總結前因後果

tearDown()被覆寫了，但在child method沒有呼叫parent::tearDown()導致Test跑完了transaction卻一直沒有被釋放掉，進而發生transaction wait timeout的問題，如果TestCase數量很少的時候這個問題其實不會太明顯，但隨著Test的數量越來越多這個問題就很難被忽視

補充

其實還有另一種方法可以解決，但還是建議使用第一個解法！畢竟有些時候會需要用同一個PHP process進行測試，PHPUnit提供了–process-isolation參數，這個參數讓PHPUnit在跑每個測試的時候都是用新的php process執行

vendor/bin/phpunit --stop-on-failure --process-isolation
Advertisements