public void Can_recalculate_and_clear_with_root_only()
{
IPendingSyncItems items = Init();
StateSyncItem stateSyncItem = new (Keccak.Zero, null, null, NodeDataType.State);
items.PushToSelectedStream(stateSyncItem, 0);
items.RecalculatePriorities();
items.Clear();
items.Count.Should().Be(0);
}
public void Prefers_left_single_branch()
{
IPendingSyncItems items = Init();
items.MaxStateLevel = 64;
PushState(items, 1, 15); // branch child 16
PushState(items, 1, 1); // branch child 1
PushState(items, 1, 0); // branch child 0
items.RecalculatePriorities();
List <StateSyncItem> batch = items.TakeBatch(256);
batch[0].Rightness.Should().Be(0);
batch[1].Rightness.Should().Be(1);
batch[2].Rightness.Should().Be(15);
}
public void Prioritizes_code_over_storage_over_state()
{
IPendingSyncItems items = Init();
items.MaxStateLevel = 64;
PushState(items, 64, 0);
PushStorage(items, 32, 0);
PushCode(items);
items.RecalculatePriorities();
List <StateSyncItem> batch = items.TakeBatch(256);
items.Count.Should().Be(0);
batch[0].NodeDataType.Should().Be(NodeDataType.Code);
batch[1].NodeDataType.Should().Be(NodeDataType.Storage);
batch[2].NodeDataType.Should().Be(NodeDataType.State);
}
public void Prioritizes_depth()
{
IPendingSyncItems items = Init();
items.MaxStateLevel = 64;
PushState(items, 0, 0);
PushState(items, 32, 0);
PushState(items, 64, 0);
items.RecalculatePriorities();
List <StateSyncItem> batch = items.TakeBatch(256);
items.Count.Should().Be(0);
batch[0].Level.Should().Be(64);
batch[1].Level.Should().Be(32);
batch[2].Level.Should().Be(0);
}
public override SyncResponseHandlingResult HandleResponse(StateSyncBatch batch)
{
if (batch == EmptyBatch)
{
_logger.Error("Received empty batch as a response");
}
if (!_pendingRequests.TryRemove(batch, out _))
{
if (_logger.IsDebug)
{
_logger.Debug($"Cannot remove pending request {batch}");
}
return(SyncResponseHandlingResult.OK);
}
else
{
if (_logger.IsTrace)
{
_logger.Trace($"Removing pending request {batch}");
}
}
int requestLength = batch.RequestedNodes?.Length ?? 0;
int responseLength = batch.Responses?.Length ?? 0;
void AddAgainAllItems()
{
for (int i = 0; i < requestLength; i++)
{
AddNodeToPending(batch.RequestedNodes[i], null, "missing", true);
}
}
try
{
lock (_handleWatch)
{
if (DateTime.UtcNow - _lastReview > TimeSpan.FromSeconds(60))
{
_lastReview = DateTime.UtcNow;
string reviewMessage = _pendingItems.RecalculatePriorities();
if (_logger.IsInfo)
{
_logger.Info(reviewMessage);
}
}
_handleWatch.Restart();
bool requestWasMade = batch.Responses != null;
if (!requestWasMade)
{
AddAgainAllItems();
if (_logger.IsTrace)
{
_logger.Trace($"Batch was not assigned to any peer.");
}
Interlocked.Increment(ref _data.NotAssignedCount);
return(SyncResponseHandlingResult.NotAssigned);
}
bool isMissingRequestData = batch.RequestedNodes == null;
bool isMissingResponseData = batch.Responses == null;
bool hasValidFormat = !isMissingRequestData && !isMissingResponseData;
if (!hasValidFormat)
{
_hintsToResetRoot++;
AddAgainAllItems();
if (_logger.IsWarn)
{
_logger.Warn($"Batch response had invalid format");
}
Interlocked.Increment(ref _data.InvalidFormatCount);
return(isMissingRequestData ? SyncResponseHandlingResult.InternalError : SyncResponseHandlingResult.NotAssigned);
}
if (_logger.IsTrace)
{
_logger.Trace($"Received node data - {responseLength} items in response to {requestLength}");
}
int nonEmptyResponses = 0;
int invalidNodes = 0;
for (int i = 0; i < batch.RequestedNodes.Length; i++)
{
StateSyncItem currentStateSyncItem = batch.RequestedNodes[i];
/* if the peer has limit on number of requests in a batch then the response will possibly be
* shorter than the request */
if (batch.Responses.Length < i + 1)
{
AddNodeToPending(currentStateSyncItem, null, "missing", true);
continue;
}
/* if the peer does not have details of this particular node */
byte[] currentResponseItem = batch.Responses[i];
if (currentResponseItem == null)
{
AddNodeToPending(batch.RequestedNodes[i], null, "missing", true);
continue;
}
/* node sent data that is not consistent with its hash - it happens surprisingly often */
if (!ValueKeccak.Compute(currentResponseItem).BytesAsSpan.SequenceEqual(currentStateSyncItem.Hash.Bytes))
{
AddNodeToPending(currentStateSyncItem, null, "missing", true);
if (_logger.IsTrace)
{
_logger.Trace($"Peer sent invalid data (batch {requestLength}->{responseLength}) of length {batch.Responses[i]?.Length} of type {batch.RequestedNodes[i].NodeDataType} at level {batch.RequestedNodes[i].Level} of type {batch.RequestedNodes[i].NodeDataType} Keccak({batch.Responses[i].ToHexString()}) != {batch.RequestedNodes[i].Hash}");
}
invalidNodes++;
continue;
}
nonEmptyResponses++;
NodeDataType nodeDataType = currentStateSyncItem.NodeDataType;
if (nodeDataType == NodeDataType.Code)
{
SaveNode(currentStateSyncItem, currentResponseItem);
continue;
}
HandleTrieNode(currentStateSyncItem, currentResponseItem, ref invalidNodes);
}
Interlocked.Add(ref _data.ConsumedNodesCount, nonEmptyResponses);
StoreProgressInDb();
if (_logger.IsTrace)
{
_logger.Trace($"After handling response (non-empty responses {nonEmptyResponses}) of {batch.RequestedNodes.Length} from ({_pendingItems.Description}) nodes");
}
/* magic formula is ratio of our desired batch size - 1024 to Geth max batch size 384 times some missing nodes ratio */
bool isEmptish = (decimal)nonEmptyResponses / Math.Max(requestLength, 1) < 384m / 1024m * 0.75m;
if (isEmptish)
{
Interlocked.Increment(ref _hintsToResetRoot);
Interlocked.Increment(ref _data.EmptishCount);
}
else
{
Interlocked.Exchange(ref _hintsToResetRoot, 0);
}
/* here we are very forgiving for Geth nodes that send bad data fast */
bool isBadQuality = nonEmptyResponses > 64 && (decimal)invalidNodes / Math.Max(requestLength, 1) > 0.50m;
if (isBadQuality)
{
Interlocked.Increment(ref _data.BadQualityCount);
}
bool isEmpty = nonEmptyResponses == 0 && !isBadQuality;
if (isEmpty)
{
if (_logger.IsDebug)
{
_logger.Debug($"Peer sent no data in response to a request of length {batch.RequestedNodes.Length}");
}
return(SyncResponseHandlingResult.NoProgress);
}
if (!isEmptish && !isBadQuality)
{
Interlocked.Increment(ref _data.OkCount);
}
SyncResponseHandlingResult result = isEmptish
? SyncResponseHandlingResult.Emptish
: isBadQuality
? SyncResponseHandlingResult.LesserQuality
: SyncResponseHandlingResult.OK;
_data.DisplayProgressReport(_pendingRequests.Count, _logger);
long total = _handleWatch.ElapsedMilliseconds + _networkWatch.ElapsedMilliseconds;
if (total != 0)
{
// calculate averages
if (_logger.IsTrace)
{
_logger.Trace($"Prepare batch {_networkWatch.ElapsedMilliseconds}ms ({(decimal) _networkWatch.ElapsedMilliseconds / total:P0}) - Handle {_handleWatch.ElapsedMilliseconds}ms ({(decimal) _handleWatch.ElapsedMilliseconds / total:P0})");
}
}
if (_handleWatch.ElapsedMilliseconds > 250)
{
if (_logger.IsDebug)
{
_logger.Debug($"Handle watch {_handleWatch.ElapsedMilliseconds}, DB reads {_data.DbChecks - _data.LastDbReads}, ratio {(decimal) _handleWatch.ElapsedMilliseconds / Math.Max(1, _data.DbChecks - _data.LastDbReads)}");
}
}
_data.LastDbReads = _data.DbChecks;
_data.AverageTimeInHandler = (_data.AverageTimeInHandler * (_data.ProcessedRequestsCount - 1) + _handleWatch.ElapsedMilliseconds) / _data.ProcessedRequestsCount;
Interlocked.Add(ref _data.HandledNodesCount, nonEmptyResponses);
return(result);
}
}
catch (Exception e)
{
_logger.Error("Error when handling state sync response", e);
return(SyncResponseHandlingResult.InternalError);
}
finally
{
_handleWatch.Stop();
}
}
public void Can_recalculate_priorities_at_start()
{
IPendingSyncItems items = Init();
items.RecalculatePriorities().Should().NotBeNullOrWhiteSpace();
}