xfs
[Top] [All Lists]

Re: long hangs when deleting large directories (3.0-rc3)

To: Dave Chinner <david@xxxxxxxxxxxxx>
Subject: Re: long hangs when deleting large directories (3.0-rc3)
From: Markus Trippelsdorf <markus@xxxxxxxxxxxxxxx>
Date: Wed, 29 Jun 2011 08:19:54 +0200
Cc: xfs@xxxxxxxxxxx
Dkim-signature: v=1; a=rsa-sha256; c=simple; d=mail.ud10.udmedia.de; h= date:from:to:cc:subject:message-id:references:mime-version: content-type:content-transfer-encoding:in-reply-to; q=dns/txt; s= beta; bh=/XjYjiMicHWRFCDuu0Z0Me0IErs3Zr1GTsnD2fp64RY=; b=tcDiW5n zu2LOY+C3P7BM44IbHUo37yYuMptcEJzSrwOxLIbhzplZAlcXFd3Ku26WDEggEVQ j7kmruHbemE66DV763WkV3gldSl2lg17zkKh2vcbuMzDESDypbA79bWwRvOTAsA9 2Bzi0h/hHpncgsIrST4rdwDDFqGxcZsOGtj8=
In-reply-to: <20110629043143.GA1026@dastard>
References: <20110621212201.GA1755@xxxxxxxxxxxxxx> <20110621185701.GB1723@xxxxxxxxxxxxxx> <20110622000449.GQ32466@dastard> <20110622070647.GA1744@xxxxxxxxxxxxxx> <20110622073047.GT32466@dastard> <20110629043143.GA1026@dastard>
On 2011.06.29 at 14:31 +1000, Dave Chinner wrote:
> On Wed, Jun 22, 2011 at 05:30:47PM +1000, Dave Chinner wrote:
> > On Wed, Jun 22, 2011 at 09:06:47AM +0200, Markus Trippelsdorf wrote:
> > > On 2011.06.22 at 10:04 +1000, Dave Chinner wrote:
> > > > On Tue, Jun 21, 2011 at 08:57:01PM +0200, Markus Trippelsdorf wrote:
> > > > 
> > > > That will at least tell us if this is the cause of your problem. If
> > > > it is, I think I know how to avoid most of the list walk overhead
> > > > fairly easily and that should avoid the need to change workqueue
> > > > configurations at all.
> > > 
> > > The kernel log is attached.
> > 
> > Ok, so that is the cause of the problem∵ THe 3 seconds of output
> > where it is nothing but:
> > 
> > Jun 22 08:53:09 x4 kernel: XFS (sdb1): ail: ooo splice, tail 0x12000156e7, 
> > item 0x12000156e6
> > Jun 22 08:53:09 x4 kernel: XFS (sdb1): ail: ooo splice, walked 15503 items  
> >     
> > .....
> > Jun 22 08:53:12 x4 kernel: XFS (sdb1): ail: ooo splice, tail 0x12000156e7, 
> > item 0x12000156e6
> > Jun 22 08:53:12 x4 kernel: XFS (sdb1): ail: ooo splice, walked 16945 items
> > 
> > Interesting is the LSN of the tail - it's only one sector further on
> > than the items being inserted. That's what I'd expect from a commit
> > record write race between two checkpoints. I'll have a deeper look
> > into whether this can be avoided later tonight and also whether I
> > can easily implement a "last insert cursor" easily so subsequent
> > inserts at the same LSN avoid the walk....
> 
> Ok, so here's a patch that does just this. I should probably also do
> a little bit of cleanup on the cursor code as well, but this avoids
> the repeated walks of the AIL to find the insert position.
> 
> Can you try it without the WQ changes you made, Marcus, and see if
> the interactivity problems go away?

Sorry to be the bringer of bad news, but this made things much worse:

-------cpu0-usage--------------cpu1-usage--------------cpu2-usage--------------cpu3-usage------
 --dsk/sdc-- ---system-- ---load-avg--- --dsk/sdc--
usr sys idl wai hiq siq:usr sys idl wai hiq siq:usr sys idl wai hiq siq:usr sys 
idl wai hiq siq| read  writ| int   csw | 1m   5m  15m |reads writs
  1   1  98   0   0   0:  0   1  99   0   0   0:  0   1  99   0   0   0:  0   1 
 99   0   0   0|   0     0 | 603   380 |0.66 0.55 0.28|   0     0 
  1   0  99   0   0   0:  1   0  99   0   0   0:  1  19  80   0   0   0:  0   0 
100   0   0   0|   0     0 | 719   383 |0.66 0.55 0.28|   0     0 
  3   1  96   0   0   0:  3   1  96   0   0   0:  1  52  47   0   0   0:  0   0 
100   0   0   0|   0  6464k|1847   919 |0.66 0.55 0.28|   0   202 
  2  13  85   0   0   0:  2   2  96   0   0   0:  1  56  43   0   0   0:  1  31 
 69   0   0   0|4096B  256k|1910  1280 |0.68 0.56 0.28|   1     8 
> 0   1  99   0   0   0:  0   0 100   0   0   0:  0   1  99   0   0   0:  0 100 
>   0   0   0   0|   0     0 |1256   170 |0.68 0.56 0.28|   0     0 
> 0   1  99   0   0   0:  1   1  98   0   0   0:  1   0  99   0   0   0:  0  99 
>   0   0   0   1|   0     0 |1395   229 |0.68 0.56 0.28|   0     0 
> 0   0 100   0   0   0:  0   0 100   0   0   0:  0   3  97   0   0   0:  0 100 
>   0   0   0   0|   0   512B|1304   167 |0.68 0.56 0.28|   0     1 
> 1   1  98   0   0   0:  1   1  98   0   0   0:  0   0 100   0   0   0:  0  99 
>   0   0   0   1|   0     0 |1211   146 |0.68 0.56 0.28|   0     0 
> 0   0 100   0   0   0:  0   0 100   0   0   0:  0   1  99   0   0   0:  0  97 
>   0   0   0   3|   0     0 |1270   149 |0.87 0.60 0.30|   0     0 
  5   2  65  29   0   0:  2   3  95   0   0   0:  1   0  99   0   0   0:  2  24 
 72   0   0   1|   0  8866k|2654  2398 |0.87 0.60 0.30|   0   496 
  6   2  25  67   0   0:  3   1  59  37   0   0:  0   0 100   0   0   0:  4   4 
 92   0   0   0|   0  4554k|2224  2494 |0.87 0.60 0.30|   0   399 
  1   1  98   0   0   0:  0   0  83  17   0   0:  1   3  96   0   0   0:  0   1 
 99   0   0   0|   0  2270k|1079  1030 |0.87 0.60 0.30|   0   200 
  1   1  98   0   0   0:  1   1  98   0   0   0:  0   1  99   0   0   0:  1   0 
 99   0   0   0|   0  9216B| 713   567 |0.87 0.60 0.30|   0     2 
  0   0 100   0   0   0:  1   1  98   0   0   0:  0   0 100   0   0   0:  0   1 
 99   0   0   0|   0     0 | 492   386 |0.80 0.59 0.30|   0     0 

As you can see in the table above (resolution 1sec) the hang is now
5-6 seconds long, instead of the 1-3 seconds seen before.

-- 
Markus

<Prev in Thread] Current Thread [Next in Thread>