well. there are several options.

a) using Tcl traces (somewhat similar to what you are doing,
   see also [1]

b) when using nsf, one can profile oo methods and procs.
   nsf defines a value-added version of "proc" called "nsf::proc",
   that allows e.g. optional type checking of arguments, checking of
   return results ... and as well profiling (when compiled
   with "--enable-profile"

   From nsf profiling, one can get
   1) detailed profiling about a full run, or
   2) profiling about single calls ("nsf::proc -debug ... {args} { .. body ...}".

   See below the proc "profile" how profiling can be used in nsf,
   by collecting the profiling information in a Tcl list. We have
   some code that produces from the resulting  Tcl list a colored
   HTML rendering, but that can be quite large. It is also possible to
   log  the profiling information to the error.log of
   NaviServer (not shown here)

   There is as well a third option in nsf by using dtrace [2], which allows to get detailed    profiling information from nsf (and Tcl as well).... but, last time i checked,
   this was only working well with Mac OS X (and maybe Solaris).


[1] https://github.com/openacs/openacs-core/blob/master/packages/acs-tcl/tcl/tcltrace-init.tcl
[2] https://github.com/gustafn/nsf/tree/master/dtrace

nsf::proc profile {cmd} {

    # Clear all old profiling information and start tracing
    nsf::__profile_trace -enable true

    # Use a datafile for keeping the profiling information. You might
    # want to tailor this in case you are working with multiple
    # profiling runs.
    set datafile [ns_mktemp]

    try {
        uplevel $cmd

    } on error {errorMsg} {
        error $errorMsg

    } finally {
        nsf::__profile_trace -enable false

    # Profiling is now turned off again, and we can the the profiling
    # information from nsf and save it to the trace file.
    set f [open $datafile w]
    puts $f [::nsf::__profile_get]
    close $f

On 2/13/18 1:03 PM, David Osborne wrote:

We've been looking at profiling the execution times of various application-level procs running NaviServer.

We want the ability to turn on profiling for selected commands, so we started off using Tcl traces in a manner similar to:

So we'd have a proc to set up a Tcl trace on command execution enter/leave in a list like so:

proc instrument {args} {
    #| Takes list of commands and adds Tcl execution trace for entering and exit
    set script ""
    foreach cmd $args {
            append script "trace add execution $cmd enter profile_begin\n"
            append script "trace add execution $cmd leave profile_end\n"
    eval $script

At the start of each proc in the list we'd push the start time to a stack:

proc profile_begin args {
    # Append current time to timer stack for this thread
    variable ::timerStack
    lappend ::timerStack [::tcl::clock::microseconds]

And then pop off the time when proc exits:

proc profile_end {command_string code result op} {
    #| Pop value off timer stack for this thread and record a subsegment
    variable ::timerStack
    set start_time [lindex $::timerStack end]
    set end_time [::tcl::clock::microseconds]
    set ::timerStack [lrange $::timerStack 0 end-1]
    record_the_timing $command_string $start_time $end_time

It wasn't obvious to me how to set up these Tcl traces so they are active in each NaviServer interpreter, but after some trial and error, I could get a result by using ns_ictl to set up a callback on interpreter allocation and use that to set up the Tcl trace:

ns_ictl trace allocate "instrument $cmd_list"

This seems to work ok but has the disadvantage that I think I need to restart NaviServer in order to add or remove commands.

So I wanted to ask:
1. Is there a more dynamic way of setting up Tcl traces across NaviServer interpreters? 2. Is anyone aware of a different/better way of profiling applications running under NaviServer?


Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot
naviserver-devel mailing list

Reply via email to