nyholku / purejavacomm

Pure Java implementation of JavaComm SerialPort
http://www.sparetimelabs.com/purejavacomm/index.html
BSD 3-Clause "New" or "Revised" License
367 stars 146 forks source link

Logging exception #76

Closed dhillsberry closed 9 years ago

dhillsberry commented 9 years ago

I recently ran into an issue when enabling logging on purejavacomm. Anything above a "3" caused an exception

Exception in thread "main" java.util.IllegalFormatConversionException: x != java.lang.String at java.util.Formatter$FormatSpecifier.failConversion(Formatter.java:4302) at java.util.Formatter$FormatSpecifier.printInteger(Formatter.java:2793) at java.util.Formatter$FormatSpecifier.print(Formatter.java:2747) at java.util.Formatter.format(Formatter.java:2520) at java.util.Formatter.format(Formatter.java:2455) at java.lang.String.format(String.java:2940) at jtermios.JTermios$JTermiosLogging.log(JTermios.java:633) at jtermios.JTermios.ioctl(JTermios.java:448) at purejavacomm.PureJavaSerialPort.(PureJavaSerialPort.java:1131) at purejavacomm.CommPortIdentifier.open(CommPortIdentifier.java:159)

The problem is caused by the following line of code

log = log && log(3, "< ioctl(%d,%d,[%08X]) => %d\n", fd, cmd, Arrays.toString(data), ret);

based on the current code in the project it appears there are only ever single integers being passed into the ioctl method so there might be a better way to fix this, but I don't trust my knowledge of ioctl enough to stray too far from the approach already being taken :-). so I changed the [%08X] to %s

The result of the change is the following style of log entries

log: < ioctl(26,1074033770,[6]) => 0
log: < ioctl(26,-2147191699,[6]) => 0
log: < ioctl(26,1074033770,[6]) => 0
log: < ioctl(26,-2147191699,[6]) => 0

Part of the issue which caused me to turn on logging was related to the select timeout, which wasn't shown anyway. So I went ahead and made an additional change.

The addition of a toString method in TimeVal got me the information I needed. It's also included in this pull request just in case you are interested.

The logging before the change...

log: < select(28,[],[],[],jtermios.TimeVal@1c91c725) => 0

and after

log: < select(28,[],[],[],TimeVal [tv_sec=0, tv_usec=100000]) => 0
nyholku commented 9 years ago

Thanks, I had spotted this but had forgotten about it.