Get stepRun.TestStepPath in ResultListener

For our big test plan, we have many steps that have similar names. I would like to include the whole tree to our report so we can easily determine of which sub-test plan the test step was part of.

In the Log output I see that teststeps report the full path every time they start, and in the source code I see they use the variable: stepRun.TestStepPath for that. In the result listener, this field however is not available.

So to be clear: In my result listener, for following test step, I would like to acquire the full name EOL-CLS-02 Status / Get Status instead of just Get Status.

How do I do that?

1 Like

Hi @andries, I don’t know of a built-in way to do that. I agree the steps full parent hierarchy would be useful info to have in the result listener.

I suppose there’s a clean and dirty way to do this. The clean way would be to develop this in OpenTAP, probably by adding the desired info as a property to the TestStepRun class.

A dirty way would be:

  1. From the OnTestPlanRunStart method, use reflection to get the TestPlan instance, like so:

TestPlan testPlan = planRun.GetTestPlan();

public static class TestPlanExtensions
{
        private static FieldInfo testPlanFieldInfo = typeof(TestPlanRun).GetField("plan", BindingFlags.NonPublic | BindingFlags.Instance);

        public static TestPlan GetTestPlan(this TestPlanRun planRun)
        {
            if (planRun == null) return null;

            TestPlan testPlan = testPlanFieldInfo.GetValue(planRun) as TestPlan;

            return testPlan;
        }
}
  1. From the OnTestStepRunCompleted method, get the test step like so:
    ITestStep testStep = testPlan.ChildTestSteps.GetStep(stepRun.TestStepId)

Once you’ve got the test step, you can determine its full parent hierarchy. I haven’t actually tried this yet, but I think something like this could work.

2 Likes

This is already possible from the ResultListener API - all the information is available there.

Maybe this should be a part of the examples - this is a pattern I often use when developing a ResultListener:

class TracksActiveRunsResultListener : ResultListener
{
    // OnTestStepRunStart/Completed are guaranteed to be called sequentially. child Start/Completed are executed between parent step Start/Completed.
    // So we can build a tree of active steps in a dictionary and use the step run GUIDs as keys.
    // Dont use the test step ID as keys as the same step can be run multiple times in parallel.
    readonly Dictionary<Guid, TestStepRun> activeSteps = new Dictionary<Guid, TestStepRun>();
    public override void OnTestStepRunStart(TestStepRun stepRun)
    {
        activeSteps.Add(stepRun.Id, stepRun);
        // use this full path
        var fullPath = BuildFullPathString(stepRun);
    }

    string BuildFullPathString(TestStepRun run)
    {
        if (activeSteps.TryGetValue(run.Parent, out var parentRun))
            // use / as separator between the test step run names.
            return BuildFullPathString(parentRun) + " / " + run.TestStepName;
        return run.TestStepName;
    }

    public override void OnTestStepRunCompleted(TestStepRun stepRun)
    {
        activeSteps.Remove(stepRun.Id);
    }
}

3 Likes

Thank you @rolf_madsen for the response.
This indeed gives me the full step name, including parents, however, when the parent steps use a parametrized name (using the {} notation), this does not reflect back in the TestStepRun.SestStepName field.

For example, I log the full name at the start of each step, per the script that you supplied, like this:

        public override void OnTestStepRunStart(TestStepRun stepRun)
        {
            activeSteps.Add(stepRun.Id, stepRun);
            Log.Debug($"*** Started {GetFullPathString(stepRun)} ***");
        }

        // returns a full path of the test step, including
        // any parents, seperated by a '/'
        string GetFullPathString(TestStepRun run)
        {
            if (activeSteps.TryGetValue(run.Parent, out var parentRun))
            {
                return GetFullPathString(parentRun) + " / " + run.TestStepName;
            }
            else
            {
                return run.TestStepName;
            }
        }

and I get the following output:

You can see here that the full name of the child step Math for example, shows Sweep 3 / Math 1, even though OpenTap just indicated the correct name, Sweep 1 / Math 1.

What is going on here?

What is going on is that the name is saved at the time of the result (step start/completed) being recorded. In this case it is probably 3 because that was the state when the test plan started.

This problem is also seen in the run summary in your screenshot.

------ Summary of test plan started 09/06/2022 16:00:44 ------
 Sweep Range Time Delay 0.1 s                       4.53 s          
   Delay                                            1.01 s          
   Delay                                            1.50 s          
   Delay                                            2.00 s          
--------------------------------------------------------------

The question I guess is what is the alternative? Should it instead write “Sweep Range {Parameters} {Time Delay}”? That’d be more correct but much less useful in general.

