CYGPROFILER.TXT

Programs and patches

CygProfiler

A small suite for producing and resolving function call traces.

Last updated · 7 February 2007

CygProfiler is a set of functions for use with gcc's -finstrument-functions option. See info page of gcc for details and description of this option.

To use it, compile your program with -finstrument-functions and link together with cyg-profile.c. Somewhere at the beginning of the program call cygprofile_enable() to start logging all function entries and exits into a logfile.

By default the name of the logfile is cyglog.$PID, but you can set a different one using cygprofile_setfilename(). To get current logfile name use cygprofile_getfilename(). To see if logging is enabled use cygprofile_isenabled(). You can stop logging by calling cygprofile_disable().

Note that subsequent enabling of logging will overwrite the previous log with the same name!

After you have created a logfile run cyg-resolve.pl with the program name that created the logfile as a first argument and the logfile name as a second argument. On stdout you'll see a log of all instrumentalized functions invoked while logging was enabled.

Example for plain C:
$ gcc -finstrument-functions -o test test.c cyg-profile.c
$ ./test
Logfile: cyglog.1234
$ ./cyg-resolve.pl test cyglog.1234
Loading symbols from test ... OK
Seen 65 symbols, stored 22 function offsets
Level correction set to 0
        +  0 0x80486a9 (from 0x804872f)  function3()
        +  1 0x804866d (from 0x80486c8)   function2()
        +  2 0x8048634 (from 0x804868c)    function1()
done
As you can see - function3() called function2() which then called function1(). Function main() isn't in the list, because the profiling was not yet enabled at the time it was called.
Example for C++:
gcc -c cyg-profile.c
$ g++ -finstrument-functions -c test.cxx
$ g++ -o test test.o cyg-profile.o
$ ./test
Logfile: cyglog.1234
$ ./cyg-resolve.pl test cyglog.1234
Loading symbols from test ... OK
Seen 78 symbols, stored 25 function offsets
Level correction set to 1
        +  1 0x400d1c (from 0x400dcb)   _ZN4test9function3Ec()
        +  2 0x400cd4 (from 0x400d48)    _ZN4test9function2Ei()
        +  3 0x400c98 (from 0x400d01)     _ZN4test9function1El()
        +  0 0x400e3e (from 0x2a95ae2c8b)  __tcf_0()
done
The usage is similar to the plain C case. Unfortunately you'll only see the mangled function names, e.g. _ZN4test9function3Ec instead of int test::function3(char c).
See the sources:
Project notes:
Download README

cyg-profile.c source


/* 
 * cyg-profile.c - CygProfiler runtime functions.
 *
 * Michal Ludvig <michal@logix.cz>
 * /devel
 *
 * cyg-profile.c
 * - Compile your program with -finstrument-functions and link 
 *   together with this code.
 * - Logging is enabled as soon as your program calls
 *   cygprofile_enable() and disabled with cygprofile_disable().
 * - Before logging was enabled you can change the name 
 *   of a logfile by calling cygprofile_setfilename().
 */

/* Hint: -finstrument-functions, no_instrument_function */

#include <errno.h>
#include <stdio.h>
#include <unistd.h>
#include <string.h>

#include "cyg-profile.h"

#define FN_SIZE 100
#define FN_DEFAULT "cyglog.%d"

/* Private variables.  */
static int level=0;
static FILE *logfile=NULL;
static int cyg_profile_enabled=0;
static char cyg_profile_filename[FN_SIZE+1];

#ifdef __cplusplus
extern "C" {
#endif

/* Static functions. */
static FILE *openlogfile (const char *filename)
        __attribute__ ((no_instrument_function));
static void closelogfile (void)
        __attribute__ ((no_instrument_function));

/* Note that these are linked internally by the compiler. 
 * Don't call them directly! */
void __cyg_profile_func_enter (void *this_fn, void *call_site)
        __attribute__ ((no_instrument_function));
void __cyg_profile_func_exit (void *this_fn, void *call_site)
        __attribute__ ((no_instrument_function));

#ifdef __cplusplus
};
#endif

void
__cyg_profile_func_enter (void *this_fn, void *call_site)
{
        if(cyg_profile_enabled)
                if (logfile || openlogfile(cyg_profile_filename))
                        fprintf(logfile, "+ %d %p %p\n", level++,
                                this_fn, call_site);
}

