| To: | Dave Chinner <david@xxxxxxxxxxxxx> |
|---|---|
| Subject: | Re: xfs and swift |
| From: | Mark Seger <mjseger@xxxxxxxxx> |
| Date: | Mon, 25 Jan 2016 11:38:07 -0500 |
| Cc: | Laurence Oberman <loberman@xxxxxxxxxx>, Linux fs XFS <xfs@xxxxxxxxxxx> |
| Delivered-to: | xfs@xxxxxxxxxxx |
| Dkim-signature: | v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:in-reply-to:references:date:message-id:subject:from:to :cc:content-type; bh=QzxDNPJBnylT4cCi9l+HdXqaLLrFHbZzI6pswIiCMvw=; b=i4t2v5w/eCc8JxzMJZLwAwbiHvG7+tDiOg993NwifGVG8gzb2xbE5b/vuRAc5fzAGb 8QWitaqzs097IdhdRkSoGPa23guaBokDzUjZcVpWb0FflO5yRtICKiUZNB0BaC5pYOAH jjpCEV/EVmyRn+prSjCeU/Hk1adxqrl18dokiUfKnlC5lqw7cd0rPHVjxCobue/U0WhQ NcrfPW6cq6sj+ftnzLzXE+QZcBgGpA/8fbnSzifx0tTns8RBz4P878dnMupTfSQBMqDx MxnPmAsfjZlaTVdl5VZI9XPjwhfCaf8getobQnt18FGmPYZLI6wY+Q5YuZd84l58zskn Z0xg== |
| In-reply-to: | <20160106234904.GL21461@dastard> |
| References: | <CAC2B=ZGX2bkEhdgCrpS2X5v+SpAg0jtxZ19vk_9+O9aHME-FSA@xxxxxxxxxxxxxx> <20160106220454.GI21461@dastard> <20160106221004.GJ21461@dastard> <CAC2B=ZHe+crzN4vTjuNRRFgaxFHDDX2=Jn16EcwY1-ukt1=M6g@xxxxxxxxxxxxxx> <20160106234904.GL21461@dastard> |
|
since getting your last reply I've been doing a lot more trying to understand the behavior of what I'm seeing by writing some non-swift code that sort of does what swift does with respect to a directory structure. Âin my case I have 1024 top level dirs, 4096 under each. Âeach 1k file I'm creating gets it's only directory under these so there are clearly a lot of directories.
xfs writes out about 25M objects and then the performance goes into the toilet. I'm sure what you said before about having to flush data and causing big delays, but would it be continuous? Âeach entry in the following table shows the time to write 10K files so the 2 blocks are 1M each Sat Jan 23 12:15:09 2016 Â16.114386 Â14.656736 Â14.789760 Â17.418389 Â14.613157 Â15.938176 Â14.865369 Â14.962058 Â17.297193 Â15.953590 Â14.895471 Â15.560252 Â14.789937 Â14.308618 Â16.390057 Â16.561789 Â15.713806 Â14.843791 Â15.940992 Â16.466924 Â15.842781 Â15.611230 Â17.102329 Â15.006291 Â14.454088 Â17.923662 Â13.378340 Â16.084664 Â15.996794 Â13.736398 Â18.125125 Â14.462063 Â18.101833 Â15.355139 Â16.603660 Â14.205896 Â16.474111 Â16.212237 Â15.072443 Â14.217581 Â16.273899 Â14.905624 Â17.285019 Â14.955722 Â13.769731 Â18.308619 Â15.601386 Â15.832661 Â14.342416 Â16.516657 Â14.697575 Â15.719496 Â16.723135 Â16.808668 Â15.443325 Â14.608358 Â17.031334 Â16.426377 Â13.900535 Â13.528603 Â16.197697 Â16.839241 Â14.802707 Â15.507915 Â14.864337 Â15.836943 Â15.660089 Â15.998911 Â13.956739 Â14.337318 Â16.416974 Â17.729661 Â14.936045 Â13.450859 Â15.943900 Â15.106077 Â15.541450 Â16.523752 Â16.555945 Â14.440305 Â14.937772 Â16.486544 Â13.780310 Â16.944841 Â14.867400 Â18.214934 Â14.142108 Â15.931952 Â14.424949 Â15.533156 Â16.010153 Â16.323108 Â14.423508 Â15.970071 Â15.277186 Â15.561362 Â14.978766 Â15.855935 Â16.953906 Â14.247016 Sat Jan 23 12:41:09 2016 Â15.908483 Â15.638943 Â17.681281 Â15.188704 Â15.721495 Â13.359225 Â15.999421 Â15.858876 Â16.402176 Â16.416312 Â15.443946 Â14.675751 Â15.470643 Â15.573755 Â15.422241 Â16.336590 Â17.220916 Â13.974890 Â15.877780 Â62.650921 Â62.667990 Â46.334603 Â53.546195 Â69.465447 Â65.006016 Â68.761229 Â70.754684 Â97.571669 104.811261 104.229302 105.605257 105.166030 105.058075 105.519703 106.573306 106.708545 106.114733 105.643131 106.049387 106.379378 104.239131 104.268931 103.852929 103.549319 103.516169 103.007015 103.724020 104.519983 105.839203 105.324985 104.328205 104.932713 103.051548 104.938652 102.769383 102.851609 101.432277 102.269842 100.937972 103.450103 103.477628 103.636130 103.444242 103.023145 102.565047 102.853115 101.402610 Â98.928230 Â99.310677 Â99.669667 101.140554 Â99.628664 102.093801 100.580659 101.762283 101.369349 102.637014 102.240950 101.778506 101.144526 100.899476 102.294952 102.029285 100.871166 102.763222 102.910690 104.892447 104.748194 105.403636 106.159345 106.413154 104.626632 105.775004 104.579775 104.778526 104.634778 106.233381 104.063642 106.635481 104.314503 if I look at the disk loads at the time, I see a dramatic increase in disk reads that correspond to the slow writes so I'm guessing at least some writes are waiting in the queue as you can see there - thanks to laurence for the patch to show disk read wait times ;) # DISK STATISTICS (/sec) #          <---------reads---------------><---------writes--------------><--------averages--------> Pct #Time   Name    KBytes Merged ÂIOs Size ÂWait ÂKBytes Merged ÂIOs Size ÂWait ÂRWSize ÂQLen ÂWait SvcTim Util 12:45:30 sdb       Â0   Â0  Â0  Â0   0 Â270040  Â105 2276 Â119   4   118  Â16   4   Â0  62 12:45:31 sdb       Â0   Â0  Â0  Â0   0 Â273776  Â120 2262 Â121   4   121  Â18   4   Â0  57 12:45:32 sdb       Â4   Â0  Â1  Â4   0 Â100164   57 Â909 Â110   4   110   6   4   Â0  84 12:45:33 sdb       Â0   Â0  Â0  Â0   0 Â229992   87 1924 Â120   1   119   2   1   Â0  68 12:45:34 sdb       Â4   Â0  Â1  Â4   4 Â153528   59 1304 Â118   0   117   1   0   Â0  78 12:45:35 sdb       Â0   Â0  Â0  Â0   0 Â220896   97 1895 Â117   1   116   1   1   Â0  62 12:45:36 sdb       Â0   Â0  Â0  Â0   0 Â419084  Â197 3504 Â120   0   119   1   0   Â0  32 12:45:37 sdb       Â0   Â0  Â0  Â0   0 Â428076  Â193 3662 Â117   0   116   1   0   Â0  32 12:45:38 sdb       Â0   Â0  Â0  Â0   0 Â428492  Â181 3560 Â120   0   120   1   0   Â0  30 12:45:39 sdb       Â0   Â0  Â0  Â0   0 Â426024  Â199 3641 Â117   0   117   1   0   Â0  32 12:45:40 sdb       Â0   Â0  Â0  Â0   0 Â429764  Â200 3589 Â120   0   119   1   0   Â0  28 12:45:41 sdb       Â0   Â0  Â0  Â0   0 Â410204  Â165 3430 Â120   0   119   3   0   Â0  36 12:45:42 sdb       Â0   Â0  Â0  Â0   0 Â406192  Â196 3437 Â118   0   118   5   0   Â0  39 12:45:43 sdb       Â0   Â0  Â0  Â0   0 Â420952  Â175 3552 Â119   0   118   1   0   Â0  34 12:45:44 sdb       Â0   Â0  Â0  Â0   0 Â428424  Â197 3645 Â118   0   117   1   0   Â0  31 12:45:45 sdb       Â0   Â0  Â0  Â0   0 Â192464   76 1599 Â120   8   120  Â18   8   Â0  75 12:45:46 sdb       Â0   Â0  Â0  Â0   0 Â340522  Â205 2951 Â115   2   115  Â16   2   Â0  41 12:45:47 sdb       Â0   Â0  Â0  Â0   0 Â429128  Â193 3664 Â117   0   117   1   0   Â0  28 12:45:48 sdb       Â0   Â0  Â0  Â0   0 Â402600  Â164 3311 Â122   0   121   3   0   Â0  39 12:45:49 sdb       Â0   Â0  Â0  Â0   0 Â435316  Â195 3701 Â118   0   117   1   0   Â0  36 12:45:50 sdb       Â0   Â0  Â0  Â0   0 Â367976  Â162 3152 Â117   1   116   7   1   Â0  46 12:45:51 sdb       Â0   Â0  Â0  Â0   0 Â255716  Â125 2153 Â119   4   118  Â16   4   Â0  60 # DISK STATISTICS (/sec) #          <---------reads---------------><---------writes--------------><--------averages--------> Pct #Time   Name    KBytes Merged ÂIOs Size ÂWait ÂKBytes Merged ÂIOs Size ÂWait ÂRWSize ÂQLen ÂWait SvcTim Util 12:45:52 sdb       Â0   Â0  Â0  Â0   0 Â360144  Â149 3006 Â120   1   119   9   1   Â0  46 12:45:53 sdb       Â0   Â0  Â0  Â0   0 Â343500  Â162 2909 Â118   1   118  Â11   1   Â0  43 12:45:54 sdb       Â0   Â0  Â0  Â0   0 Â256636  Â119 2188 Â117   2   117  Â11   2   Â0  54 12:45:55 sdb       Â0   Â0  Â0  Â0   0 Â149000   47 1260 Â118  Â14   118  Â22  Â14   Â0  79 12:45:56 sdb       Â0   Â0  Â0  Â0   0 Â198544   88 1654 Â120   7   120  Â19   7   Â0  67 12:45:57 sdb       Â0   Â0  Â0  Â0   0 Â320688  Â151 2731 Â117   1   117   8   1   Â0  53 12:45:58 sdb       Â0   Â0  Â0  Â0   0 Â422176  Â190 3532 Â120   0   119   1   0   Â0  32 12:45:59 sdb       Â0   Â0  Â0  Â0   0 Â266540  Â115 2233 Â119   5   119  Â13   5   Â0  93 12:46:00 sdb       Â8   Â0  Â2  Â4  690 Â291116  Â129 2463 Â118   3   118   9   3   Â0  82 12:46:01 sdb       Â0   Â0  Â0  Â0   0 Â249964  Â118 2160 Â116   4   115  Â15   4   Â0  60 12:46:02 sdb      4736   Â0  37 Â128   0 Â424680  Â167 3522 Â121   0   120   1   0   Â0  28 12:46:03 sdb      5016   Â0  42 Â119   0 Â391364  Â196 3344 Â117   0   117   6   0   Â0  34 12:46:04 sdb       Â0   Â0  Â0  Â0   0 Â415436  Â172 3501 Â119   0   118   2   0   Â0  33 12:46:05 sdb       Â0   Â0  Â0  Â0   0 Â398736  Â192 3373 Â118   0   118   3   0   Â0  39 12:46:06 sdb       Â0   Â0  Â0  Â0   0 Â367292  Â155 3015 Â122   0   121   6   0   Â0  39 12:46:07 sdb       Â0   Â0  Â0  Â0   0 Â420392  Â201 3614 Â116   0   116   1   0   Â0  30 12:46:08 sdb       Â0   Â0  Â0  Â0   0 Â424828  Â172 3547 Â120   0   119   1   0   Â0  32 12:46:09 sdb       Â0   Â0  Â0  Â0   0 Â500380  Â234 4277 Â117   0   116   2   0   Â0  34 12:46:10 sdb       Â0   Â0  Â0  Â0   0 Â104500   Â7 Â698 Â150   0   149   1   0   Â1  87 12:46:11 sdb       Â8   Â0  Â1  Â8 Â1260  77252   45 Â647 Â119   0   119   1   2   Â1  92 12:46:12 sdb       Â8   Â0  Â1  Â8 Â1244  73956   31 Â615 Â120   0   120   1   2   Â1  94 12:46:13 sdb       Â8   Â0  Â1  Â8  228 Â149552   64 1256 Â119   0   118   1   0   Â0  85 # DISK STATISTICS (/sec) #          <---------reads---------------><---------writes--------------><--------averages--------> Pct #Time   Name    KBytes Merged ÂIOs Size ÂWait ÂKBytes Merged ÂIOs Size ÂWait ÂRWSize ÂQLen ÂWait SvcTim Util 12:46:14 sdb       Â8   Â0  Â1  Â8 Â1232  37124   28 Â319 Â116   0   116   1   3   Â3  99 12:46:15 sdb       16   Â0  Â2  Â8  720  Â2776   23 Â120  23   1   Â22   1  Â13   Â8  99 12:46:16 sdb       Â0   Â0  Â0  Â0   0 Â108180   16 Â823 Â131   0   131   1   0   Â1  90 12:46:17 sdb       Â8   Â0  Â1  Â8 Â1260  37136   28 Â322 Â115   0   114   1   3   Â2  94 12:46:18 sdb       Â8   Â0  Â1  Â8 Â1252 Â108680   57 Â875 Â124   0   124   1   1   Â1  88 12:46:19 sdb       Â0   Â0  Â0  Â0   0    0   Â0  Â0  Â0   0    0   1   0   Â0 Â100 12:46:20 sdb       16   Â0  Â2  Â8  618  81516   49 Â685 Â119   0   118   1   1   Â1  94 12:46:21 sdb       16   Â0  Â2  Â8  640 Â225788  Â106 1907 Â118   0   118   1   0   Â0  75 12:46:22 sdb       32   Â0  Â4  Â8  Â95  73892   17 Â627 Â118   0   117   1   0   Â1  93 12:46:23 sdb       24   Â0  Â3  Â8  408 Â257012  Â119 2171 Â118   0   118   1   0   Â0  65 12:46:24 sdb       12   Â0  Â3  Â4   5  Â3608   Â0  20 Â180   0   157   1   0   43 Â100 12:46:25 sdb       44   Â0  Â7  Â6  210  74072   41 Â625 Â119   0   117   1   2   Â1  97 12:46:26 sdb       48   Â0  Â6  Â8  216 Â202852  Â112 1819 Â112   0   111   1   0   Â0  92 12:46:27 sdb       52   Â0  Â7  Â7  233 Â307156  Â137 2648 Â116   0   115   1   0   Â0  95 12:46:28 sdb       16   Â0  Â2  Â8  100  93168   Â7 Â638 Â146   0   145   1   0   Â1  97 12:46:29 sdb       16   Â0  Â2  Â8  642  37028   16 Â319 Â116   0   115   1   4   Â3  99 12:46:30 sdb       16   Â0  Â2  Â8  624  39068   36 Â342 Â114   0   113   1   3   Â2  99 12:46:31 sdb       80   Â0  10  Â8  Â94 Â253892  Â105 2169 Â117   0   116   1   0   Â0  84 12:46:32 sdb       Â0   Â0  Â0  Â0   0  Â5676   Â0  33 Â172   0   172   1   0   30 Â100 12:46:33 sdb       16   Â0  Â2  Â8  642  69236   28 Â583 Â119   0   118   1   2   Â1  96 12:46:34 sdb       Â8   Â0  Â1  Â8 Â1032  37132   30 Â315 Â118   0   117   1   3   Â3 Â100 12:46:35 sdb       16   Â0  Â2  Â8  822  56292   15 Â515 Â109   0   108   1   3   Â1 Â100 # DISK STATISTICS (/sec) #          <---------reads---------------><---------writes--------------><--------averages--------> Pct #Time   Name    KBytes Merged ÂIOs Size ÂWait ÂKBytes Merged ÂIOs Size ÂWait ÂRWSize ÂQLen ÂWait SvcTim Util 12:46:36 sdb       Â8   Â0  Â1  Â8  Â44  58768   15 Â452 Â130   0   129   1   0   Â2  96 12:46:37 sdb       28   Â0  Â4  Â7  390 Â114944   89 1100 Â104   0   104   1   1   Â0  88 12:46:38 sdb       Â0   Â0  Â0  Â0   0  29668   Â0 Â172 Â172  Â12   172   1  Â12   Â5  98 12:46:39 sdb       80   Â0  10  Â8  Â90 Â100084   31 Â882 Â113   0   112   1   1   Â1  91 12:46:40 sdb       Â0   Â0  Â0  Â0   0  24244   Â0 Â139 Â174   0   174   1   0   Â7 Â100 12:46:41 sdb       Â8   Â0  Â1  Â8 Â1224    0   Â0  Â0  Â0   0    8   1 Â1224  1000 Â100 12:46:42 sdb       Â8   Â0  Â1  Â8 Â1244  42368   29 Â354 Â120   0   119   1   3   Â2  96 12:46:43 sdb       36   Â0  Â5  Â7  251  51428   32 Â507 Â101   0   100   1   2   Â1  94 12:46:44 sdb       24   Â0  Â3  Â8  Â70  Â5732   31 Â147  39  Â15   Â38   2  Â16   Â6  99 12:46:45 sdb       32   Â0  Â4  Â8   4 Â213056   53 1647 Â129   0   129   1   0   Â0  74 12:46:46 sdb       Â8   Â0  Â1  Â8 Â1220  37416   28 Â328 Â114   0   113   1   3   Â2  96 12:46:47 sdb       Â8   Â0  Â1  Â8 Â1248  58572   67 Â607  96   0   Â96   1   2   Â1  93 12:46:48 sdb       40   Â0  Â5  Â8  Â84 Â274808   82 2173 Â126   0   126   1   0   Â0  70 12:46:49 sdb       Â0   Â0  Â0  Â0   0    0   Â0  Â0  Â0   0    0   1   0   Â0 Â100 12:46:50 sdb       Â8   Â0  Â1  Â8 Â1248    0   Â0  Â0  Â0   0    8   1 Â1248  1000 Â100 12:46:51 sdb       Â8   Â0  Â1  Â8 Â1272    0   Â0  Â0  Â0   0    8   1 Â1272  1000 Â100 12:46:52 sdb       24   Â0  Â3  Â8  414 Â205240  Â113 1798 Â114   0   113   1   0   Â0  75 12:46:53 sdb       Â8   Â0  Â1  Â8  876  92476   48 Â839 Â110   0   110   1   1   Â1  89 12:46:54 sdb       Â0   Â0  Â0  Â0   0  38700   Â0 Â225 Â172   0   172   1   0   Â4  99 12:46:55 sdb       16   Â0  Â2  Â8  582 Â150680   73 1262 Â119   0   119   1   1   Â0  87 12:46:56 sdb       Â8   Â0  Â1  Â8 Â1228    0   Â0  Â0  Â0   0    8   1 Â1228  1000 Â100 12:46:57 sdb       Â8   Â0  Â1  Â8 Â1244    0   Â0  Â0  Â0   0    8   1 Â1244  1000 Â100 next I played back the collectl process data and sorted by disk reads and discovered the top process, corresponding to the long disk reads was xfsaild. Âbtw - I also see the slab xfs_inode using about 60GB. It's also worth noting that I'm only doing 1-2MB/sec of writes and the rest of the data looks like it's coming from xfs journaling because when I look at the xfs stats I'm seeing on the order of 200-400MB/sec xfs logging writes - clearly they're not all going to disk. Once the read waits increase everything slows down including xfs logging (since it's doing less). I'm sure the simple answer may be that it is what it is, but I'm also wondering without changes to swift itself, might there be some ways to improve the situation by adding more memory or making any other tuning changes? The system I'm currently running my tests on has 128GB. -mark On Wed, Jan 6, 2016 at 6:49 PM, Dave Chinner <david@xxxxxxxxxxxxx> wrote: On Wed, Jan 06, 2016 at 05:46:33PM -0500, Mark Seger wrote: |
| <Prev in Thread] | Current Thread | [Next in Thread> |
|---|---|---|
| ||
| Previous by Date: | Re: [PATCH 0/7 V3] quota: add new quotactl Q_GETNEXTQUOTA, Eric Sandeen |
|---|---|
| Next by Date: | Re: xfs and swift, Bernd Schubert |
| Previous by Thread: | Re: xfs and swift, Dave Chinner |
| Next by Thread: | Re: xfs and swift, Dave Chinner |
| Indexes: | [Date] [Thread] [Top] [All Lists] |