WebSVN – vanilla-wow-addons – Blame – Rev 1 – /k/KLHThreatMeter/Code/KTM

Whenever the KTM_Core.lua is about to call a module's .onevent() or .onupdate() methods, it instead sends the method to mod.diag.logmethodcall(module, methodtype). The time taken in milliseconds and memory used in kilobytes is recorded. For each module that has a .onevent() or .onupdate() method, a separate entry is kept, which records the total value,average rate, maximum rate over 5 seconds and rate in the last 5 seconds.

13

14

To print out the memory data, run the command "/ktm test memory"; for timing data, "/ktm test time".

15

16

Times are recorded in one second intervals. So whenever a method is called, the .current value of the relevant dataset is incremented. Then every second, there is a collation, where .current is added to .history, and .total and .recordinterval are updated. This is done in me.onupdate().

]]

me.lastcollation = GetTime() -- value of GetTime(). Happens once a second.

22

me.datalogstart = GetTime() -- when we started logging times. For the "average rate" value.

23

24

--[[

25

timing / memory data set. Each module-method combination has a separate set. e.g. there is one for the .onevent() function of the .combat module.

26

]]

27

me.createnewdataset = function()

return

{

["total"] = 0,

["history"] = {0, 0, 0, 0, 0}, -- values for the last 5 seconds

33

["historylength"] = 5,

34

["current"] = 0, -- working value for the current second

35

["recordinterval"] = 0, -- maximum sum of .history

}

end

--[[

All the data we keep is in this table. At startup, we can only be sure the "total" sets will exist - we don't know which modules have a .onupdate or .onevent method. As soon as those methods are called for the first time, we will add a data set for them.

]]

me.data =

{

["memory"] =

{

["onupdate"] =

{

["total"] = me.createnewdataset(),

},

["onevent"] =

{

["total"] = me.createnewdataset(),

54

},

55

["total"] = me.createnewdataset(),

},

["time"] =

{

["onupdate"] =

{

["total"] = me.createnewdataset(),

},

["onevent"] =

{

["total"] = me.createnewdataset(),

66

},

67

["total"] = me.createnewdataset(),

}

}

--[[

mod.diag.logmethodcall(module, calltype)

73

Runs the special Core.lua methods, and logs the timing and memory usage.

74

<module> is a string, the key for a module, e.g. "combat", "string", "netin", etc.

75

<calltype> is either "onupdate" or "onevent".

76

]]

77

me.logmethodcall = function(module, calltype)

78

79

local method = mod[module][calltype]

local memory

local time

local manualstart = GetTime()

84

memory, time = me.getfunctionstats(method)

85

local manualtime = math.floor(0.5 + (GetTime() - manualstart) * 1000)

86

87

-- Scrub out bullshit values! > 100ms = bs, > 10 ms = should be traced. < 0 kb = bs (gc).

88

-- Sometimes debugprofile gives completely spasticated values for unknown reasons. Also we might get a negative

89

-- value for memory if a garbage collection occurs.

90

if time > 100 or time < 0 or math.abs(time - manualtime) > 5 then

91

time = 0

92

elseif time > 10 then

93

if mod.out.checktrace("info", me, "timing") then

94

			mod.out.printtrace(string.format("Time from %s %s is %s ms (manual says %s ms) (memory was %s).", module, calltype, me.formatdecimal(time), manualtime, memory))

end

end

if memory < 0 then

memory = 0

end

me.adddatapoint("time", calltype, module, time)

103

me.adddatapoint("memory", calltype, module, memory)

end

--[[

me.getfunctionstats(method)

109

Runs the the function <method>, and records how much time was taken, and memory used.

110

Returns: <memory, in whole kilobytes>, <time, in fractional milliseconds>.

111

]]

112

me.getfunctionstats = function(method)

113

114

local memorystart = gcinfo()

115

local timestart = debugprofilestop()

method()

local timetaken = (debugprofilestop() - timestart)

120

local memoryused = gcinfo() - memorystart

121

122

return memoryused, timetaken

end

--[[

me.adddatapoint(datatype, calltype, module, value)

128

Adds <value> to the .current property of the relevant dataset. Also adds it to any parent sets, e.g. "total".

129

<datatype> is "memory" or "time"

130

<calltype> is "onupdate" or "onevent"

131

<module> is "combat", "string", "data", etc.

132

]]

133

me.adddatapoint = function(datatype, calltype, module, value)

134

135

if me.data[datatype][calltype][module] == nil then

136

me.data[datatype][calltype][module] = me.createnewdataset()

137

end

138

139

me.data[datatype][calltype][module].current = me.data[datatype][calltype][module].current + value

140

me.data[datatype][calltype].total.current = me.data[datatype][calltype].total.current + value

141

me.data[datatype].total.current = me.data[datatype].total.current + value

end

--[[

Special Core.lua method. If this "second" has ended (i.e. it's been at least 1 second since the last collation),

147

then run a collation.

148

]]

149

me.onupdate = function()

150

151

local timenow = GetTime()

152

153

-- update at most once a second

154

if timenow < me.lastcollation + 1.0 then

return

end

me.collatetable(me.data, timenow - me.lastcollation)

159

me.lastcollation = timenow

end

--[[

me.collatetable(data, period)

164

Collating a dataset is to finalise the ".current" value, add it to history, update total, etc.

165

This is a recursive method. <data> might be a data set (base case), or it might be a tree containing datasets (note the

166

structure of me.data). If it is a tree, then me.collatetable will be called on any subtrees inside it.

167

<period> = time in seconds this collation is over. It will be at least 1, and close to 1, but not exactly 1. Since we want

168

to record the rate, e.g. KB/sec, we have to divide by this value.

169

]]

170

me.collatetable = function(data, period)

171

172

if data.current == nil then

173

-- this guy is a table, with subtables. do the subtables.

174

175

local value

176

for _, value in data do

177

me.collatetable(value, period)

end

return

end

-- this guy is an actual data set

local x

local interval = 0

for x = data.historylength - 1, 1, -1 do

188

data.history[x + 1] = data.history[x]

189

interval = interval + data.history[x]

190

end

191

192

-- take into account period length (we want / second)

193

data.history[1] = data.current / period

194

interval = interval + data.history[1]

195

data.total = data.total + data.current

196

197

-- check for new record 5 second burst

198

if interval > data.recordinterval then

199

data.recordinterval = interval

200

end

201

202

-- reset the current value, it's a new second

data.current = 0

end

--[[

mod.diag.printdataset(datatype, units)

209

This is called when a console command "/ktm test time" or "/ktm test memory" is run.

210

<datatype> is "time" or "memory"

211

<datatype> is a description of the units, e.g. "Milliseconds per Second".

212

]]

213

me.printalldata = function(datatype, units)

214

215

-- print total, then subcategories, recursively.

216

	mod.out.print(string.format("|cff6666ffThis is a listing of |cffffff00%s |cff6666ffusage. Units are |cffffff00%s.|r", datatype, units))

217

218

local data = me.data[datatype]

local key

local value

-- grand total

me.printdataset("|cffff3333Total", data.total)

224

225

-- onupdates

226

me.printdataset("|cff66ff66OnUpdates", data.onupdate.total)

227

228

for key, value in data.onupdate do

229

if key ~= "total" then

230

me.printdataset("|cffffff00" .. key, value)

end

end

-- onevents

me.printdataset("|cff66ff66OnEvents", data.onevent.total)

236

237

for key, value in data.onevent do

238

if key ~= "total" then

239

me.printdataset("|cffffff00" .. key, value)

end

end

end

--[[

me.printdataset(name, set)

247

This prints the values of an individual data set.

248

<name> is the name of the module or category, with colouring.

249

<set> is the actual data set.

250

]]

251

me.printdataset = function(name, set)

local x

local last5 = 0

for x = 1, 5 do

last5 = last5 + set.history[x]

258

end

259

260

mod.out.print(string.format("%s:|r Total = %s, Avg = %s, Burst = %s, Recent = %s.",

261

		name, me.formatdecimal(set.total), me.formatdecimal(set.total / (GetTime() - me.datalogstart)), me.formatdecimal(set.recordinterval / 5), me.formatdecimal(last5 / 5)))

end

--[[

me.formatdecimal(value)

267

Returns a string representation of <value>, including up the the first place after the decimal, if it exists.

268

]]