Random long times to connect using BEQ adapter

  • From: rjamya <rjamya@xxxxxxxxx>
  • To: "Oracle Discussion List" <oracle-l@xxxxxxxxxxxxx>
  • Date: Mon, 20 Nov 2006 08:16:22 -0500

After a cpu upgrade, local connections are taking exceeding long times
(between 7 to as much as 40 seconds) using sqlplus. Once connected, it
is blazingly fast to run the script.

I did a "truss -aefdo" on the sqlplus session and following is a
snipped that shows delay. For the life of me I can't find out what the
heck fd 10 is.

1597872: 3314117: 0.2855:        kfcntl(4, F_SETFD, 0x0000000000000001) = 0
1597872: 3314117: 0.2857:        lseek(4, 0, 0)         = 0
1597872: 3314117: kread(4, "1513 "011303\t\t\0\0\0\0".., 256) = 256
1597872: 3314117: 0.2861:        close(3)               = 0
1597872: 3314117: 0.2862:        close(4)               = 0
1597872: 3314117: 0.2864:
open("/usr/opt/oracle/9204/sqlplus/mesg/sp1us.msb", O_RDONLY) = 3
1597872: 3314117: 0.2865:        kfcntl(3, F_SETFD, 0x0000000000000001) = 0
1597872: 3314117: 0.2867:        lseek(3, 0, 0)         = 0
1597872: 3314117: kread(3, "1513 "011303\t\t\0\0\0\0".., 256) = 256
1597872: 3314117: 0.2870:
open("/usr/opt/oracle/9204/sqlplus/mesg/sp2us.msb", O_RDONLY) = 4
1597872: 3314117: 0.2872:        kfcntl(4, F_SETFD, 0x0000000000000001) = 0
1597872: 3314117: 0.2874:        lseek(4, 0, 0)         = 0
1597872: 3314117: kread(4, "1513 "011303\t\t\0\0\0\0".., 256) = 256
1597872: 3314117: kwrite(9, "0186\0\006\0\0\0\0\011 i".., 390) = 390
1597872: 3314117: 2.2880:        kread(10, "\0
Ì\0\006\0\0\0\0\004\0".., 2064) (sleeping...)
1597872: 3314117: kread(10, "02 %\0\006\0\0\0\0\0101D".., 2064) = 549
1597872: 3314117: 12.1737:        lseek(8, 1024, 0)     = 1024
1597872: 3314117: kread(8, "\018\0 $\0 7\0 @\0 J\0 V".., 512) = 512
1597872: 3314117: 12.1741:        lseek(8, 47104, 0)    = 47104
1597872: 3314117: kread(8, "\0\f05 ^\0\0\0 P05 x\0\0".., 512) = 512
1597872: 3314117: kwrite(9, "\0 4\0\006\0\0\0\0\011 i".., 52) = 52
1597872: 3314117: kread(10, "\014\0\006\0\0\0\0\0\b\0".., 2064) = 20
1597872: 3314117: kwrite(9, "\0 Ý\0\006\0\0\0\0\00303".., 221) = 221
1597872: 3314117: kread(10, "\090\0\006\0\0\0\0\004\0".., 2064) = 144
1597872: 3314117: kwrite(9, "\0 Â\0\006\0\0\0\0\003 G".., 194) = 194
1597872: 3314117: kread(10, "\09B\0\006\0\0\0\0\0\b\0".., 2064) = 155
1597872: 3314117: kwrite(9, "\015\0\006\0\0\0\0\00305".., 21) = 21
1597872: 3314117: kread(10, "\0 ª\0\006\0\0\0\0\004\0".., 2064) = 170
1597872: 3314117: kwrite(9, "\011\0\006\0\0\0\0\003\b".., 17) = 17
1597872: 3314117: kread(10, "\00F\0\006\0\0\0\0\0\t\0".., 2064) = 15
1597872: 3314117: kwrite(9, "01 7\0\006\0\0\0\0\003 ^".., 311) = 311
1597872: 3314117: kread(10, "\0 Þ\0\006\0\0\0\0\0\v01".., 2064) = 222
1597872: 3314117: kwrite(9, "01 6\0\006\0\0\0\0\011 i".., 310) = 310

see, in the third column the time reported (delta due to -d switch)
jumps from 2.288 to 12.1737? In the whole file, there is no reference
to a open or kopen for fd 10.

Any other ideas to identify why this slowness? Any other way to trace?
Running oracle code is fine, it is just the slowness when I issue a
"conn user/pass" in sqlplus. This is aix 5.3, oracle 9204.

TIA
Rjamya
----------------------------------------------
Got RAC?
--
//www.freelists.org/webpage/oracle-l


Other related posts: