Quick Edit and iowait

Discussion in 'General' started by anewday, Apr 19, 2008.

  1. anewday

    anewday Moderator

    On my forums, occassionally when a user clicks on the Complete button using the quick edit function..it causes the iowait of the server to spike as much as 40%. As a result, it takes more than 5 seconds for it to be processed, should be a second only. This happens during not so busy times, load under 1 with barely any iowait. The weird thing is I almost never see this type of behavior with Apache. :confused:
    Last edited: Apr 19, 2008
  2. mistwang

    mistwang LiteSpeed Staff

    I/O wait is most likely cuased by heavy random access to HD, I don't know if there is really any corelation with quick edit. If yes, you need to check the HTTP request used for quick edit and find out why.
  3. anewday

    anewday Moderator

    How can I find the http request for quick edit?
  4. anewday

    anewday Moderator

    Ok, I met this 3 times today and I was able to see consistencies in the error_log file.

    Code:
    2008-04-19 15:37:48.666	INFO	[AdminPHP] pid list size: 1
    2008-04-19 15:37:48.666	INFO	[AdminPHP] add child process pid: 23637
    The above 2 lines appeared each time. the pid is of course different.
  5. anewday

    anewday Moderator

    George, do you think it has anything to do with the Request/Response settings? I am using the default values.
  6. anewday

    anewday Moderator

    It happened again, this time I did a top and sorted it by user:

    Code:
    Tasks: 158 total,   1 running, 157 sleeping,   0 stopped,   0 zombie
    Cpu(s): 15.4% us,  3.5% sy,  0.5% ni, 30.5% id, 49.9% wa,  0.3% hi,  0.0% si
    Mem:   3114144k total,  3095836k used,    18308k free,    12976k buffers
    Swap:  2096440k total,    17304k used,  2079136k free,  2359324k cached
    
      PID USER      PR  NI %CPU    TIME+  %MEM  VIRT  RES  SHR S COMMAND                                                                
    28656 nobody    17   0    2   0:00.05  0.3 78572 7840 3956 S lsphp4                                                                 
    24031 nobody    15   0    0   3:33.35  0.3 11948 9180 3616 S lshttpd                                                                
     3339 nobody    26  10    0   0:47.98  0.0  5800 1396  844 S proftpd: (accepting connections)                                       
    24030 nobody    15   0    0   0:00.30  0.1  5380 2440 1112 S lshttpd                                                                
    24039 nobody    15   0    0   0:00.04  0.1 75440 2740 1988 S lsphp4                                                                 
    24552 nobody    16   0    0   2:20.38  0.7 79996  20m  15m S lsphp4                                                                 
    25544 nobody    16   0    0   2:23.60  0.6 79016  19m  14m S lsphp4                                                                 
    26915 nobody    16   0    0   1:16.68  0.6 79808  17m  12m S lsphp4                                                                 
    27096 nobody    16   0    0   0:33.31  0.6 79548  17m  12m S lsphp4                                                                 
    28522 nobody    20   0    0   0:02.71  0.4 79520  11m 6936 S lsphp4                                                                 
    28533 nobody    15   0    0   0:01.02  0.3 78932 9576 5276 S lsphp4                                                                 
    28539 nobody    20   0    0   0:01.97  0.4 79844  11m 6576 S lsphp4                                                                 
    28540 nobody    17   0    0   0:00.02  0.2 77680 6460 3460 S lsphp4                                                                 
    28541 nobody    17   0    0   0:00.07  0.3 78636 8480 4572 S lsphp4                                                                 
    28546 nobody    17   0    0   0:00.06  0.3 78504 8064 4272 S lsphp4                                                                 
    28548 nobody    15   0    0   0:00.34  0.3 79832 9380 4504 S lsphp4                                                                 
    28558 nobody    20   0    0   0:00.50  0.3 79548 9524 4856 S lsphp4                                                                 
    28559 nobody    20   0    0   0:00.45  0.3 79276 9196 4772 S lsphp4                                                                 
    28565 nobody    20   0    0   0:00.46  0.3 79488 9320 4708 S lsphp4                                                                 
    28566 nobody    20   0    0   0:00.66  0.4 79504  10m 6516 S lsphp4                                                                 
    28567 nobody    17   0    0   0:00.07  0.3 78504 7956 4192 S lsphp4                                                                 
    28573 nobody    15   0    0   0:00.36  0.3 79832 9380 4504 S lsphp4                                                                 
    28574 nobody    19   0    0   0:00.30  0.3 78960 8888 4696 S lsphp4                                                                 
    28575 nobody    19   0    0   0:01.14  0.3 79832  10m 5904 S lsphp4                                                                 
    28587 nobody    16   0    0   0:00.37  0.3 78664  10m 6384 S lsphp4                                                                 
    28592 nobody    16   0    0   0:00.31  0.3 79004 9460 5152 S lsphp4                                                                 
    28594 nobody    16   0    0   0:01.83  0.4 79080  10m 6784 S lsphp4                                                                 
    28595 nobody    16   0    0   0:00.52  0.3 78552 8460 4540 S lsphp4                                                                 
    28601 nobody    19   0    0   0:01.38  0.3 79900  10m 5752 S lsphp4                                                                 
    28602 nobody    16   0    0   0:00.99  0.3 78400 9352 5584 S lsphp4                                                                 
    28605 nobody    17   0    0   0:00.02  0.2 77680 6460 3460 S lsphp4                                                                 
    28607 nobody    17   0    0   0:00.23  0.3 78884 9912 5788 S lsphp4                                                                 
    28613 nobody    20   0    0   0:00.44  0.3 79284 9108 4700 S lsphp4                                                                 
    28614 nobody    17   0    0   0:00.10  0.3 78444 7952 4216 S lsphp4                                                                 
    28620 nobody    19   0    0   0:00.35  0.3 79832 9380 4504 S lsphp4                                                                 
    28626 nobody    19   0    0   0:00.32  0.3 79732 9428 4608 S lsphp4                                                                 
    28627 nobody    17   0    0   0:00.25  0.3 78864 8880 4768 S lsphp4                                                                 
    28633 nobody    19   0    0   0:01.71  0.3 79736  10m 5676 S lsphp4                                                                 
    28639 nobody    16   0    0   0:00.82  0.3 78616 8356 4376 S lsphp4                                                                 
    28645 nobody    18   0    0   0:00.06  0.3 78500 7888 4144 S lsphp4                                                                 
    28646 nobody    18   0    0   0:00.07  0.3 78504 7956 4192 S lsphp4
    
    Last edited: Apr 20, 2008
  7. anewday

    anewday Moderator

    Won't let me paste that much in the message.

    After about 5 minutes, this is the output when iowait returned to normal.
    Code:
    top - 14:28:51 up 245 days, 17:35,  1 user,  load average: 1.41, 1.88, 1.22
    Tasks: 160 total,   3 running, 157 sleeping,   0 stopped,   0 zombie
    Cpu(s): 25.2% us,  5.5% sy, 10.6% ni, 58.2% id,  0.5% wa,  0.0% hi,  0.0% si
    Mem:   3114144k total,  3095708k used,    18436k free,    13744k buffers
    Swap:  2096440k total,    17232k used,  2079208k free,  2354344k cached
    
      PID USER      PR  NI %CPU    TIME+  %MEM  VIRT  RES  SHR S COMMAND                                                                
    28758 nobody    16   0   30   0:17.87  0.4 79760  13m 8428 S lsphp4                                                                 
    24552 nobody    16   0   28   2:33.19  0.7 79932  20m  15m R lsphp4                                                                 
    24031 nobody    15   0    0   3:34.38  0.3 11372 8628 3064 S lshttpd                                                                
     3339 nobody    26  10    0   0:47.98  0.0  5800 1396  844 S proftpd: (accepting connections)                                       
    24030 nobody    15   0    0   0:00.31  0.1  5380 2440 1112 S lshttpd                                                                
    24039 nobody    16   0    0   0:00.04  0.1 75440 2740 1988 S lsphp4                                                                 
    25544 nobody    16   0    0   2:23.60  0.6 79016  19m  14m S lsphp4                                                                 
    28522 nobody    16   0    0   0:02.71  0.4 78964  11m 6936 S lsphp4                                                                 
    28533 nobody    16   0    0   0:01.03  0.3 78820 9576 5388 S lsphp4                                                                 
    28540 nobody    16   0    0   0:00.02  0.2 77680 6532 3532 S lsphp4                                                                 
    28546 nobody    16   0    0   0:00.06  0.3 78504 8352 4552 S lsphp4                                                                 
    28559 nobody    16   0    0   0:00.46  0.3 78508 8672 4796 S lsphp4                                                                 
    28566 nobody    16   0    0   0:00.66  0.3 78808  10m 6516 S lsphp4                                                                 
    28567 nobody    16   0    0   0:00.09  0.3 78700 8496 4428 S lsphp4                                                                 
    28574 nobody    16   0    0   0:00.30  0.3 78652 8736 4720 S lsphp4                                                                 
    28587 nobody    16   0    0   0:00.39  0.3 78728  10m 6452 S lsphp4                                                                 
    28601 nobody    16   0    0   0:01.38  0.3 78760 9876 5752 S lsphp4                                                                 
    28602 nobody    16   0    0   0:01.02  0.3 78820 9900 5712 S lsphp4                                                                 
    28605 nobody    16   0    0   0:00.02  0.2 77680 6532 3532 S lsphp4                                                                 
    28607 nobody    16   0    0   0:00.24  0.3 78360 9520 5788 S lsphp4                                                                 
    28613 nobody    16   0    0   0:00.44  0.3 78388 8456 4700 S lsphp4                                                                 
    28614 nobody    16   0    0   0:00.13  0.3 78848 8628 4408 S lsphp4                                                                 
    28620 nobody    16   0    0   0:00.36  0.3 78692 8588 4532 S lsphp4                                                                 
    28626 nobody    16   0    0   0:00.32  0.3 78668 8668 4636 S lsphp4                                                                 
    28627 nobody    16   0    0   0:00.25  0.3 78588 8724 4768 S lsphp4                                                                 
    28633 nobody    16   0    0   0:01.71  0.3 78696 9740 5676 S lsphp4                                                                 
    28645 nobody    16   0    0   0:00.09  0.3 78800 8716 4548 S lsphp4                                                                 
    28646 nobody    16   0    0   0:00.08  0.3 78704 8500 4428 S lsphp4                                                                 
    28662 nobody    16   0    0   0:00.02  0.2 77680 6532 3532 S lsphp4                                                                 
    28670 nobody    16   0    0   0:00.58  0.3 78828 9068 4872 S lsphp4                                                                 
    28671 nobody    16   0    0   0:00.11  0.3 78848 8628 4408 S lsphp4                                                                 
    28700 nobody    16   0    0   0:00.89  0.3 78400 8676 4912 S lsphp4                                                                 
    28701 nobody    16   0    0   0:00.43  0.3 78376 8624 4880 S lsphp4                                                                 
    28702 nobody    16   0    0   0:00.20  0.3 79084 9128 4736 S lsphp4                                                                 
    28708 nobody    16   0    0   0:03.17  0.3 78664 9832 5800 S lsphp4                                                                 
    28719 nobody    16   0    0   0:00.56  0.3 78568 8812 4876 S lsphp4                                                                 
    28730 nobody    16   0    0   0:00.11  0.3 78852 8628 4404 S lsphp4                                                                 
    28731 nobody    16   0    0   0:00.52  0.3 79092 9384 4956 S lsphp4                                                                 
    28744 nobody    16   0    0   0:00.20  0.3 79084 9132 4736 S lsphp4                                                                 
    28757 nobody    16   0    0   0:00.56  0.3 78732 8920 4824 S lsphp4                                                                 
    28760 nobody    16   0    0   0:00.20  0.3 79032 9064 4728 S lsphp4                                                                 
    28761 nobody    16   0    0   0:01.26  0.3 78468 9200 5364 S lsphp4                                                                 
    28763 nobody    16   0    0   0:00.14  0.2  7776 5744 1596 S admin_php -c ../conf/php.ini                                           
    28770 nobody    16   0    0   0:00.76  0.4 79000  10m 6572 S lsphp4                                                                 
    28776 nobody    16   0    0   0:01.44  0.3 78504  10m 6756 S lsphp4
    
    Usually, there are only 4-5 lsphp4 processes. :eek: :confused: I believe something is wrong with lsphp, why does it open so many connections for a simple task? lsphp is killing the disk I/O :( I hope this provides some clues to the problem.
    Last edited: Apr 20, 2008
  8. anewday

    anewday Moderator

    When I merged 5 consecutive posts (All are less than 30 letters). It got stuck again. This never happens with Apache. :mad:

    Code:
    2008-04-20 14:50:45.162	INFO	[24.x.x.x:33055-0#APVH_forum.......com] Connection idle time: 31 while in state: 5 watching for event: 25,close!
    2008-04-20 14:50:45.163	NOTICE	[24.x.x.x:33055-0#APVH_forum.......com] Content len: 219, Request line:
    POST /index.php?act=mod&CODE=postchoice&tact=merge&checked=1 HTTP/1.1
    2008-04-20 14:50:45.302	INFO	[24.x.x.x:33055-0#APVH_forum......com] HttpExtConnector state: 8, request body sent: 219, response body size: 0, response body sent:0, left in buffer: 0, attempts: 0.
    Last edited: Apr 20, 2008
  9. mistwang

    mistwang LiteSpeed Staff

    I think your MySQL is the bottle neck which causes high I/O wait, and stall all PHP processes, which causes LSWS to start more PHP processes.

    Maybe merging posts will cause MySQL to block and takes long time to process?
    Please post your lsphp configuration for reviewing.
  10. anewday

    anewday Moderator

    my.cnf

    Code:
    [mysqld]
    max_connections=500
    max_user_connections=300
    skip-locking
    skip-innodb
    query_cache_limit=2M
    query_cache_size=128M
    query_cache_type=1
    interactive_timeout=60
    wait_timeout=60
    connect_timeout=6
    thread_cache_size=128
    key_buffer_size=640M
    max_allowed_packet=16M
    table_cache=2048
    join_buffer=1M
    sort_buffer=2M
    record_buffer=1M
    sort_buffer_size=2M
    read_buffer_size=2M
    safe-show-database
    max_connect_errors=10
    thread_concurrency=2
    myisam_sort_buffer_size=64M
    datadir=/var/lib/mysql
    socket=/var/lib/mysql/mysql.sock
    #log_slow_queries=/var/log/mysql/mysql_slow-queries.log
    long_query_time=3
    tmp_table_size=32M
    max_heap_table_size=32M
    #log-queries-not-using-indexes=/var/log/mysql/mysql_queries_no-indexes.log
    join_buffer_size=2M
    low_priority_updates=1
    read_rnd_buffer_size=2M
    
    [mysql.server]
    user=mysql
    basedir=/var/lib
    
    [safe_mysqld]
    err-log=/var/log/mysqld.log
    var/lib/mysql/mysql.pid
    open_files_limit=8192
    
    [mysqldump]
    quick
    max_allowed_packet=16M
    
    [mysql]
    no-auto-rehash
    
    [isamchk]
    key_buffer=32M
    sort_buffer=32M
    read_buffer=16M
    write_buffer=16M
    
    [myisamchk]
    key_buffer=32M
    sort_buffer=32M
    read_buffer=16M
    write_buffer=16M
    
    [mysqlhotcopy]
    interactive-timeout
    eaccelearator settings in php.ini
    Code:
    extension_dir = "/usr/local/lsws/lsphp4/lib/php/extensions/no-debug-non-zts-20020429"
    extension="eaccelerator.so"
    eaccelerator.shm_size="64"
    eaccelerator.cache_dir="/tmp/lswseaccelerator"
    eaccelerator.enable="1"
    eaccelerator.optimizer="1"
    eaccelerator.check_mtime="0"
    eaccelerator.debug="0"
    eaccelerator.filter=""
    eaccelerator.shm_max="0"
    eaccelerator.shm_ttl="86400"
    eaccelerator.shm_prune_period="7200"
    eaccelerator.shm_only="0"
    eaccelerator.compress="1"
    eaccelerator.compress_level="9"
    eaccelerator.keys="shm"
    eaccelerator.sessions="shm"
    eaccelerator.content="shm" 
    
    lsphp config (you set these last time with the exception of max process time)

    [​IMG]

    I have switched back to Apache now to see how things will go. The weird thing is this issue doesn't happen before I used litespeed. Anything else I can provide to help? Thanks George.
    Last edited: Apr 21, 2008
  11. anewday

    anewday Moderator

    A member said it happens with regular Add Reply as well. My site serves large multimedia files. But then still cannot explain why it causes iowait to jump to 40% when the server is 95% idle at 3 in the morning....
    Last edited: Apr 21, 2008
  12. anewday

    anewday Moderator

    I checked the load graphs and noticed that it spiked up to 15 at around 8AM EST.

    http://img368.imageshack.us/img368/1807/loaddayyt0.png

    Traffic during that time was only 2.5Mbit/s and the number of processes jumped from an average of 120 to over 160. I bet those are lsphp4 processes when many members are writing to the forums. I really believe there is a bug with litespeed. :(
  13. mistwang

    mistwang LiteSpeed Staff

    Maybe there was some I/O intensive tasks like backup DB or some other files. Please check your graph history see if it happen every day around the same time.
    LSWS itself alone will not cause high I/O wait.

    More lsphp4 processes is the result of high I/O wait, not the cause. You need to find out which process causes high I/O wait, pay special attention to your MySQL and backup scripts.
  14. anewday

    anewday Moderator

    There are no I/O intensive tasks running at that time, cpanel backup and database backup scripts runs at 1AM daily. As I said earlier, with Apache, I never had an issue like this.

    I'll send the http headers to you by PM.
  15. mistwang

    mistwang LiteSpeed Staff

    Are your server experiencing similar high load during the backup time, there are two spikes in your graph at night time.

    You need to check your server when the I/O wait is high, pay attention to "SWAP" memory being used, if for some reason the server start to use swap, you need to find out which process causes it.

    And you can reduce "Max conn" for lsphp to avoid starting too many lsphp processes. when your server is short of memory, running more lsphp will only make it worse.

    Another suggestion is to run Apache for a day or two and compare the load graph with that of LSWS.
  16. anewday

    anewday Moderator

    Load during backups is 2-3 only, doesn't really slow down browsing. The other spike during night time is when server copies the database to NAS, only takes a few minutes to complete.

    According to the memory graphs, it has over 2GB of cached memory all the time.

    [​IMG]
  17. mistwang

    mistwang LiteSpeed Staff

    If your DB file is larger than 2GB, it will pretty much invalidate the whole 2GB cache memory, 2GB cache memory can guarantee that server do not have a disk I/O problem.

    You need to find out what causes the high I/O wait. And if you think Apache does not have this problem, give it a try and see what you get. We are interested in the result as well.
  18. anewday

    anewday Moderator

    The database is around 900Mb only. I will switch back to Apache later to test. It performed fine during the 3 busiest months of last year. This year isn't nearly as active.
    Last edited: Apr 21, 2008
  19. anewday

    anewday Moderator

    I just discovered the nFLT field in top and its value is 463. Isn't it rather high?

    Code:
    PID USER      PR  NI %CPU    TIME+  %MEM  VIRT  RES  SHR nFLT S COMMAND
    1999 nobody    15   0    0   0:46.20  0.2  8552 5700 1428  463 S lshttpd
  20. mistwang

    mistwang LiteSpeed Staff

Share This Page