hi enami,

this is a very good observation.  I can't think of any reason why we would
need to flush a relocated fragment immediately for the non-sync case.

however, the XXX comment you added isn't right.  in the sync case we do need
to flush the whole block to make sure it's all on disk.  this will be true
even when the current softdep interaction problem is fixed the right way.

-Chuck


On Thu, Apr 12, 2001 at 07:12:27PM +0900, enami tsugutomo wrote:
> One of reason that a tar spent more time to extract files these days
> is that it is waiting the last page to be written into disk when a
> fragment is relocated.  Look at the appended uvm history dump.
> uvn_findpage called inside ubc_fault waiting the page 0xc05f9b80,
> which is written async in ufs_balloc_range.
> 
> At least for async io, we don't need to flush pages in
> ufs_balloc_range, do we?
> 
> With appended patch, elapsed time to extract mozilla source is not so
> slow with comparing to 1.5 as listed below.
> 
> enami.
> 
> 987040683.411236 ffs_write#1098: called!
> 987040683.411242 ffs_write#1098: vp 0xc951fb60 off 0xf800 len 0x1000
> 987040683.411256 ufs_balloc_range#1371: called!
> 987040683.411264 ufs_balloc_range#1371: vp 0xc951fb60 off 0xf800 len 0x800 u_size 0xf800
> 987040683.411281 genfs_getpages#9125: called!
> 987040683.411288 genfs_getpages#9125: vp 0xc951fb60 off 0x0/e000 count 2
> 987040683.411302 uvn_findpage#42025: called!
> 987040683.411308 uvn_findpage#42025: vp 0xc951fb60 off 0xe000
> 987040683.411316 uvn_findpage#42025: found
> 987040683.411322 uvn_findpage#42026: called!
> 987040683.411328 uvn_findpage#42026: vp 0xc951fb60 off 0xf000
> 987040683.411334 uvn_findpage#42026: found
> 987040683.411341 genfs_getpages#9125: returning cached pages
> 987040683.411350 genfs_getpages#9126: called!
> 987040683.411356 genfs_getpages#9126: vp 0xc951fb60 off 0x0/10000 count 16
> 987040683.411361 genfs_getpages#9126: off 0x10000 count 16 goes past EOF 0xf800
> 987040683.411370 genfs_getpages#9127: called!
> 987040683.411375 genfs_getpages#9127: vp 0xc951fb60 off 0x0/20000 count 16
> 987040683.411381 genfs_getpages#9127: off 0x20000 count 16 goes past EOF 0xf800
> 987040683.411388 genfs_getpages#9125: succeeding, npages 2
> 987040683.411395 genfs_getpages#9125: examining pg 0xc05f9b40 flags 0x1d
> 987040683.411405 genfs_getpages#9125: examining pg 0xc05f9b80 flags 0x1d
> 987040683.411412 ufs_balloc_range#1371: got pgs1[0] 0xc05f9b40
> 987040683.411419 ufs_balloc_range#1371: got pgs1[1] 0xc05f9b80
> 987040683.411436 ffs_balloc#1387: called!
> 987040683.411445 ffs_balloc#1387: vp 0xc951fb60 lbn 0x7 size 0x2000
> 987040683.411523 uvm_vnp_setsize#3349: called!
> 987040683.411529 uvm_vnp_setsize#3349: old 0xf800 new 0x10000
> 987040683.411539 uvm_page_unbusy#2678: called!
> 987040683.411546 uvm_page_unbusy#2678: unbusying pg 0xc05f9b40
> 987040683.411553 uvm_page_unbusy#2678: unbusying pg 0xc05f9b80
> 987040683.411600 uvm_pager_put#828: called!
> 987040683.411629 genfs_putpages#828: called!
> 987040683.411635 genfs_putpages#828: vp 0xc951fb60 offset 0xe000 count 2
> 987040683.411759 genfs_putpages#828: vp 0xc951fb60 mbp 0xc0796068 num now 2 bytes 0x2000
> 987040683.411777 genfs_putpages#828: vp 0xc951fb60 offset 0xe000 bcount 0x2000 blkno 0x11f60
> 987040683.411862 genfs_putpages#828: returning 0 (async)
> 987040683.411869 uvm_pager_put#828: put -> 0
> 987040683.411891 ubc_alloc#5071: called!
> 987040683.411898 ubc_alloc#5071: uobj 0xc951fb60 offset 0xf800 len 0x800 filesize 0x10000
> 987040683.411910 ubc_alloc#5071: umap 0xc06fa1bc refs 1 va 0xc9230000
> 987040683.411990 ubc_fault#1637: called!
> 987040683.411997 ubc_fault#1637: va 0xc9231000 ubc_offset 0x75b000 at 3
> 987040683.412005 ubc_fault#1637: slot_offset 0x1000 writeoff 0x1800 writelen 0x800 u_size 0x10000
> 987040683.412012 ubc_fault#1637: NOT setting PGO_OVERWRITE
> 987040683.412019 ubc_fault#1637: getpages vp 0xc951fb60 offset 0xf000 npages 1
> 987040683.412026 genfs_getpages#9128: called!
> 987040683.412032 genfs_getpages#9128: vp 0xc951fb60 off 0x0/f000 count 1
> 987040683.412042 uvn_findpage#42027: called!
> 987040683.412049 uvn_findpage#42027: vp 0xc951fb60 off 0xf000
> 987040683.412977 uvm_aio_aiodone#865: called!
> 987040683.412984 uvm_aio_aiodone#865: bp 0xc0796068
> 987040683.413002 uvm_aio_aiodone#865: pgs[0] = 0xc05f9b40
> 987040683.413009 uvm_aio_aiodone#865: pgs[1] = 0xc05f9b80
> 987040683.413131 uvm_page_unbusy#2679: called!
> 987040683.413138 uvm_page_unbusy#2679: unbusying pg 0xc05f9b40
> 987040683.413144 uvm_page_unbusy#2679: unbusying pg 0xc05f9b80
> 987040683.413175 uvn_findpage#42027: found
> 987040683.413181 genfs_getpages#9128: returning cached pages
> 987040683.413187 genfs_getpages#9128: succeeding, npages 2
> 987040683.413193 genfs_getpages#9128: examining pg 0xc05f9b80 flags 0x1d
> 987040683.413201 ubc_fault#1637: getpages error 0 npages 1
> 987040683.413207 ubc_fault#1637: va 0xc9231000 eva 0xc9232000
> 987040683.413214 ubc_fault#1637: pgs[0] = 0xc05f9b80
> 987040683.413242 ubc_release#5071: called!
> 987040683.413249 ubc_release#5071: va 0xc9231800
> 987040683.413256 ubc_release#5071: umap 0xc06fa1bc refs 0
> 987040683.413297 uvm_pager_put#829: called!
> 987040683.413319 genfs_putpages#829: called!
> 987040683.413325 genfs_putpages#829: vp 0xc951fb60 offset 0x1000 count 1
> 987040683.413422 genfs_putpages#829: vp 0xc951fb60 mbp 0xc070be38 num now 2 bytes 0x1000
> 987040683.413432 genfs_putpages#829: vp 0xc951fb60 offset 0x1000 bcount 0x1000 blkno 0x11ef8
> 987040683.413471 genfs_putpages#829: returning 0 (async)
> 987040683.413478 uvm_pager_put#829: put -> 0
> 987040683.413489 uvm_pager_put#830: called!
> 987040683.413512 genfs_putpages#830: called!
> 987040683.413518 genfs_putpages#830: vp 0xc951fb60 offset 0x3000 count 1
> 987040683.413619 genfs_putpages#830: vp 0xc951fb60 mbp 0xc070b340 num now 4 bytes 0x1000
> 987040683.413629 genfs_putpages#830: vp 0xc951fb60 offset 0x3000 bcount 0x1000 blkno 0x11f08
> 987040683.413639 genfs_putpages#830: returning 0 (async)
> 987040683.413645 uvm_pager_put#830: put -> 0
> 987040683.413657 uvm_pager_put#831: called!
> 987040683.413678 genfs_putpages#831: called!
> 987040683.413684 genfs_putpages#831: vp 0xc951fb60 offset 0x5000 count 1
> 987040683.413783 genfs_putpages#831: vp 0xc951fb60 mbp 0xc070b270 num now 6 bytes 0x1000
> 
> 
> Index: ufs_inode.c
> ===================================================================
> RCS file: /cvsroot/syssrc/sys/ufs/ufs/ufs_inode.c,v
> retrieving revision 1.22
> diff -u -r1.22 ufs_inode.c
> --- ufs_inode.c	2001/02/27 02:55:40	1.22
> +++ ufs_inode.c	2001/04/12 09:29:40
> @@ -286,11 +286,15 @@
>  		/*
>  		 * The data in the frag might be moving to a new disk location.
>  		 * We need to flush pages to the new disk locations.
> +		 *
> +		 * XXX.  For now, we writes whole filesystem block.
> +		 * See the comment in {ffs,lfs}_write in
> +		 * ufs_readwrite.c.
>  		 */
> -
> -		(uobj->pgops->pgo_flush)(uobj, oldeof & ~(bsize - 1),
> -		    MIN((oldeof + bsize) & ~(bsize - 1), neweof),
> -		    PGO_CLEANIT | ((flags & B_SYNC) ? PGO_SYNCIO : 0));
> +		if ((flags & B_SYNC) != 0)
> +			(*uobj->pgops->pgo_flush)(uobj, oldeof & ~(bsize - 1),
> +			    (oldeof + bsize) & ~(bsize - 1),
> +			    PGO_CLEANIT | PGO_SYNCIO);
>  	}
>  	if (pgs2[0] != NULL) {
>  		uvm_page_unbusy(pgs2, npages2);
> 
> 
> Some measurements.  All files are on same nfs server.
> 
> [ppro200, 64M, 1.5]
> enami@backup% csh -c 'time tar xzf /ccd0/NetBSD/pkgsrc/distfiles/mozilla-source-0.8.1.tar.bz2'
> 129.1u 33.2s 9:12.87 29.3% 0+0k 12553+59507io 65pf+0w
> 
> [ppro200, 96M, -current with the patch]
> enami@annex-2f-floor-217% csh -c 'time tar xzf /b/pkgsrc/distfiles/mozilla-source-0.8.1.tar.bz2'
> 124.2u 72.9s 11:26.30 28.7% 0+0k 2724+18843io 33pf+0w
> 
> [p-iii 1g, 384M, -currrent]
> enami@enxio% csh -c 'time tar xzf /sink/NetBSD/pkgsrc/distfiles/mozilla-source-0.8.1.tar.bz2'
> 36.5u 10.3s 10:46.81 7.2% 0+0k 1541+20597io 36pf+0w
> 
> [p-iii 1g, 384M, -currrent with the patch]
> enami@enxio% csh -c 'time tar xzf /sink/NetBSD/pkgsrc/distfiles/mozilla-source-0.8.1.tar.bz2'
> 37.4u 8.4s 6:09.65 12.4% 0+0k 1552+16224io 36pf+0w