DeadLockTest::childrenUpdateLocked() - Code Metrics - Inspection of "Update Scrutinizer config" - yiisoft/db-mysql - Measure and Improve Code Quality continuously with Scrutinizer

Passed

Push — master ( 2b1785...29418c )

by Alexander

created 2020-07-22 11:07 UTC

DeadLockTest::childrenUpdateLocked() B

↳ Parent: Project

Complexity

Conditions	8
Paths	35

Size

Total Lines	62
Code Lines	38

Duplication

Lines	0
Ratio	0 %

Importance

Changes

Metric	Value
cc	8
eloc	38
nc	35
nop	0
dl	0
loc	62
rs	8.0675
c	0
b	0
f	0

How to fix Long Method

<?php

declare(strict_types=1);

namespace Yiisoft\Db\Mysql\Tests;

use Yiisoft\Db\Connection\Connection;
use Yiisoft\Db\Exception\Exception;
use Yiisoft\Db\Mysql\Tests\ConnectionTest as ConnectionTest;
use Yiisoft\Db\Transaction\Transaction;

class DeadLockTest extends ConnectionTest
{
    public const CHILD_EXIT_CODE_DEADLOCK = 15;
    protected ?string $driverName = 'mysql';
    private string $logFile = '';

    /**
     * Test deadlock exception.
     *
     * Accident deadlock exception lost while rolling back a transaction or savepoint
     *
     * {@link https://github.com/yiisoft/yii2/issues/12715}
     * {@link https://github.com/yiisoft/yii2/pull/13346}
     */
    public function testDeadlockException(): void
    {
        if (!\function_exists('pcntl_fork')) {
            $this->markTestSkipped('pcntl_fork() is not available');
        }

        if (!\function_exists('posix_kill')) {
            $this->markTestSkipped('posix_kill() is not available');
        }

        if (!\function_exists('pcntl_sigtimedwait')) {
            $this->markTestSkipped('pcntl_sigtimedwait() is not available');
        }

        $this->setLogFile(\sys_get_temp_dir() . '/deadlock_' . \posix_getpid());
        $this->deleteLog();

        try {
            /**
             * to cause deadlock we do:
             *
             * 1. FIRST errornously forgot "FOR UPDATE" while read the row for next update.
             * 2. SECOND does update the row and locks it exclusively.
             * 3. FIRST tryes to update the row too, but it already has shared lock. Here comes deadlock.
             * FIRST child will send the signal to the SECOND child.
             * So, SECOND child should be forked at first to obtain its PID.
             */

            $pidSecond = \pcntl_fork();

            if (-1 === $pidSecond) {
                $this->markTestIncomplete('cannot fork');
            }

            if (0 === $pidSecond) {
                /** SECOND child */
                $this->setErrorHandler();
                exit($this->childrenUpdateLocked());
            }

            $pidFirst = \pcntl_fork();

            if (-1 === $pidFirst) {
                $this->markTestIncomplete('cannot fork second child');
            }

            if (0 === $pidFirst) {
                /** FIRST child */
                $this->setErrorHandler();
                exit($this->childrenSelectAndAccidentUpdate($pidSecond));
            }

            /**
             * PARENT
             * nothing to do
             */
        } catch (\Exception $e) {
            /** wait all children */
            while (-1 !== \pcntl_wait($status)) {
                /** nothing to do */
            }
            $this->deleteLog();

            throw $e;
        } catch (\Throwable $e) {
            /** wait all children */
            while (-1 !== \pcntl_wait($status)) {
                /** nothing to do */
            }
            $this->deleteLog();

            throw $e;
        }

        /**
         * wait all children all must exit with success
         */
        $errors = [];
        $deadlockHitCount = 0;

        while (-1 !== \pcntl_wait($status)) {
            if (!\pcntl_wifexited($status)) {
                $errors[] = 'child did not exit itself';
            } else {
                $exitStatus = \pcntl_wexitstatus($status);
                if (self::CHILD_EXIT_CODE_DEADLOCK === $exitStatus) {
                    $deadlockHitCount++;
                } elseif (0 !== $exitStatus) {
                    $errors[] = 'child exited with error status';
                }
            }
        }

        $logContent = $this->getLogContentAndDelete();

        if ($errors) {
            $this->fail(
                \implode('; ', $errors)
                . ($logContent ? ". Shared children log:\n$logContent" : '')
            );
        }
        $this->assertEquals(
            1,
            $deadlockHitCount,
            "exactly one child must hit deadlock; shared children log:\n" . $logContent
        );
    }

    /**
     * Main body of first child process.
     *
     * First child initializes test row and runs two nested {@see Connection::transaction()} to perform following
     * operations:
     * 1. `SELECT ... LOCK IN SHARE MODE` the test row with shared lock instead of needed exclusive lock.
     * 2. Send signal to SECOND child identified by PID {@see $pidSecond}.
     * 3. Waits few seconds.
     * 4. `UPDATE` the test row.
     *
     * @param int $pidSecond
     *
     * @return int Exit code. In case of deadlock exit code is {@see CHILD_EXIT_CODE_DEADLOCK}. In case of success exit
     * code is 0. Other codes means an error.
     */
    private function childrenSelectAndAccidentUpdate(int $pidSecond): int
    {
        try {
            $this->log('child 1: connect');

            /** @var Connection $first */
            $first = $this->getConnection(false, false);

            $this->log('child 1: delete');

            $first->createCommand()
                ->delete('{{customer}}', ['id' => 97])
                ->execute();

            $this->log('child 1: insert');

            /** insert test row */
            $first->createCommand()
                ->insert('{{customer}}', [
                    'id'      => 97,
                    'email'   => '[email protected]',
                    'name'    => 'test',
                    'address' => 'test address',
                ])
                ->execute();

            $this->log('child 1: transaction');

            $first->transaction(function (Connection $first) use ($pidSecond) {
                $first->transaction(function (Connection $first) use ($pidSecond) {
                    $this->log('child 1: select');
                    /** SELECT with shared lock */
                    $first->createCommand('SELECT id FROM {{customer}} WHERE id = 97 LOCK IN SHARE MODE')
                        ->execute();

                    $this->log('child 1: send signal to child 2');
                    // let child to continue
                    if (!\posix_kill($pidSecond, SIGUSR1)) {
                        throw new \RuntimeException('Cannot send signal');
                    }

                    /** now child 2 tries to do the 2nd update, and hits the lock and waits */

                    /** delay to let child hit the lock */
                    \sleep(2);

                    $this->log('child 1: update');
                    /** now do the 3rd update for deadlock */
                    $first->createCommand()
                        ->update('{{customer}}', ['name' => 'first'], ['id' => 97])
                        ->execute();
                    $this->log('child 1: commit');
                });
            }, Transaction::REPEATABLE_READ);
        } catch (Exception $e) {
            [$sqlError, $driverError, $driverMessage] = $e->errorInfo;
            /** Deadlock found when trying to get lock; try restarting transaction */
            if ('40001' === $sqlError && 1213 === $driverError) {
                return self::CHILD_EXIT_CODE_DEADLOCK;
            }
            $this->log("child 1: ! sql error $sqlError: $driverError: $driverMessage");

            return 1;
        } catch (\Exception $e) {
            $this->log(
                'child 1: ! exit <<' . \get_class($e) . ' #' . $e->getCode() . ': ' . $e->getMessage() . "\n"
                . $e->getTraceAsString() . '>>'
            );

            return 1;
        } catch (\Throwable $e) {
            $this->log(
                'child 1: ! exit <<' . \get_class($e) . ' #' . $e->getCode() . ': ' . $e->getMessage() . "\n"
                . $e->getTraceAsString() . '>>'
            );

            return 1;
        }
        $this->log('child 1: exit');

        return 0;
    }

    /**
     * Main body of second child process.
     *
     * Second child at first will wait the signal from the first child in some seconds.
     *
     * After receiving the signal it runs two nested {@see Connection::transaction()} to perform `UPDATE` with the test
     * row.
     *
     * @return int Exit code. In case of deadlock exit code is {@see CHILD_EXIT_CODE_DEADLOCK}. In case of success exit
     * code is 0. Other codes means an error.
     */
    private function childrenUpdateLocked(): int
    {
        /** install no-op signal handler to prevent termination */
        if (!\pcntl_signal(SIGUSR1, static function () {}, false)) {
            $this->log('child 2: cannot install signal handler');

            return 1;
        }

        try {
            /** at first, parent should do 1st select */
            $this->log('child 2: wait signal from child 1');
            if (\pcntl_sigtimedwait([SIGUSR1], $info, 10) <= 0) {
                $this->log('child 2: wait timeout exceeded');

                return 1;
            }

            $this->log('child 2: connect');
            /** @var Connection $second */
            $second = $this->getConnection(true, false);
            $second->open();
            /** sleep(1); */
            $this->log('child 2: transaction');
            $second->transaction(function (Connection $second) {
                $second->transaction(function (Connection $second) {
                    $this->log('child 2: update');
                    // do the 2nd update
                    $second->createCommand()
                        ->update('{{customer}}', ['name' => 'second'], ['id' => 97])
                        ->execute();

                    $this->log('child 2: commit');
                });
            }, Transaction::REPEATABLE_READ);
        } catch (Exception $e) {
            [$sqlError, $driverError, $driverMessage] = $e->errorInfo;
            /** Deadlock found when trying to get lock; try restarting transaction */
            if ('40001' === $sqlError && 1213 === $driverError) {
                return self::CHILD_EXIT_CODE_DEADLOCK;
            }
            $this->log("child 2: ! sql error $sqlError: $driverError: $driverMessage");

            return 1;
        } catch (\Exception $e) {
            $this->log(
                'child 2: ! exit <<' . \get_class($e) . ' #' . $e->getCode() . ': ' . $e->getMessage() . "\n"
                . $e->getTraceAsString() . '>>'
            );

            return 1;
        } catch (\Throwable $e) {
            $this->log(
                'child 2: ! exit <<' . \get_class($e) . ' #' . $e->getCode() . ': ' . $e->getMessage() . "\n"
                . $e->getTraceAsString() . '>>'
            );

            return 1;
        }
        $this->log('child 2: exit');

        return 0;
    }

    /**
     * Set own error handler.
     *
     * In case of error in child process its execution bubbles up to phpunit to continue all the rest tests. So, all
     * the rest tests in this case will run both in the child and parent processes. Such mess must be prevented with
     * child's own error handler.
     */
    private function setErrorHandler(): void
    {
        \set_error_handler(static function ($errno, $errstr, $errfile, $errline) {
            throw new \ErrorException($errstr, $errno, $errno, $errfile, $errline);
        });
    }

    /**
     * Sets filename for log file shared between children processes.
     *
     * @param string $filename
     */
    private function setLogFile(string $filename): void
    {
        $this->logFile = $filename;
    }

    /**
     * Deletes shared log file.
     *
     * Deletes the file {@see logFile} if it exists.
     */
    private function deleteLog(): void
    {
        if (null !== $this->logFile && \is_file($this->logFile)) {
            \unlink($this->logFile);
        }
    }

    /**
     * Reads shared log content and deletes the log file.
     *
     * Reads content of log file {@see logFile} and returns it deleting the file.
     *
     * @return string|null String content of the file {@see logFile}. `false` is returned when file cannot be read.
     * `null` is returned when file does not exist or {@see logFile} is not set.
     */
    private function getLogContentAndDelete(): ?string
    {
        if (null !== $this->logFile && \is_file($this->logFile)) {
            $content = \file_get_contents($this->logFile);
            \unlink($this->logFile);

            return $content;
        }
    }

    /**
     * Append message to shared log.
     *
     * @param string $message Message to append to the log. The message will be prepended with timestamp and appended
     * with new line.
     */
    private function log(string $message): void
    {
        if (null !== $this->logFile) {
            $time = \microtime(true);
            $timeInt = \floor($time);
            $timeFrac = $time - $timeInt;
            $timestamp = \date('Y-m-d H:i:s', (int) $timeInt) . '.' . round($timeFrac * 1000);
            \file_put_contents($this->logFile, "[$timestamp] $message\n", FILE_APPEND | LOCK_EX);
        }
    }
}


1			<?php
2
3			declare(strict_types=1);
4
5			namespace Yiisoft\Db\Mysql\Tests;
6
7			use Yiisoft\Db\Connection\Connection;
8			use Yiisoft\Db\Exception\Exception;
9			use Yiisoft\Db\Mysql\Tests\ConnectionTest as ConnectionTest;
10			use Yiisoft\Db\Transaction\Transaction;
11
12			class DeadLockTest extends ConnectionTest
13			{
14			public const CHILD_EXIT_CODE_DEADLOCK = 15;
15			protected ?string $driverName = 'mysql';
16			private string $logFile = '';
17
18			/**
19			* Test deadlock exception.
20			*
21			* Accident deadlock exception lost while rolling back a transaction or savepoint
22			*
23			* {@link https://github.com/yiisoft/yii2/issues/12715}
24			* {@link https://github.com/yiisoft/yii2/pull/13346}
25			*/
26			public function testDeadlockException(): void
27			{
28			if (!\function_exists('pcntl_fork')) {
29			$this->markTestSkipped('pcntl_fork() is not available');
30			}
31
32			if (!\function_exists('posix_kill')) {
33			$this->markTestSkipped('posix_kill() is not available');
34			}
35
36			if (!\function_exists('pcntl_sigtimedwait')) {
37			$this->markTestSkipped('pcntl_sigtimedwait() is not available');
38			}
39
40			$this->setLogFile(\sys_get_temp_dir() . '/deadlock_' . \posix_getpid());
41			$this->deleteLog();
42
43			try {
44			/**
45			* to cause deadlock we do:
46			*
47			* 1. FIRST errornously forgot "FOR UPDATE" while read the row for next update.
48			* 2. SECOND does update the row and locks it exclusively.
49			* 3. FIRST tryes to update the row too, but it already has shared lock. Here comes deadlock.
50			* FIRST child will send the signal to the SECOND child.
51			* So, SECOND child should be forked at first to obtain its PID.
52			*/
53
54			$pidSecond = \pcntl_fork();
55
56			if (-1 === $pidSecond) {
57			$this->markTestIncomplete('cannot fork');
58			}
59
60			if (0 === $pidSecond) {
61			/** SECOND child */
62			$this->setErrorHandler();
63			exit($this->childrenUpdateLocked());
64			}
65
66			$pidFirst = \pcntl_fork();
67
68			if (-1 === $pidFirst) {
69			$this->markTestIncomplete('cannot fork second child');
70			}
71
72			if (0 === $pidFirst) {
73			/** FIRST child */
74			$this->setErrorHandler();
75			exit($this->childrenSelectAndAccidentUpdate($pidSecond));
76			}
77
78			/**
79			* PARENT
80			* nothing to do
81			*/
82			} catch (\Exception $e) {
83			/** wait all children */
84			while (-1 !== \pcntl_wait($status)) {
85			/** nothing to do */
86			}
87			$this->deleteLog();
88
89			throw $e;
90			} catch (\Throwable $e) {
91			/** wait all children */
92			while (-1 !== \pcntl_wait($status)) {
93			/** nothing to do */
94			}
95			$this->deleteLog();
96
97			throw $e;
98			}
99
100			/**
101			* wait all children all must exit with success
102			*/
103			$errors = [];
104			$deadlockHitCount = 0;
105
106			while (-1 !== \pcntl_wait($status)) {
107			if (!\pcntl_wifexited($status)) {
108			$errors[] = 'child did not exit itself';
109			} else {
110			$exitStatus = \pcntl_wexitstatus($status);
111			if (self::CHILD_EXIT_CODE_DEADLOCK === $exitStatus) {
112			$deadlockHitCount++;
113			} elseif (0 !== $exitStatus) {
114			$errors[] = 'child exited with error status';
115			}
116			}
117			}
118
119			$logContent = $this->getLogContentAndDelete();
120
121			if ($errors) {
122			$this->fail(
123			\implode('; ', $errors)
124			. ($logContent ? ". Shared children log:\n$logContent" : '')
125			);
126			}
127			$this->assertEquals(
128			1,
129			$deadlockHitCount,
130			"exactly one child must hit deadlock; shared children log:\n" . $logContent
131			);
132			}
133
134			/**
135			* Main body of first child process.
136			*
137			* First child initializes test row and runs two nested {@see Connection::transaction()} to perform following
138			* operations:
139			* 1. `SELECT ... LOCK IN SHARE MODE` the test row with shared lock instead of needed exclusive lock.
140			* 2. Send signal to SECOND child identified by PID {@see $pidSecond}.
141			* 3. Waits few seconds.
142			* 4. `UPDATE` the test row.
143			*
144			* @param int $pidSecond
145			*
146			* @return int Exit code. In case of deadlock exit code is {@see CHILD_EXIT_CODE_DEADLOCK}. In case of success exit
147			* code is 0. Other codes means an error.
148			*/
149			private function childrenSelectAndAccidentUpdate(int $pidSecond): int
150			{
151			try {
152			$this->log('child 1: connect');
153
154			/** @var Connection $first */
155			$first = $this->getConnection(false, false);
156
157			$this->log('child 1: delete');
158
159			$first->createCommand()
160			->delete('{{customer}}', ['id' => 97])
161			->execute();
162
163			$this->log('child 1: insert');
164
165			/** insert test row */
166			$first->createCommand()
167			->insert('{{customer}}', [
168			'id' => 97,
169			'email' => '[email protected]',
170			'name' => 'test',
171			'address' => 'test address',
172			])
173			->execute();
174
175			$this->log('child 1: transaction');
176
177			$first->transaction(function (Connection $first) use ($pidSecond) {
178			$first->transaction(function (Connection $first) use ($pidSecond) {
179			$this->log('child 1: select');
180			/** SELECT with shared lock */
181			$first->createCommand('SELECT id FROM {{customer}} WHERE id = 97 LOCK IN SHARE MODE')
182			->execute();
183
184			$this->log('child 1: send signal to child 2');
185			// let child to continue
186			if (!\posix_kill($pidSecond, SIGUSR1)) {
187			throw new \RuntimeException('Cannot send signal');
188			}
189
190			/** now child 2 tries to do the 2nd update, and hits the lock and waits */
191
192			/** delay to let child hit the lock */
193			\sleep(2);
194
195			$this->log('child 1: update');
196			/** now do the 3rd update for deadlock */
197			$first->createCommand()
198			->update('{{customer}}', ['name' => 'first'], ['id' => 97])
199			->execute();
200			$this->log('child 1: commit');
201			});
202			}, Transaction::REPEATABLE_READ);
203			} catch (Exception $e) {
204			[$sqlError, $driverError, $driverMessage] = $e->errorInfo;
205			/** Deadlock found when trying to get lock; try restarting transaction */
206			if ('40001' === $sqlError && 1213 === $driverError) {
207			return self::CHILD_EXIT_CODE_DEADLOCK;
208			}
209			$this->log("child 1: ! sql error $sqlError: $driverError: $driverMessage");
210
211			return 1;
212			} catch (\Exception $e) {
213			$this->log(
214			'child 1: ! exit <<' . \get_class($e) . ' #' . $e->getCode() . ': ' . $e->getMessage() . "\n"
215			. $e->getTraceAsString() . '>>'
216			);
217
218			return 1;
219			} catch (\Throwable $e) {
220			$this->log(
221			'child 1: ! exit <<' . \get_class($e) . ' #' . $e->getCode() . ': ' . $e->getMessage() . "\n"
222			. $e->getTraceAsString() . '>>'
223			);
224
225			return 1;
226			}
227			$this->log('child 1: exit');
228
229			return 0;
230			}
231
232			/**
233			* Main body of second child process.
234			*
235			* Second child at first will wait the signal from the first child in some seconds.
236			*
237			* After receiving the signal it runs two nested {@see Connection::transaction()} to perform `UPDATE` with the test
238			* row.
239			*
240			* @return int Exit code. In case of deadlock exit code is {@see CHILD_EXIT_CODE_DEADLOCK}. In case of success exit
241			* code is 0. Other codes means an error.
242			*/
243			private function childrenUpdateLocked(): int
244			{
245			/** install no-op signal handler to prevent termination */
246			if (!\pcntl_signal(SIGUSR1, static function () {}, false)) {
247			$this->log('child 2: cannot install signal handler');
248
249			return 1;
250			}
251
252			try {
253			/** at first, parent should do 1st select */
254			$this->log('child 2: wait signal from child 1');
255			if (\pcntl_sigtimedwait([SIGUSR1], $info, 10) <= 0) {
256			$this->log('child 2: wait timeout exceeded');
257
258			return 1;
259			}
260
261			$this->log('child 2: connect');
262			/** @var Connection $second */
263			$second = $this->getConnection(true, false);
264			$second->open();
265			/** sleep(1); */
266			$this->log('child 2: transaction');
267			$second->transaction(function (Connection $second) {
268			$second->transaction(function (Connection $second) {
269			$this->log('child 2: update');
270			// do the 2nd update
271			$second->createCommand()
272			->update('{{customer}}', ['name' => 'second'], ['id' => 97])
273			->execute();
274
275			$this->log('child 2: commit');
276			});
277			}, Transaction::REPEATABLE_READ);
278			} catch (Exception $e) {
279			[$sqlError, $driverError, $driverMessage] = $e->errorInfo;
280			/** Deadlock found when trying to get lock; try restarting transaction */
281			if ('40001' === $sqlError && 1213 === $driverError) {
282			return self::CHILD_EXIT_CODE_DEADLOCK;
283			}
284			$this->log("child 2: ! sql error $sqlError: $driverError: $driverMessage");
285
286			return 1;
287			} catch (\Exception $e) {
288			$this->log(
289			'child 2: ! exit <<' . \get_class($e) . ' #' . $e->getCode() . ': ' . $e->getMessage() . "\n"
290			. $e->getTraceAsString() . '>>'
291			);
292
293			return 1;
294			} catch (\Throwable $e) {
295			$this->log(
296			'child 2: ! exit <<' . \get_class($e) . ' #' . $e->getCode() . ': ' . $e->getMessage() . "\n"
297			. $e->getTraceAsString() . '>>'
298			);
299
300			return 1;
301			}
302			$this->log('child 2: exit');
303
304			return 0;
305			}
306
307			/**
308			* Set own error handler.
309			*
310			* In case of error in child process its execution bubbles up to phpunit to continue all the rest tests. So, all
311			* the rest tests in this case will run both in the child and parent processes. Such mess must be prevented with
312			* child's own error handler.
313			*/
314			private function setErrorHandler(): void
315			{
316			\set_error_handler(static function ($errno, $errstr, $errfile, $errline) {
317			throw new \ErrorException($errstr, $errno, $errno, $errfile, $errline);
318			});
319			}
320
321			/**
322			* Sets filename for log file shared between children processes.
323			*
324			* @param string $filename
325			*/
326			private function setLogFile(string $filename): void
327			{
328			$this->logFile = $filename;
329			}
330
331			/**
332			* Deletes shared log file.
333			*
334			* Deletes the file {@see logFile} if it exists.
335			*/
336			private function deleteLog(): void
337			{
338			if (null !== $this->logFile && \is_file($this->logFile)) {
339			\unlink($this->logFile);
340			}
341			}
342
343			/**
344			* Reads shared log content and deletes the log file.
345			*
346			* Reads content of log file {@see logFile} and returns it deleting the file.
347			*
348			* @return string\|null String content of the file {@see logFile}. `false` is returned when file cannot be read.
349			* `null` is returned when file does not exist or {@see logFile} is not set.
350			*/
351			private function getLogContentAndDelete(): ?string
352			{
353			if (null !== $this->logFile && \is_file($this->logFile)) {
354			$content = \file_get_contents($this->logFile);
355			\unlink($this->logFile);
356
357			return $content;
358			}
359			}
360
361			/**
362			* Append message to shared log.
363			*
364			* @param string $message Message to append to the log. The message will be prepended with timestamp and appended
365			* with new line.
366			*/
367			private function log(string $message): void
368			{
369			if (null !== $this->logFile) {
370			$time = \microtime(true);
371			$timeInt = \floor($time);
372			$timeFrac = $time - $timeInt;
373			$timestamp = \date('Y-m-d H:i:s', (int) $timeInt) . '.' . round($timeFrac * 1000);
374			\file_put_contents($this->logFile, "[$timestamp] $message\n", FILE_APPEND \| LOCK_EX);
375			}
376			}
377			}
378

yiisoft / db-mysql

Push — master ( 2b1785...29418c )

DeadLockTest::childrenUpdateLocked() B

Complexity

Size

Duplication

Importance

How to fix Long Method

Long Method

Duplication Side-by-Side

Filter issues like