Skip to content

Commit

Permalink
add tracing example
Browse files Browse the repository at this point in the history
  • Loading branch information
@area363
area363 committed Jul 11, 2024
1 parent a5dd5bd commit 63265e3
Show file tree
Hide file tree
Showing 3 changed files with 94 additions and 1 deletion.
2 changes: 1 addition & 1 deletion .Libplanet
Submodule .Libplanet updated 7 files
+1 −0 Libplanet.Action/Libplanet.Action.csproj
+10 −1 Libplanet.Action/State/AccountState.cs
+6 −0 Libplanet.Action/State/WorldBaseState.cs
+1 −0 Libplanet.Net/Libplanet.Net.csproj
+42 −20 Libplanet.Net/Transports/NetMQTransport.cs
+14 −1 Libplanet/Blockchain/BlockChainStates.cs
+2 −1 Libplanet/Libplanet.csproj
92 changes: 92 additions & 0 deletions Lib9c/Action/HackAndSlash.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -42,6 +42,7 @@ public class HackAndSlash : GameAction, IHackAndSlashV10
public Address AvatarAddress;
public int TotalPlayCount = 1;
public int ApStoneCount = 0;
private readonly ActivitySource ActivitySource = new ActivitySource("Lib9c.Action.HackAndSlash");

IEnumerable<Guid> IHackAndSlashV10.Costumes => Costumes;
IEnumerable<Guid> IHackAndSlashV10.Equipments => Equipments;
Expand Down Expand Up @@ -117,6 +118,7 @@ public IWorld Execute(
var addressesHex = $"[{signer.ToHex()}, {AvatarAddress.ToHex()}]";
var started = DateTimeOffset.UtcNow;
const string source = "HackAndSlash";
using var activity = ActivitySource.StartActivity("HackAndSlash");
Log.Verbose("{AddressesHex} {Source} from #{BlockIndex} exec started",
addressesHex, source, blockIndex);

Expand Down Expand Up @@ -145,17 +147,27 @@ public IWorld Execute(

var sw = new Stopwatch();
sw.Start();
using var avatarStateActivity = ActivitySource.StartActivity(
"GetAvatarState",
ActivityKind.Internal,
activity.Id);
if (!states.TryGetAvatarState(signer, AvatarAddress, out AvatarState avatarState))
{
throw new FailedLoadStateException(
$"{addressesHex}Aborted as the avatar state of the signer was failed to load.");
}

avatarStateActivity?.Dispose();
sw.Stop();
Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}",
addressesHex, source, "Get AvatarState", blockIndex, sw.Elapsed.TotalMilliseconds);

sw.Restart();
using var sheetActivity = ActivitySource.StartActivity(
"GetSheets",
ActivityKind.Internal,
activity.Id);

var collectionExist = states.TryGetCollectionState(AvatarAddress, out var collectionState) && collectionState.Ids.Any();
var sheetTypes = new List<Type>
{
Expand Down Expand Up @@ -190,11 +202,18 @@ public IWorld Execute(
containQuestSheet: true,
containSimulatorSheets: true,
sheetTypes: sheetTypes);

sheetActivity?.Dispose();
sw.Stop();
Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}",
addressesHex, source, "Get Sheets", blockIndex, sw.Elapsed.TotalMilliseconds);

sw.Restart();

var checkStateActivity = ActivitySource.StartActivity(
"CheckState",
ActivityKind.Internal,
activity.Id);
var stakingLevel = 0;
StakeActionPointCoefficientSheet actionPointCoefficientSheet = null;

Expand All @@ -206,6 +225,7 @@ public IWorld Execute(
stakingLevel = actionPointCoefficientSheet.FindLevelByStakedAmount(signer, stakedAmount);
}

checkStateActivity?.Dispose();
sw.Stop();
Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}",
addressesHex, source, "Check StateState", blockIndex, sw.Elapsed.TotalMilliseconds);
Expand All @@ -225,16 +245,25 @@ public IWorld Execute(
}

sw.Restart();
var stageSheetActivity = ActivitySource.StartActivity(
"GetStageSheet",
ActivityKind.Internal,
activity.Id);
if (!sheets.GetSheet<StageSheet>().TryGetValue(StageId, out var stageRow))
{
throw new SheetRowNotFoundException(addressesHex, nameof(StageSheet), StageId);
}

