Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[6.x] MySQL Aurora failover - DetectsLostConnections #31539

Merged
merged 1 commit into from Feb 20, 2020

Conversation

@IndexZer0
Copy link
Contributor

IndexZer0 commented Feb 20, 2020

We recently experienced a MySQL Aurora failover on production and noticed that our queue workers didn't restart.

When running the following code inside a Laravel command and then starting a failover inside RDS dashboard we see these exception messages:

  • SQLSTATE[HY000] [2002] Connection refused
  • SQLSTATE[HY000]: General error: 1290 The MySQL server is running with the --read-only option so it cannot execute this statement (SQL: update brand_daily_summary set deposit_count = 23 where id = 1)
    public static function testConnection($attemptReconnect = true)
    {
        $end = Carbon::now()->copy()->addSeconds(120);

        $lastSecondRun = null;
        $count = 0;

        while (Carbon::now()->lessThan($end)) {
            $now = Carbon::now();

            if ($lastSecondRun === null || $lastSecondRun !== $now->second) {

                \Log::debug('second: ' . $now->second);

                $count++;

                try {
                    
                    $affected = \DB::table(DailySummary::TABLE)
                        ->where('id', 1)
                        ->update(['deposit_count' => $count]);

                    \Log::debug('affected: ' . $affected);

                } catch (\Exception $e) {
                    \Log::debug('Exception');
                    \Log::debug($e->getMessage());

                    if ($attemptReconnect) {
                        if (Str::contains($e->getMessage(), ['--read-only'])) {
                            \Log::debug('attempting to reconnect');
                            \DB::reconnect();
                        }
                    }
                }

            }

            $lastSecondRun = $now->second;
        }
    }

Maybe protected function causedByLostConnection is not the correct place to be handling the --read-only option exception message though as it is quite general?

Any thoughts on this?

@IndexZer0 IndexZer0 changed the title - Added exception messages seen when MySQL Aurora is failing over. [6.x] MySQL Aurora failover - DetectsLostConnections Feb 20, 2020
@IndexZer0

This comment has been minimized.

Copy link
Contributor Author

IndexZer0 commented Feb 20, 2020

Here is full output of log file while command is running and failover is happening

[2020-02-20 09:50:58] macbook.DEBUG: second: 58 [] []
[2020-02-20 09:50:58] macbook.DEBUG: affected: 1 [] []
[2020-02-20 09:50:59] macbook.DEBUG: second: 59 [] []
[2020-02-20 09:50:59] macbook.DEBUG: affected: 1 [] []
[2020-02-20 09:51:00] macbook.DEBUG: second: 0 [] []
[2020-02-20 09:51:00] macbook.DEBUG: affected: 1 [] []
[2020-02-20 09:51:01] macbook.DEBUG: second: 1 [] []
[2020-02-20 09:51:01] macbook.DEBUG: Exception [] []
[2020-02-20 09:51:01] macbook.DEBUG: SQLSTATE[HY000] [2002] Connection refused [] []
[2020-02-20 09:51:02] macbook.DEBUG: second: 2 [] []
[2020-02-20 09:51:02] macbook.DEBUG: Exception [] []
[2020-02-20 09:51:02] macbook.DEBUG: SQLSTATE[HY000] [2002] Connection refused [] []
[2020-02-20 09:51:03] macbook.DEBUG: second: 3 [] []
[2020-02-20 09:51:03] macbook.DEBUG: Exception [] []
[2020-02-20 09:51:03] macbook.DEBUG: SQLSTATE[HY000] [2002] Connection refused [] []
[2020-02-20 09:51:04] macbook.DEBUG: second: 4 [] []
[2020-02-20 09:51:04] macbook.DEBUG: Exception [] []
[2020-02-20 09:51:04] macbook.DEBUG: SQLSTATE[HY000] [2002] Connection refused [] []
[2020-02-20 09:51:05] macbook.DEBUG: second: 5 [] []
[2020-02-20 09:51:05] macbook.DEBUG: Exception [] []
[2020-02-20 09:51:05] macbook.DEBUG: SQLSTATE[HY000] [2002] Connection refused [] []
[2020-02-20 09:51:06] macbook.DEBUG: second: 6 [] []
[2020-02-20 09:51:06] macbook.DEBUG: Exception [] []
[2020-02-20 09:51:06] macbook.DEBUG: SQLSTATE[HY000] [2002] Connection refused [] []
[2020-02-20 09:51:07] macbook.DEBUG: second: 7 [] []
[2020-02-20 09:51:07] macbook.DEBUG: Exception [] []
[2020-02-20 09:51:07] macbook.DEBUG: SQLSTATE[HY000] [2002] Connection refused [] []
[2020-02-20 09:51:08] macbook.DEBUG: second: 8 [] []
[2020-02-20 09:51:08] macbook.DEBUG: Exception [] []
[2020-02-20 09:51:08] macbook.DEBUG: SQLSTATE[HY000]: General error: 1290 The MySQL server is running with the --read-only option so it cannot execute this statement (SQL: update brand_daily_summary set deposit_count = 23 where id = 1) [] []
[2020-02-20 09:51:08] macbook.DEBUG: attempting to reconnect [] []
[2020-02-20 09:51:09] macbook.DEBUG: second: 9 [] []
[2020-02-20 09:51:09] macbook.DEBUG: Exception [] []
[2020-02-20 09:51:09] macbook.DEBUG: SQLSTATE[HY000]: General error: 1290 The MySQL server is running with the --read-only option so it cannot execute this statement (SQL: update brand_daily_summary set deposit_count = 24 where id = 1) [] []
[2020-02-20 09:51:09] macbook.DEBUG: attempting to reconnect [] []
[2020-02-20 09:51:10] macbook.DEBUG: second: 10 [] []
[2020-02-20 09:51:10] macbook.DEBUG: Exception [] []
[2020-02-20 09:51:10] macbook.DEBUG: SQLSTATE[HY000]: General error: 1290 The MySQL server is running with the --read-only option so it cannot execute this statement (SQL: update brand_daily_summary set deposit_count = 25 where id = 1) [] []
[2020-02-20 09:51:10] macbook.DEBUG: attempting to reconnect [] []
[2020-02-20 09:51:11] macbook.DEBUG: second: 11 [] []
[2020-02-20 09:51:11] macbook.DEBUG: Exception [] []
[2020-02-20 09:51:11] macbook.DEBUG: SQLSTATE[HY000]: General error: 1290 The MySQL server is running with the --read-only option so it cannot execute this statement (SQL: update brand_daily_summary set deposit_count = 26 where id = 1) [] []
[2020-02-20 09:51:11] macbook.DEBUG: attempting to reconnect [] []
[2020-02-20 09:51:12] macbook.DEBUG: second: 12 [] []
[2020-02-20 09:51:12] macbook.DEBUG: affected: 1 [] []
[2020-02-20 09:51:13] macbook.DEBUG: second: 13 [] []
[2020-02-20 09:51:13] macbook.DEBUG: affected: 1 [] []

@IndexZer0 IndexZer0 marked this pull request as ready for review Feb 20, 2020
@taylorotwell taylorotwell merged commit f9b4bc3 into laravel:6.x Feb 20, 2020
1 check passed
1 check passed
continuous-integration/styleci/pr The analysis has passed
Details
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked issues

Successfully merging this pull request may close these issues.

None yet

3 participants
You can’t perform that action at this time.