Enormously slow start in Windows (with workarounds)

[basecamelectronics]

The problem: in some Windows 10 configurations it was reported enormously slow start of app when it accesses COM port functionality. The possible (but not 100%) reason may be the presence of bluetooth serial devices. In my system, I did not see this problem until paired with the Bluetooth 3.1 SPP-profile enabled device, when virtual COM ports appeared in system.

After investigating the source code of nrjavaserial library, I found the reasons and possible workarounds:

1) The problem is slow down of the test read from each serial port candidate when scanning ports. In windows, it scans more than 40000 ports which causes delay for MINUTES. 2) When calling CommPortIdentifier.getPortIdentifiers() first time, full scan is repeated 3 times in a sequence, which makes this problem even more serious. The reason is "static" sections in some classes and initialization in other classes, which all call port scanning indirectly.

It's hard to avoid this behavior w/out a serious redesign of the library. So I found a quick way to fix it by workarounds:

1) Reduce the number of ports to scan. It would be good to allow adjusting this value externally by configuration parameter.

RXTXCommDriver.java:
private int getScannedBufferSize(){
    return 1000; // original value 40960
}

2) Avoid scanning multiple times during startup. For my application, it's okay to keep the list outdated for 1 second, so this code works well:

CommPortIdentifier.java:

private static long lastScanTime = 0;

...

    static public Enumeration getPortIdentifiers() 
    { 
        // workaround: skip multiple call of this function during init.
        long curTime = System.currentTimeMillis();
        if(curTime - lastScanTime < 1000) {
            if (debug) System.out.println("CommPortIdentifier:getPortIdentifiers() done, skipped");
            return new CommPortEnumerator();
        } else {
            if(debug) System.out.println("CommPortIdentifier:getPortIdentifiers()");
        }
                ... main code doing the job ...

        lastScanTime = curTime;

        return new CommPortEnumerator();
    }

[MrDOS]

Thanks for bringing this up. I'd noticed the issue of an insane number of serial port identifiers being scanned in a separate branch that I was working on, but I didn't break it out into its own pull request. You've lowered it to 1,000, but even that is far too high: this old Microsoft KB article, for which I cannot find a modern replacement, documents a limit of 256 ports on Windows NT-based systems.

However, this code path shouldn't actually get run: recent versions of the library (from the last few years) are supposed to use JNA to request a list of serial ports from the registry. If lowering the value of that constant causes a measurable change for you, then there may be something wrong with the JNA stuff. If possible, can you confirm with a debugger that RXTXCommDriver.windowsGetSerialPortsFromRegistry() doesn't get run, and that RXTXCommDriver.registerScannedPorts() takes the useFallback branch instead?

There is another performance hit you might be experiencing from a different piece of internal busywork: on non-Windows platforms, and on Windows if port names are guessed instead of retrieved from the registry, the library opens each possible port and attempts to read a byte to confirm that the port exists and that it has permission to access it. It's a bit stupid, and for Bluetooth ports in particular, it can take a long time. But, if the JNA scanning is working, this shouldn't affect you. This is implemented in RXTXPort.registerValidPorts(); can you confirm in a debugger that the condition at the top of that method (checking if you're on Windows, and that performReadTest is false) fails?

[basecamelectronics]

1) Regarding port numbers, 256 ports was on version 3.x as I remember (that is the reason I didn't notice this issue there). But I guess it was a reason why it was extended to ~40000 later, so returning 256 may affect back-compatibility. But a very long startup delay is a serious issue, too, so I advised to consider moving it to configuration parameter (command-line style) and setting 256 as default value.

2) I have noticed the approach reading ports information from registry, but assumed it had not found the record and gone to full scan.

Now I checked my registry, and have found that the required record is present and holds the actual COM ports information. I will try to debug this part of code to find why it does not work as expected.

3) Yes, I have enabled debug output in java and native code, and can confirm that library reads from each port, and return the correct list after all, so this approach works, but takes too long time. In version 3.x that I used before, it was much faster, I guess because of the limited number of ports and maybe a better startup architecture (now it calls getPortIdentifiers() 3 times in a series, as I wrote above).

[basecamelectronics]

Okay, I found the reason: in my project, JNA libraries were not linked. Because of a delicate and silent checking if (isClassPresent("com.sun.jna.platform.win32.Advapi32Util")) { it's hard to understand that we miss them and it causes the problem finally.

So, it would be good to give a warning that we missed library and are going to make a full scan of all ports, to the logger. Until logging is not supported by the library at this moment (hope it will be added finally) - at least printing warning to console would be a solution.

Another interesting thing that scanning of 40000x3 ports w/out bluettooth ports among them, does not delay program at all. Once bluettooth port appears in a system, the test read from even an unexisting port becomes a bit longer.

[MrDOS]

Thanks for putting in the time to chase this down – I appreciate it.

But I guess it was a reason why it was extended to ~40000 later, so returning 256 may affect back-compatibility.

Ah, look at that – this was changed in #9. Interesting. I guess it should be left high. Or as you say, made configurable, but we don't really have a precedent for global configuration. Maybe an optional argument to getPortIdentifiers() with the maximum number of results? But really, it would be better if JNA worked. Or maybe in the absence of JNA, we should shell out to the mode command and parse its output. It might be a little slow, but I can't imagine it's worse than testing the existence of 40k ports.

JNA libraries were not linked.

Interesting. How are you consuming NRJS in your project? Maven/Gradle dependency? OSGi bundle?

hope it will be added finally

As I think you're referring to, I started looking into proper logging in #193 and got the implementation off to a good start, but I got bogged down researching what and where and how and when other libraries do logging.

Once bluettooth port appears in a system, the test read from even an unexisting port becomes a bit longer.

That's really curious. I'll have to dig into that. Really, I have always been skeptical of the port probing behaviour; it seems inappropriate for the library to open and close every port.

Thanks for reporting this. I'll try to reduce the number of times getPortIdentifiers() is called internally, at least.

[basecamelectronics]

Interesting. How are you consuming NRJS in your project? Maven/Gradle dependency? OSGi bundle?

Just downloaded and added library manually. it's old project in Netbeans IDE where we are used NRJS library for a long time. Recently I had to update it to get compatibility with some Windows 10 where version 3.x failed to work.

Regarding logging, it's hard to advise. From my POV it's really helpful to allow the user of application to enable logging to find what is wrong. Taking current issue as an example, I could much faster find the reason if could enable logs in a simple manner by java -D startup parameter (even standard java.util.logging supports it).

Anyway, I solved my issue. Thank you for supporting this library, it works really well for our needs!

[hborchardt]

I would like to point out that the dependency redesign I proposed in this issue: https://github.com/NeuronRobotics/nrjavaserial/issues/187 would have made the dependency on JNA more explicit, though not automatic.

[ns96]

Hi I am running into this issue on Windows 11 in which Bluetooth SPP ports are present. It take over a minute to load al the comm ports on an 8 core AMD Ryzen machine. Are there any work arounds on the application level for this? I am using the latest library as a jar file.

[hborchardt]

Are there any work arounds on the application level for this? I am using the latest library as a jar file.

You need to add the JNA jar to the class path as well, and it will be picked up automatically.

[ns96]

Thanks @hborchardt. I can confirm copying the 4 JNA libraries from https://github.com/java-native-access/jna into the classpath solves this issue.