Also in general we don’t really know when a parameter value changes.

Suggestions are welcome. :slight_smile:

For me the expected behavior of TestStepRun.TestStepName would be the fully expanded name, with the variables corresponding to the actual state at that moment. (So if the sweepParameter at that moment is 2 and the name is Sweep {sweepParameter}, you’d expect to get back Sweep 2 no?

I understand that in the test report at the end this is not possible, and you’d probably get the last value of sweepParameter as the name, but also that is kind of ‘true’, as it is the value of that parameter at that time. Now it just caches whatever it was at the last run, which I think it not the expected behavior…

Hi @rolf_madsen, that’s a cool approach. But I’m also a bit confused. If run.TestStepName gets set at the time of the result being recorded, then shouldn’t it contain all the expected dynamic {} values?

Ok, I understand. I might have been a bit too lazy in my explaination.

Mostly importantly, the results processesing happens completely out-of-band to avoid affecting test plan performance. So, if you have very quick steps, generating lots of data and slow result listeners, the actual test plan execution might be far ahead of the result processing. Result processing might still cause a bottleneck in some situations, but mostly it turns out great because most test step generates different amounts of data, so the result processing gets time to catch up later. (Note, we only allow the estimated time to process to reach a few seconds)

This fact also means that when you read information from the test plan using reflection, that information might be out of sync with what actually happened when the start/completed/result event actually occured.

So this means that result listenrs can only safely receive information through those events. When you get the name of the parent step, it is only when TestStepRunStart or Completed for that parent step.

For sweeps in particular, it goes through multiple parameter values, but the information about the name only gets propagated to result listeners at the start and completed events.

So at the moment, Using {} for the sweept value on the sweep step does not give the best experience and I dont know how we can inprove that without negatively affecting other aspects. However, you can still set the {} on the child step name to record the value correctly.

I hope this makes more sense :slight_smile:

1 Like

Thanks for the explanation @rolf_madsen, and also pointing out that my proposed reflection approach can also produce incorrect names.

I’m realizing I’ve got the same step-name/result-listener problem as @andries, I just never noticed it :laughing:

It seems one bulletproof way to get the correct step name in a result listener would be to publish the name as a result within the result table. Seems a bit roundabout though. Any other ideas?

The simplest is probably to add a sequence step in between. Lets call it ‘iteration’:

------- Summary of test plan started 09/06/2022 22:47:50 -------
 Sweep Range Time Delay                               6.02 s          
   Iteration 1 s                                      1.01 s          
     Delay                                            1.00 s          
   Iteration 1.3333 s                       1.33 s          
     Delay                                            1.33 s          
   Iteration 1.666 s                       1.66 s          
     Delay                                            1.66 s          
   Iteration 2 s                                      2.00 s          
     Delay                                            2.00 s          
----------------------------------------------------------------
---------- Test plan completed successfully in 6.05 s ----------

Otherwise, I want to try letting Sweep call run itself when doing each iteration, but that might have some unintended side effects.

That’s my ieads for now.

I’ll try that work around. How to get the Sweep parameter into the name of the Sequence then?

Then you just need to first parameterize it unto the sequence step and then unto the sweep step. Then you can use the name of the parameter in the name.

Thank you, I managed to insert a sequence and get the information I need in the results.

In using it, I must say it is really a big miss that a sweep cannot show/output its own current variable. It is quite essential in reporting to be able to show on which parameters a test was performed, and currently this is not possible except the Sequence workaround. Feature request!

2 Likes

Thanks @andries . I’ve documented this request here:

1 Like

Another interesting thing I ran into, regarding this showing the sweep parameters in the sweep step name, just a use case to take into account in this ‘issue’:

we sweep over a parameter (output channel of a DIO box) that is an enum (DIn0, DIn1, DIn2, DIn3), yet we want to show in the test step not the actual name of the output channel, but the marker index (1, 2, 3, 4). So we sweep over both parameters to create this ‘mapping’ (see image).

image

In this case we cannot use the Sequence workaround directly, as the MarkerIdx is not actually used by any child test steps, and can therefore not be parametrized on the parent Sequence! To work around this, I added a step that uses the parameter but actually does nothing (adding a 0 to the MarkerIdx), just to be able to parametrize it on its parent, and therefore show it in the sweep.

Just my 2 cents, over here we don’t rely on test names to store critical info like what test settings were run. Instead, we publish all settings along with results (using ResultSource.Publish). So although our test names have the same problem that you’ve reported, it’s not a very critical issue for us (which is probably why we’ve never noticed it before).

1 Like