Low CPU, low RAM, low IO, but bad performance, why?

Question

I have an issue with regards to the performance of my Linux Centos Apache server. I have a program (written in c) that does many http requests simultaneously. This process on itself seems very efficiently as if I can do 500 requests to an external server simultaneously without any noticeable time difference compared to only 1 request.

However, I have many scripts on the same server which I run simultaneously using that same program. The number of scripts to run vary, but it is around 100 for a single search.

The task of each script is to call an API (on an external server) parse the data needed an insert that into the database.

I measured the start time of each script and I noticed there is a large delay in the start of each script. There is up to 10 seconds difference between the start of the first script and the start of the last script. This large time delay makes the search on my website slow.

I used top command in my linux centos machine, see below 2 samples of 2 different instances during the search.

TOP COMMAND SAMPLE 1:

top - 18:51:18 up 36 days,  3:35,  1 user,  load average: 0.02, 0.07, 0.08
Tasks: 182 total,   2 running, 180 sleeping,   0 stopped,   0 zombie
Cpu(s):  3.7%us,  1.3%sy,  0.0%ni, 94.9%id,  0.0%wa,  0.0%hi,  0.1%si,  0.0%st
Mem:   4194304k total,  3941184k used,   253120k free,    26820k buffers
Swap:  4194296k total,       76k used,  4194220k free,  2069456k cached



 PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
  691 apache    15   0  190m  18m 5052 S  4.0  0.5   0:00.19 httpd
  959 apache    17   0  189m  15m 3196 R  3.0  0.4   0:00.09 httpd
  702 apache    15   0  185m 101m 5036 S  1.7  2.5   0:00.86 httpd
  732 apache    15   0  184m  12m 5036 S  1.7  0.3   0:00.15 httpd
  689 apache    15   0  184m  14m 5144 S  0.7  0.3   0:00.87 httpd
  734 apache    15   0  184m 100m 4740 S  0.7  2.4   0:00.21 httpd
  670 apache    15   0  205m  99m 4992 S  0.3  2.4   0:00.39 httpd
  678 apache    15   0  184m  13m 5032 S  0.3  0.3   0:01.05 httpd
  795 root      15   0 12764 1356  956 R  0.3  0.0   0:00.03 top
  949 apache    15   0  181m 9616 2928 S  0.3  0.2   0:00.01 httpd
  951 apache    20   0  180m 8748 2640 S  0.3  0.2   0:00.01 httpd
    1 root      15   0 10372  792  664 S  0.0  0.0   0:00.20 init
    2 root      RT  -5     0    0    0 S  0.0  0.0   0:00.14 migration/0
    3 root      34  19     0    0    0 S  0.0  0.0   0:00.04 ksoftirqd/0
    4 root      RT  -5     0    0    0 S  0.0  0.0   0:00.00 watchdog/0
    5 root      10  -5     0    0    0 S  0.0  0.0   0:00.04 events/0
    6 root      10  -5     0    0    0 S  0.0  0.0   0:00.00 khelper
    7 root      10  -5     0    0    0 S  0.0  0.0   0:00.00 kthread
    9 root      10  -5     0    0    0 S  0.0  0.0   0:00.00 xenwatch
   10 root      10  -5     0    0    0 S  0.0  0.0   0:00.00 xenbus
   37 root      10  -5     0    0    0 S  0.0  0.0   0:00.03 kblockd/0
   42 root      20  -5     0    0    0 S  0.0  0.0   0:00.00 cqueue/0
   50 root      20  -5     0    0    0 S  0.0  0.0   0:00.00 khubd
   52 root      10  -5     0    0    0 S  0.0  0.0   0:00.00 kseriod
  137 root      15   0     0    0    0 S  0.0  0.0   0:00.00 khungtas

TOP COMMAND SAMPLE 2:

