Selection of port lost on upload when protocol other than `serial`/`network` and no "recognized" board

[per1234]

Describe the problem

For certain types of boards or ports, the port may alternately disappear and reappear during the course of the upload, sometimes even changing address.

Arduino IDE is designed to select the correct port of the board at the completion of the upload in order to avoid the confusion or inconvenience that would be imposed on the user otherwise.

🐛 When using a teensy protocol port of a Teensy board, the port selection is sometimes lost after an upload.

To reproduce

Equipment

• Any Teensy board

Steps

1. Select File > New Sketch from the Arduino IDE menus.
   ⓘ The purpose of this step is to make sure the sketch in use will compile so that the upload operation can proceed.
2. Connect a Teensy board to your computer.
3. Select the port of the board from the "Teensy ports" section of the Tools > Port menu in the Arduino IDE.
   ❗ The board may also add a port under the "Serial ports" section of the Tools > Port menu. Make sure to select the Teensy port instead.
   
4. Select the board from the Tools > Board menu in the Arduino IDE.
5. Select Sketch > Upload from the Arduino IDE menus.
6. Select Tools > Port from the Arduino IDE menus.

🐛 The port is no longer selected.

Expected behavior

Port selection is always preserved through the upload.

Arduino IDE version

Original report

2.0.0-rc9.2.snapshot-34a7fdb

Last verified with

197cea2

Operating system

Windows, Linux

Operating system version

Windows 10, Ubuntu 20.04

Additional context

I bisected the introduction of the bug to #1332 (it does not occur when using the build from d674ab9)

---

I found the problem occurred intermittently.

I found a correlation between the occurrence of the bug and the behavior of the port during the upload.

On the uploads where the bug occurred, there were always remove/add events for the teensy protocol port of the board.

On the uploads where the bug did not occur, there were never any remove/add events for the teensy protocol port of the board.

Example arduino-cli board list --format json --watch output from an upload when the bug occurred:

{
  "type": "remove",
  "address": "usb:0/1A0000/0/1/5/1/1/3",
  "protocol": "teensy",
  "properties": {}
}
{
  "type": "add",
  "address": "usb:0/1A0000/0/1/5/1/1/3",
  "label": "hid#vid_16c0\u0026pid_0478 Bootloader",
  "protocol": "teensy",
  "protocol_label": "Teensy Ports",
  "properties": {
    "modelID": "0x25",
    "name": "Teensy 4.1",
    "serialNumber": "808372"
  },
  "boards": [
    {
      "name": "Teensy 4.1",
      "fqbn": "teensy:avr:teensy41"
    }
  ]
}
{
  "type": "remove",
  "address": "usb:0/1A0000/0/1/5/1/1/3",
  "protocol": "teensy",
  "properties": {}
}
{
  "type": "add",
  "address": "usb:0/1A0000/0/1/5/1/1/3",
  "label": "hid#vid_16c0\u0026pid_0486 RawHID",
  "protocol": "teensy",
  "protocol_label": "Teensy Ports",
  "properties": {
    "modelID": "0x25",
    "name": "Teensy 4.1",
    "serialNumber": "808372",
    "usbtype": "USB_RAWHID"
  },
  "boards": [
    {
      "name": "Teensy 4.1",
      "fqbn": "teensy:avr:teensy41"
    }
  ]
}

Here is the output directly from the teensy-discovery pluggable discovery tool during the same upload:

{
"eventType": "remove",
"port": {
"address": "usb:0/1A0000/0/1/5/1/1/3",
"protocol": "teensy"
}
}
{
"eventType": "add",
"port": {
"address": "usb:0/1A0000/0/1/5/1/1/3",
"label": "hid#vid_16c0&pid_0478 Bootloader",
"protocol": "teensy",
"protocolLabel": "Teensy Ports",
"properties": {
"modelID": "0x25",
"serialNumber": "808372",
"name": "Teensy 4.1"
}
}
}
{
"eventType": "remove",
"port": {
"address": "usb:0/1A0000/0/1/5/1/1/3",
"protocol": "teensy"
}
}
{
"eventType": "add",
"port": {
"address": "usb:0/1A0000/0/1/5/1/1/3",
"label": "hid#vid_16c0&pid_0486 RawHID",
"protocol": "teensy",
"protocolLabel": "Teensy Ports",
"properties": {
"modelID": "0x25",
"usbtype": "USB_RAWHID",
"serialNumber": "808372",
"name": "Teensy 4.1"
}
}
}

---

Originally reported by @KurtE at https://forum.arduino.cc/t/serial-monitor-issues-hopefully-fixed-before-release/1026548

