Measuring Boot Time

From Texas Instruments Embedded Processors Wiki

Jump to: navigation, search


  • Image:Google-16x16.png Search for an article here:


Here is a way to measure boot time on Host. Idea is take timestamp on host after each uart message. Built and used only within cygwin on windows. However, I expect it to work on other platforms.

copy paste the following as tstamp.c and build tstamp.exe (I used gcc under cygwin).

// Purpose of this utility is to timestamp each line coming over stdin
// USAGES:
//    tstamp.exe < /dev/ttyS0
//    <commands> | tstamp.exe
// 

#include <stdio.h>
#include <time.h>
#include <sys/time.h>

char buf[10*1024];

main(int argc)
{
  struct timeval tv;
  double time_start,time_now,time_prev;
  int first=1;

  if(argc!=1) // as of now no arguments are allowed. print usage
  {
     printf("Timestamps each line coming over stdin\n"
             "\tUSAGES:\n"
             "\t\ttstamp.exe < /dev/ttyS0\n"
             "\t\t<commands> | tstamp.exe\n"
             "\t\tetc..\n");
     printf("Output is printed in the following format\n"
               "\tcolumn1 is elapsed time since first message"
               "\tcolumn2 is elapsed time since previous message\n"
             "\tcolumn3 is the message\n");
 
     exit(0);
  }

  printf("\tcolumn1 is elapsed time since first message\n"
           "\tcolumn2 is elapsed time since previous message\n"
         "\tcolumn3 is the message\n");

  while(1)
  {
    if(gets(buf))
    {
       gettimeofday(&tv, NULL); // get system time
       time_now = tv.tv_sec + (tv.tv_usec*(1.0/1000000.0)); // convert to double
       if(first) // if first time, notedown the time_start
         first = 0,  time_start = time_prev = time_now;

       printf("%03.3f %02.3f: ",(float)(time_now-time_start),
                      (float)(time_now-time_prev)); // print the column1 and 2

       puts(buf); // now print the message as column3
       time_prev = time_now;
    }
  }
}

Run tstamp.exe < /dev/ttyS0 and reset DVEVM. Assuming that uart is connected to PC. Here is the sample output:

       column1 is elapsed time since first message
       column2 is elapsed time since previous message
       column3 is the message
0.000 0.000:
0.000 0.000:
0.000 0.000: U-Boot 1.2.0 (Jun 23 2008 - 14:53:30)
0.000 0.000:
0.000 0.000: I2C:   ready
0.000 0.000: DRAM:  256 MB
0.000 0.000: MY AMD Flash: 16 MB
0.060 0.060: n:    serial
0.060 0.000: Out:   serial
0.060 0.000: Err:   serial
0.060 0.000: RM Clock :- 297MHz DDR Clock :- 162MHz
1.071 1.011: Hit any key to stop autoboot:   0
1.261 0.190: # Booting image at 80007fc0 ...
1.261 0.000:    Verifying Checksum ...
1.331 0.070: OK
1.331 0.000: OK
1.331 0.000: ## Loading Ramdisk Image at 80900000 ...
1.331 0.000:    Verifying Checksum ...
1.422 0.091: K
1.422 0.000:
1.422 0.000: Starting kernel ...
1.432 0.010:
2.093 0.661: ncompressing Linux.................................................
......................... oe otn he kernel.
2.463 0.370:bin/ash: can't access tty; job control turned off

Press Control-C to exit tstamp.exe.

  • Noticed some characters missing in the output. Not sure why (as of now).
  • Did not come across any terminal emulator which can timestamp incoming messages.
  • Please use the following instruction below to set the correct UART Speed & configuration under Fedora 8 before using tstamp.
 stty -F /dev/ttyS0 speed 115200 -parenb -cstopb cread clocal -crtscts

For technical support please post your questions at http://e2e.ti.com. Please post only comments about the article Measuring Boot Time here.
Leave a Comment

Comments

  1. REDIRECT Talk:OMAP-L137/DA830 Linux LCD driver
Personal tools