Some serial ports have slightly different timing. These timing variations result in less accurate boot time reporting. So, add a calibration mechanism to the tool so that one can determine how much time a specific machine's serial port uses.
Also, extend the main part of the tool to allow the user to specify an exact timing parameter. --- tools/readserial.py | 73 ++++++++++++++++++++++++++++++++++++++++++-------- 1 files changed, 61 insertions(+), 12 deletions(-)
diff --git a/tools/readserial.py b/tools/readserial.py index 9c955c6..d85392e 100755 --- a/tools/readserial.py +++ b/tools/readserial.py @@ -15,18 +15,48 @@ import optparse
# Reset time counter after this much idle time. RESTARTINTERVAL = 60 -# Alter timing reports based on how much time would be spent writing -# to serial. -ADJUSTBAUD = 1 # Number of bits in a transmitted byte - 8N1 is 1 start bit + 8 data # bits + 1 stop bit. BITSPERBYTE = 10
-def readserial(infile, logfile, baudrate): +def calibrateserialwrite(outfile, byteadjust): + # Build 4000 bytes of dummy data. + data = "0123456789" * 4 + "012345678" + "\n" + data = data * 80 + while 1: + st = time.time() + outfile.write(data) + outfile.flush() + et = time.time() + sys.stdout.write( + "Wrote %d - %.1fus per char (theory states %.1fus)\n" % ( + len(data), (et-st) / len(data) * 1000000, byteadjust * 1000000)) + sys.stdout.flush() + time.sleep(3) + +def calibrateserialread(infile, byteadjust): + starttime = lasttime = 0 + totalchars = 0 + while 1: + select.select([infile], [], []) + d = infile.read(4096) + curtime = time.time() + if curtime - lasttime > 1.0: + if starttime and totalchars: + sys.stdout.write( + "Calibrating on %d bytes - %.1fus per char" + " (theory states %.1fus)\n" % ( + totalchars, + float(lasttime - starttime) * 1000000 / totalchars, + byteadjust * 1000000)) + totalchars = 0 + starttime = curtime + else: + totalchars += len(d) + lasttime = curtime + +def readserial(infile, logfile, byteadjust): lasttime = 0 - byteadjust = 0.0 - if ADJUSTBAUD: - byteadjust = float(BITSPERBYTE) / baudrate while 1: # Read data try: @@ -52,8 +82,8 @@ def readserial(infile, logfile, baudrate): starttime = datatime charcount = 0 isnewline = 1 - msg = "\n\n======= %s (adjust=%d)\n" % ( - time.asctime(time.localtime(datatime)), ADJUSTBAUD) + msg = "\n\n======= %s (adjust=%.1fus)\n" % ( + time.asctime(time.localtime(datatime)), byteadjust * 1000000) sys.stdout.write(msg) logfile.write(msg) lasttime = datatime @@ -97,6 +127,15 @@ def main(): opts.add_option("-n", "--no-adjust", action="store_false", dest="adjustbaud", default=True, help="don't adjust times by serial rate") + opts.add_option("-c", "--calibrate-read", + action="store_true", dest="calibrate_read", default=False, + help="read from serial port to calibrate it") + opts.add_option("-C", "--calibrate-write", + action="store_true", dest="calibrate_write", default=False, + help="write to serial port to calibrate it") + opts.add_option("-t", "--time", + type="float", dest="time", default=None, + help="time to write one byte on serial port (in us)") options, args = opts.parse_args() serialport = 0 baud = 115200 @@ -106,8 +145,11 @@ def main(): serialport = args[0] if len(args) > 1: baud = int(args[1]) - global ADJUSTBAUD - ADJUSTBAUD=options.adjustbaud + byteadjust = float(BITSPERBYTE) / baud + if options.time is not None: + byteadjust = options.time / 1000000.0 + if not options.adjustbaud: + byteadjust = 0.0
if options.serial: # Read from serial port @@ -129,9 +171,16 @@ Or: apt-get install python-serial fcntl.fcntl(ser, fcntl.F_SETFL , fcntl.fcntl(ser, fcntl.F_GETFL) | os.O_NONBLOCK)
+ if options.calibrate_read: + calibrateserialread(ser, byteadjust) + return + if options.calibrate_write: + calibrateserialwrite(ser, byteadjust) + return + logname = time.strftime("seriallog-%Y%m%d_%H%M%S.log") f = open(logname, 'wb') - readserial(ser, f, baud) + readserial(ser, f, byteadjust)
if __name__ == '__main__': main()
Kevin O'Connor wrote:
]Some serial ports have slightly different timing. These timing ]variations result in less accurate boot time reporting. So, add a ]calibration mechanism to the tool so that one can determine how much ]time a specific machine's serial port uses.
Hello Kevin,
A while back I noticed both SeaBIOS and coreboot poll for TEMP (line status register bit for transmitter empty) before transmitting a character. An alternative is to poll THRE (transmitter holding register empty) instead.
Polling TEMP forces the code to wait until the final stop bit time period is complete before it can load the next character. It is understandable that on some implementations this will cause one idle bit time to pass before transmission of the next character starts.
When THRE is polled, the code has a period of nearly 10 bit times where the next character can be loaded such that it will transmit without any unneeded idle time between characters.
Here is the result of a transmit test using both methods on ASRock E350M1. The test works by timing a 5 second transmit:
TX baud rate test, TEMP method (SeaBIOS and coreboot) selected Measured Percent Error 110 100 9 300 273 9 600 546 9 1200 1092 9 2400 2185 8 4800 4370 8 9600 8742 8 19200 17484 8 28800 26225 8 38400 34967 8 57600 52451 8 115200 104899 8
TX baud rate test, THRE method selected Measured Percent Error 110 110 0 300 300 0 600 600 0 1200 1201 0 2400 2403 0 4800 4807 0 9600 9615 0 19200 19232 0 28800 28848 0 38400 38464 0 57600 57697 0 115200 115394 0
I also noticed coreboot enables the uart fifos. This is not beneficial because the simple polling logic used by coreboot and SeaBIOS cannot utilize the transmit fifo.
Thanks, Scott
On Sat, Jul 09, 2011 at 03:44:50PM -0500, Scott Duplichan wrote:
Kevin O'Connor wrote:
]Some serial ports have slightly different timing. These timing ]variations result in less accurate boot time reporting. So, add a ]calibration mechanism to the tool so that one can determine how much ]time a specific machine's serial port uses.
Hello Kevin,
A while back I noticed both SeaBIOS and coreboot poll for TEMP (line status register bit for transmitter empty) before transmitting a character. An alternative is to poll THRE (transmitter holding register empty) instead.
Polling TEMP forces the code to wait until the final stop bit time period is complete before it can load the next character. It is understandable that on some implementations this will cause one idle bit time to pass before transmission of the next character starts.
When THRE is polled, the code has a period of nearly 10 bit times where the next character can be loaded such that it will transmit without any unneeded idle time between characters.
Thanks Scott, in some of my recent tests I noticed that in the SeaBIOS code as well. I just sent a patch in a separate email. Unfortunately, I didn't see an improvement in the timing accuracy even after I made that change. Maybe I've missed something else.
Here is the result of a transmit test using both methods on ASRock E350M1. The test works by timing a 5 second transmit:
TX baud rate test, TEMP method (SeaBIOS and coreboot) selected Measured Percent Error 110 100 9 300 273 9 600 546 9 1200 1092 9 2400 2185 8 4800 4370 8 9600 8742 8 19200 17484 8 28800 26225 8 38400 34967 8 57600 52451 8 115200 104899 8
I'm seeing something very similar when running timing tests under Linux. I get ~93.9us per char instead of the 86.8us per character at 115200 baud - a difference of 8%. This was under Linux though.
Oddly, under Linux, if I use bigger transmissions (eg, 10K) instead of just 4000 byte transmissions I get much better timings - as little as 88.1us. Maybe Linux is using the fifos when the transmission is large enough.
TX baud rate test, THRE method selected Measured Percent Error 110 110 0 300 300 0 600 600 0 1200 1201 0 2400 2403 0 4800 4807 0 9600 9615 0 19200 19232 0 28800 28848 0 38400 38464 0 57600 57697 0 115200 115394 0I also noticed coreboot enables the uart fifos. This is not beneficial because the simple polling logic used by coreboot and SeaBIOS cannot utilize the transmit fifo.
Could the fifos being enabled be the cause of the slow down even after the SeaBIOS serial polling fix?
-Kevin
On Sat, Jul 09, 2011 at 07:01:00PM -0400, Kevin O'Connor wrote:
I also noticed coreboot enables the uart fifos. This is not beneficial because the simple polling logic used by coreboot and SeaBIOS cannot utilize the transmit fifo.
Could the fifos being enabled be the cause of the slow down even after the SeaBIOS serial polling fix?
I ran a quick test with the fifos disabled. Unfortunately, I still get a slower transmit rate - off by about 8us per character on my e350m1 - even with the seabios patch I sent separately. Weird.
-Kevin
On Sat, Jul 09, 2011 at 07:23:23PM -0400, Kevin O'Connor wrote:
On Sat, Jul 09, 2011 at 07:01:00PM -0400, Kevin O'Connor wrote:
I also noticed coreboot enables the uart fifos. This is not beneficial because the simple polling logic used by coreboot and SeaBIOS cannot utilize the transmit fifo.
Could the fifos being enabled be the cause of the slow down even after the SeaBIOS serial polling fix?
I ran a quick test with the fifos disabled. Unfortunately, I still get a slower transmit rate - off by about 8us per character on my e350m1 - even with the seabios patch I sent separately. Weird.
Bleh - that was really dumb. I had:
while ((inb(CONFIG_DEBUG_SERIAL_PORT+SEROFF_LSR) & 0x40) != 0x40)
instead of:
while ((inb(CONFIG_DEBUG_SERIAL_PORT+SEROFF_LSR) & 0x20) != 0x20)
That bit error led me down a wrong path.. It's odd that Linux seems to have the same issue.
-Kevin
-
Kevin O'Connor -
Scott Duplichan