Watchdog puzzles

[Semele]

With the above in mind, I have a suggestion for changing the Watchdog performance warning text.

Error: Performance Warning. Rift is running slowly and may effect Addon performance.

Much better!

[Mere]

On a fresh load of Rift, the client is possibly at is most busiest and as such can be classed as a reproducible stress test of the client.

Anyhow, on first loading Rift (not /reloadui) my standard Buff handler takes 0.05s compared to it's peak (now sits around 0.00093 for a full day). So, I needed to investigate this spike and found it was during load that the handler takes roughly 500 times longer during load (for doing exactly the same process while running).

What all this means, is that if the Rift Client is too busy itself, it'll push the priority of addons right down the list and basically BLAME any addon for its performance, regardless of the fact the client itself is spiking and tied up. This needs to be looked at, as there is no way in hell you can account for both other addons timings and Rifts own performance spikes.

This does start to fit with the daily error reports I have, most of them are all showing a performance warning from the code I run based on the "PlayerReady" event from SafesRaidManager (you might have heard of it ;)

The code in question is related to cleaning up any stray unitframes I created based on the player's saved vars, from their last logoff/DC (it's related to in-combat reconnects where the frames need to be back up at player reconnect)

In the normal case I'd expect the tidy-up code to have little to do. (Of course the stack trace doesn't tell me how many units it is cleaning up, could be 1-19, only way to tell would be have a func for each size, so the name is in the stack trace ) I have actually improved that code since getting the messages, as it was sub-optimal, and haven't had any error reports from the latest version hitting that issue (but that assumes people have updated).

However, that event is also the time that the action bars are loading and populating and a bunch of other stuff is streaming in. I wonder when the lua is jit'd, could it be the first time hit for the jit?

I guess what we really need is something that helps profile the lua, the stack trace is a starting point, but we want more info (I guess I'm spoilt by having profiling tools for my normal day job)

Note this hasn't stopped me working on how to improve my code's impact on the client, I'm working on solution for one of the areas.

Of course that doesn't really help you, as you've got some code that's <1ms to run most of the time, but you're getting blamed

[Semele]

Oh yeah, don't get me wrong. I'm actually enjoying this challenge. I'm just feisty sometimes and tact isn't my strongest trait.

I'm tempted to somehow push the "Player.Ready" event further down the list and try and account for the client actually loading. Obviously, an event from the Addon API saying so would be even better (unless there is one and I've missed it).

Lets face it, SRM's Player.Ready should be more "Sync Start" so everything using it can all synchronize perfectly every start-up.

For KBM, I'm adding a new pre-fetch caching system for certain UI objects I normally create on the fly then cache after use. Instead, I can calculate the maximum number of these objects that could ever be used and use an auxiliary Event (I'm thinking System.Update.End) to load one object at a time per frame until the maximum has been reached and have a full cache. This will allow KBM to run at full speed and never technically need to create objects during combat (baring initialization during an encounter/combat).

So far, I've refrained from the obvious route which is to ensure my Addons insert their events at the beginning of the table and monitor their position. This would just be an *** like move I couldn't bring myself to do even though I know it'd probably remove practically all performance warnings for KBM.

PS. If I catch any other addon author doing the above, that'll be out-right war, just saying

[DoomSprout]

Error: Performance Warning. Rift is running slowly and may effect Addon performance.

LOL

Not sure if you know, but the watchdog is disabled during handling of Event.Addon.Startup.End.

In Gadgets, I was previously running a lot of my initialisation when the player became available, but I've now moved as much as I possibly can into the above event instead.

So far, I've refrained from the obvious route which is to ensure my Addons insert their events at the beginning of the table and monitor their position.

I believe the change to give each event handler (rather than the entire event) it's own 0.1s timeslice is fairly imminent, so hopefully an all out addon war can be avoided!

[Semele]

Not sure if you know, but the watchdog is disabled during handling of Event.Addon.Startup.End.

In Gadgets, I was previously running a lot of my initialisation when the player became available, but I've now moved as much as I possibly can into the above event instead.

HA! This I did not know. I'll use that as a synchronized start instead. Thanks!

Although, for anyone using SRM, this will not change what Player.Ready does, it'll just give another event fired through SRM to latch on to for any initialization.

I believe the change to give each event handler (rather than the entire event) it's own 0.1s timeslice is fairly imminent, so hopefully an all out addon war can be avoided!

Although if it did come to addon wars, scores must be registered! (j/k)

[DoomSprout]

Although if it did come to addon wars, scores must be registered! (j/k)

Are we allowed to un-register other addon's event handlers, hide their frames, and then use Utility.Dispatch to pretend all of our own inefficient calls belong to other addons?

[Semele]

