ARMmbed/dapjs

Lost serial data using a BBC micro:bit

microbit-sam opened this issue · 12 comments

Data is lost when using a Python REPL on a BBC micro:bit. May be related to #50 ?

To reproduce

  • Download and flash an empty script (defaults to REPL) from https://python.microbit.org/
  • Run serial example (usb/hid/webusb) from repo examples/daplink-serial
  • Check output of help() command

I get:

Select a device to listen to serial output:
1: "BBC micro:bit CMSIS-DAP"
Listening at 115200 baud...
he
l
p
(
)
Type 'dir()' to see what stuff is available. For goodness sake
 type 'import this'.

Control commands:
  CTRL-C        -- 
stop a running program
  CTRL-D        -- on a blank line, do
 a soft reset of the micro:bit
  CTRL-E        -- enter paste
 mode, turning off auto-indent

For a list of available modu
les, type help('modules')

For more information about Python
, visit: http://python.org/
To find out about MicroPython, vi
sit: http://micropython.org/
Python/micro:bit documentation i
s here: https://microbit-micropython.readthedocs.io/
>>> 

Building micropython with a default baud rate of 9600 appears to output the correct data, but it would be great to get this working at the current default of 115200.

However even at 9600 baud DAPjs throws Bad response errors. I'm not certain if data is lost every time this occurs.

dap.bundle.js:1014 Uncaught (in promise) Error: Bad response for 131 -> 132
    at dap.bundle.js:1014
(anonymous) @ dap.bundle.js:1014
Promise.then (async)
(anonymous) @ dap.bundle.js:543
setInterval (async)
DAPLink.startSerialRead @ dap.bundle.js:541
(anonymous) @ python-main.js:932
Promise.then (async)
(anonymous) @ python-main.js:931
Promise.then (async)
doSerial @ python-main.js:910
(anonymous) @ python-main.js:1039
dispatch @ jquery-2.1.4.min.js:3
r.handle @ jquery-2.1.4.min.js:3
dap.bundle.js:1014 Uncaught (in promise) Error: Bad response for 132 -> 131
    at dap.bundle.js:1014
(anonymous) @ dap.bundle.js:1014
Promise.then (async)
DAPLink.serialWrite @ dap.bundle.js:578
io.onVTKeystroke @ python-main.js:965
hterm.Terminal.onVTKeystroke @ hterm_all.js:15259
hterm.Keyboard.onKeyPress_ @ hterm_all.js:6259

Please let me know if there's any more info I can gather to help

@microbit-sam can you confirm whether you see the same data loss using node-hid versus using webUSB?

Using the latest commit on master:

HID

$ node hid.js
Select a device to listen to serial output:
1: BBC micro:bit CMSIS-DAP
Listening at 115200 baud...
>>>
h
el
p
(
)
 type 'import this'.

Control commands:
  CTRL-C        --
stop a running program
  CTRL-D        -- on a blank line, do
 a soft reset of the micro:bit
  CTRL-E        -- enter paste
 mode, turning off auto-indent

For a list of available modu
les, type help('modules')

For more information about Python
, visit: http://python.org/
To find out about MicroPython, vi
sit: http://micropython.org/
Python/micro:bit documentation i
s here: https://microbit-micropython.readthedocs.io/
>>>

USB

$ node usb.js
Select a device to listen to serial output:
1: BBC micro:bit CMSIS-DAP
Listening at 115200 baud...
h
el
p
(
)

Welcome to MicroPython on the micro:bit!

Try these comman
 type 'import this'.

Control commands:
  CTRL-C        --
stop a running program
  CTRL-D        -- on a blank line, do
 a soft reset of the micro:bit
  CTRL-E        -- enter paste
 mode, turning off auto-indent

For a list of available modu
les, type help('modules')

For more information about Python
, visit: http://python.org/
To find out about MicroPython, vi
sit: http://micropython.org/
Python/micro:bit documentation i
s here: https://microbit-micropython.readthedocs.io/
>>>

