From owner-freebsd-questions  Wed Feb  1 10:44:15 1995
Return-Path: questions-owner
Received: (from root@localhost) by freefall.cdrom.com (8.6.9/8.6.6) id KAA01668 for questions-outgoing; Wed, 1 Feb 1995 10:44:15 -0800
Received: from amcell2.caisr.cwru.edu (amcell2.CAISR.CWRU.Edu [129.22.24.2]) by freefall.cdrom.com (8.6.9/8.6.6) with ESMTP id KAA01661 for <freebsd-questions@freefall.cdrom.com>; Wed, 1 Feb 1995 10:44:14 -0800
Received: (from ljo@localhost) by amcell2.caisr.cwru.edu (8.6.9/8.6.6) id JAA09582; Wed, 1 Feb 1995 09:44:47 -0500
Date: Wed, 1 Feb 1995 09:44:47 -0500
From: L Jonas Olsson <ljo@amcell2.caisr.cwru.edu>
Message-Id: <199502011444.JAA09582@amcell2.caisr.cwru.edu>
To: freebsd-questions@freefall.cdrom.com
Subject: Bogus profiling info
Reply-to: ljo@po.CWRU.Edu
Sender: questions-owner@FreeBSD.org
Precedence: bulk

 I'm profiling some code to find what parts to optimize. The problem is
that most of the time is spent in some mystery place.

 This is on FreeBSD 2.0R, using -pg option to gcc, and gprof to get
the results. The program uses a device driver that re-programs the
timer0 to 400 Hz during some parts of the program. It also forks
another program (not compiled with -pg) that it sends data to using
pipes. All linked libraries are compiled for profiling.

 The profile looks something like: (only the flat profile part, the
mystery functions are called spontaneously, so the graph gives no more
info.

  %   cumulative   self              self     total           
 time   seconds   seconds    calls  ms/call  ms/call  name    
 14.8      39.98    39.98                             _Mystery1 [11]
 11.9      72.31    32.32      346    93.42   303.23  _func1 [10]
  7.4      92.48    20.17      346    58.29    58.29  _func2 [12]
  6.4     109.73    17.25                             _Mystery2 [13]
  6.1     126.32    16.60      346    47.96   406.16  _func3 [9]
  5.6     141.53    15.20                             _Mystery3 [15]
  4.8     154.45    12.92                             _Mystery4 [16]
  4.7     167.14    12.69      346    36.68    36.68  _func4 [18]
  4.5     179.28    12.14   323966     0.04     0.05  _func5 [14]

  The func* functions have statistics that look fine. The Mystery*
functions are functions in my program, but I know that they are never
called (Besides if they were called there would be complete info about
number of calls etc for these functions).

 I can guess that some of the time is spent in system calls, but which
and called from what functions. What else can generate this bogus
info? Is there any other way to improve the profiling information?

Jonas