private async Task <BlockHeader[]> SendRequest(GetBlockHeadersMessage message, CancellationToken token)
        {
            if (_headersRequests.IsAddingCompleted || _isDisposed)
            {
                throw new TimeoutException("Session disposed");
            }

            if (Logger.IsTrace)
            {
                Logger.Trace($"Sending headers request to {Session.Node:c}:");
                Logger.Trace($"  Starting blockhash: {message.StartingBlockHash}");
                Logger.Trace($"  Starting number: {message.StartingBlockNumber}");
                Logger.Trace($"  Skip: {message.Skip}");
                Logger.Trace($"  Reverse: {message.Reverse}");
                Logger.Trace($"  Max headers: {message.MaxHeaders}");
            }

            var request = new Request <GetBlockHeadersMessage, BlockHeader[]>(message);

            _headersRequests.Add(request, token);

            var perfCalcId = _perfService.StartPerfCalc();

            Send(request.Message);
            Task <BlockHeader[]>    task = request.CompletionSource.Task;
            CancellationTokenSource delayCancellation     = new CancellationTokenSource();
            CancellationTokenSource compositeCancellation = CancellationTokenSource.CreateLinkedTokenSource(token, delayCancellation.Token);
            var firstTask = await Task.WhenAny(task, Task.Delay(Timeouts.Eth, compositeCancellation.Token));

            if (firstTask.IsCanceled)
            {
                token.ThrowIfCancellationRequested();
            }

            if (firstTask == task)
            {
                delayCancellation.Cancel();
                var latency = _perfService.EndPerfCalc(perfCalcId);
                if (latency.HasValue)
                {
                    StatsManager.ReportLatencyCaptureEvent(Session.Node, NodeLatencyStatType.BlockHeaders, latency.Value);
                }

                return(task.Result);
            }

            _perfService.EndPerfCalc(perfCalcId);
            throw new TimeoutException($"{Session} Request timeout in {nameof(GetBlockHeadersMessage)} with {message.MaxHeaders} max headers");
        }
示例#2
0
        public async Task StopAsync()
        {
            var key = _perfService.StartPerfCalc();

            _appShutdownSource.Cancel();
            StopDiscoveryTimer();
            //StopRefreshTimer();
            StopDiscoveryPersistenceTimer();

            if (_storageCommitTask != null)
            {
                await _storageCommitTask.ContinueWith(x =>
                {
                    if (x.IsFaulted)
                    {
                        if (_logger.IsError)
                        {
                            _logger.Error("Error during discovery persisntance stop.", x.Exception);
                        }
                    }
                });
            }

            await StopUdpChannelAsync();

            if (_logger.IsInfo)
            {
                _logger.Info("Discovery shutdown complete.. please wait for all components to close");
            }
            _perfService.EndPerfCalc(key, "Close: DiscoveryApp");
        }
示例#3
0
        public async Task Shutdown()
        {
            var key = _perfService.StartPerfCalc();
//            InternalLoggerFactory.DefaultFactory.AddProvider(new ConsoleLoggerProvider((s, level) => true, false));

            await _bootstrapChannel.CloseAsync().ContinueWith(t =>
            {
                if (t.IsFaulted)
                {
                    _logger.Error($"{nameof(Shutdown)} failed", t.Exception);
                }
            });

            _logger.Debug("Closed _bootstrapChannel");

            var nettyCloseTimeout = TimeSpan.FromMilliseconds(100);
            var closingTask       = Task.WhenAll(_bossGroup.ShutdownGracefullyAsync(nettyCloseTimeout, nettyCloseTimeout),
                                                 _workerGroup.ShutdownGracefullyAsync(nettyCloseTimeout, nettyCloseTimeout));

            //we need to add additional timeout on our side as netty is not executing internal timeout properly, often it just hangs forever on closing
            if (await Task.WhenAny(closingTask, Task.Delay(Timeouts.TcpClose)) != closingTask)
            {
                _logger.Warn($"Could not close rlpx connection in {Timeouts.TcpClose.TotalSeconds} seconds");
            }

            _logger.Debug("Closed _bossGroup and _workerGroup");

            _perfService.EndPerfCalc(key, "Close: Rlpx");
        }