void
__cyg_profile_func_exit (void *this_fn, void *call_site)
{
        if(cyg_profile_enabled)
                if (logfile || openlogfile(cyg_profile_filename))
                        fprintf(logfile, "- %d %p %p\n", level--,
                                this_fn, call_site);
}

void
cygprofile_enable (void)
{
        if (!cyg_profile_filename[0])
                cygprofile_setfilename (FN_DEFAULT);
        if (!openlogfile (cyg_profile_filename))
                return;
        cyg_profile_enabled = 1;
}

void
cygprofile_disable (void)
{
        cyg_profile_enabled = 0;
}

int
cygprofile_isenabled (void)
{ return cyg_profile_enabled; }

int
cygprofile_setfilename (const char *filename)
{
        char *ptr;

        if (cygprofile_isenabled ())
                return -1;

        if (strlen (filename) > FN_SIZE)
                return -2;

        ptr = strstr (filename, "%d");
        if (ptr)
        {
                size_t len;
                len = ptr - filename;
                snprintf (cyg_profile_filename, len+1, "%s", filename);
                snprintf (&cyg_profile_filename[len], FN_SIZE - len,
                        "%d", getpid ());
                len = strlen (cyg_profile_filename);
                snprintf (&cyg_profile_filename[len], FN_SIZE - len,
                        "%s", ptr + 2);
        }
        else
                snprintf (cyg_profile_filename, FN_SIZE, "%s", filename);

        if (logfile)
                closelogfile ();

        return 0;
}

char *
cygprofile_getfilename (void)
{
        if (!cyg_profile_filename[0])
                cygprofile_setfilename (FN_DEFAULT);
        return cyg_profile_filename;
}

static FILE *
openlogfile (const char *filename)
{
        static int complained = 0;
        FILE *file;

        if (complained)
                return NULL;

        if (logfile)
                return logfile;

        file = fopen(filename, "w");
        if (!file)
        {
                fprintf (stderr, "WARNING: Can't open logfile '%s': %s\n",
                        filename, strerror (errno));
                complained = 1;
                return NULL;
        }

        setlinebuf (file);
        logfile = file;

        return file;
}

static void
closelogfile (void)
{
        if (logfile)
                fclose (logfile);
}

Download raw cyg-profile.c ↓

cyg-profile.h source


/* 
 * cyg-profile.h - Header file for CygProfiler
 * 
 * Michal Ludvig <michal@logix.cz>
 * /devel
 *
 * This source code is a public domain.
 *
 * See cyg-profile.c for details on usage.
 */

#ifndef CYG_PROFILE_H
#define CYG_PROFILE_H

/* Public functions.  */

#ifdef __cplusplus
extern "C" {
#endif

/* Enable/disable CygProfiler.  */
void cygprofile_enable (void)
        __attribute__ ((no_instrument_function));
void cygprofile_disable (void)
        __attribute__ ((no_instrument_function));

/* Tell whether CygProfiler is enabled/disabled.  */
int cygprofile_isenabled (void)
        __attribute__ ((no_instrument_function));

/* Set filename of a logfile.  */
int cygprofile_setfilename (const char *filename)
        __attribute__ ((no_instrument_function));

/* Query for a filename of a logfile.  */
char *cygprofile_getfilename (void)
        __attribute__ ((no_instrument_function));

#ifdef __cplusplus
};
#endif

#endif

Download raw cyg-profile.h ↓

cyg-resolve.pl source


#!/usr/bin/perl

# 
# cyg-resolve.pl - CygProfiler resolver
# 
# Michal Ludvig <michal@logix.cz>
# /devel
# 
# Use this script to parse the output of the CygProfile suite.
# 

use strict;
use warnings;
no warnings 'portable';
use diagnostics;
use English;

my %symtab;
my ($binfile, $textfile, $levelcorr);

$OUTPUT_AUTOFLUSH=1;

