WebXR WPT: add a xr_debug function for use in tests

By default, this is a no-op, but test API implementations can override
it to do console logging or similar.

This is intended to help investigate flaky tests on Windows that are
currently just being reported as "timed out" with no indication what's
going wrong.

Includes a fix for ar_dom_overlay_hit_test.https.html, the logs had
shown that the test wasn't waiting for the test body to execute,
and an unexpectedly failing assertion wasn't being reached.

Bug: 1054750
Change-Id: I878c6ea56ebb8e0752027ea13de7106d7f9e7bdb
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2132784
Commit-Queue: Klaus Weidner <klausw@chromium.org>
Reviewed-by: Alexander Cooper <alcooper@chromium.org>
Cr-Commit-Position: refs/heads/master@{#759108}

third_party/blink/web_tests/external/wpt/resources/chromium/webxr-test.js

@@ -76,6 +76,10 @@ class ChromeXRTest {
     document.body.appendChild(button);
     test_driver.click(button);
   }
+
+  Debug(name, msg) {
+    console.log(new Date().toISOString() + ' DEBUG[' + name + '] ' + msg);
+  }
 }
 
 // Mocking class definitions

third_party/blink/web_tests/external/wpt/webxr/dom-overlay/ar_dom_overlay.https.html

@@ -106,6 +106,7 @@ let watcherStep = new Event("watcherstep");
 let watcherDone = new Event("watcherdone");
 
 let testInput = function(overlayElement, session, fakeDeviceController, t) {
+  let debug = xr_debug.bind(this, 'testInput');
 
   // Use two DIVs for this test. "inner_a" uses a "beforexrselect" handler
   // that uses preventDefault(). Controller interactions with it should trigger
@@ -135,30 +136,38 @@ let testInput = function(overlayElement, session, fakeDeviceController, t) {
       fakeDeviceController.simulateInputSourceConnection(SCREEN_CONTROLLER);
   session.requestReferenceSpace('viewer').then(function(viewerSpace) {
     // Press the primary input button and then release it a short time later.
+    debug('got viewerSpace');
     session.requestAnimationFrame((time, xrFrame) => {
+      debug('got rAF 1');
       input_source.setOverlayPointerPosition(inner_a.offsetLeft + 1,
                                              inner_a.offsetTop + 1);
       input_source.startSelection();
 
       session.requestAnimationFrame((time, xrFrame) => {
+        debug('got rAF 2');
         input_source.endSelection();
 
         session.requestAnimationFrame((time, xrFrame) => {
+          debug('got rAF 3');
           // Need to process one more frame to allow select to propagate.
           session.requestAnimationFrame((time, xrFrame) => {
+            debug('got rAF 4');
             session.dispatchEvent(watcherStep);
 
             assert_true(got_beforexrselect);
 
             session.requestAnimationFrame((time, xrFrame) => {
+              debug('got rAF 5');
               input_source.setOverlayPointerPosition(inner_b.offsetLeft + 1,
                                                      inner_b.offsetTop + 1);
               input_source.startSelection();
 
               session.requestAnimationFrame((time, xrFrame) => {
+                debug('got rAF 6');
                 input_source.endSelection();
 
                 session.requestAnimationFrame((time, xrFrame) => {
+                  debug('got rAF 7');
                   // Need to process one more frame to allow select to propagate.
                   session.dispatchEvent(watcherDone);
                 });
@@ -173,6 +182,8 @@ let testInput = function(overlayElement, session, fakeDeviceController, t) {
 };
 
 let testCrossOriginContent = function(overlayElement, session, fakeDeviceController, t) {
+  let debug = xr_debug.bind(this, 'testCrossOriginContent');
+
   let iframe = document.getElementById('iframe');
   assert_true(iframe != null);
   let inner_b = document.getElementById('inner_b');
@@ -192,27 +203,34 @@ let testCrossOriginContent = function(overlayElement, session, fakeDeviceControl
   session.requestReferenceSpace('viewer').then(function(viewerSpace) {
     // Press the primary input button and then release it a short time later.
     session.requestAnimationFrame((time, xrFrame) => {
+      debug('got rAF 1');
       input_source.setOverlayPointerPosition(iframe.offsetLeft + 1,
                                              iframe.offsetTop + 1);
       input_source.startSelection();
 
       session.requestAnimationFrame((time, xrFrame) => {
+        debug('got rAF 2');
         input_source.endSelection();
 
         session.requestAnimationFrame((time, xrFrame) => {
+          debug('got rAF 3');
           // Need to process one more frame to allow select to propagate.
           session.requestAnimationFrame((time, xrFrame) => {
+            debug('got rAF 4');
             session.dispatchEvent(watcherStep);
 
             session.requestAnimationFrame((time, xrFrame) => {
+              debug('got rAF 5');
               input_source.setOverlayPointerPosition(inner_b.offsetLeft + 1,
                                                      inner_b.offsetTop + 1);
               input_source.startSelection();
 
               session.requestAnimationFrame((time, xrFrame) => {
+                debug('got rAF 6');
                 input_source.endSelection();
 
                 session.requestAnimationFrame((time, xrFrame) => {
+                  debug('got rAF 7');
                   // Need to process one more frame to allow select to propagate.
                   session.dispatchEvent(watcherDone);
                 });

third_party/blink/web_tests/external/wpt/webxr/dom-overlay/ar_dom_overlay_hit_test.https.html

@@ -35,6 +35,7 @@ const fakeDeviceInitParams = {
   views: VALID_VIEWS,
   viewerOrigin: IDENTITY_TRANSFORM,
   supportedFeatures: ALL_FEATURES,
+  world: createFakeWorld(5.0, 2.0, 5.0),  // see webxr_test_constants_fake_world.js for details
 };
 
 const hitTestOptionsInit = {
@@ -58,40 +59,54 @@ const testCrossOriginContent = function(overlayElement, session, fakeDeviceContr
   const iframe = document.getElementById('iframe');
   const inner_b = document.getElementById('inner_b');
 
+  let debug = xr_debug.bind(this, 'testCrossOriginContent');
+
   const input_source =
       fakeDeviceController.simulateInputSourceConnection(screen_controller_init);
+  debug('start');
   return session.requestReferenceSpace('viewer').then(function(viewerSpace) {
+    debug('got viewerSpace');
     return session.requestHitTestSourceForTransientInput(hitTestOptionsInit)
                   .then((hitTestSource) => {
-      // Press the primary input button and then release it a short time later.
-      session.requestAnimationFrame((time, xrFrame) => {
-        input_source.setOverlayPointerPosition(iframe.offsetLeft + 1,
-                                               iframe.offsetTop + 1);
-        input_source.startSelection();
-
+      debug('got hitTestSource');
+      return new Promise((resolve) => {
+        // Press the primary input button and then release it a short time later.
         session.requestAnimationFrame((time, xrFrame) => {
-          input_source.endSelection();
-
-          // There should be no results for transient input for cross origin content:
-          const results = xrFrame.getHitTestResultsForTransientInput(hitTestSource);
-          t.step(() => {
-            assert_true(results.length === 0, "Hit test results should be suppressed for cross-origin content");
-          });
+          debug('got rAF 1');
+          input_source.setOverlayPointerPosition(iframe.offsetLeft + 1,
+                                                 iframe.offsetTop + 1);
+          input_source.startSelection();
 
           session.requestAnimationFrame((time, xrFrame) => {
-            // Need to process one more frame to allow select to propagate
+            input_source.endSelection();
+
+            // There should be no results for transient input for cross origin content:
+            const results = xrFrame.getHitTestResultsForTransientInput(hitTestSource);
+            t.step(() => {
+              assert_equals(results.length, 0, "Hit test results should be suppressed for cross-origin content");
+            });
 
             session.requestAnimationFrame((time, xrFrame) => {
-              input_source.setOverlayPointerPosition(inner_b.offsetLeft + 1,
-                                                      inner_b.offsetTop + 1);
-              input_source.startSelection();
+              debug('got rAF 2');
+              // Need to process one more frame to allow select to propagate
 
               session.requestAnimationFrame((time, xrFrame) => {
-                input_source.endSelection();
-
-                const results = xrFrame.getHitTestResultsForTransientInput(hitTestSource);
-                t.step(() => {
-                  assert_true(results.length === 1, "Hit test results should not be for cross-origin content");
+                debug('got rAF 3');
+                input_source.setOverlayPointerPosition(inner_b.offsetLeft + 1,
+                                                       inner_b.offsetTop + 1);
+                input_source.startSelection();
+
+                session.requestAnimationFrame((time, xrFrame) => {
+                  debug('got rAF 4');
+                  input_source.endSelection();
+
+                  const results = xrFrame.getHitTestResultsForTransientInput(hitTestSource);
+                  t.step(() => {
+                    // TODO(bialpio): this assertion is currently failing, FIXME
+                    assert_equals(results.length, 1, "Hit test results should be available for same-origin content");
+                  });
+                  debug('resolving');
+                  resolve();
                 });
               });
             });

third_party/blink/web_tests/external/wpt/webxr/getViewerPose_emulatedPosition.https.html

@@ -16,9 +16,12 @@
     };
 
     let testFunction = function(session, fakeDeviceController, t) {
+      let debug = xr_debug.bind(this, 'testFunction');
       return session.requestReferenceSpace('local')
         .then((referenceSpace) => new Promise((resolve, reject) => {
+          debug('refSpace promise');
           function CheckPositionNotEmulated(time, vrFrame){
+            debug('rAF 1: checkPositionNotEmulated');
             t.step(() => {
               let pose = vrFrame.getViewerPose(referenceSpace);
               assert_not_equals(pose, null);
@@ -30,6 +33,7 @@
           }
 
           function CheckPositionEmulated(time, vrFrame) {
+            debug('rAF 2: checkPositionEmulated');
             t.step(() => {
               let pose = vrFrame.getViewerPose(referenceSpace);
               assert_not_equals(pose, null);
@@ -37,6 +41,7 @@
             });
 
             // Finished.
+            debug('resolve');
             resolve();
           }
 

third_party/blink/web_tests/external/wpt/webxr/hit-test/ar_hittest_subscription_transientInputSources.https.html

@@ -52,11 +52,13 @@ const fakeDeviceInitParams = {
 //                            Null entries in the array mean that the given entry will not be validated.
 let testFunctionGenerator = function(ray, expectedPoses, inputFromPointer, nextFrameExpectedPoses) {
   const testFunction = function(session, fakeDeviceController, t) {
+    let debug = xr_debug.bind(this, 'testFunction');
     return session.requestReferenceSpace('local').then((localRefSpace) => new Promise((resolve, reject) => {
 
       const input_source_controller = fakeDeviceController.simulateInputSourceConnection(screen_controller_init);
 
       session.requestAnimationFrame((time, frame) => {
+        debug('rAF 1');
         t.step(() => {
           assert_equals(session.inputSources.length, 1);
         });
@@ -74,6 +76,7 @@ let testFunctionGenerator = function(ray, expectedPoses, inputFromPointer, nextF
 
           // We got a hit test source, now get the results in subsequent rAFcb:
           session.requestAnimationFrame((time, frame) => {
+            debug('rAF 2');
             const results = frame.getHitTestResultsForTransientInput(hitTestSource);
 
             t.step(() => {
@@ -92,6 +95,7 @@ let testFunctionGenerator = function(ray, expectedPoses, inputFromPointer, nextF
             input_source_controller.setPointerOrigin(inputFromPointer, false);
 
             session.requestAnimationFrame((time, frame) => {
+              debug('rAF 3');
               const results = frame.getHitTestResultsForTransientInput(hitTestSource);
 
               t.step(() => {
@@ -105,6 +109,7 @@ let testFunctionGenerator = function(ray, expectedPoses, inputFromPointer, nextF
                 }
               });
 
+              debug('resolving');
               resolve();
             });
           });

third_party/blink/web_tests/external/wpt/webxr/resources/webxr_util.js

@@ -7,13 +7,19 @@
 //
 //   --enable-blink-features=MojoJS,MojoJSTest
 
+// Debugging message helper, by default does nothing. Implementations can
+// override this.
+var xr_debug = function(name, msg) {}
+
 function xr_promise_test(name, func, properties) {
   promise_test(async (t) => {
     // Perform any required test setup:
+    xr_debug(name, 'setup');
 
     if (window.XRTest === undefined) {
       // Chrome setup
       await loadChromiumResources;
+      xr_debug = navigator.xr.test.Debug;
     }
 
     // Ensure that any devices are disconnected when done. If this were done in
@@ -22,9 +28,11 @@ function xr_promise_test(name, func, properties) {
     // interfere with the next test.
     t.add_cleanup(async () => {
       // Ensure system state is cleaned up.
+      xr_debug(name, 'cleanup');
       await navigator.xr.test.disconnectAllDevices();
     });
 
+    xr_debug(name, 'main');
     return func(t);
   }, name, properties);
 }
@@ -74,9 +82,12 @@ function xr_session_promise_test(
               })
               .then(() => new Promise((resolve, reject) => {
                       // Perform the session request in a user gesture.
+                      xr_debug(name, 'simulateUserActivation');
                       navigator.xr.test.simulateUserActivation(() => {
+                        xr_debug(name, 'document.hasFocus()=' + document.hasFocus());
                         navigator.xr.requestSession(sessionMode, sessionInit || {})
                             .then((session) => {
+                              xr_debug(name, 'session start');
                               testSession = session;
                               session.mode = sessionMode;
                               let glLayer = new XRWebGLLayer(session, gl, gllayerProperties);
@@ -87,9 +98,11 @@ function xr_session_promise_test(
                                   baseLayer: glLayer
                               });
                               sessionObjects.glLayer = glLayer;
+                              xr_debug(name, 'session.visibilityState=' + session.visibilityState);
                               resolve(func(session, testDeviceController, t, sessionObjects));
                             })
                             .catch((err) => {
+                              xr_debug(name, 'error: ' + err);
                               reject(
                                   'Session with params ' +
                                   JSON.stringify(sessionMode) +