Docstoc

TRACE

Document Sample
TRACE Powered By Docstoc
					TRACE

   Stephen Foulkes Ron Rechenmacher
  sfoulkes@fnal.gov  ron@fnal.gov
Motivation

      Need a logging facility that:
          Extremely low overhead
          Can gather timing information

          Can log in different ways

          Open source / free ware

          Works well with multithreaded apps

          Works on VxWorks and Linux




 May 3, 2007          IEEE NPSS RT07 - CM Tools - 04   2
TRACE Overview
 • Originally developed at FNAL by R. Rechenmacher
 • Support for Linux on x86, x86_64 and PowerPC, VxWorks on
 PowerPC




May 3, 2007             IEEE NPSS RT07 - CM Tools - 04        3
TRACE on Linux

   Based inside the kernel
   Configuration, status information is
    exported through /proc/trace
   Binaries with TRACE run on systems
    without TRACE
   Only supports C/C++ applications




May 3, 2007     IEEE NPSS RT07 - CM Tools - 04   4
The TRACE Circular Buffer

    Default logging backend in TRACE
    Contained in kernel space, in memory
    Thread safe, and can log messages from
     interrupt contexts
    Collects timing information
    One buffer contains all messages




 May 3, 2007     IEEE NPSS RT07 - CM Tools - 04   5
TRACE Circular Buffer Example
    21051      uS   MIBPMFlashTurnTask.hpp:process() Flash 8 triggered
   238737      uS   MIBPMControl.cpp:changeMode() Done changing to flash...
      738      uS   MIBPMControl.cpp:changeMode() Enabling flash turn mode...
        9      uS   MIBPMControl.cpp:changeMode() Changing mode FLASH...
        3      uS   MIBPMControl.cpp:changeMode() Change mode starting...
   548319      uS   MIBPMFlashTurnTask.hpp:process() Flash 7 triggered
    66702      uS   MIBPMFlashTurnTask.hpp:process() Flash 6 triggered
    66693      uS   MIBPMFlashTurnTask.hpp:process() Flash 5 triggered
    66711      uS   MIBPMFlashTurnTask.hpp:process() Flash 4 triggered
    66675      uS   MIBPMFlashTurnTask.hpp:process() Flash 3 triggered
    66708      uS   MIBPMFlashTurnTask.hpp:process() Flash 2 triggered
    66675      uS   MIBPMFlashTurnTask.hpp:process() Flash 1 triggered
    50799      uS   MIBPMControl.cpp:changeMode() Done changing to flash...
      753      uS   MIBPMControl.cpp:changeMode() Enabling flash turn mode...




 May 3, 2007                     IEEE NPSS RT07 - CM Tools - 04                 6
Generating TRACE Messages
     Define a TRACE name:
             #define TRACE_NAME “myApplication”
     Include the TRACE header
     Add TRACE calls where appropriate:
             TRACE(int level, char *fmt, int
              param1, int param2, int param3 …);
     Level is used to group messages
     Can use %d, %x, %c as conversion specifiers
     Only supports integer types (int, long, etc)
     Maximum of six parameters


May 3, 2007             IEEE NPSS RT07 - CM Tools - 04   7
Reading The Circular Buffer

    Contents of the circular buffer are
     accessed through /proc/trace/buffer
    The columns displayed are controllable
     through /proc/trace/control
              Available columns include time stamp, pid,
               level, cycle, TRACE name, message, count
              echo print=timeStamp,PID,lvl,message \
                          > /proc/trace/control


 May 3, 2007               IEEE NPSS RT07 - CM Tools - 04   8
Filtering Messages

          All filtering is controlled through
           /proc/trace/level:
             KERNEL=0x00000000,0x00000000,0x00000000,0x00000000
       realtimedemo=0xffffffff,0x0000000f,0x00000000,0x00000000
          NULL_NAME=0xffffffff,0x00000000,0x00000000,0xffffffff
               FULL=0xffffffff,0x00000000,0x00000000,0xffffffff



          Configurable from the command line:
              echo KERNEL=0xf,0xf,0x0,0x0 \
                   > /proc/trace/level

 May 3, 2007              IEEE NPSS RT07 - CM Tools - 04          9
