Fix system tests (PR nvaccess#11776)

* Fix locking issue.

Creating a new lock for each critical section is a bug.
Instead, use a reentrant lock, only _onNvdaSpeech modifies speech cache
and it will be called from another thread (NVDA Main), all asserts will
be called from the RobotRemoteServer thread.

* Ensure speech has started before declaring it has finished.

There was a race condition after completing an action to trigger speech
and waiting for that speech to be completed that meant speech may not
not have been started at all.

This is fixed by allowing the start index of the speech to be declared.

* Avoid start marker search if focus is already correct

Sometimes focus lands on the document (and sometimes URL) when
starting system tests with Chrome. If the focus is already in the document
just continue with the test to save time.

* Add example to run the only the chrome tests locally.

* reenable treegrid test

tests/system/libraries/ChromeLib.py

@@ -80,6 +80,33 @@ def _writeTestFile(testCase) -> str:
 			f.write(fileContents)
 		return filePath
 
+	def _wasStartMarkerSpoken(self, speech: str):
+		if "document" not in speech:
+			return False
+		documentIndex = speech.index("document")
+		marker = ChromeLib._beforeMarker
+		return marker in speech and documentIndex < speech.index(marker)
+
+	def _moveToStartMarker(self, spy):
+		""" Press F6 until the start marker is spoken
+		@param spy:
+		@type spy: SystemTestSpy.speechSpyGlobalPlugin.NVDASpyLib
+		@return: None
+		"""
+		for i in range(10):  # set a limit on the number of tries.
+			# Small changes in Chrome mean the number of tab presses to get into the document can vary.
+			builtIn.sleep("0.5 seconds")  # ensure application has time to receive input
+			actualSpeech = self.getSpeechAfterKey('f6')
+			if self._wasStartMarkerSpoken(actualSpeech):
+				break
+		else:  # Exceeded the number of tries
+			spy.dump_speech_to_log()
+			builtIn.fail(
+				"Unable to tab to 'before sample' marker."
+				f" Too many attempts looking for '{ChromeLib._beforeMarker}'"
+				" See NVDA log for full speech."
+			)
+
 	def prepareChrome(self, testCase: str) -> None:
 		"""
 		Starts Chrome opening a file containing the HTML sample
@@ -97,24 +124,14 @@ def prepareChrome(self, testCase: str) -> None:
 		# If this continues to be unreliable we could use solenium or similar to start chrome and inform us when
 		# it is ready.
 		applicationTitle = f"{self._testCaseTitle}"
-		spy.wait_for_specific_speech(applicationTitle)
+		appTitleIndex = spy.wait_for_specific_speech(applicationTitle)
 		# Read all is configured, but just test interacting with the sample.
 		spy.wait_for_speech_to_finish()
 
-		# move to start marker
-		for i in range(10):  # set a limit on the number of tries.
-			# Small changes in Chrome mean the number of tab presses to get into the document can vary.
-			builtIn.sleep("0.5 seconds")  # ensure application has time to receive input
-			actualSpeech = self.getSpeechAfterKey('f6')
-			if ChromeLib._beforeMarker in actualSpeech:
-				break
-		else:  # Exceeded the number of tries
-			spy.dump_speech_to_log()
-			builtIn.fail(
-				"Unable to tab to 'before sample' marker."
-				f" Too many attempts looking for '{ChromeLib._beforeMarker}'"
-				" See NVDA log for full speech."
-			)
+		afterTitleSpeech = spy.get_speech_at_index_until_now(appTitleIndex)
+		if not self._wasStartMarkerSpoken(afterTitleSpeech):
+			self._moveToStartMarker(spy)
+
 
 	@staticmethod
 	def getSpeechAfterKey(key) -> str:
@@ -125,7 +142,7 @@ def getSpeechAfterKey(key) -> str:
 		spy.wait_for_speech_to_finish()
 		nextSpeechIndex = spy.get_next_speech_index()
 		spy.emulateKeyPress(key)
-		spy.wait_for_speech_to_finish()
+		spy.wait_for_speech_to_finish(speechStartedIndex=nextSpeechIndex)
 		speech = spy.get_speech_at_index_until_now(nextSpeechIndex)
 		return speech
 

tests/system/libraries/SystemTestSpy/speechSpyGlobalPlugin.py

@@ -48,8 +48,9 @@ def __init__(self):
 		self._nvdaSpeech_requiresLock = [  # requires thread locking before read/write
 			[""],  # initialise with an empty string, this allows for access via [-1]. This is equiv to no speech.
 		]
-		self._speechOccurred_requiresLock = False  # requires thread locking before read/write
 		self._lastSpeechTime_requiresLock = _timer()
+		#: Lock to protect members written in _onNvdaSpeech.
+		self._speechLock = threading.RLock()
 		self._isNvdaStartupComplete = False
 		self._allSpeechStartIndex = self.get_last_speech_index()
 		self._maxKeywordDuration = 30
@@ -72,8 +73,7 @@ def _onNvdaStartupComplete(self):
 	def _onNvdaSpeech(self, speechSequence=None):
 		if not speechSequence:
 			return
-		with threading.Lock():
-			self._speechOccurred_requiresLock = True
+		with self._speechLock:
 			self._lastSpeechTime_requiresLock = _timer()
 			self._nvdaSpeech_requiresLock.append(speechSequence)
 
@@ -83,40 +83,42 @@ def _getJoinedBaseStringsFromCommands(speechCommandArray) -> str:
 		return ''.join(baseStrings).strip()
 
 	def _getSpeechAtIndex(self, speechIndex):
-		with threading.Lock():
+		with self._speechLock:
 			return self._getJoinedBaseStringsFromCommands(self._nvdaSpeech_requiresLock[speechIndex])
 
 	def get_speech_at_index_until_now(self, speechIndex: int) -> str:
 		""" All speech from (and including) the index until now.
 		@param speechIndex:
 		@return: The speech joined together, see L{_getJoinedBaseStringsFromCommands}
 		"""
-		with threading.Lock():
+		with self._speechLock:
 			speechCommands = [
 				self._getJoinedBaseStringsFromCommands(x) for x in self._nvdaSpeech_requiresLock[speechIndex:]
 			]
 			return "\n".join(x for x in speechCommands if x and not x.isspace())
 
 	def get_last_speech_index(self) -> int:
-		with threading.Lock():
+		with self._speechLock:
 			return len(self._nvdaSpeech_requiresLock) - 1
 
 	def _getIndexOfSpeech(self, speech, searchAfterIndex: Optional[int] = None):
 		if searchAfterIndex is None:
 			firstIndexToCheck = 0
 		else:
 			firstIndexToCheck = 1 + searchAfterIndex
-		with threading.Lock():
+		with self._speechLock:
 			for index, commands in enumerate(self._nvdaSpeech_requiresLock[firstIndexToCheck:]):
 				index = index + firstIndexToCheck
 				baseStrings = [c.strip() for c in commands if isinstance(c, str)]
 				if any(speech in x for x in baseStrings):
 					return index
 			return -1
 
-	def _hasSpeechFinished(self):
-		with threading.Lock():
-			return self.SPEECH_HAS_FINISHED_SECONDS < _timer() - self._lastSpeechTime_requiresLock
+	def _hasSpeechFinished(self, speechStartedIndex: Optional[int] = None):
+		with self._speechLock:
+			started = speechStartedIndex is None or speechStartedIndex < self.get_next_speech_index()
+			finished = self.SPEECH_HAS_FINISHED_SECONDS < _timer() - self._lastSpeechTime_requiresLock
+			return started and finished
 
 	def _devInfoToLog(self):
 		import api
@@ -128,7 +130,7 @@ def _devInfoToLog(self):
 
 	def dump_speech_to_log(self):
 		log.debug("dump_speech_to_log.")
-		with threading.Lock():
+		with self._speechLock:
 			try:
 				self._devInfoToLog()
 			except Exception:
@@ -202,9 +204,13 @@ def wait_for_specific_speech(
 			)
 		return speechIndex
 
-	def wait_for_speech_to_finish(self, maxWaitSeconds=5.0):
+	def wait_for_speech_to_finish(
+			self,
+			maxWaitSeconds=5.0,
+			speechStartedIndex: Optional[int] = None
+	):
 		_blockUntilConditionMet(
-			getValue=self._hasSpeechFinished,
+			getValue=lambda: self._hasSpeechFinished(speechStartedIndex=speechStartedIndex),
 			giveUpAfterSeconds=self._minTimeout(maxWaitSeconds),
 			errorMessage="Speech did not finish before timeout"
 		)

tests/system/readme.md

@@ -39,6 +39,11 @@ To run a single test, add the `--test` argument (wildcards accepted).
 python -m robot --test "starts" ...
 ```
 
+To run all tests with a particular tag use `-i`:
+```
+python -m robot -i "chrome" ...
+```
+
 Other options exit for specifying tests to run (e.g. by suite, tag, etc).
 Consult `python -m robot --help`
 

tests/system/robot/chromeTests.robot

@@ -38,5 +38,4 @@ pr11606
 ARIA treegrid
 	[Documentation]	Ensure that ARIA treegrids are accessible as a standard table in browse mode.
 	# Excluded due to regular failures.
-	[Tags]	excluded_from_build
 	test_ariaTreeGrid_browseMode