Tcl Source Code

View Ticket
Login
Ticket UUID: 1793984
Title: Tcl DTrace provider
Type: Patch Version: None
Submitter: das Created on: 2007-09-13 15:18:33
Subsystem: 55. Other Tools Assigned To: das
Priority: 5 Medium Severity:
Status: Closed Last Modified: 2007-09-28 00:39:17
Resolution: Fixed Closed By: das
    Closed on: 2007-09-26 01:41:02
Description:
Implementation of a DTrace provider for Tcl, patches
against HEAD and core-8-4-branch attached.

This is something most of the other major dynamic
languages have had for a while...

The information available for tracing is similar to the
existing TCL_COMPILE_DEBUG and TCL_MEM_DEBUG facilities,
but with the big advantage that DTrace probes have
essentially zero cost when not in use, so DTrace support
can be enabled in production builds, with no performance
penalty when not tracing.
There are many other advantages, such as simultaneous
tracing of all processes using Tcl on a system,
integration with syscall tracing, control over exactly
what & when to trace, stats collection via aggregations,
etc.

DTrace support is enabled via the --enable-dtrace
configure argument, it is disabled by default and will
only enable if DTrace is present on the system.

Tested on OSX 9A500 and Solaris Express DE 5/07 x86
(~ OpenSolaris build 64a). I'd welcome testing on FreeBSD
and any other platforms where DTrace is/becomes available.
User Comments: das added on 2007-09-28 00:39:17:
Logged In: YES 
user_id=90580
Originator: YES

forgot to ask, please file a separate bug about the non-dtrace related basic.test hang on 64bit Solaris 10.
Thanks

das added on 2007-09-27 22:20:32:
Logged In: YES 
user_id=90580
Originator: YES

illumino:

this is due to a bug in dtrace (fixed in SXDE 5/07), Brendan Gregg ran into the same thing and found a workaround:


On 27/09/2007, at 5:43, Brendan Gregg - Sun Microsystems wrote:

> Here was the message I got when running make,
> 
> dtrace: failed to compile script /tmp/tcl8.4.16/unix/../generic/tclDTrace.d: line 29: syntax error near "Tcl_Obj"

> moving the struct Tcl_Obj definition from the bottom of the file to the top fixed this.


On 27/09/2007, at 10:20, Adam Leventhal wrote:

> On 27/09/2007, at 6:05, Daniel A. Steffen wrote:
> 
> > I tested my patch on SXDE 5/07 x86 before committing to tcl, it
> > worked fine there, I have also successfully built the 8.4.16 tcl
> > release with dtrace support enabled on that system.
> 
> This just fired a synapse for me and Brendan and I confirmed the hypothesis;
> Brendan was hitting this bug:
> 
>   6581257 dtrace_lookup_by_type() can fail spuriously
> 
> It was fixed a few builds ago.

illumino added on 2007-09-27 17:43:42:
Logged In: YES 
user_id=426773
Originator: NO


I have downloaded tcl-8.4.16 and tried to build with --enable-dtrace
on Solaris 10 8/07 (Update 4) with gcc version 4.1.2:

Building in a 32-bit environment (both SPARC and x86) I get:

/usr/sbin/dtrace -G  -o tclDTrace.o -s /tmp/32-bit/tcl8.4.16/unix/../generic/tclDTrace.d regcomp.o regexec.o regfree.o regerror.o tclAlloc.o tclAsync.o tclBasic.o tclBinary.o tclCkalloc.o tclClock.o tclCmdAH.o tclCmdIL.o tclCmdMZ.o tclCompCmds.o tclCompExpr.o tclCompile.o tclDate.o tclEncoding.o tclEnv.o tclEvent.o tclExecute.o tclFCmd.o tclFileName.o tclGet.o tclHash.o tclHistory.o tclIndexObj.o tclInterp.o tclIO.o tclIOCmd.o tclIOGT.o tclIOSock.o tclIOUtil.o tclLink.o tclListObj.o tclLiteral.o tclLoad.o tclMain.o tclNamesp.o tclNotify.o tclObj.o tclPanic.o tclParse.o tclParseExpr.o tclPipe.o tclPkg.o tclPosixStr.o tclPreserve.o tclProc.o tclRegexp.o tclResolve.o tclResult.o tclScan.o tclStringObj.o tclThread.o tclThreadAlloc.o tclThreadJoin.o tclStubInit.o tclStubLib.o tclTimer.o tclUtf.o tclUtil.o tclVar.o tclUnixChan.o tclUnixEvent.o tclUnixFCmd.o tclUnixFile.o tclUnixPipe.o tclUnixSock.o tclUnixTime.o tclUnixInit.o tclUnixThrd.o tclUnixCompat.o tclUnixNotfy.o  tclLoadDl.o 
dtrace: failed to compile script /tmp/32-bit/tcl8.4.16/unix/../generic/tclDTrace.d: line 29: syntax error near "Tcl_Obj"
gmake: *** [tclDTrace.o] Error 1

