Re: sqlplus : 100% CPU usage while connecting to remote DB

On Jun 25, 9:14 am, Krivenok Dmitry <krivenok.dmi..._at_gmail.com> wrote:
> This is a piece of strace output on my system:
>
> ...
> ...
> ...
> read(6, "\337y\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
> 512) = 512
> lseek(6, 1024, SEEK_SET) = 1024
> read(6, "\25\7\'\0072\7>\7j\7\276\17$\'\6K5S\24TfT\307T(VsV\222"...,
> 86) = 86
> brk(0x80af000) = 0x80af000
> times(NULL) = -2058427839
> times(NULL) = -2058427839
> times(NULL) = -2058427839
> times(NULL) = -2058427839
> times(NULL) = -2058427839
> times(NULL) = -2058427839
> times(NULL) = -2058427839
> times(NULL) = -2058427839
> times(NULL) = -2058427839
> times(NULL) = -2058427839
> times(NULL) = -2058427839
> times(NULL) = -2058427839
> times(NULL) = -2058427839
> times(NULL) = -2058427839
> times(NULL) = -2058427839
> ...
> ...
> ...
>
> Compare it with another strace output (from another server where
> connection with MTT is established successfuly):
>
> ...
> ...
> ...
> open("/usr/local/oracle/app/oracle/product/10.2.0/oracore/zoneinfo/
> timezlrg.dat", O_RDONLY) = 6
> fstat64(6, {st_mode=S_IFREG|0664, st_size=404884, ...}) = 0
> mmap2(NULL, 404884, PROT_READ, MAP_PRIVATE|MAP_NORESERVE, 6, 0) =
> 0xb6cc3000
> close(6) = 0
> gettimeofday({1182779992, 205922}, NULL) = 0
> open("/usr/local/oracle/app/oracle/product/10.2.0/rdbms/mesg/
> ocius.msb", O_RDONLY) = 6
> fcntl64(6, F_SETFD, FD_CLOEXEC) = 0
> lseek(6, 0, SEEK_SET) = 0
> read(6, "\25\23\"\1\23\3\t\t\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
> 256) = 256
> lseek(6, 512, SEEK_SET) = 512
> read(6, "\337y\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
> 512) = 512
> lseek(6, 1024, SEEK_SET) = 1024
> read(6, "\25\7\'\0072\7>\7j\7\276\17$\'\6K5S\24TfT\307T(VsV\222"...,
> 86) = 86
> brk(0x80af000) = 0x80af000
> times(NULL) = 1908055079
> rt_sigprocmask(SIG_BLOCK, [INT], NULL, 8) = 0
> rt_sigaction(SIGINT, {0xb7bb3038, ~[ILL ABRT BUS FPE SEGV USR2 XCPU
> XFSZ SYS RTMIN RT_1], SA_RESTART|SA_SIGINFO}, {SIG_DFL}, 8) = 0
> rt_sigprocmask(SIG_UNBLOCK, [INT], NULL, 8) = 0
> gettimeofday({1182779992, 207500}, NULL) = 0
> gettimeofday({1182779992, 207598}, NULL) = 0
> brk(0x80d2000) = 0x80d2000
> fstat64(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 25), ...}) = 0
> mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
> 0) = 0xb6ed1000
> write(1, "\n", 1) = 1
> write(1, "SQL*Plus: Release 10.2.0.3.0 - P"..., 70) = 70
> write(1, "\n", 1) = 1
> write(1, "Copyright (c) 1982, 2006, Oracle"..., 56) = 56
> write(1, "\n", 1) = 1
> ...
> ...
> ...
>
> As you can see in second case
> times(NULL) = 1908055079
> positive value is returned and there is only one call of
> 'times' system call.
>
> In first case
> times(NULL) = -2058427839
> negative value is returned and there are many of 'times' calls.

You haven't done as I stated: trace the LISTENER and the CLIENT CONNECTTION through SQLNET. Using strace won't provide any insight into what SQL*Net is doing with this connection attempt.

David Fitzjarrell Received on Mon Jun 25 2007 - 09:28:05 CDT