Ticker test fails with NRF51 when LF clock is used

[cmonr]

Description

• Type: Bug
• Related issue: add OSHChip as an mbed target #5892
• Priority: Major

---

Bug

Target
NRF51 | OSHChip

Toolchain:
GCC_ARM

mbed-os sha:
f9cd95f

Expected behavior
Ticker test should pass, when using the RC clock as the main clock source.

Actual behavior
Ticker test fails

Steps to reproduce

• Checkout mbed-os
• Add `"overrides": {"lf_clock_src": "NRF_LF_SRC_RC"}" to NRF51_DK target, along with comma where necessary.
• Run mbed test -m AUTO -t GCC_ARM -n tests-mbed_drivers-ticker -v

Relevant output

...
[1518643678.90][CONN][RXD] >>> Running case #9: 'Test multi ticker'...
[1518643678.94][CONN][INF] found KV pair in stream: {{__testcase_start;Test multi ticker}}, queued...
[1518643679.22][CONN][INF] found KV pair in stream: {{__testcase_finish;Test multi ticker;1;0}}, queued...
[1518643679.26][CONN][RXD] >>> 'Test multi ticker': 1 passed, 0 failed
[1518643679.26][CONN][RXD]
[1518643679.32][CONN][RXD] >>> Running case #10: 'Test timers: 1x ticker'...
[1518643679.37][CONN][INF] found KV pair in stream: {{__testcase_start;Test timers: 1x ticker}}, queued...
[1518643679.40][CONN][INF] found KV pair in stream: {{timing_drift_check_start;0}}, queued...
[1518643679.42][SERI][TXD] {{base_time;0}}
[1518643679.46][CONN][INF] found KV pair in stream: {{base_time;40000}}, queued...
[1518643689.07][HTST][INF] Device base time 40000
[1518643689.07][HTST][INF] sleeping for 9.59800720215 to measure drift accurately
[1518643689.08][SERI][TXD] {{final_time;0}}
[1518643689.13][CONN][INF] found KV pair in stream: {{final_time;10489000}}, queued...
[1518643689.13][HTST][INF] Device final time 10489000
[1518643689.13][HTST][INF] Compute host events
[1518643689.13][HTST][INF] Transport delay 0: 0.0574750900269
[1518643689.13][HTST][INF] Transport delay 1: 0.0619189739227
[1518643689.13][HTST][INF] DUT base time : 40000.0
[1518643689.14][HTST][INF] DUT end time  : 10489000.0
[1518643689.14][HTST][INF] min_pass : 9.24115055799 , max_pass : 10.0885394812 for 5.0%%
[1518643689.14][HTST][INF] min_inconclusive : 9.12772619724 , max_inconclusive : 10.2139032483
[1518643689.14][HTST][INF] Time reported by device: 10.449
[1518643689.14][HTST][INF] Time outside of passing range. Timing drift seems to be present !!!
[1518643689.14][SERI][TXD] {{fail;0}}
[1518643689.25][CONN][RXD] :130::FAIL: Expected 'pass' Was 'fail'. Host side script reported a fail...
[1518643689.31][CONN][INF] found KV pair in stream: {{__testcase_finish;Test timers: 1x ticker;0;1}}, queued...
[1518643689.41][CONN][RXD] >>> 'Test timers: 1x ticker': 0 passed, 1 failed with reason 'Assertion Failed'
[1518643689.41][CONN][RXD]
[1518643689.49][CONN][RXD] >>> Test cases: 9 passed, 1 failed with reason 'Assertion Failed'
[1518643689.52][CONN][RXD] >>> TESTS FAILED!
[1518643689.56][CONN][INF] found KV pair in stream: {{__testcase_summary;9;1}}, queued...
[1518643689.58][HTST][ERR] orphan event in main phase: {{max_heap_usage;0}}, timestamp=1518643689.580707
[1518643689.58][CONN][INF] found KV pair in stream: {{max_heap_usage;0}}, queued...
[1518643689.61][HTST][ERR] orphan event in main phase: {{reserved_heap;0}}, timestamp=1518643689.612596
[1518643689.61][CONN][INF] found KV pair in stream: {{reserved_heap;0}}, queued...
[1518643689.63][HTST][INF] __notify_complete(False)
[1518643689.63][HTST][INF] __exit_event_queue received
[1518643689.63][HTST][INF] test suite run finished after 16.34 sec...
[1518643689.63][CONN][INF] found KV pair in stream: {{end;failure}}, queued...
[1518643689.63][CONN][INF] received special event '__host_test_finished' value='True', finishing
[1518643689.70][HTST][INF] CONN exited with code: 0
[1518643689.70][HTST][INF] No events in queue
[1518643689.70][HTST][INF] stopped consuming events
[1518643689.70][HTST][INF] host test result() call skipped, received: False
[1518643689.70][HTST][WRN] missing __exit event from DUT
[1518643689.70][HTST][INF] calling blocking teardown()
[1518643689.70][HTST][INF] teardown() finished
[1518643689.70][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: 110000005032312036393738313037313032303197969903
mbedgt: test suite 'tests-mbed_drivers-ticker' ....................................................... FAIL in 70.66 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.54 sec
	test case: 'Test attach_us for 100ms and time measure' ....................................... OK in 0.16 sec
	test case: 'Test attach_us for 10ms and time measure' ........................................ OK in 0.08 sec
	test case: 'Test attach_us for 500ms and time measure' ....................................... OK in 0.53 sec
	test case: 'Test detach' ..................................................................... OK in 0.70 sec
	test case: 'Test multi call and time measure' ................................................ OK in 1.01 sec
	test case: 'Test multi ticker' ............................................................... OK in 0.28 sec
	test case: 'Test timers: 1x ticker' .......................................................... FAIL in 9.94 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.0354585733
mbedgt: test suite report:
+------------------+---------------+---------------------------+--------+--------------------+-------------+
| target           | platform_name | test suite                | result | elapsed_time (sec) | copy_method |
+------------------+---------------+---------------------------+--------+--------------------+-------------+
| NRF51_DK-GCC_ARM | NRF51_DK      | tests-mbed_drivers-ticker | FAIL   | 70.66              | 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      | tests-mbed_drivers-ticker | Test attach for 0.01s and time measure    | 1      | 0      | OK      | 0.08               |
| NRF51_DK-GCC_ARM | NRF51_DK      | tests-mbed_drivers-ticker | Test attach for 0.1s and time measure     | 1      | 0      | OK      | 0.16               |
| NRF51_DK-GCC_ARM | NRF51_DK      | tests-mbed_drivers-ticker | Test attach for 0.5s and time measure     | 1      | 0      | OK      | 0.54               |
| NRF51_DK-GCC_ARM | NRF51_DK      | tests-mbed_drivers-ticker | Test attach_us for 100ms and time measure | 1      | 0      | OK      | 0.16               |
| NRF51_DK-GCC_ARM | NRF51_DK      | tests-mbed_drivers-ticker | Test attach_us for 10ms and time measure  | 1      | 0      | OK      | 0.08               |
| NRF51_DK-GCC_ARM | NRF51_DK      | tests-mbed_drivers-ticker | Test attach_us for 500ms and time measure | 1      | 0      | OK      | 0.53               |
| NRF51_DK-GCC_ARM | NRF51_DK      | tests-mbed_drivers-ticker | Test detach                               | 1      | 0      | OK      | 0.7                |
| NRF51_DK-GCC_ARM | NRF51_DK      | tests-mbed_drivers-ticker | Test multi call and time measure          | 1      | 0      | OK      | 1.01               |
| NRF51_DK-GCC_ARM | NRF51_DK      | tests-mbed_drivers-ticker | Test multi ticker                         | 1      | 0      | OK      | 0.28               |
| NRF51_DK-GCC_ARM | NRF51_DK      | tests-mbed_drivers-ticker | Test timers: 1x ticker                    | 0      | 1      | FAIL    | 9.94               |
| NRF51_DK-GCC_ARM | NRF51_DK      | 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 71.07 sec
mbedgt: exited with code 1

[cmonr]

@drewcassidy Feel free to add more details if I missed anything.

@marcuschangarm

[drewcassidy]

See this comment, the RC clock should be more than accurate enough to pass the test, but arn't. I'm wondering if there is a calibration step that isn't happening correctly somewhere in the drivers.

internal RC clock SHOULD have an accuracy of ±250ppm, far less than the ±5% its currently failing to reach. Either the datasheet is wildly off, I have multiple defective chips, or there is something wrong with the way this test is being performed

[drewcassidy]

Add `"overrides": {"lf_clock_src": "NRF_LF_SRC_RC"}" to NRF51_DK target, along with comma where necessary.

this can also be done with mbed_app.json if you dont want to modify the targets file directly.

{
    "target_overrides": {
        "*": {
            "target.lf_clock_src": "NRF_LF_SRC_XTAL"
        }
    }
}

[ciarmcom]

ARM Internal Ref: MBOTRIAGE-259

[0xc0170]

Is this issue still relevant?

cc @marcuschangarm

[donatieng]

@cmonr is still still an issue?

[cmonr]

I don't think this is an issue anymore. Closing.