search

ARMmbed / mbed-os

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

mbed_platform-critical_section test case is failing #6159

Closed akrnvm closed 6 years ago

akrnvm commented 6 years ago

Note: This is just a template, so feel free to use/remove the unnecessary things

Description

Bug

tests-mbed_platform-critical_section test case is failing

Target K64F | Custom

Toolchain: GCC_ARM|ARM|IAR

Expected behavior

tests-mbed_platform-critical_section test should pass

Actual behavior tests-mbed_platform-critical_section test case is failing

Steps to reproduce mbed test -m XXXX -t ARM -v -n tests-mbed_platform-critical_section

Question

My timer is generating interrupt at every 100us and this value is return to us_ticker read function. But in this test case, all interrupts are blocked by entering to critical section and it wait for 100us.

How can make pass this test case.

0xc0170 commented 6 years ago

@akrnvm Might be useful to provide the output (what exactly fails and how), also at least a small code snippet how your ticker is implemented to get a picture what is happening (what line in the test is failing and how ticker is related).

@mprse Can you review?

mprse commented 6 years ago

Hi, is this the same target as here: https://github.com/ARMmbed/mbed-os/issues/5992 ?

My board is Cortex M3 controller.

K64F is based on Cortex-M4.

akrnvm commented 6 years ago

Hi

Test is hanged at wait_us(wait_time_us),because us_ticker_read return same value always due to interrupt blocker.

We are using 16bit timer

  1. timer reg value is set to 100us equivalent clock ticks.
  2. start timer and interrupt
  3. usticker variable is increment in handler in each 100us.
  4. us_ticker_read function will return this value.

ISSUE: ticker handler is missing due to core_util_critical_section_enter(); function is called in top layers.

tiker read function

uint32_t us_ticker_read(void)
{
    uint32_t ret_val = 0;
    uint32_t tickerbefore = 0;
    if (!us_ticker_inited) {
        us_ticker_init();
    }
    uint32_t tickerbefore = 0;
    do {
        tickerbefore = us_ticker;
        ret_val = (us_ticker * 100);
    } while (tickerbefore != us_ticker);
    return ret_val;
}

tiker handler

void XXX_IRQHandler(void)
{
    us_ticker++;
    if (us_ticker > OVERFLOW_32BIT) {
        us_ticker = 0;
    }
}

How to write proper us_ticker_read function

akrnvm commented 6 years ago

Hi, is this the same target as here: #5992 ? yes

mprse commented 6 years ago

Thanks for clarification, but I don't understand what is the purpose of this code. Do you want to implement ticker driver for your device?

How XXX_IRQHandler routine is connected as interrupt handler? What is the frequency of the 16 bit counter?

How to write proper us_ticker_read function?

The simplest answer is that this function should return hardware counter value scaled do us according to the old HAL API and simply return hardware counter value (ticks) according to the new ticker HAL API.

I think that the easiest way to create ticker driver for your device is using new Ticker HAL API. So first you need to provide counter frequency and width, e.g.: 

const ticker_info_t* us_ticker_get_info()
{
    static const ticker_info_t info = {
        1000000,    // 1 MHz
             32     // 32 bit counter
    };
    return &info;
}

Now you need to implement the following driver functions:

void us_ticker_init(void)
uint32_t us_ticker_read()
void us_ticker_disable_interrupt(void)
void us_ticker_clear_interrupt(void)
void us_ticker_set_interrupt(timestamp_t timestamp)
void us_ticker_fire_interrupt(void)

Please check the ticker header file where ticker requirements for the new HAL API are provided and detailed description of each required driver function.

As a reference you can check my version of ticker driver - K64F consistent with the new HAL API.

akrnvm commented 6 years ago

with above code all test cases of mbed-os-5.7.5 ispassing, only issue with tests-mbed_platform-critical_section test case. I have to change my code for reading us_ticks for this case. My controller is 16bit and run in 40MHz. it given 82ms at max with 16 bit counter.

What is the frequency of the 16 bit counter?

Its take 0x28 ticks to generate 1us (1/40000000 *40)= 1us

How XXX_IRQHandler routine is connected as interrupt handler?

I have placed two timer channels, one for usticker and and second for irq_handler

As a reference you can check my version of ticker driver consistent with the new HAL API.

Thank you for sharing code, this code timer runs in 32bit and mine is 16 bit. Is it fine to simply return 16 bit hardware counter value (ticks) to the new ticker HAL API.

Is below config is fine?

const ticker_info_t* us_ticker_get_info()
{
    static const ticker_info_t info = {
        40000000,    // 40 MHz
             16     // 16 bit counter
    };
    return &info;
}

Could you please share any example code for 16bit timer with new Ticker HAL API

akrnvm commented 6 years ago

Hi @mprse Thank you for the support. It working now with above modifications.

mprse commented 6 years ago

Is it fine to simply return 16 bit hardware counter value (ticks) to the new ticker HAL API.

Yes it is, but you need to specify 16 bits counter width in us ticker info structure (us_ticker_get_info()). Example implementation can be found here.

If your counter is driven by 40 MHz clock and has 16 bits, then max counter value is equal to 65535 ticks which corresponds to 1638 us @ 40 MHz. I don't think this will work since upper ticker layer may have problems with counting elapsed time. According to the ticker requirements us ticker max frequency can be 8 MHz, but if it is possible I suggest to use hardware prescaler and make counter to be driven by 1MHz clock which is typically used for us tickers on many targets. Then you will be able to simply return counter value by us_ticker_read() function.

mprse commented 6 years ago

Please note that on master mbed HAL layer for ticker is consistent with the new Ticker HAL API, but target specific low level drivers and tests for them are not. If you are using new API, then you should relay on feature-hal-spec-ticker branch where new drivers and tests are being developed (not ready). New version of mentioned test can be found here (still not merged to the feature branch).

If your task is to make all test pass on master, then you must use old style and scale your counter to 32 bits @ 1 MHz.

akrnvm commented 6 years ago

Hi @mprse ,

I have modified as per your above comments. Use a prescaler clock of 1/32. (39.9Mhz / 32 = 1.24)

const ticker_info_t* us_ticker_get_info()
{
    static const ticker_info_t info = {
        1248000,    // 1.2 MHz
             16     // 16 bit counter
    };
    return &info;
}

Now, Ticker testcase is failing. ISSUE: With 40Mhz/20Mhz clock ticker testcase (tests-mbed_drivers-ticker) is PASSING and lp_us_tickers ( tests-mbed_hal-lp_us_tickers) is FAILING

With 1.2Mhz clock icker testcase (tests-mbed_drivers-ticker) is FAILING and lp_us_tickers ( tests-mbed_hal-lp_us_tickers) is PASSING

Testing of sub tests are passing in indivitualy

mprse commented 6 years ago

With 1.2Mhz clock icker testcase (tests-mbed_drivers-ticker) is FAILING

Which check fails?

If you want to make your driver consistent with master, then you should remove your definition of us_ticker_get_info, then default values will be used (1 MHz and 32 bits counter). You must ensure that your us_ticker_read function returns 32 bit value which represents us (convert elapsed ticks to us taking into account 16 bit counter rollover) and us_ticker_set_interrupt is able to handle setting interrupts which might be tricky in this case (conversion from us to ticks, handle cases when point in time when interrupt is to be generated is beyond 16 bit range). This is much more complicated then using new HAL API, but if you want to have all tests passed on master (not only working us ticker), then it looks like there is no other option to do it properly.

akrnvm commented 6 years ago

hi @mprse

I have tested the failure case separately. This test has 11 sub test cases and 9 test cases are passing

mbedgt: test case report:
---------------------------+-------------------------------------------+--------+--------+--------+--------------------+
 test suite                | test case                                 | passed | failed | result | elapsed_time (sec) |
