unstable test - tests-mbedmicro-rtos-mbed-queue on NUCLEO_F746ZG #8320

studavekar · 2018-10-03T21:19:01Z

Description

Type: Bug
Priority: Major

This failure are seen on CI environment creating a ticket to track the failure.

>> Running case #5: 'Test get from empty queue timeout'...
[1538599552.64][CONN][INF] found KV pair in stream: {{__testcase_start;Test get from empty queue timeout}}, queued...
[1538599552.94][CONN][RXD] :147::FAIL: Values Not Within Delta 5000 Expected 50000 Was 240386
[1538599553.04][CONN][INF] found KV pair in stream: {{__testcase_finish;Test get from empty queue timeout;0;1}}, queued...
[1538599553.14][CONN][RXD] >>> 'Test get from empty queue timeout': 0 passed, 1 failed with reason 'Assertion Failed'

Target
NUCLEO_F746ZG

Toolchain:
GCC_ARM

[1538599547.58][GLRM][INF] remote resources reset...
[1538599549.76][GLRM][TXD] mbedmbedmbedmbedmbedmbedmbedmbedmbedmbed
[1538599549.76][CONN][INF] sending up to 10 __sync packets (specified with --sync=10)
[1538599549.76][CONN][INF] sending preamble '5a1d51e4-7c48-4789-999f-9a1106939022'
[1538599549.76][GLRM][TXD] {{__sync;5a1d51e4-7c48-4789-999f-9a1106939022}}
[1538599550.94][CONN][RXD] mbedmbedmbedmbedmbedmbedmbedmbed
[1538599550.94][CONN][INF] found SYNC in stream: {{__sync;5a1d51e4-7c48-4789-999f-9a1106939022}} it is #0 sent, queued...
[1538599550.94][CONN][INF] found KV pair in stream: {{__version;1.3.0}}, queued...
[1538599550.94][HTST][INF] sync KV found, uuid=5a1d51e4-7c48-4789-999f-9a1106939022, timestamp=1538599550.940769
[1538599550.94][HTST][INF] DUT greentea-client version: 1.3.0
[1538599551.04][CONN][RXD] >>> Running 13 test cases...
[1538599551.04][CONN][INF] found KV pair in stream: {{__timeout;5}}, queued...
[1538599551.04][CONN][INF] found KV pair in stream: {{__host_test_name;default_auto}}, queued...
[1538599551.04][HTST][INF] setting timeout to: 5 sec
[1538599551.04][HTST][INF] host test class: '<class 'mbed_host_tests.host_tests.default_auto.DefaultAuto'>'
[1538599551.04][HTST][INF] host test setup() call...
[1538599551.04][HTST][INF] CALLBACKs updated
[1538599551.04][HTST][INF] host test detected: default_auto
[1538599551.14][CONN][INF] found KV pair in stream: {{__testcase_name;Test pass uint msg}}, queued...
[1538599551.14][CONN][INF] found KV pair in stream: {{__testcase_name;Test pass uint msg twice}}, queued...
[1538599551.24][CONN][INF] found KV pair in stream: {{__testcase_name;Test pass ptr msg}}, queued...
[1538599551.24][CONN][INF] found KV pair in stream: {{__testcase_name;Test get from empty queue no timeout}}, queued...
[1538599551.34][CONN][INF] found KV pair in stream: {{__testcase_name;Test get from empty queue timeout}}, queued...
[1538599551.34][CONN][INF] found KV pair in stream: {{__testcase_name;Test get empty wait forever}}, queued...
[1538599551.44][CONN][INF] found KV pair in stream: {{__testcase_name;Test put full no timeout}}, queued...
[1538599551.44][CONN][INF] found KV pair in stream: {{__testcase_name;Test put full timeout}}, queued...
[1538599551.54][CONN][INF] found KV pair in stream: {{__testcase_name;Test put full wait forever}}, queued...
[1538599551.54][CONN][INF] found KV pair in stream: {{__testcase_name;Test message ordering}}, queued...
[1538599551.72][CONN][RXD] 
[1538599551.72][CONN][INF] found KV pair in stream: {{__testcase_name;Test message priority}}, queued...
[1538599551.72][CONN][INF] found KV pair in stream: {{__testcase_name;Test queue empty}}, queued...
[1538599551.72][CONN][INF] found KV pair in stream: {{__testcase_name;Test queue full}}, queued...
[1538599551.76][CONN][RXD] >>> Running case #1: 'Test pass uint msg'...
[1538599551.76][CONN][INF] found KV pair in stream: {{__testcase_start;Test pass uint msg}}, queued...
[1538599551.84][CONN][RXD] >>> 'Test pass uint msg': 1 passed, 0 failed
[1538599551.84][CONN][RXD] 
[1538599551.84][CONN][INF] found KV pair in stream: {{__testcase_finish;Test pass uint msg;1;0}}, queued...
[1538599551.94][CONN][RXD] >>> Running case #2: 'Test pass uint msg twice'...
[1538599551.94][CONN][INF] found KV pair in stream: {{__testcase_start;Test pass uint msg twice}}, queued...
[1538599552.04][CONN][RXD] >>> 'Test pass uint msg twice': 1 passed, 0 failed
[1538599552.04][CONN][RXD] 
[1538599552.04][CONN][INF] found KV pair in stream: {{__testcase_finish;Test pass uint msg twice;1;0}}, queued...
[1538599552.14][CONN][RXD] >>> Running case #3: 'Test pass ptr msg'...
[1538599552.14][CONN][INF] found KV pair in stream: {{__testcase_start;Test pass ptr msg}}, queued...
[1538599552.24][CONN][RXD] >>> 'Test pass ptr msg': 1 passed, 0 failed
[1538599552.24][CONN][RXD] 
[1538599552.24][CONN][INF] found KV pair in stream: {{__testcase_finish;Test pass ptr msg;1;0}}, queued...
[1538599552.34][CONN][RXD] >>> Running case #4: 'Test get from empty queue no timeout'...
[1538599552.34][CONN][INF] found KV pair in stream: {{__testcase_start;Test get from empty queue no timeout}}, queued...
[1538599552.44][CONN][INF] found KV pair in stream: {{__testcase_finish;Test get from empty queue no timeout;1;0}}, queued...
[1538599552.54][CONN][RXD] >>> 'Test get from empty queue no timeout': 1 passed, 0 failed
[1538599552.54][CONN][RXD] 
[1538599552.54][CONN][RXD] >>> Running case #5: 'Test get from empty queue timeout'...
[1538599552.64][CONN][INF] found KV pair in stream: {{__testcase_start;Test get from empty queue timeout}}, queued...
[1538599552.94][CONN][RXD] :147::FAIL: Values Not Within Delta 5000 Expected 50000 Was 240386
[1538599553.04][CONN][INF] found KV pair in stream: {{__testcase_finish;Test get from empty queue timeout;0;1}}, queued...
[1538599553.14][CONN][RXD] >>> 'Test get from empty queue timeout': 0 passed, 1 failed with reason 'Assertion Failed'
[1538599553.14][CONN][RXD] 
[1538599553.14][CONN][RXD] >>> Test cases: 4 passed, 1 failed with reason 'Assertion Failed'
[1538599553.24][CONN][RXD] >>> TESTS FAILED!
[1538599553.24][CONN][INF] found KV pair in stream: {{__testcase_summary;4;1}}, queued...
[1538599553.24][CONN][INF] found KV pair in stream: {{max_heap_usage;0}}, queued...
[1538599553.24][CONN][INF] found KV pair in stream: {{reserved_heap;299664}}, queued...
[1538599553.24][HTST][ERR] orphan event in main phase: {{max_heap_usage;0}}, timestamp=1538599553.242464
[1538599553.24][HTST][ERR] orphan event in main phase: {{reserved_heap;299664}}, timestamp=1538599553.242465
[1538599553.34][CONN][INF] found KV pair in stream: {{__thread_info;"0x0200054c4",1076,4096}}, queued...
[1538599553.34][CONN][INF] found KV pair in stream: {{__thread_info;"0x020004dbc",416,512}}, queued...
[1538599553.34][HTST][ERR] orphan event in main phase: {{__thread_info;"0x0200054c4",1076,4096}}, timestamp=1538599553.342601
[1538599553.34][HTST][ERR] orphan event in main phase: {{__thread_info;"0x020004dbc",416,512}}, timestamp=1538599553.342606
[1538599553.44][CONN][RXD] {{__cpu_info        up time;572937}}
[1538599553.44][CONN][RXD] {{__cpu_info     sleep time;48766}}
[1538599553.44][CONN][INF] found KV pair in stream: {{__thread_info;"0x020004d78",104,768}}, queued...
[1538599553.44][HTST][ERR] orphan event in main phase: {{__thread_info;"0x020004d78",104,768}}, timestamp=1538599553.442877
[1538599553.54][CONN][RXD] {{__cpu_info deepsleep time;0}}
[1538599553.54][CONN][RXD] {{__cpu_info  %  sleep/deep;8;0}}
[1538599553.54][CONN][INF] found KV pair in stream: {{end;failure}}, queued...
[1538599553.54][CONN][INF] found KV pair in stream: {{__exit;0}}, queued...
[1538599553.54][HTST][INF] __exit(0)
[1538599553.54][HTST][INF] __notify_complete(False)
[1538599553.54][HTST][INF] __exit_event_queue received
[1538599553.54][HTST][INF] test suite run finished after 2.50 sec...
[1538599553.54][CONN][INF] received special event '__host_test_finished' value='True', finishing
[1538599553.54][urllib3.connectionpool]Starting new HTTP connection (1): austin-ci-linux-001
[1538599553.58][urllib3.connectionpool]http://austin-ci-linux-001:8000 "PUT /resource/081602210D1362123257FB39/disconnect HTTP/1.1" 200 2
[1538599553.58][urllib3.connectionpool]Starting new HTTP connection (1): austin-ci-linux-001
[1538599556.72][urllib3.connectionpool]http://austin-ci-linux-001:8000 "PUT /resource/081602210D1362123257FB39/release HTTP/1.1" 200 42
[1538599556.72][HTST][INF] CONN exited with code: 0
[1538599556.72][HTST][INF] Some events in queue
[1538599556.72][HTST][INF] stopped consuming events
[1538599556.72][HTST][INF] host test result() call skipped, received: False
[1538599556.72][HTST][INF] calling blocking teardown()
[1538599556.72][HTST][INF] teardown() finished
[1538599556.72][HTST][INF] {{result;failure}}

