Question

Database connections timeout

Persistent database connections to MySQL and Redis servers don’t stay open for more than a couple of minutes before connection is dropped. This issue came up since we switched to node applications in cluster mode that keep around 30 - 50 connections open at any time. Most common error is “MySQL server has gone away” that is usually handled in application logic, but lately errors like “Lost connection to MySQL server during query” and 111 “Connection refused” started coming up, which are not handled cleanly.

Even PHP applications that keep only one non-persistent connection have random connection issues. On top of that even remote SSH to server drops occasionally.

All our servers run in SF1 region. Any ideas what would be causing these connections issues?

Subscribe
Share

Actually there are messages I have missed before. Looks like the mysql server restarts itself once or twice a day. That would definitely contribute to timeouts.


2016-08-05 00:11:20 25575 [Note] InnoDB: Using CPU crc32 instructions
2016-08-05 00:11:20 25575 [Note] InnoDB: Initializing buffer pool, size = 5.0G
2016-08-05 00:11:20 25575 [Note] InnoDB: Completed initialization of buffer pool
2016-08-05 00:11:20 25575 [Note] InnoDB: Highest supported file format is Barracuda.
2016-08-05 00:11:20 25575 [Note] InnoDB: Log scan progressed past the checkpoint lsn 223074090775
2016-08-05 00:11:20 25575 [Note] InnoDB: Database was not shutdown normally!
2016-08-05 00:11:20 25575 [Note] InnoDB: Starting crash recovery.
2016-08-05 00:11:20 25575 [Note] InnoDB: Reading tablespace information from the .ibd files...
2016-08-05 00:11:21 25575 [Note] InnoDB: Restoring possible half-written data pages
2016-08-05 00:11:21 25575 [Note] InnoDB: from the doublewrite buffer...
InnoDB: Doing recovery: scanned up to log sequence number 223074115733
2016-08-05 00:11:21 25575 [Note] InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
2016-08-05 00:11:22 25575 [Note] InnoDB: 128 rollback segment(s) are active.
2016-08-05 00:11:22 25575 [Note] InnoDB: Waiting for purge to start
2016-08-05 00:11:22 25575 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.30-76.3 started; log sequence number 223074115733
2016-08-05 00:11:22 25575 [Note] RSA private key file not found: /var/lib/mysql//private_key.pem. Some authentication plugins will not work.
2016-08-05 00:11:22 25575 [Note] RSA public key file not found: /var/lib/mysql//public_key.pem. Some authentication plugins will not work.
2016-08-05 00:11:22 25575 [Note] Server hostname (bind-address): '*'; port: 3306
2016-08-05 00:11:22 25575 [Note] IPv6 is available.
2016-08-05 00:11:22 25575 [Note]   - '::' resolves to '::';
2016-08-05 00:11:22 25575 [Note] Server socket created on IP: '::'.
2016-08-05 00:11:22 25575 [Note] Event Scheduler: Loaded 0 events
2016-08-05 00:11:22 25575 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.6.30-76.3'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  Percona Server (GPL), Release 76.3, Revision 3850db5
2016-08-05 00:41:58 25575 [Warning] IP address 'xxx.xxx.xxx.xxx' could not be resolved: Name or service not known
160805 08:30:24 mysqld_safe Number of processes running now: 0
160805 08:30:24 mysqld_safe mysqld restarted
2016-08-05 08:30:26 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2016-08-05 08:30:26 0 [Note] /usr/sbin/mysqld (mysqld 5.6.30-76.3) starting as process 28380 ...
2016-08-05 08:30:26 28380 [Note] Plugin 'FEDERATED' is disabled.
2016-08-05 08:30:26 28380 [Note] InnoDB: Using atomics to ref count buffer pool pages
2016-08-05 08:30:26 28380 [Note] InnoDB: The InnoDB memory heap is disabled
2016-08-05 08:30:26 28380 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2016-08-05 08:30:26 28380 [Note] InnoDB: Memory barrier is not used
2016-08-05 08:30:26 28380 [Note] InnoDB: Compressed tables use zlib 1.2.7
2016-08-05 08:30:26 28380 [Note] InnoDB: Using Linux native AIO
2016-08-05 08:30:26 28380 [Note] InnoDB: Using CPU crc32 instructions
2016-08-05 08:30:26 28380 [Note] InnoDB: Initializing buffer pool, size = 5.0G
2016-08-05 08:30:26 28380 [Note] InnoDB: Completed initialization of buffer pool
2016-08-05 08:30:27 28380 [Note] InnoDB: Highest supported file format is Barracuda.
2016-08-05 08:30:27 28380 [Note] InnoDB: The log sequence numbers 199782124887 and 199782124887 in ibdata files do not match the log sequence number 223166042299 in the ib_logfiles!
2016-08-05 08:30:27 28380 [Note] InnoDB: Database was not shutdown normally!
2016-08-05 08:30:27 28380 [Note] InnoDB: Starting crash recovery.
2016-08-05 08:30:27 28380 [Note] InnoDB: Reading tablespace information from the .ibd files...
2016-08-05 08:30:27 28380 [Note] InnoDB: Restoring possible half-written data pages
2016-08-05 08:30:27 28380 [Note] InnoDB: from the doublewrite buffer...
2016-08-05 08:30:28 28380 [Note] InnoDB: 128 rollback segment(s) are active.
2016-08-05 08:30:28 28380 [Note] InnoDB: Waiting for purge to start
2016-08-05 08:30:28 28380 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.30-76.3 started; log sequence number 223166042299
2016-08-05 08:30:28 28380 [Note] RSA private key file not found: /var/lib/mysql//private_key.pem. Some authentication plugins will not work.
2016-08-05 08:30:28 28380 [Note] RSA public key file not found: /var/lib/mysql//public_key.pem. Some authentication plugins will not work.
2016-08-05 08:30:28 28380 [Note] Server hostname (bind-address): '*'; port: 3306
2016-08-05 08:30:28 28380 [Note] IPv6 is available.
2016-08-05 08:30:28 28380 [Note]   - '::' resolves to '::';
2016-08-05 08:30:28 28380 [Note] Server socket created on IP: '::'.
2016-08-05 08:30:28 28380 [Note] Event Scheduler: Loaded 0 events
2016-08-05 08:30:28 28380 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.6.30-76.3'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  Percona Server (GPL), Release 76.3, Revision 3850db5
2016-08-05 16:19:59 28380 [Warning] IP address 'xxx.xxx.xxx.xxx' could not be resolved: Name or service not known

Hi! Are there any errors in MySQL’s error log?

sudo tail -30 /var/log/mysql.err

Submit an answer
You can type!ref in this text area to quickly search our full set of tutorials, documentation & marketplace offerings and insert the link!

These answers are provided by our Community. If you find them useful, show some love by clicking the heart. If you run into issues leave a comment, or add your own answer to help others.

Sorry for the late reply. With those persistent connections it’s possible that you are running out of listeners (with all the slots full with persistent connections and the short term php ones as well new clients may be getting denied or dormant connections freed up).

I would recommend reviewing my.cnf (in /etc/mysql) to see what your max_connections variable is set to. With the persistent connections, check the wait_timeout value in case MySQL is timing out these connections when they are idle.