Help me to analyze SQL Log
Hi,
I am running WordPress sites on VPS, sometimes when sites are medium loaded (around 10 people are serving them) My SQL restarts and - Error establishing a database connection - message is appearing on site pages for few seconds, here is SQL error log:
Can somone please help me to figure out whats going on? Thanks
191219 16:41:02 mysqld_safe Number of processes running now: 0
191219 16:41:02 mysqld_safe mysqld restarted
2019-12-19 16:41:02 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2019-12-19 16:41:02 0 [Warning] Insecure configuration for --secure-file-priv: Current value does not restrict location of generated files. Consider setting it to a valid, non-empty path.
2019-12-19 16:41:02 0 [Note] /usr/sbin/mysqld (mysqld 5.6.45) starting as process 2843 ...
2019-12-19 16:41:02 2843 [Note] Plugin 'FEDERATED' is disabled.
2019-12-19 16:41:02 2843 [Note] InnoDB: Using atomics to ref count buffer pool pages
2019-12-19 16:41:02 2843 [Note] InnoDB: The InnoDB memory heap is disabled
2019-12-19 16:41:02 2843 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2019-12-19 16:41:02 2843 [Note] InnoDB: Memory barrier is not used
2019-12-19 16:41:02 2843 [Note] InnoDB: Compressed tables use zlib 1.2.11
2019-12-19 16:41:02 2843 [Note] InnoDB: Using Linux native AIO
2019-12-19 16:41:02 2843 [Note] InnoDB: Not using CPU crc32 instructions
2019-12-19 16:41:02 2843 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2019-12-19 16:41:02 2843 [Note] InnoDB: Completed initialization of buffer pool
2019-12-19 16:41:02 2843 [Note] InnoDB: Highest supported file format is Barracuda.
2019-12-19 16:41:02 2843 [Note] InnoDB: The log sequence numbers 19598720119 and 19598720119 in ibdata files do not match the log sequence number 34664857744 in the ib_logfiles!
2019-12-19 16:41:02 2843 [Note] InnoDB: Database was not shutdown normally!
2019-12-19 16:41:02 2843 [Note] InnoDB: Starting crash recovery.
2019-12-19 16:41:02 2843 [Note] InnoDB: Reading tablespace information from the .ibd files...
2019-12-19 16:41:06 2843 [Note] InnoDB: Restoring possible half-written data pages
2019-12-19 16:41:06 2843 [Note] InnoDB: from the doublewrite buffer...
2019-12-19 16:41:06 2843 [Note] InnoDB: 128 rollback segment(s) are active.
2019-12-19 16:41:06 2843 [Note] InnoDB: Waiting for purge to start
2019-12-19 16:41:06 2843 [Note] InnoDB: 5.6.45 started; log sequence number 34664857744
2019-12-19 16:41:07 2843 [Note] Server hostname (bind-address): '*'; port: 3306
2019-12-19 16:41:07 2843 [Note] IPv6 is available.
2019-12-19 16:41:07 2843 [Note] - '::' resolves to '::';
2019-12-19 16:41:07 2843 [Note] Server socket created on IP: '::'.
2019-12-19 16:41:07 2843 [Note] Event Scheduler: Loaded 0 events
2019-12-19 16:41:07 2843 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.6.45' socket: '/var/lib/mysql/mysql.sock' port: 3306 MySQL Community Server (GPL)
191219 16:45:58 mysqld_safe Number of processes running now: 0
191219 16:45:58 mysqld_safe mysqld restarted
2019-12-19 16:45:58 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2019-12-19 16:45:58 0 [Warning] Insecure configuration for --secure-file-priv: Current value does not restrict location of generated files. Consider setting it to a valid, non-empty path.
2019-12-19 16:45:58 0 [Note] /usr/sbin/mysqld (mysqld 5.6.45) starting as process 3387 ...
2019-12-19 16:45:58 3387 [Note] Plugin 'FEDERATED' is disabled.
2019-12-19 16:45:58 3387 [Note] InnoDB: Using atomics to ref count buffer pool pages
2019-12-19 16:45:58 3387 [Note] InnoDB: The InnoDB memory heap is disabled
2019-12-19 16:45:58 3387 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2019-12-19 16:45:58 3387 [Note] InnoDB: Memory barrier is not used
2019-12-19 16:45:58 3387 [Note] InnoDB: Compressed tables use zlib 1.2.11
2019-12-19 16:45:58 3387 [Note] InnoDB: Using Linux native AIO
2019-12-19 16:45:58 3387 [Note] InnoDB: Not using CPU crc32 instructions
2019-12-19 16:45:58 3387 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2019-12-19 16:45:58 3387 [Note] InnoDB: Completed initialization of buffer pool
2019-12-19 16:45:58 3387 [Note] InnoDB: Highest supported file format is Barracuda.
2019-12-19 16:45:58 3387 [Note] InnoDB: The log sequence numbers 19598720119 and 19598720119 in ibdata files do not match the log sequence number 34962019578 in the ib_logfiles!
2019-12-19 16:45:58 3387 [Note] InnoDB: Database was not shutdown normally!
2019-12-19 16:45:58 3387 [Note] InnoDB: Starting crash recovery.
2019-12-19 16:45:58 3387 [Note] InnoDB: Reading tablespace information from the .ibd files...
2019-12-19 16:46:02 3387 [Note] InnoDB: Restoring possible half-written data pages
2019-12-19 16:46:02 3387 [Note] InnoDB: from the doublewrite buffer...
2019-12-19 16:46:03 3387 [Note] InnoDB: 128 rollback segment(s) are active.
2019-12-19 16:46:03 3387 [Note] InnoDB: Waiting for purge to start
2019-12-19 16:46:03 3387 [Note] InnoDB: 5.6.45 started; log sequence number 34962019578
2019-12-19 16:46:03 3387 [Note] Server hostname (bind-address): '*'; port: 3306
2019-12-19 16:46:03 3387 [Note] IPv6 is available.
2019-12-19 16:46:03 3387 [Note] - '::' resolves to '::';
2019-12-19 16:46:03 3387 [Note] Server socket created on IP: '::'.
2019-12-19 16:46:03 3387 [Note] Event Scheduler: Loaded 0 events
2019-12-19 16:46:03 3387 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.6.45' socket: '/var/lib/mysql/mysql.sock' port: 3306 MySQL Community Server (GPL)
Can somone please help me to figure out whats going on? Thanks
-
Hello, This is an issue with innodb and most likely corruption. You may want to increment "innodb_force_recovery" from 1 to 2 and so on in the server's MySQL configuration at /etc/my.cnf
, restarting MySQL each step along the way in an effort to repair the corruption InnoDB is encountering when it starts up. If you are familiar with linux command line, the following guide is quite helpful and extremely detailed for database restoration and repairing InnoDB:0 -
1. Thanks for reply 2. I have hired System Administration service guys and they have scanned and analyzed all DB'S and they are not corrupted, + they say: "We can perform an MYSQL tunning to check whether the issue will persist or not. In order to tune the MYSQL, the service must be online for at least 24 hrs" 3. Do you have other ideas about what else it can be? 0 -
Hey there! The following portion of that log file does indicate there is an issue with InnoDB during the time of the crash, but MySQL was able to automatically recover: 2019-12-19 16:45:58 3387 [Note] InnoDB: The log sequence numbers 19598720119 and 19598720119 in ibdata files do not match the log sequence number 34962019578 in the ib_logfiles!
Just after that, we see the following block of text showing the crash was recoverable:2019-12-19 16:45:58 3387 [Note] InnoDB: Database was not shutdown normally! 2019-12-19 16:45:58 3387 [Note] InnoDB: Starting crash recovery. 2019-12-19 16:45:58 3387 [Note] InnoDB: Reading tablespace information from the .ibd files... 2019-12-19 16:46:02 3387 [Note] InnoDB: Restoring possible half-written data pages 2019-12-19 16:46:02 3387 [Note] InnoDB: from the doublewrite buffer... 2019-12-19 16:46:03 3387 [Note] InnoDB: 128 rollback segment(s) are active. 2019-12-19 16:46:03 3387 [Note] InnoDB: Waiting for purge to start 2019-12-19 16:46:03 3387 [Note] InnoDB: 5.6.45 started; log sequence number 34962019578
This would indicate the tables are not in a crashed state by the time the admin checked the system, but something is causing them to crash originally, although it seems to be minor as the system is able to recover itself without the need to restore from backups or adjust the MySQL settings on the system. I also agree that it is best to let MySQL run for at least 24 hours, at this gives the "mysqladmin" tools time to build up data that can be used to optimize the service. Performing that optimization and dealing with the root cause of the crashes is something that you'll want to continue working with the system administrator on, but if you'd like to share more details here when you have them, we'll be happy to check.0 -
Hi, thanks for help,. Issue was caused by low memory of ram, I have upgraded the ram and all is fine now. Kind Regards, Nick 0 -
I'm glad to hear that's all it was! 0 -
Thank you :) 0 -
Last week, I was also facing the same issues. Honestly, I am not having much knowledge about databases and storage engines. I am doing an internship right now. I am using WordPress. So I contact the support team. They tell me about the exact issue after checking the problem and as they said the problem is in InnoDB due to corruption and suggests some steps to do. I told them about my lack of knowledge then they suggest a tool to resolve this issue i.e. Stellar repair for Mysql. But a little bad for me that it is a paid tool. 0 -
Handling InnoDB corruption is always a delicate procedure, so I'm not surprised a paid tool was recommended. With those type of issues it is often best to have a professional MySQL admin check the system to make sure no future data loss happens. 0
Please sign in to leave a comment.
Comments
8 comments