---------------------------+-------------------------------------------+--------+--------+--------+--------------------+
 tests-mbed_drivers-ticker | Test attach for 0.1s and time measure     | 1      | 0      | OK     | 0.17               |
 tests-mbed_drivers-ticker | Test attach for 0.5s and time measure     | 1      | 0      | OK     | 0.56               |
 tests-mbed_drivers-ticker | Test attach_us for 100ms and time measure | 1      | 0      | OK     | 0.16               |
 tests-mbed_drivers-ticker | Test attach_us for 10ms and time measure  | 1      | 0      | OK     | 0.07               |
 tests-mbed_drivers-ticker | Test attach_us for 500ms and time measure | 1      | 0      | OK     | 0.58               |
 tests-mbed_drivers-ticker | Test detach                               | 1      | 0      | OK     | 0.74               |
 tests-mbed_drivers-ticker | Test multi call and time measure          | 1      | 0      | OK     | 1.05               |
 tests-mbed_drivers-ticker | Test timers: 1x ticker                    | 1      | 0      | OK     | 9.4                |
 tests-mbed_drivers-ticker | Test timers: 2x callbacks                 | 1      | 0      | OK     | 8.51               |
+-------------+---------------+---------------------------+-------------------------------------------+--------+-------+
mbedgt: test case results: 9 OK

The failure test case is "Test attach for 0.01s and time measure"

[1519377482.72][CONN][RXD] >>> Running case #1: 'Test attach for 0.01s and time measure'...
[1519377482.78][CONN][INF] found KV pair in stream: {{__testcase_start;Test attach for 0.01s and time measure}}, queued...
[1519377482.90][CONN][RXD] :280::FAIL: Values Not Within Delta 1000 Expected 10000 Was 43667
[1519377482.97][CONN][INF] found KV pair in stream: {{__testcase_finish;Test attach for 0.01s and time measure;0;1}}, queued...
[1519377483.07][CONN][RXD] >>> 'Test attach for 0.01s and time measure': 0 passed, 1 failed with reason 'Assertion Failed'
[1519377483.07][CONN][RXD]
[1519377483.14][CONN][RXD] >>> Test cases: 0 passed, 1 failed with reason 'Assertion Failed'
[1519377483.16][CONN][RXD] >>> TESTS FAILED!
[1519377483.19][CONN][INF] found KV pair in stream: {{__testcase_summary;0;1}}, queued...

mbedgt: test suite 'tests-mbed_drivers-ticker' ....................................................... FAIL in 15.32 sec
        test case: 'Test attach for 0.01s and time measure' .......................................... FAIL in 0.19 sec
mbedgt: test case summary: 0 passes, 1 failure
mbedgt: all tests finished!

"Test attach_us for 10ms and time measure" and "Test attach for 0.01s and time measure" are reading us_ticker in same way, then how come one is passing and other is failing

akrnvm commented 6 years ago

Hi, I have wonder how the same test cases will show different behaviour in frequency changes. My testcase is "tests-mbed_drivers-ticker"

Im using 16 bit timer with 39MHz clock in Cortex-M3 controller.

const ticker_info_t* us_ticker_get_info()
{
    static const ticker_info_t info = { 
        39936000, //39 MHz (39Mhz/1)
            16     // 16 bit counter
    };
    return &info;
}

All test cases are PASSING.

mbedgt: test case report:
+-------------+---------------+---------------------------+-------------------------------------------+--------+--------+--------+--------------------+
| target      | platform_name | test suite                | test case                                 | passed | failed | result | elapsed_time (sec) |
+-------------+---------------+---------------------------+-------------------------------------------+--------+--------+--------+--------------------+
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test attach for 0.01s and time measure    | 1      | 0      | OK     | 0.08               |
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test attach for 0.1s and time measure     | 1      | 0      | OK     | 0.18               |
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test attach for 0.5s and time measure     | 1      | 0      | OK     | 0.57               |
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test attach_us for 100ms and time measure | 1      | 0      | OK     | 0.17               |
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test attach_us for 10ms and time measure  | 1      | 0      | OK     | 0.08               |
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test attach_us for 500ms and time measure | 1      | 0      | OK     | 0.57               |
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test detach                               | 1      | 0      | OK     | 0.74               |
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test multi call and time measure          | 1      | 0      | OK     | 1.06               |
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test multi ticker                         | 1      | 0      | OK     | 0.26               |
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test timers: 1x ticker                    | 1      | 0      | OK     | 9.31               |
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test timers: 2x ticker                    | 1      | 0      | OK     | 9.32               |
+-------------+---------------+---------------------------+-------------------------------------------+--------+--------+--------+--------------------+
mbedgt: test case results: 11 OK