stageSheetActivity?.Dispose();
sw.Stop();
Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}",
addressesHex, source, "Get StageSheet", blockIndex, sw.Elapsed.TotalMilliseconds);

sw.Restart();
var validateWorldActivity = ActivitySource.StartActivity(
"ValidateWorld",
ActivityKind.Internal,
activity.Id);
var worldInformation = avatarState.worldInformation;
if (!worldInformation.TryGetWorld(WorldId, out var world))
{
Expand Down Expand Up @@ -271,11 +300,16 @@ public IWorld Execute(
);
}

validateWorldActivity?.Dispose();
sw.Stop();
Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}",
addressesHex, source, "Validate World", blockIndex, sw.Elapsed.TotalMilliseconds);

sw.Restart();
var validateItemsActivity = ActivitySource.StartActivity(
"ValidateItems",
ActivityKind.Internal,
activity.Id);
var gameConfigState = states.GetGameConfigState();
if (gameConfigState is null)
{
Expand All @@ -287,10 +321,17 @@ public IWorld Execute(
Equipments, blockIndex, gameConfigState);
var foodIds = avatarState.ValidateConsumableV2(Foods, blockIndex, gameConfigState);
var costumeIds = avatarState.ValidateCostumeV2(Costumes, gameConfigState);

validateItemsActivity?.Dispose();
sw.Stop();
Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}",
addressesHex, source, "Validate Items", blockIndex, sw.Elapsed.TotalMilliseconds);
sw.Restart();

var unequipItemsActivity = ActivitySource.StartActivity(
"UnequipItems",
ActivityKind.Internal,
activity.Id);
var materialItemSheet = sheets.GetSheet<MaterialItemSheet>();
var apPlayCount = TotalPlayCount;
var minimumCostAp = stageRow.CostAP;
Expand Down Expand Up @@ -367,11 +408,19 @@ public IWorld Execute(
var items = Equipments.Concat(Costumes);
avatarState.EquipItems(items);
sw.Stop();

unequipItemsActivity?.Dispose();
Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}",
addressesHex, source, "Unequip items", blockIndex, sw.Elapsed.TotalMilliseconds);

sw.Restart();
var questSheetActivity = ActivitySource.StartActivity(
"GetQuestSheet",
ActivityKind.Internal,
activity.Id);
var questSheet = sheets.GetQuestSheet();

questSheetActivity?.Dispose();
sw.Stop();
Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}",
addressesHex, source, "Get QuestSheet", blockIndex, sw.Elapsed.TotalMilliseconds);
Expand All @@ -384,19 +433,29 @@ public IWorld Execute(
if (ids.Any())
{
sw.Restart();
var questListActivity = ActivitySource.StartActivity(
"UpdateQuestList",
ActivityKind.Internal,
activity.Id);
questList.UpdateList(
questSheet,
sheets.GetSheet<QuestRewardSheet>(),
sheets.GetSheet<QuestItemRewardSheet>(),
sheets.GetSheet<EquipmentItemRecipeSheet>(),
ids);
questListActivity?.Dispose();
sw.Stop();
Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}",
addressesHex, source, "Update QuestList", blockIndex, sw.Elapsed.TotalMilliseconds);
}

sw.Restart();

var skillStateActivity = ActivitySource.StartActivity(
"GetSkillState",
ActivityKind.Internal,
activity.Id);

var skillStateAddress = Addresses.GetSkillStateAddressFromAvatarAddress(AvatarAddress);
var isNotClearedStage = !avatarState.worldInformation.IsStageCleared(StageId);
var skillsOnWaveStart = new List<Skill>();
Expand Down Expand Up @@ -430,6 +489,7 @@ public IWorld Execute(
}
}