Which is strange, because in a 64-bit environment (both SPARC and x86)
the code builds fine, but basic.test gets into a very tight infinite
loop and external analysis tools such truss / pstack / etc have yet to
enlighten me as to what it is doing. It should be noted that, both 64-bit
versions have this behavour in basic.test regardless of dtrace enabling.

Back on the 32-bit version, I tried the command on the command line,
without any joy. I even tried added the -32 cmdline option, with anymore
success. Aside: Solaris 10 8/07 (Update 4) dtrace identifies itself
as version 1.3.

Any Thoughts or suggestions welcome,

Peter Bray
Sydney, Australia

das added on 2007-09-26 08:41:02:
Logged In: YES 
user_id=90580
Originator: YES

I have documented the DTrace support on the wiki at 
http://wiki.tcl.tk/DTrace
This page also has a 'Discussion' section at the bottom, I am closing this
tracker item now that the patch has been committed.

sdeasey:
- the proc-, cmd-, inst- and tcl- probe macros only make sense to use at the tcl-internal probe-sites, so there are no plans to make these publicly available.
- to get obj- probes for your extension, use public object allocation/deallocation API, or include tclInt.h with USE_DTRACE defined (and ensure your link step is dtrace aware). However, the details of the DTrace obj- probe implementations in tclInt.h should be considered subject to change (as with all internal API).
- nothing prevents you from using the standard DTRACE_PROBE/DTRACE_PROBE1 etc. macros from <sys/sdt.h> in your extensions, I don't see the value gained from adding TCL_* macro wrappers to these, especially since the tcl provider is not using them itself (and does not include <sys/sdt.h>, it uses probe macros generated by 'dtrace -h').
- I do not develop on linux and so have no plans to implement systemtap support, but other tcl maintainers might. It does not look like systemtap has something equivalent to USDT in DTrace yet?
- the internal details of the current implementation should be adaptable to support other tracing mechanisms, the only exported facility is [tcl::dtrace], I do not see a major problem with the DTrace specific name, e.g. systemtap tracing could define [tcl::systemtap] and init.tcl could then define a generic [interp alias] such as [tcl::probe] to whichever one is available (or to the empty proc if neither is). This would allow script-level detection of tracing support via [info commands] in addition to having a generic command for probe triggering from tcl.

sdeasey added on 2007-09-23 01:26:31:
Logged In: YES 
user_id=87254
Originator: NO



Is it planned to make the macros which add trace points part
of Tcl's public interface? TCL_TRACE1() etc.?

I'd like to add trace points to Tcl extensions and it would be
handy to use the Tcl infrastructure to do it.



Is it also planned to add systemtap support in the future, when
it's ready? I notice some of the exported names in the patch
mention dtrace specifically, the tcl::dtrace command, for example.

Looks like Postgresql has added dtrace support, but made it generic
so it can be extended later:

http://blogs.sun.com/robertlor/entry/user_level_dtrace_probes_in

das added on 2007-09-13 23:04:07:
Logged In: YES 
user_id=90580
Originator: YES

s/login/logic/

das added on 2007-09-13 23:03:33:
Logged In: YES 
user_id=90580
Originator: YES

no, because I use Tcl_DictObjGet to get info out of the TIP280 dict (c.f. TclDTraceInfo() in tclBasic.c on HEAD).
I'd welcome suggestions on how to improve the factoring of InfoFrameCmd/TclInfoFrame so that this info is easier to get (without reproducing all the login in TclInfoFrame()), the current solution of creating the 280 dict only to throw it away after looking keys up is expensive...

andreas_kupries added on 2007-09-13 22:57:44:
Logged In: YES 
user_id=75003
Originator: NO

