Add debugging statements

Fix flaky test by executing action and setting latch sooner. Prior to this change the connection could be closed before enough messages are published to have the latch set in HandleBasicDeliver

Author: lukebakken

projects/Unit/Fixtures.cs

@@ -528,17 +528,24 @@ internal Process ExecCommand(string ctl, string args, string changeDirTo)
             }
 
             try {
+              System.Console.WriteLine("@@@@@@@@ ExecCommand FileName: {0}", cmd);
               proc.StartInfo.FileName = cmd;
+
+              System.Console.WriteLine("@@@@@@@@ ExecCommand Arguments: {0}", args);
               proc.StartInfo.Arguments = args;
+
               proc.StartInfo.RedirectStandardError = true;
               proc.StartInfo.RedirectStandardOutput = true;
 
+              System.Console.WriteLine("@@@@@@@@ ExecCommand Start()");
               proc.Start();
-                string stderr = proc.StandardError.ReadToEnd();
+              System.Console.WriteLine("@@@@@@@@ ExecCommand WaitForExit()");
               proc.WaitForExit();
+              string stderr = proc.StandardError.ReadToEnd();
+              System.Console.WriteLine("@@@@@@@@ ExecCommand WaitForExit() DONE ExitCode: {0} stderr: {1}", proc.ExitCode, stderr);
               if (stderr.Length >  0 || proc.ExitCode > 0)
               {
-                    string stdout = proc.StandardOutput.ReadToEnd();
+                  string stdout = proc.StandardOutput.ReadToEnd();
                   ReportExecFailure(cmd, args, $"{stderr}\n{stdout}");
               }
 
@@ -649,21 +656,21 @@ internal List<ConnectionInfo> ListConnections()
         internal void CloseConnection(IConnection conn)
         {
             ConnectionInfo ci = ListConnections().First(x => conn.ClientProvidedName == x.Name);
-            CloseConnection(ci.Pid);
+            CloseConnection(conn.ClientProvidedName, ci.Pid);
         }
 
         internal void CloseAllConnections()
         {
             List<ConnectionInfo> cs = ListConnections();
             foreach(ConnectionInfo c in cs)
             {
-                CloseConnection(c.Pid);
+                CloseConnection(c.Name, c.Pid);
             }
         }
 
-        internal void CloseConnection(string pid)
+        internal void CloseConnection(string name, string pid)
         {
-            ExecRabbitMQCtl($"close_connection \"{pid}\" \"Closed via rabbitmqctl\"");
+            ExecRabbitMQCtl($"close_connection \"{pid}\" \"{name} {pid} closed via rabbitmqctl\"");
         }
 
         internal void RestartRabbitMQ()

projects/Unit/TestConnectionRecovery.cs

@@ -114,7 +114,8 @@ public void TestBasicAckEventHandlerRecovery()
             CloseAndWaitForRecovery();
             Assert.IsTrue(Model.IsOpen);
 
-            WithTemporaryNonExclusiveQueue(Model, (m, q) => m.BasicPublish("", q, null, encoding.GetBytes("")));
+            byte[] mb = RandomMessageBody();
+            WithTemporaryNonExclusiveQueue(Model, (m, q) => m.BasicPublish("", q, null, mb));
             Wait(latch);
         }
 
@@ -989,7 +990,8 @@ internal void AssertQueueRecovery(IModel m, string q, bool exclusive)
             m.QueueDeclarePassive(q);
             QueueDeclareOk ok1 = m.QueueDeclare(q, false, exclusive, false, null);
             Assert.AreEqual(ok1.MessageCount, 0);
-            m.BasicPublish("", q, null, encoding.GetBytes(""));
+            byte[] mb = RandomMessageBody();
+            m.BasicPublish("", q, null, mb);
             Assert.IsTrue(WaitForConfirms(m));
             QueueDeclareOk ok2 = m.QueueDeclare(q, false, exclusive, false, null);
             Assert.AreEqual(ok2.MessageCount, 1);
@@ -1024,11 +1026,20 @@ internal void CloseAndWaitForRecovery()
 
         internal void CloseAndWaitForRecovery(AutorecoveringConnection conn)
         {
+            System.Console.WriteLine("@@@@@@@@ CloseAndWaitForRecovery START");
             ManualResetEventSlim sl = PrepareForShutdown(conn);
             ManualResetEventSlim rl = PrepareForRecovery(conn);
+            System.Console.WriteLine("@@@@@@@@ CloseAndWaitForRecovery Closing Connection START");
             CloseConnection(conn);
+            System.Console.WriteLine("@@@@@@@@ CloseAndWaitForRecovery Closing Connection DONE");
+
+            System.Console.WriteLine("@@@@@@@@ CloseAndWaitForRecovery Shutdown Wait START");
             Wait(sl);
+            System.Console.WriteLine("@@@@@@@@ CloseAndWaitForRecovery Shutdown Wait DONE");
+
+            System.Console.WriteLine("@@@@@@@@ CloseAndWaitForRecovery Recovery Wait START");
             Wait(rl);
+            System.Console.WriteLine("@@@@@@@@ CloseAndWaitForRecovery Recovery Wait DONE");
         }
 
         internal void CloseAndWaitForShutdown(AutorecoveringConnection conn)
@@ -1083,9 +1094,10 @@ internal void TestDelayedBasicAckNackAfterChannelRecovery(TestBasicConsumer1 con
             AutorecoveringConnection publishingConn = CreateAutorecoveringConnection();
             IModel publishingModel = publishingConn.CreateModel();
 
+            byte[] mb = RandomMessageBody();
             for (int i = 0; i < n; i++)
             {
-                publishingModel.BasicPublish("", q, null, encoding.GetBytes(""));
+                publishingModel.BasicPublish("", q, null, mb);
             }
 
             Wait(latch, TimeSpan.FromSeconds(20));
@@ -1157,7 +1169,6 @@ public class TestBasicConsumer1 : DefaultBasicConsumer
         {
             private readonly Action _action;
             private readonly ManualResetEventSlim _latch;
-            private ushort _counter = 0;
 
             public TestBasicConsumer1(IModel model, ManualResetEventSlim latch, Action fn)
                 : base(model)
@@ -1176,19 +1187,21 @@ public override void HandleBasicDeliver(string consumerTag,
             {
                 try
                 {
-                    if (deliveryTag == 7 && _counter < 10)
+                    System.Console.WriteLine("@@@@@@@@ HandleBasicDeliver deliveryTag: {0}", deliveryTag);
+
+                    if (deliveryTag == 5)
                     {
                         _action();
                     }
-                    if (_counter == 9)
+
+                    if (deliveryTag == 6)
                     {
                         _latch.Set();
                     }
-                    PostHandleDelivery(deliveryTag);
                 }
                 finally
                 {
-                    _counter += 1;
+                    PostHandleDelivery(deliveryTag);
                 }
             }