From 01085cb5300966bbfb3ef11211f0b40920ed0383 Mon Sep 17 00:00:00 2001 From: Ben Date: Tue, 5 Aug 2025 11:07:33 +0200 Subject: [PATCH] Improves logging for all nethereum interactions and bot mint command --- Framework/Logging/LogPrefixer.cs | 2 +- .../NethereumWorkflow/NethereumInteraction.cs | 218 +++++++++++------- Tools/BiblioTech/Commands/MintCommand.cs | 26 ++- 3 files changed, 157 insertions(+), 89 deletions(-) diff --git a/Framework/Logging/LogPrefixer.cs b/Framework/Logging/LogPrefixer.cs index 30c6524d..4e406366 100644 --- a/Framework/Logging/LogPrefixer.cs +++ b/Framework/Logging/LogPrefixer.cs @@ -24,7 +24,7 @@ public void Debug(string message = "", int skipFrames = 0) { - backingLog.Debug(GetPrefix() + message, skipFrames); + backingLog.Debug(GetPrefix() + message, skipFrames + 1); } public void Error(string message) diff --git a/Framework/NethereumWorkflow/NethereumInteraction.cs b/Framework/NethereumWorkflow/NethereumInteraction.cs index b8ada938..89a46ea2 100644 --- a/Framework/NethereumWorkflow/NethereumInteraction.cs +++ b/Framework/NethereumWorkflow/NethereumInteraction.cs @@ -3,6 +3,8 @@ using BlockchainUtils; using Logging; using Nethereum.ABI.FunctionEncoding.Attributes; using Nethereum.Contracts; +using Nethereum.Model; +using Nethereum.RPC.Eth.Blocks; using Nethereum.RPC.Eth.DTOs; using Nethereum.Web3; using Utils; @@ -23,159 +25,205 @@ namespace NethereumWorkflow this.blockCache = blockCache; } - public string SendEth(string toAddress, BigInteger ethAmount) { - log.Debug(); - var receipt = Time.Wait(web3.Eth.GetEtherTransferService().TransferEtherAndWaitForReceiptAsync(toAddress, ((decimal)ethAmount))); - if (!receipt.Succeeded()) throw new Exception("Unable to send Eth"); - return receipt.TransactionHash; + return DebugLogWrap(() => + { + var receipt = Time.Wait(web3.Eth.GetEtherTransferService().TransferEtherAndWaitForReceiptAsync(toAddress, ((decimal)ethAmount))); + if (!receipt.Succeeded()) throw new Exception("Unable to send Eth"); + return receipt.TransactionHash; + }, nameof(SendEth)); } public BigInteger GetEthBalance() { - log.Debug(); - return GetEthBalance(web3.TransactionManager.Account.Address); + return DebugLogWrap(() => + { + return GetEthBalance(web3.TransactionManager.Account.Address); + }, nameof(GetEthBalance)); } public BigInteger GetEthBalance(string address) { - log.Debug(); - var balance = Time.Wait(web3.Eth.GetBalance.SendRequestAsync(address)); - return balance.Value; + return DebugLogWrap(() => + { + var balance = Time.Wait(web3.Eth.GetBalance.SendRequestAsync(address)); + return balance.Value; + }, nameof(GetEthBalance)); } public TResult Call(string contractAddress, TFunction function) where TFunction : FunctionMessage, new() { - log.Debug(typeof(TFunction).ToString()); - var handler = web3.Eth.GetContractQueryHandler(); - return Time.Wait(handler.QueryAsync(contractAddress, function)); + return DebugLogWrap(() => + { + var handler = web3.Eth.GetContractQueryHandler(); + return Time.Wait(handler.QueryAsync(contractAddress, function)); + }, nameof(Call) + "." + typeof(TFunction).ToString()); } public TResult Call(string contractAddress, TFunction function, ulong blockNumber) where TFunction : FunctionMessage, new() { - log.Debug(typeof(TFunction).ToString()); - var handler = web3.Eth.GetContractQueryHandler(); - return Time.Wait(handler.QueryAsync(contractAddress, function, new BlockParameter(blockNumber))); + return DebugLogWrap(() => + { + var handler = web3.Eth.GetContractQueryHandler(); + return Time.Wait(handler.QueryAsync(contractAddress, function, new BlockParameter(blockNumber))); + }, nameof(Call) + "." + typeof(TFunction).ToString()); } public void Call(string contractAddress, TFunction function) where TFunction : FunctionMessage, new() { - log.Debug(typeof(TFunction).ToString()); - var handler = web3.Eth.GetContractQueryHandler(); - Time.Wait(handler.QueryRawAsync(contractAddress, function)); + DebugLogWrap(() => + { + var handler = web3.Eth.GetContractQueryHandler(); + Time.Wait(handler.QueryRawAsync(contractAddress, function)); + return string.Empty; + }, nameof(Call) + "." + typeof(TFunction).ToString()); } public void Call(string contractAddress, TFunction function, ulong blockNumber) where TFunction : FunctionMessage, new() { - log.Debug(typeof(TFunction).ToString()); - var handler = web3.Eth.GetContractQueryHandler(); - var result = Time.Wait(handler.QueryRawAsync(contractAddress, function, new BlockParameter(blockNumber))); + DebugLogWrap(() => + { + var handler = web3.Eth.GetContractQueryHandler(); + var result = Time.Wait(handler.QueryRawAsync(contractAddress, function, new BlockParameter(blockNumber))); + return string.Empty; + }, nameof(Call) + "." + typeof(TFunction).ToString()); } public string SendTransaction(string contractAddress, TFunction function) where TFunction : FunctionMessage, new() { - log.Debug(); - var handler = web3.Eth.GetContractTransactionHandler(); - var receipt = Time.Wait(handler.SendRequestAndWaitForReceiptAsync(contractAddress, function)); - if (!receipt.Succeeded()) throw new Exception("Unable to perform contract transaction."); - return receipt.TransactionHash; + return DebugLogWrap(() => + { + var handler = web3.Eth.GetContractTransactionHandler(); + var receipt = Time.Wait(handler.SendRequestAndWaitForReceiptAsync(contractAddress, function)); + if (!receipt.Succeeded()) throw new Exception("Unable to perform contract transaction."); + return receipt.TransactionHash; + }, nameof(SendTransaction) + "." + typeof(TFunction).ToString()); } public Transaction GetTransaction(string transactionHash) { - log.Debug(); - return Time.Wait(web3.Eth.Transactions.GetTransactionByHash.SendRequestAsync(transactionHash)); + return DebugLogWrap(() => + { + return Time.Wait(web3.Eth.Transactions.GetTransactionByHash.SendRequestAsync(transactionHash)); + }, nameof(GetTransaction)); } public decimal? GetSyncedBlockNumber() { - log.Debug(); - var sync = Time.Wait(web3.Eth.Syncing.SendRequestAsync()); - var number = Time.Wait(web3.Eth.Blocks.GetBlockNumber.SendRequestAsync()); - var numberOfBlocks = number.ToDecimal(); - if (sync.IsSyncing) return null; - return numberOfBlocks; + return DebugLogWrap(() => + { + var sync = Time.Wait(web3.Eth.Syncing.SendRequestAsync()); + var number = Time.Wait(web3.Eth.Blocks.GetBlockNumber.SendRequestAsync()); + var numberOfBlocks = number.ToDecimal(); + if (sync.IsSyncing) return null; + return numberOfBlocks; + }, nameof(GetTransaction)); } public bool IsContractAvailable(string abi, string contractAddress) { - log.Debug(); - try + return DebugLogWrap(() => { - var contract = web3.Eth.GetContract(abi, contractAddress); - return contract != null; - } - catch - { - return false; - } + try + { + var contract = web3.Eth.GetContract(abi, contractAddress); + return contract != null; + } + catch + { + return false; + } + }, nameof(IsContractAvailable)); } public List> GetEvents(string address, BlockInterval blockRange) where TEvent : IEventDTO, new() { - return GetEvents(address, blockRange.From, blockRange.To); + return DebugLogWrap(() => + { + return GetEvents(address, blockRange.From, blockRange.To); + }, nameof(GetEvents) + "." + typeof(TEvent).ToString()); } public List> GetEvents(string address, ulong fromBlockNumber, ulong toBlockNumber) where TEvent : IEventDTO, new() { - var logs = new List(); - var p = web3.Processing.Logs.CreateProcessor( - action: logs.Add, - minimumBlockConfirmations: 1, - criteria: l => l.IsLogForEvent() - ); + return DebugLogWrap(() => + { + var logs = new List(); + var p = web3.Processing.Logs.CreateProcessor( + action: logs.Add, + minimumBlockConfirmations: 1, + criteria: l => l.IsLogForEvent() + ); - var from = new BlockParameter(fromBlockNumber); - var to = new BlockParameter(toBlockNumber); - var ct = new CancellationTokenSource().Token; - Time.Wait(p.ExecuteAsync(toBlockNumber: to.BlockNumber, cancellationToken: ct, startAtBlockNumberIfNotProcessed: from.BlockNumber)); + var from = new BlockParameter(fromBlockNumber); + var to = new BlockParameter(toBlockNumber); + var ct = new CancellationTokenSource().Token; + Time.Wait(p.ExecuteAsync(toBlockNumber: to.BlockNumber, cancellationToken: ct, startAtBlockNumberIfNotProcessed: from.BlockNumber)); - return logs - .Where(l => l.IsLogForEvent()) - .Select(l => l.DecodeEvent()) - .ToList(); + return logs + .Where(l => l.IsLogForEvent()) + .Select(l => l.DecodeEvent()) + .ToList(); + }, nameof(GetEvents) + "." + typeof(TEvent).ToString()); } public BlockInterval ConvertTimeRangeToBlockRange(TimeRange timeRange) { - if (timeRange.To - timeRange.From < TimeSpan.FromSeconds(1.0)) - throw new Exception(nameof(ConvertTimeRangeToBlockRange) + ": Time range too small."); - - var wrapper = new Web3Wrapper(web3, log); - var blockTimeFinder = new BlockTimeFinder(blockCache, wrapper, log); - - var fromBlock = blockTimeFinder.GetLowestBlockNumberAfter(timeRange.From); - var toBlock = blockTimeFinder.GetHighestBlockNumberBefore(timeRange.To); - - if (fromBlock == null || toBlock == null) + return DebugLogWrap(() => { - throw new Exception("Failed to convert time range to block range."); - } + if (timeRange.To - timeRange.From < TimeSpan.FromSeconds(1.0)) + throw new Exception(nameof(ConvertTimeRangeToBlockRange) + ": Time range too small."); - return new BlockInterval( - timeRange: timeRange, - from: fromBlock.Value, - to: toBlock.Value - ); + var wrapper = new Web3Wrapper(web3, log); + var blockTimeFinder = new BlockTimeFinder(blockCache, wrapper, log); + + var fromBlock = blockTimeFinder.GetLowestBlockNumberAfter(timeRange.From); + var toBlock = blockTimeFinder.GetHighestBlockNumberBefore(timeRange.To); + + if (fromBlock == null || toBlock == null) + { + throw new Exception("Failed to convert time range to block range."); + } + + return new BlockInterval( + timeRange: timeRange, + from: fromBlock.Value, + to: toBlock.Value + ); + }, nameof(ConvertTimeRangeToBlockRange)); } public BlockTimeEntry GetBlockForNumber(ulong number) { - var wrapper = new Web3Wrapper(web3, log); - var blockTimeFinder = new BlockTimeFinder(blockCache, wrapper, log); - return blockTimeFinder.Get(number); + return DebugLogWrap(() => + { + var wrapper = new Web3Wrapper(web3, log); + var blockTimeFinder = new BlockTimeFinder(blockCache, wrapper, log); + return blockTimeFinder.Get(number); + }, nameof(GetBlockForNumber)); } public BlockWithTransactions GetBlockWithTransactions(ulong number) { - var retry = new Retry(nameof(GetBlockWithTransactions), - maxTimeout: TimeSpan.FromMinutes(1.0), - sleepAfterFail: TimeSpan.FromSeconds(1.0), - onFail: f => { }, - failFast: false); + return DebugLogWrap(() => + { + var retry = new Retry(nameof(GetBlockWithTransactions), + maxTimeout: TimeSpan.FromMinutes(1.0), + sleepAfterFail: TimeSpan.FromSeconds(1.0), + onFail: f => { }, + failFast: false); - return retry.Run(() => Time.Wait(web3.Eth.Blocks.GetBlockWithTransactionsByNumber.SendRequestAsync(new BlockParameter(number)))); + return retry.Run(() => Time.Wait(web3.Eth.Blocks.GetBlockWithTransactionsByNumber.SendRequestAsync(new BlockParameter(number)))); + }, nameof(GetBlockWithTransactions)); + } + + private T DebugLogWrap(Func task, string name = "") + { + log.Debug($"{name} start...", 1); + var result = task(); + log.Debug($"{name} finished", 1); + return result; } } } diff --git a/Tools/BiblioTech/Commands/MintCommand.cs b/Tools/BiblioTech/Commands/MintCommand.cs index 745823d5..82bc8373 100644 --- a/Tools/BiblioTech/Commands/MintCommand.cs +++ b/Tools/BiblioTech/Commands/MintCommand.cs @@ -1,6 +1,7 @@ using BiblioTech.Options; using CodexContractsPlugin; using GethPlugin; +using Logging; using Utils; namespace BiblioTech.Commands @@ -11,10 +12,12 @@ namespace BiblioTech.Commands description: "If set, mint tokens for this user. (Optional, admin-only)", isRequired: false); private readonly UserAssociateCommand userAssociateCommand; + private readonly ILog log; public MintCommand(UserAssociateCommand userAssociateCommand) { this.userAssociateCommand = userAssociateCommand; + log = Program.Log; } public override string Name => "mint"; @@ -33,6 +36,7 @@ namespace BiblioTech.Commands return; } + log.Debug($"Running mint command for {userId} with address {addr}..."); var report = new List(); Transaction? sentEth = null; @@ -55,6 +59,7 @@ namespace BiblioTech.Commands { if (IsTestTokenBalanceOverLimit(contracts, addr)) { + log.Debug("TestToken balance is over threshold."); report.Add("TestToken balance over threshold. (No TestTokens sent or minted.)"); return null; } @@ -69,10 +74,12 @@ namespace BiblioTech.Commands { if (IsEthBalanceOverLimit(gethNode, addr)) { + log.Debug("Eth balance is over threshold."); report.Add("Eth balance is over threshold. (No Eth sent.)"); return null; } var eth = Program.Config.SendEth.Eth(); + log.Debug($"Sending {eth}..."); var transaction = gethNode.SendEth(addr, eth); report.Add($"Sent {eth} {FormatTransactionLink(transaction)}"); return new Transaction(eth, 0.Eth(), transaction); @@ -81,11 +88,16 @@ namespace BiblioTech.Commands private async Task<(TestToken, string)> MintTestTokens(ICodexContracts contracts, EthAddress addr, List report) { var nothing = (0.TstWei(), string.Empty); - if (Program.Config.MintTT < 1) return nothing; + if (Program.Config.MintTT < 1) + { + log.Debug("Skip minting TST: configured amount is less than 1."); + return nothing; + } try { var tokens = Program.Config.MintTT.TstWei(); + log.Debug($"Minting {tokens}..."); var transaction = contracts.MintTestTokens(addr, tokens); report.Add($"Minted {tokens} {FormatTransactionLink(transaction)}"); return (tokens, transaction); @@ -101,23 +113,31 @@ namespace BiblioTech.Commands private async Task<(TestToken, string)> TransferTestTokens(ICodexContracts contracts, EthAddress addr, List report) { var nothing = (0.TstWei(), string.Empty); - if (Program.Config.SendTT < 1) return nothing; + if (Program.Config.SendTT < 1) + { + log.Debug("Skip transferring TST: configured amount is less than 1."); + return nothing; + } if (Program.GethLink == null) { + log.Debug("Skip transferring TST: GethLink not available."); report.Add("Transaction operations are currently not available."); return nothing; } try { + var current = contracts.GetTestTokenBalance(Program.GethLink.Node.CurrentAddress); var amount = Program.Config.SendTT.TstWei(); - if (contracts.GetTestTokenBalance(Program.GethLink.Node.CurrentAddress).TstWei <= amount.TstWei) + if (current.TstWei <= amount.TstWei) { + log.Debug($"Unable to transfer TST: Bot has: {current} - Transfer amount: {amount}"); report.Add("Unable to send TestTokens: Bot doesn't have enough! (Admins have been notified)"); await Program.AdminChecker.SendInAdminChannel($"{nameof(MintCommand)} failed: Bot has insufficient tokens."); return nothing; } + log.Debug($"Sending {amount}..."); var transaction = contracts.TransferTestTokens(addr, amount); report.Add($"Transferred {amount} {FormatTransactionLink(transaction)}"); return (amount, transaction);