Issue checklist

• I searched for previous reports in the issue tracker
• I verified the problem still occurs when using the latest nightly build
• My report contains all necessary details

[KurtE]

Thanks @per1234,

Another related symptom of my gut says changed was with plugging in a board and being able to choose it from the toolbar drop down list. Example I was starting to modify a program and decided to use a T4.1 to do this test. Which I turned on (pushed button on powered hub associated with the slot).

The drop-down list still visually shows Micromod:

I click on it to hopefully allow me to choose the T4.1:

But it shows it as an unknown board:

But if I go to the menu for the ports, it knows that it is a Teensy 4.1

Edit: If I choose that item for the T4.1 it does not change the drop-down list for what the current board type is, but when it drops back down it at least knows what type board it is:

[per1234]

But it shows it as an unknown board:

That is the serial port of the board. The teensy protocol port "COM27 Serial" is not being shown at all. That bug is being tracked in the dedicated issue #1365

[per1234]

I discovered some more information about the bug while testing #1377:

The bug no longer occurs with the Teensy board after the change made in #1377. Disregarding the bisection results, which also pointed at that code, this was quite unexpected to me because my understanding was that code is only used to filter which ports are shown in the "Board Selector" menu and "Select Other Board and Port" dialog.

This does tell us the exact conditions required:

• Port disappears during the upload
• Port is filtered out by the code touched here: https://github.com/arduino/arduino-ide/pull/1377/files

Currently, all ports with protocols other than serial or network are filtered out by that code. After the changes in #1377, the conditions required to be filtered will be:

• Port is of a protocol other than serial or network
• Port has not been identified as a board

The Teensy boards platform has configured identification properties for the boards, which is why those ports will no longer be affected by this bug after #1377. However, it is not possible to set up identification properties for some hardware (e.g., the classic Arduino Nano board), so it is still possible for the port loss bug could still impact other platforms (though due to the newness of the pluggable discovery system perhaps there are no such platforms currently).

I was able to verify the general nature of the bug by creating an Arduino boards platform that used a modified version of the serial-discovery tool to discover serial ports as a different protocol, then uploading to a Leonardo board with the port of that other protocol selected. However, it ended up being not so convenient because the "1200 bps touch" feature of Arduino CLI normally used during the upload process to that board is coded to only trigger when uploading to a port of the serial protocol.

So I think the easiest way to reproduce the bug will remain to use a Teensy board. Only now it is necessary to modify the platform to cause the port to not be identified as a board:

1. Select File > Quit from the Arduino IDE menus if it is running.
2. Use any text editor to open the Teensy platform's boards.txt file, which will be located at a path equivalent to:

   C:\Users\per\AppData\Local\Arduino15\packages\teensy\hardware\avr\1.57.0
   

3. Add a # character to comment out the <board ID>.upload_port.modelID property definition for the Teensy board you are using.
   For example, if using the "Teensy 4.1" board:

   #teensy41.upload_port.modelID=0x25
   

4. Save the file.
5. Start the Arduino IDE.
6. Follow the "To reproduce" instructions from the original issue report.

After you have finished testing, clean up by:

1. Select File > Quit from the Arduino IDE menus if it is running.
2. Open the Teensy platform's boards.txt file in a text editor.
3. Remove the # you added.
4. Save the file.

[PaulStoffregen]

Might be worth mentioning I am considering a change to teensy-discovery to suppress the brief port loss during upload. The teensy_ports utility (legacy pluggable discovery for IDE 1.8.x) has long implemented special timer code to suppress the remove events. When I wrote teensy-discovery to implement the new pluggable discovery protocol, I intentionally left out that timer stuff, for the sake of helping to test IDE2.

Because of the way the package index spec handles pluggable discovery and pluggable monitor tools without version numbers, when/if this change is made, it will be automatically applied to installing all prior versions of Teensy packages. If the behavior we have now is needed in this hypothetical future, to reproduce this issue you may also need to delete all newer copies of teensy-discovery.

[kittaakos]

I started working on this task and investigated the nature of the problem after buying a Teensy board. With the latest CLI release (arduino-cli Version: 0.29.0 Commit: 76251df9 Date: 2022-11-17T09:21:47Z), when I do a ./arduino-cli board list --watch --format json