For reference, this is what the help command is meant to be printing:

>>> help()
Welcome to MicroPython on the micro:bit!

Try these commands:
  display.scroll('Hello')
  running_time()
  sleep(1000)
  button_a.is_pressed()
What do these commands do? Can you improve them? HINT: use the up and down
arrow keys to get your command history. Press the TAB key to auto-complete
unfinished words (so 'di' becomes 'display' after you press TAB). These
tricks save a lot of typing and look cool!

Explore:
Type 'help(something)' to find out about it. Type 'dir(something)' to see what
it can do. Type 'dir()' to see what stuff is available. For goodness sake,
don't type 'import this'.

Control commands:
  CTRL-C        -- stop a running program
  CTRL-D        -- on a blank line, do a soft reset of the micro:bit
  CTRL-E        -- enter paste mode, turning off auto-indent

For a list of available modules, type help('modules')

For more information about Python, visit: http://python.org/
To find out about MicroPython, visit: http://micropython.org/
Python/micro:bit documentation is here: https://microbit-micropython.readthedocs.io/
>>> 

Remembered a discussion from a while ago where startSerialRead was changed to include a parameter to change the polling time

Using startSerialRead(1) appears to work and the whole of help() is displayed
Could there be any issues with such a small interval?

I'd be interested to know how high this can be set while still working. Please let us know if a more sensible default should be implemented (currently it is 200).

startSerialRead(2) has missing information

Is there a buffer in DAPLink that's overflowing? I had a quick search in the DAPLink repository, but don't know it well enough to figure out what I'm looking for

Result with startSerialRead(2):

>>> help()
Welcome to MicroPython on the micro:bit!

Try these commands:
  display.scroll('Hello')
  running_time()
  sleep(1000)
  button_a.is_pressed()
What do these commands do? Can you improve them? HINT: use the up and down
arrow keys to get your command history. Press the TAB key to auto-complete
unfinished words (so 'di' becomes 'display' after you press TAB). These
tricks save a lot of typing and look cool!

Explore:
Type 'help(something)' to find out about it. Type 'dir(something)' to see what
it can do. Type 'dir()' to see what stuff is available. For goodness sake,
don't type 'importg program
  CTRL-D        -- on ag program
  CTRL-D        -- on a blank line, do a soft reset of the micro:bit
  CTRL-E        -- enter paste mode, turning off auto-indent

For a list of available modules, type help('modules')

For more information about Python, visit: http://python.org/
To find out about MicroPython, visit: http://micropython.org/
Python/micro:bit documentation is here: https://microbit-micropython.readthedocs.io/
>>>

Using this program:

#include "MicroBit.h"

MicroBitSerial serial(USBTX, USBRX);

ManagedString text("The quick brown fox jumped over the lazy dog.\r\n");

int main()
{
    while(1) {
        serial.send(text, SYNC_SPINWAIT);
    }
}

Data is lost with 1ms polling

The quick brown fox jumped over the lazy dog.
The quick brown fox jumped over the lazy dog.
The quick brown fox jumped over the lazy dog.
The quick brown fox juazy dog.
The quick broazy dog.
The quick brown fox jumped over the lazy dog.
The quick brown fox jumped over the lazy dog.
The quick brown fox jumped over the lazy dog.
The quick brown fox jumped over the lazy dog.
The quick brown fox jumped over the lazy dog.
The quick brown fox jumped over the lazy dog.
The quick brown fox jumped over the lazy dog.
The quick brown fox jumped over the lazy dog.

@microbit-sam we're seeing "Bad Response" errors on sending as well as receiving, and also on situations where things 'appear' to be working fine. What's the error actually indicating? Currently you can trigger it (even with a shorter timeout) by pressing sending the ctrl+c command so I wonder if we haven't quite understood what's actually failing?

