Output Time in exported results. Clean res:// from path. #581

plink-plonk-will · 2024-03-21T08:53:08Z

I made the changes in a fork to better work with this GitHub test reporter: https://github.com/dorny/test-reporter

Removed "res://" from reported file paths. This enables you to click on a report in the above tool and take you to the change in Github that caused the failure.
Reporting Time taken for each test. This fills in the time column in the above tool instead of reporting "null".
There was a formatting change in collected_test.gd where it was using spaces instead of tabs.

Output from the test-reporter tool with the changes:

I'm more than happy to split into different PRs or remove bits that aren't interesting to keep (and of course understand if it's not something wanted at all 😄).

bitwes

Thanks for the PR, these are great quality-of-life improvements for the export.

In addition to the one tiny change that I just had to have, I'd like to have some tests added for this.

Writing tests for the export is a little gross and are more integration tests than unit tests. It involves creating a GUT instance and giving it scripts (located in test/resources/exporter_test_files) to be run, then examining the results. If the existing tests aren't enough to figure it all out, let me know.

test/unit/test_result_exporter.gd

Add test to verify that the "time" field is included for tests
Add a test script to test/resources/exporter_test_files that contains some tests that use await wait_seconds(x) and then add tests to test_result_exporter.gd that run those tests and assert that the time field is being filled in properly. You will probably have to use assert_almost_eq (or assert_between if you like that better) on the expected value as there is some wiggle room with await.

test/unit/test_junit_xml_export.gd

OPTIONAL

(There aren't as many tests for the xml export as I would like. These tests are harder to write since Godot doesn't provide a feature rich XML parser and I didn't write one because GUT doesn't have to read XML, only write it.

It feels a bit hypocritical to requests the kinds of tests that I didn't make originally. Though, as the repo owner, it is my right to sometimes be hypocritical, heh.)

Add a test that verifies that "res" is being removed. This can just be verifying that you cannot find "res://test/resources/exporter_test_files/whatever_script_was_run" but can find "/resources/exporter_test_files/whatever_script_was_run" in the result xml text.
(even more optional) Verify the time field is included where it should be. This could be gross to do, but if you find an easy enough way it will give me template to add in more tests for fields later.

bitwes · 2024-04-22T18:07:34Z

addons/gut/gut.gd

+				var us_elapsed = Time.get_ticks_usec() - ticks_before
+				_current_test.time_taken = us_elapsed / 1000000.0


Wasn't sure what us_elapsed meant at first. Just make this a single line.

_current_test.time_taken = (Time.get_ticks_usec() - us_elapsed) / 1000000.0

Then there's the dumb debate going on in my head as to whether the division should actually happen when making the xml and usecs should actually be stored in time_taken. Doing the division here is fine, but it does feel a bit "wrong". Having it as a single line somehow makes it less "wrong". It's fine. Right? Yea, it's fine. I've already wasted more time thinking about this incredibly minor detail and I'm moving on.

I don't know if this helps with the quandary, but the schema here has the time output in seconds: https://github.com/windyroad/JUnit-Schema/blob/master/JUnit.xsd
Although I do understand the issue with that, and source of the quandary.

But thank you so much for the detailed comments. I'll make this change and add the tests 😄

Yea, I agree the time should go into the XML as seconds. For some reason I want to do the conversion to seconds when the XML is being created, and storing microseconds in time_taken. It's easier to test if we store seconds though, since we can test for that much easier in test_result_exporter.gd than testing the resulting XML.

It's just one of those minor details that my brain wants to overthink. Storing seconds is the right answer.

I've added the time taken tests now. I haven't looked at the XML verification yet. Finding a more accurate way of getting the time was tricky - the standard await x.timeout approaches are incredibly inaccurate at small values. I added this in the test_time_taken.gd resource test script to compensate for it. It still logs the wait time to the logger like await wait_seconds.

func more_accurate_wait_time(time_to_wait_msec : int)->void: gut._lgr.yield_msg(str('-- Awaiting ', time_to_wait_msec / 1000.0, ' second(s) -- ')) var start := Time.get_ticks_msec() while (Time.get_ticks_msec() - start < time_to_wait_msec): await get_tree().process_frame func test_pass_time_taken_about_half_s(): await more_accurate_wait_time(500) assert_eq('one', 'one')

In cc27eec I modified the xml validator to also checks for valid tags and attributes. It doesn't check for valid nesting / structure - just that the tags that are encountered are expected, and that those tags contain only the required attributes for that tag.

bitwes

Great work. I cloned your branch and made the tests fail by commenting out your additions or adding things that the xml export wasn't expecting. Everything acted the way I'd expect. I've requested a little more detail in assert messages, and some other minor changes. This will be ready to be merged after that.

bitwes · 2024-05-09T18:19:12Z

test/unit/test_junit_xml_export.gd

+				# check for required attributes
+				var required_attributes : Array = RESULT_XML_VALID_TAGS[tag_name].duplicate()
+				var missing_attributes := required_attributes.filter(func(attribute): return !parser.has_attribute(attribute))
+				assert_eq(missing_attributes, [], "Required attribute(s) missing.")


Change this to the following so the failure message has more details:

assert_eq(missing_attributes, [], str(tag_name, ": Required attribute(s) missing ", missing_attributes))

bitwes · 2024-05-09T18:20:49Z

test/unit/test_junit_xml_export.gd

+					var attribute_name := parser.get_attribute_name(attribute_index)
+					if not attribute_name in RESULT_XML_VALID_TAGS[tag_name]:
+						unexpected_attributes.push_back(attribute_name)
+				assert_eq(unexpected_attributes, [], "Unexpected attribute(s).")


Change this to the following so the failure message has more details:

assert_eq(unexpected_attributes, [], str(tag_name, " Unexpected attribute(s) ", unexpected_attributes))

bitwes · 2024-05-09T18:23:30Z

test/unit/test_result_exporter.gd

+	assert_has(result, 'test_fail_time_taken_about_half_s')
+	assert_has(result, 'test_pending_time_taken_about_half_s')
+	assert_has(result, 'test_pass_time_taken_about_2s')
+	const TIME_ERROR_INTERVAL := 0.01


Change this value to 0.1. I had the tests fail once because it was just outside of the range. There are too many variables in how long it takes to run stuff, so .1 should be enough to know it is working.

bitwes · 2024-05-09T18:33:44Z

test/unit/test_result_exporter.gd

+	assert_has(result, 'tests')
+	result = result.tests
+	assert_has(result, 'test_pass_time_taken_about_half_s')
+	assert_has(result, 'test_fail_time_taken_about_half_s')
+	assert_has(result, 'test_pending_time_taken_about_half_s')
+	assert_has(result, 'test_pass_time_taken_about_2s')


Remove these lines. Earlier tests verify that tests show up in the results where we expect them. If this part fails then earlier tests will either fail or crash. Removing these also makes the scope of the test more clear.

bitwes

That does it, thatnks.

plink-plonk-will · 2024-05-10T16:13:25Z

Awesome! Thank you!

plink-plonk-will added 5 commits March 12, 2024 12:49

Export the time it took to execute the test

33dd77a

Add time for testsuite as well

56977aa

Make time in seconds

ec3c1da

Merge branch 'main' of github.com:plink-plonk-will/gut

f71699a

Remove res from filenames

7bfe341

bitwes requested changes Apr 22, 2024

View reviewed changes

plink-plonk-will added 3 commits May 1, 2024 06:44

remove intermediate us_elapsed variable

55d4d4c

Time taken tests

570e221

Additional validation for correctly formed results xml

cc27eec

plink-plonk-will requested a review from bitwes May 9, 2024 09:25

bitwes requested changes May 9, 2024

View reviewed changes

plink-plonk-will added 2 commits May 10, 2024 09:51

More detailed assert messages

812c2a4

Remove unnecessary asserts and make time error interval more forgiving.

d549d09

plink-plonk-will requested a review from bitwes May 10, 2024 07:53

bitwes approved these changes May 10, 2024

View reviewed changes

bitwes merged commit 1ac05f1 into bitwes:main May 10, 2024

		var us_elapsed = Time.get_ticks_usec() - ticks_before
		_current_test.time_taken = us_elapsed / 1000000.0

Output Time in exported results. Clean res:// from path. #581

Output Time in exported results. Clean res:// from path. #581

Uh oh!

Conversation

plink-plonk-will commented Mar 21, 2024

Uh oh!

bitwes left a comment

Choose a reason for hiding this comment

test/unit/test_result_exporter.gd

test/unit/test_junit_xml_export.gd

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

bitwes left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

bitwes left a comment

Choose a reason for hiding this comment

Uh oh!

plink-plonk-will commented May 10, 2024

Uh oh!

Uh oh!