skillStateActivity?.Dispose();
sw.Stop();
Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}",
addressesHex, source, "Get skillState", blockIndex, sw.Elapsed.TotalMilliseconds);
Expand All @@ -438,6 +498,11 @@ public IWorld Execute(
var worldUnlockSheet = sheets.GetSheet<WorldUnlockSheet>();
var crystalStageBuffSheet = sheets.GetSheet<CrystalStageBuffGachaSheet>();
sw.Restart();

var slotstateActivity = ActivitySource.StartActivity(
"UpdateSlotState",
ActivityKind.Internal,
activity.Id);
// if PlayCount > 1, it is Multi-HAS.
var simulatorSheets = sheets.GetSimulatorSheets();

Expand Down Expand Up @@ -465,10 +530,17 @@ public IWorld Execute(
{
states = states.SetRuneState(AvatarAddress, runeStates);
}

slotstateActivity?.Dispose();
sw.Stop();
Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}",
addressesHex, source, "Update slotState", blockIndex, sw.Elapsed.TotalMilliseconds);

var simulatorActivity = ActivitySource.StartActivity(
"Simulator",
ActivityKind.Internal,
activity.Id);

var stageWaveRow = sheets.GetSheet<StageWaveSheet>()[StageId];
var enemySkillSheet = sheets.GetSheet<EnemySkillSheet>();
var costumeStatSheet = sheets.GetSheet<CostumeStatSheet>();
Expand Down Expand Up @@ -522,6 +594,10 @@ public IWorld Execute(
addressesHex, source, "Simulator.Simulate()", blockIndex, sw.Elapsed.TotalMilliseconds);

sw.Restart();
var clearStageActivity = ActivitySource.StartActivity(
"ClearStage",
ActivityKind.Internal,
activity.Id);
if (simulator.Log.IsClear)
{
avatarState.worldInformation.ClearStage(
Expand All @@ -532,6 +608,8 @@ public IWorld Execute(
worldUnlockSheet
);
stageCleared = true;

clearStageActivity?.Dispose();
sw.Stop();
Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}",
addressesHex, source, "ClearStage", blockIndex, sw.Elapsed.TotalMilliseconds);
Expand Down Expand Up @@ -579,21 +657,34 @@ public IWorld Execute(
simulator.Log.waveCount
);
}
simulatorActivity?.Dispose();
sw.Stop();
Log.Debug("{AddressesHex} {Source} {Process} from #{BlockIndex}: {Elapsed}, Count: {PlayCount}",
addressesHex, source, "loop Simulate", blockIndex, sw.Elapsed.TotalMilliseconds, TotalPlayCount);

// Update CrystalRandomSkillState.Stars by clearedWaveNumber. (add)
skillState?.Update(starCount, crystalStageBuffSheet);
sw.Restart();

var updateAvatarActivity = ActivitySource.StartActivity(
"UpdateAvatarState",
ActivityKind.Internal,
activity.Id);
avatarState.UpdateQuestRewards(materialItemSheet);
avatarState.updatedAt = blockIndex;
avatarState.mailBox.CleanUp();

updateAvatarActivity?.Dispose();
sw.Stop();
Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}",
addressesHex, source, "Update AvatarState", blockIndex, sw.Elapsed.TotalMilliseconds);

sw.Restart();

var setStateActivity = ActivitySource.StartActivity(
"SetState",
ActivityKind.Internal,
activity.Id);
if (isNotClearedStage)
{
avatarState.worldInformation.TryGetLastClearedStageId(out var lastClearedStageId);
Expand All @@ -609,6 +700,7 @@ public IWorld Execute(

states = states.SetAvatarState(AvatarAddress, avatarState);

setStateActivity?.Dispose();
sw.Stop();
Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}",
addressesHex, source, "Set States", blockIndex, sw.Elapsed.TotalMilliseconds);
Expand Down
1 change: 1 addition & 0 deletions Lib9c/Lib9c.csproj
View file
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@
<ItemGroup>
<PackageReference Include="DecimalMath.DecimalEx" Version="1.0.2" />
<PackageReference Include="OptimizedPriorityQueue" Version="4.2.0" />
<PackageReference Include="Pyroscope" Version="0.8.14" />
<PackageReference Include="Serilog" Version="2.10.0" />
<PackageReference Include="SonarAnalyzer.CSharp" Version="8.38.0.46746">
<IncludeAssets>runtime; build; native; contentfiles; analyzers</IncludeAssets>
Expand Down

0 comments on commit 63265e3

Please sign in to comment.