Mbed-os: Test result is not always reliable (TEST_ASSERT_DOUBLE_WITHIN after a failed test)

Created on 2 Jul 2019 · 14Comments · Source: ARMmbed/mbed-os

Description

In case a test is failed, the status of the following ones is not exact.

For example, I am using UDP test suite for my developments and here are some extracts of the trace :

cmd : 
    mbed test -t IAR -m NUCLEO_H743ZI -v -n tests*netsocket*udp* --profile=tools/profiles/debug.json

trace :
    ...
    [1562057575.13][CONN][RXD] >>> Running case #17: 'UDPSOCKET_ECHOTEST_BURST_NONBLOCK'...
    ...
    mbedgt: :232::FAIL: Values Not Within Delta 6 Expected 20 Was 0
    [1562057576.18][CONN][RXD] :232::FAIL: Values Not Within Delta 6 Expected 20 Was 0
    [1562057576.25][CONN][INF] found KV pair in stream: {{__testcase_finish;UDPSOCKET_ECHOTEST_BURST_NONBLOCK;0;1}}, queued...
    [1562057576.34][CONN][RXD] >>> 'UDPSOCKET_ECHOTEST_BURST_NONBLOCK': 0 passed, 1 failed with reason 'Test Cases Failed'
    ...
    [1562057576.61][CONN][RXD] >>> Running case #19: 'UDPSOCKET_ECHOTEST'...
    [1562057576.64][CONN][INF] found KV pair in stream: {{__testcase_start;UDPSOCKET_ECHOTEST}}, queued...
    [1562057577.67][CONN][RXD] Packets sent: 22, packets received 0, loss ratio 1.00
    [1562057577.72][CONN][INF] found KV pair in stream: {{__testcase_finish;UDPSOCKET_ECHOTEST;1;0}}, queued...
    [1562057577.77][CONN][RXD] >>> 'UDPSOCKET_ECHOTEST': 1 passed, 0 failed
    ...
    mbedgt: test case report:
    | target            | platform_name | test suite          | test case                         | passed | failed | result | elapsed_time (sec) |
    |-------------------|---------------|---------------------|-----------------------------------|--------|--------|--------|--------------------|
    | NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_BIND_ADDRESS            | 1      | 0      | OK     | 0.06               |
    | NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_BIND_ADDRESS_INVALID    | 1      | 0      | OK     | 0.06               |
    | NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_BIND_ADDRESS_NULL       | 1      | 0      | OK     | 0.05               |
    | NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_BIND_ADDRESS_PORT       | 1      | 0      | OK     | 0.05               |
    | NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_BIND_PORT               | 1      | 0      | OK     | 0.05               |
    | NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_BIND_PORT_FAIL          | 1      | 0      | OK     | 0.06               |
    | NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_BIND_UNOPENED           | 1      | 0      | OK     | 0.06               |
    | NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_BIND_WRONG_TYPE         | 1      | 0      | OK     | 0.06               |
    | NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_ECHOTEST                | 1      | 0      | OK     | 1.08               |
    | NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_ECHOTEST_BURST          | 1      | 0      | OK     | 1.72               |
    | NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_ECHOTEST_BURST_NONBLOCK | 0      | 1      | FAIL   | 1.07               |
    | NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_ECHOTEST_NONBLOCK       | 0      | 1      | FAIL   | 1.11               |
    | NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_OPEN_CLOSE_REPEAT       | 1      | 0      | OK     | 0.06               |
    | NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_OPEN_DESTRUCT           | 1      | 0      | OK     | 0.05               |
    | NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_OPEN_LIMIT              | 1      | 0      | OK     | 0.22               |
    | NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_OPEN_TWICE              | 1      | 0      | OK     | 0.05               |
    | NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_RECV_TIMEOUT            | 1      | 0      | OK     | 0.17               |
    | NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_SENDTO_INVALID          | 1      | 0      | OK     | 0.05               |
    | NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_SENDTO_REPEAT           | 1      | 0      | OK     | 0.06               |
    | NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_SENDTO_TIMEOUT          | 1      | 0      | OK     | 0.12               |

Here, test 17 is failed (normal in my case). Then, if we look at details of test 19, it is also failed, whereas it is not the case in the final summary.

Problem is coming from TEST_ASSERT_DOUBLE_WITHIN. In this function, we don't perform the test if a previous failed has been detected. In this case, it would be better to mark test as skipped ? (or keep the real result, ie failed)

Regards

Issue request type

[ ] Question
[ ] Enhancement
[x] Bug

CLOSED mirrored bug

Source

VVESTM

Most helpful comment

Now, the PR is available and all tests are passed. So, even if you take this PR, you won't reproduce the issue.

If we can't reproduce this, we can't fix it neither. If this is not an issue anymore, we shall close it. Or find a way how to reproduce. It might be reopened later if this issue comes back.

0xc0170 on 21 Aug 2019

👍2

All 14 comments

@SeppoTakalo @0xc0170

[1562057576.61][CONN][RXD] >>> Running case #19: 'UDPSOCKET_ECHOTEST'... [1562057577.67][CONN][RXD] Packets sent: 22, packets received 0, loss ratio 1.00

0 received packet, and:

| NUCLEO_H743ZI-IAR | NUCLEO_H743ZI | tests-netsocket-udp | UDPSOCKET_ECHOTEST | 1 | 0 | OK | 1.08 |