Slowing down the read rate reduces the number of
Uncaught (in promise) Error: Bad response for 131 -> 132 or Uncaught (in promise) Error: Bad response for 132 -> 131 errors

I'm still not certain where the issue is, but I'm currently thinking it's some sort of race condition between the two DAPLink commands, causing the previous (or next) command's response to be returned in place

The commands are handled here (I think?) in DAPLink, however it looks like it should be executing quickly

https://github.com/ARMmbed/DAPLink/blob/25cbc71260c318e15f9c459f39a8fc27641de92d/source/daplink/cmsis-dap/DAP_vendor.c#L107

calls:

int32_t uart_write_data(uint8_t *data, uint16_t size)
{
    cortex_int_state_t state;
    uint32_t cnt;

    cnt = circ_buf_write(&write_buffer, data, size);

    // Atomically enable TX
    state = cortex_int_get_and_disable();
    if (circ_buf_count_used(&write_buffer)) {
        UART->C2 |= UART_C2_TIE_MASK;
    }
    cortex_int_restore(state);

    return cnt;
}

Using

ovfl_on.cfg This file turns on serial overflow reporting. If the host PC is not reading data fast enough from DAPLink and an overflow occurs the text DAPLink:Overflow will show up in the serial data. Serial overflow reporting is turned off by default.

https://github.com/ARMmbed/DAPLink/blob/master/docs/MSD_COMMANDS.md

We get DAPLink overflow errors for help() at all serial read intervals, this example is startSerialRead(30) as an example where they are more frequent

>>> help()
Welcome to MicroPython on the micro:bit!

Try these commands:
  display.scroll('Hello')
  running_time()
  sleep(1000)
  button_a.is_pressed()
What do these commands do? Can you improve them? HINT: use the up and down
arrow keys to get your command history. Press the TAB key to auto-complete
unfinished words (so 'di' becomes 'display' after you press TAB). These
tricks save a lot of typing and look cool!

Explore:
Type 'help(something)' to find out about it. Type 'dir(something)' to see what
it can do. Type 'dir()' to see what stuff<DAPLink:Overflow>
                                                            CTRL-C        -- stop a running program
 <DAPLink:Overflow>
                   /micropython.org/
Python/micro:bit documen<DAPLink:Overflow>

DAPLink overflow errors aren't always detected either, for example:
(It's possible the error is detected, and then overwritten in the buffer by new data coming in)
https://github.com/ARMmbed/DAPLink/blob/b164e86339eb443d5eb8cc04e42f876693a4695c/source/hic_hal/freescale/kl26z/uart.c#L253

Control commands:
  CTRL-C        -- stop a running program
  CTRL-D        -- on a blank line, do a soft reseng off auto-indent

For a lng off auto-indent

Buffer size is currently #define BUFFER_SIZE (512)
https://github.com/ARMmbed/DAPLink/blob/b164e86339eb443d5eb8cc04e42f876693a4695c/source/hic_hal/freescale/kl26z/uart.c#L31

How likely is it that the buffer is already at it's upper limit? Or could there be space to increase it

Alternatively, should the help() message be split into chunks? If the device sent them with a tiny gap between, it may prevent the overflow and also be transparent to the user

@jaustin re your question:
I don't think it's possible to read the data from the serial buffer any faster

this.timer = setInterval(() => {
            return this.send(DAPLinkSerial.READ)
            .then(serialData => {
                // Handle data 
            });
        }, 0); // As fast as JS event loop can handle

Each READ request can respond with 62 bytes (64 byte packet) out of the buffer. So I guess even with a larger buffer, the read requests may not be able to keep up with a large string

Example on my mid-2012 MBP

var x = Date.now();
window.setInterval(() => {
   console.log(Date.now() - x);
   x = Date.now();
}, 0);

When running that in the Chrome console, I usually get between 3 to 5ms, so it's going to be tough to request data fast enough