Re: Random long times to connect using BEQ adapter

To figure out what's behind fd10, you could try to look at lsof (might have to get your SE to install it first, on aix it's not there per default afaik).

Then grep for your sqlplus' PID - IF it can write to it, it has to have it open.

Stefan

On 11/20/06, rjamya <rjamya_at_gmail.com> wrote:
>
> 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?
> --
> http://www.freelists.org/webpage/oracle-l
>
>
>

--
http://www.freelists.org/webpage/oracle-l