kernel_stats-irix5.3.tcl 9.86 KB
#
# Copyright (C) 1996-1998 by the Board of Trustees
#    of Leland Stanford Junior University.
# 
# This file is part of the SimOS distribution. 
# See LICENSE file for terms of the license. 
#

## 
## kernel_stats.tcl
##

timing create kstats
log [timing fields]

###
### statistics logging
###

annotation set simos exit {
    timing exit kstats
    log [timing dump kstats]
}

annotation set simos sigusr {
    log [timing dump kstats]
}

###
### thread naming
### In Hive there are multiple copies of each pid so we
### must differentiate by cell number
###

if [info exists RUNNING_HIVE] {
    proc ktname {} {
        global CELL PID CPU
        return ${CELL}_$PID($CPU)
    }
    proc pid2ktname {pid} {
        global CELL
        return ${CELL}_$pid
    }
} elseif { $PARAM(MACHINE.Count) == 1 } {
    proc ktname {} {
        global PID CPU
		return $PID($CPU)
    }
    proc pid2ktname {pid} {
		return $pid
    }
} else {
    proc ktname {} {
        global M PID CPU
       	return $M($CPU)_$PID($CPU)
    }
    proc pid2ktname {pid} {
        global M CPU
       	return $M($CPU)_$pid
    }
}


###
### thread control
###

proc kstatsSwitch args {
    global PROCESS CELL RUNNING_HIVE CYCLES kstatsThread M CPU PARAM

    if [info exists RUNNING_HIVE] {
        eval timing switch kstats [ktname] cell$CELL $args
	} elseif { $PARAM(MACHINE.Count) == 1 } {
        eval timing switch kstats [ktname] $args
    } else {
        eval timing switch kstats [ktname] machine$M($CPU) $args
    }

    if ![info exists kstatsThread([ktname])] {
        set kstatsThread([ktname]) "runq"
    } else {
        timing end kstats $kstatsThread([ktname])
    }
}

annotation set simos enter {
    if [inUserMode] {
        kstatsSwitch 
    } elseif {$PROCESS($CPU) == "boot"} {
        kstatsSwitch bootproc
    } elseif {$PROCESS($CPU) == "idle"} {
        kstatsSwitch idleproc idle
    } else {
        kstatsSwitch startup
    }
}

annotation set osEvent switchOut {
    # has thread still active (i.e. has not exited)
    if [info exists kstatsThread([ktname])] {
        if {[timing current kstats] == "ROOT"} { 
            console "KSTATS: CPU $CPU CYCLE $CYCLES: bad DESCHED pid $PID($CPU)\n"
        }
        
        timing start kstats $kstatsThread([ktname])
    }
}

set kernelThreadNames(vhand) 1
set kernelThreadNames(bdflush) 1
set kernelThreadNames(pdflush) 1
set kernelThreadNames(sched) 1
if [info exists RUNNING_HIVE] {
    set kernelThreadNames(dspatch) 1
    set kernelThreadNames(PING) 1
    set kernelThreadNames(LSET) 1
    set kernelThreadNames(RECV) 1
    set kernelThreadNames(RBOT) 1
    set kernelThreadNames(BALANCE) 1
}

proc kernelThreadState {proc} {
    global kernelThreadNames

    if {[string range $proc 0 4] == "hrpc_"} {
        return hrpcServer
    } elseif [info exists kernelThreadNames($proc)] {
        return $proc
    } else {
        return fork
    }
}

annotation set osEvent switchIn {
    if {$PROCESS($CPU) == "idle"} {
        kstatsSwitch idleproc
    } elseif {$PROCESS($CPU) == "runq"} {
        kstatsSwitch runqproc
    } else {
        kstatsSwitch [kernelThreadState $PROCESS($CPU)]
    }
}

annotation set osEvent procexit {
    timing terminate kstats [ktname]
    unset kstatsThread([ktname])
}


###
### kernel services
###

annotation set utlb {
    timing start kstats utlb
}

annotation set exc {
    if {[timing current kstats] == "utlb"} {
        timing end kstats utlb
    }

    set exc [expr ($cause >> 2) & 0x1F]

    if {$exc == 0} {
        timing start? kstats intrdisp
    } elseif {$exc == 8} {
        timing start kstats syscall([expr $v0])
    } else {
        timing start? kstats exc($exc)
    }
}

annotation set inst rfe {
    set current [timing current kstats]
    if {$current != "ROOT"} {
        timing end kstats $current
    } else {
        console "KSTATS: CPU $CPU CYCLE $CYCLES: bad rfe pid $PID($CPU)\n"
    }
}

annotation set osEvent startIdle {
    timing start kstats idle
}

annotation set osEvent endIdle {
    timing end kstats idle
}

annotation set osEvent startSync {
    timing start kstats sync
}

annotation set osEvent endSync {
    timing end kstats sync
}

##
## rpc servers
##

if [info exists RUNNING_HIVE] {
    annotation set pc kernel::registerQMethodAnn:START {
        timing start kstats qmethod($a0)
    }

    annotation set pc kernel:hrpc.c:1041 {
        timing end kstats [timing current kstats]
    }

    for {set i 0} {$i < $PARAM(CPU.Count)} {incr i} {
        set inFMethod($i) 0
    }

    annotation set pc kernel::registerFMethodAnn:START {
        timing start kstats fmethod($a0)
        set inFMethod($CPU) 1
    }

    annotation set pc kernel:hrpc.c:hrpcRequestInterrupt:END {
        if {$inFMethod($CPU)} {
            timing end kstats [timing current kstats]
            set inFMethod($CPU) 0
        }
    }
}

