Server load excessively high (three figures!!) after migration

CTXMedia

Well-known member
I can restart my server and run CycleChat XF as a closed board and it runs just fine. No problems.

As soon as I open it and my members begin using it the server load starts rising and rising and it takes longer and longer for pages/posts/actions to complete, to the point it becomes useless.

Any ideas about what I might have missed, or misconfigured?

Thanks,
Shaun :D
 
I'm really at a loss to know exactly what it was, but it's running lovely and smooth now. And server load is nice and low.

I've been running a cron job every two minutes to log server load so we'll leave that running for another month and then compare pre/post migration to see if there's any marked difference. (y)
 
I'm really at a loss to know exactly what it was, but it's running lovely and smooth now. And server load is nice and low.

I've been running a cron job every two minutes to log server load so we'll leave that running for another month and then compare pre/post migration to see if there's any marked difference. (y)

Attempt a "Trial of One", where you reverse a change to the previous state and see if that messes things up again. Only then will you know what worked and what was the problem. This information could be valuable in the future.

Of course, do it in a few days once you've had a chance to sleep.
 
0? did you change this value? normally set at 6 to 10?

Yes, it's now set to 8 ... (y)

Here's the relative part of my.cnf now:

Code:
innodb_log_buffer_size = 8M
innodb_log_file_size = 16M
innodb_flush_log_at_trx_commit = 2
innodb_flush_method = O_DIRECT
innodb_thread_concurrency = 8
innodb_additional_mem_pool_size = 8M
innodb_buffer_pool_size = 1500M
 
Your log_file_size is way too small for your site.

Also, login to MySQL and run the following:
Code:
show engine innodb status\G

Paste the results here...
 
Your log_file_size is way too small for your site

After experimenting, I couldn't get MySQL to start when the log file was any larger.

I suspect an MySQL expert could probably reconfigure it to run much sweeter on my server, but it's going like the proverbial clappers this morning so whatever was causing the bottleneck is now resolved.

I did have a mass of entries in my slow query log and when I viewed the process list via phpmyadmin I had lots of queries waiting to be processed, but this morning there are no delays.

InnoDB status:

Code:
=====================================
111122  9:47:06 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 42 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 20114, signal count 20068
Mutex spin waits 0, rounds 237424, OS waits 7810
RW-shared spins 25384, OS waits 12113; RW-excl spins 985, OS waits 162
------------
TRANSACTIONS
------------
Trx id counter 0 174835208
Purge done for trx's n:o < 0 174834777 undo n:o < 0 0
History list length 25
Total number of lock structs in row lock hash table 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 0, not started, process no 8048, OS thread id 915557264
MySQL thread id 60770, query id 2114229 localhost ccipb
SHOW INNODB STATUS
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (write thread)
Pending normal aio reads: 0, aio writes: 0,
 ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
56603 OS file reads, 66814 OS file writes, 18675 OS fsyncs
0.21 reads/s, 16384 avg bytes/read, 2.76 writes/s, 0.71 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 5, seg size 7,
814 inserts, 817 merged recs, 792 merges
Hash table size 6640657, used cells 575749, node heap has 592 buffer(s)
2734.63 hash searches/s, 215.09 non-hash searches/s
---
LOG
---
Log sequence number 8 1896130461
Log flushed up to   8 1896130461
Last checkpoint at  8 1896130076
0 pending log writes, 0 pending chkp writes
19295 log i/o's done, 0.69 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 1848071218; in additional pool allocated 8388608
Buffer pool size   102400
Free buffers       0
Database pages     101808
Modified db pages  9
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 167791, created 379, written 49991
0.21 reads/s, 0.00 creates/s, 2.26 writes/s
Buffer pool hit rate 1000 / 1000
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
Main thread process no. 8048, id 990550928, state: sleeping
Number of rows inserted 29940, updated 11940, deleted 23025, read 87980663
0.21 inserts/s, 0.00 updates/s, 0.05 deletes/s, 2811.29 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
 
You have to do a full flush to disk when you stop MySQL, delete the log files, change the size in the my.cnf file and then restart MySQL. ie, innodb_fast_shutdown has to be zero before you shutdown as it causes the log files to be properly flushed so they can safely be deleted.

Looking at the output it is telling me that the memory allocated to InnoDB is not enough to keep the pages in the cache, your Buffer pool and Memory has zero pages free so you will be reading from disk for data.
 
Would cloud hosting solve this issue so you could be able to scale infinitely? Does anyone here use cloud hosting? Is it worth it?

I don't think MySQL was configured optimally on my server (it's an old one I've had for years and should be upgraded next year anyway) - and Deebs is helping me via PM to reconfigure it, so hopefully it'll be better once we've finished.

I've already got a lot of other things in place and now it has settled down it's working really well with around 40% overall less load on the server than when it was on IPB, so I'm more than pleased. It may go up a tiny bit as I put a few add-ons in place, but I don't expect any dramatic change. (y)
 
GeeksChat, when you get your db settings stable, you should post them as a helpful suggestion for others. Your server needs more memory double or triple it. :)

I recently doubled it to 8GB - but it can't take any more due to its age. I've had it for 4/5 years now so it's going to be upgraded in the new year - more "juice" so-to-speak (y)

TBH with the couple of tweaks Deebs helped me to make it's running very nicely now and at a good, very low, server load level too!! :D

I've reduced the max connections and lowered the myisam settings to gain a bit more memory (I only have a couple of packages that use myisam now and they work fine with the lower settings), and with Deebs help managed to more than double innodb_buffer_pool_size and double the log file size (I was approaching that part wrongly - see the green line added to my.cnf and you need to manually rename/remove the logs so MySQL recreates them at the newer size on restart!!).

Here's the new my.cnf with changes highlighted:

Rich (BB code):
[client]
port             = 3306
socket           = /var/run/mysqld/mysqld.sock

[safe_mysqld]
err-log          = /var/log/mysql/mysql.err

[mysqld]
user             = mysql
pid-file         = /var/run/mysqld/mysqld.pid
socket           = /var/run/mysqld/mysqld.sock
port             = 3306
max_connections  = 300
basedir          = /usr
datadir          = /var/lib/mysql
tmpdir           = /tmp
language         = /usr/share/mysql/english
log-slow-queries = /var/log/mysql-slow.log

skip-locking

key_buffer              = 512M
myisam_sort_buffer_size = 16M
max_allowed_packet      = 16M
table_cache             = 3000
join_buffer_size        = 2M
sort_buffer_size        = 2M
read_buffer_size        = 2M
read_rnd_buffer_size    = 2M
thread_cache_size       = 64
query_cache_limit       = 16M
query_cache_size        = 64M
query_cache_type        = 1
tmp_table_size          = 128M
max_heap_table_size     = 128M
long_query_time         = 2

wait_timeout = 360
interactive_timeout = 360
connect_timeout = 10
net_read_timeout = 30
net_write_timeout = 60
concurrent_insert = 2

innodb_log_buffer_size = 8M
innodb_log_file_size = 32M
innodb_flush_log_at_trx_commit = 2
innodb_flush_method = O_DIRECT
innodb_thread_concurrency = 8
innodb_additional_mem_pool_size = 8M
innodb_buffer_pool_size = 2200M
innodb_fast_shutdown = 0


ft_min_word_len = 3


[mysqldump]
quick
max_allowed_packet = 16M

[mysql]

[isamchk]
key_buffer = 64M
sort_buffer = 64M
read_buffer = 16M
write_buffer = 16M
ft_min_word_len = 3

[myisamchk]
key_buffer = 64M
sort_buffer = 64M
read_buffer = 16M
write_buffer = 16M
ft_min_word_len = 3

Server load seems to be around 40% less and speed of page loading faster, so I'm quite pleased with it now. :D

And I haven't had too many complaints from members about the change and quite a good positive responses, so so far, so good! (y)

As to the initial surge of server load, I'm still at a loss, but I do wonder if it was simply the flood of members piling back on to the server combined with the lower innodb settings and lots of account updates as they first logged in that simply bottlenecked MySQL and lead to the massive load.

It's been running fine all day today and is a pleasure to use once again. ;)

Cheers,
Shaun :D

PS. Yes, if a mod could add [SOLVED] to the title that would be good.
 
Just out of interest, here's a snippet of the server load averages for the period when it went a bit Pete Tong (wrong):

Code:
17:00:01 up 23:26,  0 users,  load average: 0.01, 0.05, 0.08
17:02:04 up 23:28,  0 users,  load average: 1.14, 0.30, 0.16
17:04:01 up 23:30,  0 users,  load average: 15.76, 6.26, 2.36
17:06:01 up 23:32,  0 users,  load average: 3.18, 4.79, 2.31
17:08:01 up 23:34,  0 users,  load average: 31.93, 14.11, 5.95
17:16:37 up 23:42,  0 users,  load average: 110.05, 93.29, 51.63
17:18:44 up 23:44,  0 users,  load average: 97.74, 93.51, 56.91
17:20:01 up 23:46,  0 users,  load average: 60.81, 84.20, 56.76
17:24:55 up 23:51,  1 user,  load average: 51.54, 61.50, 54.07
17:26:02 up 23:52,  1 user,  load average: 33.47, 54.23, 52.09
17:26:02 up 23:52,  1 user,  load average: 33.47, 54.23, 52.09
17:26:02 up 23:52,  1 user,  load average: 33.47, 54.23, 52.09
17:26:03 up 23:52,  1 user,  load average: 33.47, 54.23, 52.09
17:26:03 up 23:52,  1 user,  load average: 33.47, 54.23, 52.09
17:28:01 up 23:54,  1 user,  load average: 4.93, 36.50, 45.85
17:30:01 up 23:56,  1 user,  load average: 5.47, 26.22, 40.98
17:32:01 up 23:58,  1 user,  load average: 12.49, 22.94, 38.05
17:34:01 up 1 day, 0 min,  1 user,  load average: 18.23, 21.71, 35.76
17:36:14 up 1 day, 2 min,  1 user,  load average: 9.76, 15.66, 31.53
17:38:51 up 1 day, 5 min,  1 user,  load average: 61.10, 29.52, 33.99
17:44:33 up 1 day, 10 min,  1 user,  load average: 183.77, 137.67, 80.03
17:44:33 up 1 day, 10 min,  1 user,  load average: 183.77, 137.67, 80.03
17:46:47 up 1 day, 12 min,  1 user,  load average: 176.12, 143.47, 89.21
17:48:04 up 1 day, 14 min,  1 user,  load average: 219.89, 166.59, 101.89
17:48:50 up 1 day, 15 min,  1 user,  load average: 152.91, 155.55, 101.18
17:50:11 up 1 day, 16 min,  1 user,  load average: 171.43, 160.15, 107.24
17:52:05 up 1 day, 18 min,  1 user,  load average: 141.21, 150.40, 109.78
17:54:01 up 1 day, 20 min,  1 user,  load average: 179.10, 164.04, 119.73
17:56:38 up 1 day, 22 min,  1 user,  load average: 142.67, 166.39, 128.46
17:58:29 up 1 day, 24 min,  1 user,  load average: 117.67, 146.18, 125.14
18:01:41 up 1 day, 27 min,  1 user,  load average: 174.13, 157.19, 132.98
18:08:54 up 1 day, 35 min,  1 user,  load average: 179.01, 184.95, 155.84
18:09:16 up 1 day, 35 min,  1 user,  load average: 163.93, 181.18, 155.23
18:10:22 up 1 day, 36 min,  0 users,  load average: 185.23, 184.68, 158.22
18:12:20 up 1 day, 38 min,  0 users,  load average: 182.95, 174.53, 157.09
18:14:01 up 1 day, 40 min,  0 users,  load average: 171.14, 172.46, 158.12
18:15:45 up 1 day, 41 min,  1 user,  load average: 193.59, 172.82, 159.30
18:19:13 up 1 day, 45 min,  1 user,  load average: 118.61, 145.89, 151.84
18:22:10 up 1 day, 48 min,  1 user,  load average: 184.69, 172.25, 161.54
18:23:03 up 1 day, 49 min,  1 user,  load average: 171.96, 170.43, 161.46
18:23:08 up 1 day, 49 min,  1 user,  load average: 168.36, 169.70, 161.27
18:23:18 up 1 day, 49 min,  1 user,  load average: 173.41, 170.75, 161.70
18:28:29 up 1 day, 54 min,  1 user,  load average: 175.33, 163.91, 161.06
18:28:39 up 1 day, 54 min,  1 user,  load average: 166.57, 162.28, 160.55
18:28:39 up 1 day, 54 min,  1 user,  load average: 166.57, 162.28, 160.55
18:30:28 up 1 day, 56 min,  1 user,  load average: 108.30, 145.62, 154.86
18:35:13 up 1 day,  1:01,  1 user,  load average: 91.44, 107.04, 135.69
18:35:13 up 1 day,  1:01,  1 user,  load average: 91.44, 107.04, 135.69
18:39:00 up 1 day,  1:05,  1 user,  load average: 269.45, 189.69, 161.55
18:41:13 up 1 day,  1:07,  1 user,  load average: 217.65, 191.34, 165.57
18:43:07 up 1 day,  1:09,  1 user,  load average: 242.14, 204.13, 172.81
18:48:07 up 1 day,  1:14,  1 user,  load average: 115.05, 157.87, 161.96
18:49:18 up 1 day,  1:15,  1 user,  load average: 113.03, 148.39, 158.36
18:52:52 up 1 day,  1:19,  1 user,  load average: 149.77, 147.15, 155.73
18:53:58 up 1 day,  1:20,  1 user,  load average: 126.70, 139.41, 152.34
18:56:35 up 1 day,  1:22,  0 users,  load average: 100.64, 121.80, 143.69
18:57:03 up 1 day,  1:23,  0 users,  load average: 104.50, 121.12, 142.88
19:01:34 up 1 day,  1:27,  0 users,  load average: 99.66, 113.07, 134.16
19:01:34 up 1 day,  1:27,  0 users,  load average: 99.66, 113.07, 134.16
19:01:54 up 1 day,  1:28,  0 users,  load average: 85.97, 109.12, 132.41
19:02:14 up 1 day,  1:28,  1 user,  load average: 126.87, 116.46, 133.78
19:12:33 up 1 day,  1:38,  1 user,  load average: 127.72, 117.69, 124.07
19:15:26 up 1 day,  1:41,  1 user,  load average: 118.14, 121.55, 124.84
19:18:29 up 1 day,  1:44,  1 user,  load average: 96.31, 115.64, 122.37
19:21:33 up 1 day,  1:47,  1 user,  load average: 118.58, 117.70, 122.07
19:21:33 up 1 day,  1:47,  1 user,  load average: 118.58, 117.70, 122.07
19:25:08 up 1 day,  1:51,  1 user,  load average: 76.47, 98.89, 113.86
19:46:01 up 3 min,  1 user,  load average: 7.54, 3.09, 1.16
19:48:01 up 5 min,  1 user,  load average: 17.23, 7.88, 3.12
19:53:02 up 10 min,  1 user,  load average: 24.29, 21.68, 10.87
19:57:44 up 15 min,  1 user,  load average: 35.32, 28.40, 16.63
20:00:24 up 18 min,  1 user,  load average: 45.80, 35.38, 21.10
20:03:58 up 21 min,  1 user,  load average: 56.15, 41.10, 26.02
20:05:25 up 23 min,  1 user,  load average: 42.05, 39.22, 26.61
20:07:37 up 25 min,  1 user,  load average: 88.25, 60.34, 36.27
20:10:40 up 28 min,  1 user,  load average: 219.43, 122.81, 63.72
20:18:10 up 35 min,  1 user,  load average: 34.22, 89.10, 74.29
20:18:13 up 35 min,  1 user,  load average: 32.76, 87.89, 73.97
20:18:13 up 35 min,  1 user,  load average: 32.76, 87.89, 73.97
20:18:13 up 35 min,  1 user,  load average: 32.76, 87.89, 73.97
20:18:15 up 36 min,  1 user,  load average: 32.76, 87.89, 73.97
20:18:16 up 36 min,  1 user,  load average: 31.10, 86.63, 73.64
20:18:20 up 36 min,  1 user,  load average: 31.10, 86.63, 73.64
20:18:21 up 36 min,  1 user,  load average: 29.25, 85.33, 73.29
20:20:01 up 37 min,  1 user,  load average: 5.68, 61.12, 65.83
20:22:01 up 39 min,  1 user,  load average: 0.86, 40.92, 57.85
20:24:01 up 41 min,  1 user,  load average: 0.52, 27.63, 50.93
20:26:01 up 43 min,  1 user,  load average: 0.45, 18.61, 44.80
20:28:01 up 45 min,  1 user,  load average: 0.53, 12.61, 39.42
 
Top Bottom