Skip to main content
  1. Posts/

Day 73 - Effectiveness

OldDays seitan-spin ruby cucumber

Wordy.
Wordy.

In which we read a lot of code, and try a lot of things, to little effect.

Test Every Day
#

Goal: Test everything in PlayerEffects that actually does something
#

As we found out previously, not all of the effects can be imposed on a player by adding to the PlayerEffects table. So let’s dig into the server and see what actually has an impact:

Where do we load them from the DB?

DragonsSpine/DAL/DBPlayer.cs
2254
2255
2256
2257
2258
2259
2260
2261
2262
2263
2264
2265
2266
2267
2268
2269
2270
2271
2272
2273
2274
2275
2276
2277
2278
2279
2280
2281
2282
2283
2284
2285
2286
2287
2288
2289
2290
internal static void loadPlayerEffects(PC pc) // retrieves effect record from PlayerEffects table
{
  try
  {
    for (int slot = 1; slot <= 20; slot++)
    {
      SqlStoredProcedure sp = new SqlStoredProcedure("prApp_PlayerEffects_Select", DataAccess.GetSQLConnection());
      sp.AddParameter("@PlayerID", SqlDbType.Int, 4, ParameterDirection.Input, pc.PlayerID);
      sp.AddParameter("@EffectSlot", SqlDbType.Int, 4, ParameterDirection.Input, slot);
      DataTable dtPlayerEffect = sp.ExecuteDataTable();
      foreach (DataRow dr in dtPlayerEffect.Rows)
      {
        if (Convert.ToInt32(dr["EffectID"]) > 0)
        {
          addPlayerEffect(dr, pc);
        }
      }
    }
  }
  catch (Exception e)
  {
    Utils.LogException(e);
  }
}

internal static void addPlayerEffect(DataRow drItem, PC pc) // convert PlayerEffects table results
{
  try
  {
    Effect.CreateCharacterEffect((Effect.EffectType)Convert.ToInt32(drItem["EffectID"]),
      Convert.ToInt32(drItem["Amount"]), pc, Convert.ToInt32(drItem["Duration"]), null);
  }
  catch(Exception e)
  {
    Utils.LogException(e);
  }
}

Ah, let’s look at this CreateCharacterEffect:

DragonsSpine/GameSystems/Effects/Effect.cs
590
591
592
593
594
595
596
597
598
599
600
601
602
603
604
605
606
607
608
609
610
611
612
613
614
615
616
617
618
619
public static void CreateCharacterEffect(EffectType effectType, int effectAmount, Character target, int duration, Character caster)
{
  try
  {
    if (target.effectList.ContainsKey(effectType)) // the target already has this effect type
    {
      if (target.effectList[effectType].effectAmount <= effectAmount)
      {
        target.effectList[effectType].effectAmount = effectAmount;
        target.effectList[effectType].duration = duration;
        target.effectList[effectType].caster = caster;
      }
      return;
    }

    Effect effect = new Effect(effectType, effectAmount, duration, target, caster);

    switch (effectType)
    {
      case EffectType.Dog_Follow:
        target.FollowName = caster.Name;
        effect.caster = null;
        break;
      #region Strictly Bottle Effects
      case EffectType.Ale:
        target.SendToAllInSight(target.Name + " burps loudly.");
        break;
      case EffectType.Balm: // healing over time
        Effect.DoBalmEffect(target, target.effectList[effectType]);
        break;

DragonsSpine/GameSystems/Effects/Effect.cs
851
852
853
854
855
856
857
858
859
860
861
862
863
864
865
866
867
868
869
870
871
      case EffectType.Fear:
        if(!target.IsPC)
        {
          if(target.Group != null)
          {
            target.Group.Remove((NPC)target);
          }
        }
        break;
      case EffectType.Blind:
        if (!target.IsPC)
        {
          if (target.Group != null)
          {
            target.Group.Remove((NPC)target);
          }
        }
        break;
      default:
        break;
    }

So there are all sorts of initial effects, and an Effect object is created:

DragonsSpine/GameSystems/Effects/Effect.cs
221
222
223
224
225
226
227
228
229
230
231
232
233
// character effect
public Effect(EffectType effectType, int amount, int duration, Character target, Character caster)
{
  this.effectType = effectType;
  this.effectAmount = amount;
  this.duration = duration;
  this.target = target;
  this.caster = caster;
  this.target.effectList.Add(this.effectType, this);
  this.effectTimer = new System.Timers.Timer(DragonsSpineMain.MasterRoundInterval);
  this.effectTimer.Elapsed += new System.Timers.ElapsedEventHandler(CharacterEffectEvent);
  this.effectTimer.Start();
}

And we get a timer for the ongoing effects:

DragonsSpine/GameSystems/Effects/Effect.cs
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
void CharacterEffectEvent(object sender, System.Timers.ElapsedEventArgs e)
{
  if (!this.target.IsPC || this.target.PCState == Globals.ePlayerState.PLAYING)
  {
    if (this.duration > 0)
    {
      this.duration--;
    }

    try
    {
      if (this.duration == 0)
      {
        if (this.effectType == EffectType.Hide_In_Shadows)
        {
          if (this.caster != null)
          {
            if (this.caster.IsPC)
            {
              if (this.caster.IsHidden)
              {
                Map.checkHiddenStatus(this.caster);
              }
              if (!this.caster.IsHidden)
              {
                this.effectTimer.Stop();
                this.StopCharacterEffect();
              }
            }
          }
        }
        else
        {
          this.effectTimer.Stop();
          this.StopCharacterEffect();
        }
      }
      else
      {
        switch (this.effectType)
        {
          case EffectType.Balm:
            Effect.DoBalmEffect(this.target, this);
            break;
        }
      }
    }
    catch (Exception ex)
    {
      this.duration = 1;
      Utils.LogException(ex);
    }
  }
}

Which is a lot of lines but not much action (full disclosure: I strongly prefer K&R style braces over the Allman style used in this code). Currently concerned with DB-driven effects (where the caster doesn’t exist), we can boil this down to:

  1. The duration is decremented each round.
  2. If duration is zero, the effect is stopped unless it is Hide_In_Shadows.
  3. If the duration is not zero, the Balm effect occurs.

What does StopCharacterEffect do?

DragonsSpine/GameSystems/Effects/Effect.cs
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
452
public void StopCharacterEffect()
{
  try
  {
    switch (this.effectType)
    {
      case EffectType.Dog_Follow:
        this.target.FollowName = "";
        break;
      case EffectType.Peek:
        this.target.CurrentCell = this.target.MyClone.CurrentCell;
        this.target.MyClone.CurrentCell = null;
        this.target.IsInvisible = this.target.WasInvisible;
        this.target.WasInvisible = false;
        this.target.MyClone.RemoveFromWorld();
        this.target.MyClone.RemoveFromLimbo();
        this.target.MyClone = null;
        this.target.PeekTarget = null;
        break;

DragonsSpine/GameSystems/Effects/Effect.cs
552
553
554
555
556
557
558
559
560
561
562
563
564
565
566
567
568
569
570
571
572
573
574
575
576
577
578
579
580
581
582
583
584
585
586
587
588
      case EffectType.Balm: // healing over time
        if (this.effectAmount > 0)
        {
          this.target.Hits += this.effectAmount;
          if (this.target.Hits > this.target.HitsFull)
            this.target.Hits = this.target.HitsFull;
        }
        break;
      default:
        break;
    }

    this.target.effectList.Remove(this.effectType);
    if (this.target.PCState == Globals.ePlayerState.PLAYING || !this.target.IsPC)
    {
      if (Effect.GetEffectName(this.effectType) != "Unknown")
      {
        this.target.WriteToDisplay("The " + Effect.GetEffectName(this.effectType) + " spell has worn off.");

        if (this.caster != null && this.caster.IsPC)
        {
          PC pc = PC.getOnline(this.caster.PlayerID);
          if (pc != null && pc.PCState == Globals.ePlayerState.PLAYING && pc.PlayerID != this.target.PlayerID)
          {
            pc.WriteToDisplay("Your " + GetEffectName(this.effectType) + " spell has worn off of " + this.target.Name + ".");
          }
        }
      }
    }
    
  }
  catch (Exception e)
  {
    Utils.Log("Failure at StopCharacterEffect Effect: " + this.effectType.ToString(), Utils.LogType.SystemFailure);
    Utils.LogException(e);
  }
}

Cleans up the actual effect, and always tells the player it was a spell (as we’ve seen). And what about that DoBalmEffect?

DragonsSpine/GameSystems/Effects/Effect.cs
1482
1483
1484
1485
1486
1487
1488
1489
1490
1491
1492
1493
1494
1495
1496
1497
1498
1499
static void DoBalmEffect(Character target, Effect effect)
{
  try
  {
    int balmAmount = (int)(effect.effectAmount / 2);
    effect.effectAmount -= balmAmount;
    target.Hits += balmAmount;
    if (target.Hits >= target.HitsFull || effect.duration <= 0 || effect.effectAmount <= 0)
    {
      target.Hits = target.HitsFull;
      effect.StopCharacterEffect();
    }
  }
  catch (Exception e)
  {
    Utils.LogException(e);
  }
}

At first glance, it looks like this: heals and consumes half of the remaining effectAmount each turn, until either a) the character is fully healed, b) the duration has ended, or c) the effectAmount has diminished to zero; and then fully heals the character anyway?

