Jacdac: Live view reacts slow to Jacdac modules #271

fabianhugo · 2023-12-06T13:42:42Z

Describe the bug
When using the current Calliope Makecode in version 6.0.27 and the Jacdac extension in version 1.9.24, the time of recognizing new modules and showing updated module output is quite long, testet with different minis and different Jacdac modules. E.g. Keycap button 14 seconds and 8seconds on second trial to appear in the live view, the button presses are shown with a big delay (~2s). When using the micro:bit Makecode in Version 6.0.24 and the Jacdac extension in version 1.9.24 the reaction times are much shorter. E.g. Keycap button 0,5s on the first and second trial, button presses are shown in real time. When switching then back to the Calliope Makecode with the previous "micro:bit" hex on the mini, the appearance time stays short. This means that the problem is most likely in the codal-libraries or the jacdac extension.

To Reproduce
Steps to reproduce the behavior:

Go to 'makecode.calliope.cc'
Connect board with WEBUSB'
Add Jacdac Extension
Download program
Connect Jacdac module
Note the time until the module appears
Go to 'makecode.microbit.org'
Connect board with WEBUSB'
Add Jacdac Extension
Download program
Connect Jacdac module
Note the time until the module appears
Go to 'makecode.calliope.cc'
Open Program with loaded Jacdac Extension
Connect board with WEBUSB'
DO NOT download program
Connect Jacdac module
Note the time until the module appears

Expected behavior
The module should appear earlier in the device section in the left display pane. The module output should be shown in real time.

Desktop (please complete the following information):

OS: Ubuntu 20.04, Windows 10
Browser Chrome
Version 119.0.6045.199

fabianhugo · 2023-12-13T16:28:48Z

I attached 3 Gif videos to show the behaviour. The bug is solved when using a Hex file generated from the micro:bit makecode. As you can see in the first video, sometimes the button is not fully operational, the picture doesn't load or the button presses are not noticed. Capturing the screen video might have had an additional adverse effect.

Jacdac using the Calliope Makecode Editor with a Calliope Hex file

Jacdac using the Microbit Makecode Editor with a micro:bit Hex file

Jacdac using the Calliope Makecode Editor with a micro:bit Hex file

Amerlander · 2023-12-13T18:20:18Z

@pelikhan can you look into this issue and provide some help?

Here is a summary:

JacDac devices and inputs are delayed in the makecode simulator and the jacdac dashboard
- see the first video at 0:55 for a sample of a huge delay. Or the rest of the video for smaller, but still laggy delays.
There are no delays, while the mini is flashed with a microbit hex file (second video).
- So we think it is not a hardware issue
- The codals are very similar, we couldn't remember about changes that would affect jacdac
- The codebase of pxt-calliope master and its dependencies is correpsonding to pxt-microbit v6.0.17, but we also tested locally with a version that is corresponding to 6.0.25 which is the current stable without any improvements.
We are not sure how to debug this and where the source of the issue could be located.

Calliope mini 3 running the mini 3 firmware

flash firmware from makecode.calliope.cc with jacdac extension
connect to makecode.calliope.cc
interact with jacdac and experience delays
- The JACDAC hardware is shown with a delay of 1 to 10 seconds. The thumbnails also loading a moment later.
- Inputs are delayed in the simulator by about 500-1000ms

calliopejacdac.mp4

Calliope mini 3 running the microbit v2 firmware - how it should be

flash firmware from makecode.microbit.org with jacdac extension
connect to makecode.calliope.cc
interact with jacdac and experience no delays
- Connected JACDAC hardware is recognized immediately and the thumbnails of the hardware is loaded without delay
- Inputs are displayed in the simulator without any delay

callioppemicrobitjacdac.mp4

pelikhan · 2023-12-13T20:57:39Z

Could you try to connect the calliope mini at https://microsoft.github.io/jacdac-docs/dashboard/ and record a trace with calliope firmware vs microbit firmware?

pelikhan · 2023-12-13T22:15:19Z

Is this a regression from a previous calliope firmware version?

Amerlander · 2023-12-14T10:41:00Z

Here is a trace where I just connect the mini and then connect PJ01 Keycap Button:
trace-cp.jd.txt
trace-mb.jd.txt

Here is a more complex trace, where the mini is already connected, and I just connect the Keycap Button, wait for it to appear, press the button and remove it. The calliope is not recognized in this trace (product: ? (0x?)) and the delay after connecting was a few seconds
trace2-cp.jd.txt
trace2-mb.jd.txt