top - 18:52:49 up 36 days,  3:36,  1 user,  load average: 0.53, 0.21, 0.12
Tasks: 240 total,   8 running, 231 sleeping,   0 stopped,   1 zombie
Cpu(s): 50.4%us,  4.8%sy,  0.0%ni, 43.5%id,  0.5%wa,  0.0%hi,  0.5%si,  0.2%st
Mem:   4194304k total,  4097104k used,    97200k free,    27148k buffers
Swap:  4194296k total,       76k used,  4194220k free,  1965428k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
  949 apache    16   0  185m 101m 5328 S 32.1  2.5   0:01.19 httpd
 1229 apache    16   0  184m  12m 4580 S 32.1  0.3   0:00.98 httpd
  968 apache    17   0  188m  17m 4732 S 30.4  0.4   0:01.92 httpd
 1244 apache    17   0  184m  12m 4580 S 27.8  0.3   0:00.86 httpd
  994 apache    16   0  190m  19m 5060 S 27.5  0.5   0:01.69 httpd
 1222 apache    16   0  218m  44m 4676 R 26.5  1.1   0:00.82 httpd
 1657 mysql     15   0  627m 223m 5664 S 23.5  5.5  65:16.63 mysqld
 1256 apache    16   0  184m  12m 4580 S 21.2  0.3   0:00.81 httpd
 1245 apache    16   0  210m  37m 4084 R 14.6  0.9   0:00.47 httpd
 1005 apache    16   0  213m  42m 5308 R 13.6  1.0   0:00.67 httpd
 1246 apache    17   0  184m  12m 4580 S 11.3  0.3   0:00.74 httpd
 1214 apache    16   0  182m  10m 4060 S  3.3  0.3   0:00.23 httpd
 1253 apache    16   0  184m  12m 4580 S  2.3  0.3   0:00.67 httpd
 1233 apache    15   0  196m  22m 3696 R  2.0  0.6   0:00.17 httpd
 1215 apache    15   0  183m  11m 4060 S  1.7  0.3   0:00.18 httpd
 1265 apache    15   0  182m  11m 3444 S  1.7  0.3   0:00.05 httpd
 1230 apache    16   0  180m 9644 3436 S  1.3  0.2   0:00.04 httpd
 1210 apache    15   0  192m  19m 3620 S  1.0  0.5   0:00.14 httpd
 1011 apache    15   0  193m  22m 5356 R  0.7  0.5   0:00.86 httpd
 1016 apache    15   0  192m  19m 4092 S  0.7  0.5   0:00.20 httpd
 1019 apache    15   0  192m  21m 4972 S  0.7  0.5   0:01.27 httpd
 1051 root      15   0 12896 1424  956 R  0.7  0.0   0:00.10 top
 1221 apache    15   0  180m 9820 3436 S  0.7  0.2   0:00.03 httpd
  989 apache    15   0  193m  21m 5332 R  0.3  0.5   0:01.06 httpd
 1000 apache    15   0  208m 102m 5424 S  0.3  2.5   0:00.97 httpd
 1032 apache    15   0  190m  18m 4748 S  0.3  0.4   0:00.39 httpd
 1213 apache    15   0     0    0    0 Z  0.3  0.0   0:00.15 httpd <defunct>
 1251 apache    15   0  184m  11m 3700 S  0.3  0.3   0:00.02 httpd
    1 root      15   0 10372  792  664 S  0.0  0.0   0:00.20 init
    2 root      RT  -5     0    0    0 S  0.0  0.0   0:00.14 migration/0
    3 root      34  19     0    0    0 S  0.0  0.0   0:00.04 ksoftirqd/0
    4 root      RT  -5     0    0    0 S  0.0  0.0   0:00.00 watchdog/0
    5 root      10  -5     0    0    0 S  0.0  0.0   0:00.04 events/0

I also had a look at the disk IO, there are a lot of processes, but all together there isn't much IO:

Total DISK READ: 0.00 B/s | Total DISK WRITE: 0.00 B/s
  TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN     IO>    COMMAND
 2804 be/3 root        0.00 B/s    0.00 B/s  0.00 %  1.13 % [ib_cm/1]
32387 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.75 % httpd -k start -DSSL
32344 be/4 apache      0.00 B/s    3.77 K/s  0.00 %  0.75 % httpd -k start -DSSL
32465 be/4 apache      0.00 B/s    0.00 B/s -0.75 %  0.75 % httpd -k start -DSSL
32487 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.75 % httpd -k start -DSSL
32377 be/4 apache      0.00 B/s    3.77 K/s  0.00 %  0.38 % httpd -k start -DSSL
32462 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.38 % httpd -k start -DSSL
32469 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.38 % httpd -k start -DSSL
32445 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.38 % httpd -k start -DSSL
32349 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32436 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % python /usr/bin/iotop
32385 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32382 be/4 apache      0.00 B/s    3.77 K/s  0.38 %  0.00 % httpd -k start -DSSL
32446 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32381 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32375 be/4 apache      0.00 B/s    0.00 B/s  0.75 %  0.00 % httpd -k start -DSSL
32312 be/4 apache      0.00 B/s    3.77 K/s  0.00 %  0.00 % httpd -k start -DSSL
32342 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
 1407 be/4 dbus        0.00 B/s    0.00 B/s  0.00 %  0.00 % dbus-daemon --system