{
  "type": "add",
  "address": "/dev/cu.BLTH",
  "label": "/dev/cu.BLTH",
  "protocol": "serial",
  "protocol_label": "Serial Port",
  "properties": {}
}
{
  "type": "add",
  "address": "/dev/cu.Bluetooth-Incoming-Port",
  "label": "/dev/cu.Bluetooth-Incoming-Port",
  "protocol": "serial",
  "protocol_label": "Serial Port",
  "properties": {}
}
{
  "type": "add",
  "address": "usb:14300000",
  "label": "[no_device] Bootloader",
  "protocol": "teensy",
  "protocol_label": "Teensy Ports",
  "properties": {
    "name": "Teensy",
    "serialNumber": "1279023"
  }
}
{
  "type": "add",
  "address": "usb:14300000",
  "label": "HID=16c0:0478.ff9c.25 Bootloader",
  "protocol": "teensy",
  "protocol_label": "Teensy Ports",
  "properties": {
    "modelID": "0x25",
    "name": "Teensy 4.1",
    "serialNumber": "1279023"
  },
  "boards": [
    {
      "name": "Teensy 4.1",
      "fqbn": "teensy:avr:teensy41"
    }
  ]
}
{
  "type": "remove",
  "address": "usb:14300000",
  "protocol": "teensy",
  "properties": {}
}
{
  "type": "add",
  "address": "usb:14300000",
  "label": "[no_device] Bootloader",
  "protocol": "teensy",
  "protocol_label": "Teensy Ports",
  "properties": {
    "modelID": "0x25",
    "name": "Teensy 4.1",
    "serialNumber": "1279023"
  },
  "boards": [
    {
      "name": "Teensy 4.1",
      "fqbn": "teensy:avr:teensy41"
    }
  ]
}
{
  "type": "add",
  "address": "usb:14300000",
  "label": "HID=16c0:0478.ff9c.25 Bootloader",
  "protocol": "teensy",
  "protocol_label": "Teensy Ports",
  "properties": {
    "modelID": "0x25",
    "name": "Teensy 4.1",
    "serialNumber": "1279023"
  },
  "boards": [
    {
      "name": "Teensy 4.1",
      "fqbn": "teensy:avr:teensy41"
    }
  ]
}
{
  "type": "remove",
  "address": "usb:14300000",
  "protocol": "teensy",
  "properties": {}
}
{
  "type": "add",
  "address": "usb:14300000",
  "label": "[no_device] Bootloader",
  "protocol": "teensy",
  "protocol_label": "Teensy Ports",
  "properties": {
    "modelID": "0x25",
    "name": "Teensy 4.1",
    "serialNumber": "1279023"
  },
  "boards": [
    {
      "name": "Teensy 4.1",
      "fqbn": "teensy:avr:teensy41"
    }
  ]
}
{
  "type": "add",
  "address": "usb:14300000",
  "label": "HID=16c0:0478.ff9c.25 Bootloader",
  "protocol": "teensy",
  "protocol_label": "Teensy Ports",
  "properties": {
    "modelID": "0x25",
    "name": "Teensy 4.1",
    "serialNumber": "1279023"
  },
  "boards": [
    {
      "name": "Teensy 4.1",
      "fqbn": "teensy:avr:teensy41"
    }
  ]
}
{
  "type": "remove",
  "address": "usb:14300000",
  "protocol": "teensy",
  "properties": {}
}
{
  "type": "add",
  "address": "usb:14300000",
  "label": "[no_device] Bootloader",
  "protocol": "teensy",
  "protocol_label": "Teensy Ports",
  "properties": {
    "modelID": "0x25",
    "name": "Teensy 4.1",
    "serialNumber": "1279023"
  },
  "boards": [
    {
      "name": "Teensy 4.1",
      "fqbn": "teensy:avr:teensy41"
    }
  ]
}
{
  "type": "add",
  "address": "usb:14300000",
  "label": "HID=16c0:0478.ff9c.25 Bootloader",
  "protocol": "teensy",
  "protocol_label": "Teensy Ports",
  "properties": {
    "modelID": "0x25",
    "name": "Teensy 4.1",
    "serialNumber": "1279023"
  },
  "boards": [
    {
      "name": "Teensy 4.1",
      "fqbn": "teensy:avr:teensy41"
    }
  ]
}
{
  "type": "remove",
  "address": "usb:14300000",
  "protocol": "teensy",
  "properties": {}
}
{
  "type": "add",
  "address": "usb:14300000",
  "label": "[no_device] Bootloader",
  "protocol": "teensy",
  "protocol_label": "Teensy Ports",
  "properties": {
    "modelID": "0x25",
    "name": "Teensy 4.1",
    "serialNumber": "1279023"
  },
  "boards": [
    {
      "name": "Teensy 4.1",
      "fqbn": "teensy:avr:teensy41"
    }
  ]
}
{
  "type": "add",
  "address": "usb:14300000",
  "label": "HID=16c0:0478.ff9c.25 Bootloader",
  "protocol": "teensy",
  "protocol_label": "Teensy Ports",
  "properties": {
    "modelID": "0x25",
    "name": "Teensy 4.1",
    "serialNumber": "1279023"
  },
  "boards": [
    {
      "name": "Teensy 4.1",
      "fqbn": "teensy:avr:teensy41"
    }
  ]
}

Without doing anything, I can see the CLI's board discovery detects a board removal and addition. Could someone with the required domain expertise tell me why this is happening?

Also, why are two add type events with the same address and protocol, and how should this be handled?

{
  "type": "add",
  "address": "usb:14300000",
  "label": "[no_device] Bootloader",
  "protocol": "teensy",
  "protocol_label": "Teensy Ports",
  "properties": {
    "modelID": "0x25",
    "name": "Teensy 4.1",
    "serialNumber": "1279023"
  },
  "boards": [
    {
      "name": "Teensy 4.1",
      "fqbn": "teensy:avr:teensy41"
    }
  ]
}
{
  "type": "add",
  "address": "usb:14300000",
  "label": "HID=16c0:0478.ff9c.25 Bootloader",
  "protocol": "teensy",
  "protocol_label": "Teensy Ports",
  "properties": {
    "modelID": "0x25",
    "name": "Teensy 4.1",
    "serialNumber": "1279023"
  },
  "boards": [
    {
      "name": "Teensy 4.1",
      "fqbn": "teensy:avr:teensy41"
    }
  ]
}

IDE2 (correctly?) generates the following warning when I start IDE2, attach my Teensy 4.1, and do nothing:

root WARN Detected a new port that has been already discovered. The old value will be overridden. Old value: [{"address":"usb:14300000","addressLabel":"[no_device] Bootloader","protocol":"teensy","protocolLabel":"Teensy Ports","properties":{"name":"Teensy","serialNumber":"1279023"}},[]], new value: {"boards":[{"fqbn":"teensy:avr:teensy41","name":"Teensy 4.1","port":{"address":"usb:14300000","addressLabel":"HID=16c0:0478.ff9c.25 Bootloader","protocol":"teensy","protocolLabel":"Teensy Ports","properties":{"modelID":"0x25","name":"Teensy 4.1","serialNumber":"1279023"}}}],"port":{"address":"usb:14300000","addressLabel":"HID=16c0:0478.ff9c.25 Bootloader","protocol":"teensy","protocolLabel":"Teensy Ports","properties":{"modelID":"0x25","name":"Teensy 4.1","serialNumber":"1279023"}}}

Thank you!

[PaulStoffregen]

@kittaakos - Are you testing on MacOS? Can you confirm which version of teensy-discovery you have installed? Is this M1 or Intel Mac? I'd like to try to reproduce unnecessary 'remove' message. I have a few older Macs and only 1 newer model capable of running Ventura. Please let me know a bit more about your setup so I can give it a try here?

Regarding "Also, why are two add type events with the same address and protocol, and how should this be handled?", I believe the Pluggable Discovery Specification says:

If the information about a port needs to be updated the discovery may send a new add message for the same port address and protocol without sending a remove first: this means that all the previous information about the port must be discarded and replaced with the new one.

To explain a bit more, discovery of USB devices and their capabilities (called "enumeration" in USB lingo) happens in multiple steps. First the USB device as a whole is recognized. Devices can offer multiple configurations requiring varying bandwidth and power consumption (though offering just 1 configuration is pretty common, except for webcams). Once the host driver chooses a configuration, a list of all its interfaces is obtained. Typically the user visible features correspond to each interface, or a small group of interfaces. The operating system loads drivers for each interface group.

Windows, MacOS and Linux each have their own real-time notifications system for hardware changes. Multiple notifications are given as the USB enumeration progresses. The Teensy discovery utility uses these notifications to get the most timely updated possible. It sends multiple "add" events, one for each hardware change notification is received from the system, with as much info as is known at that moment. So it's normal and expected behavior to get multiple "add" messages.

[kittaakos]

Are you testing on MacOS?

Yes. 12.5.1 is my working macOS, and 11.7.2 is my personal. Both have an Intel chip.

Can you confirm which version of teensy-discovery you have installed?

I did not. When I received my board, I started to use it on my personal mac, and as everything was working, I never installed additional software. This is my setup:

1. Latest CLI:

./arduino-cli version
arduino-cli  Version: git-snapshot Commit: a735ddfd Date: 2023-01-13T13:43:56Z

2. Default CLI config with the Teensy platform:

