Fix Swarm<T>.BroadcastTxAsync() an exception from IStore on some race conditions

.azure-pipelines/mono.yml

@@ -2,6 +2,7 @@ parameters:
   configuration: Debug
   testDisplayName: xunit.console.exe *.Tests.dll
   testCommand: "mono xunit.runner.console.*/tools/net461/xunit.console.exe"
+  testArguments: -verbose
 
 steps:
 
@@ -30,7 +31,8 @@ steps:
   inputs:
     script: |
       ${{ parameters.testCommand }} \
-        "$(pwd)"/*.Tests/bin/${{ parameters.configuration }}/net*/*.Tests.dll
+        "$(pwd)"/*.Tests/bin/${{ parameters.configuration }}/net*/*.Tests.dll \
+        ${{ parameters.testArguments }}
   env:
     TURN_SERVER_URL: ${{ parameters.turnServerUrl }}
   timeoutInMinutes: 10

.azure-pipelines/windows-net461.yml

@@ -1,5 +1,6 @@
 parameters:
   configuration: Debug
+  testArguments: -verbose
 
 steps:
 

CHANGES.md

@@ -13,9 +13,14 @@ To be released.
     reference is duplicate, where `trustedStateValidators` is present and
     a miner tries to download precalculated states from a trusted peer.
     [[#465], [#474]]
+ -  Fixed a bug tag `Swarm<T>.StartAsync()` sometimes had thrown an exception
+    from `IStore` (e.g., `NullReferenceException`) during broadcasting
+    transactions.  [[#352], [#476]]
 
+[#352]: https://github.com/planetarium/libplanet/issues/352
 [#465]: https://github.com/planetarium/libplanet/issues/465
 [#474]: https://github.com/planetarium/libplanet/pull/474
+[#476]: https://github.com/planetarium/libplanet/pull/476
 
 
 Version 0.5.1

Libplanet.Stun/Stun/TurnClient.cs

@@ -257,7 +257,7 @@ private async Task ProcessMessage()
                 {
                     Log.Error(
                         e,
-                        $"An unexpected exception occured during parsing."
+                        $"An unexpected exception occurred during {nameof(ProcessMessage)}(): {e}"
                     );
                 }
             }

Libplanet.Tests/Net/SwarmTest.cs

@@ -30,6 +30,8 @@ public class SwarmTest : IDisposable
         private const int Timeout = 60 * 1000;
         private const int DisposeTimeout = 5 * 1000;
 
+        private static Block<DumbAction>[] _fixtureBlocksForPreloadAsyncCancellationTest;
+
         private readonly ITestOutputHelper _output;
         private readonly StoreFixture _fx1;
         private readonly StoreFixture _fx2;
@@ -49,6 +51,8 @@ public SwarmTest(ITestOutputHelper output)
                 .CreateLogger()
                 .ForContext<SwarmTest>();
 
+            Log.Logger.Debug($"Started to initialize a {nameof(SwarmTest)} instance.");
+
             _output = output;
 
             var policy = new BlockPolicy<DumbAction>(new MinerReward(1));
@@ -81,22 +85,46 @@ public SwarmTest(ITestOutputHelper output)
                     appProtocolVersion: 1,
                     host: IPAddress.Loopback.ToString()),
             };
+
+            Log.Logger.Debug($"Finished to initialize a {nameof(SwarmTest)} instance.");
         }
 
         public void Dispose()
         {
-            _output.WriteLine($"Call {nameof(SwarmTest.Dispose)}()...");
+            Log.Logger.Debug($"Started to {nameof(Dispose)}() a {nameof(SwarmTest)} instance.");
+
+            try
+            {
+                Log.Logger.Debug(
+                    $"Started to {nameof(Dispose)}() {nameof(Swarm<DumbAction>)} instances."
+                );
+                int i = 1;
+                foreach (Swarm<DumbAction> s in _swarms)
+                {
+                    s.StopAsync().Wait(DisposeTimeout);
+                    Log.Logger.Debug(
+                        $"Finished to {nameof(Dispose)}() a {nameof(Swarm<DumbAction>)} " +
+                        "instance #{{0}}.",
+                        i
+                    );
+                    i++;
+                }
 
-            _fx1.Dispose();
-            _fx2.Dispose();
-            _fx3.Dispose();
+                Log.Logger.Debug(
+                    $"Finished to {nameof(Dispose)}() {nameof(Swarm<DumbAction>)} instances."
+                );
 
-            foreach (Swarm<DumbAction> s in _swarms)
+                NetMQConfig.Cleanup(false);
+                Log.Logger.Debug($"Finished to clean up the {nameof(NetMQConfig)} singleton.");
+            }
+            finally
             {
-                s.StopAsync().Wait(DisposeTimeout);
+                _fx1.Dispose();
+                _fx2.Dispose();
+                _fx3.Dispose();
             }
 
-            NetMQConfig.Cleanup(false);
+            Log.Logger.Debug($"Finished to {nameof(Dispose)}() a {nameof(SwarmTest)} instance.");
         }
 
         [Fact]
@@ -1209,28 +1237,19 @@ public async Task PreloadAsyncCancellation(int cancelAfter)
         {
             Swarm<DumbAction> minerSwarm = _swarms[0];
             Swarm<DumbAction> receiverSwarm = _swarms[1];
-            _output.WriteLine("Miner:    {0}", minerSwarm.Address);
-            _output.WriteLine("Receiver: {0}", receiverSwarm.Address);
+            Log.Logger.Information("Miner:    {0}", minerSwarm.Address);
+            Log.Logger.Information("Receiver: {0}", receiverSwarm.Address);
 
             BlockChain<DumbAction> minerChain = _blockchains[0];
             BlockChain<DumbAction> receiverChain = _blockchains[1];
             Guid receiverChainId = _blockchains[1].Id;
 
-            var signer = new PrivateKey();
-            Address address = signer.PublicKey.ToAddress();
-            _output.WriteLine("Fixture blocks:");
-            for (int i = 0; i < 20; i++)
-            {
-                for (int j = 0; j < 5; j++)
-                {
-                    minerChain.MakeTransaction(
-                        signer,
-                        new[] { new DumbAction(address, $"Item{i}.{j}") }
-                    );
-                }
+            (Address address, IEnumerable<Block<DumbAction>> blocks) =
+                MakeFixtureBlocksForPreloadAsyncCancellationTest();
 
-                Block<DumbAction> block = minerChain.MineBlock(minerSwarm.Address);
-                _output.WriteLine("  #{0,2} {1}", block.Index, block.Hash);
+            foreach (Block<DumbAction> block in blocks)
+            {
+                minerChain.Append(block);
             }
 
             Assert.NotNull(minerChain.Tip);
@@ -1248,11 +1267,11 @@ await receiverSwarm.PreloadAsync(
                     cancellationToken: cts.Token
                 );
                 canceled = false;
-                _output.WriteLine($"{nameof(receiverSwarm.PreloadAsync)}() normally finished.");
+                Log.Logger.Debug($"{nameof(receiverSwarm.PreloadAsync)}() normally finished.");
             }
             catch (OperationCanceledException)
             {
-                _output.WriteLine($"{nameof(receiverSwarm.PreloadAsync)}() aborted.");
+                Log.Logger.Debug($"{nameof(receiverSwarm.PreloadAsync)}() aborted.");
             }
 
             cts.Dispose();
@@ -1281,6 +1300,43 @@ await receiverSwarm.PreloadAsync(
             }
         }
 
+        private static (Address, Block<DumbAction>[])
+            MakeFixtureBlocksForPreloadAsyncCancellationTest()
+        {
+            Block<DumbAction>[] blocks = _fixtureBlocksForPreloadAsyncCancellationTest;
+
+            if (blocks is null)
+            {
+                var policy = new BlockPolicy<DumbAction>(new MinerReward(1));
+                using (var storeFx = new LiteDBStoreFixture())
+                {
+                    var chain = new BlockChain<DumbAction>(policy, storeFx.Store);
+                    Address miner = new PrivateKey().PublicKey.ToAddress();
+                    var signer = new PrivateKey();
+                    Address address = signer.PublicKey.ToAddress();
+                    Log.Logger.Information("Fixture blocks:");
+                    for (int i = 0; i < 20; i++)
+                    {
+                        for (int j = 0; j < 5; j++)
+                        {
+                            chain.MakeTransaction(
+                                signer,
+                                new[] { new DumbAction(address, $"Item{i}.{j}") }
+                            );
+                        }
+
+                        Block<DumbAction> block = chain.MineBlock(miner);
+                        Log.Logger.Information("  #{0,2} {1}", block.Index, block.Hash);
+                    }
+
+                    blocks = chain.ToArray();
+                    _fixtureBlocksForPreloadAsyncCancellationTest = blocks;
+                }
+            }
+
+            return (blocks[0].Transactions.First().Actions.First().TargetAddress, blocks);
+        }
+
         private async Task<Task> StartAsync(
             Swarm<DumbAction> swarm,
             CancellationToken cancellationToken = default

Libplanet/Blockchain/BlockChain.cs

@@ -1037,7 +1037,7 @@ internal IEnumerable<TxId> GetStagedTransactionIds(bool toBroadcast)
 
             try
             {
-                return Store.IterateStagedTransactionIds(toBroadcast);
+                return Store.IterateStagedTransactionIds(toBroadcast).ToArray();
             }
             finally
             {

azure-pipelines.yml

@@ -127,6 +127,7 @@ jobs:
       testDisplayName: StandaloneOSX *.Tests.dll
       testCommand: |-
         /tmp/StandaloneOSX.app/Contents/MacOS/StandaloneOSX
+      testArguments: ""
   timeoutInMinutes: 30
 
 - job: Linux_NETCore