Skip to content

Commit

Permalink
[POA] Move the mining statistics log to a async loop (#736)
Browse files Browse the repository at this point in the history 
* Miner stats refactor

* Remove IBD check

* Start quicker

* Fix Log

* Adjsut miner log

* Dispose loop

* Fix async
  • Loading branch information
@fassadlr
fassadlr committed Oct 11, 2021
1 parent a357ef5 commit 183292f
Show file tree
Hide file tree
Showing 2 changed files with 124 additions and 85 deletions.
205 changes: 124 additions & 81 deletions src/Stratis.Bitcoin.Features.PoA/PoAMiner.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -78,6 +78,14 @@ public class PoAMiner : IPoAMiner

private readonly IIdleFederationMembersKicker idleFederationMembersKicker;

private Task miningTask;

private IAsyncLoop miningStatisticsLoop;

private string miningStatisticsLog;

private readonly INodeLifetime nodeLifetime;

private readonly NodeSettings nodeSettings;

private MiningStatisticsModel miningStatistics;
Expand All @@ -92,8 +100,6 @@ public class PoAMiner : IPoAMiner

private readonly IAsyncProvider asyncProvider;

private Task miningTask;

private Script walletScriptPubKey;

public PoAMiner(
Expand Down Expand Up @@ -132,6 +138,7 @@ public class PoAMiner : IPoAMiner
this.poaSettings = poAMinerSettings;
this.asyncProvider = asyncProvider;
this.idleFederationMembersKicker = idleFederationMembersKicker;
this.nodeLifetime = nodeLifetime;

this.logger = loggerFactory.CreateLogger(this.GetType().FullName);
this.cancellation = CancellationTokenSource.CreateLinkedTokenSource(new[] { nodeLifetime.ApplicationStopping });
Expand All @@ -151,6 +158,117 @@ public virtual void InitializeMining()
this.miningTask = this.CreateBlocksAsync();
this.asyncProvider.RegisterTask($"{nameof(PoAMiner)}.{nameof(this.miningTask)}", this.miningTask);
}

// Initialize the interop polling loop, to check for interop contract requests.
this.miningStatisticsLoop = this.asyncProvider.CreateAndRunAsyncLoop(nameof(this.miningStatisticsLoop), (cancellation) =>
{
try
{
this.GatherMiningStatistics();
}
catch (Exception e)
{
this.logger.LogWarning("Exception raised when gathering mining statistics; {0}", e);
}
return Task.CompletedTask;
},
this.nodeLifetime.ApplicationStopping,
repeatEvery: TimeSpans.Minute,
startAfter: TimeSpans.TenSeconds);
}

