Created
January 31, 2018 07:35
-
-
Save anonymous/4873033bb990e29f3f321b5f61c1c9a4 to your computer and use it in GitHub Desktop.
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| mbedgt: greentea test automation tool ver. 1.3.2 | |
| mbedgt: test specification file '/Users/drewcassidy/Projects/OSHChip-mbed-tests/BUILD/tests/NRF51_DK/GCC_ARM/test_spec.json' (specified with --test-spec option) | |
| mbedgt: using '/Users/drewcassidy/Projects/OSHChip-mbed-tests/BUILD/tests/NRF51_DK/GCC_ARM/test_spec.json' from current directory! | |
| mbedgt: detecting connected mbed-enabled devices... | |
| [1517384021.12][mbedls.lstools_base]Call to deprecated function list_mbeds_ext. Functionality has been moved into 'list_mbeds'. Please use list_mbeds with 'unique_names=True' and 'read_details_txt=True' | |
| mbedgt: detected 2 devices | |
| +---------------+----------------------+-----------------------+------------------+--------------------------------------------------+ | |
| | platform_name | platform_name_unique | serial_port | mount_point | target_id | | |
| +---------------+----------------------+-----------------------+------------------+--------------------------------------------------+ | |
| | NRF51_DK | NRF51_DK[0] | /dev/tty.usbmodem1451 | /Volumes/JLINK | 1100021852333120343935373230322031323033AFD4DFD8 | | |
| | OSHCHIP | OSHCHIP[0] | /dev/tty.usbmodem1432 | /Volumes/DAPLINK | 740100001a9c95d400000000000000000000000097969902 | | |
| +---------------+----------------------+-----------------------+------------------+--------------------------------------------------+ | |
| mbedgt: processing target 'NRF51_DK' toolchain 'GCC_ARM' compatible platforms... (note: switch set to --parallel 1) | |
| +---------------+----------------------+----------------------------+----------------+--------------------------------------------------+ | |
| | platform_name | platform_name_unique | serial_port | mount_point | target_id | | |
| +---------------+----------------------+----------------------------+----------------+--------------------------------------------------+ | |
| | NRF51_DK | NRF51_DK[0] | /dev/tty.usbmodem1451:9600 | /Volumes/JLINK | 1100021852333120343935373230322031323033AFD4DFD8 | | |
| +---------------+----------------------+----------------------------+----------------+--------------------------------------------------+ | |
| mbedgt: test case filter (specified with -n option) | |
| test filtered in 'mbed-os-tests-mbed_drivers-ticker' | |
| mbedgt: running 1 test for platform 'NRF51_DK' and toolchain 'GCC_ARM' | |
| use 1 instance of execution threads for testing | |
| mbedgt: checking for 'host_tests' directory above image directory structure | |
| found 'host_tests' directory in: 'mbed-os/TESTS/host_tests' | |
| mbedgt: selecting test case observer... | |
| calling mbedhtrun: mbedhtrun -m NRF51_DK -p /dev/tty.usbmodem1451:9600 -f "BUILD/tests/NRF51_DK/GCC_ARM/mbed-os/TESTS/mbed_drivers/ticker/ticker.hex" -e "mbed-os/TESTS/host_tests" -d /Volumes/JLINK -C 6 -c default -t 1100021852333120343935373230322031323033AFD4DFD8 -r default --sync 5 | |
| mbedgt: mbed-host-test-runner: started | |
| [1517384025.85][HTST][INF] host test executor ver. 1.3.0 | |
| [1517384025.85][HTST][INF] copy image onto target... | |
| [1517384025.85][COPY][INF] Waiting up to 60 sec for '1100021852333120343935373230322031323033AFD4DFD8' mount point (current is '/Volumes/JLINK')... | |
| [1517384061.07][HTST][INF] starting host test process... | |
| [1517384061.08][CONN][INF] starting connection process... | |
| [1517384061.08][CONN][INF] notify event queue about extra 60 sec timeout for serial port pooling | |
| [1517384061.08][CONN][INF] initializing serial port listener... | |
| [1517384061.08][PLGN][INF] Waiting up to 60 sec for '1100021852333120343935373230322031323033AFD4DFD8' serial port (current is '/dev/tty.usbmodem1451')... | |
| [1517384061.08][HTST][INF] setting timeout to: 60 sec | |
| [1517384064.53][SERI][INF] serial(port=/dev/tty.usbmodem1451, baudrate=9600, read_timeout=0.01, write_timeout=5) | |
| [1517384064.53][SERI][INF] reset device using 'default' plugin... | |
| [1517384064.93][SERI][INF] waiting 1.00 sec after reset | |
| [1517384065.94][SERI][INF] wait for it... | |
| [1517384065.94][SERI][TXD] mbedmbedmbedmbedmbedmbedmbedmbedmbedmbed | |
| [1517384065.94][CONN][INF] sending up to 5 __sync packets (specified with --sync=5) | |
| [1517384065.94][CONN][INF] sending preamble '5eea18ff-3afc-4fc6-9d15-6f0e1a0e3d93' | |
| [1517384065.94][SERI][TXD] {{__sync;5eea18ff-3afc-4fc6-9d15-6f0e1a0e3d93}} | |
| [1517384066.08][CONN][RXD] mbedmbedmbedmbedmbedmbedmbedmbed | |
| [1517384066.13][CONN][INF] found SYNC in stream: {{__sync;5eea18ff-3afc-4fc6-9d15-6f0e1a0e3d93}} it is #0 sent, queued... | |
| [1517384066.13][HTST][INF] sync KV found, uuid=5eea18ff-3afc-4fc6-9d15-6f0e1a0e3d93, timestamp=1517384066.131489 | |
| [1517384066.15][CONN][INF] found KV pair in stream: {{__version;1.3.0}}, queued... | |
| [1517384066.15][HTST][INF] DUT greentea-client version: 1.3.0 | |
| [1517384066.18][CONN][INF] found KV pair in stream: {{__timeout;240}}, queued... | |
| [1517384066.18][HTST][INF] setting timeout to: 240 sec | |
| [1517384066.22][CONN][INF] found KV pair in stream: {{__host_test_name;timing_drift_auto}}, queued... | |
| [1517384066.22][HTST][INF] host test class: '<class 'timing_drift_auto.TimingDriftSync'>' | |
| [1517384066.22][HTST][INF] host test setup() call... | |
| [1517384066.22][HTST][INF] CALLBACKs updated | |
| [1517384066.22][HTST][INF] host test detected: timing_drift_auto | |
| [1517384066.25][CONN][INF] found KV pair in stream: {{__testcase_count;11}}, queued... | |
| [1517384066.27][CONN][RXD] >>> Running 11 test cases... | |
| [1517384066.34][CONN][INF] found KV pair in stream: {{__testcase_name;Test attach for 0.01s and time measure}}, queued... | |
| [1517384066.40][CONN][INF] found KV pair in stream: {{__testcase_name;Test attach_us for 10ms and time measure}}, queued... | |
| [1517384066.47][CONN][INF] found KV pair in stream: {{__testcase_name;Test attach for 0.1s and time measure}}, queued... | |
| [1517384066.54][CONN][INF] found KV pair in stream: {{__testcase_name;Test attach_us for 100ms and time measure}}, queued... | |
| [1517384066.61][CONN][INF] found KV pair in stream: {{__testcase_name;Test attach for 0.5s and time measure}}, queued... | |
| [1517384066.67][CONN][INF] found KV pair in stream: {{__testcase_name;Test attach_us for 500ms and time measure}}, queued... | |
| [1517384066.71][CONN][INF] found KV pair in stream: {{__testcase_name;Test detach}}, queued... | |
| [1517384066.77][CONN][INF] found KV pair in stream: {{__testcase_name;Test multi call and time measure}}, queued... | |
| [1517384066.81][CONN][INF] found KV pair in stream: {{__testcase_name;Test multi ticker}}, queued... | |
| [1517384066.86][CONN][INF] found KV pair in stream: {{__testcase_name;Test timers: 1x ticker}}, queued... | |
| [1517384066.90][CONN][RXD] | |
| [1517384066.90][CONN][INF] found KV pair in stream: {{__testcase_name;Test timers: 2x ticker}}, queued... | |
| [1517384066.98][CONN][RXD] >>> Running case #1: 'Test attach for 0.01s and time measure'... | |
| [1517384067.04][CONN][INF] found KV pair in stream: {{__testcase_start;Test attach for 0.01s and time measure}}, queued... | |
| [1517384067.12][CONN][INF] found KV pair in stream: {{__testcase_finish;Test attach for 0.01s and time measure;1;0}}, queued... | |
| [1517384067.19][CONN][RXD] >>> 'Test attach for 0.01s and time measure': 1 passed, 0 failed | |
| [1517384067.19][CONN][RXD] | |
| [1517384067.27][CONN][RXD] >>> Running case #2: 'Test attach_us for 10ms and time measure'... | |
| [1517384067.33][CONN][INF] found KV pair in stream: {{__testcase_start;Test attach_us for 10ms and time measure}}, queued... | |
| [1517384067.42][CONN][INF] found KV pair in stream: {{__testcase_finish;Test attach_us for 10ms and time measure;1;0}}, queued... | |
| [1517384067.49][CONN][RXD] >>> 'Test attach_us for 10ms and time measure': 1 passed, 0 failed | |
| [1517384067.49][CONN][RXD] | |
| [1517384067.56][CONN][RXD] >>> Running case #3: 'Test attach for 0.1s and time measure'... | |
| [1517384067.62][CONN][INF] found KV pair in stream: {{__testcase_start;Test attach for 0.1s and time measure}}, queued... | |
| [1517384067.78][CONN][INF] found KV pair in stream: {{__testcase_finish;Test attach for 0.1s and time measure;1;0}}, queued... | |
| [1517384067.86][CONN][RXD] >>> 'Test attach for 0.1s and time measure': 1 passed, 0 failed | |
| [1517384067.86][CONN][RXD] | |
| [1517384067.93][CONN][RXD] >>> Running case #4: 'Test attach_us for 100ms and time measure'... | |
| [1517384068.00][CONN][INF] found KV pair in stream: {{__testcase_start;Test attach_us for 100ms and time measure}}, queued... | |
| [1517384068.17][CONN][INF] found KV pair in stream: {{__testcase_finish;Test attach_us for 100ms and time measure;1;0}}, queued... | |
| [1517384068.24][CONN][RXD] >>> 'Test attach_us for 100ms and time measure': 1 passed, 0 failed | |
| [1517384068.24][CONN][RXD] | |
| [1517384068.31][CONN][RXD] >>> Running case #5: 'Test attach for 0.5s and time measure'... | |
| [1517384068.37][CONN][INF] found KV pair in stream: {{__testcase_start;Test attach for 0.5s and time measure}}, queued... | |
| [1517384068.90][CONN][INF] found KV pair in stream: {{__testcase_finish;Test attach for 0.5s and time measure;1;0}}, queued... | |
| [1517384068.96][CONN][RXD] >>> 'Test attach for 0.5s and time measure': 1 passed, 0 failed | |
| [1517384068.96][CONN][RXD] | |
| [1517384069.04][CONN][RXD] >>> Running case #6: 'Test attach_us for 500ms and time measure'... | |
| [1517384069.11][CONN][INF] found KV pair in stream: {{__testcase_start;Test attach_us for 500ms and time measure}}, queued... | |
| [1517384069.64][CONN][INF] found KV pair in stream: {{__testcase_finish;Test attach_us for 500ms and time measure;1;0}}, queued... | |
| [1517384069.72][CONN][RXD] >>> 'Test attach_us for 500ms and time measure': 1 passed, 0 failed | |
| [1517384069.72][CONN][RXD] | |
| [1517384069.75][CONN][RXD] >>> Running case #7: 'Test detach'... | |
| [1517384069.80][CONN][INF] found KV pair in stream: {{__testcase_start;Test detach}}, queued... | |
| [1517384070.47][CONN][INF] found KV pair in stream: {{__testcase_finish;Test detach;1;0}}, queued... | |
| [1517384070.51][CONN][RXD] >>> 'Test detach': 1 passed, 0 failed | |
| [1517384070.51][CONN][RXD] | |
| [1517384070.58][CONN][RXD] >>> Running case #8: 'Test multi call and time measure'... | |
| [1517384070.64][CONN][INF] found KV pair in stream: {{__testcase_start;Test multi call and time measure}}, queued... | |
| [1517384071.62][CONN][INF] found KV pair in stream: {{__testcase_finish;Test multi call and time measure;1;0}}, queued... | |
| [1517384071.69][CONN][RXD] >>> 'Test multi call and time measure': 1 passed, 0 failed | |
| [1517384071.69][CONN][RXD] | |
| [1517384071.73][CONN][RXD] >>> Running case #9: 'Test multi ticker'... | |
| [1517384071.77][CONN][INF] found KV pair in stream: {{__testcase_start;Test multi ticker}}, queued... | |
| [1517384072.05][CONN][INF] found KV pair in stream: {{__testcase_finish;Test multi ticker;1;0}}, queued... | |
| [1517384072.09][CONN][RXD] >>> 'Test multi ticker': 1 passed, 0 failed | |
| [1517384072.09][CONN][RXD] | |
| [1517384072.15][CONN][RXD] >>> Running case #10: 'Test timers: 1x ticker'... | |
| [1517384072.20][CONN][INF] found KV pair in stream: {{__testcase_start;Test timers: 1x ticker}}, queued... | |
| [1517384072.23][CONN][INF] found KV pair in stream: {{timing_drift_check_start;0}}, queued... | |
| [1517384072.25][SERI][TXD] {{base_time;0}} | |
| [1517384072.29][CONN][INF] found KV pair in stream: {{base_time;37000}}, queued... | |
| [1517384081.80][HTST][INF] Device base time 37000 | |
| [1517384081.80][HTST][INF] sleeping for 9.50128555298 to measure drift accurately | |
| [1517384081.80][SERI][TXD] {{final_time;0}} | |
| [1517384081.85][CONN][INF] found KV pair in stream: {{final_time;10539000}}, queued... | |
| [1517384081.86][HTST][INF] Device final time 10539000 | |
| [1517384081.86][HTST][INF] Compute host events | |
| [1517384081.86][HTST][INF] Transport delay 0: 0.0562660694122 | |
| [1517384081.86][HTST][INF] Transport delay 1: 0.0569820404053 | |
| [1517384081.86][HTST][INF] DUT base time : 37000.0 | |
| [1517384081.86][HTST][INF] DUT end time : 10539000.0 | |
| [1517384081.86][HTST][INF] min_pass : 9.13902186155 , max_pass : 9.98211364746 for 5.0%% | |
| [1517384081.86][HTST][INF] min_inconclusive : 9.03143615723 , max_inconclusive : 10.1010241628 | |
| [1517384081.86][HTST][INF] Time reported by device: 10.502 | |
| [1517384081.86][HTST][INF] Time outside of passing range. Timing drift seems to be present !!! | |
| [1517384081.86][SERI][TXD] {{fail;0}} | |
| [1517384081.97][CONN][RXD] :130::FAIL: Expected 'pass' Was 'fail'. Host side script reported a fail... | |
| [1517384082.03][CONN][INF] found KV pair in stream: {{__testcase_finish;Test timers: 1x ticker;0;1}}, queued... | |
| [1517384082.12][CONN][RXD] >>> 'Test timers: 1x ticker': 0 passed, 1 failed with reason 'Assertion Failed' | |
| [1517384082.12][CONN][RXD] | |
| [1517384082.20][CONN][RXD] >>> Test cases: 9 passed, 1 failed with reason 'Assertion Failed' | |
| [1517384082.22][CONN][RXD] >>> TESTS FAILED! | |
| [1517384082.25][CONN][INF] found KV pair in stream: {{__testcase_summary;9;1}}, queued... | |
| [1517384082.27][CONN][INF] found KV pair in stream: {{max_heap_usage;0}}, queued... | |
| [1517384082.27][HTST][ERR] orphan event in main phase: {{max_heap_usage;0}}, timestamp=1517384082.274104 | |
| [1517384082.30][CONN][INF] found KV pair in stream: {{reserved_heap;0}}, queued... | |
| [1517384082.30][HTST][ERR] orphan event in main phase: {{reserved_heap;0}}, timestamp=1517384082.296119 | |
| [1517384082.32][CONN][INF] found KV pair in stream: {{end;failure}}, queued... | |
| [1517384082.32][HTST][INF] __notify_complete(False) | |
| [1517384082.32][HTST][INF] __exit_event_queue received | |
| [1517384082.32][HTST][INF] test suite run finished after 16.14 sec... | |
| [1517384082.33][CONN][INF] received special event '__host_test_finished' value='True', finishing | |
| [1517384082.33][HTST][INF] CONN exited with code: 0 | |
| [1517384082.33][HTST][INF] No events in queue | |
| [1517384082.33][HTST][INF] stopped consuming events | |
| [1517384082.33][HTST][INF] host test result() call skipped, received: False | |
| [1517384082.33][HTST][WRN] missing __exit event from DUT | |
| [1517384082.33][HTST][INF] calling blocking teardown() | |
| [1517384082.33][HTST][INF] teardown() finished | |
| [1517384082.33][HTST][INF] {{result;failure}} | |
| mbedgt: checking for GCOV data... | |
| mbedgt: mbed-host-test-runner: stopped and returned 'FAIL' | |
| mbedgt: test on hardware with target id: 1100021852333120343935373230322031323033AFD4DFD8 | |
| mbedgt: test suite 'mbed-os-tests-mbed_drivers-ticker' ............................................... FAIL in 57.12 sec | |
| test case: 'Test attach for 0.01s and time measure' .......................................... OK in 0.08 sec | |
| test case: 'Test attach for 0.1s and time measure' ........................................... OK in 0.16 sec | |
| test case: 'Test attach for 0.5s and time measure' ........................................... OK in 0.53 sec | |
| test case: 'Test attach_us for 100ms and time measure' ....................................... OK in 0.17 sec | |
| test case: 'Test attach_us for 10ms and time measure' ........................................ OK in 0.09 sec | |
| test case: 'Test attach_us for 500ms and time measure' ....................................... OK in 0.53 sec | |
| test case: 'Test detach' ..................................................................... OK in 0.67 sec | |
| test case: 'Test multi call and time measure' ................................................ OK in 0.98 sec | |
| test case: 'Test multi ticker' ............................................................... OK in 0.28 sec | |
| test case: 'Test timers: 1x ticker' .......................................................... FAIL in 9.83 sec | |
| test case: 'Test timers: 2x ticker' .......................................................... SKIPPED in 0.00 sec | |
| mbedgt: test case summary: 9 passes, 1 failure | |
| mbedgt: utest test case summary mismatch: utest reported passes and failures miscount! | |
| reported by utest: passes = 9, failures 1) | |
| test case result count: passes = 9, failures 2) | |
| mbedgt: all tests finished! | |
| mbedgt: shuffle seed: 0.2510803519 | |
| mbedgt: test suite report: | |
| +------------------+---------------+-----------------------------------+--------+--------------------+-------------+ | |
| | target | platform_name | test suite | result | elapsed_time (sec) | copy_method | | |
| +------------------+---------------+-----------------------------------+--------+--------------------+-------------+ | |
| | NRF51_DK-GCC_ARM | NRF51_DK | mbed-os-tests-mbed_drivers-ticker | FAIL | 57.12 | default | | |
| +------------------+---------------+-----------------------------------+--------+--------------------+-------------+ | |
| mbedgt: test suite results: 1 FAIL | |
| mbedgt: test case report: | |
| +------------------+---------------+-----------------------------------+-------------------------------------------+--------+--------+---------+--------------------+ | |
| | target | platform_name | test suite | test case | passed | failed | result | elapsed_time (sec) | | |
| +------------------+---------------+-----------------------------------+-------------------------------------------+--------+--------+---------+--------------------+ | |
| | NRF51_DK-GCC_ARM | NRF51_DK | mbed-os-tests-mbed_drivers-ticker | Test attach for 0.01s and time measure | 1 | 0 | OK | 0.08 | | |
| | NRF51_DK-GCC_ARM | NRF51_DK | mbed-os-tests-mbed_drivers-ticker | Test attach for 0.1s and time measure | 1 | 0 | OK | 0.16 | | |
| | NRF51_DK-GCC_ARM | NRF51_DK | mbed-os-tests-mbed_drivers-ticker | Test attach for 0.5s and time measure | 1 | 0 | OK | 0.53 | | |
| | NRF51_DK-GCC_ARM | NRF51_DK | mbed-os-tests-mbed_drivers-ticker | Test attach_us for 100ms and time measure | 1 | 0 | OK | 0.17 | | |
| | NRF51_DK-GCC_ARM | NRF51_DK | mbed-os-tests-mbed_drivers-ticker | Test attach_us for 10ms and time measure | 1 | 0 | OK | 0.09 | | |
| | NRF51_DK-GCC_ARM | NRF51_DK | mbed-os-tests-mbed_drivers-ticker | Test attach_us for 500ms and time measure | 1 | 0 | OK | 0.53 | | |
| | NRF51_DK-GCC_ARM | NRF51_DK | mbed-os-tests-mbed_drivers-ticker | Test detach | 1 | 0 | OK | 0.67 | | |
| | NRF51_DK-GCC_ARM | NRF51_DK | mbed-os-tests-mbed_drivers-ticker | Test multi call and time measure | 1 | 0 | OK | 0.98 | | |
| | NRF51_DK-GCC_ARM | NRF51_DK | mbed-os-tests-mbed_drivers-ticker | Test multi ticker | 1 | 0 | OK | 0.28 | | |
| | NRF51_DK-GCC_ARM | NRF51_DK | mbed-os-tests-mbed_drivers-ticker | Test timers: 1x ticker | 0 | 1 | FAIL | 9.83 | | |
| | NRF51_DK-GCC_ARM | NRF51_DK | mbed-os-tests-mbed_drivers-ticker | Test timers: 2x ticker | 0 | 0 | SKIPPED | 0.0 | | |
| +------------------+---------------+-----------------------------------+-------------------------------------------+--------+--------+---------+--------------------+ | |
| mbedgt: test case results: 1 FAIL / 1 SKIPPED / 9 OK | |
| mbedgt: completed in 61.31 sec | |
| mbedgt: exited with code 1 | |
| [mbed] Working path "/Users/drewcassidy/Projects/OSHChip-mbed-tests" (program) | |
| [mbed] Exec "mbedgt --test-spec /Users/drewcassidy/Projects/OSHChip-mbed-tests/BUILD/tests/NRF51_DK/GCC_ARM/test_spec.json -n mbed-os-tests-mbed_drivers-ticker -V" in /Users/drewcassidy/Projects/OSHChip-mbed-tests |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment