search

ARMmbed / mbed-os

Arm Mbed OS is a platform operating system designed for the internet of things
https://mbed.com
Other
4.68k stars 2.98k forks source link

Failing heap tests on wizwiki platform #7711

Closed aashishc1988 closed 6 years ago

aashishc1988 commented 6 years ago

Description

Bug

Target WIZWIKI_W7500

Toolchain: IAR

Tests we are failing: tests-mbed_platform-stats_heap

Steps to reproduce

mbed test -m WIZWIKI_W7500 -t IAR -n tests-mbed_platform-stats_heap -DMBED_HEAP_STATS_ENABLED=1 -v

log snippet

> 
00:20:08.531 mbedgt: mbed-host-test-runner: started
00:20:08.843 [1533362965.47][root]Generating grammar tables from /usr/lib/python2.7/lib2to3/Grammar.txt
00:20:08.870 [1533362965.50][root]Generating grammar tables from /usr/lib/python2.7/lib2to3/PatternGrammar.txt
00:20:08.881 [1533362965.51][HTST][INF] host test executor ver. 1.4.0
00:20:08.881 [1533362965.51][HTST][INF] copy image onto target... SKIPPED!
00:20:08.883 [1533362965.51][HTST][INF] starting host test process...
00:20:08.887 [1533362965.52][CONN][INF] starting connection process...
00:20:08.888 [1533362965.52][CONN][INF] notify event queue about extra 60 sec timeout for serial port pooling
00:20:08.888 [1533362965.52][CONN][INF] initializing global resource mgr listener...
00:20:08.924 [1533362965.55][HTST][INF] setting timeout to: 60 sec
00:20:08.946 [1533362965.58][GLRM][INF] remote resources initialization: remote(host=goku.austin.arm.com, port=8000)
00:20:08.948 [1533362965.58][urllib3.connectionpool]Starting new HTTP connection (1): goku.austin.arm.com:8000
00:20:08.952 [1533362965.58][urllib3.connectionpool]http://goku.austin.arm.com:8000 "POST /login HTTP/1.1" 200 213
00:20:08.954 [1533362965.58][urllib3.connectionpool]Starting new HTTP connection (1): goku.austin.arm.com:8000
00:20:08.956 [1533362965.59][urllib3.connectionpool]http://goku.austin.arm.com:8000 "GET /socket.io/?token=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJ1c2VybmFtZSI6InVzZXIiLCJncm91cCI6InVzZXIiLCJpYXQiOjE1MzMzNjI5NjUsImV4cCI6MTUzMzk2Nzc2NX0.hnv9AoLtf3WgwSBEm76frCsN8w7wxk30FBH6hqlLwjo&EIO=3&transport=polling&t=1533362965582-0 HTTP/1.1" 200 101
00:20:08.963 [1533362965.59][urllib3.connectionpool]Starting new HTTP connection (1): goku.austin.arm.com:8000
00:20:08.965 [1533362965.59][urllib3.connectionpool]http://goku.austin.arm.com:8000 "GET /this/resource HTTP/1.1" 200 3651
00:20:08.966 [1533362965.60][urllib3.connectionpool]Starting new HTTP connection (1): goku.austin.arm.com:8000
00:20:08.975 [1533362965.61][urllib3.connectionpool]http://goku.austin.arm.com:8000 "GET /resource HTTP/1.1" 200 55174
00:20:08.979 [1533362965.61][GLRM][INF] remote resources count: 39
00:20:08.996 [1533362965.63][urllib3.connectionpool]Starting new HTTP connection (1): goku.austin.arm.com:8000
00:20:08.997 [1533362965.63][urllib3.connectionpool]http://goku.austin.arm.com:8000 "GET /resource/2201000003b9f89e00000000000000000000000097969902 HTTP/1.1" 200 1843
00:20:08.998 [1533362965.63][GLRM][INF] remote resources flashing with 'BUILD/tests/WIZWIKI_W7500/IAR/TESTS/mbed_platform/stats_heap/stats_heap.bin'...
00:20:08.999 [1533362965.63][urllib3.connectionpool]Starting new HTTP connection (1): goku.austin.arm.com:8000
00:20:09.002 [1533362965.63][urllib3.connectionpool]http://goku.austin.arm.com:8000 "POST /file HTTP/1.1" 200 246
00:20:22.404 [1533362979.03][GLRM][INF] opening connection to platform at baudrate='9600'
00:20:22.405 [1533362979.04][urllib3.connectionpool]Starting new HTTP connection (1): goku.austin.arm.com:8000
00:20:22.539 [1533362979.17][urllib3.connectionpool]http://goku.austin.arm.com:8000 "PUT /resource/2201000003b9f89e00000000000000000000000097969902/connect HTTP/1.1" 200 15
00:20:22.540 [1533362979.17][GLRM][INF] remote resources reset...
00:20:24.732 [1533362981.36][GLRM][TXD] mbedmbedmbedmbedmbedmbedmbedmbedmbedmbed
00:20:24.732 [1533362981.36][CONN][INF] sending up to 10 __sync packets (specified with --sync=10)
00:20:24.732 [1533362981.36][CONN][INF] sending preamble '644fe1cd-e00f-4b74-9939-46265e0ba7f8'
00:20:24.733 [1533362981.36][GLRM][TXD] {{__sync;644fe1cd-e00f-4b74-9939-46265e0ba7f8}}
00:20:25.892 [1533362982.52][CONN][RXD] mbedmbedmbedmbedmbedmbedmbedmbed
00:20:25.892 [1533362982.52][CONN][INF] found SYNC in stream: {{__sync;644fe1cd-e00f-4b74-9939-46265e0ba7f8}} it is #0 sent, queued...
00:20:25.892 [1533362982.52][CONN][INF] found KV pair in stream: {{__version;1.3.0}}, queued...
00:20:25.892 [1533362982.52][HTST][INF] sync KV found, uuid=644fe1cd-e00f-4b74-9939-46265e0ba7f8, timestamp=1533362982.522355
00:20:25.893 [1533362982.52][HTST][INF] DUT greentea-client version: 1.3.0
00:20:25.995 [1533362982.62][CONN][INF] found KV pair in stream: {{__timeout;20}}, queued...
00:20:25.995 [1533362982.62][HTST][INF] setting timeout to: 20 sec
00:20:25.995 [1533362982.62][CONN][INF] found KV pair in stream: {{__host_test_name;default_auto}}, queued...
00:20:25.995 [1533362982.63][CONN][INF] found KV pair in stream: {{__testcase_count;4}}, queued...
00:20:25.995 [1533362982.63][HTST][INF] host test class: '<class 'mbed_host_tests.host_tests.default_auto.DefaultAuto'>'
00:20:25.995 [1533362982.63][HTST][INF] host test setup() call...
00:20:25.995 [1533362982.63][HTST][INF] CALLBACKs updated
00:20:25.995 [1533362982.63][HTST][INF] host test detected: default_auto
00:20:26.087 [1533362982.72][CONN][RXD] >>> Running 4 test cases...
00:20:26.087 [1533362982.72][CONN][INF] found KV pair in stream: {{__testcase_name;malloc and free size}}, queued...
00:20:26.087 [1533362982.72][CONN][INF] found KV pair in stream: {{__testcase_name;allocate size zero}}, queued...
00:20:26.187 [1533362982.82][CONN][RXD]
00:20:26.187 [1533362982.82][CONN][INF] found KV pair in stream: {{__testcase_name;allocation failure}}, queued...
00:20:26.187 [1533362982.82][CONN][INF] found KV pair in stream: {{__testcase_name;realloc size}}, queued...
00:20:26.334 [1533362982.96][CONN][RXD] >>> Running case #1: 'malloc and free size'...
00:20:26.335 [1533362982.97][CONN][INF] found KV pair in stream: {{__testcase_start;malloc and free size}}, queued...
00:20:26.388 [1533362983.02][CONN][RXD] >>> 'malloc and free size': 1 passed, 0 failed
00:20:26.388 [1533362983.02][CONN][RXD]
00:20:26.388 [1533362983.02][CONN][INF] found KV pair in stream: {{__testcase_finish;malloc and free size;1;0}}, queued...
00:20:26.506 [1533362983.14][CONN][RXD] >>> Running case #2: 'allocate size zero'...
00:20:26.508 [1533362983.14][CONN][INF] found KV pair in stream: {{__testcase_start;allocate size zero}}, queued...
00:20:26.508 [1533362983.14][CONN][INF] found KV pair in stream: {{__testcase_finish;allocate size zero;1;0}}, queued...
00:20:26.589 [1533362983.22][CONN][RXD] >>> 'allocate size zero': 1 passed, 0 failed
00:20:26.590 [1533362983.22][CONN][RXD]
00:20:26.592 [1533362983.22][CONN][RXD] >>> Running case #3: 'allocation failure'...
00:20:26.693 [1533362983.32][CONN][INF] found KV pair in stream: {{__testcase_start;allocation failure}}, queued...
00:20:26.693 [1533362983.32][CONN][INF] found KV pair in stream: {{__testcase_finish;allocation failure;1;0}}, queued...
00:20:26.789 [1533362983.42][CONN][RXD] >>> 'allocation failure': 1 passed, 0 failed
00:20:26.790 [1533362983.42][CONN][RXD]
00:20:26.790 [1533362983.42][CONN][RXD] >>> Running case #4: 'realloc size'...
00:20:26.790 [1533362983.42][CONN][INF] found KV pair in stream: {{__testcase_start;realloc size}}, queued...
00:20:26.896 mbedgt: :173::FAIL: Expression Evaluated To FALSE
00:20:26.896 [1533362983.53][CONN][RXD] :173::FAIL: Expression Evaluated To FALSE
00:20:26.897 [1533362983.53][CONN][INF] found KV pair in stream: {{__testcase_finish;realloc size;0;1}}, queued...
00:20:26.991 [1533362983.62][CONN][RXD] >>> 'realloc size': 0 passed, 1 failed with reason 'Assertion Failed'
00:20:26.991 [1533362983.62][CONN][RXD]
00:20:27.091 [1533362983.72][CONN][RXD] >>> Test cases: 3 passed, 1 failed with reason 'Assertion Failed'
00:20:27.091 [1533362983.72][CONN][RXD] >>> TESTS FAILED!
00:20:27.092 [1533362983.72][CONN][INF] found KV pair in stream: {{__testcase_summary;3;1}}, queued...
00:20:27.092 [1533362983.72][HTST][ERR] orphan event in main phase: {{max_heap_usage;688}}, timestamp=1533362983.721610
00:20:27.093 [1533362983.72][CONN][INF] found KV pair in stream: {{max_heap_usage;688}}, queued...
00:20:27.208 [1533362983.84][HTST][ERR] orphan event in main phase: {{reserved_heap;1024}}, timestamp=1533362983.838570
00:20:27.209 [1533362983.84][CONN][INF] found KV pair in stream: {{reserved_heap;1024}}, queued...
00:20:27.209 [1533362983.84][HTST][ERR] orphan event in main phase: {{__thread_info;"0x020000bf4",744,4096}}, timestamp=1533362983.838576
00:20:27.209 [1533362983.84][CONN][INF] found KV pair in stream: {{__thread_info;"0x020000bf4",744,4096}}, queued...
00:20:27.291 [1533362983.92][CONN][RXD] {{__cpu_info        up time;0}}
00:20:27.292 [1533362983.92][CONN][INF] found KV pair in stream: {{__thread_info;"0x020002ad8",64,512}}, queued...
00:20:27.292 [1533362983.92][HTST][ERR] orphan event in main phase: {{__thread_info;"0x020002ad8",64,512}}, timestamp=1533362983.921762
00:20:27.292 [1533362983.92][CONN][INF] found KV pair in stream: {{__thread_info;"0x020002b20",112,768}}, queued...
00:20:27.292 [1533362983.92][HTST][ERR] orphan event in main phase: {{__thread_info;"0x020002b20",112,768}}, timestamp=1533362983.921769
00:20:27.391 [1533362984.02][CONN][RXD] {{__cpu_info     sleep time;0}}
00:20:27.391 [1533362984.02][CONN][RXD] {{__cpu_info deepsleep time;0}}
00:20:27.392 [1533362984.02][CONN][RXD] {{__cpu_info  %  sleep/deep;0;0}}
00:20:27.491 [1533362984.12][CONN][INF] found KV pair in stream: {{end;failure}}, queued...
00:20:27.492 [1533362984.12][CONN][INF] found KV pair in stream: {{__exit;0}}, queued...
00:20:27.492 [1533362984.12][HTST][INF] __exit(0)
00:20:27.492 [1533362984.12][HTST][INF] __notify_complete(False)
00:20:27.492 [1533362984.12][HTST][INF] __exit_event_queue received
00:20:27.492 [1533362984.12][HTST][INF] test suite run finished after 1.50 sec...
00:20:27.506 [1533362984.14][CONN][INF] received special event '__host_test_finished' value='True', finishing
00:20:27.507 [1533362984.14][urllib3.connectionpool]Starting new HTTP connection (1): goku.austin.arm.com:8000
00:20:27.589 [1533362984.22][urllib3.connectionpool]http://goku.austin.arm.com:8000 "PUT /resource/2201000003b9f89e00000000000000000000000097969902/disconnect HTTP/1.1" 200 2
00:20:27.589 [1533362984.22][urllib3.connectionpool]Starting new HTTP connection (1): goku.austin.arm.com:8000
00:20:30.780 [1533362987.41][urllib3.connectionpool]http://goku.austin.arm.com:8000 "PUT /resource/2201000003b9f89e00000000000000000000000097969902/release HTTP/1.1" 200 66
00:20:30.784 [1533362987.41][HTST][INF] CONN exited with code: 0
00:20:30.784 [1533362987.41][HTST][INF] Some events in queue
00:20:30.784 [1533362987.41][HTST][INF] stopped consuming events
00:20:30.784 [1533362987.41][HTST][INF] host test result() call skipped, received: False
00:20:30.784 [1533362987.41][HTST][INF] calling blocking teardown()
00:20:30.784 [1533362987.41][HTST][INF] teardown() finished
00:20:30.784 [1533362987.41][HTST][INF] {{result;failure}}
[ ] Question
[ ] Enhancement 
[X ] Bug
ciarmcom commented 6 years ago

ARM Internal Ref: MBOTRIAGE-1497

andrewc-arm commented 6 years ago

Hi, @khj098765 There seems to be W7500 + IAR cause heap problem. Could you please follow this issue?

andrewc-arm commented 6 years ago

Hi, @aashishc1988 When WIZnet and I run the same command, I get this error. Do you know how we should solve this compile error?

C:\Andrew\code\greentea>mbed test -m WIZWIKI_W7500 -t IAR -n tests-mbed_platform-stats_heap -DMBED_HEAP_STATS_ENABLED=1 -v

Build successes:

  • WIZWIKI_W7500::IAR::MBED-BUILD [mbed] Exec "mbedgt --test-spec C:\Andrew\code\greentea\BUILD\tests\WIZWIKI_W7500\IAR\test_spec.json -n tests-mbed_platform-stats_heap -V -DMBED_HEAP_STATS_ENABLED=1" in C:\Andrew\code\greentea Usage: mbedgt [options]

mbedgt: error: no such option: -D [mbed] ERROR: "mbedgt" returned error code 2.

Thanks,

aashishc1988 commented 6 years ago

@andrewc-arm Try replacing "mbed test" with "mbed test --compile"

andrewc-arm commented 6 years ago

Hi. @aashishc1988 I replaced it and got following failure.

