Re: process running slowly, lots of yield() calls ?

On Nov 21, 7:04 am, "Jonathan Lewis" <jonat..._at_jlcomp.demon.co.uk> wrote:
> "Andy" <andy..._at_gmail.com> wrote in message
>
> news:f7571f0a-c9cd-4b08-9d26-fd510754852e_at_v13g2000yqm.googlegroups.com...
>
>
>
>
>
> > We upgraded database from 9i to 10g at the weekend. One of the
> > processes (whose statement basically consists of an "create table as
> > select etc") is taking +7hrs and still running instead of the more
> > usual 30 mins. OK, I would think that this is a statistics/explain-
> > plan related issue and we have the vendor investigating.
>
> > However, what I am more curious about is the truss output on the
> > spawned oracle process. It's peppered with yield() calls and I'm
> > suspicious. Why would it be running a processor flat out, and yet
> > yielding so much ? Can anyone throw some light on this please ?
>
> > sample:
> > ...
> > yield()                                         = 0
> > times(0xFFFFFFFF7FFF4070)                       = 164268253
> > times(0xFFFFFFFF7FFF3FC0)                       = 164268253
> > yield()                                         = 0
> > yield()                                         = 0
> > pread(268, "0602\0\001 B M A0781F492".., 8192, 0x49A82000) = 8192
> > yield()                                         = 0
> > yield()                                         = 0
> > yield()                                         = 0
> > times(0xFFFFFFFF7FFF4070)                       = 164268870
> > times(0xFFFFFFFF7FFF3FC0)                       = 164268870
> > pread(266, "0602\0\00102 ^9407 pB9B3".., 8192, 0x4BD28000) = 8192
> > yield()                                         = 0
> > yield()                                         = 0
> > yield()                                         = 0
> > yield()                                         = 0
> > yield()                                         = 0
> > yield()                                         = 0
> > yield()                                         = 0
> > yield()                                         = 0
> > yield()                                         = 0
> > yield()                                         = 0
> > ...
>
> > truss -cpf 8881
> > syscall              seconds   calls  errors
> > times                    .00      60
> > yield                    .01     330
> > pread                    .01     163
> >                     -------  ------   ----
> > sys totals:              .02     553      0
> > usr time:             173.64
> > elapsed:              175.24
> > I know times() is used by Oracle to help in its timing statistics, but
> > why the yield() so much ?
>
> > Thanks
>
> > AW
>
> Andy,
>
> I believe that Oracle changed some of the latch-related code
> so that (for some latches, at least) rather than sleeping after a
> failed spin, the first failure turns into a yield, putting the process
> immediately at the bottom of the run queue in a 'ready to run'
> state. So it's possible that your yields are a sign of latch contention.
>
> --
> Regards
>
> Jonathan Lewishttp://jonathanlewis.wordpress.com
>
> Author: Cost Based Oracle: Fundamentalshttp://www.jlcomp.demon.co.uk/cbo_book/ind_book.html
>
> The Co-operative Oracle Users' FAQhttp://www.jlcomp.demon.co.uk/faq/ind_faq.html

Would that be true of the PL/SQL lock timer sleep? In my ignorance of how it actually works I'm imagining silly code that hyperaggressively checks for time slept at a very fine grain. "I'm ready to run George, oh, ok, I'm yielding, now I'm ready to run George, is it time yet, huh George, huh George, huh?"

jg

--
@home.com is bogus.
 Wentz, B. M.  http://newsroom.mtv.com/2008/11/21/is-bronx-mowgli-wentz-the-best-celebrity-baby-name-ever/