| Oracle FAQ | Your Portal to the Oracle Knowledge Grid | |
 |
 | |||
| Oracle FAQ | Your Portal to the Oracle Knowledge Grid | |
|
| |||
Home -> Community -> Mailing Lists -> Oracle-L -> Re: Timed_statistics : Why so many getrusage syscall via truss/strace output?
Hi,
I think I get it. Timed_statistics does have much impact on SYSTEM CALLS. But as system calls CPU utilization is just part of total CPU that the process consumes(more of them are user calls), so, when timed statistics is on, system call increased about 40-50% increasement,but the total CPU used by this session does not change significantly. I did not notice that strace/truss only printed system call and its cpu utilization,but there is also a line talking about "user time". I did this test first on linux and linux strace does not print the "user time" part.For compare,I did another truss on solaris and found the same result, but not seeing the user time part. Thanks, seems doubt solved:)
sys totals: 3.87 70798 747 usr time: 21.57 elapsed: 233.47
My impression is, Oracle collects *ALL* statistics anyway. Enabling timed_statistics just enable writes to the v$views which is all in memory. The overhead is different from version to version. The last I remembered reading about 8i was the overhead is 2.5% to 5% where in 716, it was slightly higher.
But I dont think it was ever more than 10% in any version.
Back in the old days, a lot of people said it is 15% - 20% but it was all mis-conceptions about Oracle.
One thing I am almost positive is, Oracle collects them anyway. The only difference is whether it populates the v$ views.
NOw, turning on OS_timed_statistics is probably expensive. But I don't have a number. Almost no site that I know turns this one on.
-----Original Message-----
Sent: Friday, November 14, 2003 1:30 AM
To: ORACLE-L_at_fatcity.com
Cc: Chorng, Bass; Yong Huang; Jack; Tai, Hubert
Hi:
I happeded to use strace to trace system call of an oracle process and suprised to find that it used so many getrusage/gettimeofday/times system call than I can imagine.
Is it because of timed_statistics or Oracle itself used so many to maintain its v$ views? From the result, it used 50%+ of the CPU that process consumes.
I tried to set timed_statistics in one running session to false and did another strace,and there is nearly no getrusage at all! Does it mean that timed_statistics caused 40%+ resource utilization?
>>default, with timed_statistics = true;
[oracle_at_rac1 oracle]$ strace -c -p 26798 (Linux AS2.1)
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
41.87 2.025445 899 2254 read
40.73 1.970439 7 266948 getrusage
13.72 0.663586 4 159727 gettimeofday
3.63 0.175616 23 7596 write
0.03 0.001389 198 7 munmap
0.02 0.000880 73 12 old_mmap
0.00 0.000070 70 1 semctl
------ ----------- ----------- --------- --------- ----------------
100.00 4.837425 436545 total
[oracle_at_rac1 sync]$ strace -c -p 22161
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ---------------- 94.15 0.509831 740 689 read 3.57 0.019323 5 4232 gettimeofday--Still this system call 2.28 0.012367 14 887 write ------ ----------- ----------- --------- --------- ---------------- 100.00 0.541521 5808 total
<<Solaris 8/oracle 817/Timed_statistics = true;>> [oracle_at_main-db1 oracle]$ truss -c -p 6107
^Csyscall seconds calls errors
read .86 14496
write 1.37 19638
lseek .02 1031
times 1.12 31851
semctl .00 2
semop .00 2
sigprocmask .00 8
getcontext .00 2
yield .01 317
setitimer .00 4
lwp_mutex_wakeup .01 29
lwp_mutex_lock .01 110
lwp_cond_wait .01 837
lwp_cond_signal .20 794
pread .01 151
pwrite .00 643
kaio .25 815 747
kaio .00 68
------- ------ ----
sys totals: 3.87 70798 747
usr time: 21.57
elapsed: 233.47
[oracle_at_main-db1 oracle]$ sqlplus internal
17:31:12 SQL> @whoisit
Enter value for spid: 6107
old 3: select addr from v$process where spid in(&spid))
new 3: select addr from v$process where spid in(6107))
SID SERIAL# USERNAME OSUSER MACHINE PROGRAM PROCESS TO_CHAR(LOGON_TIME,
---------- ---------- ------------------------------ ------------------------------ ------------------------------ ---------------------------------------- --------- -------------------
298 8491 BIDDER store appg ? @appg (TNS V1-V3) 18818 2003/10/31 16:04:01
17:31:37 SQL> exec dbms_system.set_BOOL_PARAM_IN_SESSION(298,8491,'TIMED_STATISTICS',false)
<<After change timed_statistics to false and we see few times sys call>> [oracle_at_main-db1 oracle]$ truss -c -p 6107
^Csyscall seconds calls errors
read .51 7779
write .76 10432
lseek .03 552
kill .00 1
semctl .00 1
semop .00 2
sigprocmask .00 8
getcontext .00 2
readv .00 1
yield .00 178
setitimer .00 4
lwp_mutex_wakeup .01 11
lwp_mutex_lock .00 44
lwp_cond_wait .00 446
lwp_cond_signal .08 420
pread .00 97
pwrite .00 324
kaio .19 431 384
kaio .00 47
------- ------ ----
sys totals: 1.58 20780 384
usr time: 12.14
elapsed: 131.92
-- Please see the official ORACLE-L FAQ: http://www.orafaq.net -- Author: zhu chao INET: chao_ping_at_vip.163.com Fat City Network Services -- 858-538-5051 http://www.fatcity.com San Diego, California -- Mailing list and web hosting services --------------------------------------------------------------------- To REMOVE yourself from this mailing list, send an E-Mail message to: ListGuru_at_fatcity.com (note EXACT spelling of 'ListGuru') and in the message BODY, include a line containing: UNSUB ORACLE-L (or the name of mailing list you want to be removed from). You may also send the HELP command for other information (like subscribing).Received on Sun Nov 16 2003 - 19:54:27 CST
 |
 |