When I have changed the clock frequency to around 1Mhz ( 39MHz / 32_preclock = 1248000), First test case is Failing.

const ticker_info_t* us_ticker_get_info()
{
    static const ticker_info_t info = { 
       1248000, //1.24 MHz (39Mhz/32)
            16     // 16 bit counter
    };
    return &info;
}

One test is FAILING

[1519377482.72][CONN][RXD] >>> Running case #1: 'Test attach for 0.01s and time measure'...
[1519377482.78][CONN][INF] found KV pair in stream: {{__testcase_start;Test attach for 0.01s and time measure}}, queued...
[1519377482.90][CONN][RXD] :280::FAIL: Values Not Within Delta 1000 Expected 10000 Was 43667
[1519377482.97][CONN][INF] found KV pair in stream: {{__testcase_finish;Test attach for 0.01s and time measure;0;1}}, queued...
[1519377483.07][CONN][RXD] >>> 'Test attach for 0.01s and time measure': 0 passed, 1 failed with reason 'Assertion Failed'
[1519377483.07][CONN][RXD]
[1519377483.14][CONN][RXD] >>> Test cases: 0 passed, 1 failed with reason 'Assertion Failed'
[1519377483.16][CONN][RXD] >>> TESTS FAILED!
[1519377483.19][CONN][INF] found KV pair in stream: {{__testcase_summary;0;1}}, queued...

mbedgt: test suite 'tests-mbed_drivers-ticker' ....................................................... FAIL in 15.32 sec
        test case: 'Test attach for 0.01s and time measure' .......................................... FAIL in 0.19 sec
mbedgt: test case summary: 0 passes, 1 failure
mbedgt: all tests finished!

After commenting the first test case, rest all tests are PASSING.

+-------------+---------------+---------------------------+-------------------------------------------+--------+--------+--------+--------------------+
| target      | platform_name | test suite                | test case                                 | passed | failed | result | elapsed_time (sec) |
+-------------+---------------+---------------------------+-------------------------------------------+--------+--------+--------+--------------------+
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test attach for 0.1s and time measure     | 1      | 0      | OK     | 0.16               |
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test attach for 0.5s and time measure     | 1      | 0      | OK     | 0.56               |
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test attach_us for 100ms and time measure | 1      | 0      | OK     | 0.18               |
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test attach_us for 10ms and time measure  | 1      | 0      | OK     | 0.09               |
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test attach_us for 500ms and time measure | 1      | 0      | OK     | 0.56               |
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test detach                               | 1      | 0      | OK     | 0.73               |
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test multi call and time measure          | 1      | 0      | OK     | 1.06               |
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test multi ticker                         | 1      | 0      | OK     | 0.28               |
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test timers: 1x ticker                    | 1      | 0      | OK     | 9.23               |
| XXXXXXX-ARM | XXXXXXX       | tests-mbed_drivers-ticker | Test timers: 2x ticker                    | 1      | 0      | OK     | 9.31               |
+-------------+---------------+---------------------------+-------------------------------------------+--------+--------+--------+--------------------+
mbedgt: test case results: 10 OK

This issue is not present in Cortex-M4 controllers which are running in above 120MHz freq. we tested same code in 2 Cortex-M4 boards and its passing.

Is this issue related to frequency or cortex-M3, our issue boards are running in 40MHz. How to resolve this issue. Please share any inputs were I should check to resolve this issue.

ciarmcom commented 6 years ago

ARM Internal Ref: MBOTRIAGE-251

donatieng commented 6 years ago

@akrnvm are you testing against the feature-has-spec-ticker branch? Otherwise please follow @mprse's guidelines

donatieng commented 6 years ago

Closing as inactive, feel free to re-open if still experiencing the issue