mbed_hal-common_tickers test fails on NUMAKER_PFM_M2351 #8044
Description
Description
- Type: Bug
- Priority: Major
Bug
Target
NUMAKER_PFM_M2351
Toolchain:
ARMC6
mbed-os sha:
6827c370 (HEAD -> master, origin/master, origin/feature-hal-spec-spi, origin/HEAD) Merge pull request #7971 from JammuKekkonen/fix_softdevice_memory_reservation_for_nrf52dk
Steps to reproduce
Use command run : mbed test -m NUMAKER_PFM_M2351 -t ARMC6 -n tests-mbed_hal-common_tickers -v
logs snippet
mbedgt: selecting test case observer...
calling mbedhtrun: mbedhtrun -m NUMAKER_PFM_M2351 -p /dev/ttyACM22:9600 -f "BUILD/tests/NUMAKER_PFM_M2351/ARMC6/TESTS/mbed_hal/common_tickers/common_tickers.hex" -e "TESTS/host_tests" -d /mnt/pci-0000_00_14_0-usb-0_7_2_3_1_0-scsi-0_0_0_0 -c default -t 13050000002D0101013B97B000000002 -r default -C 4 --sync 5 -P 60
mbedgt: mbed-host-test-runner: started
[1536342719.41][root]Generating grammar tables from /usr/lib/python2.7/lib2to3/Grammar.txt
[1536342719.42][root]Generating grammar tables from /usr/lib/python2.7/lib2to3/PatternGrammar.txt
[1536342719.43][HTST][INF] host test executor ver. 1.4.1
[1536342719.43][HTST][INF] copy image onto target...
[1536342719.43][COPY][INF] Waiting up to 60 sec for '13050000002D0101013B97B000000002' mount point (current is '/mnt/pci-0000_00_14_0-usb-0_7_2_3_1_0-scsi-0_0_0_0')...
[1536342732.23][HTST][INF] starting host test process...
[1536342732.23][CONN][INF] starting connection process...
[1536342732.23][CONN][INF] notify event queue about extra 60 sec timeout for serial port pooling
[1536342732.23][CONN][INF] initializing serial port listener...
[1536342732.23][HTST][INF] setting timeout to: 60 sec
[1536342732.23][PLGN][INF] Waiting up to 60 sec for '13050000002D0101013B97B000000002' serial port (current is '/dev/ttyACM22')...
[1536342732.52][mbedls.lstools_base]No valid file found to update JLink device details
[1536342732.52][mbedls.lstools_base]No valid file found to update JLink device details
[1536342732.52][mbedls.lstools_base]daplink entry: "0000" not found in platform database
[1536342732.52][mbedls.lstools_base]No valid file found to update JLink device details
[1536342732.52][mbedls.lstools_base]daplink entry: "7012" not found in platform database
[1536342732.52][SERI][INF] serial(port=/dev/ttyACM22, baudrate=9600, read_timeout=0.01, write_timeout=5)
[1536342732.52][SERI][INF] reset device using 'default' plugin...
[1536342732.64][SERI][INF] waiting 1.00 sec after reset
[1536342733.64][SERI][INF] wait for it...
[1536342733.64][SERI][TXD] mbedmbedmbedmbedmbedmbedmbedmbedmbedmbed
[1536342733.64][CONN][INF] sending up to 5 __sync packets (specified with --sync=5)
[1536342733.64][CONN][INF] sending preamble '3dc66c4b-cc00-4c95-beda-5958895636c6'
[1536342733.64][SERI][TXD] {{__sync;3dc66c4b-cc00-4c95-beda-5958895636c6}}
[1536342733.78][CONN][RXD] mbedmbedmbedmbedmbedmbedmbedmbed
[1536342733.83][CONN][INF] found SYNC in stream: {{__sync;3dc66c4b-cc00-4c95-beda-5958895636c6}} it is #0 sent, queued...
[1536342733.83][HTST][INF] sync KV found, uuid=3dc66c4b-cc00-4c95-beda-5958895636c6, timestamp=1536342733.828346
[1536342733.84][CONN][INF] found KV pair in stream: {{__version;1.3.0}}, queued...
[1536342733.84][HTST][INF] DUT greentea-client version: 1.3.0
[1536342733.87][CONN][INF] found KV pair in stream: {{__timeout;30}}, queued...
[1536342733.87][HTST][INF] setting timeout to: 30 sec
[1536342733.90][CONN][INF] found KV pair in stream: {{__host_test_name;default_auto}}, queued...
[1536342733.90][HTST][INF] host test class: '<class 'mbed_host_tests.host_tests.default_auto.DefaultAuto'>'
[1536342733.90][HTST][INF] host test setup() call...
[1536342733.90][HTST][INF] CALLBACKs updated
[1536342733.90][HTST][INF] host test detected: default_auto
[1536342733.94][CONN][RXD] >>> Running 18 test cases...
[1536342734.01][CONN][INF] found KV pair in stream: {{__testcase_name;Microsecond ticker init is safe to call repeatedly}}, queued...
[1536342734.06][CONN][INF] found KV pair in stream: {{__testcase_name;Microsecond ticker info test}}, queued...
[1536342734.12][CONN][INF] found KV pair in stream: {{__testcase_name;Microsecond ticker interrupt test}}, queued...
[1536342734.17][CONN][INF] found KV pair in stream: {{__testcase_name;Microsecond ticker past interrupt test}}, queued...
[1536342734.23][CONN][INF] found KV pair in stream: {{__testcase_name;Microsecond ticker reschedule test}}, queued...
[1536342734.29][CONN][INF] found KV pair in stream: {{__testcase_name;Microsecond ticker fire interrupt}}, queued...
[1536342734.35][CONN][INF] found KV pair in stream: {{__testcase_name;Microsecond ticker overflow test}}, queued...
[1536342734.41][CONN][INF] found KV pair in stream: {{__testcase_name;Microsecond ticker increment test}}, queued...
[1536342734.45][CONN][INF] found KV pair in stream: {{__testcase_name;Microsecond ticker speed test}}, queued...
[1536342734.53][CONN][INF] found KV pair in stream: {{__testcase_name;lp ticker init is safe to call repeatedly}}, queued...
[1536342734.57][CONN][INF] found KV pair in stream: {{__testcase_name;lp ticker info test}}, queued...
[1536342734.61][CONN][INF] found KV pair in stream: {{__testcase_name;lp ticker interrupt test}}, queued...
[1536342734.66][CONN][INF] found KV pair in stream: {{__testcase_name;lp ticker past interrupt test}}, queued...
[1536342734.72][CONN][INF] found KV pair in stream: {{__testcase_name;lp ticker reschedule test}}, queued...
[1536342734.76][CONN][INF] found KV pair in stream: {{__testcase_name;lp ticker fire interrupt}}, queued...
[1536342734.81][CONN][INF] found KV pair in stream: {{__testcase_name;lp ticker overflow test}}, queued...
[1536342734.86][CONN][INF] found KV pair in stream: {{__testcase_name;lp ticker increment test}}, queued...
[1536342734.91][CONN][RXD]
[1536342734.91][CONN][INF] found KV pair in stream: {{__testcase_name;lp ticker speed test}}, queued...
[1536342734.98][CONN][RXD] >>> Running case #1: 'Microsecond ticker init is safe to call repeatedly'...
[1536342735.06][CONN][INF] found KV pair in stream: {{__testcase_start;Microsecond ticker init is safe to call repeatedly}}, queued...
[1536342735.14][CONN][INF] found KV pair in stream: {{__testcase_finish;Microsecond ticker init is safe to call repeatedly;1;0}}, queued...
[1536342735.22][CONN][RXD] >>> 'Microsecond ticker init is safe to call repeatedly': 1 passed, 0 failed
[1536342735.22][CONN][RXD]
[1536342735.28][CONN][RXD] >>> Running case #2: 'Microsecond ticker info test'...
[1536342735.33][CONN][INF] found KV pair in stream: {{__testcase_start;Microsecond ticker info test}}, queued...
[1536342735.38][CONN][INF] found KV pair in stream: {{__testcase_finish;Microsecond ticker info test;1;0}}, queued...
[1536342735.45][CONN][RXD] >>> 'Microsecond ticker info test': 1 passed, 0 failed
[1536342735.45][CONN][RXD]
[1536342735.51][CONN][RXD] >>> Running case #3: 'Microsecond ticker interrupt test'...
[1536342735.56][CONN][INF] found KV pair in stream: {{__testcase_start;Microsecond ticker interrupt test}}, queued...
[1536342735.63][CONN][INF] found KV pair in stream: {{__testcase_finish;Microsecond ticker interrupt test;1;0}}, queued...
[1536342735.69][CONN][RXD] >>> 'Microsecond ticker interrupt test': 1 passed, 0 failed
[1536342735.69][CONN][RXD]
[1536342735.76][CONN][RXD] >>> Running case #4: 'Microsecond ticker past interrupt test'...
[1536342735.83][CONN][INF] found KV pair in stream: {{__testcase_start;Microsecond ticker past interrupt test}}, queued...
[1536342735.89][CONN][INF] found KV pair in stream: {{__testcase_finish;Microsecond ticker past interrupt test;1;0}}, queued...
[1536342735.95][CONN][RXD] >>> 'Microsecond ticker past interrupt test': 1 passed, 0 failed
[1536342735.95][CONN][RXD]
[1536342736.03][CONN][RXD] >>> Running case #5: 'Microsecond ticker reschedule test'...
[1536342736.08][CONN][INF] found KV pair in stream: {{__testcase_start;Microsecond ticker reschedule test}}, queued...
[1536342736.14][CONN][INF] found KV pair in stream: {{__testcase_finish;Microsecond ticker reschedule test;1;0}}, queued...
[1536342736.21][CONN][RXD] >>> 'Microsecond ticker reschedule test': 1 passed, 0 failed
[1536342736.21][CONN][RXD]
[1536342736.27][CONN][RXD] >>> Running case #6: 'Microsecond ticker fire interrupt'...
[1536342736.33][CONN][INF] found KV pair in stream: {{__testcase_start;Microsecond ticker fire interrupt}}, queued...
[1536342736.40][CONN][INF] found KV pair in stream: {{__testcase_finish;Microsecond ticker fire interrupt;1;0}}, queued...
[1536342736.46][CONN][RXD] >>> 'Microsecond ticker fire interrupt': 1 passed, 0 failed
[1536342736.46][CONN][RXD]
[1536342736.52][CONN][RXD] >>> Running case #7: 'Microsecond ticker overflow test'...
[1536342736.57][CONN][INF] found KV pair in stream: {{__testcase_start;Microsecond ticker overflow test}}, queued...
mbedgt: :366::FAIL: Expected 1 Was 2
[1536342749.46][CONN][RXD] :366::FAIL: Expected 1 Was 2
[1536342749.52][CONN][INF] found KV pair in stream: {{__testcase_finish;Microsecond ticker overflow test;0;1}}, queued...
[1536342749.61][CONN][RXD] >>> 'Microsecond ticker overflow test': 0 passed, 1 failed with reason 'Assertion Failed'
[1536342749.61][CONN][RXD]
[1536342749.68][CONN][RXD] >>> Test cases: 6 passed, 1 failed with reason 'Assertion Failed'
[1536342749.70][CONN][RXD] >>> TESTS FAILED!
[1536342749.73][CONN][INF] found KV pair in stream: {{__testcase_summary;6;1}}, queued...
[1536342749.76][CONN][INF] found KV pair in stream: {{max_heap_usage;0}}, queued...
[1536342749.76][HTST][ERR] orphan event in main phase: {{max_heap_usage;0}}, timestamp=1536342749.759211
[1536342749.77][CONN][INF] found KV pair in stream: {{reserved_heap;0}}, queued...
[1536342749.77][HTST][ERR] orphan event in main phase: {{reserved_heap;0}}, timestamp=1536342749.769775
[1536342749.79][CONN][INF] found KV pair in stream: {{end;failure}}, queued...
[1536342749.79][HTST][INF] __notify_complete(False)
[1536342749.79][HTST][INF] __exit_event_queue received
[1536342749.79][HTST][INF] test suite run finished after 15.92 sec...
[1536342749.80][CONN][INF] received special event '__host_test_finished' value='True', finishing
[1536342749.84][HTST][INF] CONN exited with code: 0
[1536342749.84][HTST][INF] No events in queue
[1536342749.84][HTST][INF] stopped consuming events
[1536342749.84][HTST][INF] host test result() call skipped, received: False
[1536342749.84][HTST][WRN] missing __exit event from DUT
[1536342749.84][HTST][INF] calling blocking teardown()
[1536342749.84][HTST][INF] teardown() finished
[1536342749.84][HTST][INF] {{result;failure}}
mbedgt: retry mbedhtrun 1/1
mbedgt: ['mbedhtrun', '-m', u'NUMAKER_PFM_M2351', '-p', '/dev/ttyACM22:9600', '-f', u'"BUILD/tests/NUMAKER_PFM_M2351/ARMC6/TESTS/mbed_hal/common_tickers/common_tickers.hex"', '-e', u'"TESTS/host_tests"', '-d', u'/mnt/pci-0000_00_14_0-usb-0_7_2_3_1_0-scsi-0_0_0_0', '-c', 'default', '-t', u'13050000002D0101013B97B000000002', '-r', 'default', '-C', '4', '--sync', '5', '-P', '60'] failed after 1 count
mbedgt: checking for GCOV data...
mbedgt: mbed-host-test-runner: stopped and returned 'FAIL'
mbedgt: test on hardware with target id: 13050000002D0101013B97B000000002
mbedgt: test suite 'tests-mbed_hal-common_tickers' ................................................... FAIL in 30.62 sec
test case: 'Microsecond ticker fire interrupt' ............................................... OK in 0.07 sec
test case: 'Microsecond ticker increment test' ............................................... SKIPPED in 0.00 sec
test case: 'Microsecond ticker info test' .................................................... OK in 0.05 sec
test case: 'Microsecond ticker init is safe to call repeatedly' .............................. OK in 0.08 sec
test case: 'Microsecond ticker interrupt test' ............................................... OK in 0.07 sec
test case: 'Microsecond ticker overflow test' ................................................ FAIL in 12.95 sec
test case: 'Microsecond ticker past interrupt test' .......................................... OK in 0.06 sec
test case: 'Microsecond ticker reschedule test' .............................................. OK in 0.06 sec
test case: 'Microsecond ticker speed test' ................................................... SKIPPED in 0.00 sec
test case: 'lp ticker fire interrupt' ........................................................ SKIPPED in 0.00 sec
test case: 'lp ticker increment test' ........................................................ SKIPPED in 0.00 sec
test case: 'lp ticker info test' ............................................................. SKIPPED in 0.00 sec
test case: 'lp ticker init is safe to call repeatedly' ....................................... SKIPPED in 0.00 sec
test case: 'lp ticker interrupt test' ........................................................ SKIPPED in 0.00 sec
test case: 'lp ticker overflow test' ......................................................... SKIPPED in 0.00 sec
test case: 'lp ticker past interrupt test' ................................................... SKIPPED in 0.00 sec
test case: 'lp ticker reschedule test' ....................................................... SKIPPED in 0.00 sec
test case: 'lp ticker speed test' ............................................................ SKIPPED in 0.00 sec
mbedgt: test case summary: 6 passes, 1 failure
mbedgt: utest test case summary mismatch: utest reported passes and failures miscount!
reported by utest: passes = 6, failures 1)
test case result count: passes = 6, failures 12)
mbedgt: all tests finished!
mbedgt: shuffle seed: 0.6261068520
mbedgt: test suite report:
+-------------------------+-------------------+-------------------------------+--------+--------------------+-------------+
| target | platform_name | test suite | result | elapsed_time (sec) | copy_method |
+-------------------------+-------------------+-------------------------------+--------+--------------------+-------------+
| NUMAKER_PFM_M2351-ARMC6 | NUMAKER_PFM_M2351 | tests-mbed_hal-common_tickers | FAIL | 30.62 | default |
+-------------------------+-------------------+-------------------------------+--------+--------------------+-------------+
mbedgt: test suite results: 1 FAIL
mbedgt: test case report:
+-------------------------+-------------------+-------------------------------+----------------------------------------------------+--------+--------+---------+--------------------+
| target | platform_name | test suite | test case | passed | failed | result | elapsed_time (sec) |
+-------------------------+-------------------+-------------------------------+----------------------------------------------------+--------+--------+---------+--------------------+
| NUMAKER_PFM_M2351-ARMC6 | NUMAKER_PFM_M2351 | tests-mbed_hal-common_tickers | Microsecond ticker fire interrupt | 1 | 0 | OK | 0.07 |
| NUMAKER_PFM_M2351-ARMC6 | NUMAKER_PFM_M2351 | tests-mbed_hal-common_tickers | Microsecond ticker increment test | 0 | 0 | SKIPPED | 0.0 |
| NUMAKER_PFM_M2351-ARMC6 | NUMAKER_PFM_M2351 | tests-mbed_hal-common_tickers | Microsecond ticker info test | 1 | 0 | OK | 0.05 |
| NUMAKER_PFM_M2351-ARMC6 | NUMAKER_PFM_M2351 | tests-mbed_hal-common_tickers | Microsecond ticker init is safe to call repeatedly | 1 | 0 | OK | 0.08 |
| NUMAKER_PFM_M2351-ARMC6 | NUMAKER_PFM_M2351 | tests-mbed_hal-common_tickers | Microsecond ticker interrupt test | 1 | 0 | OK | 0.07 |
| NUMAKER_PFM_M2351-ARMC6 | NUMAKER_PFM_M2351 | tests-mbed_hal-common_tickers | Microsecond ticker overflow test | 0 | 1 | FAIL | 12.95 |
| NUMAKER_PFM_M2351-ARMC6 | NUMAKER_PFM_M2351 | tests-mbed_hal-common_tickers | Microsecond ticker past interrupt test | 1 | 0 | OK | 0.06 |
| NUMAKER_PFM_M2351-ARMC6 | NUMAKER_PFM_M2351 | tests-mbed_hal-common_tickers | Microsecond ticker reschedule test | 1 | 0 | OK | 0.06 |
| NUMAKER_PFM_M2351-ARMC6 | NUMAKER_PFM_M2351 | tests-mbed_hal-common_tickers | Microsecond ticker speed test | 0 | 0 | SKIPPED | 0.0 |
| NUMAKER_PFM_M2351-ARMC6 | NUMAKER_PFM_M2351 | tests-mbed_hal-common_tickers | lp ticker fire interrupt | 0 | 0 | SKIPPED | 0.0 |
| NUMAKER_PFM_M2351-ARMC6 | NUMAKER_PFM_M2351 | tests-mbed_hal-common_tickers | lp ticker increment test | 0 | 0 | SKIPPED | 0.0 |
| NUMAKER_PFM_M2351-ARMC6 | NUMAKER_PFM_M2351 | tests-mbed_hal-common_tickers | lp ticker info test | 0 | 0 | SKIPPED | 0.0 |
| NUMAKER_PFM_M2351-ARMC6 | NUMAKER_PFM_M2351 | tests-mbed_hal-common_tickers | lp ticker init is safe to call repeatedly | 0 | 0 | SKIPPED | 0.0 |
| NUMAKER_PFM_M2351-ARMC6 | NUMAKER_PFM_M2351 | tests-mbed_hal-common_tickers | lp ticker interrupt test | 0 | 0 | SKIPPED | 0.0 |
| NUMAKER_PFM_M2351-ARMC6 | NUMAKER_PFM_M2351 | tests-mbed_hal-common_tickers | lp ticker overflow test | 0 | 0 | SKIPPED | 0.0 |
| NUMAKER_PFM_M2351-ARMC6 | NUMAKER_PFM_M2351 | tests-mbed_hal-common_tickers | lp ticker past interrupt test | 0 | 0 | SKIPPED | 0.0 |
| NUMAKER_PFM_M2351-ARMC6 | NUMAKER_PFM_M2351 | tests-mbed_hal-common_tickers | lp ticker reschedule test | 0 | 0 | SKIPPED | 0.0 |
| NUMAKER_PFM_M2351-ARMC6 | NUMAKER_PFM_M2351 | tests-mbed_hal-common_tickers | lp ticker speed test | 0 | 0 | SKIPPED | 0.0 |
+-------------------------+-------------------+-------------------------------+----------------------------------------------------+--------+--------+---------+--------------------+
mbedgt: test case results: 1 FAIL / 11 SKIPPED / 6 OK
mbedgt: completed in 31.04 sec
mbedgt: exited with code 1
CC : @maclobdell @bentcooke @ccli8