Issue request type

[ ] Question
[ ] Enhancement
[x] Bug

The text was updated successfully, but these errors were encountered:

0xc0170 · 2018-10-04T08:15:28Z

@ARMmbed/team-st-mcd Please review

jeromecoutant · 2018-10-04T11:17:04Z

Hi
I will check the issue after #8242 #7582 #8279 merge into master
Thx

0xc0170 · 2018-10-04T11:44:05Z

I will check the issue after #8242 #7582 #8279 merge into master

Hopefully they will get in soon (8279 needs work).

ciarmcom · 2018-10-29T17:13:35Z

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

jeromecoutant · 2018-11-06T16:50:27Z

Hi
Is this issue still relevant ?
Thx

cmonr · 2018-11-13T22:00:53Z

Fairly sure this issue is still relevant, but it's incredibly hard to reproduce.

elm3 · 2019-01-07T17:12:08Z

All the PR's have been merged...do we think this is fixed?

0xc0170 · 2019-01-08T14:58:15Z

I believe we can close, and if it comes back reopen but shall not!

0xc0170 added the devices: st label Oct 4, 2018

yennster added the component: tests label Oct 10, 2018

ciarmcom added the HEADER NEEDS ACTION label Oct 23, 2018

adbridge removed HEADER FORMATTING ISSUE labels Oct 29, 2018