Are we allowed to un-register other addon's event handlers, hide their frames, and then use Utility.Dispatch to pretend all of our own inefficient calls belong to other addons?

lol, I know right. Could get so evil.

[Thorarin]

Trying to keep the peace and moving back on-topic

Yesterday Zorba mentioned that the Watchdog is disabled "during load and shutdown sequences". Apparently this does not help your startup slowness?

It may indeed be the JITer being at the root of the initial slowness. LuaJIT does a combination of interpretation and compilation. It's possible that the first run of the function is fully interpreted and that the JITer decides to compile it for consecutive executions (kinda like the HotSpot Java VM)

[ZorbaTHut]

Live changelog:

NONBREAKING CHANGES:

* The Addon Watchdog now counts execution time per event handler instead of per event. This means addons will no longer be influenced by the behavior of previous addons.
* The result of Inspect.System.Watchdog() is now more reliable.

[Semele]

Live changelog:

NONBREAKING CHANGES:

* The Addon Watchdog now counts execution time per event handler instead of per event. This means addons will no longer be influenced by the behavior of previous addons.
* The result of Inspect.System.Watchdog() is now more reliable.

Good work! That was actually faster than I'd expected. Now time for some serious optimizing. This made my morning

At least we can technically stop worrying about other authors effects and false positives etc.

[sophee]

Live changelog:

NONBREAKING CHANGES:

* The Addon Watchdog now counts execution time per event handler instead of per event. This means addons will no longer be influenced by the behavior of previous addons.
* The result of Inspect.System.Watchdog() is now more reliable.

Very nice - thanks for this change.
Its live as in live on the servers? Without a patch?

[Sarim]

Live changelog:

NONBREAKING CHANGES:

* The Addon Watchdog now counts execution time per event handler instead of per event. This means addons will no longer be influenced by the behavior of previous addons.
* The result of Inspect.System.Watchdog() is now more reliable.

Sounds good!

One question: is the above mentioned Event.Addon.Startup.End the only event in which the watchdog is disabled? Or does that include other startup events too?

[Adelea]

I'm rewriting one of my addons so that all the UI creation/update happens in a coroutine.

Now, under normal circumstances, it builds fine and quickly and no warning are thrown.

Things change when a conquest match starts...

The build UI code is doing pretty frequent

if Inspect.System.Watchdog() < 0.05 then coroutine.yield() end

But still warnings get thrown.

It's not just addons that are running slowly though - stood in Sanctum, if I disable all addons, and do a /reloadui, I can actually watch the UI draw - the hotkey bars appear with visible delays in them.

Given the native UI is being affected by conquest running, what hope do addons have! (http://www.exyles.com/RIFT/2012-07-09_140510.avi shows this)

Putting something like

local needpause = true
while needpause do
	if Inspect.System.Watchdog() < 0.05 then
		coroutine.yield()
	else
		needpause = false
	end
end

Before every line of code that does something UI related seems a bit of overkill.

[Semele]

Inspect.System.Watchdog() seems to be bugged at the moment, always returning 0.1s no matter what.

I found this out when updating my diagnostic tracking to store the closest the Watchdog timer got to triggering a warning.

I'll quote myself here from the Bug Reports section of this forum. This'll be part of the reason your warnings are getting through.

The other unfortunate fact is, that if the Rift Client itself bogs down (regardless of Addons) you'll have next to zero performance left for your Addon as Addons sit on what seems to be a low priority thread and therefor a badly performing Client will start throwing errors for the smallest of handlers.

These are the hard facts unfortunately. Hopefully we can eventually get some lee-way on our thread priority or something, I dunno.

Just seems sad to me that KBM runs smooth as houses while I'm getting horrid ability lag. I check and check my diagnostics, and even panicked it was KBM causing the Client's button lag. But I don't believe it is. So, I can only imagine the blame KBM receives on lower end machines, when in fact it's the Client at fault, not the Addon.

[DoomSprout]

I'm getting notifications for people getting the brutal 3.0 second chop, when opening dialogs that open instantly on my very low spec machine (1.8 Ghz Core 2 Duo, surely not many people are below that spec?).

It's depressing to get warnings on things that are totally outside your control.

Not sure what I can do about it, 3.0s is a *huge* amount of time, it's a tiny dialog, and I'm not even sure it's correct - one of the people who got it was Solsis, who told me in IRC that the dialog didn't seem slow to open.

From testing I've done, I still think the watchdog is targeting the wrong things entirely. I can knock loads off the framerate by simply adding Frames to the screen. I halved my FPS without so much as a whimper from the doggy:

Rift Addon API Benchmarks

I suspect this is generally having a much bigger impact on client performance than any actual processing we're doing in addons.