Oracle FAQ Your Portal to the Oracle Knowledge Grid
HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US
 

Home -> Community -> Mailing Lists -> Oracle-L -> Random long times to connect using BEQ adapter

Random long times to connect using BEQ adapter

From: rjamya <rjamya_at_gmail.com>
Date: Mon, 20 Nov 2006 08:16:22 -0500
Message-ID: <9177895d0611200516p496e50b4na5b750959b733806@mail.gmail.com>


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.

  1. 3314117: 0.2855: kfcntl(4, F_SETFD, 0x0000000000000001) = 0
  2. 3314117: 0.2857: lseek(4, 0, 0) = 0
  3. 3314117: kread(4, "1513 "011303\t\t\0\0\0\0".., 256) = 256
  4. 3314117: 0.2861: close(3) = 0
  5. 3314117: 0.2862: close(4) = 0
  6. 3314117: 0.2864: open("/usr/opt/oracle/9204/sqlplus/mesg/sp1us.msb", O_RDONLY) = 3
  7. 3314117: 0.2865: kfcntl(3, F_SETFD, 0x0000000000000001) = 0
  8. 3314117: 0.2867: lseek(3, 0, 0) = 0
  9. 3314117: kread(3, "1513 "011303\t\t\0\0\0\0".., 256) = 256
  10. 3314117: 0.2870: open("/usr/opt/oracle/9204/sqlplus/mesg/sp2us.msb", O_RDONLY) = 4
  11. 3314117: 0.2872: kfcntl(4, F_SETFD, 0x0000000000000001) = 0
  12. 3314117: 0.2874: lseek(4, 0, 0) = 0
  13. 3314117: kread(4, "1513 "011303\t\t\0\0\0\0".., 256) = 256
  14. 3314117: kwrite(9, "0186\0\006\0\0\0\0\011 i".., 390) = 390
  15. 3314117: 2.2880: kread(10, "\0 \0\006\0\0\0\0\004\0".., 2064) (sleeping...)
  16. 3314117: kread(10, "02 %\0\006\0\0\0\0\0101D".., 2064) = 549
  17. 3314117: 12.1737: lseek(8, 1024, 0) = 1024
  18. 3314117: kread(8, "\018\0 $\0 7\0 @\0 J\0 V".., 512) = 512
  19. 3314117: 12.1741: lseek(8, 47104, 0) = 47104
  20. 3314117: kread(8, "\0\f05 ^\0\0\0 P05 x\0\0".., 512) = 512
  21. 3314117: kwrite(9, "\0 4\0\006\0\0\0\0\011 i".., 52) = 52
  22. 3314117: kread(10, "\014\0\006\0\0\0\0\0\b\0".., 2064) = 20
  23. 3314117: kwrite(9, "\0 \0\006\0\0\0\0\00303".., 221) = 221
  24. 3314117: kread(10, "\090\0\006\0\0\0\0\004\0".., 2064) = 144
  25. 3314117: kwrite(9, "\0 \0\006\0\0\0\0\003 G".., 194) = 194
  26. 3314117: kread(10, "\09B\0\006\0\0\0\0\0\b\0".., 2064) = 155
  27. 3314117: kwrite(9, "\015\0\006\0\0\0\0\00305".., 21) = 21
  28. 3314117: kread(10, "\0 \0\006\0\0\0\0\004\0".., 2064) = 170
  29. 3314117: kwrite(9, "\011\0\006\0\0\0\0\003\b".., 17) = 17
  30. 3314117: kread(10, "\00F\0\006\0\0\0\0\0\t\0".., 2064) = 15
  31. 3314117: kwrite(9, "01 7\0\006\0\0\0\0\003 ^".., 311) = 311
  32. 3314117: kread(10, "\0 \0\006\0\0\0\0\0\v01".., 2064) = 222
  33. 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?
--
http://www.freelists.org/webpage/oracle-l
Received on Mon Nov 20 2006 - 07:16:22 CST

Original text of this message

HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US