But we know from CharacterEffectEvent that this is only called when duration is non-zero, and duration is only decremented when above zero, so we have no chance of getting here with a duration of zero or less. (Assuming an effect is not created with a zero or negative duration.)

And the effect amount is diminished by half its value truncated to an int. As long as it started out positive, it’ll never reach zero. At one, it will stay at one, healing zero hits per turn.

So the tripartite conditional in DoBalmEffect is probably historical in origin, and doesn’t actually cause the issues we were worried about.

Reality: Trying to Figure Out One Test Takes Forever
#

After a little trial and error, here’s a test that passes:

features/player_effects.feature
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
Scenario: Balm effect fades correctly when limited by duration
  Given I use the "minimal" database
  And I add player and character "TestBalm01"
  And I set the character's max HP to "30"
  And I set the character's current HP to "1"
  And I give the character a balm effect of "20" for "3" turns
  And the server is started
  When I log on as "TestBalm01"
  And I enter the game
  And after "0" turns I have a current HP of "16"
  And after "1" turns I have a current HP of "18"
  And after "1" turns I have a current HP of "20"
  And after "1" turns I have a current HP of "22"
  And after "1" turns I have a current HP of "22"
  And after "1" turns I have a current HP of "23"
  And after "1" turns I have a current HP of "23"
  And after "1" turns I have a current HP of "23"
  And after "1" turns I have a current HP of "24"

That seems a little counter-intuitive. To make some sense of it, we need to recall that the effect triggers immediately on being created, and to know about the ThirdRoundEvent:

DragonsSpine/GameObjects/GameLiving/Character/Character.cs
1497
1498
1499
1500
1501
1502
1503
#region Constructor
public Character()
{
  this.thirdRoundTimer = new Timer(DragonsSpineMain.MasterRoundInterval * 3);
  this.thirdRoundTimer.Elapsed += new ElapsedEventHandler(ThirdRoundEvent);
  this.thirdRoundTimer.AutoReset = true;
  this.thirdRoundTimer.Start();
DragonsSpine/GameObjects/GameLiving/Character/Character.cs
1663
1664
1665
1666
1667
1668
1669
1670
1671
1672
1673
1674
1675
#region Timer Related
protected void ThirdRoundEvent(object obj, ElapsedEventArgs e)
{
  if (this.IsPC && this.PCState != Globals.ePlayerState.PLAYING)
    return;

  if (!this.IsDead)
  {
    //TODO: modify stats gain to reflect additional stats due to temporary stat effects
    if (this.Hits < this.HitsFull) // gain a point of health
    {
      this.Hits++;
      this.updateHits = true;

A whole set of things happen every third round the character is in the game, including one point of healing.

So let’s attempt to annotate that test:

  And I enter the game
  # 1 + 10 (initial effect) = 11 (amount now 10, duration now 3)
  And after "0" turns I have a current HP of "16"
  # 11 + 5 (effect on initial turn) = 16 (amount now 5, duration now 2)
  And after "1" turns I have a current HP of "18"
  # 16 + 2 (effect) = 18 (amount now 3, duration now 1)
  And after "1" turns I have a current HP of "20"
  # 18 + 1 (effect) = 19 (amount now 2, duration now 0)
  # 19 + 1 (third round healing) = 20
  And after "1" turns I have a current HP of "22"
  # ???

It makes sense up to the round where I suddenly have 22 HP. I’ll have to actually add some debug to figure this one out.

9/30/2016 0:00:06 AM: {Unknown} Round 0: Character TestBalm01_name receives balm effect. effectAmount 20, duration 3.
9/30/2016 0:00:06 AM: {Unknown} Round 0: Character TestBalm01_name received balm effect. Healed 10 HP to make current HP 11, effectAmount now 10.
9/30/2016 0:00:06 AM: {Unknown} Round 0: Character TestBalm01_name receives balm effect. effectAmount 10, duration 3.
9/30/2016 0:00:06 AM: {Unknown} Round 0: Character TestBalm01_name received balm effect. Healed 5 HP to make current HP 16, effectAmount now 5.
9/30/2016 0:00:11 AM: {Unknown} Round 1: Character TestBalm01_name receives balm effect. effectAmount 5, duration 2.
9/30/2016 0:00:11 AM: {Unknown} Round 1: Character TestBalm01_name received balm effect. Healed 2 HP to make current HP 18, effectAmount now 3.
9/30/2016 0:00:16 AM: {Unknown} Round 2: Character TestBalm01_name receives balm effect. effectAmount 3, duration 1.
9/30/2016 0:00:16 AM: {Unknown} Round 2: Character TestBalm01_name received balm effect. Healed 1 HP to make current HP 19, effectAmount now 2.
9/30/2016 0:00:19 AM: {Unknown} Round 3: Character TestBalm01_name received ThirdRoundEvent healing, current HP now 20.
9/30/2016 0:00:34 AM: {Unknown} Round 6: Character TestBalm01_name received ThirdRoundEvent healing, current HP now 23.
9/30/2016 0:00:49 AM: {Unknown} Round 9: Character TestBalm01_name received ThirdRoundEvent healing, current HP now 24.

My expectations are confirmed, but there’s some extra healing going on that I don’t know about. I looked through the code but couldn’t see what was going on. In a final desperate effort I added code to print out System.Environment.StackTrace every time the character’s HP changed.

9/30/2016 0:12:23 AM: {Unknown} Round 3: Character TestBalm01_name had their Hits set to 22 (was 20).
9/30/2016 0:12:23 AM: {Unknown} Stack trace:    at System.Environment.get_StackTrace()
   at DragonsSpine.Character.set_Hits(Int32 value) in 
   k:\301days\Code\drag-spin-exp\DragonsSpine\GameObjects\GameLiving\Character\Character.cs:line 1000
   at DragonsSpine.Effect.StopCharacterEffect() in 
   k:\301days\Code\drag-spin-exp\DragonsSpine\GameSystems\Effects\Effect.cs:line 555

and there it was. I had somehow missed what was going on in StopCharacterEffect; once the duration has elapsed, there’s a kind of “catch-up” clause that applies the remaining amount:

DragonsSpine/GameSystems/Effects/Effect.cs
552
553
554
555
556
557
558
559
560
561
562
      case EffectType.Balm: // healing over time
        if (this.effectAmount > 0)
        {
          this.target.Hits += this.effectAmount;
          if (this.target.Hits > this.target.HitsFull)
            this.target.Hits = this.target.HitsFull;
        }
        break;
      default:
        break;
    }

I’ll add some debug output there just to make sure:

9/30/2016 0:28:03 AM: {Unknown} Round 0: Character TestBalm01_name receives balm effect. effectAmount 20, duration 3.
9/30/2016 0:28:03 AM: {Unknown} Round 0: Character TestBalm01_name received balm effect. Healed 10 HP to make current HP 11, effectAmount now 10.
9/30/2016 0:28:03 AM: {Unknown} Round 0: Character TestBalm01_name receives balm effect. effectAmount 10, duration 3.
9/30/2016 0:28:03 AM: {Unknown} Round 0: Character TestBalm01_name received balm effect. Healed 5 HP to make current HP 16, effectAmount now 5.
9/30/2016 0:28:08 AM: {Unknown} Round 1: Character TestBalm01_name receives balm effect. effectAmount 5, duration 2.
9/30/2016 0:28:08 AM: {Unknown} Round 1: Character TestBalm01_name received balm effect. Healed 2 HP to make current HP 18, effectAmount now 3.
9/30/2016 0:28:13 AM: {Unknown} Round 2: Character TestBalm01_name receives balm effect. effectAmount 3, duration 1.
9/30/2016 0:28:13 AM: {Unknown} Round 2: Character TestBalm01_name received balm effect. Healed 1 HP to make current HP 19, effectAmount now 2.
9/30/2016 0:28:16 AM: {Unknown} Round 3: Character TestBalm01_name received ThirdRoundEvent healing, current HP now 20.
9/30/2016 0:28:18 AM: {Unknown} Round 3: Character TestBalm01_name received final balm effect. Healed 2 HP to make current HP 22.
9/30/2016 0:28:31 AM: {Unknown} Round 6: Character TestBalm01_name received ThirdRoundEvent healing, current HP now 23.
9/30/2016 0:28:46 AM: {Unknown} Round 9: Character TestBalm01_name received ThirdRoundEvent healing, current HP now 24.

So now the correctly annotated test case:

features/player_effects.feature
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
Scenario: Balm effect processes correctly when limited by duration
  Given I use the "minimal" database
  And I add player and character "TestBalm01"
  And I set the character's max HP to "30"
  And I set the character's current HP to "1"
  And I give the character a balm effect of "20" for "3" turns
  And the server is started
  When I log on as "TestBalm01"
  And I enter the game
  # 1 + 10 (initial effect) = 11 (amount now 10, duration now 3)
  And after "0" turns I have a current HP of "16"
  # 11 + 5 (effect on initial turn) = 16 (amount now 5, duration now 2)
  And after "1" turns I have a current HP of "18"
  # 16 + 2 (effect) = 18 (amount now 3, duration now 1)
  And after "1" turns I have a current HP of "20"
  # 18 + 1 (effect) = 19 (amount now 2, duration now 0)
  # 19 + 1 (third round healing) = 20
  And after "1" turns I have a current HP of "22"
  # 20 + 2 (effect) = 22 (effect completed)
  And after "1" turns I have a current HP of "22"
  And after "1" turns I have a current HP of "23"
  # 22 + 1 (third round healing) = 23

And it even passes. One more to make sure we understand how this logic works:

features/player_effects.feature
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
Scenario: Balm effect processes correctly when limited by effect
  Given I use the "minimal" database
  And I add player and character "TestBalm02"
  And I set the character's max HP to "30"
  And I set the character's current HP to "1"
  And I give the character a balm effect of "10" for "4" turns
  And the server is started
  When I log on as "TestBalm02"
  And I enter the game
  # 1 + 5 (initial effect) = 6 (amount now 5, duration now 4)
  And after "0" turns I have a current HP of "8"
  # 6 + 2 (effect on initial turn) = 8 (amount now 3, duration now 3)
  And after "1" turns I have a current HP of "9"
  # 8 + 1 (effect) = 9 (amount now 2, duration now 2)
  And after "1" turns I have a current HP of "11"
  # 9 + 1 (effect) = 10 (amount now 1, duration now 1)
  # 10 + 1 (third round healing) = 11
  And after "1" turns I have a current HP of "11"
  # 11 + 0 (effect) = 11 (amount still 1, duration now 0)
  And after "1" turns I have a current HP of "12"
  # 11 + 1 (effect) = 12 (effect completed)
  And after "1" turns I have a current HP of "13"
  # 12 + 1 (third round healing) = 13

Ok, that’s one effect down, many to go. Unfortunately database connection issues keep getting in the way of running through the complete test suite. I’ll need to tackle that once and for all. Tomorrow.


Useful Stuff
#


More to come
More to come

Day 73 code - tests

Day 73 code - server