bug: xfs_repair becomes very slow when file system has a large sparse file

Joe Landman landman at scalableinformatics.com
Tue Jan 10 11:32:46 CST 2012


User just gave us permission to work on the system now, and we can be 
destructive if needed.  Took a few months, but we have a full 
backup/snapshot which is now the primary, and this is an "extra" system 
to be remissioned, but still exhibits the problem reported last August.


FWIW:

[root at jr4-4 ~]# df -h /data
Filesystem            Size  Used Avail Use% Mounted on
/dev/md2               33T   30T  3.0T  92% /data



On 08/19/2011 08:26 PM, Dave Chinner wrote:
> On Fri, Aug 19, 2011 at 12:37:05PM -0400, Joe Landman wrote:
>> (If you prefer we file this on a bug reporting system, please let me
>> know where and I'll do this).
>>
>> Scenario:  xfs_repair being run against an about 17TB volume,
>> containing 1 large sparse file.  Logical size of 7 PB, actual size,
>> a few hundred GB.
>>
>> Metadata:  Kernel = 2.6.32.41, 2.6.39.4, and others. Xfstools 3.1.5.
>> Hardware RAID ~17TB LUN.  Base OS: Centos 5.6 + updates + updated
>> xfs tools + our kernels.  Using external journal on a different
>> device
>>
>> What we observe:
>>
>> Running xfs_repair
>>
>> 	xfs_repair -l /dev/md2 -vv /dev/sdd2
>
> can you post the actual output of xfs_repair?
>

Will do below.

>>
>> the system gets to stage 3 and the first ag.  Then it appears to
>> stop. After an hour or so, we strace it, and we see
>>
>> 	pread(...) = 4096
>
> and the same for the strace, along with syscall completion time?
> (i.e. strace -ttt -T .....) That will tell us if the time is spend
> doing IO or in the repair binary.
>

Ok.  Will do below as well.

> What is the CPU usage when this happens? How much memory do you

A single CPU filled.

> have? Is the machine swapping while it is slowing down? A couple of

No.  Checked that.

> minutes output of 'vmstat 5' when it is in this state would be handy.

Ok, will append this as well.

>
>> occurring about 2-3 per second.  An hour later, its down to 1 per
>> second.   An hour after that, its once every 2 seconds.
>>
>> Also, somewhere on this disk, someone has created an unfortunately
>> large file
>>
>> [root at jr4-2 ~]# ls -alF /data/brick-sdd2/dht/scratch/xyzpdq
>> total 4652823496
>> d---------   2 1232 1000               86 Jun 27 20:31 ./
>> drwx------ 104 1232 1000            65536 Aug 17 23:53 ../
>> -rw-------   1 1232 1000               21 Jun 27 09:57 Default.Route
>> -rw-------   1 1232 1000              250 Jun 27 09:57 Gau-00000.inp
>> -rw-------   1 1232 1000                0 Jun 27 09:57 Gau-00000.d2e
>> -rw-------   1 1232 1000 7800416534233088 Jun 27 20:18 Gau-00000.rwf
>>
>> [root at jr4-2 ~]# ls -ahlF /data/brick-sdd2/dht/scratch/xyzpdq
>> total 4.4T
>> d---------   2 1232 1000   86 Jun 27 20:31 ./
>> drwx------ 104 1232 1000  64K Aug 17 23:53 ../
>> -rw-------   1 1232 1000   21 Jun 27 09:57 Default.Route
>> -rw-------   1 1232 1000  250 Jun 27 09:57 Gau-00000.inp
>> -rw-------   1 1232 1000    0 Jun 27 09:57 Gau-00000.d2e
>> -rw-------   1 1232 1000 7.0P Jun 27 20:18 Gau-00000.rwf
>>
>> This isn't a 7PB file system, its a 100TB file system across 3
>> machines, roughly 17TB per brick or OSS.  The Gau-00000.rwf is
>> obviously a sparse file, as could be seen with an ls -alsF
>
> What does du tell you about it?  xfs_io -f -c "stat"<large file>?
> xfs_bmap -vp<large file>?

In the cases presented below, none of the files are sparse.  I am 
wondering if it simply happens for large files.  I scanned the file 
system for large files (greater than 10GB in size), and found quite a 
few ... a number of which were at 250+ GB size.

>
>> Upon removing that file, the xfs_repair completes within ~10
>> minutes. Leaving that file on there, the xfs_repair does not
>> terminate, it just gets asymptotically slower.

I'd like to leave these in place until you tell me you need them to be 
removed/looked at.

>
> That could simply be the memory footprint causing more swapping per
> operation to occur. Or it could be that something is simply getting
> too large for the index type being used. If the machine is not
> swapping, can you point 'perf top -p<pid of xfs_repair>' at it so
> we might see where that CPU time is being spent?  (you might need to
> use a non-stripped version of the binary to get any useful
> information)

Ok.  I'll generate that if needed.

>
>> Please let me know if you need more information, or if you would
>> like me to file this somewhere else for official reportage.
>
> This is the right place to let us know about problems.
>

Separating with 8x========== on top and ==========x8 on bottom, with 
additional meta-data below the 8x ... portion

8x========== xfs_repair output for
# nohup xfs_repair  -m 16384 -vvv -l /dev/md10 /dev/md2 > \
#            repair.out 2>&1 &

[root at jr4-4 ~]# cat repair.out
Phase 1 - find and verify superblock...
         - max_mem = 16777216, icount = 15540800, imem = 60706, dblock = 
8782223872, dmem = 4288195
         - block cache size set to 1547288 entries
Phase 2 - using external log on /dev/md10
         - zero log...
zero_log: head block 2 tail block 2
         - scan filesystem freespace and inode maps...
         - found root inode chunk
libxfs_bcache: 0x8804c0
Max supported entries = 1547288
Max utilized entries = 11850
Active entries = 11850
Hash table size = 193411
Hits = 0
Misses = 11850
Hit ratio =  0.00
MRU 0 entries =  11850 (100%)
MRU 1 entries =      0 (  0%)
MRU 2 entries =      0 (  0%)
MRU 3 entries =      0 (  0%)
MRU 4 entries =      0 (  0%)
MRU 5 entries =      0 (  0%)
MRU 6 entries =      0 (  0%)
MRU 7 entries =      0 (  0%)
MRU 8 entries =      0 (  0%)
MRU 9 entries =      0 (  0%)
MRU 10 entries =      0 (  0%)
MRU 11 entries =      0 (  0%)
MRU 12 entries =      0 (  0%)
MRU 13 entries =      0 (  0%)
MRU 14 entries =      0 (  0%)
MRU 15 entries =      0 (  0%)
Hash buckets with   0 entries 182822 (  0%)
Hash buckets with   1 entries   9785 ( 82%)
Hash buckets with   2 entries    530 (  8%)
Hash buckets with   3 entries    108 (  2%)
Hash buckets with   4 entries    155 (  5%)
Hash buckets with   5 entries      9 (  0%)
Hash buckets with   8 entries      2 (  0%)
Phase 3 - for each AG...
         - scan and clear agi unlinked lists...
         - process known inodes and perform inode discovery...
         - agno = 0
         - agno = 1
         - agno = 2
         - agno = 3
         - agno = 4
         - agno = 5
         - agno = 6
         - agno = 7

# stuck here for more than 1 hour now
==========x8

8x========== top output
#

[root at jr4-4 ~]# top

top - 11:30:27 up 160 days, 13:42,  2 users,  load average: 0.87, 0.86, 0.87
Tasks: 384 total,   2 running, 382 sleeping,   0 stopped,   0 zombie
Cpu(s):  0.0%us,  0.8%sy,  0.0%ni, 98.2%id,  0.8%wa,  0.0%hi,  0.2%si, 
0.0%st
Mem:  49459860k total, 15226800k used, 34233060k free,      380k buffers
Swap: 13670752k total,        0k used, 13670752k free,     9612k cached

   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND 

16623 root      20   0 15.6g  14g  908 R 99.9 30.0 121:00.98 xfs_repair 

17099 root      20   0 12880 1232  732 R  2.0  0.0   0:00.02 top 

     1 root      20   0 10360  636  520 S  0.0  0.0   1:20.24 init 

     2 root      20   0     0    0    0 S  0.0  0.0   0:00.02 kthreadd 

     3 root      RT   0     0    0    0 S  0.0  0.0   3:44.51 
migration/0 

     4 root      20   0     0    0    0 S  0.0  0.0  88:34.79 
ksoftirqd/0

==========x8

8x========== vmstat 5 output for
# nohup vmstat 5 > vmstat.out 2>&1 &
# started the xfs_repair after starting this, so this is the initial
# data, subsequent data after the ... where xfs_repair appears to be
# mired down.

[root at jr4-4 ~]# tail -f vmstat.out
procs -----------memory---------- ---swap-- -----io---- --system-- 
-----cpu------
  r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy 
id wa st
  0  0      0 49093752    868  11020    0    0   744   249    0    0  0 
  1 98  1  0
  0  0      0 49094260    868  11020    0    0     0     4 1616  264  0 
  0 100  0  0
  0  0      0 49094384    876  11020    0    0     0     8 1614  262  0 
  0 100  0  0
  0  0      0 49094320    876  11020    0    0     0     0 1614  271  0 
  0 100  0  0
  0  0      0 49094332    884  11020    0    0     0    10 1619  275  0 
  0 100  0  0
  1  0      0 45504692    884  11020    0    0 647582 24578 57587 68969 
  8  4 84  3  0
  1  1      0 45481944    892  11020    0    0  2436     9 2232 1490  6 
  0 94  0  0
  1  0      0 45478984    892  11020    0    0   306     7 1698  423  6 
  0 94  0  0
  1  0      0 45477620    900  11020    0    0   134    10 1656  344  6 
  0 94  0  0
  1  0      0 45476380    900  11020    0    0   106     0 1643  322  6 
  0 94  0  0
  1  0      0 45475264    908  11020    0    0    90     6 1642  314  6 
  0 94  0  0
  1  0      0 45474396    908  11020    0    0    76     4 1638  308  6 
  0 94  0  0
  1  0      0 45473528    916  11020    0    0    74     6 1639  308  6 
  0 94  0  0
  1  0      0 45472784    916  11020    0    0    66     0 1634  301  6 
  0 94  0  0
  0  1      0 45471544    924  11020    0    0   174    10 1666  359  6 
  0 94  1  0
  1  0      0 45470428    924  11020    0    0   179     4 1667  364  4 
  0 94  2  0
  1  0      0 45469684    932  11020    0    0   114     6 1648  327  5 
  0 94  2  0
  1  0      0 45469188    932  11020    0    0    94     0 1639  315  5 
  0 94  1  0
  1  0      0 45468692    940  11020    0    0    85     6 1640  312  5 
  0 94  1  0
  0  1      0 45467328    940  11020    0    0   246     0 1677  391  4 
  0 94  3  0
  1  0      0 45466584    948  11020    0    0   135     6 1653  337  5 
  0 94  2  0
procs -----------memory---------- ---swap-- -----io---- --system-- 
-----cpu------
  r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy 
id wa st
  1  0      0 45465964    952  11016    0    0   101     2 1641  318  5 
  0 94  1  0
  1  0      0 45465468    956  11020    0    0    88     7 1644  314  5 
  0 94  1  0
  1  0      0 45464972    964  11020    0    0    80     6 1640  313  5 
  0 94  1  0
  1  4      0 43957340    964  11020    0    0 251558     0 14506 21971 
  4  1 87  8  0
  0  1      0 43732652    972  11020    0    0 75435     6 2454 1011  1 
  0 90  9  0
  0  1      0 43728312    972  11020    0    0   355     0 1704  443  1 
  0 94  5  0
  0  1      0 43724220    980  11020    0    0   310     6 1697  431  1 
  0 94  5  0
  0  1      0 43721244    980  11020    0    0   315     0 1694  423  0 
  0 94  6  0
  0  1      0 43719508    988  11020    0    0   325    11 1703  438  1 
  0 94  5  0
  0  5      0 43475228    988  11020    0    0  7897     4 5164 2114  2 
  0 92  5  0
  0  1      0 43239876    996  11020    0    0 81598     6 2387  967  1 
  0 90  9  0
  0  1      0 43234048    996  11020    0    0   378     0 1710  455  1 
  0 94  6  0
  0  1      0 42899620   1004  11020    0    0 63013     6 3309 3314  2 
  0 93  5  0
  0  5      0 42643932   1004  11020    0    0 48565     0 2664 2174  1 
  0 92  7  0
  1  0      0 42390972   1012  11020    0    0 47660     6 2905 1949  1 
  0 92  6  0
  1  0      0 42389236   1012  11020    0    0   237     4 1679  388  4 
  0 94  2  0
  0  1      0 42373472    324   9724    0    0  2662    34 1786  584  1 
  0 94  5  0
  0  1      0 42367004    348   9740    0    0   333    10 1704  445  0 
  0 94  6  0
  0  1      0 42362664    348   9740    0    0   326     0 1698  435  0 
  0 94  6  0
  0  1      0 42358944    356   9740    0    0   326     6 1702  434  0 
  0 94  6  0
  0  1      0 42354728    356   9740    0    0   758     0 1705  437  0 
  0 94  6  0
procs -----------memory---------- ---swap-- -----io---- --system-- 
-----cpu------
  r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy 
id wa st
  1  4      0 42313932    364   9740    0    0  6844     6 2211  765  0 
  0 93  6  0
  0  5      0 41600312    364   9740    0    0 126161     6 8847 7009  2 
  1 89  8  0
  1  0      0 40934052    372   9744    0    0 141561    20 16966 12097 
  3  1 88  8  0
  0  1      0 40546056    372   9744    0    0 75141     0 4493 3544  2 
  0 91  7  0
  0  5      0 40097548    380   9744    0    0 83139     6 11961 5714  2 
  1 89  8  0
  1  4      0 39235500    380   9744    0    0 162830     0 21207 15579 
  3  1 88  9  0
  1  4      0 36952660    388   9744    0    0 470646     6 73141 48593 
  6  3 77 15  0
  0  5      0 36735288    400   9744    0    0 41452     0 6851 2697  1 
  1 86 13  0
  3  3      0 35785820    408   9744    0    0 134878    10 33292 18313 
  3  1 85 10  0
  1  4      0 35285976    408   9744    0    0 171517     0 9015 5008  1 
  1 85 13  0
  0  1      0 35154040    416   9744    0    0 336041    10 4593 2815  2 
  1 86 12  0
  0  1      0 35145980    416   9744    0    0   309     0 1770  426  0 
  0 94  6  0
  0  1      0 35141268    424   9744    0    0   279     6 1758  412  3 
  0 94  3  0
  0  1      0 35140028    424   9744    0    0   198     0 1715  366  3 
  0 94  3  0
  1  0      0 35138540    432   9744    0    0   240     6 1740  391  3 
  0 94  3  0
  1  0      0 35135688    432   9744    0    0   232     4 1733  388  3 
  0 94  3  0
  0  1      0 35130480    440   9744    0    0   352     6 1795  446  1 
  0 94  5  0
  0  1      0 35127628    444   9744    0    0   375     0 1802  455  0 
  0 94  6  0
  0  1      0 35118576    452   9744    0    0   346    10 1792  446  2 
  0 94  4  0
  0  1      0 35114484    452   9744    0    0   514     0 1872  528  0 
  0 94  6  0
  0  1      0 35111260    460   9744    0    0   329     6 1782  434  0 
  0 94  6  0
procs -----------memory---------- ---swap-- -----io---- --system-- 
-----cpu------
  r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy 
id wa st
  0  1      0 35108408    464   9740    0    0   338     2 1785  438  1 
  0 94  6  0
  0  1      0 35105432    468   9744    0    0   361     7 1800  451  1 
  0 94  6  0
  0  1      0 35102828    476   9744    0    0   326     6 1783  439  0 
  0 94  6  0
  0  1      0 35099852    476   9744    0    0   365     0 1797  450  0 
  0 94  6  0
  0  1      0 35097000    484   9744    0    0   362     6 1800  453  0 
  0 94  6  0
  0  1      0 35094272    484   9744    0    0   371     0 1801  456  1 
  0 94  6  0
  0  1      0 35091172    492   9744    0    0   355     6 1798  452  0 
  0 94  6  0
  0  1      0 35088320    492   9744    0    0   355     0 1792  444  1 
  0 94  6  0
  0  1      0 35085716    500   9744    0    0   346    10 1794  447  1 
  0 94  6  0
  0  1      0 35083112    500   9744    0    0   344     0 1786  441  1 
  0 94  6  0
  0  1      0 35080136    508   9744    0    0   341     6 1789  445  0 
  0 94  6  0
  1  0      0 35077408    508   9744    0    0   345     0 1787  440  0 
  0 94  6  0
  0  1      0 35074556    516   9744    0    0   372    10 1810  462  0 
  0 94  6  0
  0  1      0 35071704    516   9744    0    0   338     0 1785  437  0 
  0 94  6  0
  0  1      0 35069224    524   9744    0    0   306     6 1771  427  1 
  0 94  6  0
  1  0      0 35066992    524   9744    0    0   305     4 1769  423  1 
  0 94  6  0
  0  5      0 35026196    532   9744    0    0 127340     6 3111 3127  2 
  0 89  9  0
  0  1      0 35013052    540   9744    0    0 113392     6 2554 2902  2 
  0 90  8  0
  0  1      0 35010200    540   9744    0    0 16826     0 1854  891  1 
  0 94  6  0
  0  1      0 35005860    548   9744    0    0 28107     6 2006 1215  0 
  0 93  7  0
  0  5      0 34971388    548   9744    0    0 82062     4 3487 4203  2 
  0 87 10  0
procs -----------memory---------- ---swap-- -----io---- --system-- 
-----cpu------
  r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy 
id wa st
  0  5      0 34900836    556   9744    0    0 395478   433 4399 3190  3 
  1 83 14  0
  0  1      0 34876656    556   9744    0    0 40074     4 2049  765  1 
  0 91  8  0
  0  1      0 34872564    564   9744    0    0   300    10 1696  423  1 
  0 94  5  0
  0  1      0 34869836    564   9744    0    0   334     0 1699  437  1 
  0 94  6  0
  0  1      0 34867480    572   9744    0    0   329     6 1700  434  1 
  0 94  5  0
  0  1      0 34865000    572   9748    0    0   311     0 1693  424  0 
  0 94  6  0

... (after 30 minutes)

1  0      0 34250164    540   9492    0    0     3     8 1619  285  6  0 
94  0  0
  1  0      0 34249920    548   9492    0    0     4     4 1618  288  6 
  0 94  0  0
  1  0      0 34249920    548   9500    0    0     5     2 1617  289  6 
  0 94  0  0
procs -----------memory---------- ---swap-- -----io---- --system-- 
-----cpu------
  r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy 
id wa st
  1  0      0 34249920    556   9500    0    0     4    14 1624  293  6 
  0 94  0  0
  1  0      0 34249796    564   9504    0    0     3     8 1620  286  6 
  0 94  0  0
  1  0      0 34249800    572   9504    0    0     4     6 1619  290  6 
  0 94  0  0
  1  0      0 34249676    580   9504    0    0     5     6 1622  293  6 
  0 94  0  0
  1  0      0 34255388    588   9508    0    0     4     6 1618  289  6 
  0 94  0  0
  1  0      0 34255388    608   9500    0    0    43     9 1624  304  6 
  0 94  0  0
  1  0      0 34255080    616   9692    0    0     4     6 1619  289  6 
  0 94  0  0
  1  0      0 34255080    624   9692    0    0     4    16 1623  288  6 
  0 94  0  0
  1  0      0 34254956    632   9688    0    0     4     8 1619  286  6 
  0 94  0  0
  1  0      0 34254836    640   9692    0    0     3     4 1617  281  6 
  0 94  0  0
  1  0      0 34254836    640   9696    0    0     4     2 1617  285  6 
  0 94  0  0
  1  0      0 34254836    648   9696    0    0     3    10 1620  286  6 
  0 94  0  0
  1  0      0 34254712    656   9700    0    0     5     8 1620  290  6 
  0 94  0  0
  1  0      0 34254716    664   9700    0    0     4     6 1619  286  6 
  0 94  0  0

==========x8

8x========== strace output for
# nohup strace -p 16623 -ttt -T > strace.out 2>&1 &

1326216486.322990 pread(4, 
"BMAP\0\0\0\376\0\0\0\0r\\\310@\0\0\0\0\v\367\342\271\0\0\0BQ\33j\0"..., 
4096, 7859072671744) = 4096 <0.010081>
1326216487.813946 mprotect(0x7fe40cfe7000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000028>
1326216487.814068 pread(4, 
"BMAP\0\0\0\260\0\0\0\0r]T\242\0\0\0\0r]\323O\0\0\0BQ\270f\0"..., 4096, 
822455537664) = 4096 <0.017904>
1326216488.866388 mprotect(0x7fe40cfe8000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000023>
1326216488.866519 pread(4, 
"BMAP\0\0\0\376\0\0\0\0\v\367\342\271\0\0\0\0r]t\317\0\0\0BR\35\350\0"..., 
4096, 7859205500928) = 4096 <0.009517>
1326216490.356207 mprotect(0x7fe40cfe9000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000033>
1326216490.356330 pread(4, 
"BMAP\0\0\0\376\0\0\0\0r]\323O\0\0\0\0ri\357\305\0\0\0BS\301\300\0"..., 
4096, 7859106410496) = 4096 <0.010006>
1326216491.846474 mprotect(0x7fe40cfea000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000030>
1326216491.846590 pread(4, 
"BMAP\0\0\0\201\0\0\0\0r]t\317\0\0\0\0rj'\7\0\0\0Bl\321j\0"..., 4096, 
7862456569856) = 4096 <0.012849>
1326216492.611395 mprotect(0x7fe40cfeb000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000032>
1326216492.611518 pread(4, 
"BMAP\0\0\0\200\0\0\0\0ri\357\305\0\0\0\0\v\371R\374\0\0\0Bm\236f\0"..., 
4096, 7862514511872) = 4096 <0.011286>
1326216493.369264 mprotect(0x7fe40cfec000, 8192, PROT_READ|PROT_WRITE) = 
0 <0.000028>
1326216493.369388 pread(4, 
"BMAP\0\0\0\376\0\0\0\0rj'\7\0\0\0\0\v\371\220\230\0\0\0Bm\351N\0"..., 
4096, 822841688064) = 4096 <0.014758>
1326216494.873466 mprotect(0x7fe40cfee000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000030>
1326216494.873586 pread(4, 
"BMAP\0\0\0\223\0\0\0\0\v\371R\374\0\0\0\0\v\372#\237\0\0\0BnqT\0"..., 
4096, 822906290176) = 4096 <0.011972>
1326216495.742900 mprotect(0x7fe40cfef000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000031>
1326216495.743018 pread(4, 
"BMAP\0\0\0\376\0\0\0\0\v\371\220\230\0\0\0\0\v\371\315\370\0\0\0Bn\316V\0"..., 
4096, 823060459520) = 4096 <0.014324>
1326216497.238220 mprotect(0x7fe40cff0000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000032>
1326216497.238347 pread(4, 
"BMAP\0\0\0\204\0\0\0\0\v\372#\237\0\0\0\0\v\372\357I\0\0\0Bom \0"..., 
4096, 822970646528) = 4096 <0.014281>
1326216498.022466 mprotect(0x7fe40cff1000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000032>
1326216498.022584 pread(4, 
"BMAP\0\1\0\376\0\0\0\0r\21N=\0\0\0\0\f\200+\217\0\0\0\0!7\347S"..., 
4096, 823104323584) = 4096 <0.011951>
1326216498.034632 mprotect(0x7fe40cff2000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000023>
1326216498.034712 pread(4, 
"BMAP\0\0\0\210\0\0\0\0\v\371\315\370\0\0\0\0\v\372Ms\0\0\0Bo\316\246\0"..., 
4096, 823274016768) = 4096 <0.015055>
1326216498.843386 mprotect(0x7fe40cff3000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000033>
1326216498.843504 pread(4, 
"BMAP\0\0\0\376\0\0\0\0\v\372\357I\0\0\0\0\v\372\225c\0\0\0Bp'4\0"..., 
4096, 823104319488) = 4096 <0.015296>
1326216500.339933 mprotect(0x7fe40cff4000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000022>
1326216500.340026 pread(4, 
"BMAP\0\0\0\201\0\0\0\0\v\372Ms\0\0\0\0rjU\251\0\0\0Bp\312\24\0"..., 
4096, 823179751424) = 4096 <0.009657>
1326216501.101929 mprotect(0x7fe40cff5000, 8192, PROT_READ|PROT_WRITE) = 
0 <0.000029>
1326216501.102049 pread(4, 
"BMAP\0\0\0\201\0\0\0\0\v\372\225c\0\0\0\0\v\372\320<\0\0\0Bq\23\244\0"..., 
4096, 7862563409920) = 4096 <0.016088>
1326216501.871373 mprotect(0x7fe40cff7000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000030>
1326216501.871494 pread(4, 
"BMAP\0\0\0\376\0\0\0\0rjU\251\0\0\0\0\v\373\20\341\0\0\0BqG\200\0"..., 
4096, 823241457664) = 4096 <0.010275>
1326216503.364635 mprotect(0x7fe40cff8000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000031>
1326216503.364755 pread(4, 
"BMAP\0\0\0\200\0\0\0\0\v\372\320<\0\0\0\0\v\373\355\360\0\0\0Bq\303\242\0"..., 
4096, 823309242368) = 4096 <0.016705>
1326216504.128107 mprotect(0x7fe40cff9000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000028>
1326216504.128232 pread(4, 
"BMAP\0\0\0\236\0\0\0\0\v\373\20\341\0\0\0\0\v\373f\25\0\0\0Br\37D\0"..., 4096, 
823541039104) = 4096 <0.017153>
1326216505.076279 mprotect(0x7fe40cffa000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000033>
1326216505.076395 pread(4, 
"BMAP\0\0\0\376\0\0\0\0\v\373\355\360\0\0\0\0\v\373\246i\0\0\0Br|\246\0"..., 
4096, 823398584320) = 4096 <0.017912>
1326216506.576563 mprotect(0x7fe40cffb000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000031>
1326216506.576682 pread(4, 
"BMAP\0\0\0\220\0\0\0\0\v\373f\25\0\0\0\0\v\374\1774\0\0\0Bs!H\0"..., 
4096, 823466037248) = 4096 <0.011574>
1326216507.429031 mprotect(0x7fe40cffc000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000033>
1326216507.429174 pread(4, 
"BMAP\0\0\0\303\0\0\0\0\v\373\246i\0\0\0\0\v\373\357/\0\0\0Bs~\346\0"..., 4096, 
823693361152) = 4096 <0.014163>
1326216508.580628 mprotect(0x7fe40cffd000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000029>
1326216508.580747 pread(4, 
"BMAP\0\0\0\376\0\0\0\0\v\374\1774\0\0\0\0\v\3746\372\0\0\0Bs\361P\0"..., 4096, 
823542345728) = 4096 <0.018541>
1326216510.081415 mprotect(0x7fe40cffe000, 8192, PROT_READ|PROT_WRITE) = 
0 <0.000029>
1326216510.081540 pread(4, 
"BMAP\0\0\0\235\0\0\0\0\v\373\357/\0\0\0\0\v\375&\346\0\0\0Bt\212b\0"..., 4096, 
823617626112) = 4096 <0.014412>
1326216511.012066 mprotect(0x7fe40d000000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000033>
1326216511.012190 pread(4, 
"BMAP\0\0\0\313\0\0\0\0\v\3746\372\0\0\0\0\v\374t\263\0\0\0Bt\312\24\0"..., 
4096, 823869202432) = 4096 <0.011888>
1326216512.208978 mprotect(0x7fe40d001000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000030>
1326216512.209100 pread(4, 
"BMAP\0\0\0\376\0\0\0\0\v\375&\346\0\0\0\0\v\374\304\346\0\0\0Bu9,\0"..., 4096, 
823682347008) = 4096 <0.015123>
1326216513.706751 mprotect(0x7fe40d002000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000032>
1326216513.706873 pread(4, 
"BMAP\0\0\0\237\0\0\0\0\v\374t\263\0\0\0\0\v\375\255\0\0\0\0Bu\257\354\0"..., 
4096, 823766441984) = 4096 <0.015348>
1326216514.650434 mprotect(0x7fe40d003000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000027>
1326216514.650554 pread(4, 
"BMAP\0\0\0\271\0\0\0\0\v\374\304\346\0\0\0\0\v\375\6\263\0\0\0Bv\f\202\0"..., 
4096, 824009818112) = 4096 <0.008932>
1326216515.739710 mprotect(0x7fe40d004000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000029>
1326216515.739834 pread(4, 
"BMAP\0\0\0\376\0\0\0\0\v\375\255\0\0\0\0\0\211f\332_\0\0\0Bvr\324\0"..., 4096, 
823835439104) = 4096 <0.019711>
1326216517.242497 mprotect(0x7fe40d005000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000031>
1326216517.242618 pread(4, 
"BMAP\0\0\0\214\0\0\0\0\v\375\6\263\0\0\0\0\v\376i\317\0\0\0Bw\32\320\0"..., 
4096, 9442176659456) = 4096 <0.012487>
1326216518.072182 mprotect(0x7fe40d006000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000029>
1326216518.072303 pread(4, 
"BMAP\0\0\0\253\0\0\0\0\211f\332_\0\0\0\0\215\30W\303\0\0\0BwT\254\0"..., 4096, 
824207798272) = 4096 <0.013816>
1326216519.084891 mprotect(0x7fe40d007000, 8192, PROT_READ|PROT_WRITE) = 
0 <0.000031>
1326216519.085008 pread(4, 
"BMAP\0\0\0\376\0\0\0\0\v\376i\317\0\0\0\0\v\375\352p\0\0\0Bw\262d\0"..., 4096, 
9695979646976) = 4096 <0.014198>
1326216520.581764 mprotect(0x7fe40d009000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000030>
1326216520.581881 pread(4, 
"BMAP\0\0\0\177\0\0\0\0\215\30W\303\0\0\0\0rj\230 \0\0\0Bxa\266\0"..., 
4096, 824074240000) = 4096 <0.012057>
1326216521.335842 mprotect(0x7fe40d00a000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000031>
1326216521.335962 pread(4, 
"BMAP\0\0\0\376\0\0\0\0\v\375\352p\0\0\0\0\v\376F\310\0\0\0Bx\253\24\0"..., 
4096, 7862633103360) = 4096 <0.012886>
1326216522.832068 mprotect(0x7fe40d00b000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000029>
1326216522.832189 pread(4, "BMAP\0\0\0\376\0\0\0\0rj\230 
\0\0\0\0\216\261\21\313\0\0\0By\351\0\0"..., 4096, 824171069440) = 4096 
<0.015956>
1326216524.331849 mprotect(0x7fe40d00c000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000033>
1326216524.331975 pread(4, 
"BMAP\0\0\0\376\0\0\0\0\v\376F\310\0\0\0\0\v\377\210\237\0\0\0B{\237\300\0"..., 
4096, 9805696380928) = 4096 <0.012498>
1326216525.828539 mprotect(0x7fe40d00d000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000029>
1326216525.828659 pread(4, 
"BMAP\0\0\0\266\0\0\0\0\216\261\21\313\0\0\0\0rp2:\0\0\0B\206\243:\0"..., 4096, 
824508542976) = 4096 <0.005462>
1326216526.897970 mprotect(0x7fe40d00e000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000031>
1326216526.898094 pread(4, 
"BMAP\0\0\0\376\0\0\0\0\v\377\210\237\0\0\0\0\f\21.7\0\0\0B\246\324\"\0"..., 
4096, 7864136867840) = 4096 <0.009157>
1326216528.390700 mprotect(0x7fe40d00f000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000028>
1326216528.390822 pread(4, 
"BMAP\0\0\0\203\0\0\0\0rp2:\0\0\0\0\f\22\240\370\0\0\0B\252\332\22\0"..., 4096, 
829245583360) = 4096 <0.014973>
1326216529.171630 mprotect(0x7fe40d010000, 8192, PROT_READ|PROT_WRITE) = 
0 <0.000032>
1326216529.171750 pread(4, 
"BMAP\0\0\0\234\0\0\0\0\f\21.7\0\0\0\0\f\22%?\0\0\0B\253\2174\0"..., 
4096, 829634347008) = 4096 <0.012732>
1326216530.095737 mprotect(0x7fe40d012000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000032>
1326216530.095856 pread(4, 
"BMAP\0\0\0\376\0\0\0\0\f\22\240\370\0\0\0\0\f\23\243\232\0\0\0B\254g\360\0"..., 
4096, 829504614400) = 4096 <0.017642>
1326216531.597565 mprotect(0x7fe40d013000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000031>
1326216531.597683 pread(4, 
"BMAP\0\0\0\261\0\0\0\0\f\22%?\0\0\0\0\f\23\301\353\0\0\0B\255\263\212\0"..., 
4096, 829905543168) = 4096 <0.012275>
1326216532.644040 mprotect(0x7fe40d014000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000030>
1326216532.644162 pread(4, 
"BMAP\0\0\0\210\0\0\0\0\f\23\243\232\0\0\0\0\f\22\374\322\0\0\0B\256\202\24\0"..., 
4096, 829937332224) = 4096 <0.011165>
1326216533.450555 mprotect(0x7fe40d015000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000027>
1326216533.450677 pread(4, 
"BMAP\0\0\0\376\0\0\0\0\f\23\301\353\0\0\0\0\f\24>\245\0\0\0B\257]\6\0"..., 
4096, 829730660352) = 4096 <0.011231>
1326216534.946533 mprotect(0x7fe40d016000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000032>
1326216534.946653 pread(4, 
"BMAP\0\0\0\264\0\0\0\0\f\22\374\322\0\0\0\0\f\26\230!\0\0\0B\261\226\330\0"..., 
4096, 830068117504) = 4096 <0.011953>
1326216536.010196 mprotect(0x7fe40d017000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000028>
1326216536.010308 pread(4, 
"BMAP\0\0\0\376\0\0\0\0\f\24>\245\0\0\0\0\f\26<\246\0\0\0B\262\371R\0"..., 
4096, 830698819584) = 4096 <0.014615>
1326216537.509542 mprotect(0x7fe40d018000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000030>
1326216537.509665 pread(4, 
"BMAP\0\0\0\177\0\0\0\0\f\26\230!\0\0\0\0\f\30\32\36\0\0\0B\264\2260\0"..., 
4096, 830602895360) = 4096 <0.016656>
1326216538.268615 mprotect(0x7fe40d019000, 8192, PROT_READ|PROT_WRITE) = 
0 <0.000033>
1326216538.268743 pread(4, 
"BMAP\0\0\0\376\0\0\0\0\f\26<\246\0\0\0\0\f\0306\336\0\0\0B\265f\n\0"..., 4096, 
831103557632) = 4096 <0.015820>
1326216539.777465 mprotect(0x7fe40d01b000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000032>
1326216539.777582 pread(4, 
"BMAP\0\0\0\220\0\0\0\0\f\30\32\36\0\0\0\0\f\34\312\215\0\0\0B\267C^\0"..., 
4096, 831133704192) = 4096 <0.018219>
1326216540.637506 mprotect(0x7fe40d01c000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000030>
1326216540.637626 pread(4, 
"BMAP\0\0\0\311\0\0\0\0\f\0306\336\0\0\0\0rp\216\374\0\0\0B\270sV\0"..., 
4096, 832362303488) = 4096 <0.011067>
1326216541.823721 mprotect(0x7fe40d01d000, 4096, PROT_READ|PROT_WRITE) = 
0 <0.000030>
1326216541.823839 pread(4, 
"BMAP\0\0\0\376\0\0\0\0\f\34\312\215\0\0\0\0rp\302F\0\0\0B\271\320,\0"..., 
4096, 7864234131456) = 4096 <0.015157>


==========x8

[root at jr4-4 ~]# uname -r
2.6.32.41.scalable


Let me know if you need anything else.

> Cheers,
>
> Dave.


-- 
Joseph Landman, Ph.D
Founder and CEO
Scalable Informatics Inc.
email: landman at scalableinformatics.com
web  : http://scalableinformatics.com
        http://scalableinformatics.com/sicluster
phone: +1 734 786 8423 x121
fax  : +1 866 888 3112
cell : +1 734 612 4615




More information about the xfs mailing list