Skip to content

Commit 46ae5a0

Browse files
committed
Add a debug() method to Serial
This commit also turns a 100ns wait inside JSSC in a yield() and removes the invocation of serialEvent outside the synchronized block.
1 parent fa7a9ce commit 46ae5a0

File tree

2 files changed

+161
-19
lines changed

2 files changed

+161
-19
lines changed
781 Bytes
Binary file not shown.

java/libraries/serial/src/processing/serial/Serial.java

Lines changed: 161 additions & 19 deletions
Original file line numberDiff line numberDiff line change
@@ -48,6 +48,28 @@ public class Serial implements SerialPortEventListener {
4848

4949
volatile boolean invokeSerialAvailable = false;
5050

51+
// DEBUG
52+
int baudRate = 0;
53+
int countEvents = 0; // number of event handler invocations
54+
int countFuncs = 0; // number of SerialEvent invocations
55+
int countReads = 0; // number of read operations
56+
int countSyncs = 0; // number of synchronizations
57+
int countWrites = 0; // number of write operations
58+
long firstEvent = 0; // timestamp of first event handler invocation
59+
int maxBufferLength = 0; // maximum size of input buffer
60+
long maxFuncTime = 0; // maximum time spend invoking SerialEvent
61+
int maxRead = 0; // maximum number of bytes read
62+
long maxReadTime = 0; // maximum time spent on read operations
63+
long maxReadSyncTime = 0; // maximum time spent on a synchronization in the event handler
64+
long maxSyncTime = 0; // maximum time spent on a synchronization elsewhere
65+
long maxWriteTime = 0; // maximum time spent on a write operation
66+
long sumFuncTime = 0; // sum of time spent in SerialEvent
67+
int sumRead = 0; // sum of bytes read
68+
long sumReadSyncTime = 0; // sum of time spent on synchonizations in the event handler
69+
long sumReadTime = 0; // sum of time spent on read operations
70+
long sumSyncTime = 0; // sum of time spent on synchonizations elsewhere
71+
long sumWriteTime = 0; // sum of time spent on write operations
72+
5173
// Things we are currently not exposing:
5274
// * hardware flow control
5375
// * state of the RING, RLSD line
@@ -79,6 +101,8 @@ public Serial(PApplet parent, String portName, int baudRate, char parity, int da
79101
parent.registerMethod("dispose", this);
80102
parent.registerMethod("pre", this);
81103

104+
this.baudRate = baudRate;
105+
82106
// setup parity
83107
if (parity == 'O') {
84108
parity = SerialPort.PARITY_ODD;
@@ -160,13 +184,37 @@ public void bufferUntil(int inByte) {
160184

161185

162186
public void clear() {
187+
long start = System.nanoTime();
163188
synchronized (buffer) {
189+
long len = System.nanoTime()-start;
190+
if (maxSyncTime < len) {
191+
maxSyncTime = len;
192+
}
193+
sumSyncTime += len;
194+
countSyncs++;
164195
inBuffer = 0;
165196
readOffset = 0;
166197
}
167198
}
168199

169-
200+
201+
public void debug() {
202+
float secs = (System.nanoTime()-firstEvent)/1000000000.0f;
203+
System.out.println("\nSerial: test #3");
204+
System.out.println(port.getPortName()+" @ "+baudRate+" bps");
205+
System.out.println(secs+" sec receiving data:");
206+
System.out.println(countEvents+" events, "+(countEvents/secs)+" per sec");
207+
System.out.println(countReads+" reads, "+(countReads/secs)+" per sec, "+(sumReadTime/(float)countReads)+" ns avg, "+maxReadTime+" ns max");
208+
System.out.println((sumRead/(float)countReads)+" bytes avg per read, "+(sumRead/secs)+" per sec, "+maxRead+" bytes max");
209+
System.out.println("Max buffer length: "+maxBufferLength);
210+
System.out.println(sumReadSyncTime/(float)countReads+" ns avg read synchronizations, "+maxReadSyncTime+" ns max");
211+
System.out.println(countFuncs+" callbacks, "+(sumFuncTime/(float)countFuncs)+" ns avg, "+maxFuncTime+" ns max");
212+
System.out.println(countWrites+" writes, "+(sumWriteTime/(float)countWrites)+" ns avg, "+maxWriteTime+" ns max");
213+
System.out.println(countSyncs+" synchonizations, "+(sumSyncTime/(float)countSyncs)+" ns avg, "+maxSyncTime+" ns max");
214+
port.debug();
215+
}
216+
217+
170218
public boolean getCTS() {
171219
try {
172220
return port.isCTS();
@@ -189,13 +237,20 @@ public static Map<String, String> getProperties(String portName) {
189237
return SerialPortList.getPortProperties(portName);
190238
}
191239

192-
240+
193241
public int last() {
194242
if (inBuffer == readOffset) {
195243
return -1;
196244
}
197245

246+
long start = System.nanoTime();
198247
synchronized (buffer) {
248+
long len = System.nanoTime()-start;
249+
if (maxSyncTime < len) {
250+
maxSyncTime = len;
251+
}
252+
sumSyncTime += len;
253+
countSyncs++;
199254
int ret = buffer[inBuffer-1] & 0xFF;
200255
inBuffer = 0;
201256
readOffset = 0;
@@ -221,7 +276,14 @@ public int read() {
221276
return -1;
222277
}
223278

279+
long start = System.nanoTime();
224280
synchronized (buffer) {
281+
long len = System.nanoTime()-start;
282+
if (maxSyncTime < len) {
283+
maxSyncTime = len;
284+
}
285+
sumSyncTime += len;
286+
countSyncs++;
225287
int ret = buffer[readOffset++] & 0xFF;
226288
if (inBuffer == readOffset) {
227289
inBuffer = 0;
@@ -237,7 +299,14 @@ public byte[] readBytes() {
237299
return null;
238300
}
239301

302+
long start = System.nanoTime();
240303
synchronized (buffer) {
304+
long len = System.nanoTime()-start;
305+
if (maxSyncTime < len) {
306+
maxSyncTime = len;
307+
}
308+
sumSyncTime += len;
309+
countSyncs++;
241310
byte[] ret = new byte[inBuffer-readOffset];
242311
System.arraycopy(buffer, readOffset, ret, 0, ret.length);
243312
inBuffer = 0;
@@ -252,7 +321,14 @@ public int readBytes(byte[] dest) {
252321
return 0;
253322
}
254323

324+
long start = System.nanoTime();
255325
synchronized (buffer) {
326+
long len = System.nanoTime()-start;
327+
if (maxSyncTime < len) {
328+
maxSyncTime = len;
329+
}
330+
sumSyncTime += len;
331+
countSyncs++;
256332
int toCopy = inBuffer-readOffset;
257333
if (dest.length < toCopy) {
258334
toCopy = dest.length;
@@ -273,7 +349,14 @@ public byte[] readBytesUntil(int inByte) {
273349
return null;
274350
}
275351

352+
long start = System.nanoTime();
276353
synchronized (buffer) {
354+
long len = System.nanoTime()-start;
355+
if (maxSyncTime < len) {
356+
maxSyncTime = len;
357+
}
358+
sumSyncTime += len;
359+
countSyncs++;
277360
// look for needle in buffer
278361
int found = -1;
279362
for (int i=readOffset; i < inBuffer; i++) {
@@ -304,7 +387,14 @@ public int readBytesUntil(int inByte, byte[] dest) {
304387
return 0;
305388
}
306389

390+
long start = System.nanoTime();
307391
synchronized (buffer) {
392+
long len = System.nanoTime()-start;
393+
if (maxSyncTime < len) {
394+
maxSyncTime = len;
395+
}
396+
sumSyncTime += len;
397+
countSyncs++;
308398
// look for needle in buffer
309399
int found = -1;
310400
for (int i=readOffset; i < inBuffer; i++) {
@@ -362,41 +452,72 @@ public String readStringUntil(int inByte) {
362452
public void serialEvent(SerialPortEvent event) {
363453
if (event.getEventType() == SerialPortEvent.RXCHAR) {
364454
int toRead;
455+
countEvents++;
456+
if (firstEvent == 0) {
457+
firstEvent = System.nanoTime();
458+
}
365459
try {
366460
while (0 < (toRead = port.getInputBufferBytesCount())) {
461+
long start = System.nanoTime();
367462
// this method can be called from the context of another thread
368463
synchronized (buffer) {
464+
long len = System.nanoTime()-start;
465+
if (maxReadSyncTime < len) {
466+
maxReadSyncTime = len;
467+
}
468+
sumReadSyncTime += len;
369469
// enlarge buffer if necessary
370470
if (buffer.length < inBuffer+toRead) {
371471
byte temp[] = new byte[buffer.length<<1];
372472
System.arraycopy(buffer, 0, temp, 0, inBuffer);
373473
buffer = temp;
374474
}
475+
if (maxBufferLength < buffer.length) {
476+
maxBufferLength = buffer.length;
477+
}
375478
// read an array of bytes and copy it into our buffer
479+
start = System.nanoTime();
376480
byte[] read = port.readBytes(toRead);
481+
len = System.nanoTime()-start;
482+
if (maxReadTime < len) {
483+
maxReadTime = len;
484+
}
485+
sumReadTime += len;
486+
if (maxRead < read.length) {
487+
maxRead = read.length;
488+
}
489+
sumRead += read.length;
490+
countReads++;
377491
System.arraycopy(read, 0, buffer, inBuffer, read.length);
378492
inBuffer += read.length;
379-
if (serialEventMethod != null) {
380-
if ((0 < bufferUntilSize && bufferUntilSize <= inBuffer-readOffset) ||
381-
(0 == bufferUntilSize && bufferUntilByte == buffer[inBuffer-1])) {
382-
try {
383-
// serialEvent() is invoked in the context of the current (serial) thread
384-
// which means that serialization and atomic variables need to be used to
385-
// guarantee reliable operation (and better not draw() etc..)
386-
// serialAvailable() does not provide any real benefits over using
387-
// available() and read() inside draw - but this function has no
388-
// thread-safety issues since it's being invoked during pre in the context
389-
// of the Processing applet
390-
serialEventMethod.invoke(parent, new Object[] { this });
391-
} catch (Exception e) {
392-
System.err.println("Error, disabling serialEvent() for "+port.getPortName());
393-
System.err.println(e.getLocalizedMessage());
394-
serialEventMethod = null;
493+
}
494+
if (serialEventMethod != null) {
495+
if ((0 < bufferUntilSize && bufferUntilSize <= inBuffer-readOffset) ||
496+
(0 == bufferUntilSize && bufferUntilByte == buffer[inBuffer-1])) {
497+
try {
498+
// serialEvent() is invoked in the context of the current (serial) thread
499+
// which means that serialization and atomic variables need to be used to
500+
// guarantee reliable operation (and better not draw() etc..)
501+
// serialAvailable() does not provide any real benefits over using
502+
// available() and read() inside draw - but this function has no
503+
// thread-safety issues since it's being invoked during pre in the context
504+
// of the Processing applet
505+
start = System.nanoTime();
506+
serialEventMethod.invoke(parent, new Object[] { this });
507+
long len = System.nanoTime()-start;
508+
if (maxFuncTime < len) {
509+
maxFuncTime = len;
395510
}
511+
sumFuncTime += len;
512+
countFuncs++;
513+
} catch (Exception e) {
514+
System.err.println("Error, disabling serialEvent() for "+port.getPortName());
515+
System.err.println(e.getLocalizedMessage());
516+
serialEventMethod = null;
396517
}
397518
}
398-
invokeSerialAvailable = true;
399519
}
520+
invokeSerialAvailable = true;
400521
}
401522
} catch (SerialPortException e) {
402523
throw new RuntimeException("Error reading from serial port " + e.getPortName() + ": " + e.getExceptionType());
@@ -439,7 +560,14 @@ public void stop() {
439560
public void write(byte[] src) {
440561
try {
441562
// this might block if the serial device is not yet ready (esp. tty devices under OS X)
563+
long start = System.nanoTime();
442564
port.writeBytes(src);
565+
long len = System.nanoTime()-start;
566+
if (maxWriteTime < len) {
567+
maxWriteTime = len;
568+
}
569+
sumWriteTime += len;
570+
countWrites++;
443571
// we used to call flush() here
444572
} catch (SerialPortException e) {
445573
throw new RuntimeException("Error writing to serial port " + e.getPortName() + ": " + e.getExceptionType());
@@ -449,7 +577,14 @@ public void write(byte[] src) {
449577

450578
public void write(int src) {
451579
try {
580+
long start = System.nanoTime();
452581
port.writeInt(src);
582+
long len = System.nanoTime()-start;
583+
if (maxWriteTime < len) {
584+
maxWriteTime = len;
585+
}
586+
sumWriteTime += len;
587+
countWrites++;
453588
} catch (SerialPortException e) {
454589
throw new RuntimeException("Error writing to serial port " + e.getPortName() + ": " + e.getExceptionType());
455590
}
@@ -458,7 +593,14 @@ public void write(int src) {
458593

459594
public void write(String src) {
460595
try {
596+
long start = System.nanoTime();
461597
port.writeString(src);
598+
long len = System.nanoTime()-start;
599+
if (maxWriteTime < len) {
600+
maxWriteTime = len;
601+
}
602+
sumWriteTime += len;
603+
countWrites++;
462604
} catch (SerialPortException e) {
463605
throw new RuntimeException("Error writing to serial port " + e.getPortName() + ": " + e.getExceptionType());
464606
}

0 commit comments

Comments
 (0)