&help() if($#ARGV < 1);
$binfile=$ARGV[0];
&help() if($binfile =~ /--help/);
$textfile=($#ARGV > 0 ? $ARGV[1] : "cygprof.log");
$levelcorr=($#ARGV > 1 ? $ARGV[2] : -1);

&main();

# ==== Subs

sub help()
{
        printf("CygProgile parser, Michal Ludvig <michal\@logix.cz>, 2002-2003\n");
        printf("Usage: %s <bin-file> <log-file> [<correction>]\n", $0);
        printf("\t<bin-file>   Program that generated the logfile.\n");
        printf("\t<log-file>   Logfile generated by the profiled program.\n");
        printf("\t<correction> Correction of the nesting level.\n");
        exit;
}

sub main()
{
        my($offset, $type, $function);
        my($nsym, $nfunc);

        $nsym=0;
        $nfunc=0;

        open(NM, "nm $binfile|") or die("Unable to run 'nm $binfile': $!\n");
        printf("Loading symbols from $binfile ... ");

        while(<NM>)
        {
                $nsym++;
                next if(!/^([0-9A-F]+) (.) (.+)$/i);
                $offset=hex($1); $type=$2; $function=$3;
                next if($type !~ /[tT]/);
                $nfunc++;
                $symtab{$offset}=$function;
        }
        printf("OK\nSeen %d symbols, stored %d function offsets\n", $nsym, $nfunc);
        close(NM);

        open(TEXT, "$textfile")
                or die("Unable to open '$textfile': $!\n");

        if ($levelcorr == -1)
        {
                $levelcorr = 0;
                while(<TEXT>)
                {
                        if ((/^.*[+-] (-*\d+)/) && ($1 < -$levelcorr))
                                { $levelcorr = -$1; }
                }
                printf("Level correction set to %d\n", $levelcorr);
                seek(TEXT, 0, 0);
        }

        while(<TEXT>)
        {
                # Change the pattern if the output format 
                # of __cyg_...() functions has changed.
                if(!/(.*)([+-]) (-*\d+) 0x([[:xdigit:]]+) 0x([[:xdigit:]]+)\s*(\d*)/)
                        { print $_; next; }
                else
                {
                        my $prolog=$1;
                        my $type=$2;

                        my $level=$3 + $levelcorr;
                        my $off1=hex($4);
                        my $off2=hex($5);
                        my $pid=$6;

                        printf("$prolog\n") if ($prolog);

                        # Don't print exits
                        next if($type eq "-");
                        my $sym=(defined($symtab{$off1})?$symtab{$off1}:"???");

                        printf("\t%s %2d 0x%x (from 0x%x) %*s%s\n",
                                $type, $level, $off1, $off2,
                                $level+1, " ", "$sym()");
                }
        }
        close(TEXT);

        printf("done\n");
}

Download raw cyg-resolve.pl ↓

test.c source


#include <stdio.h>
#include "cyg-profile.h"

int
function1 (void)
{
  return 0;
}

int
function2 (void)
{
  return function1 () + 1;
}

int
function3 (void)
{
  return function2 () + 1;
}

int
main (void)
{
  printf ("Logfile: %s\n", cygprofile_getfilename ());
  cygprofile_enable ();
  return function3 ();
}

Download raw test.c ↓

test.cxx source


#include <iostream>

#include "cyg-profile.h"

using namespace std;

class test {
    int function1 (long l);
    int function2 (int i);
  public:
    int function3 (char c);
};

int
test::function1 (long l) {
  return l;
}

int
test::function2 (int i) {
  return test::function1 (i) + 1;
}

int
test::function3 (char c) {
  return test::function2 (c) + 1;
}

int main () {
  class test *ptest;

  cout << "Logfile: " << cygprofile_getfilename () << endl;

  cygprofile_enable();

  ptest = new test();

  return ptest->function3 (1);
}

Download raw test.cxx ↓

CygProfilerUTF-8 · LOGIX.CZ

Find in Logix

Search page titles and descriptions. Esc closes.

A few handy keys

A little Borland, a little early desktop, a corner of the web to call home.

Pick a directory from the menu or tree. Use Find when you know what you’re after.

Tab / Shift+Tab
Move between controls
↑ / ↓ in menus
Choose an entry
← / → in menus
Switch directories
/
Find a page
Esc
Close menu or dialog
F1
Open this help

Prefer a different atmosphere? View has blue, grey, and green palettes.

No commands to learn. Just follow your curiosity.