示例#4
0
        public async Task StopAsync()
        {
            var key = _perfService.StartPerfCalc();

            _appShutdown = true;
            StopDiscoveryTimer();
            //StopRefreshTimer();
            StopDiscoveryPersistanceTimer();

            if (_storageCommitTask != null)
            {
                await _storageCommitTask.ContinueWith(x =>
                {
                    if (x.IsFaulted)
                    {
                        if (_logger.IsError)
                        {
                            _logger.Error("Error during discovery persisntance stop.", x.Exception);
                        }
                    }
                });
            }

            await StopUdpChannelAsync();

            _perfService.EndPerfCalc(key, "Close: DiscoveryApp");
        }
        private async Task <BlockHeader[]> SendRequest(GetBlockHeadersMessage message, CancellationToken token)
        {
            if (Logger.IsTrace)
            {
                Logger.Trace("Sending headers request:");
                Logger.Trace($"Starting blockhash: {message.StartingBlockHash}");
                Logger.Trace($"Starting number: {message.StartingBlockNumber}");
                Logger.Trace($"Skip: {message.Skip}");
                Logger.Trace($"Reverse: {message.Reverse}");
                Logger.Trace($"Max headers: {message.MaxHeaders}");
            }

            var request = new Request <GetBlockHeadersMessage, BlockHeader[]>(message);

            _headersRequests.Add(request, token);
            var perfCalcId = _perfService.StartPerfCalc();

            Send(request.Message);
            Task <BlockHeader[]> task = request.CompletionSource.Task;
            var firstTask             = await Task.WhenAny(task, Task.Delay(Timeouts.Eth, token));

            if (firstTask.IsCanceled)
            {
                token.ThrowIfCancellationRequested();
            }

            if (firstTask == task)
            {
                var latency = _perfService.EndPerfCalc(perfCalcId);
                if (latency.HasValue)
                {
                    P2PSession?.NodeStats.AddLatencyCaptureEvent(NodeLatencyStatType.BlockHeaders, latency.Value);
                }

                return(task.Result);
            }

            throw new TimeoutException($"{P2PSession.RemoteNodeId} Request timeout in {nameof(GetBlockHeadersMessage)}");
        }
示例#6
0
        public async Task <bool> SendPing()
        {
            if (!_isInitialized)
            {
                return(true);
            }

            if (_pongCompletionSource != null)
            {
                if (Logger.IsWarn)
                {
                    Logger.Warn($"Another ping request in process: {Session.RemoteNodeId}");
                }
                return(true);
            }

            _pongCompletionSource = new TaskCompletionSource <Packet>();
            var pongTask = _pongCompletionSource.Task;

            if (Logger.IsTrace)
            {
                Logger.Trace($"{Session} P2P sending ping on {Session.RemotePort} ({RemoteClientId})");
            }
            Send(PingMessage.Instance);
            _nodeStatsManager.ReportEvent(Session.Node, NodeStatsEventType.P2PPingOut);
            var pingPerfCalcId = _perfService.StartPerfCalc();

            CancellationTokenSource delayCancellation = new CancellationTokenSource();
            var firstTask = await Task.WhenAny(pongTask, Task.Delay(Timeouts.P2PPing, delayCancellation.Token));

            _pongCompletionSource = null;
            if (firstTask != pongTask)
            {
                return(false);
            }

            delayCancellation.Cancel();
            var latency = _perfService.EndPerfCalc(pingPerfCalcId);

            if (latency.HasValue)
            {
                _nodeStatsManager.ReportLatencyCaptureEvent(Session.Node, NodeLatencyStatType.P2PPingPong, latency.Value);
            }

            return(true);
        }