##
## page faults
##

annotation set pc kernel::pfault:START {
    timing vector kstats pfault
}

annotation set pc kernel::page_copy:START {
    if {[timing current kstats] == "pfault"} {
        timing vector kstats COW_fault
    }
}

annotation set pc kernel::vfault:START {
    timing vector kstats vfault
}

annotation set pc kernel::page_zero:START {
    if {[timing current kstats] == "vfault"} {
        timing vector kstats demand_zero
    }
}


##
## interrutps
##

# simscsi_intr, if_etintr, and du_poll all share the interrupt
# dispatch path. There are two ways to charge the overhead to
# routines. 1) We can treat the routines as interrupt handlers in the
# normal way. This leads to simscsi_intr getting charged all the
# dispatch overhead and du_poll getting charged all the return
# overhead. This is what is currently done. 2) We could have a
# level3_intr, do normal start, ends on simscsi_intr, if_etintr, and
# du_poll, and then divide the overhead of level3_intr among the 3 as
# a post processing step. Fortunately the overhead is small enough
# where we do not really care.

set intr(timein)         1
set intr(netintr)        2
set intr(simscsi_intr)   3
set intr(if_etintr)      3
set intr(du_poll)        3
set intr(level4_intr)    4
set intr(clock)          5
set intr(cpuintr)        6
set intr(ackkgclock)     7
set intr(buserror_intr)  8

if [info exists RUNNING_HIVE] {
    set intr(hrpcRequestInterrupt)        3
}

foreach i [array names intr] {
    annotation set pc kernel:SIMMP.c:$i:START "dointr $i"
}

proc dointr {name} {
    global intr CPU CYCLES
    set current [timing current kstats] 
    if {$current == "intrdisp"} {
        timing vector kstats $name
    } elseif [info exists intr($current)] {
        timing end kstats $current
        timing start kstats $name
    } else {
        console "KSTATS: CPU $CPU CYCLE $CYCLES: bad intr: $name current: $current\n"
    }
}


##
## Latency Components
##

# kstatsThread is an array indexed by pid that holds the reason that
# the thread is getting descheduled. There are two ways a thread could
# get descheduled. 1) the thread could get pre-empted and put on the
# runq. In this case we do nothing and it goes down as DESCHED. 2) The
# thread could get put on a semaphore. In this case we try to
# determine further the reason its on the semaphore. Currently we only
# deferentiate IO. All other semaphores are put under semawait.

annotation set pc kernel:sema.c:semaaddproc:START {
    if {$kstatsThread([ktname]) == "runq"} {
        set kstatsThread([ktname]) semawait
    }
}

# The if check in the following that looks at timing current
# responds to the following race condition:
#
# thread A does a psema.  This calls semaaddproc above.
# Normally next event is that thread A calls swtch, causing
# an osEvent switchOut which does timing start semawait.
#
# However, it is possible for an interrupt to occur between the
# semaaddproc and the call to swtch(), during which the interrupt
# handler can do a semarmproc or a semadq.
#
# We can tell if this has happened because the timing current value
# will show that we have not yet made it to semawait or diskIO.
# Appropriate response in terms of stats is to change kstatsThread
# so the switchOut will change to runq (ready to run) rather than
# semawait or diskIO.


annotation set pc kernel:sema.c:semarmproc:END {
    set pid [symbol read "kernel:proc.h:((proc_t*)$a1)->p_pid"]
    set kname [pid2ktname $pid]
    if {[info exists kstatsThread($kname)] && $v0 && ($pid != $PID($CPU))} {
        if {[timing current kstats $kname] == $kstatsThread($kname)} {
            timing end kstats $kstatsThread($kname) $kname
            timing start kstats runq $kname
        } else {
            log "$CYCLES semarmproc special case: thread $kname\n"
            timing dumpstack kstats $kname
            log "State after desched will be \"runq\" rather than \"$kstatsThread($kname)\"\n"
        }
        set kstatsThread($kname) "runq"
    }
}

annotation set pc kernel:sema.c:semadq:END {
    set pid [symbol read "kernel:proc.h:((proc_t*)$v0)->p_pid"]
    set kname [pid2ktname $pid]
    if {[info exists kstatsThread($kname)] && ($pid != $PID($CPU))} {
        if {[timing current kstats $kname] == $kstatsThread($kname)} {
            timing end kstats $kstatsThread($kname) $kname
            timing start kstats runq $kname
        } else {
            log "$CYCLES semarmproc special case: thread $kname\n"
            timing dumpstack kstats $kname
            log "State after desched will be \"runq\" rather than \"$kstatsThread($kname)\"\n"
        }
        set kstatsThread($kname) "runq"
    }
}

annotation set pc kernel:simscsi.c:simscsi_command:START {
    set kstatsThread([ktname]) diskIO
}


if [info exists RUNNING_HIVE] {
    annotation set pc kernel:hrpc.c:1196 {
        set kstatsThread([ktname]) queuedRPC
    }

    annotation set pc kernel:hrpc.c:hrpcFastInvokeINTERN:START {
        timing start kstats fastRPC
    }

    annotation set pc kernel:hrpc.c:hrpcFastInvokeINTERN:block {
        set kstatsThread([ktname]) fastRPCblock
    }

    annotation set pc kernel:hrpc.c:hrpcFastInvokeINTERN:END {
        timing end kstats fastRPC
    }
}