4

My MySQL server running the latest version of MySql on Ubuntu 16.x keeps crashing once or twice a day. Sometimes it repairs itself fairly quickly (10 minutes). Sometimes I have to reboot and do an fsck to get things running again.

What would be causing this?

Things I've tried so far:

  • increased RAM from 1.5GB up to 5GB.
  • Hardware Upgrades: MotherBoard, processor, RAM (DDR4) but that didn't help (it was running a 7 year old processor, now running 7th Gen Core I5).
  • Setup UFW firewall to ensure it wasn't being caused by bots attacking MySQL or other services.
  • In my.cnf, changed innodb_buffer_pool_size from 128MB to 500MB. didn't help but still in place
  • I've run: mysqlcheck -u root -p --auto-repair --optimize --all-databases multiple times. didn't help
  • In my.cnf, Decreased mysql max_connections from 151 to 80 and restarted mysql. didn't help
  • Decreased apache MaxRequestWorkers from 150 to 100. Didn't help. Still crashing.
  • I already had a 1GB Swap file. Left it.
  • Scoured through Apache2 logs, SysLog, any other log that seemed appropriate but haven't found anything that caught my eye.
  • Shutdown the server and tried to move the VM to another drive but it fails with File Error.
  • My latest suspicion is this is being caused by a bad block but running badblocks seemed to trigger a crash at 25% complete. During the fsck I see this: fsck critical medium error, dev sda, sector 147306432

Here is a typical mysql error log:

