private async Task ExecuteRequest(CancellationToken token, StateSyncBatch batch)
{
SyncPeerAllocation nodeSyncAllocation = _syncPeerPool.Borrow(BorrowOptions.DoNotReplace, "node sync");
try
{
ISyncPeer peer = nodeSyncAllocation?.Current?.SyncPeer;
batch.AssignedPeer = nodeSyncAllocation;
if (peer != null)
{
var hashes = batch.RequestedNodes.Select(r => r.Hash).ToArray();
Task <byte[][]> getNodeDataTask = peer.GetNodeData(hashes, token);
await getNodeDataTask.ContinueWith(
t =>
{
if (t.IsCompletedSuccessfully)
{
batch.Responses = getNodeDataTask.Result;
}
}
);
}
(NodeDataHandlerResult Result, int NodesConsumed)result = (NodeDataHandlerResult.InvalidFormat, 0);
try
{
result = _nodeDataFeed.HandleResponse(batch);
if (result.Result == NodeDataHandlerResult.BadQuality)
{
_syncPeerPool.ReportBadPeer(batch.AssignedPeer);
}
}
catch (Exception e)
{
if (_logger.IsError)
{
_logger.Error($"Error when handling response", e);
}
}
Interlocked.Add(ref _consumedNodesCount, result.NodesConsumed);
if (result.NodesConsumed == 0 && peer != null)
{
_syncPeerPool.ReportNoSyncProgress(nodeSyncAllocation);
}
}
finally
{
if (nodeSyncAllocation != null)
{
// _logger.Warn($"Free {nodeSyncAllocation?.Current}");
_syncPeerPool.Free(nodeSyncAllocation);
}
}
}
private void FreeBlocksSyncAllocation()
{
if (_blocksSyncAllocation != null)
{
_blocksSyncAllocation.Cancelled -= AllocationOnCancelled;
_blocksSyncAllocation.Replaced -= AllocationOnReplaced;
_blocksSyncAllocation.Refreshed -= AllocationOnRefreshed;
_syncPeerPool.Free(_blocksSyncAllocation);
_blocksSyncAllocation = null;
}
}
private void AllocateBlocksSync()
{
if (_blocksSyncAllocation == null)
{
if (_logger.IsDebug)
{
_logger.Debug("Allocating block sync.");
}
_blocksSyncAllocation = _syncPeerPool.Borrow("synchronizer");
_blocksSyncAllocation.Replaced += AllocationOnReplaced;
_blocksSyncAllocation.Cancelled += AllocationOnCancelled;
_blocksSyncAllocation.Refreshed += AllocationOnRefreshed;
}
}
public void Free(SyncPeerAllocation syncPeerAllocation)
{
if (_logger.IsTrace)
{
_logger.Trace($"Returning {syncPeerAllocation}");
}
if (!syncPeerAllocation.CanBeReplaced)
{
_peerBadness.TryRemove(syncPeerAllocation.Current, out _);
}
_allocations.TryRemove(syncPeerAllocation, out _);
syncPeerAllocation.Cancel();
}
public void ReportBadPeer(SyncPeerAllocation batchAssignedPeer)
{
if (batchAssignedPeer.CanBeReplaced)
{
throw new InvalidOperationException("Reporting bad peer is only supported for non-dynamic allocations");
}
_peerBadness.AddOrUpdate(batchAssignedPeer.Current, 0, (pi, badness) => badness + 1);
if (_peerBadness[batchAssignedPeer.Current] >= 10)
{
// fast Geth nodes send invalid nodes quite often :/
// so we let them deliver fast and only disconnect them when they really misbehave
batchAssignedPeer.Current.SyncPeer.Disconnect(DisconnectReason.BreachOfProtocol, "bad node data");
}
}
public void ReportNoSyncProgress(SyncPeerAllocation allocation)
{
PeerInfo peer = allocation?.Current;
if (peer == null)
{
return;
}
// this is generally with the strange Parity nodes behaviour
if (_logger.IsDebug)
{
_logger.Debug($"No sync progress reported with {allocation.Current}");
}
_sleepingPeers.TryAdd(peer, DateTime.UtcNow);
}
private void ReplaceIfWorthReplacing(SyncPeerAllocation allocation, PeerInfo peerInfo)
{
if (!allocation.CanBeReplaced)
{
return;
}
if (peerInfo == null)
{
return;
}
if (allocation.Current == null)
{
allocation.ReplaceCurrent(peerInfo);
return;
}
if (peerInfo == allocation.Current)
{
if (_logger.IsTrace)
{
_logger.Trace($"{allocation} is already syncing with best peer {peerInfo}");
}
return;
}
var currentLatency = _stats.GetOrAdd(allocation.Current?.SyncPeer.Node)?.GetAverageLatency(NodeLatencyStatType.BlockHeaders) ?? 100000;
var newLatency = _stats.GetOrAdd(peerInfo.SyncPeer.Node)?.GetAverageLatency(NodeLatencyStatType.BlockHeaders) ?? 100001;
if (newLatency / (decimal)Math.Max(1L, currentLatency) < 1m - _syncConfig.MinDiffPercentageForLatencySwitch / 100m &&
newLatency < currentLatency - _syncConfig.MinDiffForLatencySwitch)
{
if (_logger.IsInfo)
{
_logger.Info($"Sync peer substitution{Environment.NewLine} OUT: {allocation.Current}[{currentLatency}]{Environment.NewLine} IN : {peerInfo}[{newLatency}]");
}
allocation.ReplaceCurrent(peerInfo);
}
else
{
if (_logger.IsTrace)
{
_logger.Trace($"Staying with current peer {allocation.Current}[{currentLatency}] (ignoring {peerInfo}[{newLatency}])");
}
}
}
private void ReplaceIfWorthReplacing(SyncPeerAllocation allocation, PeerInfo peerInfo)
{
if (!allocation.CanBeReplaced)
{
return;
}
if (peerInfo == null)
{
return;
}
if (allocation.Current == null)
{
allocation.ReplaceCurrent(peerInfo);
return;
}
if (peerInfo == allocation.Current)
{
if (_logger.IsTrace)
{
_logger.Trace($"{allocation} is already syncing with best peer {peerInfo}");
}
return;
}
var currentSpeed = _stats.GetOrAdd(allocation.Current?.SyncPeer.Node)?.GetAverageTransferSpeed() ?? 0;
var newSpeed = _stats.GetOrAdd(peerInfo.SyncPeer.Node)?.GetAverageTransferSpeed() ?? 0;
if (newSpeed / (decimal)Math.Max(1L, currentSpeed) > 1m + _minDiffPercentageForSpeedSwitch &&
newSpeed > currentSpeed + _minDiffForSpeedSwitch)
{
if (_logger.IsInfo)
{
_logger.Info($"Sync peer substitution{Environment.NewLine} OUT: {allocation.Current}[{currentSpeed}]{Environment.NewLine} IN : {peerInfo}[{newSpeed}]");
}
allocation.ReplaceCurrent(peerInfo);
}
else
{
if (_logger.IsTrace)
{
_logger.Trace($"Staying with current peer {allocation.Current}[{currentSpeed}] (ignoring {peerInfo}[{newSpeed}])");
}
}
}
/// <summary>
/// Frees the allocation space borrowed earlier for some sync consumer.
/// </summary>
/// <param name="syncPeerAllocation">Allocation to free</param>
public void Free(SyncPeerAllocation syncPeerAllocation)
{
if (_logger.IsTrace)
{
_logger.Trace($"Returning {syncPeerAllocation}");
}
_replaceableAllocations.TryRemove(syncPeerAllocation, out _);
syncPeerAllocation.Cancel();
if (_replaceableAllocations.Count > 1024 * 16)
{
_logger.Warn($"Peer allocations leakage - {_replaceableAllocations.Count}");
}
_signals.Set();
}
public SyncPeerAllocation Borrow(BorrowOptions borrowOptions, string description)
{
SyncPeerAllocation allocation = new SyncPeerAllocation(description);
if ((borrowOptions & BorrowOptions.DoNotReplace) == BorrowOptions.DoNotReplace)
{
allocation.CanBeReplaced = false;
}
PeerInfo bestPeer = SelectBestPeerForAllocation(allocation, "BORROW");
if (bestPeer != null)
{
allocation.ReplaceCurrent(bestPeer);
}
_allocations.TryAdd(allocation, null);
return(allocation);
}
public void ReportWeakPeer(SyncPeerAllocation allocation)
{
PeerInfo weakPeer = allocation.Current;
if (weakPeer == null)
{
/* it may have just got disconnected and in such case the allocation would be nullified
* in such case there is no need to talk about whether the peer is good or bad
*/
return;
}
if (weakPeer.IncreaseWeakness() > MaxPeerWeakness)
{
/* fast Geth nodes send invalid nodes quite often :/
* so we let them deliver fast and only disconnect them when they really misbehave
*/
allocation.Current.SyncPeer.Disconnect(DisconnectReason.UselessPeer, "peer is too weak");
}
}
public SyncPeerAllocation Borrow(BorrowOptions borrowOptions, string description, long?minNumber = null)
{
SyncPeerAllocation allocation = new SyncPeerAllocation(description);
allocation.MinBlocksAhead = minNumber - _blockTree.BestSuggestedHeader?.Number;
if ((borrowOptions & BorrowOptions.DoNotReplace) == BorrowOptions.DoNotReplace)
{
allocation.CanBeReplaced = false;
}
PeerInfo bestPeer = SelectBestPeerForAllocation(allocation, "BORROW", (borrowOptions & BorrowOptions.LowPriority) == BorrowOptions.LowPriority);
if (bestPeer != null)
{
allocation.ReplaceCurrent(bestPeer);
}
_allocations.TryAdd(allocation, null);
return(allocation);
}
public void Free(SyncPeerAllocation syncPeerAllocation)
{
if (_logger.IsTrace)
{
_logger.Trace($"Returning {syncPeerAllocation}");
}
PeerInfo peerInfo = syncPeerAllocation.Current;
if (peerInfo != null && !syncPeerAllocation.CanBeReplaced)
{
_peerBadness.TryRemove(peerInfo, out _);
}
_allocations.TryRemove(syncPeerAllocation, out _);
syncPeerAllocation.Cancel();
if (_allocations.Count > 1024 * 16)
{
_logger.Warn($"Peer allocations leakage - {_allocations.Count}");
}
}
public async Task <SyncPeerAllocation> BorrowAsync(IPeerSelectionStrategy peerSelectionStrategy, string description = "", int timeoutMilliseconds = 0)
{
int tryCount = 1;
DateTime startTime = DateTime.UtcNow;
SyncPeerAllocation allocation = new SyncPeerAllocation(peerSelectionStrategy);
while (true)
{
lock (_isAllocatedChecks)
{
allocation.AllocateBestPeer(UsefulPeers.Where(p => !p.IsAllocated), _stats, _blockTree, "INIT");
if (allocation.HasPeer)
{
if (peerSelectionStrategy.CanBeReplaced)
{
_replaceableAllocations.TryAdd(allocation, null);
}
return(allocation);
}
}
bool timeoutReached = timeoutMilliseconds == 0 ||
(DateTime.UtcNow - startTime).TotalMilliseconds > timeoutMilliseconds;
if (timeoutReached)
{
return(SyncPeerAllocation.FailedAllocation);
}
int waitTime = 10 * tryCount++;
await _signals.WaitOneAsync(waitTime, CancellationToken.None);
_signals.Reset(); // without this we have no delay
}
}
private PeerInfo SelectBestPeerForAllocation(SyncPeerAllocation allocation, string reason, bool isLowPriority)
{
if (_logger.IsTrace)
{
_logger.Trace($"[{reason}] Selecting best peer for {allocation}");
}
(PeerInfo Info, long TransferSpeed)bestPeer = (null, isLowPriority ? long.MaxValue : -1);
foreach ((_, PeerInfo info) in _peers)
{
if (allocation.MinBlocksAhead.HasValue && info.HeadNumber < (_blockTree.BestSuggestedHeader?.Number ?? 0) + allocation.MinBlocksAhead.Value)
{
continue;
}
if (!info.IsInitialized || info.TotalDifficulty <= (_blockTree.BestSuggestedHeader?.TotalDifficulty ?? UInt256.Zero))
{
continue;
}
if (info.IsAllocated && info != allocation.Current)
{
continue;
}
if (info.IsAsleep)
{
if (DateTime.UtcNow - info.SleepingSince < _timeBeforeWakingPeerUp)
{
continue;
}
info.SleepingSince = null;
}
if (info.TotalDifficulty - (_blockTree.BestSuggestedHeader?.TotalDifficulty ?? UInt256.Zero) <= 2 && info.SyncPeer.ClientId.Contains("Parity"))
{
// Parity advertises a better block but never sends it back and then it disconnects after a few conversations like this
// Geth responds all fine here
// note this is only 2 difficulty difference which means that is just for the POA / Clique chains
continue;
}
long averageTransferSpeed = _stats.GetOrAdd(info.SyncPeer.Node).GetAverageTransferSpeed() ?? 0;
if (isLowPriority ? (averageTransferSpeed <= bestPeer.TransferSpeed) : (averageTransferSpeed > bestPeer.TransferSpeed))
{
bestPeer = (info, averageTransferSpeed);
}
}
if (bestPeer.Info == null)
{
if (_logger.IsTrace)
{
_logger.Trace($"[{reason}] No peer found for ETH sync");
}
}
else
{
if (_logger.IsTrace)
{
_logger.Trace($"[{reason}] Best ETH sync peer: {bestPeer.Info} | BlockHeaderAvSpeed: {bestPeer.TransferSpeed}");
}
}
return(bestPeer.Info);
}
private PeerInfo SelectBestPeerForAllocation(SyncPeerAllocation allocation, string reason)
{
if (_logger.IsTrace)
{
_logger.Trace($"[{reason}] Selecting best peer for {allocation}");
}
(PeerInfo Info, long Latency)bestPeer = (null, 100000);
foreach ((_, PeerInfo info) in _peers)
{
if (allocation.MinBlocksAhead.HasValue && info.HeadNumber < _blockTree.BestKnownNumber + allocation.MinBlocksAhead.Value)
{
continue;
}
if (!info.IsInitialized || info.TotalDifficulty <= (_blockTree.BestSuggested?.TotalDifficulty ?? UInt256.Zero))
{
continue;
}
if (info.IsAllocated && info != allocation.Current)
{
continue;
}
if (_sleepingPeers.TryGetValue(info, out DateTime sleepingSince))
{
if (DateTime.UtcNow - sleepingSince < _timeBeforeWakingPeerUp)
{
continue;
}
_sleepingPeers.TryRemove(info, out _);
}
if (info.TotalDifficulty - (_blockTree.BestSuggested?.TotalDifficulty ?? UInt256.Zero) <= 2 && info.SyncPeer.ClientId.Contains("Parity"))
{
// Parity advertises a better block but never sends it back and then it disconnects after a few conversations like this
// Geth responds all fine here
// note this is only 2 difficulty difference which means that is just for the POA / Clique chains
continue;
}
long latency = _stats.GetOrAdd(info.SyncPeer.Node).GetAverageLatency(NodeLatencyStatType.BlockHeaders) ?? 100000;
if (latency <= bestPeer.Latency)
{
bestPeer = (info, latency);
}
}
if (bestPeer.Info == null)
{
if (_logger.IsTrace)
{
_logger.Trace($"[{reason}] No peer found for ETH sync");
}
}
else
{
if (_logger.IsTrace)
{
_logger.Trace($"[{reason}] Best ETH sync peer: {bestPeer.Info} | BlockHeaderAvLatency: {bestPeer.Latency}");
}
}
return(bestPeer.Info);
}
public void ReportInvalid(SyncPeerAllocation allocation)
{
ReportInvalid(allocation?.Current);
}
public void ReportNoSyncProgress(SyncPeerAllocation allocation)
{
ReportNoSyncProgress(allocation?.Current);
}