private void LogBlockchainProgress(Data.Blockchain blockchain, Stopwatch totalStopwatch, long totalTxCount, long totalInputCount, Stopwatch currentRateStopwatch, long currentBlockCount, long currentTxCount, long currentInputCount) { var currentBlockRate = (float)currentBlockCount / currentRateStopwatch.ElapsedSecondsFloat(); var currentTxRate = (float)currentTxCount / currentRateStopwatch.ElapsedSecondsFloat(); var currentInputRate = (float)currentInputCount / currentRateStopwatch.ElapsedSecondsFloat(); Debug.WriteLine( string.Join("\n", new string('-', 80), "Height: {0,10} | Date: {1} | Duration: {7} hh:mm:ss | Validation: {8} hh:mm:ss | Blocks/s: {2,7} | Tx/s: {3,7} | Inputs/s: {4,7} | Total Tx: {5,7} | Total Inputs: {6,7} | Utxo Size: {9,7}", "GC Memory: {10,10:#,##0.00} MB", "Process Memory: {11,10:#,##0.00} MB", new string('-', 80) ) .Format2 ( blockchain.Height.ToString("#,##0"), "", currentBlockRate.ToString("#,##0"), currentTxRate.ToString("#,##0"), currentInputRate.ToString("#,##0"), totalTxCount.ToString("#,##0"), totalInputCount.ToString("#,##0"), totalStopwatch.Elapsed.ToString(@"hh\:mm\:ss"), validateStopwatch.Elapsed.ToString(@"hh\:mm\:ss"), blockchain.Utxo.Count.ToString("#,##0"), (float)GC.GetTotalMemory(false) / 1.MILLION(), (float)Process.GetCurrentProcess().PrivateMemorySize64 / 1.MILLION() )); }
private void ValidateCurrentChainWorker() { var currentBlockchainLocal = this._currentBlockchain; if (currentBlockchainLocal != null && this.Rules.GenesisBlock != null) { var stopwatch = new Stopwatch(); stopwatch.Start(); // revalidate current blockchain try { Calculator.RevalidateBlockchain(currentBlockchainLocal, this.Rules.GenesisBlock); } catch (ValidationException e) { //TODO this does not cancel a blockchain that is currently being processed Debug.WriteLine("******************************"); Debug.WriteLine("******************************"); Debug.WriteLine("BLOCKCHAIN ERROR DETECTED, ROLLING BACK TO GENESIS"); Debug.WriteLine("******************************"); Debug.WriteLine("******************************"); UpdateCurrentBlockchain(this._rules.GenesisBlockchain); } catch (MissingDataException e) { HandleMissingData(e); } stopwatch.Stop(); Debug.WriteLine("ValidateCurrentChainWorker: {0:#,##0.000}s".Format2(stopwatch.ElapsedSecondsFloat())); } }
private void ValidationWorker() { var stopwatch = new Stopwatch(); stopwatch.Start(); stopwatch.Stop(); Debug.WriteLine("ValidationWorker: {0:#,##0.000}s".Format2(stopwatch.ElapsedSecondsFloat())); }
private void LoadExistingState() { var stopwatch = new Stopwatch(); stopwatch.Start(); //TODO Tuple <BlockchainKey, BlockchainMetadata> winner = null; foreach (var tuple in this.StorageContext.BlockchainStorage.ListBlockchains()) { if (winner == null) { winner = tuple; } if (tuple.Item2.TotalWork > winner.Item2.TotalWork) { winner = tuple; } } // check if an existing blockchain has been found if (winner != null) { // read the winning blockchain var blockchain = this.StorageContext.BlockchainStorage.ReadBlockchain(winner.Item1); UpdateCurrentBlockchain(blockchain); UpdateWinningBlock(blockchain.RootBlock); // collect after loading GC.Collect(GC.MaxGeneration, GCCollectionMode.Forced, blocking: true); // clean up any old blockchains this.StorageContext.BlockchainStorage.RemoveBlockchains(winner.Item2.TotalWork); // log statistics stopwatch.Stop(); Debug.WriteLine( string.Join("\n", new string('-', 80), "Loaded blockchain on startup in {0:#,##0.000} seconds, height: {1:#,##0}, utxo size: {2:#,##0}", "GC Memory: {3,10:#,##0.00} MB", "Process Memory: {4,10:#,##0.00} MB", new string('-', 80) ) .Format2 ( stopwatch.ElapsedSecondsFloat(), blockchain.Height, blockchain.Utxo.Count, (float)GC.GetTotalMemory(false) / 1.MILLION(), (float)Process.GetCurrentProcess().PrivateMemorySize64 / 1.MILLION() )); } }
private void WriteBlockchainWorker() { var stopwatch = new Stopwatch(); stopwatch.Start(); // grab a snapshot var currentBlockchainLocal = this._currentBlockchain; // don't write out genesis blockchain if (currentBlockchainLocal != null && currentBlockchainLocal.Height > 0) { //TODO this.StorageContext.BlockchainStorage.WriteBlockchain(currentBlockchainLocal); this.StorageContext.BlockchainStorage.RemoveBlockchains(currentBlockchainLocal.TotalWork); } stopwatch.Stop(); Debug.WriteLine("WriteBlockchainWorker: {0:#,##0.000}s".Format2(stopwatch.ElapsedSecondsFloat())); }
private void WriteLine(Stopwatch stopwatch, string timerName, long filterTime, string memberName, int lineNumber) { if (IsEnabled) { if (timerName != null) { LogIf(stopwatch.ElapsedMilliseconds > filterTime, "\t[TIMING] {0}:{1}:{2} took {3:#,##0.000000} s".Format2(timerName, memberName, lineNumber, stopwatch.ElapsedSecondsFloat())); } else { LogIf(stopwatch.ElapsedMilliseconds > filterTime, "\t[TIMING] {1}:{2} took {3:#,##0.000000} s".Format2(timerName, memberName, lineNumber, stopwatch.ElapsedSecondsFloat())); } } }
private void WorkerLoop() { try { var working = false; try { var totalTime = Stopwatch.StartNew(); var workerTime = new Stopwatch(); var lastReportTime = DateTime.Now; while (!this.isDisposing) { // notify worker is idle this.idleEvent.Set(); // wait for execution to start this.startEvent.Wait(); // cooperative loop if (!this.isStarted) { continue; } // delay for the requested wait time, unless forced this.forceNotifyEvent.WaitOne(this.MinIdleTime); // wait for work notification if (this.MaxIdleTime == TimeSpan.MaxValue) { this.notifyEvent.WaitOne(); } else { this.notifyEvent.WaitOne(this.MaxIdleTime - this.MinIdleTime); // subtract time already spent waiting } // cooperative loop if (!this.isStarted) { continue; } // notify that work is starting this.idleEvent.Reset(); // notify var startHandler = this.OnWorkStarted; if (startHandler != null) { startHandler(); } // perform the work working = true; workerTime.Start(); try { WorkAction(); } finally { workerTime.Stop(); } working = false; // notify var stopHandler = this.OnWorkStopped; if (stopHandler != null) { stopHandler(); } if (DateTime.Now - lastReportTime > TimeSpan.FromSeconds(30)) { lastReportTime = DateTime.Now; var percentWorkerTime = workerTime.ElapsedSecondsFloat() / totalTime.ElapsedSecondsFloat(); this.logger.Debug("{0,55} work time: {1,10:##0.00%}".Format2(this.Name, percentWorkerTime)); } } } catch (ObjectDisposedException) { // only throw disposed exceptions that occur in WorkAction() if (!this.isDisposed && working) { throw; } } catch (OperationCanceledException) { } } catch (Exception e) { this.logger.FatalException("Unhandled worker exception", e); } }
public bool TryWriteValues(IEnumerable<KeyValuePair<UInt256, WriteValue<ImmutableArray<Transaction>>>> values) { var stopwatch = new Stopwatch(); var count = 0; try { using (var conn = this.OpenWriteConnection()) using (var cmd = conn.CreateCommand()) { cmd.CommandText = @" INSERT OR IGNORE INTO BlockTransactions ( BlockHash, TxIndex, TxHash, TxBytes ) VALUES ( @blockHash, @txIndex, @txHash, @txBytes )"; cmd.Parameters.Add(new SQLiteParameter { ParameterName = "@blockHash", DbType = DbType.Binary, Size = 32 }); cmd.Parameters.Add(new SQLiteParameter { ParameterName = "@txIndex", DbType = DbType.Int32 }); cmd.Parameters.Add(new SQLiteParameter { ParameterName = "@txHash", DbType = DbType.Binary, Size = 32 }); cmd.Parameters.Add(new SQLiteParameter { ParameterName = "@txBytes", DbType = DbType.Binary }); foreach (var keyPair in values) { var blockHash = keyPair.Key; cmd.Parameters["@blockHash"].Value = blockHash.ToDbByteArray(); for (var txIndex = 0; txIndex < keyPair.Value.Value.Length; txIndex++) { var tx = keyPair.Value.Value[txIndex]; var txBytes = StorageEncoder.EncodeTransaction(tx); cmd.Parameters["@txIndex"].Value = txIndex; cmd.Parameters["@txHash"].Value = tx.Hash.ToDbByteArray(); cmd.Parameters["@txBytes"].Size = txBytes.Length; cmd.Parameters["@txBytes"].Value = txBytes; count++; cmd.ExecuteNonQuery(); } } stopwatch.Start(); conn.Commit(); stopwatch.Stop(); return true; } } finally { Debug.WriteLine("flushed {0,5}: {1:#,##0.000000}s @ {2:#,##0.000}/s".Format2(count, stopwatch.ElapsedSecondsFloat(), count / stopwatch.ElapsedSecondsFloat())); } }
private void WriteBlockchainWorker() { var stopwatch = new Stopwatch(); stopwatch.Start(); // grab a snapshot var currentBlockchainLocal = this._currentBlockchain; // don't write out genesis blockchain if (!currentBlockchainLocal.IsDefault && currentBlockchainLocal.Height > 0) { //TODO this.StorageContext.BlockchainStorage.WriteBlockchain(currentBlockchainLocal); this.StorageContext.BlockchainStorage.RemoveBlockchains(currentBlockchainLocal.TotalWork); } stopwatch.Stop(); Debug.WriteLine("WriteBlockchainWorker: {0:#,##0.000}s".Format2(stopwatch.ElapsedSecondsFloat())); }
private void ValidateCurrentChainWorker() { var currentBlockchainLocal = this._currentBlockchain; if (!currentBlockchainLocal.IsDefault && !this.Rules.GenesisBlock.IsDefault) { var stopwatch = new Stopwatch(); stopwatch.Start(); // revalidate current blockchain try { Calculator.RevalidateBlockchain(currentBlockchainLocal, this.Rules.GenesisBlock); } catch (ValidationException e) { //TODO this does not cancel a blockchain that is currently being processed Debug.WriteLine("******************************"); Debug.WriteLine("******************************"); Debug.WriteLine("BLOCKCHAIN ERROR DETECTED, ROLLING BACK TO GENESIS"); Debug.WriteLine("******************************"); Debug.WriteLine("******************************"); UpdateCurrentBlockchain(this._rules.GenesisBlockchain); } catch (MissingDataException e) { HandleMissingData(e); } stopwatch.Stop(); Debug.WriteLine("ValidateCurrentChainWorker: {0:#,##0.000}s".Format2(stopwatch.ElapsedSecondsFloat())); } }
private void LoadExistingState() { var stopwatch = new Stopwatch(); stopwatch.Start(); //TODO Tuple<BlockchainKey, BlockchainMetadata> winner = null; foreach (var tuple in this.StorageContext.BlockchainStorage.ListBlockchains()) { if (winner == null) winner = tuple; if (tuple.Item2.TotalWork > winner.Item2.TotalWork) { winner = tuple; } } // check if an existing blockchain has been found if (winner != null) { // read the winning blockchain var blockchain = this.StorageContext.BlockchainStorage.ReadBlockchain(winner.Item1); UpdateCurrentBlockchain(blockchain); UpdateWinningBlock(blockchain.RootBlock); // collect after loading GC.Collect(GC.MaxGeneration, GCCollectionMode.Forced, blocking: true); // clean up any old blockchains this.StorageContext.BlockchainStorage.RemoveBlockchains(winner.Item2.TotalWork); // log statistics stopwatch.Stop(); Debug.WriteLine( string.Join("\n", new string('-', 80), "Loaded blockchain on startup in {0:#,##0.000} seconds, height: {1:#,##0}, utxo size: {2:#,##0}", "GC Memory: {3,10:#,##0.00} MB", "Process Memory: {4,10:#,##0.00} MB", new string('-', 80) ) .Format2 ( stopwatch.ElapsedSecondsFloat(), blockchain.Height, blockchain.Utxo.Count, (float)GC.GetTotalMemory(false) / 1.MILLION(), (float)Process.GetCurrentProcess().PrivateMemorySize64 / 1.MILLION() )); } }
// storage worker thread, flush values to storage private void StorageWorker() { // grab a snapshot var flushPendingLocal = this.flushPending.ToDictionary(x => x.Key, x => x.Value); // check for pending data if (flushPendingLocal.Count > 0) { // block threads on an excess storage flush if (this.IsPendingExcessivelyOversized) { this.storageBlockEvent.Reset(); } var stopwatch = new Stopwatch(); stopwatch.Start(); var sizeDelta = 0L; // try to flush to storage bool result; try { result = this.dataStorage.TryWriteValues(flushPendingLocal); } catch (Exception e) { Debug.WriteLine("{0}: UnboundedCache encountered exception during flush: {1}".Format2(this._name, e.Message)); Debugger.Break(); result = false; } if (result) { // success // remove values from pending list, unless they have been updated foreach (var keyPair in flushPendingLocal) { var key = keyPair.Key; var flushedValue = keyPair.Value; // try to remove the flushed value WriteValue <TValue> writeValue; if (this.flushPending.TryRemove(key, out writeValue)) { var valueSize = this.sizeEstimator(writeValue.Value); sizeDelta -= valueSize; // check that the removed value matches the flushed value if (flushedValue.Guid != writeValue.Guid) { // mismatch, try to add the flush value back if (this.flushPending.TryAdd(key, writeValue)) { sizeDelta += valueSize; } } } } // after flush, cache the stored values foreach (var keyPair in flushPendingLocal) { CacheValue(keyPair.Key, keyPair.Value.Value); } } // update pending size based on changes made Interlocked.Add(ref this.flushPendingSize, sizeDelta); stopwatch.Stop(); //Debug.WriteLineIf(this.Name == "BlockCache", "{0,25} StorageWorker flushed {1,3:#,##0} items, {2,6:#,##0} KB in {3,6:#,##0} ms".Format2(this.Name + ":", flushPendingLocal.Count, (float)-sizeDelta / 1.THOUSAND(), stopwatch.ElapsedMilliseconds)); this.flushRatesLock.DoWrite(() => { var flushedSize = flushPendingLocal.Values.Select(x => this.sizeEstimator(x.Value)).Sum(); this.flushRates.Add(flushedSize / stopwatch.ElapsedSecondsFloat()); while (this.flushRates.Count > 50) { this.flushRates.RemoveAt(0); } }); } // unblock any threads waiting on an excess storage flush //if (!this.IsPendingExcessivelyOversized) this.storageBlockEvent.Set(); }
public void RevalidateBlockchain(Data.Blockchain blockchain, Block genesisBlock) { var stopwatch = new Stopwatch(); stopwatch.Start(); try { //TODO delete corrupted data? could get stuck in a fail-loop on the winning chain otherwise // verify blockchain has blocks if (blockchain.BlockList.Count == 0) { throw new ValidationException(); } // verify genesis block hash if (blockchain.BlockList[0].BlockHash != genesisBlock.Hash) { throw new ValidationException(); } // get genesis block header var chainGenesisBlockHeader = this.CacheContext.GetBlockHeader(blockchain.BlockList[0].BlockHash); // verify genesis block header if ( genesisBlock.Header.Version != chainGenesisBlockHeader.Version || genesisBlock.Header.PreviousBlock != chainGenesisBlockHeader.PreviousBlock || genesisBlock.Header.MerkleRoot != chainGenesisBlockHeader.MerkleRoot || genesisBlock.Header.Time != chainGenesisBlockHeader.Time || genesisBlock.Header.Bits != chainGenesisBlockHeader.Bits || genesisBlock.Header.Nonce != chainGenesisBlockHeader.Nonce || genesisBlock.Hash != chainGenesisBlockHeader.Hash || genesisBlock.Hash != CalculateHash(chainGenesisBlockHeader)) { throw new ValidationException(); } // setup expected previous block hash value to verify each chain actually does link var expectedPreviousBlockHash = genesisBlock.Header.PreviousBlock; for (var height = 0; height < blockchain.BlockList.Count; height++) { // cooperative loop this.shutdownToken.ThrowIfCancellationRequested(); // get the current link in the chain var chainedBlock = blockchain.BlockList[height]; // verify height if (chainedBlock.Height != height) { throw new ValidationException(); } // verify blockchain linking if (chainedBlock.PreviousBlockHash != expectedPreviousBlockHash) { throw new ValidationException(); } // verify block exists var blockHeader = this.CacheContext.GetBlockHeader(chainedBlock.BlockHash); // verify block metadata matches header values if (blockHeader.PreviousBlock != chainedBlock.PreviousBlockHash) { throw new ValidationException(); } // verify block header hash if (CalculateHash(blockHeader) != chainedBlock.BlockHash) { throw new ValidationException(); } // next block metadata should have the current metadata's hash as its previous hash value expectedPreviousBlockHash = chainedBlock.BlockHash; } // all validation passed } finally { stopwatch.Stop(); Debug.WriteLine("Blockchain revalidation: {0:#,##0.000000}s".Format2(stopwatch.ElapsedSecondsFloat())); } }
public void RevalidateBlockchain(Data.Blockchain blockchain, Block genesisBlock) { var stopwatch = new Stopwatch(); stopwatch.Start(); try { //TODO delete corrupted data? could get stuck in a fail-loop on the winning chain otherwise // verify blockchain has blocks if (blockchain.BlockList.Count == 0) throw new ValidationException(); // verify genesis block hash if (blockchain.BlockList[0].BlockHash != genesisBlock.Hash) throw new ValidationException(); // get genesis block header var chainGenesisBlockHeader = this.CacheContext.GetBlockHeader(blockchain.BlockList[0].BlockHash); // verify genesis block header if ( genesisBlock.Header.Version != chainGenesisBlockHeader.Version || genesisBlock.Header.PreviousBlock != chainGenesisBlockHeader.PreviousBlock || genesisBlock.Header.MerkleRoot != chainGenesisBlockHeader.MerkleRoot || genesisBlock.Header.Time != chainGenesisBlockHeader.Time || genesisBlock.Header.Bits != chainGenesisBlockHeader.Bits || genesisBlock.Header.Nonce != chainGenesisBlockHeader.Nonce || genesisBlock.Hash != chainGenesisBlockHeader.Hash || genesisBlock.Hash != CalculateHash(chainGenesisBlockHeader)) { throw new ValidationException(); } // setup expected previous block hash value to verify each chain actually does link var expectedPreviousBlockHash = genesisBlock.Header.PreviousBlock; for (var height = 0; height < blockchain.BlockList.Count; height++) { // cooperative loop this.shutdownToken.ThrowIfCancellationRequested(); // get the current link in the chain var chainedBlock = blockchain.BlockList[height]; // verify height if (chainedBlock.Height != height) throw new ValidationException(); // verify blockchain linking if (chainedBlock.PreviousBlockHash != expectedPreviousBlockHash) throw new ValidationException(); // verify block exists var blockHeader = this.CacheContext.GetBlockHeader(chainedBlock.BlockHash); // verify block metadata matches header values if (blockHeader.PreviousBlock != chainedBlock.PreviousBlockHash) throw new ValidationException(); // verify block header hash if (CalculateHash(blockHeader) != chainedBlock.BlockHash) throw new ValidationException(); // next block metadata should have the current metadata's hash as its previous hash value expectedPreviousBlockHash = chainedBlock.BlockHash; } // all validation passed } finally { stopwatch.Stop(); Debug.WriteLine("Blockchain revalidation: {0:#,##0.000000}s".Format2(stopwatch.ElapsedSecondsFloat())); } }
public bool TryWriteValues(IEnumerable <KeyValuePair <UInt256, WriteValue <ImmutableArray <Transaction> > > > values) { var stopwatch = new Stopwatch(); var count = 0; try { using (var conn = this.OpenWriteConnection()) using (var cmd = conn.CreateCommand()) { cmd.CommandText = @" INSERT OR IGNORE INTO BlockTransactions ( BlockHash, TxIndex, TxHash, TxBytes ) VALUES ( @blockHash, @txIndex, @txHash, @txBytes )" ; cmd.Parameters.Add(new SQLiteParameter { ParameterName = "@blockHash", DbType = DbType.Binary, Size = 32 }); cmd.Parameters.Add(new SQLiteParameter { ParameterName = "@txIndex", DbType = DbType.Int32 }); cmd.Parameters.Add(new SQLiteParameter { ParameterName = "@txHash", DbType = DbType.Binary, Size = 32 }); cmd.Parameters.Add(new SQLiteParameter { ParameterName = "@txBytes", DbType = DbType.Binary }); foreach (var keyPair in values) { var blockHash = keyPair.Key; cmd.Parameters["@blockHash"].Value = blockHash.ToDbByteArray(); for (var txIndex = 0; txIndex < keyPair.Value.Value.Length; txIndex++) { var tx = keyPair.Value.Value[txIndex]; var txBytes = StorageEncoder.EncodeTransaction(tx); cmd.Parameters["@txIndex"].Value = txIndex; cmd.Parameters["@txHash"].Value = tx.Hash.ToDbByteArray(); cmd.Parameters["@txBytes"].Size = txBytes.Length; cmd.Parameters["@txBytes"].Value = txBytes; count++; cmd.ExecuteNonQuery(); } } stopwatch.Start(); conn.Commit(); stopwatch.Stop(); return(true); } } finally { Debug.WriteLine("flushed {0,5}: {1:#,##0.000000}s @ {2:#,##0.000}/s".Format2(count, stopwatch.ElapsedSecondsFloat(), count / stopwatch.ElapsedSecondsFloat())); } }