Skip to content

RDS MySQL instance shut down unexpectedly - how do I interpret what happened via log file posted below?

0

My RDS MySQL instance has shutdown unexpectedly during production. I have checked the log file which shows the following:

2023-05-18T13:52:17.379213Z 0 [System] [MY-013172] [Server] Received SHUTDOWN from user <via user signal>. Shutting down mysqld (Version: 8.0.28).

2023-05-18T13:52:21.438698Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 94856 user: 'user1'.

2023-05-18T13:52:21.499783Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 73760 user: 'user1'.

2023-05-18T13:52:21.499838Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 94872 user: 'user1'.

2023-05-18T13:52:21.499862Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 92632 user: 'user1'.

2023-05-18T13:52:21.499881Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 92641 user: 'user1'.

2023-05-18T13:52:21.499896Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 80785 user: 'user1'.

2023-05-18T13:52:21.499911Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 94786 user: 'user1'.

2023-05-18T13:52:21.499926Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 94866 user: 'user1'.

2023-05-18T13:52:21.499945Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 92634 user: 'user1'.

2023-05-18T13:52:21.499963Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 91130 user: 'user2'.

2023-05-18T13:52:21.500010Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 94858 user: 'user1'.

2023-05-18T13:52:21.500026Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 94867 user: 'user1'.

2023-05-18T13:52:21.500044Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 94787 user: 'user1'.

2023-05-18T13:52:21.500062Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 94859 user: 'user1'.

2023-05-18T13:52:21.500080Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 94868 user: 'user1'.

2023-05-18T13:52:21.500098Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 81604 user: 'user1'.

2023-05-18T13:52:21.500116Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 94869 user: 'user1'.

2023-05-18T13:52:21.500132Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 92637 user: 'user1'.

2023-05-18T13:52:21.500151Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 85158 user: 'user1'.

2023-05-18T13:52:21.500167Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 92846 user: 'user1'.

2023-05-18T13:52:21.500183Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 94870 user: 'user1'.

2023-05-18T13:52:21.500201Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 94855 user: 'user1'.

2023-05-18T13:52:21.500218Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 92775 user: 'user1'.

2023-05-18T13:52:21.500233Z 0 [Warning] [MY-010909] [Server] /rdsdbbin/mysql/bin/mysqld: Forcing close of thread 92759 user: 'user1'.

2023-05-18T13:52:38.464212Z 0 [System] [MY-010910] [Server] /rdsdbbin/mysql/bin/mysqld: Shutdown complete (mysqld 8.0.28) Source distribution.

2023-05-18T13:54:06.975918Z 0 [Warning] [MY-011068] [Server] The syntax 'log_slave_updates' is deprecated and will be removed in a future release. Please use log_replica_updates instead.

2023-05-18T13:54:06.975932Z 0 [Warning] [MY-011069] [Server] The syntax '--master-info-repository' is deprecated and will be removed in a future release.

2023-05-18T13:54:06.975944Z 0 [Warning] [MY-011069] [Server] The syntax '--master-info-repository' is deprecated and will be removed in a future release.

2023-05-18T13:54:06.975995Z 0 [Warning] [MY-011069] [Server] The syntax '--relay-log-info-file' is deprecated and will be removed in a future release.

2023-05-18T13:54:06.976000Z 0 [Warning] [MY-011069] [Server] The syntax '--relay-log-info-repository' is deprecated and will be removed in a future release.

2023-05-18T13:54:06.976026Z 0 [Warning] [MY-011068] [Server] The syntax 'skip_slave_start' is deprecated and will be removed in a future release. Please use skip_replica_start instead.

2023-05-18T13:54:06.976032Z 0 [Warning] [MY-011068] [Server] The syntax 'slave_exec_mode' is deprecated and will be removed in a future release. Please use replica_exec_mode instead.

2023-05-18T13:54:06.976039Z 0 [Warning] [MY-011068] [Server] The syntax 'slave_load_tmpdir' is deprecated and will be removed in a future release. Please use replica_load_tmpdir instead.

2023-05-18T13:54:06.977134Z 0 [Warning] [MY-010918] [Server] 'default_authentication_plugin' is deprecated and will be removed in a future release. Please use authentication_policy instead.

2023-05-18T13:54:06.978517Z 0 [System] [MY-010116] [Server] /rdsdbbin/mysql/bin/mysqld (mysqld 8.0.28) starting as process 754

2023-05-18T13:54:07.077699Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.

2023-05-18T13:54:07.092822Z 1 [Warning] [MY-012191] [InnoDB] Scan path '/rdsdbdata/db/innodb' is ignored because it is a sub-directory of '/rdsdbdata/db/

2023-05-18T13:54:08.362637Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.

2023-05-18T13:54:09.008608Z 0 [Warning] [MY-013414] [Server] Server SSL certificate doesn't verify: unable to get issuer certificate

2023-05-18T13:54:09.009363Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.

2023-05-18T13:54:09.155728Z 0 [System] [MY-010931] [Server] /rdsdbbin/mysql/bin/mysqld: ready for connections. Version: '8.0.28' socket: '/tmp/mysql.sock' port: 3306 Source distribution.

2023-05-18T13:55:17.502242Z 9 [Warning] [MY-010055] [Server] IP address 'xxx.xx.xx.xxx' could not be resolved: Name or service not known

2023-05-18T13:55:29.364990Z 12 [Warning] [MY-010055] [Server] IP address 'yyy.yy.yy.yyy' could not be resolved: Name or service not known

2023-05-18T13:55:39.356404Z 15 [Warning] [MY-010055] [Server] IP address 'zzz.zz.zz.zzz' could not be resolved: Name or service not known

2023-05-18T13:55:48.327968Z 18 [Warning] [MY-010056] [Server] Host name 'aaa-aaa-aaa-aa.pool.some-domain.ch' could not be resolved: Name or service not known

Can somebody explain to me what has happened here? Was this triggered by AWS? Or was this triggered by a user that should not have access to the database? The IP's xxx.xx.xx.xxx (and y and z) are EC2 instances in my network. The aaa-aaa-aaa-aa is my home-PCs public IP address. Should I be concerned about the warnings regarding the deprecations?

Many Thanks for your support!

asked 3 years ago2.2K views

2 Answers
0

Using something deprecated is certainly not a good idea, but as far as I could tell from this log, it was not something that would stop on its own.
Is this log an error log?
Also, what was the performance of the RDS during the time this logging occurred?
If CPU and memory utilization, etc. are high, the cause may be there.

EXPERT

answered 3 years ago

  • Thank you for your answer. Yes, this is an error log: error/mysql-error-running.log CPU utilization was slightly elevated (4% instead of 3%), with the increase happening about 22h prior to the unexpected shutdown. However, CPUCreditBalance stayed at its maximum all the time, until it was reset to 0 at the time of the shutdown. what might help is that EBSByteBalance% was constantly at 100% the day prior to the event. Then about 22h prior to the event the EBYByteBalance% declined continuously, at hit 0 at the event. After the event, it was reset to 100%.

    Also, about 22h prior to the event LVMReadIOPS and ReadIOPS were increased to about 10x the normal level and stayed up for about 22h (at approx 3-4 count/sec).

    Unfortunately I cannot interpret these numbers myself. Could you maybe advise?

    And regarding the deprecations, what do I need to update to use the latest version / configuration?

  • I don't know what kind of application you are using RDS for, but it is conceivable that this could have been caused by performance degradation of RDS. The fact that EBYByteBalance% was low indicates a throughput bottleneck. https://docs.aws.amazon.com/AWSEC2/latest/UserGuide/viewing_metrics_with_cloudwatch.html
    Countermeasures will require finding SQL with high load or changing the type of EBS, as described in the following document. Please select an EBS type that allows you to set the throughput yourself, such as io1 or gp3. https://repost.aws/knowledge-center/rds-latency-ebs-iops-bottleneck

  • Are there any logs in AWS which show which statements were responsible for the rapid decay of EBSByteBalance% ? I have a couple of applications connected to the DB, but i have never observed any of them causing such a high load, and they are running for months already.

0

There was a hardware failure and the automation replaced your instance. You can look at the events in the RDS console to see this.

AWS
MODERATOR

answered 3 years ago

You are not logged in. Log in to post an answer.

A good answer clearly answers the question and provides constructive feedback and encourages professional growth in the question asker.