ARMmbed deleted a comment from ciarmcom Oct 29, 2018

ciarmcom added type: bug Jira status: OPEN labels Oct 29, 2018

ciarmcom added the mirrored label Oct 29, 2018

studavekar mentioned this issue Nov 13, 2018

[DNM] Silly change to test CI #8731

Closed

0xc0170 closed this as completed Jan 8, 2019

ciarmcom added Jira status: CLOSED and removed Jira status: OPEN labels Jan 8, 2019

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

unstable test - tests-mbedmicro-rtos-mbed-queue on NUCLEO_F746ZG #8320

unstable test - tests-mbedmicro-rtos-mbed-queue on NUCLEO_F746ZG #8320

studavekar commented Oct 3, 2018 •

edited by ciarmcom

Loading

0xc0170 commented Oct 4, 2018

jeromecoutant commented Oct 4, 2018 •

edited

Loading

0xc0170 commented Oct 4, 2018

ciarmcom commented Oct 29, 2018

jeromecoutant commented Nov 6, 2018

cmonr commented Nov 13, 2018

elm3 commented Jan 7, 2019

0xc0170 commented Jan 8, 2019

unstable test - tests-mbedmicro-rtos-mbed-queue on NUCLEO_F746ZG #8320

unstable test - tests-mbedmicro-rtos-mbed-queue on NUCLEO_F746ZG #8320

Comments

studavekar commented Oct 3, 2018 • edited by ciarmcom Loading

Description

Issue request type

0xc0170 commented Oct 4, 2018

jeromecoutant commented Oct 4, 2018 • edited Loading

0xc0170 commented Oct 4, 2018

ciarmcom commented Oct 29, 2018

jeromecoutant commented Nov 6, 2018

cmonr commented Nov 13, 2018

elm3 commented Jan 7, 2019

0xc0170 commented Jan 8, 2019

studavekar commented Oct 3, 2018 •

edited by ciarmcom

Loading

jeromecoutant commented Oct 4, 2018 •

edited

Loading