Brian Utterback wrote: > Ah, Pramod was right, for at least part of my problem. I just re-read > the chapter on speculative tracing, and it says that when a commit is > done, the speculative buffer from the cpu that does the commit is > immediately copied to the principle buffer, with the speculative > buffer from other cpus copied sometime later. This greatly increases > the chances of the the discard happening before the buffer is copied, > but after the value of ts is examined. It still doesn't explain the > missing processes though.
The dtrace provider chapter mentions (http://wikis.sun.com/display/DTrace/dtrace+Provider) : 'The END probe fires after all other probes. This probe will not fire until all other probe clauses have completed' As per the above assertion the race [as mentioned in the previous mail] between the commit and discard cannot happen because in the script the commit is done when the END probe fires and the END probe fires when all the other probe clauses (discard clause) have completed. Pramod > > I worked around this problem by having a global variable on the clause > with the discard. In the very first END clause, I change the global so > the clause with the discard is thus always false and no more discard > occur. This got rid of all the empty output. Are global variables > coherent across CPUs? > > Brian Utterback wrote: >> Actually, I thought that there might be some kind of race condition >> like that, but that really can't be it. See the time stamps? >> Speculation 5 was set 9 seconds earlier, and speculation 6 was set >> 1.6 seconds earlier. The point is that I am seeing a very small >> number of syspoll calls and they tend to wait a relatively long time. >> I could see getting that kind of race once in awhile at that rate, or >> even all of the time if the rate of pollsys calls was very high, but >> that isn't the case. Also, there is the one process that I know is >> waiting in syspoll that doesn't show up here at all. >> >> Pramod Batni wrote: >>> >>> >>>> 1 2 :END 5 9163 >>>> =================================================== >>>> >>>> >>>> 1 2 :END 6 1686 >>>> =================================================== >>>> >>>> >>>> >>>> See the problem? In this case speculations 5 and 6 both have >>>> non-zero ts array entries (or they would not have printed) but >>>> there is nothing in the speculation buffer (otherwise there would >>>> have been the first set of traces printed). Any ideas why this is >>>> happening? >>>> >>> Consider the following 2 probes firing on 2 different cpu's at >>> approximately the same time. >>>> } \ >>>> END \ >>>> /ts[this->spec]/ \ >>>> { \ >>>> commit(this->spec); \ >>>> this->spec++; \ >>>> } >>>> >>>> >>>> >>>> syscall::pollsys:return >>>> /self->spec/ >>>> { >>>> ts[self->spec] = 0; >>>> discard(self->spec); >>>> self->spec = 0; >>>> } >>>> >>>> >>> The interleaved execution of the predicate and the clause could lead >>> to the kind of output you are observing. >>> The first probe would find ts[this->spec] to be non-zero and before >>> it can execute 'commit(this->spec)' the second >>> probe would fire and execute 'discard(self->spec)' . The contents of >>> the speculative buffer are discarded and the 'commit(this->spec)' >>> would become a nop. >>> Such a sequence could explain the missing data for speculation 5 and 6. >>> >>> >>> Pramod >> > _______________________________________________ dtrace-discuss mailing list [email protected]
