What can cause CreateFile calls on a serial port to be extremely slow?

Question

I've got a Qt app (Qt 4.8.1) that's doing some Windows serial port tasks. I'm finding that occasionally the CreateFileA call that I do to open the serial port is taking up to 30 seconds to complete! Obviously I'm doing something to trigger this odd behavior, and I want to know what it is I might be doing to cause this.

m_portHand = CreateFileA( portDevice.c_str(),
                          GENERIC_READ | GENERIC_WRITE,
                          0,      //  must be opened with exclusive-access
                          NULL,   //  default security attributes
                          OPEN_EXISTING, //  must use OPEN_EXISTING
                          FILE_FLAG_OVERLAPPED,      //  overlapped I/O
                          NULL ); //  hTemplate must be NULL for comm devices

m_portHand is a HANDLE, and portDevice is an std::string and contains "COM5".

This call is triggered by a button push in the main thread of my app. At the time it happens the app has at most one other thread, but those threads (if any) are idle.

The only major thing going on in the system is a VM running Linux, but the system is a quad-core and 3 of the cores are as near to idle as you see on a Windows box, with only one doing anything with the VM.

The serial ports are on an 8 port USB serial box, could that be related?

Is this related to the Overlapped IO in some way?

In response to comments:

Port is not open by another app. Port was previously open by a previous invocation of this app, which was properly closed, and the port closed with 'CloseHandle'.

I have not been able to determine any correlations between it taking 30 seconds and not - sometimes I start the app up, click the button and we're off to the races, sometimes it takes up to 30 seconds.

The VM is intercepting some other USB devices on the same serial box.

Other than the serial box (with the VM polling 4 ports looking for devices), the USB bus is unloaded.

I've not seen the behavior in other apps. I'll try switching to a built-in port (COM1 on the motherboard) to see if that has any effect.

A thought just occurred to me: can the form of the port addressing have anything to do with it? Other similar apps I work on use the qestserialport library, which opens ports using the '\\.\COM#' notation. Is there some way that the notation used could affect the timing?

The USB serial device says 'VScom' on it, and normally it opens up right away (< 10 milliseconds for the CreateFile call). It's just an occasional issue where things get stuffed up, and I've got other programs that NEVER seem to exhibit this behavior.

The device I'm talking to is a medical monitor using the IEEE 11073 protocol. Anyway, I have the connection to the device working just fine, it's ONLY the serial port open that's problematic. Could the state of the serial control lines at open time have something to do with this? The device at the other end is polling it's ports looking for various things to talk to, so I have no idea what the serial lines look like at the exact moment things go wrong.

Answer 1

OK, problem is understood, if not solved. I was playing with a different serial device and the problem began manifesting even more frequently.

The problem seems to be that when the VM is in control of some of the serial ports, the drivers become intermittently slow to open the available ports.

My test program opens then closes the port 1000 times, timing the open call. It does NOT set the serial port parameters in any way. Prior to running the test program, I was doing actual work with a device that uses the baud rate 460800.

When the VM is in possession of 4 of the ports, then opens on the remaining 4 ports can sometimes (20-30 times out of 1000 attempts) take 20-30 seconds to complete. When the VM is not running, the opens happen quickly all 1000 attempts. With the VM running, but no USB serial ports in it's possession, the opens happened quickly on all 1000 attempts.

Since the VM is a development tool, not part of our intended deployment scenario, I can live with this issue.

Interestingly, this effect seems to be dependent on what baud rate the port was last used at. Prior to my initial inquiries I'd been operating at 9600 baud and below and don't recall ever seeing the problem. When I first asked the question, I was working with a device that was at 115000 baud, and was having the problem intermittently. With the latest device at 460800 baud, I get the problem often enough to be able to hunt the problem down. No idea why, but there it is.