Remove races from the WebRequest debugger unit test

Got rid of our reliance on sleeps to ensure correct timing in the WebRequest debugger unit test. A change with a recent diff removed some of the races by waiting for the client to enter the busy state before sending an interrupt to mimic ctrl-c. Generalized that a bit, and extended it to ensure the initial handshake between the harness, debugger request, and the request to be debugged is correct. I've removed the 10s sleep on startup, and the 3s sleep after each notification from the various requests back to the harness. Also added a bunch of comments to hopefully explain the test better, and renamed some files/functions to better reflect what they're doing. This seems to work well on my box… I've run it a bunch in both dbg and opt builds to try to get it to fail but haven't yet. Fingers crossed ;)

hphp/test/debugger_tests/web_request_phase_1.php

@@ -0,0 +1,76 @@
+<?php
+require_once("hphpd.php");
+require_once("hphpd_test_inc.php");
+
+error_log("In test ".$_SERVER['PHP_SELF']);
+$client = get_client("web_request", "debugger_tests");
+if (!$client) {
+  echo FAIL;
+  return;
+}
+
+function breaks($c) {
+  // order depends on web_request_t.php
+  // file:line
+
+  // We might like to test breaking at request start here, but we can't. There
+  // is a race between telling the harness were ready for web_request_t.php
+  // below and issuing the continue command right after that. The request may
+  // start before we've issued the continue command, and we'll miss the
+  // corresponding interrupt. We test request end and PSP end elsewhere, which
+  // both share the same properties as request start, so that will have to do.
+
+  // Normal breakpoint to get things started.
+  $c->processCmd('break', array('break_t.php:7'));
+
+  // Get the harness to load web_request_t.php, which will wait for the client
+  // to enter the busy state (via the Continue command below) before proceeding
+  // to execute the code where the breakpoint is set.
+  sendToHarness('1');
+
+  // Continue and wait for the breakpoint to hit.
+  $o = $c->processCmd('continue', null);
+  VS($o['output_type'], 'code_loc');
+  VS(substr($o['file'],-11), 'break_t.php');
+  VS($o['line_no'], 7);
+  $o = $c->processCmd('variable', null);
+  VS($o['values']['x'], 'test_break() in web_request_t.php');
+  $c->processCmd('break', array('clear', 'all'));
+
+  // func entry
+  $c->processCmd('break', array('foo()'));
+  $o = $c->processCmd('continue', null);
+  VS(substr($o['file'],-11), 'break_t.php');
+  VS($o['line_no'], 6);
+  $c->processCmd('break', array('clear', 'all'));
+
+  // object method
+  $c->processCmd('break', array('cls::pubObj()'));
+  $o = $c->processCmd('continue', null);
+  VS(substr($o['file'],-11), 'break_t.php');
+  VS($o['line_no'], 12);
+  $c->processCmd('break', array('clear', 'all'));
+
+  // static method
+  $c->processCmd('break', array('cls::pubCls()'));
+  $o = $c->processCmd('continue', null);
+  VS(substr($o['file'],-11), 'break_t.php');
+  VS($o['line_no'], 15);
+  $c->processCmd('break', array('clear', 'all'));
+
+  // hphpd_break()
+  $o = $c->processCmd('continue', null);
+  VS(substr($o['file'],-11), 'break_t.php');
+  VS($o['line_no'], 19);
+}
+
+try {
+  breaks($client);
+  echo PASS;
+} catch (TestFailure $t) {
+  error_log($t);
+  echo FAIL;
+} catch (Exception $e) {
+  error_log($e);
+  echo FAIL;
+}

hphp/test/debugger_tests/web_request_phase_2.php

@@ -0,0 +1,65 @@
+<?php
+require_once("hphpd.php");
+require_once("hphpd_test_inc.php");
+
+error_log("In test ".$_SERVER['PHP_SELF']);
+$client = get_client("web_request", "debugger_tests");
+if (!$client) {
+  echo FAIL;
+  return;
+}
+
+function signal1($c) {
+  // Wait for an interrupt with in the request.
+  sendToHarness('2');
+  $o = $c->processCmd('continue', null);
+  VS($o['output_type'], 'code_loc');
+  VS(substr($o['file'],-17), 'web_request_t.php');
+  VS($o['line_no'], 20);
+  $o = $c->processCmd('print', array('$a'));
+  VS($o['values']['value'], 1);
+  // Break the endless loop in web_request_t.php.
+  $c->processCmd('@', array('$a=0'));
+}
+
+function signal2($c) {
+  // Stop on request and PSP end.
+  $c->processCmd('break', array('end', '/web_request_t.php'));
+  $c->processCmd('break', array('psp', '/web_request_t.php'));
+  $o = $c->processCmd('continue', null);
+
+  // Should be at request end.
+  // Try to print something bogus. Should be undefined.
+  VS(substr($o['text'], -7, 5), 'ended');
+  $o = $c->processCmd('print', array('$foo'));
+  VS(substr($o['text'], 23, 23), 'Undefined variable: foo');
+  $o = $c->processCmd('continue', null);
+
+  // Should be at psp end.
+  // Try to print something bogus. Should be undefined.
+  VS(substr($o['text'], -7, 5), 'ended');
+  $o = $c->processCmd('print', array('$foo'));
+  VS(substr($o['text'], 23, 23), 'Undefined variable: foo');
+
+  // Tell the test harness that we're done messing with the request, and to
+  // interrupt us one last time.
+  $c->processCmd('break', array('clear', 'all'));
+  sendToHarness('3');
+
+  // Wait for an interrupt after the request is done, controlled by test harness
+  $o = $c->processCmd('continue', null);
+  VS($o['output_type'], 'code_loc');
+  VS($o['file'], '');
+}
+
+try {
+  signal1($client);
+  signal2($client);
+  echo PASS;
+} catch (TestFailure $t) {
+  error_log($t);
+  echo FAIL;
+} catch (Exception $e) {
+  error_log($e);
+  echo FAIL;
+}

hphp/test/test_debugger.cpp

@@ -181,6 +181,12 @@ static std::string getSandboxHostFormat() {
   return sandboxHost;
 }
 
+// Wait for a notification from a request that it is ready for the test
+// harness to proceed to another step.
+// NB: the notification comes in before the debugging logic running in the
+// server has a chance to continue. Every request that follows a call to this
+// function should likely beging with a call to waitForClientToGetBusy() to
+// ensure the client is ready to receive more interrupts.
 bool TestDebugger::recvFromTests(char& flag) {
   const int TIMEOUT_SEC = 10;
   int fifoFd = open(m_fname.c_str(), O_RDONLY | O_NONBLOCK);
@@ -212,12 +218,12 @@ bool TestDebugger::recvFromTests(char& flag) {
     return false;
   }
   close(fifoFd);
-  // slightly wait here since the server side will send out the flag _before_
-  // going to block, but we should take action _after_ it is blocked.
-  usleep(30000);
   return true;
 }
 
+// The goal of this is to test a real web request, rather than simply evaling
+// snippets of code like the other tests. A single web request is issued and
+// debugged by multiple other requests.
 bool TestDebugger::TestWebRequest() {
   bool ret = false;
 
@@ -226,6 +232,9 @@ bool TestDebugger::TestWebRequest() {
   if (sandboxHost.empty()) {
     return CountSkip();
   }
+
+  // A quick sanity check to ensure the server is still up and accepting
+  // requests.
   string result;
   if (!getResponse("hello.php", result, -1, sandboxHost) ||
       result != "Hello, World!") {
@@ -234,6 +243,9 @@ bool TestDebugger::TestWebRequest() {
     return CountSkip();
   }
 
+  // We need to wait at various times during the test for a request to progress
+  // to a certian point, at which time we can take further action. This is done
+  // via this pipe.
   m_fname = "/tmp/hphpd_test_fifo." +
             boost::lexical_cast<string>(Process::GetProcessId());
   if (mkfifo(m_fname.c_str(), 0666)) {
@@ -243,19 +255,18 @@ bool TestDebugger::TestWebRequest() {
 
   m_tempResult = false;
 
-  AsyncFunc<TestDebugger> func(this, &TestDebugger::testWebRequestHelper);
+  // Kick off a thread to make requests for the debugger portions of this test.
+  AsyncFunc<TestDebugger> func(this, &TestDebugger::testWebRequestHelperPhase1);
   func.start();
 
   char flag;
-  // wait for "web_request.php" to connect and wait
+  // Wait for web_request_phase_1.php, the first debugger portion of the test,
+  // to connect and get ready to debug.
   if (!recvFromTests(flag) || flag != '1') {
     printf("failed to receive from test\n");
   } else {
-    // First try to make sure that the client in web_requests enters the mode
-    // where it can respond to a breakpoint being reached.
-    sleep(10);
     // Now get web_request_t.php running so that web_requests.php
-    // can debug it.
+    // can debug it. Wait here for the entire request to finish.
     if (!getResponse("web_request_t.php", result, -1, sandboxHost) ||
         result != "request done") {
       printf("failed on web_request_t.php\n");
@@ -268,47 +279,64 @@ bool TestDebugger::TestWebRequest() {
 
   unlink(m_fname.c_str());
 
-  // testWebRequestHelper() should flag m_tempResult to true if succeed
+  // testWebRequestHelperPhase1() should flag m_tempResult to true if succeed
   ret = ret && m_tempResult;
   return Count(ret);
 }
 
-void TestDebugger::testWebRequestHelper() {
+// First phase of debugging for TestWebRequest.
+// This thread will issue requests to debug the the request for
+// web_request_t.php. This is done with multiple requests to allow us to test
+// breaking with ctrl-c.
+void TestDebugger::testWebRequestHelperPhase1() {
   string result;
-  if (getResponse("web_request.php", result)) {
+  // Start with the first phase of debugging. This will test request start,
+  // breakpoints and inspection, and a hard breakpoint. web_request_t.php will
+  // be left stopped at a hard breakpoint near the end of test_break().
+  if (getResponse("web_request_phase_1.php", result)) {
     m_tempResult = result == "pass";
   } else {
-    printf("failed to get response for web_request.php\n");
+    printf("failed to get response for web_request_phase_1.php\n");
   }
   if (!m_tempResult) {
     return;
   }
 
   m_tempResult = false;
-  // test interrupt: again starting a new thread first wait on interrupts
+  // Test interrupt: again starting a new thread to continue the next phase of
+  // debugging logic. This will issue a request for web_request_phase_2.php.
   AsyncFunc<TestDebugger> func(this,
-                               &TestDebugger::testWebRequestHelperSignal);
+                               &TestDebugger::testWebRequestHelperPhase2);
   func.start();
 
   char flag;
-  // wait for "web_request_signal.php" to connect and wait
+  // Wait for web_request_phase_2.php to connect and get ready to debug.
   if (!recvFromTests(flag) || flag != '2') {
     printf("failed to receive from test\n");
     return;
   }
 
+  // Issue a reqeust for web_request_interrupt.php. Web_request_phase_2.php has
+  // let the original request for web_request_t.php run, and it should now be
+  // spinning in an infinite loop in test_sleep(). This will issue a ctrl-c
+  // which will break within that loop.
   if (!getResponse("web_request_interrupt.php", result) ||
       result != "interrupt done") {
     printf("failed on web_request_interrupt.php\n");
     return;
   }
 
-  // wait for "web_request_t.php" to finish
+  // Wait for web_request_phase_2.php to finish debugging the original request
+  // for web_request_t.php, which will be left running after the end of PSP.
   if (!recvFromTests(flag) || flag != '3') {
     printf("failed to receive from test\n");
     return;
   }
 
+  // Issue another request for web_request_interrupt.php. The original request
+  // for web_request_t.php should be done by now, so this should interrupt in
+  // the dummy sandbox. This will finally let web_request_phase_2.php complete,
+  // thus completing the debugging portion of this test.
   if (!getResponse("web_request_interrupt.php", result) ||
       result != "interrupt done") {
     printf("failed on web_request_interrupt.php\n");
@@ -318,12 +346,15 @@ void TestDebugger::testWebRequestHelper() {
   func.waitForEnd();
 }
 
-void TestDebugger::testWebRequestHelperSignal() {
+// Second phase of debugging for TestWebRequest.
+// This thread will issue a single request for web_request_phase_2.php, which
+// will complete debugging of the request for web_request_t.php.
+void TestDebugger::testWebRequestHelperPhase2() {
   string result;
-  if (getResponse("web_request_signal.php", result)) {
+  if (getResponse("web_request_phase_2.php", result)) {
     m_tempResult = result == "pass";
   } else {
-    printf("failed to get response for web_request_signal.php\n");
+    printf("failed to get response for web_request_phase_2.php\n");
   }
 }
 

hphp/test/test_debugger.h

@@ -56,8 +56,8 @@ private:
                    const std::string& host = "");
   bool recvFromTests(char& c);
 
-  void testWebRequestHelper();
-  void testWebRequestHelperSignal();
+  void testWebRequestHelperPhase1();
+  void testWebRequestHelperPhase2();
   bool m_tempResult;
 };