{"action":"created","issue":{"url":"https://api.github.com/repos/ARMmbed/mbed-os/issues/6732","repository_url":"https://api.github.com/repos/ARMmbed/mbed-os","labels_url":"https://api.github.com/repos/ARMmbed/mbed-os/issues/6732/labels{/name}","comments_url":"https://api.github.com/repos/ARMmbed/mbed-os/issues/6732/comments","events_url":"https://api.github.com/repos/ARMmbed/mbed-os/issues/6732/events","html_url":"https://github.com/ARMmbed/mbed-os/issues/6732","id":317280086,"number":6732,"title":"NRF52_DK: Not all callbacks called when multiple Timeout objects scheduled one by one","user":{"login":"fkjagodzinski","id":26014847,"avatar_url":"https://avatars0.githubusercontent.com/u/26014847?v=4","gravatar_id":"","url":"https://api.github.com/users/fkjagodzinski","html_url":"https://github.com/fkjagodzinski","followers_url":"https://api.github.com/users/fkjagodzinski/followers","following_url":"https://api.github.com/users/fkjagodzinski/following{/other_user}","gists_url":"https://api.github.com/users/fkjagodzinski/gists{/gist_id}","starred_url":"https://api.github.com/users/fkjagodzinski/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/fkjagodzinski/subscriptions","organizations_url":"https://api.github.com/users/fkjagodzinski/orgs","repos_url":"https://api.github.com/users/fkjagodzinski/repos","events_url":"https://api.github.com/users/fkjagodzinski/events{/privacy}","received_events_url":"https://api.github.com/users/fkjagodzinski/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":0,"created_at":"2018-04-24T15:30:16Z","updated_at":"2018-04-24T18:34:24Z","closed_at":null,"author_association":"CONTRIBUTOR","body":"### Description\r\n- Type: Bug\r\n- Priority: Major\r\n\r\n**Target**\r\nNRF52_DK\r\n\r\n**Toolchain:**\r\nARM, IAR\r\n\r\n**Toolchain version:**\r\nARM `5.24 (Flex) ARM Compiler 5.06 update 5 (build 528)`,\r\nIAR `ANSI C/C++ Compiler V7.80.4.12462/W32 for ARM`\r\n\r\n**mbed-cli version:** \r\n`1.5.0`\r\n\r\n**mbed-os sha:**\r\n42d77ecd1\r\n\r\n**Code**\r\n```cpp\r\n#include \"mbed.h\"\r\n\r\n#define VERBOSE 0\r\n\r\n#define NUM_TIMEOUTS 16\r\n#define TEST_DELAY_US 10000ULL\r\n\r\nvoid cnt_callback(volatile uint32_t *cnt)\r\n{\r\n    (*cnt)++;\r\n}\r\n\r\nint main()\r\n{\r\n    const ticker_data_t * const us_ticker = get_us_ticker_data();\r\n    const ticker_event_queue_t *ticker_event_q = us_ticker->queue;\r\n\r\n    uint32_t cnt1 = 0;\r\n    do {\r\n#if VERBOSE\r\n        us_timestamp_t event_timestamps[NUM_TIMEOUTS] = { 0 };\r\n#endif\r\n        us_timestamp_t ts0, ts1, ts2, end_ts, head_ts1, head_ts2;\r\n        volatile uint32_t callback_count = 0;\r\n        Timeout timeouts[NUM_TIMEOUTS];\r\n\r\n        for (size_t i = 0; i < NUM_TIMEOUTS; i++) {\r\n            timeouts[i].attach_us(mbed::callback(cnt_callback, &callback_count), TEST_DELAY_US);\r\n        }\r\n        ts0 = ticker_read_us(us_ticker);\r\n#if VERBOSE\r\n        ticker_event_t *te = ticker_event_q->head;\r\n        int i = 0;\r\n        while (te != NULL) {\r\n            event_timestamps[i] = te->timestamp;\r\n            i++;\r\n            te = te->next;\r\n        }\r\n#endif\r\n\r\n        end_ts = ts0 + TEST_DELAY_US;\r\n        while (ticker_read_us(us_ticker) < end_ts) {\r\n        };\r\n        // At this point all callbacks should have been called,\r\n        // so expected values are:\r\n        // cnt1 == NUM_TIMEOUTS\r\n        // ticker_event_q-> head == NULL\r\n        cnt1 = callback_count;\r\n        ts1 = ticker_read_us(us_ticker);\r\n        head_ts1 = (ticker_event_q->head == NULL) ? 0 : ticker_event_q->head->timestamp;\r\n\r\n        // Wait more to check if any callback was late.\r\n        end_ts += 2 * TEST_DELAY_US;\r\n        while (callback_count < NUM_TIMEOUTS && ticker_read_us(us_ticker) < end_ts) {\r\n        };\r\n        uint32_t cnt2 = callback_count;\r\n        ts2 = ticker_read_us(us_ticker);\r\n        head_ts2 = (ticker_event_q->head == NULL) ? 0 : ticker_event_q->head->timestamp;\r\n\r\n#if VERBOSE\r\n        us_timestamp_t prev_ts = event_timestamps[0];\r\n        for (size_t i = 0; i < NUM_TIMEOUTS; i++) {\r\n            printf(\"ts[%02i]=%llu, delta=%03llu\\r\\n\", i, event_timestamps[i], event_timestamps[i] - prev_ts);\r\n            prev_ts = event_timestamps[i];\r\n        }\r\n#endif\r\n        printf(\"ts0=%llu, ts1=%llu, ts2=%llu, ts2-ts0=%llu, \"\r\n                \"cnt1=%lu, cnt2=%lu, head_ts1=%llu, head_ts2=%llu\\r\\n\", ts0, ts1, ts2, ts2 - ts0, cnt1, cnt2, head_ts1,\r\n                head_ts2);\r\n    } while (cnt1 == NUM_TIMEOUTS);\r\n    printf(\"gotcha!\\r\\n\");\r\n\r\n    return 0;\r\n}\r\n```\r\n\r\n**Expected behavior**\r\nWhen multiple `Timeout` objects are scheduled one by one, all callbacks are called after given delay.\r\n\r\n**Actual behavior**\r\nWith multiple repetitions it is possible to catch a case where not all the callbacks are called. The ticker event queue is not empty and still contains outdated events.\r\n\r\n**Steps to reproduce**\r\n`mbed compile -t ARM -m NRF52_DK -f`\r\n\r\n```\r\nts0=732, ts1=10803, ts2=10833, ts2-ts0=10101, cnt1=16, cnt2=16, head_ts1=0, head_ts2=0\r\nts0=103119, ts1=113128, ts2=113128, ts2-ts0=10009, cnt1=16, cnt2=16, head_ts1=0, head_ts2=0\r\nts0=210632, ts1=220642, ts2=220642, ts2-ts0=10010, cnt1=16, cnt2=16, head_ts1=0, head_ts2=0\r\nts0=318176, ts1=328186, ts2=348205, ts2-ts0=30029, cnt1=15, cnt2=15, head_ts1=328145, head_ts2=328145\r\ngotcha!\r\n\r\n# RESET button pressed\r\nts0=732, ts1=10742, ts2=10742, ts2-ts0=10010, cnt1=16, cnt2=16, head_ts1=0, head_ts2=0\r\nts0=103180, ts1=113189, ts2=113189, ts2-ts0=10009, cnt1=16, cnt2=16, head_ts1=0, head_ts2=0\r\nts0=210663, ts1=220703, ts2=220703, ts2-ts0=10040, cnt1=16, cnt2=16, head_ts1=0, head_ts2=0\r\nts0=318298, ts1=328308, ts2=328308, ts2-ts0=10010, cnt1=16, cnt2=16, head_ts1=0, head_ts2=0\r\nts0=425872, ts1=435882, ts2=455902, ts2-ts0=30030, cnt1=3, cnt2=3, head_ts1=435323, head_ts2=435323\r\ngotcha!\r\n\r\n# RESET button pressed\r\nts0=732, ts1=10742, ts2=10742, ts2-ts0=10010, cnt1=16, cnt2=16, head_ts1=0, head_ts2=0\r\nts0=103210, ts1=113220, ts2=113220, ts2-ts0=10010, cnt1=16, cnt2=16, head_ts1=0, head_ts2=0\r\nts0=210754, ts1=220825, ts2=220825, ts2-ts0=10071, cnt1=16, cnt2=16, head_ts1=0, head_ts2=0\r\nts0=318451, ts1=328460, ts2=328460, ts2-ts0=10009, cnt1=16, cnt2=16, head_ts1=0, head_ts2=0\r\nts0=426025, ts1=436035, ts2=436035, ts2-ts0=10010, cnt1=16, cnt2=16, head_ts1=0, head_ts2=0\r\nts0=533600, ts1=543640, ts2=543640, ts2-ts0=10040, cnt1=16, cnt2=16, head_ts1=0, head_ts2=0\r\nts0=641143, ts1=651153, ts2=671173, ts2-ts0=30030, cnt1=12, cnt2=12, head_ts1=650991, head_ts2=650991\r\ngotcha!\r\n\r\n# RESET button pressed\r\nts0=732, ts1=10742, ts2=10742, ts2-ts0=10010, cnt1=16, cnt2=16, head_ts1=0, head_ts2=0\r\nts0=103180, ts1=113189, ts2=113189, ts2-ts0=10009, cnt1=16, cnt2=16, head_ts1=0, head_ts2=0\r\nts0=210724, ts1=220733, ts2=220733, ts2-ts0=10009, cnt1=16, cnt2=16, head_ts1=0, head_ts2=0\r\nts0=318329, ts1=328338, ts2=348358, ts2-ts0=30029, cnt1=13, cnt2=13, head_ts1=328237, head_ts2=328237\r\ngotcha!\r\n```"},"comment":{"url":"https://api.github.com/repos/ARMmbed/mbed-os/issues/comments/384035628","html_url":"https://github.com/ARMmbed/mbed-os/issues/6732#issuecomment-384035628","issue_url":"https://api.github.com/repos/ARMmbed/mbed-os/issues/6732","id":384035628,"user":{"login":"marcuschangarm","id":7205609,"avatar_url":"https://avatars2.githubusercontent.com/u/7205609?v=4","gravatar_id":"","url":"https://api.github.com/users/marcuschangarm","html_url":"https://github.com/marcuschangarm","followers_url":"https://api.github.com/users/marcuschangarm/followers","following_url":"https://api.github.com/users/marcuschangarm/following{/other_user}","gists_url":"https://api.github.com/users/marcuschangarm/gists{/gist_id}","starred_url":"https://api.github.com/users/marcuschangarm/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/marcuschangarm/subscriptions","organizations_url":"https://api.github.com/users/marcuschangarm/orgs","repos_url":"https://api.github.com/users/marcuschangarm/repos","events_url":"https://api.github.com/users/marcuschangarm/events{/privacy}","received_events_url":"https://api.github.com/users/marcuschangarm/received_events","type":"User","site_admin":false},"created_at":"2018-04-24T18:34:24Z","updated_at":"2018-04-24T18:34:24Z","author_association":"CONTRIBUTOR","body":"@mprse @bulislaw \r\n\r\nI would expect this PR https://github.com/ARMmbed/mbed-os/pull/5629 to fix it?"}}
{"actor":{"display_login":"marcuschangarm"}}