cat ~/Library/Arduino15/arduino-cli.yaml
board_manager:
  additional_urls: [
    https://www.pjrc.com/teensy/td_156/package_teensy_index.json
  ]
daemon:
  port: "50051"
directories:
  data: /Users/akos.kitta/Library/Arduino15
  downloads: /Users/akos.kitta/Library/Arduino15/staging
  user: /Users/akos.kitta/Documents/Arduino
library:
  enable_unsafe_install: false
logging:
  file: ""
  format: text
  level: info
metrics:
  addr: :9090
  enabled: true
sketch:
  always_export_binaries: false
updater:
  enable_notification: true

4. Installed platforms:

./arduino-cli core list                       
ID                Installed Latest Name
arduino:avr       1.8.6     1.8.6  Arduino AVR Boards
arduino:mbed_nano 3.5.1     3.5.1  Arduino Mbed OS Nano Boards
teensy:avr        1.57.2    1.57.2 Teensy

5. The CLI detects the board:

./arduino-cli board list --watch --format json
{
  "type": "add",
  "address": "/dev/cu.Bluetooth-Incoming-Port",
  "label": "/dev/cu.Bluetooth-Incoming-Port",
  "protocol": "serial",
  "protocol_label": "Serial Port",
  "properties": {}
}
{
  "type": "add",
  "address": "usb:14100000",
  "label": "[no_device] Bootloader",
  "protocol": "teensy",
  "protocol_label": "Teensy Ports",
  "properties": {
    "name": "Teensy",
    "serialNumber": "1279023"
  }
}
{
  "type": "add",
  "address": "usb:14100000",
  "label": "HID=16c0:0478.ff9c.25 Bootloader",
  "protocol": "teensy",
  "protocol_label": "Teensy Ports",
  "properties": {
    "modelID": "0x25",
    "name": "Teensy 4.1",
    "serialNumber": "1279023"
  },
  "boards": [
    {
      "name": "Teensy 4.1",
      "fqbn": "teensy:avr:teensy41"
    }
  ]
}

6. Compile works:

./arduino-cli compile -b teensy:avr:teensy41 ~/Desktop/dev/__trash/blink 
Opening Teensy Loader...
Memory Usage on Teensy 4.1:
  FLASH: code:9580, data:3992, headers:8952   free for files:8103940
   RAM1: variables:4512, code:6912, padding:25856   free for local variables:487008
   RAM2: variables:12384  free for malloc/new:511904


Used platform Version Path                                                                   
teensy:avr    1.57.2  /Users/akos.kitta/Library/Arduino15/packages/teensy/hardware/avr/1.57.2

7. Upload works; I can alter the led blink frequency from the sketch and upload. I use the built-in Blink example:

./arduino-cli upload -b teensy:avr:teensy41 -p usb:14100000 ~/Desktop/dev/__trash/blink

When uploading, this window pops up, but I have yet to interact with it. The upload functionality was working, so I never touched it. 😬

I'd like to try to reproduce unnecessary 'remove' message.

I am happy to assist you. I have noticed that on my personal mac, the add/remove event frequency is lower (1 per 5 minutes), compared to the working mac. I posted #1366 (comment) from the working notebook when I noticed the frequent add/remove messages. I have not noticed the same on the personal mac, although I use the Teensy board almost daily.

On both notebooks, I have the following serial-discovery versions installed, if it matters:

ls -al ~/Library/Arduino15/packages/builtin/tools/serial-discovery 
total 0
drwxr-xr-x  4 a.kitta  staff  128 Jan 10 13:05 .
drwxr-xr-x  6 a.kitta  staff  192 Jan  9 09:46 ..
drwxr-xr-x  4 a.kitta  staff  128 Jan  9 09:46 1.3.2
drwxr-xr-x  4 a.kitta  staff  128 Jan 10 13:05 1.3.3

So it's normal and expected behavior to get multiple "add" messages.

Great explanation. Thank you! IDE2 should treat these events as normal behavior instead of warnings:

arduino-ide/arduino-ide-extension/src/node/board-discovery.ts

Lines 274 to 280 in 197cea2

	this.logger.warn(
	`Port '${Port.toString(
	port
	)}' was already available. Known boards before override: ${JSON.stringify(
	knownBoards
	)}`
	);

---

on my personal mac, the add/remove event frequency is lower (1 per 5 minutes), compared to the working mac.

I attached the Teensy4.1 board to the working mac to give a rough estimation of the frequency of the add/remove events, and I have not received any in the last 20 minutes. If I recognize any pattern or have the steps to reproduce it, I will update this issue.