I know quite well that I/O wait has been discussed multiple times on this site, but all the other topics seem to cover constant I/O latency, while the I/O problem we need to solve on our server occurs at irregular (short) intervals, but is ever-present with massive spikes of up to 20k ms a-wait and service times of 2 seconds. The disk affected is /dev/sdb (Seagate Barracuda, for details see below).

A typical iostat -x output would at times look like this, which is an extreme sample but by no means rare:

iostat (Oct 6, 2013)
  tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
 0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
 0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
16.00      0.00    156.00      9.75     21.89    288.12     36.00     57.60
 5.50      0.00     44.00      8.00     48.79   2194.18    181.82    100.00
 2.00      0.00     16.00      8.00     46.49   3397.00    500.00    100.00
 4.50      0.00     40.00      8.89     43.73   5581.78    222.22    100.00
14.50      0.00    148.00     10.21     13.76   5909.24     68.97    100.00
 1.50      0.00     12.00      8.00      8.57   7150.67    666.67    100.00
 0.50      0.00      4.00      8.00      6.31  10168.00   2000.00    100.00
 2.00      0.00     16.00      8.00      5.27  11001.00    500.00    100.00
 0.50      0.00      4.00      8.00      2.96  17080.00   2000.00    100.00
34.00      0.00   1324.00      9.88      1.32    137.84      4.45     59.60
 0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
22.00     44.00    204.00     11.27      0.01      0.27      0.27      0.60

Let me provide you with some more information regarding the hardware. It's a Dell 1950 III box with Debian as OS where uname -a reports the following:

Linux xx 2.6.32-5-amd64 #1 SMP Fri Feb 15 15:39:52 UTC 2013 x86_64 GNU/Linux

The machine is a dedicated server that hosts an online game without any databases or I/O heavy applications running. The core application consumes about 0.8 of the 8 GBytes RAM, and the average CPU load is relatively low. The game itself, however, reacts rather sensitive towards I/O latency and thus our players experience massive ingame lag, which we would like to address as soon as possible.

iostat:
avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           1.77    0.01    1.05    1.59    0.00   95.58

Device:            tps   Blk_read/s   Blk_wrtn/s   Blk_read   Blk_wrtn
sdb              13.16        25.42       135.12  504701011 2682640656
sda               1.52         0.74        20.63   14644533  409684488

Uptime is:

19:26:26 up 229 days, 17:26,  4 users,  load average: 0.36, 0.37, 0.32

Harddisk controller:

01:00.0 RAID bus controller: LSI Logic / Symbios Logic MegaRAID SAS 1078 (rev 04)

Harddisks:

Array 1, RAID-1, 2x Seagate Cheetah 15K.5 73 GB SAS
Array 2, RAID-1, 2x Seagate ST3500620SS Barracuda ES.2 500GB 16MB 7200RPM SAS

Partition information from df:

Filesystem           1K-blocks      Used Available Use% Mounted on
/dev/sdb1            480191156  30715200 425083668   7% /home
/dev/sda2              7692908    437436   6864692   6% /
/dev/sda5             15377820   1398916  13197748  10% /usr
/dev/sda6             39159724  19158340  18012140  52% /var

Some more data samples generated with iostat -dx sdb 1 (Oct 11, 2013)

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await  svctm  %util
sdb               0.00    15.00    0.00   70.00     0.00   656.00     9.37     4.50    1.83   4.80  33.60
sdb               0.00     0.00    0.00    2.00     0.00    16.00     8.00    12.00  836.00 500.00 100.00
sdb               0.00     0.00    0.00    3.00     0.00    32.00    10.67     9.96 1990.67 333.33 100.00
sdb               0.00     0.00    0.00    4.00     0.00    40.00    10.00     6.96 3075.00 250.00 100.00
sdb               0.00     0.00    0.00    0.00     0.00     0.00     0.00     4.00    0.00   0.00 100.00
sdb               0.00     0.00    0.00    2.00     0.00    16.00     8.00     2.62 4648.00 500.00 100.00
sdb               0.00     0.00    0.00    0.00     0.00     0.00     0.00     2.00    0.00   0.00 100.00
sdb               0.00     0.00    0.00    1.00     0.00    16.00    16.00     1.69 7024.00 1000.00 100.00
sdb               0.00    74.00    0.00  124.00     0.00  1584.00    12.77     1.09   67.94   6.94  86.00

Characteristic charts generated with rrdtool can be found here:

iostat plot 1, 24 min interval: http://imageshack.us/photo/my-images/600/yqm3.png/

iostat plot 2, 120 min interval: http://imageshack.us/photo/my-images/407/griw.png/

As we have a rather large cache of 5.5 GBytes, we thought it might be a good idea to test if the I/O wait spikes would perhaps be caused by cache miss events. Therefore, we did a sync and then this to flush the cache and buffers:

echo 3 > /proc/sys/vm/drop_caches

and directly afterwards the I/O wait and service times virtually went through the roof, and everything on the machine felt like slow motion. During the next few hours the latency recovered and everything was as before - small to medium lags in short, unpredictable intervals.

Now my question is: does anybody have any idea what might cause this annoying behaviour? Is it the first indication of the disk array or the raid controller dying, or something that can be easily mended by rebooting? (At the moment we're very reluctant to do this, however, because we're afraid that the disks might not come back up again.)

Any help is greatly appreciated.

Thanks in advance, Chris.