2017-04-20T18:43:46.958430Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 11791ms. The settings might not be optimal. (flu shed=92 and evicted=0, during the time.)
2017-04-20T18:44:11.989905Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 6822ms. The settings might not be optimal. (flushed=8 and evicted=0, during the time.)
2017-04-20T18:44:49.145162Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 5021ms. The settings might not be optimal. (flus hed=0 and evicted=0, during the time.)
2017-04-20T18:45:22.322429Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 26338ms. The settings might not be optimal. (flu shed=10 and evicted=0, during the time.)
2017-04-20T18:45:53.926808Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 4510ms. The settings might not be optimal. (flus hed=0 and evicted=0, during the time.)
2017-04-20T18:46:03.097400Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 5384ms. The settings might not be optimal. (flus hed=13 and evicted=0, during the time.)
2017-04-20T18:46:39.247467Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 14848ms. The settings might not be optimal. (flu shed=8 and evicted=0, during the time.)
2017-04-20T18:47:16.271672Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 29107ms. The settings might not be optimal. (flu shed=8 and evicted=0, during the time.)
2017-04-20T18:47:53.669557Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 5969ms. The settings might not be optimal. (flus hed=37 and evicted=0, during the time.)
2017-04-20T18:50:23.879411Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 37671ms. The settings might not be optimal. (flu shed=6 and evicted=0, during the time.)
2017-04-20T18:55:07.190725Z 0 [Warning] Changed limits: max_open_files: 1024 (requested 5000) 2017-04-20T18:55:07.235759Z 0 [Warning] Changed limits: table_open_cache: 431 (requested 2000)
2017-04-20T18:55:10.486670Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_times tamp server option (see documentation for more details).
2017-04-20T18:55:11.563578Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.17-0ubuntu0.16.04.2) starting as process 24701 ...
2017-04-20T18:55:21.979225Z 0 [Note] InnoDB: PUNCH HOLE support available
2017-04-20T18:55:21.979250Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-04-20T18:55:21.979253Z 0 [Note] InnoDB: Uses event mutexes 2017-04-20T18:55:21.979256Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-04-20T18:55:21.979259Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-04-20T18:55:21.979262Z 0 [Note] InnoDB: Using Linux native AIO 2017-04-20T18:55:22.004800Z 0 [Note] InnoDB: Number of pools: 1
2017-04-20T18:55:22.060762Z 0 [Note] InnoDB: Using CPU crc32 instructions
2017-04-20T18:55:22.104584Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2017-04-20T18:55:24.184701Z 0 [Note] InnoDB: Completed initialization of buffer pool
2017-04-20T18:55:24.210160Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2017-04-20T18:55:26.405242Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2017-04-20T18:55:27.508456Z 0 [Note] InnoDB: Log scan progressed past the checkpoint lsn 35288448161
2017-04-20T18:55:27.508478Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 35288448170
2017-04-20T18:55:27.508630Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 35288448170
2017-04-20T18:55:27.508634Z 0 [Note] InnoDB: Database was not shutdown normally!
2017-04-20T18:55:27.508637Z 0 [Note] InnoDB: Starting crash recovery.
2017-04-20T18:56:16.516761Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2017-04-20T18:56:16.516785Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2017-04-20T18:56:16.516817Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2017-04-20T18:56:16.621736Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2017-04-20T18:56:16.622203Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2017-04-20T18:56:16.622211Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2017-04-20T18:56:16.622565Z 0 [Note] InnoDB: Waiting for purge to start
2017-04-20T18:56:16.672708Z 0 [Note] InnoDB: 5.7.17 started; log sequence number 35288448170
2017-04-20T18:56:16.672708Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 52462ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)
2017-04-20T18:56:16.673192Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2017-04-20T18:56:16.702959Z 0 [Note] Plugin 'FEDERATED' is disabled.
2017-04-20T18:56:16.851553Z 0 [ERROR] Function 'archive' already exists
2017-04-20T18:56:16.851568Z 0 [Warning] Couldn't load plugin named 'archive' with soname 'ha_archive.so'.
2017-04-20T18:56:16.851574Z 0 [ERROR] Function 'blackhole' already exists
2017-04-20T18:56:16.851575Z 0 [Warning] Couldn't load plugin named 'blackhole' with soname 'ha_blackhole.so'.
2017-04-20T18:56:16.851578Z 0 [ERROR] Function 'federated' already exits 2017-04-20T18:56:16.851579Z 0 [Warning] Couldn't load plugin named 'federated' with soname 'ha_federated.so'.
2017-04-20T18:56:16.851582Z 0 [ERROR] Function 'innodb' already exists 2017-04-20T18:56:16.851583Z 0 [Warning] Couldn't load plugin named 'innodb' with soname 'ha_innodb.so'.
2017-04-20T18:56:17.044733Z 0 [Warning] Failed to set up SSL because of the following SSL library error: SSL context is not usable without certificate and private key
2017-04-20T18:56:17.044754Z 0 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
2017-04-20T18:56:17.044761Z 0 [Note] - '0.0.0.0' resolves to '0.0.0.0';
2017-04-20T18:56:17.044779Z 0 [Note] Server socket created on IP: '0.0.0.0'. 2017-04-20T18:56:18.483575Z 0 [Note] Event Scheduler: Loaded 0 events
2017-04-20T18:56:18.483706Z 0 [Note] Executing 'SELECT * FROM INFORMATION_SCHEMA.TABLES;' to get a list of tables using the deprecated partition engine. You may use the startup option '--disable-partition-engine-check' to skip this check.
2017-04-20T18:56:18.483716Z 0 [Note] Beginning of list of non-natively partitioned tables
2017-04-20T18:56:25.478293Z 0 [Note] InnoDB: Buffer pool(s) load completed at 170420 13:56:25
2017-04-20T18:56:26.091240Z 0 [Note] End of list of non-natively partitioned tables
2017-04-20T18:56:26.091423Z 0 [Note] /usr/sbin/mysqld: ready for connections. Version: '5.7.17-0ubuntu0.16.04.2' socket: '/var/run/mysqld/mysqld.sock' port: 3306 (Ubuntu)
2017-04-20T18:56:26.155810Z 4 [ERROR] /usr/sbin/mysqld: Table './example/wp_options' is marked as crashed and should be repaired
2017-04-20T18:56:26.155889Z 5 [ERROR] /usr/sbin/mysqld: Table './example/wp_options' is marked as crashed and should be repaired
2017-04-20T18:56:26.156037Z 4 [Warning] Checking table:'./example/wp_options'
2017-04-20T18:56:35.816730Z 4 [ERROR] /usr/sbin/mysqld: Table './example/wp_usermeta' is marked as crashed and should be repaired
2017-04-20T18:56:35.816875Z 4 [Warning] Checking table: './example/wp_usermeta'

Improve this question
6
  • 2
    What is the value of innodb_buffer_pool_size? For 3GB of RAM it needs to be about 1000M if you are mostly using InnoDB, not MyISAM.
    – Rick James
    Apr 20, 2017 at 22:26
  • Which Engine are you using? It sounds like MyISAM, since I see "Checking table".
    – Rick James
    Apr 20, 2017 at 22:27
  • Mostly using InnoDB.
    – EfficionDave
    Apr 21, 2017 at 15:26
  • I've now installed MySQLTuner 1.6.0 and am following it's recommendations.
    – EfficionDave
    Apr 21, 2017 at 19:29
  • Still crashing despite tuning and larger innodb_buffer_pool_size. And I often have to reboot and do an fsck to get things running again.
    – EfficionDave
    Apr 22, 2017 at 13:28

