Linux kernel: outgoing network packets stalled?

Question

ESX VM: 2 vCPUs. RedHat Ent 5.6. Apache 2.2.3/ python cgi and a J2EE app.

We have a monitor script pulling a page from this Apache, which calls a simple python cgi script, every minute, using curl, with max-time set to 30 seconds.

Everyday, at 9 am, the NetBackup software kick in, which increases a CPU and I/O load on the system for about 20 minutes or so.... quite often, the monitor would fail, saying it did not get anything in 30 seconds, maybe every other day or so....

I would like to figure out exactly what the problem is...

Apache logs the request was handled fine. The cgi python that was called also logged that everything went fine and quick.

CPU during the backup shows 40% I/O wait, 40% user some 10% idle.

Disk read ops do peak at that time, but disk read time does not go up by much at all.

I run strace on the httpd processes, during the backup time, and got lucky capturing a trace of one such failed monitor probe. The odd thing is, the trace shows the request was completed in about 1.3 seconds... but the client never received the response data in the 30 seconds it waited for it.

I did not take a tcpdump during this straced probe, but did previously and did notice indeed, that the system simply takes 10, 20 and more, seconds, to send the data packets, while apache would have logged that it was done with the response.

strace looks like this:

28259 09:25:01.617226 accept(6, {sa_family=AF_INET, sin_port=htons(34106), sin_addr=inet_addr("192.168.151.84")}, [17179869200]) = 24 <0.000045>
...

18130 09:25:01.670991 execve("/var/path/to/script.py",
...
28259 09:25:01.661924 clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x2b8bf4a3c3d0) = 18130 <0.003602>
...
18130 09:25:02.965223 write(1, "content-type: text/html\n\n1001                              Missing Required Parameter \r\n", 88) = 88 <0.000084>
28259 09:25:02.965408 <... epoll_wait resumed> {{EPOLLIN, {u32=261317976, u64=47880556733784}}}, 2, 300000) = 1 <1.297266>
18130 09:25:02.966161 exit_group(0)     = ?
28259 09:25:02.966299 read(29, "content-type: text/html\n\n1001                              Missing Required Parameter \r\n", 8000) = 88 <0.002616>
28259 09:25:02.969791 epoll_wait(27,

My question is how do I debug this further? Where was the response stuck? Could more vCPUs be what this system needs to deal with the increase in I/O ops? is it I/O ops issue?

Also, How could apache log a request finished with 200 status code, when the client never received the data and ended up actively closing the TCP connection? This might not be the case actually. might be that Apache did not log the request at all.

Answer 1

You may wish to have a look at the ring buffers on your network cards. Since you are doing a network backup that it likely having an impact. Here is an article in the RH Knowledge base: What is the first thing to try when I see my network interfaces dropping packets.

To summarize the document: Many times dropped packets are due to a network buffer being full, often times the receiving buffer. Check the interface in question using ifconfig to see if packets are being dropped. If they are consider increasing the size of the ring buffers using ethtool.

In addition since you are running your system as a guest VM, change your IO Scheduler to "noop". This is the best scheduler to use when you are running a virtualized guest. The noop scheduler does not bother to attempt to prioritize it's IO operations, which also reduces CPU overhead. Normally this can cause some congestion, however in this situation the IO scheduling will be better handed off to the hypervisor, thus allowing it to more appropriately schedule IO operations for all guests.