From 36a06fa5c60dabb3c956ac1e2f44a18ce5d525b7 Mon Sep 17 00:00:00 2001 From: area363 Date: Tue, 16 Jul 2024 12:16:51 +0900 Subject: [PATCH] test log --- .../RenderSubscriber.cs | 139 ++++++++++-------- .../AdventureBossRenderSubscriber.cs | 58 +++++--- 2 files changed, 117 insertions(+), 80 deletions(-) diff --git a/NineChronicles.DataProvider/RenderSubscriber.cs b/NineChronicles.DataProvider/RenderSubscriber.cs index 814c8c9c..7bed9c2c 100644 --- a/NineChronicles.DataProvider/RenderSubscriber.cs +++ b/NineChronicles.DataProvider/RenderSubscriber.cs @@ -259,7 +259,7 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) _blockTimeOffset)); var end = DateTimeOffset.UtcNow; - Log.Debug("Stored TransferAsset action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored TransferAsset action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } if (ev.Action is IClaimStakeReward claimStakeReward) @@ -292,12 +292,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) _blockTimeOffset)); _claimStakeList.Add(ClaimStakeRewardData.GetClaimStakeRewardInfo(claimStakeReward, inputState, outputState, ev.Signer, ev.BlockIndex, _blockTimeOffset)); var end = DateTimeOffset.UtcNow; - Log.Debug("Stored ClaimStakeReward action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored ClaimStakeReward action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -329,12 +329,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) ev.BlockIndex, _blockTimeOffset)); var end = DateTimeOffset.UtcNow; - Log.Debug("Stored EventDungeonBattle action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored EventDungeonBattle action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -350,12 +350,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) var outputState = new World(_blockChainStates.GetWorldState(ev.OutputState)); _eventConsumableItemCraftsList.Add(EventConsumableItemCraftsData.GetEventConsumableItemCraftsInfo(eventConsumableItemCrafts, inputState, outputState, ev.Signer, ev.BlockIndex, _blockTimeOffset)); var end = DateTimeOffset.UtcNow; - Log.Debug("Stored EventConsumableItemCrafts action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored EventConsumableItemCrafts action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -370,12 +370,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) _requestPledgeList.Add(RequestPledgeData.GetRequestPledgeInfo(ev.TxId.ToString()!, ev.BlockIndex, _blockHash!, ev.Signer, requestPledge.AgentAddress, requestPledge.RefillMead, _blockTimeOffset)); var end = DateTimeOffset.UtcNow; - Log.Debug("Stored RequestPledge action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored RequestPledge action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -390,12 +390,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) _approvePledgeList.Add(ApprovePledgeData.GetApprovePledgeInfo(ev.TxId.ToString()!, ev.BlockIndex, _blockHash!, ev.Signer, approvePledge.PatronAddress, _blockTimeOffset)); var end = DateTimeOffset.UtcNow; - Log.Debug("Stored ApprovePledge action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored ApprovePledge action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -417,12 +417,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) } var end = DateTimeOffset.UtcNow; - Log.Debug("Stored HackAndSlash action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored HackAndSlash action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -452,12 +452,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) ev.BlockIndex, _blockTimeOffset)); var end = DateTimeOffset.UtcNow; - Log.Debug("Stored HackAndSlashSweep action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored HackAndSlashSweep action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -482,12 +482,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) ev.BlockIndex, _blockTimeOffset)); var end = DateTimeOffset.UtcNow; - Log.Debug("Stored CombinationConsumable action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored CombinationConsumable action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -570,7 +570,7 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -612,7 +612,7 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) ev.BlockIndex, _blockTimeOffset)); var end = DateTimeOffset.UtcNow; - Log.Debug("Stored ItemEnhancement action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored ItemEnhancement action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); start = DateTimeOffset.UtcNow; var slotState = outputState.GetCombinationSlotState( @@ -638,7 +638,7 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -707,7 +707,7 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -815,7 +815,7 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -831,12 +831,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) var outputState = new World(_blockChainStates.GetWorldState(ev.OutputState)); _stakeList.Add(StakeData.GetStakeInfo(inputState, outputState, ev.Signer, ev.BlockIndex, _blockTimeOffset, stake.Id)); var end = DateTimeOffset.UtcNow; - Log.Debug("Stored Stake action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored Stake action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -852,12 +852,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) var outputState = new World(_blockChainStates.GetWorldState(ev.OutputState)); _mmcList.Add(MigrateMonsterCollectionData.GetMigrateMonsterCollectionInfo(inputState, outputState, ev.Signer, ev.BlockIndex, _blockTimeOffset)); var end = DateTimeOffset.UtcNow; - Log.Debug("Stored MigrateMonsterCollection action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored MigrateMonsterCollection action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -880,12 +880,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) } var end = DateTimeOffset.UtcNow; - Log.Debug("Stored Grinding action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored Grinding action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -906,12 +906,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) } var end = DateTimeOffset.UtcNow; - Log.Debug("Stored UnlockEquipmentRecipe action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored UnlockEquipmentRecipe action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -932,12 +932,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) } var end = DateTimeOffset.UtcNow; - Log.Debug("Stored UnlockWorld action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored UnlockWorld action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -953,12 +953,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) var outputState = new World(_blockChainStates.GetWorldState(ev.OutputState)); _hasRandomBuffList.Add(HackAndSlashRandomBuffData.GetHasRandomBuffInfo(inputState, outputState, ev.Signer, hasRandomBuff.AvatarAddress, hasRandomBuff.AdvancedGacha, hasRandomBuff.Id, ev.BlockIndex, _blockTimeOffset)); var end = DateTimeOffset.UtcNow; - Log.Debug("Stored HasRandomBuff action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored HasRandomBuff action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -974,12 +974,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) var outputState = new World(_blockChainStates.GetWorldState(ev.OutputState)); _joinArenaList.Add(JoinArenaData.GetJoinArenaInfo(inputState, outputState, ev.Signer, joinArena.avatarAddress, joinArena.round, joinArena.championshipId, joinArena.Id, ev.BlockIndex, _blockTimeOffset)); var end = DateTimeOffset.UtcNow; - Log.Debug("Stored JoinArena action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored JoinArena action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -1007,12 +1007,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) ev.BlockIndex, _blockTimeOffset)); var end = DateTimeOffset.UtcNow; - Log.Debug("Stored BattleArena action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored BattleArena action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -1038,12 +1038,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) ev.BlockIndex, _blockTimeOffset)); var end = DateTimeOffset.UtcNow; - Log.Debug("Stored EventMaterialItemCrafts action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored EventMaterialItemCrafts action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -1068,12 +1068,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) ev.BlockIndex, _blockTimeOffset)); var end = DateTimeOffset.UtcNow; - Log.Debug("Stored RuneEnhancement action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored RuneEnhancement action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -1117,12 +1117,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) } var end = DateTimeOffset.UtcNow; - Log.Debug("Stored TransferAssets action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored TransferAssets action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -1158,12 +1158,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) acquiredRune, _blockTimeOffset)); var end = DateTimeOffset.UtcNow; - Log.Debug("Stored DailyReward action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored DailyReward action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -1212,12 +1212,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) } var end = DateTimeOffset.UtcNow; - Log.Debug("Stored ClaimRaidReward action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored ClaimRaidReward action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -1241,12 +1241,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) ev.BlockIndex, _blockTimeOffset)); var end = DateTimeOffset.UtcNow; - Log.Debug("Stored UnlockRuneSlot action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored UnlockRuneSlot action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -1270,12 +1270,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) ev.BlockIndex, _blockTimeOffset)); var end = DateTimeOffset.UtcNow; - Log.Debug("Stored RapidCombination action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); + Log.Debug("[DataProvider] Stored RapidCombination action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -1286,6 +1286,7 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) { if (ev.Exception is null) { + var start = DateTimeOffset.UtcNow; var inputState = new World(_blockChainStates.GetWorldState(ev.PreviousState)); var outputState = new World(_blockChainStates.GetWorldState(ev.OutputState)); var sheets = outputState.GetSheets( @@ -1346,11 +1347,13 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) raiderState.PurchaseCount); _raiderList.Add(RaidData.GetRaidInfo(raidId, raiderState)); MySqlStore.StoreRaider(model); + var end = DateTimeOffset.UtcNow; + Log.Debug("[DataProvider] Stored Raid action in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -1375,12 +1378,12 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) _blockTimeOffset )); var end = DateTimeOffset.UtcNow; - Log.Debug("Stored PetEnhancement action in block #{BlockIndex}. Time taken: {Time} ms", ev.BlockIndex, end - start); + Log.Debug("[DataProvider] Stored PetEnhancement action in block #{BlockIndex}. Time taken: {Time} ms", ev.BlockIndex, end - start); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -1390,6 +1393,7 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) { if (ev.Action is { } auraSummon) { + var start = DateTimeOffset.UtcNow; var inputState = new World(_blockChainStates.GetWorldState(ev.PreviousState)); var outputState = new World(_blockChainStates.GetWorldState(ev.OutputState)); if (ev.Exception is null) @@ -1421,11 +1425,14 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) _blockTimeOffset )); } + + var end = DateTimeOffset.UtcNow; + Log.Debug("[DataProvider] Stored AuraSummon action in block #{BlockIndex}. Time taken: {Time} ms", ev.BlockIndex, end - start); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -1435,6 +1442,7 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) { if (ev.Action is { } runeSummon) { + var start = DateTimeOffset.UtcNow; var outputState = new World(_blockChainStates.GetWorldState(ev.OutputState)); if (ev.Exception is null) { @@ -1472,11 +1480,14 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) _blockTimeOffset )); } + + var end = DateTimeOffset.UtcNow; + Log.Debug("[DataProvider] Stored RuneSummon action in block #{BlockIndex}. Time taken: {Time} ms", ev.BlockIndex, end - start); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -1486,6 +1497,7 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) { if (ev.Exception is null && ev.Action is { } activateCollection) { + var start = DateTimeOffset.UtcNow; var outputState = new World(_blockChainStates.GetWorldState(ev.OutputState)); var collectionSheet = outputState.GetSheet(); var avatar = MySqlStore.GetAvatar(activateCollection.AvatarAddress, true); @@ -1498,11 +1510,14 @@ protected override Task ExecuteAsync(CancellationToken stoppingToken) avatar, activateCollection.Id.ToString() ); + + var end = DateTimeOffset.UtcNow; + Log.Debug("[DataProvider] Stored MigrateActivateCollections action in block #{BlockIndex}. Time taken: {Time} ms", ev.BlockIndex, end - start); } } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "R[DataProvider] enderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } }); @@ -1591,6 +1606,7 @@ private void ProcessAgentAvatarData(ActionEvaluation ev) if (ev.Signer != _miner) { + var start = DateTimeOffset.UtcNow; var outputState = new World(_blockChainStates.GetWorldState(ev.OutputState)); var agentState = outputState.GetAgentState(ev.Signer); if (agentState is { } ag) @@ -1625,10 +1641,13 @@ private void ProcessAgentAvatarData(ActionEvaluation ev) } catch (Exception ex) { - Log.Error(ex, "RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); + Log.Error(ex, "[DataProvider] RenderSubscriber Error: {ErrorMessage}, StackTrace: {StackTrace}", ex.Message, ex.StackTrace); } } } + + var end = DateTimeOffset.UtcNow; + Log.Debug("[DataProvider] Stored Avatar Information in block #{index}. Time Taken: {time} ms.", ev.BlockIndex, (end - start).Milliseconds); } } } @@ -1636,7 +1655,7 @@ private void ProcessAgentAvatarData(ActionEvaluation ev) private void StoreRenderedData((Block OldTip, Block NewTip) b) { var start = DateTimeOffset.Now; - Log.Debug("Storing Data..."); + Log.Debug("[DataProvider] Storing Data..."); var tasks = new List { Task.Run(() => diff --git a/NineChronicles.DataProvider/Subscriber/AdventureBossRenderSubscriber.cs b/NineChronicles.DataProvider/Subscriber/AdventureBossRenderSubscriber.cs index 911ad114..a6d45371 100644 --- a/NineChronicles.DataProvider/Subscriber/AdventureBossRenderSubscriber.cs +++ b/NineChronicles.DataProvider/Subscriber/AdventureBossRenderSubscriber.cs @@ -28,46 +28,46 @@ private void StoreAdventureBossList() try { var tasks = new List(); - Log.Debug("[Adventure Boss] Store adventure boss list"); + Log.Debug("[DataProvider AdventureBoss] Store adventure boss list"); tasks.Add(Task.Run(async () => { - Log.Debug($"[Adventure Boss] {_adventureBossSeasonDict.Count} Season"); + Log.Debug($"[DataProvider AdventureBoss] {_adventureBossSeasonDict.Count} Season"); await MySqlStore.StoreAdventureBossSeasonList(_adventureBossSeasonDict.Values.ToList()); } )); tasks.Add(Task.Run(async () => { - Log.Debug($"[Adventure Boss] {_adventureBossWantedList.Count} Wanted"); + Log.Debug($"[DataProvider AdventureBoss] {_adventureBossWantedList.Count} Wanted"); await MySqlStore.StoreAdventureBossWantedList(_adventureBossWantedList); } )); tasks.Add(Task.Run(async () => { - Log.Debug($"[Adventure Boss] {_adventureBossChallengeList.Count} Challenge"); + Log.Debug($"[DataProvider AdventureBoss] {_adventureBossChallengeList.Count} Challenge"); await MySqlStore.StoreAdventureBossChallengeList(_adventureBossChallengeList); } )); tasks.Add(Task.Run(async () => { - Log.Debug($"[Adventure Boss] {_adventureBossRushList.Count} Rush"); + Log.Debug($"[DataProvider AdventureBoss] {_adventureBossRushList.Count} Rush"); await MySqlStore.StoreAdventureBossRushList(_adventureBossRushList); } )); tasks.Add(Task.Run(async () => { - Log.Debug($"[Adventure Boss] {_adventureBossUnlockFloorList.Count} Unlock"); + Log.Debug($"[DataProvider AdventureBoss] {_adventureBossUnlockFloorList.Count} Unlock"); await MySqlStore.StoreAdventureBossUnlockFloorList(_adventureBossUnlockFloorList); } )); tasks.Add(Task.Run(async () => { - Log.Debug($"[Adventure Boss] {_adventureBossClaimRewardList.Count} claim"); + Log.Debug($"[DataProvider AdventureBoss] {_adventureBossClaimRewardList.Count} claim"); await MySqlStore.StoreAdventureBossClaimRewardList(_adventureBossClaimRewardList); } )); @@ -82,7 +82,7 @@ private void StoreAdventureBossList() private void ClearAdventureBossList() { - Log.Debug("[Adventure Boss] Clear adventure boss action lists"); + Log.Debug("[DataProvider AdventureBoss] Clear adventure boss action lists"); _adventureBossSeasonDict.Clear(); _adventureBossWantedList.Clear(); _adventureBossChallengeList.Clear(); @@ -93,22 +93,25 @@ private void ClearAdventureBossList() partial void SubscribeAdventureBossWanted(ActionEvaluation evt) { - Log.Debug("[Adventure Boss] Subscribe Wanted"); + Log.Debug("[DataProvider AdventureBoss] Subscribe Wanted"); try { if (evt.Exception is null && evt.Action is { } wanted) { + var start = DateTimeOffset.UtcNow; var outputState = new World(_blockChainStates.GetWorldState(evt.OutputState)); _adventureBossWantedList.Add(AdventureBossWantedData.GetWantedInfo( outputState, evt.BlockIndex, _blockTimeOffset, wanted )); - Log.Debug($"[Adventure Boss] Wanted added : {_adventureBossWantedList.Count}"); + Log.Debug($"[DataProvider AdventureBoss] Wanted added : {_adventureBossWantedList.Count}"); // Update season info _adventureBossSeasonDict[wanted.Season] = AdventureBossSeasonData.GetAdventureBossSeasonInfo( outputState, wanted.Season, _blockTimeOffset ); - Log.Debug($"[Adventure Boss] Season added : {_adventureBossSeasonDict.Count}"); + Log.Debug($"[DataProvider AdventureBoss] Season added : {_adventureBossSeasonDict.Count}"); + var end = DateTimeOffset.UtcNow; + Log.Debug("[DataProvider] Stored AdventureBossWanted action in block #{BlockIndex}. Time taken: {Time} ms", evt.BlockIndex, end - start); } } catch (Exception e) @@ -124,17 +127,20 @@ partial void SubscribeAdventureBossWanted(ActionEvaluation evt) partial void SubscribeAdventureBossChallenge(ActionEvaluation evt) { - Log.Debug("[Adventure Boss] Subscribe Explore"); + Log.Debug("[DataProvider AdventureBoss] Subscribe Explore"); try { if (evt.Exception is null && evt.Action is { } challenge) { + var start = DateTimeOffset.UtcNow; var prevState = new World(_blockChainStates.GetWorldState(evt.PreviousState)); var outputState = new World(_blockChainStates.GetWorldState(evt.OutputState)); _adventureBossChallengeList.Add(AdventureBossChallengeData.GetChallengeInfo( prevState, outputState, evt.BlockIndex, _blockTimeOffset, challenge )); - Log.Debug($"[Adventure Boss] Challenge added : {_adventureBossChallengeList.Count}"); + Log.Debug($"[DataProvider AdventureBoss] Challenge added : {_adventureBossChallengeList.Count}"); + var end = DateTimeOffset.UtcNow; + Log.Debug("[DataProvider] Stored AdventureBossChallenge action in block #{BlockIndex}. Time taken: {Time} ms", evt.BlockIndex, end - start); } } catch (Exception e) @@ -150,17 +156,20 @@ partial void SubscribeAdventureBossChallenge(ActionEvaluation evt) { - Log.Debug("[Adventure Boss] Subscribe Rush"); + Log.Debug("[DataProvider AdventureBoss] Subscribe Rush"); try { if (evt.Exception is null && evt.Action is { } rush) { + var start = DateTimeOffset.UtcNow; var prevState = new World(_blockChainStates.GetWorldState(evt.PreviousState)); var outputState = new World(_blockChainStates.GetWorldState(evt.OutputState)); _adventureBossRushList.Add(AdventureBossRushData.GetRushInfo( prevState, outputState, evt.BlockIndex, _blockTimeOffset, rush )); - Log.Debug($"[Adventure Boss] Rush added : {_adventureBossRushList.Count}"); + Log.Debug($"[DataProvider AdventureBoss] Rush added : {_adventureBossRushList.Count}"); + var end = DateTimeOffset.UtcNow; + Log.Debug("[DataProvider] Stored AdventureBossRush action in block #{BlockIndex}. Time taken: {Time} ms", evt.BlockIndex, end - start); } } catch (Exception e) @@ -176,17 +185,20 @@ partial void SubscribeAdventureBossRush(ActionEvaluation evt partial void SubscribeAdventureBossUnlockFloor(ActionEvaluation evt) { - Log.Debug("[Adventure Boss] Subscribe UnlockFloor"); + Log.Debug("[DataProvider AdventureBoss] Subscribe UnlockFloor"); try { if (evt.Exception is null && evt.Action is { } unlock) { + var start = DateTimeOffset.UtcNow; var prevState = new World(_blockChainStates.GetWorldState(evt.PreviousState)); var outputState = new World(_blockChainStates.GetWorldState(evt.OutputState)); _adventureBossUnlockFloorList.Add(AdventureBossUnlockFloorData.GetUnlockInfo( prevState, outputState, evt.BlockIndex, _blockTimeOffset, unlock )); - Log.Debug($"[Adventure Boss] Unlock added : {_adventureBossUnlockFloorList.Count}"); + Log.Debug($"[DataProvider AdventureBoss] Unlock added : {_adventureBossUnlockFloorList.Count}"); + var end = DateTimeOffset.UtcNow; + Log.Debug("[DataProvider] Stored AdventureBossUnlock action in block #{BlockIndex}. Time taken: {Time} ms", evt.BlockIndex, end - start); } } catch (Exception e) @@ -202,19 +214,23 @@ partial void SubscribeAdventureBossUnlockFloor(ActionEvaluation evt partial void SubscribeAdventureBossClaim(ActionEvaluation evt) { - Log.Debug("[Adventure Boss] Subscribe Claim"); + Log.Debug("[DataProvider AdventureBoss] Subscribe Claim"); try { if (evt.Exception is null && evt.Action is { } claim) { + var start = DateTimeOffset.UtcNow; var prevState = new World(_blockChainStates.GetWorldState(evt.PreviousState)); var outputState = new World(_blockChainStates.GetWorldState(evt.OutputState)); _adventureBossClaimRewardList.Add(AdventureBossClaimRewardData.GetClaimInfo( prevState, evt.BlockIndex, _blockTimeOffset, claim )); - Log.Debug($"[Adventure Boss] Claim added : {_adventureBossClaimRewardList.Count}"); + Log.Debug($"[DataProvider AdventureBoss] Claim added : {_adventureBossClaimRewardList.Count}"); + var end = DateTimeOffset.UtcNow; + Log.Debug("[DataProvider] Stored AdventureBossClaim action in block #{BlockIndex}. Time taken: {Time} ms", evt.BlockIndex, end - start); // Update season info + start = DateTimeOffset.UtcNow; var latestSeason = prevState.GetLatestAdventureBossSeason(); var season = latestSeason.EndBlockIndex <= evt.BlockIndex ? latestSeason.Season // New season not started @@ -222,7 +238,9 @@ partial void SubscribeAdventureBossClaim(ActionEvaluation