Here are the hex files I used for testing. Just MakeCode files from either Calliope or MicroBit with jacdac extension and scrolling cp or mb on the display at the start:
Hex-files-JACDAC.zip

The Firmware for Calliope mini 3 is forked from MicroBit v2. The changes we made are not a regression from previous calliope firmware versions.

Here is a comparison of the firmware changes we made:
Codal MicroBit v2 ./. Codal Calliope mini 3

Updates in GitHub Workflows
Change Pins in MicroBitCompat.h, MicroBitIO.cpp and MicroBitIO.h
Turn RGB LEDs off in init() in MicroBit.cpp
Link to forked codal-core to invert axes of Magnetometer in target.json, target-locked.json and module.json
Updates in logger files to style and localize in resources/logfs/* and MicroBitLog.cpp
Update Board names in MicroBitBLEManager.cpp

The changes in codal core are just for inverting the axes of the Magnetometer:
Codal Core MicroBit ./. Codal Core Calliope

pelikhan · 2023-12-15T01:11:33Z

Coul you scope the data line on the jacdac cable? (if you have a salea https://microsoft.github.io/jacdac-docs/tools/traces/#saleae-logic )

It seems that there is a bunch a broken packets in the cp trace.

pelikhan · 2023-12-15T03:45:56Z

@mmoskal do you have a hunch here?

fabianhugo · 2023-12-18T12:55:23Z

I attached a recording of the jacdac data line. The Calliope mini has two Jacdac ports, the recording was made on the second port so I could attach modules on the first port. The mini was connected via USB during the measurement.
The recording has a duration of 50s and was captured on channel 0. I did the following steps while recording:

after 10s: press the connect button on the Jacdac dashboard website
after 20s: connect the Keycap Button v1.0 (Kittenbot) to the first jacdac port
after 30s: press the Keycap button
after 40s: press the Keycap button

jacdac-recording1.zip

Let me know if you need a another recording.

pelikhan · 2023-12-18T19:25:32Z

We are in winter break, realistically looking at this in Jan.

mmoskal · 2024-01-02T17:38:57Z

There is nothing remotely suspicious in the diff and the .sal file looks all right.

fabianhugo · 2024-01-05T10:37:22Z

@mmoskal Thank you a lot for looking into this! So this means, that also inside the timing there was nothing suspicious/ All messages are received in the expected timely manner?
Do you have a hint, where else we could have a look?
Are there debugging methods for pxt to look into ram usage of a generated hex file?

FIY: The bug is independent from hardware, i.e. the slow reactions can be reproduced with micro:bit hardware in combination with pxt-calliope, and the normal behavior is observed with pxt-microbit on the calliope hardware

pelikhan · 2024-01-05T21:50:22Z

You could try to do a binary search approach by commenting out the differences with micro:bit (like comment out the RGB code) until you do not see the performance degradation.

pelikhan · 2024-01-05T23:38:35Z

I attached a recording of the jacdac data line. The Calliope mini has two Jacdac ports, the recording was made on the second port so I could attach modules on the first port. The mini was connected via USB during the measurement. The recording has a duration of 50s and was captured on channel 0. I did the following steps while recording:

after 10s: press the connect button on the Jacdac dashboard website

after 20s: connect the Keycap Button v1.0 (Kittenbot) to the first jacdac port

after 30s: press the Keycap button

after 40s: press the Keycap button

jacdac-recording1.zip

Let me know if you need a another recording.

You could also try to connect the micro:bit via USB and use it as a "proxy" to channel the jacdac packets.

fabianhugo · 2024-01-08T10:49:39Z

Thank you!

You could also try to connect the micro:bit via USB and use it as a "proxy" to channel the jacdac packets.

While we are continuing the binary search, I tried the following setup with the proxy idea: Microbit (+Jacdaptor) to PC USB; Calliope mini (powered by battery) to the Jacdac Bus; Then Keyboard Key to the Jacdac bus.
The attached trace showed the following steps:
trace45s.jd.txt
0s : Start recording of the Jacdac Trace (only microbit connected)
10s : Connect the Calliope mini to the jacdac bus
20s : Connect the Keycap Button to the jacdac bus
30s : Press the Keycap Button
40s : Press the Keycap Button
~45s : Stop recording

The micro:bit had a jacdac firmware from makecode.microbit, the mini had a jacdac firmware from makecode.calliope.cc.
Was that what you meant?
And do you know of any extended debugging possibilities for RAM usage?

pelikhan · 2024-01-08T16:43:07Z

It seems that the micro:bit was not connected to the web when recording the trace. Could you try to record while connected again?

fabianhugo · 2024-01-09T11:27:48Z

True, there seems to be something wrong with the recoding. I think the device FV93 refers to some device that is OS related, since it is not the micro:bit or calliope mini or anything else. Unclear to me how this happened.
I redid the recording in the same way: trace_ubit45s.jd.txt
0s : Start recording of the Jacdac Trace (only microbit connected)
10s : Connect the Calliope mini to the jacdac bus
20s : Connect the Keycap Button to the jacdac bus
30s : Press the Keycap Button
40s : Press the Keycap Button
~45s : Stop recording

I also repeated this recording one more time with the Calliope mini V3 also connected via WebUSB in another browser: trace_ubit45s_miniconnected.jd.txt

And made a 3rd trace recording where I connect the trace of the Calliope mini, with the same procedure and the microbit connected via WebUSB: trace_mini45s_ubitconnected.jd.txt. This trace seems a bit off as well, since neither Calliope mini nor micro:bit appear in the list of devices in the beginning of the file. When I replay it the devices VU03 (ubit v2) and UI98 (mini v3) show up in the dashboard however.

pelikhan · 2024-01-09T18:36:54Z

are you seeing packet drops when using the micro:bit as proxy? this would point to an issue with the packet->usb routing

fabianhugo · 2024-01-10T12:01:45Z

I get invalid data packing, e9ba6b02 recoded to e9ba6b0200000000 in uptime from VU03/CONTROL. VU03 is the micro:bit id. I copied this packet using the clipboard button:
uptime_from_VU03CONTROLpacket.txt
And i see out pipe error: no ack in error from VU03/LOGGER (2). I copied the packet as well:
error_from_VU03_LOGGER_packet.txt
I tried the micro:bit without the calliope in the bus, and with the calliope in the bus without a WebUSB connection, and the invalid data packing still shows up. But the output pipe error only shows up if the calliope is connected to the bus and has a seperate WebUSB connection. Here is another trace of that scenario: trace.jdwithcalliopeconnected.txt

pelikhan · 2024-01-11T03:07:47Z

trim.3423C727-8EB2-4900-9D9B-DD414C8DA06B.MOV

I connect the microbit to the jacdac-docs dashboard and bridged the calliope through the jacdac bus. The button pakets are flowing correctly through the micro:bit and the calliope is responding correctly to the button presses (see LED blinking on each button press).

So this test tells me seems to indicate the calliope is receiving correctly the packets but somehow they are lost in the USB transport.

fabianhugo · 2024-01-11T14:15:36Z

Thank you for the video! Great to see the calliope in action, and that the reaction times using code on the calliope mini are short :) The jacdac dashboard was connected to the microbit in this example i assume?
To also exclude DAPLink in the list of possible error sources I made a quick test with a micro:bit daplink firmware, and the issue persists. Which also makes sense since the micro:bit harwdare behaves the same with a calliope makecode hexfile.
Lost in the USB transport then would mean on the way between the application SoC (NRF52833) and the interface SoC (NRF52820), correct?
Could this also be a performance issue of too less ram or cpu clock under load? Is there a way to check this?

pelikhan · 2024-01-11T16:38:00Z

Yes the micro:bit was connected to the dashboard so it handled the USB routing.

mmoskal · 2024-01-11T19:32:10Z

Do you guys by any chance use TEMP_IRQn for something?

pelikhan · 2024-01-11T19:35:30Z

TEMP_IRQn is used https://github.com/microsoft/pxt-jacdac/blob/master/mbbridge.cpp#L100

Amerlander · 2024-01-12T15:20:43Z

We tackled it down to the Bluetooth settings. "bluetooth": { "enabled": 1 }. We have it enabled by default, so the App users have a better experience.

We initially tested disabling Bluetooth, but it seems like the setting was stuck in enabled mode, and therefore we had a false negative (similar to the behavior described in this issue: #264). The content of mbbridge.cpp made me recheck this. I'm glad we found it, but feel a bit sorry since it seems obvious now.

Here is a Project, where Bluetooth is disabled and Jacdac is working smooth: https://makecode.calliope.cc/_V7g9EfcPrPvi

@pelikhan what do you think would be the best option to fix this, when we want to keep bluetooth eabled by default?
We will need to apply the setting in config as well as in optionalConfig to make sure the switch in the GUI is checked and disabled (like the code below). Could we add these settings into pxt-jacdac/pxt.json? Or does it work to include a custom pxt.json only for the calliope like "pxt.json": "target:calliopemini" as fileDependencies? Or should we try to fix this outside of pxt-jacdac?

"yotta": {
        "config": {
            "JACDAC_WEBUSB": 1,
            "JACDAC_SWS_TRANSPORT": 1,
            "microbit-dal": {
                "bluetooth": {
                    "enabled": 0
                }
            }
        },
        "optionalConfig": {
            "microbit-dal": {
                "bluetooth": {
                    "enabled": 0
                }
            }
        }
    }

pelikhan · 2024-01-12T16:40:24Z

I've applied the BLE disabling settings to pxt-jacdac 1.9.15. Tested as working, i think you can close this one!!!

fabianhugo · 2024-01-24T10:09:25Z

Thank you all! Closing as fixed :)

pelikhan self-assigned this Dec 13, 2023

pelikhan mentioned this issue Jan 12, 2024

disable ble, always microsoft/pxt-jacdac#105

Merged

fabianhugo closed this as completed Jan 24, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Jacdac: Live view reacts slow to Jacdac modules #271

Jacdac: Live view reacts slow to Jacdac modules #271

fabianhugo commented Dec 6, 2023

fabianhugo commented Dec 13, 2023

Amerlander commented Dec 13, 2023 •

edited

pelikhan commented Dec 13, 2023

pelikhan commented Dec 13, 2023

Amerlander commented Dec 14, 2023 •

edited

pelikhan commented Dec 15, 2023

pelikhan commented Dec 15, 2023

fabianhugo commented Dec 18, 2023 •

edited

pelikhan commented Dec 18, 2023

mmoskal commented Jan 2, 2024

fabianhugo commented Jan 5, 2024

pelikhan commented Jan 5, 2024

pelikhan commented Jan 5, 2024

fabianhugo commented Jan 8, 2024

pelikhan commented Jan 8, 2024

fabianhugo commented Jan 9, 2024

pelikhan commented Jan 9, 2024

fabianhugo commented Jan 10, 2024

pelikhan commented Jan 11, 2024 •

edited

fabianhugo commented Jan 11, 2024

pelikhan commented Jan 11, 2024

mmoskal commented Jan 11, 2024

pelikhan commented Jan 11, 2024

Amerlander commented Jan 12, 2024

pelikhan commented Jan 12, 2024

fabianhugo commented Jan 24, 2024

Jacdac: Live view reacts slow to Jacdac modules #271

Jacdac: Live view reacts slow to Jacdac modules #271

Comments

fabianhugo commented Dec 6, 2023

fabianhugo commented Dec 13, 2023

Jacdac using the Calliope Makecode Editor with a Calliope Hex file

Jacdac using the Microbit Makecode Editor with a micro:bit Hex file

Jacdac using the Calliope Makecode Editor with a micro:bit Hex file

Amerlander commented Dec 13, 2023 • edited

pelikhan commented Dec 13, 2023

pelikhan commented Dec 13, 2023

Amerlander commented Dec 14, 2023 • edited

pelikhan commented Dec 15, 2023

pelikhan commented Dec 15, 2023

fabianhugo commented Dec 18, 2023 • edited

pelikhan commented Dec 18, 2023

mmoskal commented Jan 2, 2024

fabianhugo commented Jan 5, 2024

pelikhan commented Jan 5, 2024

pelikhan commented Jan 5, 2024

fabianhugo commented Jan 8, 2024

pelikhan commented Jan 8, 2024

fabianhugo commented Jan 9, 2024

pelikhan commented Jan 9, 2024

fabianhugo commented Jan 10, 2024

pelikhan commented Jan 11, 2024 • edited

fabianhugo commented Jan 11, 2024

pelikhan commented Jan 11, 2024

mmoskal commented Jan 11, 2024

pelikhan commented Jan 11, 2024

Amerlander commented Jan 12, 2024

pelikhan commented Jan 12, 2024

fabianhugo commented Jan 24, 2024

Amerlander commented Dec 13, 2023 •

edited

Amerlander commented Dec 14, 2023 •

edited

fabianhugo commented Dec 18, 2023 •

edited

pelikhan commented Jan 11, 2024 •

edited