private void GatherMiningStatistics()
{
var log = new StringBuilder();

log.AppendLine(">> Miner");
log.AppendLine();

if (this.ibdState.IsInitialBlockDownload())
{
log.AppendLine("Mining information is not available whilst the node is syncing.");
log.AppendLine("The node will mine once it reaches the network's height.");
log.AppendLine();

this.miningStatisticsLog = log.ToString();

return;
}

ChainedHeader tip = this.consensusManager.Tip;
ChainedHeader currentHeader = tip;

int pubKeyTakeCharacters = 5;
int hitCount = 0;

// If the node is in DevMode just use the genesis members via the federation manager.
List<IFederationMember> modifiedFederation;
if (this.nodeSettings.DevMode != null)
modifiedFederation = this.federationManager.GetFederationMembers();
else
modifiedFederation = this.votingManager?.GetModifiedFederation(currentHeader) ?? this.federationManager.GetFederationMembers();

int maxDepth = modifiedFederation.Count;

log.AppendLine($"Mining information for the last { maxDepth } blocks.");
log.AppendLine("Note that '<' and '>' surrounds a slot where a miner didn't produce a block.");

uint timeHeader = (uint)this.dateTimeProvider.GetAdjustedTimeAsUnixTimestamp();
timeHeader -= timeHeader % this.network.ConsensusOptions.TargetSpacingSeconds;
if (timeHeader < currentHeader.Header.Time)
timeHeader += this.network.ConsensusOptions.TargetSpacingSeconds;

// Iterate mining slots.
for (int i = 0; i < maxDepth; i++)
{
int headerSlot = (int)(timeHeader / this.network.ConsensusOptions.TargetSpacingSeconds) % modifiedFederation.Count;

PubKey pubKey = modifiedFederation[headerSlot].PubKey;

string pubKeyRepresentation = pubKey.ToString().Substring(0, pubKeyTakeCharacters);
if (pubKey == this.federationManager.CurrentFederationKey?.PubKey)
pubKeyRepresentation = "█████";

// Mined in this slot?
if (timeHeader == currentHeader.Header.Time)
{
log.Append($"[{ pubKeyRepresentation }] ");

currentHeader = currentHeader.Previous;
hitCount++;

if (this.nodeSettings.DevMode != null)
modifiedFederation = this.federationManager.GetFederationMembers();
else
modifiedFederation = this.votingManager?.GetModifiedFederation(currentHeader) ?? this.federationManager.GetFederationMembers();

if (pubKey == this.federationManager.CurrentFederationKey?.PubKey)
this.miningStatistics.ProducedBlockInLastRound = true;
}
else
{
log.Append($"<{ pubKeyRepresentation }> ");

if (pubKey == this.federationManager.CurrentFederationKey?.PubKey)
this.miningStatistics.ProducedBlockInLastRound = false;
}

timeHeader -= this.network.ConsensusOptions.TargetSpacingSeconds;

if ((i % 20) == 19)
log.AppendLine();
}

this.miningStatistics.MinerHits = hitCount;

log.Append("...");
log.AppendLine();
log.AppendLine($"Miner hits".PadRight(LoggingConfiguration.ColumnLength) + $": {hitCount} of {maxDepth}({(((float)hitCount / (float)maxDepth)).ToString("P2")})");
log.AppendLine($"Miner idle time".PadRight(LoggingConfiguration.ColumnLength) + $": { TimeSpan.FromSeconds(this.network.ConsensusOptions.TargetSpacingSeconds * (maxDepth - hitCount)).ToString(@"hh\:mm\:ss")}");
log.AppendLine();

this.miningStatisticsLog = log.ToString();
}

private async Task CreateBlocksAsync()
Expand Down Expand Up @@ -198,8 +316,6 @@ private async Task CreateBlocksAsync()
continue;
}

this.miningStatistics.LastBlockProducedHeight = chainedHeader.Height;

