6

After 30 minutes of uptime using Ubuntu 14.04 with an ext4 hybrid SSD I see many processes blocking IO using iotop.

The root cause of this slowdown has been traced back to the Unix system call sync.

Running sync from the terminal repeatedly can take on the order of 1 - 2 seconds but ONLY after 30 minutes uptime.

To prove this I made a script that outputs uptime in seconds against time taken to execute sync, and ran it every second :

while true;
do
cat /proc/uptime | awk '{printf "%f ",$1}'; /usr/bin/time -f '%e' sync;
sleep 1;
done;

I ran the above script, waited around an hour (system was left idle) and plotted the results in gnuplot (y = time in seconds to execute sync, x = uptime in seconds):

slowdown graph

The point in time where the graph shoots up is around 1780 (1780/60 = roughly 30 minutes).

Nothing should be writing to the disk at this time apart from the script, so there should be next to nothing in the page cache after the first sync each subsequent sync will be writing exactly what's being written to the script which will be roughly 100 bytes or so.

When I check cat /proc/meminfo the dirty row (data in the page cache that needs to be saved to disk?) and the writeback row (HD disk buffer?) are all at zero. My thought was that calling sync flushes these disk caches but it still freezes even when there's nothing in those caches so does it do something else?

This issue persists after reboots; for example - if I wait 30 minutes for the slowdown then reboot, the slowdown will still be there. If I powerdown then reboot the issue disappears until 30 minutes later.

Another curiosity is that when I examined the above graph and zoomed in on an area where the slowdown is occurring I got this:

slowdown graph zoomed

The peaks and troughs repeat - this occurs at intervals of 10 seconds from trough to trough.

I've also ran hdparm tests (hdparm -t /dev/sda and hdparm -T /dev/sda) before the slowdown :

/dev/sda:
Timing cached reads:   23778 MB in  2.00 seconds = 11900.64 MB/sec
/dev/sda:
Timing buffered disk reads: 318 MB in  3.01 seconds = 105.63 MB/sec

and during the slowdown:

/dev/sda:
 Timing cached reads:     2 MB in  2.24 seconds = 915.50 kB/sec
/dev/sda:
Timing buffered disk reads: 300 MB in  3.01 seconds =  99.54 MB/sec

Showing that actual disk reads aren't being effected but cached reads are, could that mean that this is to do with the system bus and not the HD after all?

Here's the solutions I've tried :

  • Change the spindown settings of the HD (maybe the HD was going into power savings mode?):

    hdparm /dev/sda -S252 #(set it to 5 hours before spindown)
    
  • Change the filesystem's journalling type to writeback rather than ordered so that we get performance improvements - this isn't solving the problem though as it doesn't explain the 30 minutes slowdown-free uptime when I tried this there was no change.

  • Disabled CRON as it seems to be occuring after a round 30 minutes.

  • CPU usage is fine and is completely idle so no processes can be blamed however I've tried shutting down every service including the session manager (lightdm) this does nothing as I believe the issue is lower level.

  • Analysing any new processes coming in at 30 minutes indicates no changes - I've diffed the output of PS before and after and there's no difference.

This only started occurring about 2 weeks ago, nothing was installed and no updates were done around that time. I'm thinking this issue is much lower level so would really appreciate some help here as I'm clueless, even pointing me in the right direction would be helpful.

Write caching is enabled on the disk in question, I've also tried disabling write barriers. SMART data on the HD indicates no problems with the HD itself however I have my suspicions it's the HD doing something mysterious as it persists after reboots.

  • 1
    +1 for presenting a good question. What does the free command show during those periods? Also, consider in-memory file caching. Linux like to use spare RAM for disk. FWIW, If you have huge amounts of cache, each invocation of sync has to look for dirty pages in there. Which if it is several GB, could take time. – jim mcnamara Nov 3 '14 at 13:24
  • Thanks for the guidance, free gives me 800mb cached memory without the issue and 1.6gb with the issue but the increase might be a coincidence as I may of opened more programs at the time. I'll try with an idle system. Thing about that is that you'd think the algorithm to calculate dirty pages wouldn't need any IO hence should be pretty quick to calculate as it's straight from RAM, I'm not too familiar with all this though so I may be wrong. – alex.p Nov 3 '14 at 13:49
  • You should make sure that there really is no IOs, you can use iostat to check for that and see if there are writes to the disk. – Baruch Even Nov 3 '14 at 14:00
  • Oh, there is IO, the script will of course be writing to disk throughout this but this will only be writing around 100 bytes per second - (just the text to formulate the above graph), what I meant with my previous comment is that I presume there wouldn't be any IO when it searches for dirty pages within RAM. – alex.p Nov 3 '14 at 15:03
  • I've edited the question slightly to make it clearer that the script is writing to disk but the amount of data should be insignificant. – alex.p Nov 3 '14 at 15:07
3

This was caused by SMART data being enabled for the drive in question.

Disabling SMART data solved this :

sudo smartctl --smart=off /dev/sda

Interestingly re-enabling SMART data for the drive does not make the issue return which suggests to me that SMART was in an inconsistent state (possible crash whilst the self-tests were running?) and switching it off and then on again reset that state.

Presumably it kept rerunning some kind of internal self-test 30 minutes after the disk spun up and got into a loop; as this was at the hardware layer the rest of the computer was unaware of it going on hence I could see no process in particular responsible for IO blocking and no processes hogging resources.

I'd run the SMART self tests whilst trying to work out what was wrong but even that didn't reset the state - it had to be switched off and then on explicitly.

  • 1
    This is definitely within the bounds of 'firmware problem', I'd suggest reporting it to the manufacturer. Hopefully they take it seriously! – MikeyB Nov 9 '14 at 1:38
2

This issue persists after reboots; for example - if I wait 30 minutes for the slowdown then reboot, the slowdown will still be there. If I powerdown then reboot the issue disappears until 30 minutes later.

This indicates that there is a firmware bug in the SSD itself that appears after 30 minutes of being powered.

  • I agree if the problem occurs like clockwork. Reboot is not clearing the memory in the SSD controller. – jim mcnamara Nov 4 '14 at 11:48
  • I thought the same, unfortunately there's no firmware updates from Seagate regarding this nor can I find anyone complaining about anything similar in reviews for this SSD or through Googling. I've made an update to the question regarding disk reads, it seems direct disk reads are unaffected; 100 mb/s constantly but cached reads from memory are at 12000 mb/s and then drop to 900 kb/s to 2000 mb/s with the slowdown. – alex.p Nov 4 '14 at 13:37
  • Does that now mean an SSD device swap is order? Seems like it. – jim mcnamara Nov 5 '14 at 2:55

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

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