- Added a little program for analyzing the devexec log

This commit is contained in:
koennecke
2007-01-11 08:51:12 +00:00
parent bc22cc624d
commit b79958a864

274
tcl/analyzedevexeclog Executable file
View File

@ -0,0 +1,274 @@
#!/usr/bin/tclsh
#-----------------------------------------------------------------------------
# This program analyses a devexec log as written by SICS. It should produce
# a list of devices together with the time each device was active
# in seconds.
#
# Mark Koennecke, January 2007
#----------------------------------------------------------------------------
# Some utility routines for processing an entry in the devexeclog. A line
# has the form:
# DEVEXEC:OP:DEVICE:SECONDS:NANOSECONDS
# This is split into a list and accessor function are provided for various
# items
#---------------------------------------------------------------------------
proc parseLogLine {line} {
set l [split $line :]
set tst [lindex $l 0]
if {[string compare $tst DEVEXEC] != 0} {
error "Bad log line: $line"
}
return [lrange $l 1 end]
}
#--------------------------------------------------------------------------
proc getLogOp {logList} {
return [lindex $logList 0]
}
#--------------------------------------------------------------------------
proc getLogDevice {logList} {
return [lindex $logList 1]
}
#--------------------------------------------------------------------------
proc getLogSeconds {logList} {
return [lindex $logList 2]
}
#--------------------------------------------------------------------------
proc getLogNanos {logList} {
return [lindex $logList 3]
}
#-------------------------------------------------------------------------
proc getStamp {logList} {
return [lrange $logList 2 end]
}
#==========================================================================
proc calcTimeDiff {sec1 nano1 sec2 nano2} {
set secSum 0
set nanoSum 0
if {$sec2 > $sec1} {
set nanoSum [expr 1000000 - $nano1]
set secSum [expr $sec2 - $sec1 + 1]
set nanoSum [expr $nanoSum + $nano2]
} elseif {$sec2 == $sec1} {
set secSum 0
set nanoSum [expr $nano2 - $nano1]
} else {
error "Bad time order: sec2 should be bigger then sec1"
}
return [list $secSum $nanoSum]
}
#=========================================================================
# There are two arrays:
# One is called devices and holds the device name and the total number
# of seconds this device has run. There are special devices:
# - nobeam for couting NOBEAM time. This has later to be subtracted from
# counting times.
# - unallocated time which can not be clearly given to some device
# This might happen if the SICServer restarts whilst something is
# running.
#
# The other one is running and holds all the devices which are currently
# being run. For each such device a list will be held with seconds
# and nanos. At each Start and stop, time differences to the previous
# event will be calculated and added to the devices running. If more then
# one device is running at a given time, the time will be distributed
# equally to all devices.
#
# There is also a counter for devices which are currently running.
#
# This section now provides helper functions for dealing with these
# arrays
#========================================================================
set devRun 0
set devices(nobeam) 0
set devices(unaccounted) 0
set sicsRestart 0
#------------------------------------------------------------------------
proc addToDevice {dev sec nano} {
upvar #0 devices devices
set totalSec [expr double($sec) + double($nano)/1000000.0]
if {[info exists devices($dev)] } {
set devices($dev) [expr $devices($dev) + $totalSec]
} else {
set devices($dev) $totalSec
}
}
#------------------------------------------------------------------------
proc addToRunning {dev sec nano} {
upvar #0 running running devRun devRun
if {[info exists running($dev)] } {
set l $running($dev)
set newSec [expr double([lindex $l 0]) + double($sec)]
set newNano [expr double([lindex $l 1]) + double($nano)]
set running($dev) [list $newSec $newNano]
} else {
set running($dev) [list $sec $nano]
incr devRun
}
}
#------------------------------------------------------------------------
proc stopRunning {dev} {
upvar #0 running running devRun devRun devices devices
set l $running($dev)
addToDevice $dev [lindex $l 0] [lindex $l 1]
incr devRun -1
unset running($dev)
}
#-----------------------------------------------------------------------
proc isDevRunning {dev} {
upvar #0 running running
return [info exists running($dev)]
}
#------------------------------------------------------------------------
proc cancelAll {} {
upvar #0 running running devRun devRun devices devices
upvar #0 sicsRestart sicsRestart
if {$devRun > 0} {
incr sicsRestart
}
set runlist [array names running]
foreach dev $runlist {
puts stdout "Live restart on device $dev"
set l $running($dev)
addToDevice unaccounted [lindex $l 0] [lindex $l 1]
unset running($dev)
}
set devRun 0
}
#---------------------------------------------------------------------
proc addRunDiff {dev stamp lastStamp} {
upvar #0 running running devRun devRun
set diff [calcTimeDiff [lindex $lastStamp 0] \
[lindex $lastStamp 1] \
[lindex $stamp 0]\
[lindex $stamp 1]]
if {![info exists running($dev)] } {
addToRunning $dev 0 0
}
set disSec [expr double([lindex $diff 0])/double($devRun)]
set disNano [expr double([lindex $diff 1])/double($devRun)]
set devlist [array names running]
foreach d $devlist {
addToRunning $d $disSec $disNano
}
}
#---------------------------------------------------------------------
proc clearAll {} {
upvar #0 devRun devRun __lastStamp lastStamp __nobeamStamp nobeamStamp
upvar #0 devices devices running running sicsRestart sicsRestart
set devRun 0
catch {unset lastStamp}
catch {unset nobeamStamp}
set l [array names devices]
foreach d $l {
unset devices($d)
}
set l [array names running]
foreach d $l {
unset running($d)
}
set devices(nobeam) 0
set devices(unaccounted) 0
set sicsRestart 0
}
#=======================================================================
# This section contains the code with the main interpretation and
# analysis
#=======================================================================
proc analyzeLine {line after} {
upvar #0 devRun devRun __lastStamp lastStamp __nobeamStamp nobeamStamp
set log [parseLogLine $line]
set afterSec [clock scan $after]
set op [getLogOp $log]
set t [getLogSeconds $log]
if {$t < $afterSec} {
return
}
switch $op {
START {
set dev [getLogDevice $log]
if {[string compare $dev SICS] == 0} {
cancelAll
return
}
if {$devRun > 0} {
set stamp [getStamp $log]
addRunDiff $dev $stamp $lastStamp
set lastStamp $stamp
} else {
if {![isDevRunning $dev] } {
addToRunning $dev 0 0
set lastStamp [getStamp $log]
}
}
}
STOP {
if {![info exists lastStamp]} {
return
}
set dev [getLogDevice $log]
if {[string compare $dev SICS] == 0} {
cancelAll
return
}
set stamp [getStamp $log]
addRunDiff $dev $stamp $lastStamp
if {[isDevRunning $dev] } {
stopRunning $dev
}
if {$devRun == 0} {
unset lastStamp
}
}
NOBEAM {
set nobeamStamp [getStamp $log]
}
CONTINUE {
set stamp [getStamp $log]
set diff [calcTimeDiff [lindex $nobeamStamp 0] \
[lindex $nobeamStamp 1] \
[lindex $stamp 0]\
[lindex $stamp 1]]
addToDevice nobeam [lindex $diff 0] [lindex $diff 1]
unset nobeamStamp
}
}
}
#==========================================================================
proc printResult {} {
upvar #0 devices devices sicsRestart sicsRestart
set l [array names devices]
puts stdout "DEVICE SECONDS"
foreach dev $l {
puts stdout [format "%-20s %12.2f" $dev $devices($dev)]
}
puts stdout [format "%-20s %12.2f" "Live Restarts" $sicsRestart]
}
#=========================================================================
proc analyzeFile {filename after} {
set f [open $filename r]
while {[gets $f line] >= 0} {
set status [catch {analyzeLine $line $after} msg]
if {$status != 0} {
puts stdout "ERROR: error $msg processing $line"
}
}
close $f
}
#=============== MAIN Program ===========================================
proc main {} {
global argv
if {[llength $argv] < 2} {
puts stdout "Usage:\n\tanalysedevexeclog filename after"
puts stdout "\t with after being a date in format MM/DD/YYYY"
exit 1
}
analyzeFile [lindex $argv 0] [lindex $argv 1]
printResult
}
main
exit 0