Port is grayed out for initial 5-10 minutes after opening IDE

[francisreader]

Tested on 1.6.x -> 1.9.0-beta. Linux Mint 18.3 x86_64.
Upon starting IDE, Port is greyed out for up to 10minutes, after which Port is not grayed and all ACMs/ttyUSB connections are shown.

NB: I have no issues uploading scripts manually from commandline OR using eclipse-arduino plugin at anytime including during the time Arduino-IDE has port grayed.

If after Port is no longer greyed, ie: I can select port and get board-id or upload scripts, If I close the IDE, and restart it, Port is now grayed out for up to 5-10mins.

[francisreader]

Is there anything I can do to assist in getting verbose output on what triggers the Port to NOT be grayed out and then re-appear. NB: There are no additional message in dmesg or syslog.

[matthijskooijman]

When the port menu is grayed out, are the ttyACMx / ttyUSBx files in /dev present? AFAIK the port list is filled using a fairly simple regex matching against the available files in /dev, and the menu is grayed out when the detected list is empty (not 100% sure, been a while since I looked at the code).

[francisreader]

The device files in /dev/ for ttyACM0 (genuine UNO) and ttyUSB3 (ftdi) are there before during and after the IDE launches.

Its weird that it only after a period of time the Port menu can be accessed.
[66541.496401] usbcore: registered new interface driver cdc_acm
[66541.496402] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
[75249.150882] perf: interrupt took too long (3153 > 3150), lowering kernel.perf_event_max_sample_rate to 63250
[79384.806189] usb 3-9.3: new full-speed USB device number 18 using xhci_hcd
[79384.932625] usb 3-9.3: New USB device found, idVendor=0403, idProduct=6001
[79384.932627] usb 3-9.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[79384.932629] usb 3-9.3: Product: FT232R USB UART
[79384.932630] usb 3-9.3: Manufacturer: FTDI
[79384.932631] usb 3-9.3: SerialNumber: 00000000
[79384.935595] ftdi_sio 3-9.3:1.0: FTDI USB Serial Device converter detected
[79384.935616] usb 3-9.3: Detected FT232RL
[79384.935910] usb 3-9.3: FTDI USB Serial Device converter now attached to ttyUSB3

francis@e3-1246 ~ $ ls -l /dev/ttyUSB3 /dev/ttyACM0
crw-rw---- 1 root dialout 166, 0 May 7 10:31 /dev/ttyACM0
crw-rw---- 1 root dialout 188, 3 May 7 14:05 /dev/ttyUSB3

[francisreader]

Sorry clicked wrong button.. ;-)

[matthijskooijman]

Could it be that modemmanager is somehow keeping the ports busy? I know it sometimes does this (scanning when they are connected), though that usually only shows when opening the port, not when listing them AFAIK. Still, might be something to try, to disable/stop/uninstall modemmanager (check that it isn't autorestarted somehow) and see if the problem persists?

[francisreader]

I HAD removed modemmanager previously as part of my investigation to get this working.. ;-)

francis@e3-1246 ~ $ dpkg -l| grep -i modem
ii  libmm-glib0:amd64                           1.6.4-1ubuntu0.16.04.1                       amd64        D-Bus service for managing modems - shared libraries
rc  modemmanager                                1.4.12-1ubuntu1                              amd64        D-Bus service for managing modems
francis@e3-1246 ~ $ sudo apt-get remove modemmanager
Reading package lists... Done
Building dependency tree       
Reading state information... Done
Package 'modemmanager' is not installed, so not removed
The following packages were automatically installed and are no longer required:
  arduino-core avr-libc avrdude binutils-avr gcc-avr libftdi1 libjna-java libjna-jni
Use 'sudo apt autoremove' to remove them.
0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.

[francisreader]

Is there a way to enable debuging of the IDE itself, to see it probe the TTYs?

[matthijskooijman]

Hm, then I'm out of ideas for now, at least without diving into the source (for which I'll probably not have time anytime soon).

Is there a way to enable debuging of the IDE itself, to see it probe the TTYs?

Oh, good idea! What you could try, is to use strace when starting the IDE. This should list all system calls the IDE makes, which could give you an idea of it is doing and if/why things are failing.

The actual probing happens by the serial library (JSSC IIRC, not sure where the source lives, seems there is no JSSC repo within the Arduino github organisation, so it probably is not a custom version), so the code is a bit hidden away (in case you wanted to look at that).

[francisreader]

Reading the commits, the serial probing code was rewritten for 1.6.
1.0.x works everytime, ie: Port is NOT grayed at anytime (since I have ttyUSB0->2 plugged in permanently for some work STB development)

[francisreader]

Sorry no new messages referring to any device file in /dev after the initialisation. And the only references to /dev/tty* is open("/dev/tty", O_RDWR|O_NONBLOCK) = 3`

After the period when Port is no longer grayed, there are no additional system call messages captured via strace. (which seem odd, since I did a BoardID to /dev/ttyACM0 )

[francisreader]

Strace output. I cannot see anything relevant.
ide.log.gz

[facchinm]

@francisreader recent version of the IDE list ports via https://github.com/arduino/listSerialPortsC , which provides some richer information (VID, PID, serialnumber). The IDE requests information via a JNI call using a dynamically loaded library, so I think strace could lose the actual calls.
There is also some heavy caching in place to avoid requesting the same stuff too many times.
Two possible tests come to my mind:

• with the port menu grayed out, try launching listSerialC binary (from here https://github.com/arduino/listSerialPortsC/releases). If you get some output, the problem is on the Java side.
• if it doesn't work, try running https://github.com/arduino/arduino-create-agent which uses a different method to retrieve the ports; if this too doesn't work, it is surely related with some other program running in the background (a friend of modemmanager 🙂 )

[matthijskooijman]

Looking at the strace log, I suspect you need to run strace -f to also strace any forked children processes. I suspect you're now only stracing the startup script that starts java, but not the java process itself.

As for looking in the log, I would suspect it would do an opendir/readdir on /dev, it might not actually mention the ttyXXX devices themselves.

[francisreader]

listSerialC looks okay this was done before starting ./arduino. Also it was almost 10mins when the Port became un-grayed.
ide.log.gz

./listSerialC 
/dev/ttyUSB3 | 0403:6001 | 00000000 FT232R USB UART FTDI FT232R USB UART - FT232R USB UART
/dev/ttyUSB1 | 067B:2303 | (null) USB-Serial Controller Prolific Technology Inc. USB-Serial Controller
/dev/ttyACM0 | 2341:0043 | 55732323131351018180 (null) Arduino (www.arduino.cc) ttyACM0
/dev/ttyUSB2 | 067B:2303 | (null) USB-Serial Controller Prolific Technology Inc. USB-Serial Controller
/dev/ttyUSB0 | 067B:2303 | (null) USB-Serial Controller Prolific Technology Inc. USB-Serial Controller

attached is gzip'ed strace with timestamps, From my

[facchinm]

Just an idea: is the port greyed out if you remove all the FTDI converters?

[francisreader]

Yes.

francis@e3-1246 /usr/local/tmp/listSerialPortsC/distrib/linux64 $ ./listSerialC 
/dev/ttyACM0 | 2341:0043 | 55732323131351018180 (null) Arduino (www.arduino.cc) ttyACM0
/dev/ttyUSB0 | 067B:2303 | (null) USB-Serial Controller Prolific Technology Inc. USB-Serial Controller

[gregkrsak]

I'm still seeing a greyed-out port (USB) in Lubuntu, with a SparkFun Pro Micro. Tried different cables, ports, with external power to the board and without, rebooting the PC, restarting the IDE, downgrading the SparkFun AVR Boards library, etc.

My Lubuntu version is 21.10.
Current SparkFun AVR Boards version is 1.1.13.
Current Arduino IDE version is 1.8.15.

[gregkrsak]

The weird thing is: It was working earlier today.

[gregkrsak]

sudo watch -n 1 "dmesg | tail -n 50"

...gives me this relevant output...

[  113.753479] usb 1-7: new full-speed USB device number 4 using xhci_hcd
[  113.881309] usb 1-7: device descriptor read/64, error -71
[  114.117413] usb 1-7: device descriptor read/64, error -71
[  114.353316] usb 1-7: new full-speed USB device number 5 using xhci_hcd
[  114.481290] usb 1-7: device descriptor read/64, error -71
[  114.717224] usb 1-7: device descriptor read/64, error -71                                           
[  114.825221] usb usb1-port7: attempt power cycle                                                     
[  115.476981] usb 1-7: new full-speed USB device number 6 using xhci_hcd                              
[  115.477208] usb 1-7: Device not responding to setup address.                                        
[  115.685115] usb 1-7: Device not responding to setup address.                                        
[  115.892704] usb 1-7: device not accepting address 6, error -71                                      
[  116.020846] usb 1-7: new full-speed USB device number 7 using xhci_hcd                              
[  116.021074] usb 1-7: Device not responding to setup address.                                        
[  116.229002] usb 1-7: Device not responding to setup address.                                        
[  116.436738] usb 1-7: device not accepting address 7, error -71                                      
[  116.436965] usb usb1-port7: unable to enumerate USB device

[gregkrsak]

Well, shoot... I tried another SparkFun Pro Micro and it worked. Guess mine just died randomly. Any way to fix this, or should I just write it off?

Sorry for the trouble.

[per1234]

Hi @gregkrsak. Thanks for the update.

Any way to fix this, or should I just write it off?

There is a chance it could be fixed easily. Please post over on the Arduino forum and we'll provide instructions:

https://forum.arduino.cc/c/using-arduino/avrdude-stk500-bootloader-issues/81