<div dir="ltr"><div class="gmail_extra"><div class="gmail_quote"><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex">
There is no way that fallocate() of 1000x1k files should be causing<br>
450MB/s of IO for 5 seconds.<br></blockquote><div><br></div><div style>I agree and that's what has me puzzled as well.</div><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex">
However, I still have no idea what you are running this test on - as<br>
I asked in another email, can you provide some information about<br>
the system your are seeing this problem on so we can try to work out<br>
what might be causing this?<br></blockquote><div><br></div><div style>sorry about that. This is an HP box with 192GB RAM and 6 2-core hyperthreaded CPUs, running ubuntu/precise</div><div style><br></div><div>segerm@az1-sw-object-0006:~$ uname -a</div>
<div>Linux az1-sw-object-0006 2.6.38-16-server #68hf1026116v20120926-Ubuntu SMP Wed Sep 26 14:34:13 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux</div><div><br></div><div style><div>segerm@az1-sw-object-0006:~$ python --version</div>
<div>Python 2.7.1+</div><div><br></div><div><div>segerm@az1-sw-object-0006:~$ xfs_repair -V</div><div>xfs_repair version 3.1.4</div></div><div><br></div><div><div>segerm@az1-sw-object-0006:~$ cat /proc/meminfo</div><div>MemTotal: 198191696 kB</div>
<div>MemFree: 166202324 kB</div><div>Buffers: 193268 kB</div><div>Cached: 21595332 kB</div><div>SwapCached: 36 kB</div><div>Active: 7992268 kB</div><div>Inactive: 14068428 kB</div>
<div>Active(anon): 719408 kB</div><div>Inactive(anon): 5244092 kB</div><div>Active(file): 7272860 kB</div><div>Inactive(file): 8824336 kB</div><div>Unevictable: 0 kB</div><div>Mlocked: 0 kB</div>
<div>SwapTotal: 126889980 kB</div><div>SwapFree: 126863972 kB</div><div>Dirty: 0 kB</div><div>Writeback: 0 kB</div><div>AnonPages: 232156 kB</div><div>Mapped: 11384 kB</div>
<div>Shmem: 5731388 kB</div><div>Slab: 5755820 kB</div><div>SReclaimable: 4792292 kB</div><div>SUnreclaim: 963528 kB</div><div>KernelStack: 6240 kB</div><div>PageTables: 7328 kB</div>
<div>NFS_Unstable: 0 kB</div><div>Bounce: 0 kB</div><div>WritebackTmp: 0 kB</div><div>CommitLimit: 225985828 kB</div><div>Committed_AS: 8851976 kB</div><div>VmallocTotal: 34359738367 kB</div>
<div>VmallocUsed: 725112 kB</div><div>VmallocChunk: 34159749436 kB</div><div>HardwareCorrupted: 0 kB</div><div>HugePages_Total: 0</div><div>HugePages_Free: 0</div><div>HugePages_Rsvd: 0</div>
<div>HugePages_Surp: 0</div><div>Hugepagesize: 2048 kB</div><div>DirectMap4k: 118648 kB</div><div>DirectMap2M: 5089280 kB</div><div>DirectMap1G: 196083712 kB</div></div><div><br></div><div style>over 60 mounts, but here's the one I'm writing to:</div>
<div style><br></div><div><div>segerm@az1-sw-object-0006:~$ mount | grep disk0</div><div>/dev/sdc1 on /srv/node/disk0 type xfs (rw,nobarrier)</div></div><div style><br></div><div style>not sure what you're looking for here so here's it all</div>
<div style><br></div><div><div>segerm@az1-sw-object-0006:~$ cat /proc/partitions</div><div>major minor #blocks name</div><div><br></div><div> 8 0 976762584 sda</div><div> 8 1 248976 sda1</div><div>
8 2 1 sda2</div><div> 8 5 976510993 sda5</div><div> 251 0 41943040 dm-0</div><div> 251 1 8785920 dm-1</div><div> 251 2 2928640 dm-2</div><div> 8 16 976762584 sdb</div>
<div> 8 17 976760832 sdb1</div><div> 251 3 126889984 dm-3</div><div> 251 4 389120 dm-4</div><div> 251 5 41943040 dm-5</div><div> 8 32 2930233816 sdc</div><div> 8 33 2930233344 sdc1</div>
<div> 8 48 2930233816 sdd</div><div> 8 49 2930233344 sdd1</div><div> 8 64 2930233816 sde</div><div> 8 65 2930233344 sde1</div><div> 8 80 2930233816 sdf</div><div> 8 81 2930233344 sdf1</div>
<div> 8 96 2930233816 sdg</div><div> 8 97 2930233344 sdg1</div><div> 8 112 2930233816 sdh</div><div> 8 113 2930233344 sdh1</div><div> 8 128 2930233816 sdi</div><div> 8 129 2930233344 sdi1</div>
<div> 8 144 2930233816 sdj</div><div> 8 145 2930233344 sdj1</div><div> 8 160 2930233816 sdk</div><div> 8 161 2930233344 sdk1</div><div> 8 176 2930233816 sdl</div><div> 8 177 2930233344 sdl1</div>
<div> 8 192 2930233816 sdm</div><div> 8 193 2930233344 sdm1</div><div> 8 208 2930233816 sdn</div><div> 8 209 2930233344 sdn1</div><div> 8 240 2930233816 sdp</div><div> 8 241 2930233344 sdp1</div>
<div> 8 224 2930233816 sdo</div><div> 8 225 2930233344 sdo1</div><div> 65 0 2930233816 sdq</div><div> 65 1 2930233344 sdq1</div><div> 65 16 2930233816 sdr</div><div> 65 17 2930233344 sdr1</div>
<div> 65 32 2930233816 sds</div><div> 65 33 2930233344 sds1</div><div> 65 176 2930233816 sdab</div><div> 65 177 2930233344 sdab1</div><div> 66 0 2930233816 sdag</div><div> 66 1 2930233344 sdag1</div>
<div> 65 64 2930233816 sdu</div><div> 65 65 2930233344 sdu1</div><div> 65 128 2930233816 sdy</div><div> 65 129 2930233344 sdy1</div><div> 65 224 2930233816 sdae</div><div> 65 225 2930233344 sdae1</div>
<div> 65 144 2930233816 sdz</div><div> 65 145 2930233344 sdz1</div><div> 65 208 2930233816 sdad</div><div> 65 209 2930233344 sdad1</div><div> 65 48 2930233816 sdt</div><div> 65 49 2930233344 sdt1</div>
<div> 65 240 2930233816 sdaf</div><div> 65 241 2930233344 sdaf1</div><div> 65 96 2930233816 sdw</div><div> 65 97 2930233344 sdw1</div><div> 66 32 2930233816 sdai</div><div> 66 33 2930233344 sdai1</div>
<div> 66 48 2930233816 sdaj</div><div> 66 49 2930233344 sdaj1</div><div> 65 112 2930233816 sdx</div><div> 65 113 2930233344 sdx1</div><div> 65 160 2930233816 sdaa</div><div> 65 161 2930233344 sdaa1</div>
<div> 65 80 2930233816 sdv</div><div> 65 81 2930233344 sdv1</div><div> 65 192 2930233816 sdac</div><div> 65 193 2930233344 sdac1</div><div> 66 16 2930233816 sdah</div><div> 66 17 2930233344 sdah1</div>
<div> 66 64 2930233816 sdak</div><div> 66 65 2930233344 sdak1</div><div> 66 144 2930233816 sdap</div><div> 66 145 2930233344 sdap1</div><div> 66 224 2930233816 sdau</div><div> 66 225 2930233344 sdau1</div>
<div> 67 208 2930233816 sdbj</div><div> 67 209 2930233344 sdbj1</div><div> 66 112 2930233816 sdan</div><div> 66 113 2930233344 sdan1</div><div> 66 96 2930233816 sdam</div><div> 66 97 2930233344 sdam1</div>
<div> 66 80 2930233816 sdal</div><div> 66 81 2930233344 sdal1</div><div> 67 96 2930233816 sdbc</div><div> 67 97 2930233344 sdbc1</div><div> 66 128 2930233816 sdao</div><div> 66 129 2930233344 sdao1</div>
<div> 67 128 2930233816 sdbe</div><div> 67 129 2930233344 sdbe1</div><div> 66 176 2930233816 sdar</div><div> 66 177 2930233344 sdar1</div><div> 67 160 2930233816 sdbg</div><div> 67 161 2930233344 sdbg1</div>
<div> 66 160 2930233816 sdaq</div><div> 66 161 2930233344 sdaq1</div><div> 67 48 2930233816 sdaz</div><div> 67 49 2930233344 sdaz1</div><div> 66 208 2930233816 sdat</div><div> 66 209 2930233344 sdat1</div>
<div> 67 112 2930233816 sdbd</div><div> 67 113 2930233344 sdbd1</div><div> 67 144 2930233816 sdbf</div><div> 67 145 2930233344 sdbf1</div><div> 67 64 2930233816 sdba</div><div> 67 65 2930233344 sdba1</div>
<div> 67 16 2930233816 sdax</div><div> 67 17 2930233344 sdax1</div><div> 67 32 2930233816 sday</div><div> 67 33 2930233344 sday1</div><div> 66 192 2930233816 sdas</div><div> 66 193 2930233344 sdas1</div>
<div> 67 192 2930233816 sdbi</div><div> 67 193 2930233344 sdbi1</div><div> 66 240 2930233816 sdav</div><div> 66 241 2930233344 sdav1</div><div> 67 80 2930233816 sdbb</div><div> 67 81 2930233344 sdbb1</div>
<div> 67 176 2930233816 sdbh</div><div> 67 177 2930233344 sdbh1</div><div> 67 0 2930233816 sdaw</div><div> 67 1 2930233344 sdaw1</div></div><div><br></div><div><div>segerm@az1-sw-object-0006:~$ xfs_info /srv/node/disk0</div>
<div>meta-data=/dev/sdc1 isize=1024 agcount=32, agsize=22892416 blks</div><div> = sectsz=512 attr=2</div><div>data = bsize=4096 blocks=732557312, imaxpct=5</div>
<div> = sunit=64 swidth=64 blks</div><div>naming =version 2 bsize=4096 ascii-ci=0</div><div>log =internal bsize=4096 blocks=357696, version=2</div><div>
= sectsz=512 sunit=64 blks, lazy-count=1</div><div>realtime =none extsz=4096 blocks=0, rtextents=0</div></div><div><br></div><div style>Is this enough to describe my environment?</div>
<div><br></div></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex">
<br>
<a href="http://xfs.org/index.php/XFS_FAQ#Q:_What_information_should_I_include_when_reporting_a_problem.3F" target="_blank">http://xfs.org/index.php/XFS_FAQ#Q:_What_information_should_I_include_when_reporting_a_problem.3F</a><br>
<div class="im"><br>
> This is the same behavior I'm seeing on swift. 10K 1KB files X 4kb minimal<br>
> block size still comes out to a lot less than the multiple GB of writes<br>
> being reported. Actually since these whole thing only takes a few seconds<br>
> and I know a single disk can't write that fast maybe it's just a bug in the<br>
> way the kernel is reported allocated preallocated blocks and nothing to do<br>
> with XFS? Or iis xfs responsible for the stats?<br>
<br>
</div>I don't know what stats you are getting your information from. XFS<br>
is only responsible for what is in /proc/fs/xfs/,,,</blockquote><div><br></div><div style>I'm getting my stats from 2 places, collectl reading /proc/diskstats AND xfs from /proc/fs/xfs though I've only shown you the collectl stats. It's easy enough to send you the /proc/fs/xfs stats if you want them as both formatted output as well as the raw /proc/fs/xfs contents every second from which they're derived.</div>
<div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex"><div class="im">
> If I remove the fallocate call I see the expected amount of disk traffic.<br>
<br>
</div>Have you run strace to confirm that your python script is actually<br>
calling fallocate(), and it's not being emulated by python or libc?</blockquote><div><br></div><div style>I haven't. However when I saw this exact behavior with swift, we did see both fallocate being called and here's a small section showing a complete 10K PUT operation and the beginning of the next one:</div>
<div style><br></div><div style><div> 0.067874 cpu=0 pid=41977 fallocate [285] entry fd=15 mode=0x1 offset=0x0 len=10240</div><div> 0.067980 cpu=0 pid=41977 block_rq_insert dev_t=0x04100030 wr=write flags=SYNC sector=0xaec11a00 len=262144</div>
<div> 0.067983 cpu=0 pid=41977 block_rq_issue dev_t=0x04100030 wr=write flags=SYNC sector=0xaec11a00 len=262144</div><div> 0.068010 cpu=0 pid=41977 sched_switch prio=120 state=SSLEEP next_pid=0 next_prio=120</div><div>
0.068125 cpu=0 pid=0 block_rq_complete dev_t=0x04100030 wr=write flags=SYNC sector=0xaec11a00 len=262144 qpid=41977 spid=41977 qtm= 0.000004 svtm= 0.000142</div><div> 0.068175 cpu=0 pid=48168 sched_wakeup target_pid=41977 prio=120 target_cpu=12 success=1</div>
<div> 0.068180 cpu=12 pid=0 sched_switch prio=n/a state=n/a next_pid=41977 next_prio=120</div><div> 0.068185 cpu=12 pid=41977 fallocate [285] ret=0x0 syscallbeg= 0.000311 fd=15 mode=0x1 offset=0x0 len=10240</div>
<div><br></div></div><div style>I hope this helps but if there's any more I can provide I'll be happy to do so.</div><div style>-mark</div><div style><br></div><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex">
<div class=""><div class="h5">
Cheers,<br>
<br>
Dave.<br>
--<br>
Dave Chinner<br>
<a href="mailto:david@fromorbit.com">david@fromorbit.com</a><br>
</div></div></blockquote></div><br></div></div>