> Also note that the TIP 280 dependent probes are not available on
> core-8-4-branch.

Are they available if core-8-4-branch is compiled with -DTIP_280 ?
I.e. are they available if the 8.4 core is compiled with #280 support ?

das added on 2007-09-13 22:30:28:
Logged In: YES 
user_id=90580
Originator: YES

committed to HEAD and core-8-4-branch

das added on 2007-09-13 22:23:16:
Logged In: YES 
user_id=90580
Originator: YES

oops, that should have been

tcl*:::obj-create
    triggered immediately after a new Tcl_Obj has been created
arg0: object created(Tcl_Obj*)

tcl*:::obj-free
    triggered immediately before a Tcl_Obj is freed
arg0: object to be freed(Tcl_Obj*)


Also note that the TIP 280 dependent probes are not available on core-8-4-branch.

das added on 2007-09-13 22:19:49:
Logged In: YES 
user_id=90580
Originator: YES

List of probes made available by the 'tcl' provider,
c.f. tclDTrace.d for more details:

tcl*:::proc-entry
    triggered immediately before proc bytecode execution
arg0: proc name(string)
arg1: number of arguments(int)
arg2: array of proc argument objects(Tcl_Obj**)

tcl*:::proc-return
    triggered immediately after proc bytecode execution
arg0: proc name(string)
arg1: return code(int)

tcl*:::proc-result
    triggered after proc-return probe and result processing
arg0: proc name(string)
arg1: return code(int)
arg2: proc result(string)
arg3: proc result object(Tcl_Obj*)

tcl*:::proc-args
    triggered before proc-entry probe, gives access to string
    representation of proc arguments
arg0: proc name(string)
arg1-arg9: proc arguments or NULL(strings)

tcl*:::proc-info probe:
    triggered before proc-entry probe, gives access to TIP 280
    information for the proc invocation (i.e. [info frame 0])
arg0: TIP 280 cmd(string)
arg1: TIP 280 type(string)
arg2: TIP 280 proc(string)
arg3: TIP 280 file(string)
arg4: TIP 280 line(int)
arg5: TIP 280 level(int)


tcl*:::cmd-entry
    triggered immediately before commmand execution
arg0: command name(string)
arg1: number of arguments(int)
arg2: array of command argument objects(Tcl_Obj**)

tcl*:::cmd-return
    triggered immediately after commmand execution
arg0: command name(string)
arg1: return code(int)

tcl*:::cmd-result
    triggered after cmd-return probe and result processing
arg0: command name(string)
arg1: return code(int)
arg2: command result(string)
arg3: command result object(Tcl_Obj*)

tcl*:::cmd-args
    triggered before cmd-entry probe, gives access to string
    representation of command arguments
arg0: command name(string)
arg1-arg9: command arguments or NULL(strings)

tcl*:::cmd-info probe:
    triggered before cmd-entry probe, gives access to TIP 280
    information for the command invocation (i.e. [info frame 0])
arg0: TIP 280 cmd(string)
arg1: TIP 280 type(string)
arg2: TIP 280 proc(string)
arg3: TIP 280 file(string)
arg4: TIP 280 line(int)
arg5: TIP 280 level(int)


tcl*:::inst-start
    triggered immediately before execution of a bytecode
arg0: bytecode name(string)
arg1: depth of stack(int)
arg2: top of stack(Tcl_Obj**)

tcl*:::inst-done
    triggered immediately after execution of a bytecode
arg0: bytecode name(string)
arg1: depth of stack(int)
arg2: top of stack(Tcl_Obj**)

tcl*:::inst-create
    triggered immediately after a new Tcl_Obj has been created
arg0: object created(Tcl_Obj*)

tcl*:::inst-free
    triggered immediately before a Tcl_Obj is freed
arg0: object to be freed(Tcl_Obj*)


tcl*:::tcl-probe
    triggered when the ::tcl::dtrace command is called
arg0-arg9: command arguments(strings)

das added on 2007-09-13 22:19:11:

File Added - 245528: tcl-dtrace-core-8-4-branch.diff

Logged In: YES 
user_id=90580
Originator: YES

File Added: tcl-dtrace-core-8-4-branch.diff

das added on 2007-09-13 22:18:33:

File Added - 245527: tcl-dtrace-HEAD.diff

Attachments: