Bug 1346673 - Add more logging to external media test startup. r?maja_zf
Add extra logging to the external media tests' startup in order to help
diagnose failures to start. Also standardise log calls, replacing instances
that were using execute script for logging. Finally, move some of the wait
object creation so they're closer to where they're used, especially given
the new log lines.
MozReview-Commit-ID: Lf3rxsm7u5Z
--- a/dom/media/test/external/external_media_tests/media_utils/twitch_puppeteer.py
+++ b/dom/media/test/external/external_media_tests/media_utils/twitch_puppeteer.py
@@ -40,25 +40,28 @@ class TwitchPuppeteer(VideoPuppeteer):
def __init__(self, marionette, url, autostart=True,
set_duration=10.0, **kwargs):
self.player = None
self._last_seen_player_state = None
super(TwitchPuppeteer,
self).__init__(marionette, url, set_duration=set_duration,
autostart=False, **kwargs)
- wait = Wait(self.marionette, timeout=30)
with self.marionette.using_context(Marionette.CONTEXT_CONTENT):
+ wait = Wait(self.marionette, timeout=30)
+ self.marionette.log(type(self).__name__ + ': waiting for .player '
+ 'element. Timeout: {}.'
+ .format(wait.timeout))
verbose_until(wait, self,
expected.element_present(By.CLASS_NAME,
'player'))
self.player = self.marionette.find_element(By.CLASS_NAME,
'player')
- self.marionette.execute_script("log('.player "
- "element obtained');")
+ self.marionette.log(type(self).__name__ +
+ ': .player element obtained')
if autostart:
self.start()
def _update_expected_duration(self):
if 0 < self._set_duration:
self.expected_duration = self._set_duration
else:
# If we don't have a set duration we don't know how long is left
--- a/dom/media/test/external/external_media_tests/media_utils/video_puppeteer.py
+++ b/dom/media/test/external/external_media_tests/media_utils/video_puppeteer.py
@@ -105,35 +105,41 @@ class VideoPuppeteer(object):
self.timeout = timeout
self._set_duration = set_duration
self.video = None
self.expected_duration = 0
self._first_seen_time = 0
self._first_seen_wall_time = 0
self._fetch_state_script_string = None
self._last_seen_video_state = None
- wait = Wait(self.marionette, timeout=self.timeout)
with self.marionette.using_context(Marionette.CONTEXT_CONTENT):
+ self.marionette.log(type(self).__name__ + ': Navigating to URL: {}'
+ .format(self.test_url))
self.marionette.navigate(self.test_url)
- self.marionette.execute_script("""
- log('URL: {0}');""".format(self.test_url))
+ self.marionette.log(type(self).__name__ + ': Navigated to URL: {}'
+ .format(self.test_url))
+ wait = Wait(self.marionette, timeout=self.timeout)
+ self.marionette.log(type(self).__name__ + ': waiting for video '
+ 'element. Timeout: {}.'
+ .format(wait.timeout))
verbose_until(wait, self,
expected.element_present(By.TAG_NAME, 'video'))
videos_found = self.marionette.find_elements(By.CSS_SELECTOR,
video_selector)
if len(videos_found) > 1:
self.marionette.log(type(self).__name__ + ': multiple video '
'elements found. '
'Using first.')
if len(videos_found) <= 0:
self.marionette.log(type(self).__name__ + ': no video '
'elements found.')
return
self.video = videos_found[0]
- self.marionette.execute_script("log('video element obtained');")
+ self.marionette.log(type(self).__name__ +
+ ': video element obtained')
if autostart:
self.start()
def start(self):
# To get an accurate expected_duration, playback must have started
self._refresh_state()
wait = Wait(self, timeout=self.timeout)
verbose_until(wait, self, VideoPuppeteer.playback_started,
--- a/dom/media/test/external/external_media_tests/media_utils/youtube_puppeteer.py
+++ b/dom/media/test/external/external_media_tests/media_utils/youtube_puppeteer.py
@@ -81,25 +81,29 @@ class YouTubePuppeteer(VideoPuppeteer):
def __init__(self, marionette, url, autostart=True, **kwargs):
self.player = None
self._last_seen_player_state = None
super(YouTubePuppeteer,
self).__init__(marionette, url,
video_selector='.html5-video-player video',
autostart=False,
**kwargs)
- wait = Wait(self.marionette, timeout=30)
with self.marionette.using_context(Marionette.CONTEXT_CONTENT):
+ wait = Wait(self.marionette, timeout=30)
+ self.marionette.log(type(self).__name__ + ': waiting for '
+ '.html5-video-player '
+ 'element. Timeout: {}.'
+ .format(wait.timeout))
verbose_until(wait, self,
expected.element_present(By.CLASS_NAME,
'html5-video-player'))
self.player = self.marionette.find_element(By.CLASS_NAME,
'html5-video-player')
- self.marionette.execute_script("log('.html5-video-player "
- "element obtained');")
+ self.marionette.log(type(self).__name__ +
+ ': .html5-video-player element obtained')
# When an ad is playing, self.player_duration indicates the duration
# of the spliced-in ad stream, not the duration of the main video, so
# we attempt to skip the ad first.
for attempt in range(5):
sleep(1)
self.process_ad()
if (self._last_seen_player_state.player_ad_inactive and
self._last_seen_video_state.duration and not