jeromecoutant on 2 Jul 2019

Internal Jira reference: https://jira.arm.com/browse/MBOCUSTRIA-1372

ciarmcom on 2 Jul 2019

cc @ARMmbed/mbed-os-ipcore

0xc0170 on 2 Jul 2019

@VVESTM , @jeromecoutant , thanks for pointing this out!

I don't think the root cause is that TEST_ASSERT_DOUBLE_WITHIN does not fail if the previous test failed. Looking at the code it will only skip testing if the current test is marked as failed. I checked that this flag gets cleared on test teardown.
Furthermore, I could not reproduce the issue on my end. I admit I don't have the NUCLEO_H743ZI board, but I checked K66F with IAR and ARM compilers and always got the test failure right (I hacked the loss ratio to be 1.0 in the two tests, no matter if the packets arrive or not):

[1564576289.70][CONN][RXD] >>> Running case #17: 'UDPSOCKET_ECHOTEST_BURST_NONBLOCK'...
[1564576289.76][CONN][INF] found KV pair in stream: {{__testcase_start;UDPSOCKET_ECHOTEST_BURST_NONBLOCK}}, queued...
[1564576290.69][CONN][RXD] Packets sent: 100, packets received 100, loss ratio 1.00
mbedgt: :230::FAIL: Values Not Within Delta
[1564576290.74][CONN][RXD] :230::FAIL: Values Not Within Delta
[1564576290.80][CONN][INF] found KV pair in stream: {{__testcase_finish;UDPSOCKET_ECHOTEST_BURST_NONBLOCK;0;1}}, queued...
[1564576290.89][CONN][RXD] >>> 'UDPSOCKET_ECHOTEST_BURST_NONBLOCK': 0 passed, 1 failed with reason 'Test Cases Failed'

...

1564576291.17][CONN][RXD] >>> Running case #19: 'UDPSOCKET_ECHOTEST'...
[1564576291.21][CONN][INF] found KV pair in stream: {{__testcase_start;UDPSOCKET_ECHOTEST}}, queued...
[1564576292.25][CONN][RXD] Packets sent: 22, packets received 22, loss ratio 1.00
mbedgt: :108::FAIL: Values Not Within Delta
[1564576292.28][CONN][RXD] :108::FAIL: Values Not Within Delta
[1564576292.34][CONN][INF] found KV pair in stream: {{__testcase_finish;UDPSOCKET_ECHOTEST;0;1}}, queued...
[1564576292.41][CONN][RXD] >>> 'UDPSOCKET_ECHOTEST': 0 passed, 1 failed with reason 'Test Cases Failed'

...

        test case: 'UDPSOCKET_ECHOTEST' .............................................................. FAIL in 1.13 sec
        test case: 'UDPSOCKET_ECHOTEST_BURST' ........................................................ OK in 1.02 sec
        test case: 'UDPSOCKET_ECHOTEST_BURST_NONBLOCK' ............................................... FAIL in 1.04 sec
...
mbedgt: test case summary: 18 passes, 2 failures

Have you ever managed to reproduce the failure on any other platform than NUCLEO_H743ZI?

michalpasztamobica on 31 Jul 2019

Have you ever managed to reproduce the failure on any other platform than NUCLEO_H743ZI?

Netsocket tests are OK (or we think it is...) with other targets.
We are currently implementing netsocket feature for H7

jeromecoutant on 19 Aug 2019

Does PR https://github.com/ARMmbed/mbed-os/pull/11274 relate in any way?
It seems to say that the tests are passing for this platform.
What is the current reproducibility of this issue?

michalpasztamobica on 21 Aug 2019

I faced this issue while doing my developments for PR #11274.
Now, the PR is available and all tests are passed. So, even if you take this PR, you won't reproduce the issue.
I don't understand why it is working on K66F board, I don't see any board specific code in the tests.

VVESTM on 21 Aug 2019

@VVESTM , if this was a one-off error and cannot be reproduced any more, then I'd suggest to close the issue.

michalpasztamobica on 21 Aug 2019

No...
If you can not trust the OK result, we can't trust CI test any more

jeromecoutant on 21 Aug 2019

@ARMmbed/mbed-os-tools

jeromecoutant on 21 Aug 2019

Now, the PR is available and all tests are passed. So, even if you take this PR, you won't reproduce the issue.

If we can't reproduce this, we can't fix it neither. If this is not an issue anymore, we shall close it. Or find a way how to reproduce. It might be reopened later if this issue comes back.

0xc0170 on 21 Aug 2019

👍2

With this commit, I can reproduce the issue :
https://github.com/VVESTM/mbed-os/commit/f7b9b226cdd69d68dbb4d6beee95376af8804d9c

Reproduced with K64F board :
mbed test -t IAR -m K64F -v -n tests*netsocket*udp*

VVESTM on 21 Aug 2019

@VVESTM , thanks for the commit.
I confirm, with the two lines changed the suite acts weird - UDPSOCKET_ECHOTEST reports a pass, while it should fail.
I think the ticket should be reopened.

michalpasztamobica on 21 Aug 2019

🎉1

@VVESTM nice !

@michalpasztamobica fix right-away 💯

0xc0170 on 22 Aug 2019

Was this page helpful?

0 / 5 - 0 ratings