very slow SSD with fsync

* very slow SSD with fsync
@ 2015-03-13 14:48 Adrian Bridgett
  2015-03-13 15:25 ` Theodore Ts'o
  0 siblings, 1 reply; 4+ messages in thread
From: Adrian Bridgett @ 2015-03-13 14:48 UTC (permalink / raw)
  To: linux-ext4

Slow as in sync(1) taking 6 seconds on an idle system, dd-ing from the 
raw disk drops from 600MB/s to less than 1MB/s.   iotop shows jbd2 often 
waiting a long time, but _very_ low throughput (KB/s it that).  I've 
spent a day or so trying everything I can find to identify the cause but 
I'm completely stuck (even with help from a btrfs guru - he eventually 
suggested asking here).

Chrome and dropbox seem to trigger this, I'm just installing a pretty 
new Macbook Pro (didn't get along with OSX, returning to Linux).  The 
system was fine, but now seems to be reaaaaalllly slow.  Maybe it's as 
I've put stuff on, but I think that it's degradation caused by something 
else.

The only thing that makes a difference is mounting with barrier=0 but 
I'd rather not do that of course.  I'm not trying to maximise 
performance here, just eliminate some nasty buglet/incompatibility.

I've tried:
- fstrim
- noncq (just in case)
- disabling power management (tlp daemon, then turning off tweakables in 
powertop)
- latest 3.19.1 ubuntu kernel and also 3.16
- adding discard to mount options, also taking it away again and just fstrim
- disabling SMART (saw one report on a normal hard disk after 30mins - 
note that mine is slow immediately) 
http://unix.stackexchange.com/questions/165464/calls-to-sync-fsync-slow-down-after-30-minutes-uptime
- using the tracing framework (thanks to Ted for a comment elsewhere) I 
traced the slowness to these syncs being very slow (my much older laptop 
takes 0.05s...)

Disk is EcryptFS on LVM (mounted data=ordered) - Ubuntu defaults. I 
tried moving dropbox to non-encryptFS and no joy.  My friend suggested 
that I use LUKS instead but it seems that I'll still have this issue.

I've been using dd|pv for some tests, hdparm shows similar results (this 
set taken with thunderbird, but no chrome, no dropbox running) - and the 
cursor locks up every few seconds whilst I'm typing this!)

[13:50]~# hdparm -I /dev/sda

/dev/sda:

ATA device, with non-removable media
     Model Number:       APPLE SSD SM0512F
     Serial Number:      S1K5NYBF266383
     Firmware Revision:  UXM2JA1Q
     Transport:          Serial, ATA8-AST, SATA 1.0a, SATA II 
Extensions, SATA Rev 2.5, SATA Rev 2.6, SATA Rev 3.0
Standards:
     Used: unknown (minor revision code 0x0039)
     Supported: 8 7 6 5
     Likely used: 8
Configuration:
     Logical        max    current
     cylinders    16383    16383
     heads        16    16
     sectors/track    63    63
     --
     CHS current addressable sectors:   16514064
     LBA    user addressable sectors:  268435455
     LBA48  user addressable sectors:  977105060
     Logical  Sector size:                   512 bytes
     Physical Sector size:                  4096 bytes
     Logical Sector-0 offset:                  0 bytes
     device size with M = 1024*1024:      477102 MBytes
     device size with M = 1000*1000:      500277 MBytes (500 GB)
     cache/buffer size  = unknown
     Nominal Media Rotation Rate: Solid State Device
Capabilities:
     LBA, IORDY(can be disabled)
     Queue depth: 32
     Standby timer values: spec'd by Standard, no device specific minimum
     R/W multiple sector transfer: Max = 16    Current = 16
     Recommended acoustic management value: 128, current value: 0
     DMA: mdma0 mdma1 mdma2 udma0 udma1 udma2 udma3 udma4 udma5 *udma6
          Cycle time: min=120ns recommended=120ns
     PIO: pio0 pio1 pio2 pio3 pio4
          Cycle time: no flow control=120ns  IORDY flow control=120ns
Commands/features:
     Enabled    Supported:
        *    SMART feature set
             Security Mode feature set
        *    Power Management feature set
        *    Write cache
        *    Look-ahead
        *    Host Protected Area feature set
        *    WRITE_BUFFER command
        *    READ_BUFFER command
        *    NOP cmd
        *    DOWNLOAD_MICROCODE
        *    SET_MAX security extension
             Automatic Acoustic Management feature set
        *    48-bit Address feature set
        *    Device Configuration Overlay feature set
        *    Mandatory FLUSH_CACHE
        *    FLUSH_CACHE_EXT
        *    SMART error logging
        *    SMART self-test
        *    General Purpose Logging feature set
        *    WRITE_{DMA|MULTIPLE}_FUA_EXT
        *    64-bit World wide name
        *    {READ,WRITE}_DMA_EXT_GPL commands
        *    Segmented DOWNLOAD_MICROCODE
        *    Gen1 signaling speed (1.5Gb/s)
        *    Gen2 signaling speed (3.0Gb/s)
        *    Gen3 signaling speed (6.0Gb/s)
        *    Native Command Queueing (NCQ)
        *    Phy event counters
             DMA Setup Auto-Activate optimization
        *    Software settings preservation
        *    SET MAX SETPASSWORD/UNLOCK DMA commands
        *    WRITE BUFFER DMA command
        *    READ BUFFER DMA command
        *    Data Set Management TRIM supported (limit 8 blocks)
Security:
     Master password revision code = 65534
         supported
     not    enabled
     not    locked
         frozen
     not    expired: security count
         supported: enhanced erase
     6min for SECURITY ERASE UNIT. 32min for ENHANCED SECURITY ERASE UNIT.
Logical Unit WWN Device Identifier: 5002538655584d30
     NAA        : 5
     IEEE OUI    : 002538
     Unique ID    : 655584d30
Integrity word not set (found 0x00bf, expected 0x100a5)

iotop -o -b:
Total DISK READ :       0.00 B/s | Total DISK WRITE :       0.00 B/s
Actual DISK READ:       0.00 B/s | Actual DISK WRITE:       0.00 B/s
   TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN      IO COMMAND
   184 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.05 % [kworker/u16:3]
Total DISK READ :       0.00 B/s | Total DISK WRITE :       0.00 B/s
Actual DISK READ:       0.00 B/s | Actual DISK WRITE:      11.81 K/s
   TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN      IO COMMAND
   275 be/3 root        0.00 B/s    0.00 B/s  0.00 % 99.99 % [jbd2/dm-0-8]
  4308 be/4 abridget    0.00 B/s    0.00 B/s  0.00 % 99.99 % thunderbird
Total DISK READ :       0.00 B/s | Total DISK WRITE :       0.00 B/s
Actual DISK READ:       0.00 B/s | Actual DISK WRITE:       0.00 B/s
   TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN      IO COMMAND
   184 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.07 % [kworker/u16:3]
Total DISK READ :       0.00 B/s | Total DISK WRITE :      31.33 K/s
Actual DISK READ:       0.00 B/s | Actual DISK WRITE:       0.00 B/s
   TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN      IO COMMAND
   184 be/4 root        0.00 B/s   31.33 K/s  0.00 %  0.00 % [kworker/u16:3]
Total DISK READ :       0.00 B/s | Total DISK WRITE :       7.70 K/s
Actual DISK READ:       0.00 B/s | Actual DISK WRITE:       0.00 B/s
   TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN      IO COMMAND
   275 be/3 root        0.00 B/s    0.00 B/s  0.00 % 99.99 % [jbd2/dm-0-8]
   184 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.04 % [kworker/u16:3]
  3148 be/4 abridget    0.00 B/s    7.70 K/s  0.00 %  0.00 % upstart --user
Total DISK READ :       0.00 B/s | Total DISK WRITE :      15.74 K/s
Actual DISK READ:       0.00 B/s | Actual DISK WRITE:      70.81 K/s
   TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN      IO COMMAND
  4308 be/4 abridget    0.00 B/s   15.74 K/s  0.00 %  0.08 % thunderbird
   275 be/3 root        0.00 B/s    0.00 B/s  0.00 %  0.01 % [jbd2/dm-0-8]
Total DISK READ :       0.00 B/s | Total DISK WRITE :       0.00 B/s
Actual DISK READ:       0.00 B/s | Actual DISK WRITE:       0.00 B/s
   TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN      IO COMMAND
   184 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.07 % [kworker/u16:3]
Total DISK READ :       0.00 B/s | Total DISK WRITE :      42.50 K/s
Actual DISK READ:       0.00 B/s | Actual DISK WRITE:      42.50 K/s
   TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN      IO COMMAND
   275 be/3 root        0.00 B/s   27.04 K/s  0.00 % 99.99 % [jbd2/dm-0-8]
  4308 be/4 abridget    0.00 B/s   15.45 K/s  0.00 %  0.07 % thunderbird
Total DISK READ :       0.00 B/s | Total DISK WRITE :       0.00 B/s
Actual DISK READ:       0.00 B/s | Actual DISK WRITE:       0.00 B/s
   TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN      IO COMMAND
   184 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.06 % [kworker/u16:3]
Total DISK READ :       0.00 B/s | Total DISK WRITE :      30.87 K/s
Actual DISK READ:       0.00 B/s | Actual DISK WRITE:     212.24 K/s
   TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN      IO COMMAND
   275 be/3 root        0.00 B/s   19.29 K/s  0.00 % 99.99 % [jbd2/dm-0-8]
  4308 be/4 abridget    0.00 B/s   11.58 K/s  0.00 %  0.00 % thunderbird
Total DISK READ :       0.00 B/s | Total DISK WRITE :       0.00 B/s
Actual DISK READ:       0.00 B/s | Actual DISK WRITE:      23.49 K/s
   TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN      IO COMMAND
  4308 be/4 abridget    0.00 B/s    0.00 B/s  0.00 % 25.66 % thunderbird
   184 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.05 % [kworker/u16:3]
   275 be/3 root        0.00 B/s    0.00 B/s  0.00 %  0.02 % [jbd2/dm-0-8]

And now (more programs):
[14:30]~$ sudo mount -o remount,barrier=0 /
[14:33]~$ sudo hdparm -tT /dev/sda
/dev/sda:
  Timing cached reads:   6548 MB in  2.00 seconds = 3275.19 MB/sec
  Timing buffered disk reads: 2352 MB in  3.00 seconds = 783.92 MB/sec

[14:34]~$ sudo mount -o remount,barrier=1 /
[14:34]~$ sudo hdparm -tT /dev/sda
/dev/sda:
  Timing cached reads:     2 MB in  2.88 seconds = 710.50 kB/sec
  Timing buffered disk reads:  20 MB in  5.07 seconds =   3.94 MB/sec

[14:34]~$ sudo mount -o remount,barrier=0 /
[14:35]~$ sudo hdparm -tT /dev/sda
/dev/sda:
  Timing cached reads:   17316 MB in  2.00 seconds = 8666.69 MB/sec
  Timing buffered disk reads: 2368 MB in  3.00 seconds = 789.12 MB/sec

^ permalink raw reply	[flat|nested] 4+ messages in thread