2012-10-31

Health tracking

Activity tracking is still MIA :), but health tracking turned out to be a lot simpler than I remembered from my tanking days.  I think there are two reasons for this: first is that I don't care for precision, I just want to "give an idea", which makes life very much easier.  When you're not dealing with exact numbers, you can safely ignore the total HP pool, effect of raid buffs on Stamina and temporary health enhancements (Might of Ursoc and friends).  Of course the result will be approximate, but if you're sitting in bad stuff it'll show up clearly, and that was the original idea.
The second reason is associated to the changes brought by Cataclysm: much larger health pools and "smaller" heals.  In Wrath, tank HP were oscillating like mad, here I'm testing tracking on a DPS (much smaller damage intake) and huge health pools which are not meant to be healed in a single spell.  As a result, the inconsistencies coming from the timing issues (sequence errors resulting in heals arriving before the damage is inflicted) are a lot less visible.
I had to do some internal changes, so that on the health display zooming in provides better resolution for picking and displaying events (there are tons of small heals going on...), and I did some other minor quality of life improvements.  As soon as I can get a windows compiler running, I'll create the "MoP release" and put it up for download.  If you're curious: health tracking in the final Elegon phase looks like this:


(in case you wonder: the final red line is Elegon one-shotting me with his final attack)

2012-10-29

The endless cast

Since I'm abroad I don't have access to any "new" logs to play with.  In particular, I cannot test DoC/NV since I don't have here any logs where I used them..... I've put the code in, but I'll be postponing the tests until I can create some appropriate logs.
So I have decided to add activity tracking: the idea is to see if you are a key-spammer (tons of cast failed due to GCD / low energy) or a classy-clicker (just press the key once exactly at the right time.  Of course, it turns out that it's not so easy.  Apart from the negative-time casts (which I can try to detect as instant cast since I have the spell effect just before the cast_success), I've found a new gem: SPELL_CAST_SUCCESS is used for instant casts, but it doesn't appear in the log for channeled casts.  What I mean is this:

10/17 00:10:27.143  SPELL_CAST_START,0x0180000001B138CB,"Helistar",0x511,0x0,0x0000000000000000,nil,0x80000000,0x80000000,5176,"Wrath",0x8
10/17 00:10:28.189  SPELL_CAST_FAILED,0x0180000001B138CB,"Helistar",0x511,0x0,0x0000000000000000,nil,0x80000000,0x80000000,5176,"Wrath",0x8,"Another action is in progress"
10/17 00:10:28.959  SPELL_CAST_START,0x0180000001B138CB,"Helistar",0x511,0x0,0x0000000000000000,nil,0x80000000,0x80000000,5176,"Wrath",0x8
10/17 00:10:31.163  SPELL_DAMAGE,0x0180000001B138CB,"Helistar",0x511,0x0,0xF130EBFA00004EBC,"Elegon",0x10a48,0x0,5176,"Wrath",0x8,308679,-1,8,0,0,0,nil,nil,nil

The SPELL_DAMAGE event corresponds to the *first* Wrath cast (remember, Wrath has a fairly long "flight time").  This means that I have no way to detect that the actual casting of Wrath has ended, except guessing it from the fact that I had another CAST_START.  This also means that I have no easy way of knowing if the player is idle or not.  I'll need to do some tests, but I fear I'll be forced to go dig in the CAST_FAILED error message to see *why* it failed, in order to understand if it's just a key-spam while already casting (= you're not idle), or if the cast really failed because you moved (or the target died, ...), in which cast the CAST_FAILED indicates a transition back to the idle state.
And it's actually worse: if you cast a single Wrath, I have no way of knowing that the casting has ended.... since the spell effect (SPELL_DAMAGE) will appear a lot later.

I don't know why, but I'm starting to think that this whole "activity display" thing is a bad idea.....

2012-10-25

Cast, instant cast, *negative-time* cast!

More combat log weirdness.
Even more weird since it cannot be due to multiple clients having different latencies and the lag-compensation code messing the timestamps: here I am healing *myself*:

10/17 00:17:00.970  SPELL_HEAL,0x0180000001B138CB,"Helistar",0x511,0x0,0x0180000001B138CB,"Helistar",0x511,0x0,5185,"Healing Touch",0x8,92919,0,0,nil
10/17 00:17:00.991  SPELL_CAST_START,0x0180000001B138CB,"Helistar",0x511,0x0,0x0000000000000000,nil,0x80000000,0x80000000,5185,"Healing Touch",0x8

The healing touch healed me 21ms *before* I even cast it.....
In the best of worlds we would have SPELL_CAST_START followed by SPELL_CAST_SUCCESS and then SPELL_...whatever effect it does...
Or maybe, for an instant spell we could just have the effect, or if we really want to keep track of client/server latency, SPELL_CAST_START followed by the spell effect.
Clearly, we are not in the best of worlds.
Before you ask: yes, this makes for nightmarish scenarios where some poor piece of code sees a cast_start and hopefully waits (forever...) for the spell effect to take place (solution: ignore the cast_start).  It's bit like the horrible consistency errors you get on bosses like Ultraxion or Gara'jal where the logs of players from one "dimension" are missing all the information about those in the other dimension, leading to all possible aura-uptime consistency failures....

2012-10-23

Updates, updates

The list of stuff to add is growing, but the code is not :)  this is not good.
I need to add the heals/DoC detection/Wrathspam and I just found out that I messed up Soul of the Forest, which, unbelievably, actually appears as SPELL_ENERGIZE in the log.
I have checked the damn Rip uptime log thing and it's trouble:
- applied at (seconds) 12.831 (expected to end +16s later, so at 28.831)
- refreshed 3 times by shred (so expected to end in total at +22s or 34.831)
- gets refreshed by another Rip at 38.166
Now, I know that one extra tick is possible, which would place the expiration at 36.831.  I also know that the aura is "sometimes" longer (even if it appears correctly to end at the last tick in EventHorizon).  But this is almost 1.5 AFTER the exceptional tick.  It's not a +6s shred refresh, it's almost +10s refresh (9.33 to be exact).  I don't know exactly how to deal with this.  I will alter the BitW code to be a lot more tolerant (+3.3s/shred instead of +2s), but I'm wondering if something is going wrong...... the rip refresh mechanism has always been "weird", but it's the first time I see it being *so* weird.
Whatever... I'll see if I can cook up a release in a couple of weeks.

2012-10-17

Elegon down, and Rip woes....

Ok, so Elegon is down.  Ugly down, we (barely) won.  So I feed the log to the analyzer and I find that I suck (hardly a surprise), but also that there is a phase where Elegon is DoT-immune (I had not really cared much to check, it seems to be during the p2-p1 transitions, from a cursory look).
But there's stuff going wrong: I have a BitW range which starts in phase 1, which is definitely wrong.  Looking at the visualization it seems like there's a Rip which is lasting too long.  I know that 1 extra tick is possible, but here it's more than that.  Usually, even when one extra tick is added, the aura fades immediately afterwards, but here it seems like there's a refresh after half a tick, and this with 4 extra ticks.  Since visualization is independent of the preprocessing, it means that there really is some spell_periodic_damage going on.  I'll have to go through the log in detail to see what happens.  Blizzard does weird stuff with the logs at times (and not just logs...) :).

2012-10-11

RWF for MoP

I've started updating RWF for Pandaria.

There is a ton of changes, mostly in the amount of stuff to track.  Some mechanics have changed as well, so my energy check for TF are failing systematically, I'll have to look into detail to see what's going on.
I also have no idea on how to provide a "quick" display on the buffed status of DoTs, which can now be buffed by TF, DoC and (rarely) agi potion.  I think it would be nice to be able to quickly see if a DoT was buffed and by what without being forced to hover on it, but there are a lot of combinations, so using colors would be an utter mess.  I'll probably stick to "red = error, yellow = unbuffed, green = buffed by at least one thing" and let the user hover on the DoT to see the details.
There were also some random changes in the combat log, such as the type of environmental damage being written lowercase instead of uppercase (which crashed the parser.....), I guess that with time I'll be able to clean them up.
Well, at least the preprocessor to locate the execute (BitW) range works.