32455 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32466 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32470 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32488 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
25045 be/4 dovecot     0.00 B/s    0.00 B/s  0.00 %  0.00 % dovecot/pop3-login
    4 rt/3 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [watchdog/0]
32514 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32581 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32531 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32471 be/4 apache      0.00 B/s    0.00 B/s  0.38 %  0.00 % httpd -k start -DSSL
32546 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32519 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32521 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32315 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32523 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32524 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32335 be/4 apache      0.00 B/s    3.77 K/s  0.00 %  0.00 % httpd -k start -DSSL
32583 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32566 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32526 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32481 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32557 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32529 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32530 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32541 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32507 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32570 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL
32504 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  0.00 % httpd -k start -DSSL

I also tested with different settings of my httpd.conf:

TEST HTTPD.CONF 1:

<IfModule mpm_prefork_module>
    StartServers 2
    MinSpareServers 2
    MaxSpareServers 5
    ServerLimit 200
    MaxClients 200
    MaxRequestsPerChild 100
</IfModule>

TEST HTTPD.CONF 2:

<IfModule mpm_prefork_module>
    StartServers 2
    MinSpareServers 2
    MaxSpareServers 5
    ServerLimit 2
    MaxClients 2
    MaxRequestsPerChild 1
</IfModule>

The above doesn't seem to have any impact on the performance.

I also checked if the mpm module is installed (and this seems to be the case), see below. However I really don't understand how the above settings don't have any impact on the performance of my server.

-bash-3.2# httpd -M
[Wed Mar 11 18:59:42 2015] [warn] module php5_module is already loaded, skipping
Loaded Modules:
 core_module (static)
 authn_file_module (static)
 authn_default_module (static)
 authz_host_module (static)
 authz_groupfile_module (static)
 authz_user_module (static)
 authz_default_module (static)
 auth_basic_module (static)
 reqtimeout_module (static)
 include_module (static)
 filter_module (static)
 deflate_module (static)
 log_config_module (static)
 logio_module (static)
 env_module (static)
 expires_module (static)
 headers_module (static)
 unique_id_module (static)
 setenvif_module (static)
 version_module (static)
 proxy_module (static)
 proxy_connect_module (static)
 proxy_ftp_module (static)
 proxy_http_module (static)
 proxy_scgi_module (static)
 proxy_ajp_module (static)
 proxy_balancer_module (static)
 ssl_module (static)
 mpm_prefork_module (static)
 http_module (static)
 mime_module (static)
 dav_module (static)
 status_module (static)
 autoindex_module (static)
 asis_module (static)
 suexec_module (static)
 cgi_module (static)
 dav_fs_module (static)
 dav_lock_module (static)
 negotiation_module (static)
 dir_module (static)
 actions_module (static)
 userdir_module (static)
 alias_module (static)
 rewrite_module (static)
 so_module (static)
 php5_module (shared)
Syntax OK

I am really lost in my search to what could be the bottleneck for this performance. Important to not is that when I put exit in the top of all 100 scripts there is no time delay, but when the scripts do all the curl requests and data parsing there is a large time delay.

All help is very welcome!

You run 100 scripts, each of which does a separate connection to an api on an external server? What kind of QPS do you get from that external api (without connection reuse)? — that other guy, Mar 11 '15 at 20:34
They are all different api response time varies from 0.2 to 25 seconfs — BastiaanWW, Mar 12 '15 at 00:19

score 1 · Answer 1 · answered Mar 12 '15 at 06:18

If there are about 100 external requests per operation, that will make your script slow. No matter what level of efficiency you introduce to your server/script those 100 request have to share the network bandwidth. Also there are more complex things that go on the network level which make it slower than ideal theoretical value.

If you are having a repeated requests for the same url, you might be able to cache the response for a short span of time depending on the rate of change of data in the source.

Say for example out of 100 requests you do for an operation if you are able to get even about 30-40% of the response from the cache that will speed up your script considerably.

I am already caching repeated requests, but most of the time requests are unique. Do you mean that the bottleneck is the bandwidth? — BastiaanWW, Mar 12 '15 at 09:24
Not just bandwidth, but overall with that number of calls things get slowed down. Specially when you have a lot of concurrent requests. — Abhilash S Hebbar, Mar 13 '15 at 10:27

Low CPU, low RAM, low IO, but bad performance, why?

1 Answers1