Miscellaneous Tasks

      Clearing the circular buffer:
              echo reset > /proc/trace/control
      Enabling/Disabling Logging Backends
              Mode is a bitmask that enables/disables the
               backends
              echo mode=0x3 > /proc/trace/control
              Turn TRACE completely off:
                   echo mode=0x0 > /proc/trace/control




 May 3, 2007                  IEEE NPSS RT07 - CM Tools - 04   10
Installing TRACE

      If your architecture is already supported,
       this is easy:
              Download and unpack the TRACE tarball
                   ftp://ftp.fnal.gov/pub/trace/current
              make install
                   The installer will try to guess the location of your
                    kernel sources and version, and will apply the
                    correct set of patches
      Rebuild your kernel and reboot

 May 3, 2007                    IEEE NPSS RT07 - CM Tools - 04             11
A successful TRACE installation
   CPU 0 irqstacks, hard=c03f5000 soft=c03d5000
   PID hash table entries: 4096 (order: 12, 65536 bytes)
   Detected 1600.001 MHz processor.
   Using pmtmr for high-res timesource
   trace_init: allocated 4096(0x1000) bytes for …
   trace_init: allocated 4096(0x1000) bytes for sp …
   trace_init: traceLevel_ip=c191e010
   trace_init: attempting to allocate 8392704(0x801000)
   trace: cpu0 just set AMD PMC0 to 0x400003
   trace: cpu0 just set AMD PMC1 to 0x400004
   Console: colour VGA+ 80x25
   Dentry cache hash table entries: 131072 (order: 7,
      524288 bytes)
   Memory: 1024868k/1048064k available (1897k kernel code,
      22316k reserved, 767k data, 184k init, 130496k
      highmem)


 May 3, 2007          IEEE NPSS RT07 - CM Tools - 04         12
Configuring The Circular Buffer

    Configuration is done at compile time
    Can change:
          The max number of applications that can
           log to TRACE
          The max number of logging backends
          The max message size
          The max number of parameters to a
           message
      All contained in src/init/trace.c

 May 3, 2007          IEEE NPSS RT07 - CM Tools - 04   13
TRACE Example

   Define a function to log to the console
    with printf()
   Generate two TRACE messages, one
    with parameters and one without
   Should see both messages on the
    console, and in the circular buffer



May 3, 2007      IEEE NPSS RT07 - CM Tools - 04   14
TRACE Example
  #include <stdio.h>
  #include <sys/time.h>
  #include <stdarg.h>

  // Define my logging function, log to the console
  void steves_logger(struct timeval *time, int lvl,
    int id, char *fmt, ...) {
    va_list ap;
    va_start( ap, msg );
    vprintf( msg, ap );
    va_end( ap );
  }



May 3, 2007        IEEE NPSS RT07 - CM Tools - 04     15
TRACE Example
  #define TRACE_NAME “realtimedemo”
  #define TRACE_FUNCTIONS {steves_logger}

  #include <linux/trace.h>

  int main() {
    int one = 1; int eleven = 11;
    TRACE(0, “Hello World!”);
    TRACE(5, “With parameters: %d %x”, one, eleven);

      return 0;
  }

May 3, 2007        IEEE NPSS RT07 - CM Tools - 04      16
TRACE Example
  [~]$ gcc -I/usr/src/linux/include -Wall test.c
  [~]$ ./a.out
  Hello World!
  With parameters: 1 b
  [~]$ cat /proc/trace/buffer
  timeStamp    PID     lvl Name         Message
  --------------------------------------------------
  117757564    8259    5   realtimedemo With Parameters: 1 b
  117751573    8259    0   realtimedemo Hello World!
  [~]$




May 3, 2007            IEEE NPSS RT07 - CM Tools - 04          17
Summary

     Open source logging facility that runs on
      VxWorks and Linux
         Low overhead
         Multiple backends

         Easy filtering of messages



     TRACE Website:
             http://fermitools.fnal.gov/abstracts/trace/abstract.html


May 3, 2007                   IEEE NPSS RT07 - CM Tools - 04             18

				
DOCUMENT INFO
Shared By:
Categories:
Stats:
views:5
posted:5/12/2010
language:English
pages:18