Hi,
For a research project we are running OpenSolaris (SPARC) from a full
system simulator. For our experiments we will need to track
process/lwp/thread creation, switching and termination. For these
experiments we cannot use dtrace, because that would interfere with
normal execution.
The simulator does recognize 'magic instructions', which are dummy
writes to the %g0 register. When a magic instruction is encountered,
control is transferred to the simulator where it subsequently is
possible to read out register values and memory fields.
I have added such magic instructions throughout the functions in which
I'm interested, for example thread_{create, exit}, lwp_{create, exit},
resume, swtch, etc. The triggering of such an instruction prints out a
message.
The trace we get from this procedure seems a bit odd however. For
example, it happens that there appear to be several thread_exits of a
same process and thread, directly after each other.
I would therefore like to know what the normal function trace should
be. For example, when running a multi-threaded program from the shell,
which steps should happen (from creation over switching to
termination)?
In parts of our log which 'seems' normal, we see:
1. a bunch of lwp_create (equal to the number of threads used)
2. a lot of calls to dispdeq() (which seems to be the actual execution)
3. lwp_exits for each thread (one less than the actual amount of
threads, I suppose the last one is the main thread?)
4. proc_exit() of the last thread.
However, lwp_create doesn't seem to call thread_create, even though
according to my understanding of the source code should do that every
time. Is this correct?
Furthermore, there appears to be no resume*, swtch, ... functions
called during dispdeq(). Is this normal? Surely the different threads
get switched using these functions?
Other questions I have are:
- On which occasions is preempt() called? For example, in our logs I
see that it is called after current_thread() and intr_thread() which
handle interrupts. But at the moment preempt() is called, the
interrupts is already handled, so I don't see why the preempt is
there.
- I also see a lot of sequences of current_thread() followed
immediately by intr_thread(). Both handle interrupts, only the first
one uses pinning, right? Do they necessarily follow each other?
- Here's another example sequence which I don't understand:
cpu0 [ cycle 4959000299L ]: [ magic 5330 ] current_thread(): entry
cpu0 [ cycle 4959000316L ]: [ magic 5333 ] current_thread(): not
interrupting another interrupt
cpu0 [ cycle 4959000332L ]: [ magic 5334 ] current_thread(): before handler
cpu0 [ cycle 4959002773L ]: [ magic 5337 ] current_thread(): exit
cpu0 [ cycle 4959007958L ]: [ magic 5324 ] intr_thread(): exit
cpu0 [ cycle 4959008316L ]: [ magic 1008 ] preempt() | pid 100006 [tid
7 | threadp 0x 30002dc3720]
cpu0 [ cycle 4959008548L ]: [ magic 1016 ] setfrontdq(): entry | pid
100006 [tid 7 | threadp 0x 30002dc3720]
cpu0 [ cycle 4959009366L ]: [ magic 1017 ] setfrontdq(): exit | pid
100006 [tid 7 | threadp 0x 30002dc3720]
cpu0 [ cycle 4959750279L ]: [ magic 5330 ] current_thread(): entry
cpu0 [ cycle 4959750296L ]: [ magic 5333 ] current_thread(): not
interrupting another interrupt
cpu0 [ cycle 4959750312L ]: [ magic 5334 ] current_thread(): before handler
cpu0 [ cycle 4959752520L ]: [ magic 5337 ] current_thread(): exit
cpu0 [ cycle 4959757705L ]: [ magic 5324 ] intr_thread(): exit
cpu0 [ cycle 4959758063L ]: [ magic 1008 ] preempt() | pid 100006 [tid
7 | threadp 0x 30002dc3720]
cpu0 [ cycle 4959758295L ]: [ magic 1016 ] setfrontdq(): entry | pid
100006 [tid 7 | threadp 0x 30002dc3720]
cpu0 [ cycle 4959758996L ]: [ magic 1017 ] setfrontdq(): exit | pid
100006 [tid 7 | threadp 0x 30002dc3720]
cpu0 [ cycle 4960500279L ]: [ magic 5330 ] current_thread(): entry
cpu0 [ cycle 4960500296L ]: [ magic 5333 ] current_thread(): not
interrupting another interrupt
cpu0 [ cycle 4960500312L ]: [ magic 5334 ] current_thread(): before handler
cpu0 [ cycle 4960502520L ]: [ magic 5337 ] current_thread(): exit
cpu0 [ cycle 4960507705L ]: [ magic 5324 ] intr_thread(): exit
............. (this goes on for a long time)..........
First, how come there is only an exit of intr_thread(), even though I
have put a magic instr. at the entrance as well (and I have seen the
instruction before). Could this be due to a massive interrupting of
interrupts?
Second: thread 100006:7 seems to be preempted, but is then immediately
after put in front of the queue. Why then the preempt? Or is the
preempt called anyway after an interrupt? Or is preempt called anyway
after each OS tick (10 ms), even without an interrupt?
I have looked in the source code, but the kernel and especially the
scheduler are quite complex, so it's easy to overlook things (at least
for me).
Thanks very much for your help,
Thomas
_______________________________________________
opensolaris-code mailing list
[email protected]
http://mail.opensolaris.org/mailman/listinfo/opensolaris-code
