Take the 2-minute tour ×
Server Fault is a question and answer site for professional system and network administrators. It's 100% free, no registration required.

Im having a problem with a stalling Linux system and I have found sysstat/sar to report huge peaks in disk I/O utilization, average service time as well as average wait time at the time of the system stall.

How could I go about to determine which process is causing these peaks the next time it happen?
Is it possible to do with sar (ie: can I find this info from the alreade recorded sar files?

Output for "sar -d", system stall happened around 12.58-13.01pm.

12:40:01          DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
12:40:01       dev8-0     11.57      0.11    710.08     61.36      0.01      0.97      0.37      0.43
12:45:01       dev8-0     13.36      0.00    972.93     72.82      0.01      1.00      0.32      0.43
12:50:01       dev8-0     13.55      0.03    616.56     45.49      0.01      0.70      0.35      0.47
12:55:01       dev8-0     13.99      0.08    917.00     65.55      0.01      0.86      0.37      0.52
13:01:02       dev8-0      6.28      0.00    400.53     63.81      0.89    141.87    141.12     88.59
13:05:01       dev8-0     22.75      0.03    932.13     40.97      0.01      0.65      0.27      0.62
13:10:01       dev8-0     13.11      0.00    634.55     48.42      0.01      0.71      0.38      0.50

This is a follow-up question to a thread I started yesterday: Sudden peaks in load and disk block wait, I hope its ok that I created a new topic/question on the matter since I have not been able to resolve the problem yet.

share|improve this question
    
It sounds like the problem may be less a particular process and more a sporadically unresponsive disk. Disks do these sorts of things which at the system level appear to be cliffs that a system hit. If you find no culprits, then it is time to investigate the disk sub-system. –  slashdot Jan 11 '13 at 23:52
add comment

4 Answers

up vote 9 down vote accepted

If you are lucky to catch the next peak, you can study per-process I/O stats interactively, using iotop.

share|improve this answer
    
Hey, thanks! Yet another geek toy to store in my toolbox. :-) –  Janne Pikkarainen Aug 12 '10 at 11:41
    
Running iotop in batch mode could be a very good complement/replacement for the "ps -eo" solution above. Thanks! –  Avada Kedavra Aug 12 '10 at 11:43
    
Awesome, "iotop -n 1 -b -o" provides exactly the output i need. Thanks! –  Avada Kedavra Aug 12 '10 at 11:59
add comment

Use btrace. It's easy to use, for example btrace /dev/sda. If the command is not available, it is probably available in package blktrace.

EDIT: Since the debugfs is not enabled in the kernel, you might try date >>/tmp/wtf && ps -eo "cmd,pid,min_flt,maj_flt" >>/tmp/wtf or similar. Logging page faults is not of course at all the same than using btrace, but if you are lucky, it MAY give you some hint about the most disk hungry processes. I just tried that one on of my most I/O intensive servers and list included the processes I know are consuming lots of I/O.

share|improve this answer
    
Hello Janne, the kernel is unfortunately not compiled with debug file system, and its a live system so I am unable to recompile the kernel. Is there any other way to do this without recompiling? –  Avada Kedavra Aug 12 '10 at 8:13
    
OK, I edited my reply a bit :) –  Janne Pikkarainen Aug 12 '10 at 8:27
    
Great, now we're getting somewhere! Im thinking about putting this into a cronjob and execute it concurrently with the sar cron job. Then, next time the server stalls I should be able to compare the rate of the page faults to see which process/processes has an increased rate of page faults. I guess I could be unlucky and see a raise in disk io for all processes during the stall, but its definately worth a good try. Thanks Janne! (i would vote up on your answere if i could :S) –  Avada Kedavra Aug 12 '10 at 9:02
    
You're welcome. Let me know how it went, this was just a creative problem solving attempt from me. :-) –  Janne Pikkarainen Aug 12 '10 at 9:55
    
The iotop output is easier to under interpret, so ill accept that solution. Ill be back to vote up on your answere as soon as I have earned rep enough to do so. Thanks for your support! –  Avada Kedavra Aug 12 '10 at 12:00
show 1 more comment

Nothing beats ongoing monitoring, you simply cannot get time-sensitive data back after the event...

There are a couple of things you might be able to check to implicate or eliminate however -- /proc is your friend.

sort -n -k 10 /proc/diskstats
sort -n -k 11 /proc/diskstats

Fields 10, 11 are accumulated written sectors, and accumulated time (ms) writing. This will show your hot file-system partitions.

cut -d" " -f 1,2,42 /proc/*/stat | sort -n -k +3

Those fields are PID, command and cumulative IO-wait ticks. This will show your hot processes, though only if they are still running. (You probably want to ignore your filesystem journalling threads.)

The usefulness of the above depends on uptime, the nature of your long running processes, and how your file systems are used.

Caveats: does apply to pre 2.6 kernels, check your documentation if unsure.

(Now go and do your future-self a favour, install Munin/Nagios/Cacti/whatever ;-)

share|improve this answer
add comment

You can use pidstat to print cumulative io statistics per process every 20 seconds with this command:

# pidstat -dl 20

Each row will have follwing columns:

  • PID - process ID
  • kB_rd/s - Number of kilobytes the task has caused to be read from disk per second.
  • kB_wr/s - Number of kilobytes the task has caused, or shall cause to be written to disk per second.
  • kB_ccwr/s - Number of kilobytes whose writing to disk has been cancelled by the task. This may occur when the task truncates some dirty pagecache. In this case, some IO which another task has been accounted for will not be happening.
  • Command - The command name of the task.

Output looks like this:

05:57:12 PM       PID   kB_rd/s   kB_wr/s kB_ccwr/s  Command
05:57:32 PM       202      0.00      2.40      0.00  jbd2/sda1-8
05:57:32 PM      3000      0.00      0.20      0.00  kdeinit4: plasma-desktop [kdeinit]              

05:57:32 PM       PID   kB_rd/s   kB_wr/s kB_ccwr/s  Command
05:57:52 PM       202      0.00      0.80      0.00  jbd2/sda1-8
05:57:52 PM       411      0.00      1.20      0.00  jbd2/sda3-8
05:57:52 PM      2791      0.00     37.80      1.00  kdeinit4: kdeinit4 Running...                   
05:57:52 PM      5156      0.00      0.80      0.00  /usr/lib64/chromium/chromium --password-store=kwallet --enable-threaded-compositing 
05:57:52 PM      8651     98.20      0.00      0.00  bash 

05:57:52 PM       PID   kB_rd/s   kB_wr/s kB_ccwr/s  Command
05:58:12 PM       202      0.00      0.20      0.00  jbd2/sda1-8
05:58:12 PM      3000      0.00      0.80      0.00  kdeinit4: plasma-desktop [kdeinit]              
share|improve this answer
add comment

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Not the answer you're looking for? Browse other questions tagged or ask your own question.