Edited to add: we do see one or two processes go to 'D' state in top, one of which seems to be kjournald rather frequently. If I'm not mistaken, however, this does not indicate the processes causing the latency, but rather those affected by it - correct me if I'm wrong. Does the information about uninterruptibly sleeping processes help us in any way to address the problem?

@Andy Shinn requested smartctl data, here it is:

smartctl -a -d megaraid,2 /dev/sdb yields:

smartctl 5.40 2010-07-12 r3124 [x86_64-unknown-linux-gnu] (local build)
Copyright (C) 2002-10 by Bruce Allen, http://smartmontools.sourceforge.net

Device: SEAGATE  ST3500620SS      Version: MS05
Serial number:
Device type: disk
Transport protocol: SAS
Local Time is: Mon Oct 14 20:37:13 2013 CEST
Device supports SMART and is Enabled
Temperature Warning Disabled or Not Supported
SMART Health Status: OK

Current Drive Temperature:     20 C
Drive Trip Temperature:        68 C
Elements in grown defect list: 0
Vendor (Seagate) cache information
  Blocks sent to initiator = 1236631092
  Blocks received from initiator = 1097862364
  Blocks read from cache and sent to initiator = 1383620256
  Number of read and write commands whose size <= segment size = 531295338
  Number of read and write commands whose size > segment size = 51986460
Vendor (Seagate/Hitachi) factory information
  number of hours powered up = 36556.93
  number of minutes until next internal SMART test = 32

Error counter log:
           Errors Corrected by           Total   Correction     Gigabytes    Total
               ECC          rereads/    errors   algorithm      processed    uncorrected
           fast | delayed   rewrites  corrected  invocations   [10^9 bytes]  errors
read:   509271032       47         0  509271079   509271079      20981.423           0
write:         0        0         0         0          0       5022.039           0
verify: 1870931090      196         0  1870931286   1870931286     100558.708           0

Non-medium error count:        0

SMART Self-test log
Num  Test              Status                 segment  LifeTime  LBA_first_err [SK ASC ASQ]
     Description                              number   (hours)
# 1  Background short  Completed                  16   36538                 - [-   -    -]
# 2  Background short  Completed                  16   36514                 - [-   -    -]
# 3  Background short  Completed                  16   36490                 - [-   -    -]
# 4  Background short  Completed                  16   36466                 - [-   -    -]
# 5  Background short  Completed                  16   36442                 - [-   -    -]
# 6  Background long   Completed                  16   36420                 - [-   -    -]
# 7  Background short  Completed                  16   36394                 - [-   -    -]
# 8  Background short  Completed                  16   36370                 - [-   -    -]
# 9  Background long   Completed                  16   36364                 - [-   -    -]
#10  Background short  Completed                  16   36361                 - [-   -    -]
#11  Background long   Completed                  16       2                 - [-   -    -]
#12  Background short  Completed                  16       0                 - [-   -    -]

Long (extended) Self Test duration: 6798 seconds [113.3 minutes]

smartctl -a -d megaraid,3 /dev/sdb yields:

smartctl 5.40 2010-07-12 r3124 [x86_64-unknown-linux-gnu] (local build)
Copyright (C) 2002-10 by Bruce Allen, http://smartmontools.sourceforge.net

Device: SEAGATE  ST3500620SS      Version: MS05
Serial number:
Device type: disk
Transport protocol: SAS
Local Time is: Mon Oct 14 20:37:26 2013 CEST
Device supports SMART and is Enabled
Temperature Warning Disabled or Not Supported
SMART Health Status: OK

Current Drive Temperature:     19 C
Drive Trip Temperature:        68 C
Elements in grown defect list: 0
Vendor (Seagate) cache information
  Blocks sent to initiator = 288745640
  Blocks received from initiator = 1097848399
  Blocks read from cache and sent to initiator = 1304149705
  Number of read and write commands whose size <= segment size = 527414694
  Number of read and write commands whose size > segment size = 51986460
Vendor (Seagate/Hitachi) factory information
  number of hours powered up = 36596.83
  number of minutes until next internal SMART test = 28

Error counter log:
           Errors Corrected by           Total   Correction     Gigabytes    Total
               ECC          rereads/    errors   algorithm      processed    uncorrected
           fast | delayed   rewrites  corrected  invocations   [10^9 bytes]  errors
read:   610862490       44         0  610862534   610862534      20470.133           0
write:         0        0         0         0          0       5022.480           0
verify: 2861227413      203         0  2861227616   2861227616     100872.443           0

Non-medium error count:        1

SMART Self-test log
Num  Test              Status                 segment  LifeTime  LBA_first_err [SK ASC ASQ]
     Description                              number   (hours)
# 1  Background short  Completed                  16   36580                 - [-   -    -]
# 2  Background short  Completed                  16   36556                 - [-   -    -]
# 3  Background short  Completed                  16   36532                 - [-   -    -]
# 4  Background short  Completed                  16   36508                 - [-   -    -]
# 5  Background short  Completed                  16   36484                 - [-   -    -]
# 6  Background long   Completed                  16   36462                 - [-   -    -]
# 7  Background short  Completed                  16   36436                 - [-   -    -]
# 8  Background short  Completed                  16   36412                 - [-   -    -]
# 9  Background long   Completed                  16   36404                 - [-   -    -]
#10  Background short  Completed                  16   36401                 - [-   -    -]
#11  Background long   Completed                  16       2                 - [-   -    -]
#12  Background short  Completed                  16       0                 - [-   -    -]

Long (extended) Self Test duration: 6798 seconds [113.3 minutes]