Skip site navigation (1)Skip section navigation (2)
Date:      Sat, 26 Jan 2013 05:50:01 GMT
From:      Harry Coin <hgcoin@gmail.com>
To:        freebsd-fs@FreeBSD.org
Subject:   Re: kern/169480: [zfs] ZFS stalls on heavy I/O
Message-ID:  <201301260550.r0Q5o1YW079534@freefall.freebsd.org>

next in thread | raw e-mail | index | archive | help
The following reply was made to PR kern/169480; it has been noted by GNATS.

From: Harry Coin <hgcoin@gmail.com>
To: bug-followup@FreeBSD.org, levent.serinol@mynet.com, jdc@koitsu.org
Cc:  
Subject: Re: kern/169480: [zfs] ZFS stalls on heavy I/O
Date: Fri, 25 Jan 2013 23:49:23 -0600

 I appreciate your effort very much.
 
 One change from last time was I set failmode=continue from 'wait'.   
 There were no errors in zpool or other logs.
 
 re 1,2: switching to bs=64k and /dev/zero as the input source, the dd 
 completes and the ls -l during the process causes no problems.  Transfer 
 speed reported by dd of 183qMBytes/sec.
 
 re 3:  the gstat -I500ms shows each of the raid partitions hanging in at 
 about top speed of 50-ish MBps during the above dd.  All disks perform 
 within a couple % of one another.
 
 re 4: we'll stick with gstat.
 
 re 5: I see we agree about that.  Nothing happened during the scrub 
 other than the scrub.  14Mbps scrub speed is 1/6th of the minimum I'd 
 expect.
 
 re 6:  Tuning Is Evil.  On the other hand, Crashing is Eviler.  So I 
 tried Evil Tuning, with poor results as noted upstream.  So, perhaps 
 tuning is indeed not only evil but a black hole for time as well.
 
 Switching back to the 512 byte writes, I notice on gstat the writes are 
 zero for 4 secs or so, then a burst of activity (all partitions within a 
 few % of one another), all quiet, repeat.   Then I throw in the ls -l... 
 and... it all works with no problems.   Trying the dd with the big 
 blocksize and /dev/urandom.... and:  gstat looks bursty as in the 512 
 byte writes.   ls -l causes no changes, works.    Trying the original 
 /dev/urandom and bs=512 and ... the gstat pattern does the usual bursty 
 thing, ls -l works well.    Thinking it's about the gstat...
 
 Doing top -S -s 1 .. nothing.
 
 nas4free:~# vmstat -i
 interrupt                          total       rate
 irq1: atkbd0                         168          0
 irq18: uhci2                        1136          0
 irq20: hpet0                      620136        328
 irq21: uhci0 ehci0                  7764          4
 irq256: hdac0                         37          0
 irq257: ahci0                       1090          0
 irq258: em0                         5625          2
 irq259: ahci1                     849746        450
 Total                            1485702        787
 
 So weird.  It's not crashing.  So, I tried to move a video from one 
 dataset to another using mv.  Within moments all the writes gstat shows 
 have stopped, while there's a few K / s reads.  And there it sits.  
 Here's top
 
 last pid:  3932;  load averages:  0.02,  0.04,  
 0.13                                             up 0+00:24:46  05:03:53
 249 processes: 3 running, 229 sleeping, 17 waiting
 CPU:  0.0% user,  0.0% nice,  1.2% system,  0.0% interrupt, 98.8% idle
 Mem: 14M Active, 19M Inact, 953M Wired, 8256K Buf, 2246M Free
 Swap:
 
    PID USERNAME     PRI NICE   SIZE    RES STATE   C   TIME   WCPU COMMAND
     11 root         155 ki31     0K    32K CPU1    1  22:02 100.00% 
 idle{idle: cpu1}
     11 root         155 ki31     0K    32K RUN     0  22:06 98.49% 
 idle{idle: cpu0}
     13 root          -8    -     0K    48K -       1   0:06  0.10% 
 geom{g_up}
      5 root          -8    -     0K    80K zio->i  0   0:05  0.10% 
 zfskern{txg_thread_enter}
      0 root         -16    0     0K  2624K sched   1   2:30  0.00% 
 kernel{swapper}
      0 root         -16    0     0K  2624K -       0   0:30  0.00% 
 kernel{zio_read_intr_1}
      0 root         -16    0     0K  2624K -       0   0:30  0.00% 
 kernel{zio_read_intr_0}
      0 root         -16    0     0K  2624K -       1   0:10  0.00% 
 kernel{zio_write_issue_}
      0 root         -16    0     0K  2624K -       1   0:10  0.00% 
 kernel{zio_write_issue_}
     12 root         -88    -     0K   272K WAIT    1   0:08  0.00% 
 intr{irq259: ahci1}
      0 root         -16    0     0K  2624K -       1   0:07  0.00% 
 kernel{zio_write_intr_2}
      0 root         -16    0     0K  2624K -       1   0:07  0.00% 
 kernel{zio_write_intr_3}
      0 root         -16    0     0K  2624K -       1   0:07  0.00% 
 kernel{zio_write_intr_6}
      0 root         -16    0     0K  2624K -       1   0:07  0.00% 
 kernel{zio_write_intr_1}
      0 root         -16    0     0K  2624K -       0   0:07  0.00% 
 kernel{zio_write_intr_0}
      0 root         -16    0     0K  2624K -       0   0:07  0.00% 
 kernel{zio_write_intr_4}
      0 root         -16    0     0K  2624K -       1   0:07  0.00% 
 kernel{zio_write_intr_7}
      0 root         -16    0     0K  2624K -       1   0:07  0.00% 
 kernel{zio_write_intr_5}
     13 root          -8    -     0K    48K -       1   0:07  0.00% 
 geom{g_down}
   3919 root          20    0  9916K  1636K tx->tx  1   0:07  0.00% mv
     20 root          16    -     0K    16K syncer  0   0:03  0.00% syncer
     12 root         -60    -     0K   272K WAIT    0   0:01  0.00% 
 intr{swi4: clock}
     12 root         -52    -     0K   272K WAIT    1   0:01  0.00% 
 intr{swi6: Giant task}
     14 root         -16    -     0K    16K -       0   0:01  0.00% yarrow
      5 root          -8    -     0K    80K arc_re  0   0:01  0.00% 
 zfskern{arc_reclaim_thre}
     12 root         -84    -     0K   272K WAIT    1   0:01  0.00% 
 intr{irq1: atkbd0}
      0 root         -16    0     0K  2624K -       1   0:00  0.00% 
 kernel{zio_write_issue_}
      0 root          -8    0     0K  2624K -       0   0:00  0.00% 
 kernel{zil_clean}
      0 root         -16    0     0K  2624K -       1   0:00  0.00% 
 kernel{zio_write_issue_}
 
 
 Set failmode back to wait.  Rebooted from the livecd and now repeating 
 the tests:
 And they work properly.
 
 So,  with gstat running I once again try to move a video file from one 
 dataset to another.   I watch a bunch of reads happen, the a burst of 
 writes, and that goes on for a couple of minutes.  Then the writes stop 
 and the reads continue at 3Kbps according to gstat.  The total memory 
 still has 2.5G free.   There is no writing to the zpool.   I notice that 
 one of the video files has moved, and the writing stopped when it was 
 trying to open the next one I'm guessing.   I can sucessfully ^C out of 
 the mv, and notice a constant low speed read going on, 80-100KBps.   I 
 try restarting the move, no change to the read pattern, no writes.
 
 So, no memory explosion, ^C works, but I can't write, and gstat reports 
 a steady read low pace read for no obvious reason, just as it was when 
 the mv process was active.
 
 So, a huger puzzle.
 
 
 
 



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?201301260550.r0Q5o1YW079534>