C:\Andrew\code\greentea>mbed test --compile -m WIZWIKI_W7500 -t IAR -n tests-mbed_platform-stats_heap -DMBED_HEAP_STATS_ENABLED=1 -v [mbed] Working path "C:\Andrew\code\greentea" (program) [mbed] Exec "C:\Python27\python.exe -u C:\Andrew\code\greentea\mbed-os\tools\test.py -t IAR -m WIZWIKI_W7500 --source C:\Andrew\code\greentea --build C:\Andrew\code\greentea\BUILD\tests\WIZWIKI_W7500\IAR --test-spec C:\Andrew\code\greentea\BUILD\tests\WIZWIKI_W7500\IAR\test_spec.json -n tests-mbed_platform-stats_heap -v -DMBED_HEAP_STATS_ENABLED=1" in C:\Andrew\code\greentea [Warning] Test with name 'tests-mbed_platform-stats_heap' was not found in the available tests Building library mbed-build (WIZWIKI_W7500, IAR) Scan: greentea

Could you please make sure 'Steps to Reproduce' is working for you?

aashishc1988 commented 6 years ago

@andrewc-arm Sorry for late reply. Can you please post the complete log? I just tried

mbed test --compile -m WIZWIKI_W7500 -t IAR -n tests-mbed_platform-stats_heap -DMBED_HEAP_STATS_ENABLED=1 -v

