Add debugging information to raw_secure_server_socket_test.

tests/standalone/io/raw_secure_server_socket_test.dart

 // Copyright (c) 2013, the Dart project authors.  Please see the AUTHORS file
 // for details. All rights reserved. Use of this source code is governed by a
 // BSD-style license that can be found in the LICENSE file.
 //
 // VMOptions=
 // VMOptions=--short_socket_read
 // VMOptions=--short_socket_write
 // VMOptions=--short_socket_read --short_socket_write
 // OtherResources=certificates/server_chain.pem
 // OtherResources=certificates/server_key.pem
@@ skipping 12 matching lines @@
 
 SecurityContext serverContext = new SecurityContext()
   ..useCertificateChain(localFile('certificates/server_chain.pem'))
   ..usePrivateKey(localFile('certificates/server_key.pem'),
                   password: 'dartdart');
 
 SecurityContext clientContext = new SecurityContext()
   ..setTrustedCertificates(localFile('certificates/trusted_certs.pem'));
 
 void testSimpleBind() {
+  print("asyncStart testSimpleBind");
   asyncStart();
   RawSecureServerSocket.bind(HOST, 0, serverContext).then((s) {
     Expect.isTrue(s.port > 0);
     s.close();
+    print("asyncEnd testSimpleBind");
     asyncEnd();
   });
 }
 
 void testInvalidBind() {
   int count = 0;
 
   // Bind to a unknown DNS name.
   asyncStart();
+  print("asyncStart testInvalidBind");
   RawSecureServerSocket.bind("ko.faar.__hest__", 0, serverContext).then((_) {
     Expect.fail("Failure expected");
   }).catchError((error) {
     Expect.isTrue(error is SocketException);
+    print("asyncEnd testInvalidBind");
     asyncEnd();
   });
 
   // Bind to an unavaliable IP-address.
   asyncStart();
+  print("asyncStart testInvalidBind 2");
   RawSecureServerSocket.bind("8.8.8.8", 0, serverContext).then((_) {
     Expect.fail("Failure expected");
   }).catchError((error) {
     Expect.isTrue(error is SocketException);
+    print("asyncEnd testInvalidBind 2");
     asyncEnd();
   });
 
   // Bind to a port already in use.
   asyncStart();
+  print("asyncStart testInvalidBind 3");
   RawSecureServerSocket.bind(HOST, 0, serverContext).then((s) {
     RawSecureServerSocket.bind(HOST,
                                s.port,
                                serverContext).then((t) {
       s.close();
       t.close();
       Expect.fail("Multiple listens on same port");
     })
     .catchError((error) {
       Expect.isTrue(error is SocketException);
       s.close();
+      print("asyncEnd testInvalidBind 3");
       asyncEnd();
     });
   });
 }
 
 void testSimpleConnect() {
+  print("asyncStart testSimpleConnect");
   asyncStart();
   RawSecureServerSocket.bind(HOST, 0, serverContext).then((server) {
     var clientEndFuture =
     RawSecureSocket.connect(HOST, server.port, context: clientContext);
     server.listen((serverEnd) {
       clientEndFuture.then((clientEnd) {
         // TODO(whesse): Shutdown(SEND) not supported on secure sockets.
         clientEnd.shutdown(SocketDirection.SEND);
         serverEnd.shutdown(SocketDirection.SEND);
         server.close();
+        print("asyncEnd testSimpleConnect");
         asyncEnd();
       });
     });
   });
 }
 
+int debugTestSimpleConnectFailCounter = 0;
 void testSimpleConnectFail(SecurityContext context, bool cancelOnError) {
+  var counter = debugTestSimpleConnectFailCounter++;
+  print("asyncStart testSimpleConnectFail $counter");
   asyncStart();
   RawSecureServerSocket.bind(HOST, 0, context).then((server) {
     var clientEndFuture =
         RawSecureSocket.connect(HOST, server.port, context: clientContext)
       .then((clientEnd) {
         Expect.fail("No client connection expected.");
       })
       .catchError((error) {
         Expect.isTrue(error is SocketException ||
                       error is HandshakeException);
       });
     server.listen((serverEnd) {
       Expect.fail("No server connection expected.");
     },
     onError: (error) {
       Expect.isTrue(error is SocketException ||
                     error is HandshakeException);
       clientEndFuture.then((_) {
         if (!cancelOnError) server.close();
+        print("asyncEnd testSimpleConnectFail $counter");
         asyncEnd();
       });
     },
     cancelOnError: cancelOnError);
   });
 }
 
 void testServerListenAfterConnect() {
+  print("asyncStart testServerListenAfterConnect");
   asyncStart();
   RawSecureServerSocket.bind(HOST, 0, serverContext).then((server) {
     Expect.isTrue(server.port > 0);
     var clientEndFuture =
         RawSecureSocket.connect(HOST, server.port, context: clientContext);
     new Timer(const Duration(milliseconds: 500), () {
       server.listen((serverEnd) {
         clientEndFuture.then((clientEnd) {
           clientEnd.shutdown(SocketDirection.SEND);
           serverEnd.shutdown(SocketDirection.SEND);
           server.close();
+          print("asyncEnd testServerListenAfterConnect");
           asyncEnd();
         });
       });
     });
   });
 }
 
 // This test creates a server and a client connects. The client then
 // writes and the server echos. When the server has finished its echo
 // it half-closes. When the client gets the close event is closes
@@ skipping 29 matching lines @@
                           bool handshakeBeforeSecure,
                           bool postponeSecure,
                           bool dropReads}) {
   int clientReads = 0;
   int serverReads = 0;
   if (handshakeBeforeSecure == true &&
       (listenSecure == true || connectSecure == true)) {
     Expect.fail("Invalid arguments to testSimpleReadWrite");
   }
 
+  print("asyncStart testSimpleReadWrite($listenSecure, $connectSecure, "
+       "$handshakeBeforeSecure, $postponeSecure, $dropReads");
   asyncStart();
 
   const messageSize = 1000;
   const handshakeMessageSize = 100;
 
   List<int> createTestData() {
     List<int> data = new List<int>(messageSize);
     for (int i = 0; i < messageSize; i++) {
       data[i] = i & 0xff;
     }
@@ skipping 277 matching lines @@
                 subscription: secure[0],
                 bufferedData: secure[1]).then((client) {
             runServer(client).then((_) => server.close());
           });
         });
       }
     });
 
     connectClient(server.port).then(runClient).then((socket) {
       socket.close();
+      print("asyncEnd testSimpleReadWrite($listenSecure, $connectSecure, "
+       "$handshakeBeforeSecure, $postponeSecure, $dropReads");
       asyncEnd();
     });
   }
 
   if (listenSecure) {
     RawSecureServerSocket.bind(
         HOST, 0, serverContext).then(serverReady);
   } else {
     RawServerSocket.bind(HOST, 0).then(serverReady);
   }
 }
 
 testPausedSecuringSubscription(bool pausedServer, bool pausedClient) {
+  print(
+      "asyncStart testPausedSecuringSubscription $pausedServer $pausedClient");
   asyncStart();
   var clientComplete = new Completer();
   RawServerSocket.bind(HOST, 0).then((server) {
     server.listen((client) {
       var subscription;
       subscription = client.listen((_) {
         if (pausedServer) {
           subscription.pause();
         }
         void done() {
           server.close();
           clientComplete.future.then((_) {
             client.close();
+            print("asyncEnd testPausedSecuringSubscription "
+                "$pausedServer $pausedClient");
             asyncEnd();
           });
         }
         try {
           RawSecureSocket.secureServer(
               client, serverContext, subscription: subscription)
             .catchError((_) {})
             .whenComplete(() {
               if (pausedServer) {
                 Expect.fail("secureServer succeeded with paused subscription");
@@ skipping 37 matching lines @@
             Expect.isTrue(e is ArgumentError);
           }
           clientComplete.complete(null);
         }
       });
     });
   });
 }
 
 main() {
+  print("asyncStart main");
   asyncStart();
   InternetAddress.lookup("localhost").then((hosts) {
     HOST = hosts.first;
     runTests();
+    print("asyncEnd main");
     asyncEnd();
   });
 }
 
 runTests() {

[Florian Schneider, 2016/12/13 18:27:20]

Would it make sense to split this up as a multi-test? This way we would also see
which part timed out without having to add printing.

[floitsch, 2016/12/13 19:21:48]

Unfortunately no: the test uses VMOptions which is not supported with
multitests.

   testSimpleBind();
   testInvalidBind();
   testSimpleConnect();
   SecurityContext context = new SecurityContext();
   testSimpleConnectFail(context, false);
   testSimpleConnectFail(context, true);
   var chain =
       Platform.script.resolve('certificates/untrusted_server_chain.pem')
       .toFilePath();
   context.useCertificateChain(chain);
@@ skipping 47 matching lines @@
   testSimpleReadWrite(listenSecure: false,
                       connectSecure: false,
                       handshakeBeforeSecure: true,
                       postponeSecure: true,
                       dropReads: true);
   testPausedSecuringSubscription(false, false);
   testPausedSecuringSubscription(true, false);
   testPausedSecuringSubscription(false, true);
   testPausedSecuringSubscription(true, true);
 }