var builder = new StringBuilder();
builder.AppendLine("<<==============================================================>>");
builder.AppendLine($"Block mined hash : '{chainedHeader}'");
Expand Down Expand Up @@ -422,80 +538,7 @@ private void AddVotingData(BlockTemplate blockTemplate)
[NoTrace]
private void AddComponentStats(StringBuilder log)
{
log.AppendLine(">> Miner");

if (this.ibdState.IsInitialBlockDownload())
{
log.AppendLine("Mining information is not available whilst the node is syncing.");
log.AppendLine("The node will mine once it reaches the network's height.");
log.AppendLine();
return;
}
ChainedHeader tip = this.consensusManager.Tip;
ChainedHeader currentHeader = tip;

int pubKeyTakeCharacters = 5;
int hitCount = 0;

// If the node is in DevMode just use the genesis members via the federation manager.
List<IFederationMember> modifiedFederation;
if (this.nodeSettings.DevMode != null)
modifiedFederation = this.federationManager.GetFederationMembers();
else
modifiedFederation = this.votingManager?.GetModifiedFederation(currentHeader) ?? this.federationManager.GetFederationMembers();

int maxDepth = modifiedFederation.Count;

log.AppendLine($"Mining information for the last { maxDepth } blocks.");
log.AppendLine("Note that '<' and '>' surrounds a slot where a miner didn't produce a block.");

uint timeHeader = (uint)this.dateTimeProvider.GetAdjustedTimeAsUnixTimestamp();
timeHeader -= timeHeader % this.network.ConsensusOptions.TargetSpacingSeconds;
if (timeHeader < currentHeader.Header.Time)
timeHeader += this.network.ConsensusOptions.TargetSpacingSeconds;

// Iterate mining slots.
for (int i = 0; i < maxDepth; i++)
{
int headerSlot = (int)(timeHeader / this.network.ConsensusOptions.TargetSpacingSeconds) % modifiedFederation.Count;

PubKey pubKey = modifiedFederation[headerSlot].PubKey;

string pubKeyRepresentation = pubKey.ToString().Substring(0, pubKeyTakeCharacters);
if (pubKey == this.federationManager.CurrentFederationKey?.PubKey)
pubKeyRepresentation = "█████";

// Mined in this slot?
if (timeHeader == currentHeader.Header.Time)
{
log.Append($"[{ pubKeyRepresentation }] ");

currentHeader = currentHeader.Previous;
hitCount++;

if (this.nodeSettings.DevMode != null)
modifiedFederation = this.federationManager.GetFederationMembers();
else
modifiedFederation = this.votingManager?.GetModifiedFederation(currentHeader) ?? this.federationManager.GetFederationMembers();
}
else
{
log.Append($"<{ pubKeyRepresentation }> ");
}

timeHeader -= this.network.ConsensusOptions.TargetSpacingSeconds;

if ((i % 20) == 19)
log.AppendLine();
}

this.miningStatistics.MinerHits = hitCount;

log.Append("...");
log.AppendLine();
log.AppendLine($"Miner hits".PadRight(LoggingConfiguration.ColumnLength) + $": {hitCount} of {maxDepth}({(((float)hitCount / (float)maxDepth)).ToString("P2")})");
log.AppendLine($"Miner idle time".PadRight(LoggingConfiguration.ColumnLength) + $": { TimeSpan.FromSeconds(this.network.ConsensusOptions.TargetSpacingSeconds * (maxDepth - hitCount)).ToString(@"hh\:mm\:ss")}");
log.AppendLine();
log.AppendLine(this.miningStatisticsLog);
}

/// <inheritdoc/>
Expand All @@ -509,7 +552,7 @@ public virtual void Dispose()
{
this.cancellation.Cancel();
this.miningTask?.GetAwaiter().GetResult();

this.miningStatisticsLoop?.Dispose();
this.cancellation.Dispose();
}
}
Expand All @@ -519,7 +562,7 @@ public sealed class MiningStatisticsModel
[JsonProperty(PropertyName = "minerHits")]
public int MinerHits { get; set; }

[JsonProperty(PropertyName = "lastBlockProducedHeight")]
public int LastBlockProducedHeight { get; set; }
[JsonProperty(PropertyName = "producedBlockInLastRound")]
public bool ProducedBlockInLastRound { get; set; }
}
}
4 changes: 0 additions & 4 deletions src/Stratis.Bitcoin.Features.PoA/Voting/FederationController.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -89,17 +89,13 @@ public IActionResult GetCurrentMemberInfo()
PubKey = this.federationManager.CurrentFederationKey.PubKey.ToHex()
};

ChainedHeader chainTip = this.chainIndexer.Tip;
federationMemberModel.FederationSize = this.federationManager.GetFederationMembers().Count;

KeyValuePair<PubKey, uint> lastActive = this.idleFederationMembersKicker.GetFederationMembersByLastActiveTime().FirstOrDefault(x => x.Key == this.federationManager.CurrentFederationKey.PubKey);
if (lastActive.Key != null)
{
federationMemberModel.LastActiveTime = new DateTime(1970, 1, 1, 0, 0, 0).AddSeconds(lastActive.Value);
federationMemberModel.PeriodOfInActivity = DateTime.UtcNow - new DateTime(1970, 1, 1, 0, 0, 0).AddSeconds(lastActive.Value);

var roundDepth = chainTip.Height - federationMemberModel.FederationSize;
federationMemberModel.ProducedBlockInLastRound = this.poaMiner.MiningStatistics.LastBlockProducedHeight >= roundDepth;
}

// Is this member part of a pending poll
Expand Down

0 comments on commit 183292f

Please sign in to comment.