示例#7
0
        public async Task RunPeerUpdate()
        {
            lock (_isPeerUpdateInProgressLock)
            {
                if (_isPeerUpdateInProgress)
                {
                    return;
                }

                _isPeerUpdateInProgress = true;
            }

            var key = _perfService.StartPerfCalc();

            var availibleActiveCount = _configurationProvider.ActivePeersMaxCount - _activePeers.Count;

            if (availibleActiveCount <= 0)
            {
                return;
            }

            var candidates = _newPeers.OrderBy(x => x.Value.NodeStats.IsTrustedPeer)
                             .ThenByDescending(x => x.Value.NodeStats.CurrentNodeReputation)
                             .Take(availibleActiveCount).ToArray();

            var newActiveNodes = 0;

            for (var i = 0; i < candidates.Length; i++)
            {
                var candidate = candidates[i];

                _newPeers.TryRemove(candidate.Key, out _);
                if (!_activePeers.TryAdd(candidate.Key, candidate.Value))
                {
                    if (_logger.IsErrorEnabled)
                    {
                        _logger.Error($"Active peer was already added to collection: {candidate.Key.ToString(false)}");
                        continue;
                    }
                }

                var result = await InitializePeerConnection(candidate.Value);

                if (result)
                {
                    newActiveNodes++;
                }
            }

            if (_logger.IsInfoEnabled)
            {
                _logger.Info($"RunPeerUpdate | Tried: {candidates.Length}, Added {newActiveNodes} active peers, current new peers: {_newPeers.Count}, current active peers: {_activePeers.Count}");

                if (_logCounter % 5 == 0)
                {
                    //TODO Change to debug after testing
                    _logger.Info($"\n\nAll active peers: \n{string.Join('\n', ActivePeers.Select(x => $"{x.Node.ToString()} | P2PInitialized: {x.NodeStats.DidEventHappen(NodeStatsEvent.P2PInitialized)} | Eth62Initialized: {x.NodeStats.DidEventHappen(NodeStatsEvent.Eth62Initialized)} | ClientId: {x.NodeStats.NodeDetails.ClientId}"))} \n\n");
                }

                _logCounter++;
            }

            _perfService.EndPerfCalc(key, "RunPeerUpdate");
            _isPeerUpdateInProgress = false;
        }
        public void LogSessionStats(IReadOnlyCollection <Peer> activePeers, IReadOnlyCollection <Peer> candidatePeers, bool logEventDetails)
        {
            var key        = _perfService.StartPerfCalc();
            var peers      = activePeers.Concat(candidatePeers).GroupBy(x => x.Node.Id).Select(x => x.First()).ToArray();
            var eventTypes = Enum.GetValues(typeof(NodeStatsEventType)).OfType <NodeStatsEventType>().Where(x => !x.ToString().Contains("Discovery"))
                             .OrderBy(x => x).ToArray();
            var eventStats = eventTypes.Select(x => new
            {
                EventType = x.ToString(),
                Count     = peers.Count(y => y.NodeStats.DidEventHappen(x))
            }).ToArray();

            var chains = peers.Where(x => x.NodeStats.EthNodeDetails != null).GroupBy(x => x.NodeStats.EthNodeDetails.ChainId).Select(
                x => new { ChainName = ChainId.GetChainName((int)x.Key), Count = x.Count() }).ToArray();
            var clients = peers.Where(x => x.NodeStats.P2PNodeDetails != null).Select(x => x.NodeStats.P2PNodeDetails.ClientId).GroupBy(x => x).Select(
                x => new { ClientId = x.Key, Count = x.Count() }).ToArray();
            var remoteDisconnect = peers.Count(x => x.NodeStats.EventHistory.Any(y => y.DisconnectDetails != null && y.DisconnectDetails.DisconnectType == DisconnectType.Remote));

            var sb = new StringBuilder();

            sb.AppendLine($"Session stats | {DateTime.Now.ToString(_networkConfig.DetailedTimeDateFormat)} | Active peers: {activePeers.Count} | Candidate peers: {candidatePeers.Count}");
            sb.AppendLine($"Peers count with each EVENT:{Environment.NewLine}" +
                          $"{string.Join(Environment.NewLine, eventStats.Select(x => $"{x.EventType.ToString()}:{x.Count}"))}{Environment.NewLine}" +
                          $"Remote disconnect: {remoteDisconnect}{Environment.NewLine}{Environment.NewLine}" +
                          $"CHAINS: {Environment.NewLine}" +
                          $"{string.Join(Environment.NewLine, chains.Select(x => $"{x.ChainName}:{x.Count}"))}{Environment.NewLine}{Environment.NewLine}" +
                          $"CLIENTS:{Environment.NewLine}" +
                          $"{string.Join(Environment.NewLine, clients.Select(x => $"{x.ClientId}:{x.Count}"))}{Environment.NewLine}");

            var peersWithLatencyStats = peers.Where(x => x.NodeStats.LatencyHistory.Any()).ToArray();

            if (peersWithLatencyStats.Any())
            {
                var latencyLog = GetLatencyComparisonLog(peersWithLatencyStats);
                sb.AppendLine(latencyLog);
            }

            if (_statsConfig.CaptureNodeStatsEventHistory && logEventDetails)
            {
                sb.AppendLine($"All peers ({peers.Length}):");
                sb.AppendLine($"{string.Join(Environment.NewLine, peers.Select(x => GetNodeLog(x.NodeStats)))}{Environment.NewLine}");

                var peersWithEvents = peers.Where(x => x.NodeStats.EventHistory.Any(y => y.EventType != NodeStatsEventType.NodeDiscovered)).ToArray();
                sb.AppendLine($"Logging {peersWithEvents.Length} peers log event histories");
                foreach (var peer in peersWithEvents)
                {
                    LogPeerEventHistory(peer);
                }
            }
            else
            {
                sb.AppendLine($"Detailed session log disabled, CaptureNodeStatsEventHistory: {_statsConfig.CaptureNodeStatsEventHistory}, logEventDetails: {logEventDetails}");
            }

            sb.AppendLine();
            var generalFilePath = Path.Combine(_eventLogsDirectoryPath, "generalStats.log");
            var content         = sb.ToString();

            File.AppendAllText(generalFilePath, content);
            if (_logger.IsTrace)
            {
                _logger.Trace(content);
            }

            var logTime = _perfService.EndPerfCalc(key);

            if (_logger.IsDebug)
            {
                _logger.Debug($"LogSessionStats time: {logTime} ms");
            }
        }
