Why does my UART performance in Java vary?

Question

I'm using an ordinary serial port on a PC to send and receive data in a Java application. The PC runs Windows XP SP3 with java 1.6.0. Here is the code:

import gnu.io.CommPortIdentifier;
import gnu.io.SerialPort;
import java.io.InputStream;
import java.io.OutputStream;
import java.io.BufferedInputStream;
import java.io.BufferedOutputStream;
import java.util.concurrent.ArrayBlockingQueue;

// Open the serial port.
CommPortIdentifier portId;
SerialPort serialPort;
portId = CommPortIdentifier.getPortIdentifier("COM1");
serialPort = (SerialPort) portId.open("My serial port", 1000 /* 1 second timeout */);
serialPort.setSerialPortParams(115200, SerialPort.DATABITS_8, SerialPort.STOPBITS_1, SerialPort.PARITY_NONE);

// Set up input and output streams which will be used to receive and transmit data on the UART.
InputStream input;
OutputStream output;
input = serialPort.getInputStream();
output = serialPort.getOutputStream();

// Wrap the input and output streams in buffers to improve performance. 1024 is the buffer size in bytes. 
input = new BufferedInputStream(input, 1024);
output = new BufferedOutputStream(output, 1024);

// Sync connection.
// Validate connection.
// Start Send- and Receive threads (see below).
// Send a big chunk of data.

To send data I've set up a thread that takes packages from a queue (ArrayBlockingQueue) and sends it on the UART. Similar for receive. Other parts of the application can simply insert packages into the send queue and then poll the receive queue to get the reply.

private class SendThread extends Thread {
  public void run() {
    try {
      SendPkt pkt = SendQueue.take();
      // Register Time1.
      output.write(pkt.data);
      output.flush();
      // Register Time2.
      // Put the data length and Time2-Time1 into an array.

      // Receive Acknowledge.
      ResponsePkt RspPkt = new ResponsePkt();
      RspPkt.data = receive(); // This function calls "input.read" and checks for errors.
      ReceiveQueue.put(RspPkt);
    } catch (IOException e) { ... }
  }

Each send packet is at most 256 bytes, which should take 256*8 bits / 115200 bits/s = 17,7ms to transfer.

I put measurements of Time2-Time1 in an array, i.e. the send time, and check it later. It turns out that sometimes a transfer of 256 bytes takes 15ms to transfer, which seems good since it's close to the teoretical minimum. I'm not sure though why it's faster in practice than in theory. However, the problem is that sometimes a transfer of 256 bytes takes 32ms, i.e. twice as much as needed. What could be causing this?

/Henrik

Answer 1

Do you measure the time with System.nanoTime()?

Windows clock resolution used by System.currentTimeMillis() is by default around 15ms so perhaps in real time each task takes 20ms but some are spread over two ticks instead of one.

See System.currentTimeMillis vs System.nanoTime for more info.