and it built fine for me.

andrewc-arm commented 6 years ago

Hi, @khj098765 @aashishc1988 confirmed the new command works for him. Could you please test if it works for you? Also, could you please make sure that your latest W7500 driver code in the latest mbed-os solves the problem? Thanks,

khj098765 commented 6 years ago

Hi, @aashishc1988 @andrewc-arm I have tried this test. compile was possible but this test occured NOT_SUPPORTED error. Is the test that W7500 should support?

mbed test --compile -m WIZWIKI_W7500 -t IAR -n tests-mbed_platform-stats_heap -DMBED_HEAP_STATS_ENABLED=1 -v heapcompilelog.txt

mbed test -m WIZWIKI_W7500 -t IAR -n tests-mbed_platform-stats_heap heaptestlog.txt

aashishc1988 commented 6 years ago

@khj098765 It is saying NOT_SUPPORTED because with the second call

mbed test -m WIZWIKI_W7500 -t IAR -n tests-mbed_platform-stats_heap

You are rebuilding the test without the necessary flag

DMBED_HEAP_STATS_ENABLED=1

To fix that and run the test locally, you can do this

Build the example first

mbed test --compile -m WIZWIKI_W7500 -t IAR -n tests-mbed_platform-stats_heap -DMBED_HEAP_STATS_ENABLED=1 -v

And then run locally using greentea

mbedgt --use-tids 2201000003b8bdc800000000000000000000000097969902 -n tests-mbed_platform-stats_heap -v V

Do a mbedls to find the right target id for your device and replace the one above with that.

khj098765 commented 6 years ago

@aashishc1988 I run locally using greentea

mbedgt --use-tids 2201000003b8bdc800000000000000000000000097969902 -n tests-mbed_platform-stats_heap -v V

mbedgt --use-tids 2201000003b8bdc800000000000000000000000097969902 -n tests-mbed_platform-stats_heap -v V

mbedgt: greentea test automation tool ver. 1.2.6 mbedgt: using multiple test specifications from current directory! using 'BUILD\tests\WIZWIKI_W7500\IAR\test_spec.json mbedgt: detecting connected mbed-enabled devices... mbedgt: detected 1 device mbedgt: filtering out target ids not on below list (specified with --use-tids switch) accepting target id '2201000003b8bdc800000000000000000000000097969902 mbedgt: processing target 'WIZWIKI_W7500' toolchain 'IAR' compatible platforms... (note: switch set to --parallel 1) mbedgt: all tests finished! mbedgt: shuffle seed: 0.9835318232 mbedgt: no platform/target matching tests were found! mbedgt: no matching platforms were found! mbedgt: completed in 0.37 sec mbedgt: exited with code -110

gtlog.txt

but I returned message about no maching.

If you possible, can you try this issue test after the following PR has been merged? https://github.com/ARMmbed/mbed-os/pull/7921#issuecomment-422500049

aashishc1988 commented 6 years ago

@khj098765 I ran the test on that PR and it is fixed now. Closing this one