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.
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
>
--
blu
There are two rules in life:
Rule 1- Don't tell people everything you know
----------------------------------------------------------------------
Brian Utterback - Solaris RPE, Sun Microsystems, Inc.
Ph:877-259-7345, Em:brian.utterback-at-ess-you-enn-dot-kom
_______________________________________________
dtrace-discuss mailing list
[email protected]
