diff --git a/Lib9c/Action/HackAndSlash.cs b/Lib9c/Action/HackAndSlash.cs index 27a02b5c6f..2ec9a0c4fa 100644 --- a/Lib9c/Action/HackAndSlash.cs +++ b/Lib9c/Action/HackAndSlash.cs @@ -123,7 +123,8 @@ public IAccountStateDelta Execute( var addressesHex = $"[{signer.ToHex()}, {AvatarAddress.ToHex()}]"; var started = DateTimeOffset.UtcNow; const string source = "HackAndSlash"; - Log.Verbose("{AddressesHex} {Source} HAS exec started", addressesHex, source); + Log.Verbose("{AddressesHex} {Source} from #{BlockIndex} exec started", + addressesHex, source, blockIndex); if (ApStoneCount > UsableApStoneCount) { @@ -157,7 +158,8 @@ public IAccountStateDelta Execute( } sw.Stop(); - Log.Verbose("{AddressesHex} {Source} HAS {Process}: {Elapsed}", addressesHex, source, "Get AvatarState", sw.Elapsed.TotalMilliseconds); + Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}", + addressesHex, source, "Get AvatarState", blockIndex, sw.Elapsed.TotalMilliseconds); sw.Restart(); var sheets = states.GetSheets( @@ -186,7 +188,8 @@ public IAccountStateDelta Execute( typeof(RuneListSheet), }); sw.Stop(); - Log.Verbose("{AddressesHex} {Source} HAS {Process}: {Elapsed}", addressesHex, source, "Get Sheets", sw.Elapsed.TotalMilliseconds); + Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}", + addressesHex, source, "Get Sheets", blockIndex, sw.Elapsed.TotalMilliseconds); sw.Restart(); var stakingLevel = 0; @@ -200,7 +203,8 @@ public IAccountStateDelta Execute( } sw.Stop(); - Log.Verbose("{AddressesHex} {Source} HAS {Process}: {Elapsed}", addressesHex, source, "Check StateState", sw.Elapsed.TotalMilliseconds); + Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}", + addressesHex, source, "Check StateState", blockIndex, sw.Elapsed.TotalMilliseconds); var worldSheet = sheets.GetSheet(); if (!worldSheet.TryGetValue(WorldId, out var worldRow, false)) @@ -223,7 +227,8 @@ public IAccountStateDelta Execute( } sw.Stop(); - Log.Verbose("{AddressesHex} {Source} HAS {Process}: {Elapsed}", addressesHex, source, "Get StageSheet", sw.Elapsed.TotalMilliseconds); + Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}", + addressesHex, source, "Get StageSheet", blockIndex, sw.Elapsed.TotalMilliseconds); sw.Restart(); var worldInformation = avatarState.worldInformation; @@ -263,14 +268,16 @@ public IAccountStateDelta Execute( } sw.Stop(); - Log.Verbose("{AddressesHex} {Source} HAS {Process}: {Elapsed}", addressesHex, source, "Validate World", sw.Elapsed.TotalMilliseconds); + Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}", + addressesHex, source, "Validate World", blockIndex, sw.Elapsed.TotalMilliseconds); sw.Restart(); var equipmentList = avatarState.ValidateEquipmentsV2(Equipments, blockIndex); var foodIds = avatarState.ValidateConsumable(Foods, blockIndex); var costumeIds = avatarState.ValidateCostume(Costumes); sw.Stop(); - Log.Verbose("{AddressesHex} {Source} HAS {Process}: {Elapsed}", addressesHex, source, "Validate Items", sw.Elapsed.TotalMilliseconds); + Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}", + addressesHex, source, "Validate Items", blockIndex, sw.Elapsed.TotalMilliseconds); sw.Restart(); var materialItemSheet = sheets.GetSheet(); var apPlayCount = TotalPlayCount; @@ -316,6 +323,7 @@ public IAccountStateDelta Execute( "{AddressesHex} {Source} TotalPlayCount: {TotalPlayCount}, " + "ApStoneCount: {ApStoneCount}, PlayCount by Ap stone: {ApStonePlayCount}, " + "Ap cost per 1 play: {MinimumCostAp}, " + + "BlockIndex: {BlockIndex}, " + "PlayCount by action point: {ApPlayCount}, Used AP: {UsedAp}", addressesHex, source, @@ -348,12 +356,14 @@ public IAccountStateDelta Execute( var items = Equipments.Concat(Costumes); avatarState.EquipItems(items); sw.Stop(); - Log.Verbose("{AddressesHex} {Source} HAS {Process}: {Elapsed}", addressesHex, source, "Unequip items", sw.Elapsed.TotalMilliseconds); + Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}", + addressesHex, source, "Unequip items", blockIndex, sw.Elapsed.TotalMilliseconds); sw.Restart(); var questSheet = sheets.GetQuestSheet(); sw.Stop(); - Log.Verbose("{AddressesHex} {Source} HAS {Process}: {Elapsed}", addressesHex, source, "Get QuestSheet", sw.Elapsed.TotalMilliseconds); + Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}", + addressesHex, source, "Get QuestSheet", blockIndex, sw.Elapsed.TotalMilliseconds); // Update QuestList only when QuestSheet.Count is greater than QuestList.Count var questList = avatarState.questList; @@ -366,7 +376,8 @@ public IAccountStateDelta Execute( sheets.GetSheet(), sheets.GetSheet()); sw.Stop(); - Log.Verbose("{AddressesHex} {Source} HAS {Process}: {Elapsed}", addressesHex, source, "Update QuestList", sw.Elapsed.TotalMilliseconds); + Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}", + addressesHex, source, "Update QuestList", blockIndex, sw.Elapsed.TotalMilliseconds); } sw.Restart(); @@ -405,7 +416,8 @@ public IAccountStateDelta Execute( } sw.Stop(); - Log.Verbose("{AddressesHex} {Source} HAS {Process}: {Elapsed}", addressesHex, source, "Get skillState", sw.Elapsed.TotalMilliseconds); + Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}", + addressesHex, source, "Get skillState", blockIndex, sw.Elapsed.TotalMilliseconds); sw.Restart(); var worldUnlockSheet = sheets.GetSheet(); @@ -441,7 +453,8 @@ public IAccountStateDelta Execute( } } sw.Stop(); - Log.Verbose("{AddressesHex} {Source} HAS {Process}: {Elapsed}", addressesHex, source, "Update slotState", sw.Elapsed.TotalMilliseconds); + Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}", + addressesHex, source, "Update slotState", blockIndex, sw.Elapsed.TotalMilliseconds); var stageWaveRow = sheets.GetSheet()[StageId]; var enemySkillSheet = sheets.GetSheet(); @@ -472,12 +485,14 @@ public IAccountStateDelta Execute( rewards, false); sw.Stop(); - Log.Verbose("{AddressesHex} {Source} HAS {Process}: {Elapsed}", addressesHex, source, "Initialize Simulator", sw.Elapsed.TotalMilliseconds); + Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}", + addressesHex, source, "Initialize Simulator", blockIndex, sw.Elapsed.TotalMilliseconds); sw.Restart(); simulator.Simulate(); sw.Stop(); - Log.Verbose("{AddressesHex} {Source} HAS {Process}: {Elapsed}", addressesHex, source, "Simulator.Simulate()", sw.Elapsed.TotalMilliseconds); + Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}", + addressesHex, source, "Simulator.Simulate()", blockIndex, sw.Elapsed.TotalMilliseconds); sw.Restart(); if (simulator.Log.IsClear) @@ -494,7 +509,8 @@ public IAccountStateDelta Execute( stageCleared = true; } sw.Stop(); - Log.Verbose("{AddressesHex} {Source} HAS {Process}: {Elapsed}", addressesHex, source, "ClearStage", sw.Elapsed.TotalMilliseconds); + Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}", + addressesHex, source, "ClearStage", blockIndex, sw.Elapsed.TotalMilliseconds); } sw.Restart(); @@ -525,6 +541,7 @@ public IAccountStateDelta Execute( sw.Stop(); Log.Verbose( "{AddressesHex} {Source} {Process} by simulator({AvatarAddress}); " + + "blockIndex: {BlockIndex} " + "worldId: {WorldId}, stageId: {StageId}, result: {Result}, " + "clearWave: {ClearWave}, totalWave: {TotalWave}", addressesHex, @@ -539,8 +556,8 @@ public IAccountStateDelta Execute( ); } sw.Stop(); - Log.Debug("{AddressesHex} {Source} {Process}: {Elapsed}, Count: {PlayCount}", - addressesHex, source, "loop Simulate", sw.Elapsed.TotalMilliseconds, TotalPlayCount); + 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); @@ -549,7 +566,8 @@ public IAccountStateDelta Execute( avatarState.updatedAt = blockIndex; avatarState.mailBox.CleanUp(); sw.Stop(); - Log.Verbose("{AddressesHex} {Source} HAS {Process}: {Elapsed}", addressesHex, source, "Update AvatarState", sw.Elapsed.TotalMilliseconds); + Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}", + addressesHex, source, "Update AvatarState", blockIndex, sw.Elapsed.TotalMilliseconds); sw.Restart(); if (isNotClearedStage) @@ -571,10 +589,11 @@ public IAccountStateDelta Execute( .SetState(worldInformationAddress, avatarState.worldInformation.Serialize()) .SetState(questListAddress, avatarState.questList.Serialize()); sw.Stop(); - Log.Verbose("{AddressesHex} {Source} HAS {Process}: {Elapsed}", addressesHex, source, "Set States", sw.Elapsed.TotalMilliseconds); + Log.Verbose("{AddressesHex} {Source} HAS {Process} from #{BlockIndex}: {Elapsed}", + addressesHex, source, "Set States", blockIndex, sw.Elapsed.TotalMilliseconds); var totalElapsed = DateTimeOffset.UtcNow - started; - Log.Verbose("{AddressesHex} {Source} HAS {Process}: {Elapsed}", addressesHex, source, "Total Executed Time", totalElapsed.TotalMilliseconds); + Log.Verbose("{AddressesHex} {Source} HAS {Process}: {Elapsed}, blockIndex: {BlockIndex}", addressesHex, source, "Total Executed Time", totalElapsed.TotalMilliseconds, blockIndex); return states; }