[coreboot] Timing via serial port

[Kevin O'Connor]

Hi,

I wrote a script that can be used on a host machine to read from the
serial port and output timing information on each line received.  It
also tries to adjust for time spent by the target machine actually
generating the serial reports.  The script is attached if anyone wants
to use it (it requires python and the pyserial package).

The results are interesting.

On my epia-cn machine, it takes coreboot-v2 8.7 seconds to launch
SeaBIOS.  It looks like about 4 seconds is lost due to a reboot
half-way through the startup - I'm guessing a watchdog timer is
kicking in.  As to why it takes so long to boot - maybe rom caching is
off?

SeaBIOS takes 1.5 seconds (from startup to OS launch) - after
subtracting the 2.5 seconds spent waiting at the boot menu.

The biggest SeaBIOS time consumers:

500ms - initializing the ps2 port / keyboard

425ms - scanning for option roms

260ms - initializing ATA drives

200ms - running the via vga rom

-Kevin

#!/usr/bin/env python
# Script that can read from a serial device and show timestamps.
#
# Copyright (C) 2009  Kevin O'Connor <ke...@koconnor.net>
#
# This file may be distributed under the terms of the GNU GPLv3 license.

# Usage:
#   tools/readserial.py /dev/ttyUSB0 115200

import sys
import time
import select
import serial

# 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

def readserial(infile, logfile, baudrate):
    starttime = 0
    isnewline = 1
    while 1:
        # Read data
        try:
            select.select([infile], [], [])
        except KeyboardInterrupt:
            break
        curtime = time.time()
        d = infile.read(4096)
        logfile.write(d)
        logfile.flush()

        # Reset start time if no data for some time
        if curtime - starttime > RESTARTINTERVAL:
            starttime = curtime
            charcount = 0
            isnewline = 1
            sys.stdout.write("\n")

        # Translate unprintable chars; add timestamps
        out = ""
        for c in d:
            if isnewline:
                delta = curtime - starttime
                if ADJUSTBAUD:
                    delta -= float(charcount * 9) / baudrate
                out += "%07.3f: " % delta
                isnewline = 0
            oc = ord(c)
            charcount += 1
            if oc == 0x0d:
                continue
            if oc == 0x0a:
                out += "\n"
                isnewline = 1
                continue
            if oc < 0x20 or oc >= 0x7f and oc != 0x09:
                out += "<%02x>" % oc
                continue
            out += c

        sys.stdout.write(out)
        sys.stdout.flush()

def printUsage():
    print "Usage:\n   %s [<serialdevice> [<baud>]]" % (sys.argv[0],)
    sys.exit(1)

def main():
    serialport = 0
    baud = 115200
    if len(sys.argv) > 3:
        printUsage()
    if len(sys.argv) > 1:
        serialport = sys.argv[1]
    if len(sys.argv) > 2:
        baud = int(sys.argv[2])

    ser = serial.Serial(serialport, baud, timeout=0)

    logname = time.strftime("seriallog-%Y%m%d_%H%M%S.log")
    f = open(logname, 'wb')
    readserial(ser, f, baud)

if __name__ == '__main__':
    main()

-- 
coreboot mailing list: coreboot@coreboot.org
http://www.coreboot.org/mailman/listinfo/coreboot