Writing to executionContext.Manager.Log in OnInitializeDataSource

[Todd]

I followed the instructions at https://docs.telerik.com/teststudio/advanced-topics/coded-samples/general/execution-extensions and I am successfully getting and using a dynamic dataset from the method OnInitializeDataSource. My problem is that output written to executionContext.Manager.Log is not presenting in the log file. The log file is:

Overall Result: Pass
------------------------------------------------------------
'9/30/2022 10:47:21 AM' - Executing test: 'WebTest1', path: '_POC\WebTest1.tstest.'
'9/30/2022 10:47:21 AM' - Using .Net Runtime version: '4.0.30319.42000' for test execution. Build version is '2022.3.914.3'.
'9/30/2022 10:47:21 AM' - Starting execution....
'9/30/2022 10:47:25 AM' - Detected custom code in test. Locating test assembly: TestProject1.dll.
'9/30/2022 10:47:25 AM' - Assembly Found: D:\TelerikTestStudio\VNAV_Playground\bin\TestProject1.dll
'9/30/2022 10:47:25 AM' - Loading code class: 'TestProject1.WebTest1'.
------------------------------------------------------------
------------------------------------------------------------
'9/30/2022 10:47:25 AM' - Detected DataDriven Test. Starting data iterations.
------------------------------------------------------------
'9/30/2022 10:47:25 AM' - [Iteration #1: (ENV=Env2)(TEST_ITERATION=1)(VNAV_ID=V00000001)]
------------------------------------------------------------
Overall Result: Pass
------------------------------------------------------------
'9/30/2022 10:47:25 AM' - LOG: Executing VrsExecutionExtension: OnBeforeTestStarted
'9/30/2022 10:47:25 AM' - Using 'EdgeChromiumHeadless' version '105.0.1343.53' as default browser. 
'9/30/2022 10:47:25 AM' - Using Telerik Components Version: 'Latest'
'9/30/2022 10:47:25 AM' - Using 'https://xxx/xxxx' as base url.
'9/30/2022 10:47:25 AM' - LOG: ********** This is my test code ********
'9/30/2022 10:47:25 AM' - 'Pass' : 1. New Coded Step
------------------------------------------------------------
'9/30/2022 10:47:25 AM' - Overall Result: Pass
'9/30/2022 10:47:25 AM' - Duration: [0 min: 0 sec: 19 msec]
------------------------------------------------------------
'9/30/2022 10:47:25 AM' - LOG: Executing VrsExecutionExtension: OnAfterTestCompleted
------------------------------------------------------------
'9/30/2022 10:47:25 AM' - Overall Result: Pass
'9/30/2022 10:47:25 AM' - Duration: [0 min: 0 sec: 22 msec]
------------------------------------------------------------
'9/30/2022 10:47:26 AM' - Test completed!

My class is:

	public class ExecutionExtension : IExecutionExtension
	{
		public void OnAfterTestCompleted(ExecutionContext executionContext, TestResult result)
		{
			executionContext.Manager.Log.WriteLine($"Executing {nameof(VrsExecutionExtension)}: {nameof(OnAfterTestCompleted)}");
		}

		public void OnAfterTestListCompleted(RunResult result)
		{
		}
		public void OnBeforeTestListStarted(TestList list)
		{
		}

		public void OnBeforeTestStarted(ExecutionContext executionContext, Test test)
		{
			executionContext.Manager.Log.WriteLine($"Executing {nameof(VrsExecutionExtension)}: {nameof(OnBeforeTestStarted)}");
		}

		public DataTable OnInitializeDataSource(ExecutionContext executionContext)
		{
			executionContext.Manager.Log.WriteLine($"Executing {nameof(VrsExecutionExtension)}: {nameof(OnInitializeDataSource)}");

			DataTable dt = null;

			... // code excluded but is successfully populating and returning dt

			return dt;

		}

		public void OnStepFailure(ExecutionContext executionContext, AutomationStepResult stepResult)
		{
			executionContext.Manager.Log.WriteLine($"Executing {nameof(VrsExecutionExtension)}: {nameof(OnStepFailure)}");
		}
	}

In the log, I can see that OnBeforeTestStarted and OnAfterTestCompleted successfully write to the test log, but OnInitializeDataSource does not. Any thoughts on what I might be missing here?

On a somewhat unrelated note, it appears that the name of the DLL created as part of this project has to match some specification. This was not apparent to me while following the instructions at https://docs.telerik.com/teststudio/advanced-topics/coded-samples/general/execution-extensions. Naming the DLL ClassLibrary, ClassLibrary1, or ClassLibrary2 all appeared to work. Naming it ExecutionExtension.dll did not. If there is a requirement, noting it on the coded-samples page might prove helpful for anyone else stumbling their way through this for the first time.

Thank you.

[Plamen Mitrev]

Hello Todd,

Thank you for your details message and for starting this discussion. 

The execution log is created when the test is being prepared to start and it includes the actions and logs from OnBeforeTestStarted(), as you have already tested. However, the initialization of data happens before all that and nothing is logged in the execution log, because it is not yet created. So, it is expected that the logged actions do not show up in the test's execution log.

You can find the logged information in the Test Studio application log file and in the log files that the Test List execution creates (by default in C:\WebAiiLog). I tested it on my end and was able to see the test messages in both places. Please try it on your end and let me know what is the outcome. 

I also tried to rename the DLL exactly ExecutionExtension.dll and put it in the Plugins folder. I did not notice any issues there. Maybe there are errors in the Test Studio application log, or there are more than one execution extension DLLs in the Plugins folder.

If you continue to experience any troubles, share the Test Studio project and the VS project for the execution extension for further investigation. You can also send me the Test Studio application log from your test run.

Regards,
Plamen Mitrev
Progress Telerik

[Todd]

Thanks for pointing me in the right direction to find the logged output from OnInitializeDataSource. It is indeed where you indicated it would be.

Regarding the naming of the DLL, thank you for confirming we should be able to name it however we would like. Once we establish how we want to name and structure all of this, I will return to trying to get something other than classlibrary*.dll to work and open a new thread should I run into issues.

[Plamen Mitrev]

Hi Todd, I am happy to hear that you found the information you needed to review from the execution extension. I remain available to discuss the naming of the DLL, whenever you get back to this in the future. You can write again in this thread, or start a new one with details about your setup.

Have a great start to your week!

[Todd]

Follow up to the DLL naming issue created here:

https://www.telerik.com/forums/name-of-dll-for-iexecutionextension-implementation#1582680

Thank you.