2 Answers 2

Reset to default
4
+50
  • Shutdown the server and tried to move the VM to another drive but it fails with File Error.
  • My latest suspicion is this is being caused by a bad block but running badblocks seemed to trigger a crash at 25% complete. During the fsck I see this: fsck critical medium error, dev sda, sector 147306432

Don't waste your time on DB tuning & others things, your drive seem definitely guilty for me...

Try to make a dump of the DB with as much as you can, try a low level drive formatting and start a clean VM.

Improve this answer
4
  • I agree that the main problem is most likely the drive. Further confirmation of this is another VM which has a disk on the same drive can, when certain files are hit, also trigger the datastore to get detached and not reattach until the physical machine is rebooted. But, I'd really like to find a way to move the VM to another drive and not rebuild it from scratch as that seems like it'd take 20 hours to get everything back to the way I have it.
    – EfficionDave
    Apr 25, 2017 at 22:24
  • @EfficionDave your don't seem to get the criticality of the situation: you're about to loose the VM data's. Make a backup, if it fail, try a byte-by-byte recovery mode copy of the virtual drive file, ddrescue may help you a lot, but understand we already speak of days to get everything back from bad sectors.
    – Blag
    Apr 25, 2017 at 22:55
  • For the last 3 days, I don't believe anything on the Ubuntu VM has triggered the drive to crash. It has been crashed by accessing certain files by a different VM. I've managed to move all the files for the other VMs off of the drive at this point so the Ubuntu VM is the only thing left on the drive and it has been very stable and the mysql logs are mostly quiet. I will definitely be getting rid of the drive but I'm still hopeful I can now move, backup, or repair the VM rather than rebuilding from scratch. I'll find out tonight.
    – EfficionDave
    Apr 26, 2017 at 17:33
  • @EfficionDave nice work so ;) Good luck with the copy, as already said, if the straight copy don't work, give a try with ddrescue, as it seem your drive is not totally dead, you have your chance to get back the few broken block...
    – Blag
    Apr 26, 2017 at 18:18
1

Your problem may stem from an old issue with the page cleaner.

There are bug reports about it

What is interesting to note is someone actually narrowed down the page cleaner issue with regards to the InnoDB Buffer Pool instances. The post was written back in November 2016 (MySQL InnoDB page_cleaner settings might not be optimal) That post mentions something from the MySQL 5.7 Documentation on innodb_page_cleaners. Here is the full first paragraph:

The number of page cleaner threads that flush dirty pages from buffer pool instances. Page cleaner threads perform flush list and LRU flushing. A single page cleaner thread was introduced in MySQL 5.6 to offload buffer pool flushing work from the InnoDB master thread. In MySQL 5.7, InnoDB provides support for multiple page cleaner threads. A value of 1 maintains the pre-MySQL 5.7 configuration in which there is a single page cleaner thread. When there are multiple page cleaner threads, buffer pool flushing tasks for each buffer pool instance are dispatched to idle page cleaner threads. The innodb_page_cleaners default value was changed from 1 to 4 in MySQL 5.7. If the number of page cleaner threads exceeds the number of buffer pool instances, innodb_page_cleaners is automatically set to the same value as innodb_buffer_pool_instances.

According to your question and its comments, your buffer pool may still be too small. Since the Buffer Pool is < 1G (1024M), innodb_buffer_pool_instances drops to 1. This, in turn, would force innodb_page_cleaners to drop to 1.

You can verify than with

SHOW GLOBAL VARIABLES LIKE 'innodb_buffer_pool_instances';
SHOW GLOBAL VARIABLES LIKE 'innodb_page_cleaners';

I would set the innodb_buffer_pool_size to 1536M (which is 1.5G). Then, upon mysqld restart, innodb_buffer_pool_instances would bounce up to its default of 8. Even though innodb_buffer_pool_size is dynamic, innodb_buffer_pool_instances is not. Therefore, you must set these values in my.cnf and restart mysqld (it is required).

Improve this answer
1
  • I ran these statements: SHOW GLOBAL VARIABLES LIKE 'innodb_buffer_pool_instances'; SHOW GLOBAL VARIABLES LIKE 'innodb_page_cleaners'; And both were at 1 currently. I will try updating them once I've moved the VM to a new drive.
    – EfficionDave
    Apr 25, 2017 at 22:11

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.

Not the answer you're looking for? Browse other questions tagged or ask your own question.