<font size="2">
<p dir="ltr">Dear all,</p>
<p dir="ltr">Not realy sure whether this is bug or not, but we found that sometimes OCFS2 on our system do journaling a lot. </p>
<p dir="ltr">(Please see screen shot below)</p>
<p dir="ltr">As you can see, the IO was jumped from 111 w/s to 11,960 w/s , IO utilize jumped from 1.5% to 97% , %iowait jumped from 0.25% to 10.94%.</p>
<p dir="ltr">It will not come into question, if this happen in short time period (eg. 1-2 sec.) , but sometimes we found this persist for half an hour or even more. </p>
<p dir="ltr">Is this normal for OCFS2 or not ? How could I tune OCFS2 to avoid the above situation.</p>
<p dir="ltr">We also suspect the relation of this symptom with another problem similar to <a href="http://oss.oracle.com/pipermail/ocfs2-users/2009-January/003250.html">http://oss.oracle.com/pipermail/ocfs2-users/2009-January/003250.html</a> , because we found OCFS2 file system pause for a long period of time too ( 5-20 Sec. on open for write). Those scattered happen all day with more frequence during highload time. (Screen shot below)</p>
<p dir="ltr">Our configuration is 3 web servers connect to HP SAN Storage using OCFS2 1.4.7. Amongst those 3 servers , there are 2 for reading data and 1 for writing data (traffic seperate at proxy layer) . The symptom above happen on data writing server.</p>
<p dir="ltr">Thank you.</p>
<p dir="ltr">Wanchat Padungrat</p>
<p dir="ltr">PS. We keep our service by reinstall the whole data every month, without doing whole data copy (consumed 12 hours), the symptom getting worse an worse eg. journaling persist longer , file system pause longer (sometimes more than a minute !!) ... which affect the whole system , such as, too many waiting apache process, lavg going skyrocket(sometimes 400+) and cannot recover itself etc. .</p>
<p dir="ltr"> </p>
<p dir="ltr">Screen shot</p>
<p dir="ltr">-----------------</p>
<p dir="ltr">-----------------------------------------------------------------------------</p>
<p dir="ltr">Here is iostat+top during journaling process running.</p>
<p dir="ltr">-----------------------------------------------------------------------------</p>
<p dir="ltr">avg-cpu: %user %nice %system %iowait %steal %idle</p>
<p dir="ltr">1.88 0.00 5.38 10.94 0.00 81.81</p>
<p dir="ltr">Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util</p>
<p dir="ltr">sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00</p>
<p dir="ltr">sda1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00</p>
<p dir="ltr">sda2 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00</p>
<p dir="ltr">sdb 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00</p>
<p dir="ltr">sdb1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00</p>
<p dir="ltr">sdc 0.00 5156.00 5.00 6804.50 19.00 47892.25 14.07 9.76 1.43 0.14 97.55</p>
<p dir="ltr">sdc1 0.00 5156.00 5.00 6804.50 19.00 47892.25 14.07 9.76 1.43 0.14 97.60</p>
<p dir="ltr">sdd 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00</p>
<p dir="ltr">sdd1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00</p>
<p dir="ltr">sde 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00</p>
<p dir="ltr">sde1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00</p>
<p dir="ltr">dm-0 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00</p>
<p dir="ltr">dm-1 0.00 0.00 5.00 11960.00 19.00 47838.25 8.00 13.65 1.14 0.08 97.25 </p>
<p dir="ltr">dm-2 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00</p>
<p dir="ltr">dm-3 0.00 0.00 5.00 11960.00 19.00 47838.25 8.00 13.66 1.14 0.08 97.30</p>
<p dir="ltr">-------------------------------------------------------------------------------------------</p>
<p dir="ltr">Tasks: 215 total, 2 running, 213 sleeping, 0 stopped, 0 zombie</p>
<p dir="ltr">Cpu(s): 2.5%us, 3.6%sy, 0.0%ni, 81.9%id, 10.9%wa, 0.0%hi, 1.1%si, 0.0%st</p>
<p dir="ltr">Mem: 12298636k total, 11783892k used, 514744k free, 1679156k buffers</p>
<p dir="ltr">Swap: 2048276k total, 396k used, 2047880k free, 6149700k cached</p>
<p dir="ltr">PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND </p>
<p dir="ltr">3416 root 10 -5 0 0 0 S 5.7 0.0 473:10.53 o2net </p>
<p dir="ltr">10034 httpd 16 0 192m 18m 2476 D 3.7 0.2 0:43.44 httpd </p>
<p dir="ltr">16119 httpd 16 0 190m 16m 2200 S 3.7 0.1 0:25.65 httpd </p>
<p dir="ltr">6660 root 10 -5 0 0 0 D 3.3 0.0 39:15.14 ocfs2cmt <--- Journaling </p>
<p dir="ltr">20840 httpd 16 0 191m 16m 2168 D 3.3 0.1 0:14.99 httpd </p>
<p dir="ltr">6659 root 10 -5 0 0 0 S 3.0 0.0 34:32.57 kjournald <--- Journaling </p>
<p dir="ltr">14282 httpd 16 0 190m 16m 2240 D 2.7 0.1 0:29.31 httpd </p>
<p dir="ltr">6656 root 11 -5 0 0 0 S 1.7 0.0 79:21.05 dlm_thread </p>
<p dir="ltr">17159 httpd 16 0 190m 16m 2240 D 1.7 0.1 0:24.06 httpd </p>
<p dir="ltr">14718 httpd 16 0 192m 18m 2408 D 1.3 0.2 0:28.30 httpd </p>
<p dir="ltr">6655 root 10 -5 0 0 0 S 1.0 0.0 12:02.41 ocfs2dc </p>
<p dir="ltr">10041 httpd 16 0 192m 18m 2252 R 1.0 0.2 0:41.68 httpd </p>
<p dir="ltr">14227 httpd 16 0 191m 17m 2248 D 1.0 0.1 0:29.96 httpd </p>
<p dir="ltr">14246 httpd 16 0 194m 20m 2236 D 1.0 0.2 0:30.14 httpd </p>
<p dir="ltr">19852 httpd 16 0 191m 16m 2160 D 1.0 0.1 0:16.72 httpd </p>
<p dir="ltr">25976 httpd 16 0 191m 16m 2148 D 1.0 0.1 0:05.45 httpd </p>
<p dir="ltr">6658 root 11 -5 0 0 0 S 0.7 0.0 86:50.46 dlm_wq </p>
<p dir="ltr">7387 httpd 16 0 201m 27m 2284 D 0.7 0.2 0:49.53 httpd </p>
<p dir="ltr">9843 httpd 16 0 191m 17m 2288 D 0.7 0.1 0:40.68 httpd </p>
<p dir="ltr">-------------------------------------------------------------------------------------------</p>
<p dir="ltr">Here is iostat+top during journaling process sleep (normal run).</p>
<p dir="ltr">-------------------------------------------------------------------------------------------</p>
<p dir="ltr">avg-cpu: %user %nice %system %iowait %steal %idle</p>
<p dir="ltr">3.00 0.00 2.31 0.25 0.00 94.44</p>
<p dir="ltr">Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util</p>
<p dir="ltr">sda 0.00 26.00 0.00 10.50 0.00 146.00 27.81 0.13 12.05 1.38 1.45</p>
<p dir="ltr">sda1 0.00 26.00 0.00 10.50 0.00 146.00 27.81 0.13 12.05 1.38 1.45</p>
<p dir="ltr">sda2 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00</p>
<p dir="ltr">sdb 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00</p>
<p dir="ltr">sdb1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00</p>
<p dir="ltr">sdc 0.00 80.50 3.00 31.00 11.00 444.25 26.78 0.05 1.41 0.46 1.55</p>
<p dir="ltr">sdc1 0.00 80.50 3.00 31.00 11.00 444.25 26.78 0.05 1.41 0.46 1.55</p>
<p dir="ltr">sdd 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00</p>
<p dir="ltr">sdd1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00</p>
<p dir="ltr">sde 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00</p>
<p dir="ltr">sde1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00</p>
<p dir="ltr">dm-0 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00</p>
<p dir="ltr">dm-1 0.00 0.00 3.00 111.50 11.00 444.25 7.95 0.13 1.10 0.14 1.55</p>
<p dir="ltr">dm-2 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00</p>
<p dir="ltr">dm-3 0.00 0.00 3.00 111.50 11.00 444.25 7.95 0.13 1.11 0.14 1.55</p>
<p dir="ltr">-------------------------------------------------------------------------------------------</p>
<p dir="ltr">top - 15:44:49 up 12 days, 2:21, 1 user, load average: 0.72, 9.27, 15.66</p>
<p dir="ltr">Tasks: 215 total, 1 running, 214 sleeping, 0 stopped, 0 zombie</p>
<p dir="ltr">Cpu(s): 2.2%us, 1.0%sy, 0.0%ni, 96.0%id, 0.2%wa, 0.0%hi, 0.5%si, 0.0%st</p>
<p dir="ltr">Mem: 12298636k total, 11832348k used, 466288k free, 1688052k buffers</p>
<p dir="ltr">Swap: 2048276k total, 396k used, 2047880k free, 6215116k cached</p>
<p dir="ltr">PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND </p>
<p dir="ltr">26088 httpd 16 0 189m 15m 2152 S 4.0 0.1 0:11.31 httpd </p>
<p dir="ltr">3416 root 11 -5 0 0 0 S 3.3 0.0 474:07.19 o2net </p>
<p dir="ltr">29193 httpd 15 0 191m 17m 2152 S 3.0 0.1 0:05.16 httpd </p>
<p dir="ltr">9842 httpd 15 0 191m 17m 2252 S 2.7 0.1 0:47.80 httpd </p>
<p dir="ltr">14329 httpd 15 0 191m 16m 2240 S 2.7 0.1 0:35.21 httpd </p>
<p dir="ltr">13245 httpd 15 0 190m 16m 2272 S 1.7 0.1 0:37.53 httpd </p>
<p dir="ltr">14719 httpd 16 0 190m 16m 2240 S 1.3 0.1 0:31.97 httpd </p>
<p dir="ltr">6658 root 11 -5 0 0 0 D 1.0 0.0 86:59.26 dlm_wq </p>
<p dir="ltr">10039 httpd 16 0 190m 16m 2328 S 0.7 0.1 0:44.13 httpd </p>
<p dir="ltr">10041 httpd 16 0 191m 17m 2252 S 0.7 0.1 0:46.10 httpd </p>
<p dir="ltr">16120 httpd 15 0 190m 16m 2240 S 0.7 0.1 0:36.17 httpd </p>
<p dir="ltr">6656 root 10 -5 0 0 0 D 0.3 0.0 79:35.89 dlm_thread </p>
<p dir="ltr">9844 httpd 15 0 188m 14m 2260 S 0.3 0.1 0:47.96 httpd </p>
<p dir="ltr">9845 httpd 15 0 191m 17m 2292 S 0.3 0.1 0:46.30 httpd </p>
<p dir="ltr">14227 httpd 15 0 192m 18m 2248 S 0.3 0.2 0:35.18 httpd </p>
<p dir="ltr">14232 httpd 15 0 190m 16m 2244 S 0.3 0.1 0:33.24 httpd </p>
<p dir="ltr">14247 httpd 15 0 190m 16m 2164 S 0.3 0.1 0:35.52 httpd </p>
<p dir="ltr">14281 httpd 15 0 189m 15m 2272 S 0.3 0.1 0:36.51 httpd </p>
<p dir="ltr">14327 httpd 15 0 192m 18m 2196 S 0.3 0.2 0:35.16 httpd </p>
<p dir="ltr">14331 httpd 15 0 190m 16m 2240 S 0.3 0.1 0:33.99 httpd </p>
<p dir="ltr"> </p>
<p dir="ltr">-------------------------------------------------------------------------------------------</p>
<p dir="ltr">Lag on open file for write shown by strace simple cp command, </p>
<p dir="ltr">the symptom appear at bottom of the list </p>
<p dir="ltr">------------------------------------------------------------------------------------------</p>
<p dir="ltr">[root@cafe4 wanchat-san1]# strace -T cp source_file destiantion_file</p>
<p dir="ltr"></p>
<p dir="ltr">execve("/bin/cp", ["cp", "source_file", "destiantion_file"], [/* 22 vars */]) = 0 <0.000210></p>
<p dir="ltr">brk(0) = 0x2347000 <0.000006></p>
<p dir="ltr">mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2b6d685af000 <0.000006></p>
<p dir="ltr">uname({sys="Linux", node="<a href="http://cafe4.pantip.com">cafe4.pantip.com</a>", ...}) = 0 <0.000006></p>
<p dir="ltr">access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) <0.000008></p>
<p dir="ltr">open("/etc/ld.so.cache", O_RDONLY) = 3 <0.000009></p>
<p dir="ltr">fstat(3, {st_mode=S_IFREG|0644, st_size=63180, ...}) = 0 <0.000006></p>
<p dir="ltr">mmap(NULL, 63180, PROT_READ, MAP_PRIVATE, 3, 0) = 0x2b6d685b0000 <0.000010></p>
<p dir="ltr">close(3) = 0 <0.000007></p>
<p dir="ltr">open("/lib64/libacl.so.1", O_RDONLY) = 3 <0.000013></p>
<p dir="ltr">read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\31`\0379\0\0\0"..., 832) = 832 <0.000008></p>
<p dir="ltr">fstat(3, {st_mode=S_IFREG|0755, st_size=28008, ...}) = 0 <0.000020></p>
<p dir="ltr">mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2b6d685c0000 <0.000008></p>
<p dir="ltr">mmap(0x391f600000, 2120992, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x391f600000 <0.000010></p>
<p dir="ltr">mprotect(0x391f606000, 2093056, PROT_NONE) = 0 <0.000012></p>
<p dir="ltr">mmap(0x391f805000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x5000) = 0x391f805000 <0.000007></p>
<p dir="ltr">close(3) = 0 <0.000005></p>
<p dir="ltr">open("/lib64/libselinux.so.1", O_RDONLY) = 3 <0.000007></p>
<p dir="ltr">read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0`E\240\0369\0\0\0"..., 832) = 832 <0.000006></p>
<p dir="ltr">fstat(3, {st_mode=S_IFREG|0755, st_size=95464, ...}) = 0 <0.000005></p>
<p dir="ltr">mmap(0x391ea00000, 2192784, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x391ea00000 <0.000007></p>
<p dir="ltr">mprotect(0x391ea15000, 2097152, PROT_NONE) = 0 <0.000007></p>
<p dir="ltr">mmap(0x391ec15000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x15000) = 0x391ec15000 <0.000011></p>
<p dir="ltr">mmap(0x391ec17000, 1424, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x391ec17000 <0.000010></p>
<p dir="ltr">close(3) = 0 <0.000007></p>
<p dir="ltr">open("/lib64/libattr.so.1", O_RDONLY) = 3 <0.000012></p>
<p dir="ltr">read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\320\17 \0369\0\0\0"..., 832) = 832 <0.000007></p>
<p dir="ltr">fstat(3, {st_mode=S_IFREG|0755, st_size=17888, ...}) = 0 <0.000005></p>
<p dir="ltr">mmap(0x391e200000, 2110728, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x391e200000 <0.000007></p>
<p dir="ltr">mprotect(0x391e204000, 2093056, PROT_NONE) = 0 <0.000011></p>
<p dir="ltr">mmap(0x391e403000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3000) = 0x391e403000 <0.000012></p>
<p dir="ltr">close(3) = 0 <0.000007></p>
<p dir="ltr">open("/lib64/libc.so.6", O_RDONLY) = 3 <0.000012></p>
<p dir="ltr">read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220\332!\0359\0\0\0"..., 832) = 832 <0.000009></p>
<p dir="ltr">fstat(3, {st_mode=S_IFREG|0755, st_size=1717800, ...}) = 0 <0.000005></p>
<p dir="ltr">mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2b6d685c1000 <0.000009></p>
<p dir="ltr">mmap(0x391d200000, 3498328, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x391d200000 <0.000009></p>
<p dir="ltr">mprotect(0x391d34d000, 2097152, PROT_NONE) = 0 <0.000009></p>
<p dir="ltr">mmap(0x391d54d000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x14d000) = 0x391d54d000 <0.000011></p>
<p dir="ltr">mmap(0x391d552000, 16728, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x391d552000 <0.000014></p>
<p dir="ltr">close(3) = 0 <0.000005></p>
<p dir="ltr">open("/lib64/libdl.so.2", O_RDONLY) = 3 <0.000012></p>
<p dir="ltr">read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\20\16`\0359\0\0\0"..., 832) = 832 <0.000008></p>
<p dir="ltr">fstat(3, {st_mode=S_IFREG|0755, st_size=23360, ...}) = 0 <0.000007></p>
<p dir="ltr">mmap(0x391d600000, 2109696, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x391d600000 <0.000009></p>
<p dir="ltr">mprotect(0x391d602000, 2097152, PROT_NONE) = 0 <0.000007></p>
<p dir="ltr">mmap(0x391d802000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x391d802000 <0.000007></p>
<p dir="ltr">close(3) = 0 <0.000005></p>
<p dir="ltr">open("/lib64/libsepol.so.1", O_RDONLY) = 3 <0.000009></p>
<p dir="ltr">read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0=`\0369\0\0\0"..., 832) = 832 <0.000006></p>
<p dir="ltr">fstat(3, {st_mode=S_IFREG|0755, st_size=247496, ...}) = 0 <0.000005></p>
<p dir="ltr">mmap(0x391e600000, 2383136, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x391e600000 <0.000006></p>
<p dir="ltr">mprotect(0x391e63b000, 2097152, PROT_NONE) = 0 <0.000007></p>
<p dir="ltr">mmap(0x391e83b000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3b000) = 0x391e83b000 <0.000008></p>
<p dir="ltr">mmap(0x391e83c000, 40224, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x391e83c000 <0.000007></p>
<p dir="ltr">close(3) = 0 <0.000005></p>
<p dir="ltr">mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2b6d685c2000 <0.000005></p>
<p dir="ltr">mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2b6d685c3000 <0.000005></p>
<p dir="ltr">arch_prctl(ARCH_SET_FS, 0x2b6d685c2f90) = 0 <0.000005></p>
<p dir="ltr">mprotect(0x391d54d000, 16384, PROT_READ) = 0 <0.000007></p>
<p dir="ltr">mprotect(0x391d802000, 4096, PROT_READ) = 0 <0.000006></p>
<p dir="ltr">mprotect(0x391d01b000, 4096, PROT_READ) = 0 <0.000005></p>
<p dir="ltr">munmap(0x2b6d685b0000, 63180) = 0 <0.000010></p>
<p dir="ltr">access("/etc/selinux/", F_OK) = 0 <0.000007></p>
<p dir="ltr">brk(0) = 0x2347000 <0.000005></p>
<p dir="ltr">brk(0x2368000) = 0x2368000 <0.000005></p>
<p dir="ltr">open("/etc/selinux/config", O_RDONLY) = 3 <0.000013></p>
<p dir="ltr">fstat(3, {st_mode=S_IFREG|0644, st_size=511, ...}) = 0 <0.000005></p>
<p dir="ltr">mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2b6d685b0000 <0.000005></p>
<p dir="ltr">read(3, "# This file controls the state o"..., 4096) = 511 <0.000009></p>
<p dir="ltr">read(3, "", 4096) = 0 <0.000006></p>
<p dir="ltr">close(3) = 0 <0.000006></p>
<p dir="ltr">munmap(0x2b6d685b0000, 4096) = 0 <0.000008></p>
<p dir="ltr">open("/proc/mounts", O_RDONLY) = 3 <0.000033></p>
<p dir="ltr">fstat(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 <0.000005></p>
<p dir="ltr">mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2b6d685b0000 <0.000005></p>
<p dir="ltr">read(3, "rootfs / rootfs rw 0 0\n/dev/root"..., 4096) = 667 <0.000041></p>
<p dir="ltr">read(3, "", 4096) = 0 <0.000005></p>
<p dir="ltr">close(3) = 0 <0.000006></p>
<p dir="ltr">munmap(0x2b6d685b0000, 4096) = 0 <0.000007></p>
<p dir="ltr">open("/proc/filesystems", O_RDONLY) = 3 <0.000011></p>
<p dir="ltr">read(3, "nodev\tsysfs\nnodev\trootfs\nnodev\tb"..., 4095) = 354 <0.000014></p>
<p dir="ltr">close(3) = 0 <0.000006></p>
<p dir="ltr">open("/usr/lib/locale/locale-archive", O_RDONLY) = 3 <0.000010></p>
<p dir="ltr">fstat(3, {st_mode=S_IFREG|0644, st_size=56471264, ...}) = 0 <0.000005></p>
<p dir="ltr">mmap(NULL, 56471264, PROT_READ, MAP_PRIVATE, 3, 0) = 0x2b6d685c4000 <0.000006></p>
<p dir="ltr">close(3) = 0 <0.000004></p>
<p dir="ltr">geteuid() = 0 <0.000006></p>
<p dir="ltr">stat("destiantion_file", {st_mode=S_IFREG|0644, st_size=1307, ...}) = 0 <0.000013></p>
<p dir="ltr">stat("source_file", {st_mode=S_IFREG|0644, st_size=1307, ...}) = 0 <0.000009></p>
<p dir="ltr">stat("destiantion_file", {st_mode=S_IFREG|0644, st_size=1307, ...}) = 0 <0.000008></p>
<p dir="ltr">open("source_file", O_RDONLY) = 3 <0.000022></p>
<p dir="ltr">fstat(3, {st_mode=S_IFREG|0644, st_size=1307, ...}) = 0 <0.000005></p>
<p dir="ltr">open("destiantion_file", O_WRONLY|O_TRUNC) = 4 <8.159196> <------ 8 Sec ! During normal condition 0.000034</p>
<p dir="ltr">fstat(4, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0 <0.000008></p>
<p dir="ltr">fstat(3, {st_mode=S_IFREG|0644, st_size=1307, ...}) = 0 <0.000007></p>
<p dir="ltr">read(3, "Linux 2.6.18-194.3.1.el5 (cafe4."..., 4096) = 1307 <0.000012></p>
<p dir="ltr">write(4, "Linux 2.6.18-194.3.1.el5 (cafe4."..., 1307) = 1307 <0.003315></p>
<p dir="ltr">read(3, "", 4096) = 0 <0.000010></p>
<p dir="ltr">close(4) = 0 <0.000006></p>
<p dir="ltr">close(3) = 0 <0.000007></p>
<p dir="ltr">close(1) = 0 <0.000005></p>
<p dir="ltr">exit_group(0) = ?</p></font>