RepoItemInfo.WaitForExists() fails early despite long timeout

[rmathena]

I have a test which passes 90% of the time, but sometimes fails with an error I don't understand. I'm waiting for an item to exist. The timeout is 30s but it fails after 5s with an invocation error. I've checked the timeout for the individual Exists action in the recording, as well at the values associated with the repository item. Is there something else I should be checking? Or is this a bug?

This is Ranorex 9.1.1 on Windows 10 64-bit.

Attached screenshots show the report and the project in Ranorex Studio.

This is the generated code:

Code: Select all

            Report.Log(ReportLevel.Info, "Wait", "Waiting 30s to exist. Associated repository item: 'RootMainWindow.LicenseStatus'", repo.RootMainWindow.LicenseStatusInfo, new ActionTimeout(30000), new RecordItemIndex(15));
            repo.RootMainWindow.LicenseStatusInfo.WaitForExists(30000);

This is from the log:

-------------------------------
---[Info] Waiting 30s to exist. Associated repository item: 'RootMainWindow.LicenseStatus'---
[type] repoitem
[path] /form[@wpfnative='True' and @name='RootMainWindow']/container/?/?/text[@automationid='LicenseStatus']
[itempath] container/?/?/text[@automationid='LicenseStatus']
[fullname] MyRealTestRepository.RootMainWindow.LicenseStatus
[id] e4f0107162804987aec421d96d208c04
[timeout] 30000
[codefile] c:\TeamCity\buildAgent\work\ea2ea9f02f1842f\src\Tests\MyRealTest\StartAUT.cs
[itemindex] 15
---------------------------------------------------------------------------------------------
---[Debug] LineageGlueRule 'wpf_root' caused ApplicationNotRespondingException on Execute. Invocation did not finish within the timeout of '00:00:05'.---
[stacktrace] Ranorex.ApplicationNotRespondingException: Invocation did not finish within the timeout of '00:00:05'.
Ranorex.Core.FunctionExecuteWithTimeout.TryExecute(Func`1 func,TimeSpan timeout) +0x2a
Ranorex.Core.FunctionExecuteWithTimeout.WithTimeout(Func`1 func,Nullable`1 timeout) +0x10
Ranorex.Plugin.WpfRootRule.TryAddWpfRootToElementEngine(WpfAutomationWrapper proxy,Win32FlavorElement candidate,GlueRuleExecutionState state) +0x8b
Ranorex.Plugin.WpfRootRule.AddWpfNative(GlueRuleExecutionState state) +0x71
Ranorex.Plugin.WpfRootRule.Execute(GlueRuleExecutionState state) +0x34
Ranorex.Core.ElementEngine.ApplyGlueRules(Element element,GlueRuleExecutionStateImpl state,Boolean includeRemotes) +0x6a
Called from:
Ranorex.Core.ElementEngine.ApplyGlueRules(Element element,GlueRuleExecutionStateImpl state,Boolean includeRemotes) +0xc8
Ranorex.Core.ElementEngine.ApplyReplaceGlueRulesOnSingleRecentlyInsertedElement(Element parentElement,GlueRuleExecutionStateImpl state,GlueRuleExecutionStateImpl replaceState,Element recentlyInsertedElement) +0x45
Ranorex.Core.ElementEngine.ApplyReplaceGlueRulesOnRecentlyInserted(Element element,GlueRuleExecutionStateImpl state) +0x1f
Ranorex.Core.ElementEngine.ApplyGlueRules(Element element,GlueRuleExecutionStateImpl state,Boolean includeRemotes) +0xf6
Ranorex.Core.ElementEngine.ApplyGlueRules(Element element,Boolean includeRemotes) +0x17
Ranorex.Core.Element.GetChildren(CacheSession session) +0x4f
Ranorex.Core.Element.get_Children() +0x7
Ranorex.Core.RxPath.collectAxis(LocationStep step,Axis optimizedAxis,Element self,IList`1 elements,Boolean quitOnFirstGoodNode) +0x47
Ranorex.Core.RxPath.ApplyInternal(RxPath path,Element startElement,Duration timeout,Boolean findSingle,CacheSession& usedCacheSession,PathDiagnostics& pathDiagnostics) +0x4a1
Ranorex.Core.RxPath.Apply(Element startElement,Duration timeout,Boolean findSingle,CacheSession& usedCacheSession,PathDiagnostics& pathDiagnostics) +0xd
Ranorex.Core.Element.TryFindInternal(RxPath path,Duration timeout,Boolean findSingle,IList`1& foundElements,CacheSession& usedCacheSession,Duration& elementSearchTime,Int32& iterations) +0x139
Ranorex.Core.Repository.RepoItemInfo.FindInternal(Boolean findSingle,Boolean throwException,Duration effectiveTimeoutOverride) +0x4a
Ranorex.Core.Repository.RepoItemInfo+<>c__DisplayClass75_0`1.<Find>b__0() +0x18
Ranorex.Core.Testing.Services.NoMaintenanceModeService.HandleElementNotFound(Func`1 action,RepoItemInfo entry) +0x1
Ranorex.Core.Repository.RepoItemInfo.Find(Boolean findSingle,Boolean throwException,Duration effectiveTimeoutOverride) +0x33
Ranorex.Core.Repository.RepoItemInfo.WaitForExists(Duration waitTimeout) +0x0
MyRealTest.StartAUT.Ranorex.Core.Testing.ITestModule.Run() c:\TeamCity\buildAgent\work\ea2ea9f02f1842f\src\Tests\MyRealTest\StartAUT.cs:line 153;13
Ranorex.Core.Testing.TestModuleLeaf.RunInternal(DataContext parentDataContext,Int32 iteration,Int32 iterationCount,Boolean skipIteration) +0xfe
Ranorex.Core.Testing.TestModuleLeaf.RunWithRepeats(DataContext parentDataContext,ErrorBehavior errorBehavior) +0xe0
Ranorex.Core.Testing.TestModuleLeaf.Run(DataContext parentDataContext,Boolean childSkip) +0x2f
Ranorex.Core.Testing.SetupNode.Run(DataContext parentDataContext,Boolean childSkip) +0x4f
Ranorex.Core.Testing.TestCaseNode.RunChildren(IEnumerable`1 entries,TestResult overallResult,Boolean& childSkip,Boolean& tearDownPending) +0x21
Ranorex.Core.Testing.TestCaseNode.RunSetupContainer(Boolean& childSkip,Boolean& tearDownPending) +0x0
Ranorex.Core.Testing.TestCaseNode.RunChildren(Boolean childSkip) +0x2
Ranorex.Core.Testing.TestCaseNode+<>c__DisplayClass81_0.<RunWithoutIterations>b__0(RetryInfo retry) +0x69
Ranorex.Core.Testing.Retry.DoRetry(Func`2 operationToRetry) +0x13
Ranorex.Core.Testing.TestCaseNode.RunWithoutIterations(Boolean childSkip) +0x26
Ranorex.Core.Testing.TestCaseNode.RunInternal(Boolean childSkip) +0x68
Ranorex.Core.Testing.TestCaseNode.Run(DataContext parentDataContext,Boolean childSkip) +0x0
Ranorex.Core.Testing.TestSuite.Run(String runConfigName,String runLabel,Dictionary`2 parameters) +0x145
Ranorex.Core.Testing.TestSuiteRunner.TryRunTestSuite(RunParams rp,TestSuite testSuite) +0x128
Ranorex.Core.Testing.TestSuiteRunner+<>c__DisplayClass13_1.<RunInternal>b__5() +0x11
Ranorex.Common.Types.OptCombinators.UnwrapOrElse(Opt`1 self,Func`1 generator) +0xa
Ranorex.Core.Testing.TestSuiteRunner.RunInternal(Type containerType,String[] testSuiteXmls,RunParams[] rps) +0x768
Ranorex.Core.Testing.TestSuiteRunner.RunInternal(Type containerType,String[] testSuiteXmls,RunParams rp) +0xc
Ranorex.Core.Testing.TestSuiteRunner.RunInternal(Type containerType,String testSuiteXml,RunParams rp) +0x0
Ranorex.Core.Testing.TestSuiteRunner.Run(Type containerType,String cmdLineArgs,String testSuiteXml) +0x14c
Ranorex.Core.Testing.TestSuiteRunner.Run(Type containerType,String cmdLineArgs) +0x3
MyRealTest.Program.Main(String[] args) c:\TeamCity\buildAgent\work\ea2ea9f02f1842f\src\Tests\MyRealTest\Program.cs:line 39;17
System.RuntimeMethodHandle.InvokeMethod(Object target,Object[] arguments,Signature sig,Boolean constructor) +0xffffffff
System.Reflection.RuntimeMethodInfo.UnsafeInvokeInternal(Object obj,Object[] parameters,Object[] arguments) +0x16
System.Reflection.RuntimeMethodInfo.Invoke(Object obj,BindingFlags invokeAttr,Binder binder,Object[] parameters,CultureInfo culture) +0x7a
Ranorex.Core.Resolver.MainInvoker.Invoke(Assembly callerAssembly,String startUpObject,String[] args) +0x5a
__RxMain.__RxProgram.Main(String[] args) c:\TeamCity\buildAgent\work\ea2ea9f02f1842f\src\Tests\MyRealTest\obj\x86\Debug\__RxPrograms.g.cs:line 32;17

[codefile] c:\TeamCity\buildAgent\work\ea2ea9f02f1842f\src\Tests\MyRealTest\StartAUT.cs
[itemindex] 15
---------------------------------------------------------------------------------------------------------------------------------------------------------
---[Error] Failed to wait for item to exist.<br/>Invocation did not finish within the timeout of '00:00:05'.---
[stacktrace] at Ranorex.Core.Repository.RepoItemInfo.WaitForExists(Duration waitTimeout)
at MyRealTest.StartAUT.Ranorex.Core.Testing.ITestModule.Run() in c:\TeamCity\buildAgent\work\ea2ea9f02f1842f\src\Tests\MyRealTest\StartAUT.cs:line 153
at Ranorex.Core.Testing.TestModuleLeaf.RunInternal(DataContext parentDataContext, Int32 iteration, Int32 iterationCount, Boolean skipIteration)
[codefile] c:\TeamCity\buildAgent\work\ea2ea9f02f1842f\src\Tests\MyRealTest\StartAUT.cs
[itemindex] 15

[Support Team]

Hi rmathena,

Try increasing the adapter.functionexecutiontimeout in the solution settings file. This settings is designed to help catch a non-responding/crashed AUT, but in your application, 5 seconds (the default value) may be to short and the application responds shortly after this. While this feature cannot be disabled, you can set it to a much higher value to avoid it from causing this exception (e.g. 60000ms).

1.png (15.72 KiB) Viewed 1109 times

Hope this helps!

Cheers,
Ned

[BCTest]

Hi,

it's strange, because we still get this behaviuor after changing the settings from 5000ms to 120000ms.
Our solution was created with Ranorex 5.3 so we don't have a "Solution items"-folder in the Projects View - should we add it manually?
But we have a "Ranorex.rxsettings" file in the same location as the project-solution-file (*.rxsln). So we changed the value for "adapter.functionexecutiontimeout" and the test still fails after only 5 seconds of waiting, not 120 seconds as expected. Do we have to copy this file with the executionable binaries or are these values compiled in the binariers?

Sorry for this post, it should be easy to solve but I don't have a clue what's going wrong.

Regards,
BcTest

[Support Team]

Hi BcTest,

Since this is an older solution, you can add a solution settings file by clicking the button pictured below. This will generate it in the solution folder and will be copied to the output folder when the test is built.

1.png (4.68 KiB) Viewed 1029 times

As long as this settings file is in the same folder as the test executable, the settings from it will be used by the test. Otherwise, Ranorex will fallback on the machine settings file (found in %appdata%). If you prefer to only use a machine settings file, you can delete the solution settings file add the adapter.functionexecutiontimeout setting manually to the RanorexConfig#.xml file and it will be used the same as if it were in the solution settings file.

For more information on Ranorex settings, check out this section of our user guide.

I hope this clarifies everything!

Cheers,
Ned

[BCTest]

As long as this settings file is in the same folder as the test executable, the settings from it will be used by the test. Otherwise, Ranorex will fallback on the machine settings file (found in %appdata%).
...
For more information on Ranorex settings, check out this section of our user guide.

I hope this clarifies everything!

Cheers,
Ned

Thanks a lot for the clarification, looks like it works now.

Regards,
BcTest