示例#9
0
        public async Task RunPeerUpdate()
        {
            lock (_isPeerUpdateInProgressLock)
            {
                if (_isPeerUpdateInProgress)
                {
                    return;
                }

                _isPeerUpdateInProgress = true;
            }

            var key = _perfService.StartPerfCalc();

            var availibleActiveCount = _configurationProvider.ActivePeersMaxCount - _activePeers.Count;

            if (availibleActiveCount <= 0)
            {
                return;
            }

            var candidates = _candidatePeers.Where(x => !_activePeers.ContainsKey(x.Key) && CheckLastDisconnect(x.Value))
                             .OrderBy(x => x.Value.NodeStats.IsTrustedPeer)
                             .ThenByDescending(x => x.Value.NodeStats.CurrentNodeReputation).ToArray();

            var newActiveNodes = 0;
            var tryCount       = 0;

            for (var i = 0; i < candidates.Length; i++)
            {
                if (newActiveNodes >= availibleActiveCount)
                {
                    break;
                }

                var candidate = candidates[i];
                tryCount++;

                if (!_activePeers.TryAdd(candidate.Key, candidate.Value))
                {
                    if (_logger.IsErrorEnabled)
                    {
                        _logger.Error($"Active peer was already added to collection: {candidate.Key}");
                    }
                }

                var result = await InitializePeerConnection(candidate.Value);

                if (!result)
                {
                    _activePeers.TryRemove(candidate.Key, out _);
                    continue;
                }

                newActiveNodes++;
            }

            if (_logger.IsInfoEnabled)
            {
                _logger.Info($"{nameof(RunPeerUpdate)} | Tried: {tryCount}, Added {newActiveNodes} active peers, current candidate peers: {_candidatePeers.Count}, current active peers: {_activePeers.Count}");

                if (_logCounter % 5 == 0)
                {
                    string nl = Environment.NewLine;
                    _logger.Debug($"{nl}{nl}All active peers: {nl}{string.Join(nl, ActivePeers.Select(x => $"{x.Node.ToString()} | P2PInitialized: {x.NodeStats.DidEventHappen(NodeStatsEvent.P2PInitialized)} | Eth62Initialized: {x.NodeStats.DidEventHappen(NodeStatsEvent.Eth62Initialized)} | ClientId: {x.NodeStats.NodeDetails.ClientId}"))} {nl}{nl}");
                }

                _logCounter++;
            }

            _perfService.EndPerfCalc(key, "RunPeerUpdate");
            _isPeerUpdateInProgress = false;
        }