diff druntime/src/compiler/ldc/trace.d @ 1458:e0b2d67cfe7c

Added druntime (this should be removed once it works).
author Robert Clipsham <robert@octarineparrot.com>
date Tue, 02 Jun 2009 17:43:06 +0100
parents
children
line wrap: on
line diff
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/druntime/src/compiler/ldc/trace.d	Tue Jun 02 17:43:06 2009 +0100
@@ -0,0 +1,919 @@
+/**
+ * Contains support code for code profiling.
+ *
+ * Copyright: Copyright Digital Mars 1995 - 2009.
+ * License:   <a href="http://www.boost.org/LICENSE_1_0.txt>Boost License 1.0</a>.
+ * Authors:   Walter Bright, Sean Kelly
+ *
+ *          Copyright Digital Mars 1995 - 2009.
+ * Distributed under the Boost Software License, Version 1.0.
+ *    (See accompanying file LICENSE_1_0.txt or copy at
+ *          http://www.boost.org/LICENSE_1_0.txt)
+ */
+module rt.trace;
+
+private
+{
+    import rt.util.string;
+    import core.stdc.ctype;
+    import core.stdc.stdio;
+    import core.stdc.string;
+    import core.stdc.stdlib;
+}
+
+extern (C):
+
+char* unmangle_ident(char*);    // from DMC++ runtime library
+
+alias long timer_t;
+
+/////////////////////////////////////
+//
+
+struct SymPair
+{
+    SymPair* next;
+    Symbol* sym;        // function that is called
+    uint count;         // number of times sym is called
+}
+
+/////////////////////////////////////
+// A Symbol for each function name.
+
+struct Symbol
+{
+        Symbol* Sl, Sr;         // left, right children
+        SymPair* Sfanin;        // list of calling functions
+        SymPair* Sfanout;       // list of called functions
+        timer_t totaltime;      // aggregate time
+        timer_t functime;       // time excluding subfunction calls
+        ubyte Sflags;
+        char[] Sident;          // name of symbol
+}
+
+const ubyte SFvisited = 1;      // visited
+
+
+//////////////////////////////////
+// Build a linked list of these.
+
+struct Stack
+{
+    Stack* prev;
+    Symbol* sym;
+    timer_t starttime;          // time when function was entered
+    timer_t ohd;                // overhead of all the bookkeeping code
+    timer_t subtime;            // time used by all subfunctions
+}
+
+__gshared			// doesn't work with multithreaded code anyway
+{
+    Symbol* root;            // root of symbol table
+
+    Stack* stack_freelist;
+    Stack* trace_tos;                // top of stack
+    int trace_inited;                // !=0 if initialized
+    timer_t trace_ohd;
+
+    Symbol** psymbols;
+    uint nsymbols;           // number of symbols
+
+    string trace_logfilename = "trace.log";
+    FILE* fplog;
+
+    string trace_deffilename = "trace.def";
+    FILE* fpdef;
+}
+
+////////////////////////////////////////
+// Set file name for output.
+// A file name of "" means write results to stdout.
+// Returns:
+//      0       success
+//      !=0     failure
+
+int trace_setlogfilename(string name)
+{
+    trace_logfilename = name;
+    return 0;
+}
+
+////////////////////////////////////////
+// Set file name for output.
+// A file name of "" means write results to stdout.
+// Returns:
+//      0       success
+//      !=0     failure
+
+int trace_setdeffilename(string name)
+{
+    trace_deffilename = name;
+    return 0;
+}
+
+////////////////////////////////////////
+// Output optimal function link order.
+
+static void trace_order(Symbol *s)
+{
+    while (s)
+    {
+        trace_place(s,0);
+        if (s.Sl)
+            trace_order(s.Sl);
+        s = s.Sr;
+    }
+}
+
+//////////////////////////////////////////////
+//
+
+static Stack* stack_malloc()
+{   Stack *s;
+
+    if (stack_freelist)
+    {   s = stack_freelist;
+        stack_freelist = s.prev;
+    }
+    else
+        s = cast(Stack *)trace_malloc(Stack.sizeof);
+    return s;
+}
+
+//////////////////////////////////////////////
+//
+
+static void stack_free(Stack *s)
+{
+    s.prev = stack_freelist;
+    stack_freelist = s;
+}
+
+//////////////////////////////////////
+// Qsort() comparison routine for array of pointers to SymPair's.
+
+static int sympair_cmp(in void* e1, in void* e2)
+{   SymPair** psp1;
+    SymPair** psp2;
+
+    psp1 = cast(SymPair**)e1;
+    psp2 = cast(SymPair**)e2;
+
+    return (*psp2).count - (*psp1).count;
+}
+
+//////////////////////////////////////
+// Place symbol s, and then place any fan ins or fan outs with
+// counts greater than count.
+
+static void trace_place(Symbol *s, uint count)
+{   SymPair* sp;
+    SymPair** base;
+
+    if (!(s.Sflags & SFvisited))
+    {   size_t num;
+        uint u;
+
+        //printf("\t%.*s\t%u\n", s.Sident, count);
+        fprintf(fpdef,"\t%.*s\n", s.Sident);
+        s.Sflags |= SFvisited;
+
+        // Compute number of items in array
+        num = 0;
+        for (sp = s.Sfanin; sp; sp = sp.next)
+            num++;
+        for (sp = s.Sfanout; sp; sp = sp.next)
+            num++;
+        if (!num)
+            return;
+
+        // Allocate and fill array
+        base = cast(SymPair**)trace_malloc(SymPair.sizeof * num);
+        u = 0;
+        for (sp = s.Sfanin; sp; sp = sp.next)
+            base[u++] = sp;
+        for (sp = s.Sfanout; sp; sp = sp.next)
+            base[u++] = sp;
+
+        // Sort array
+        qsort(base, num, (SymPair *).sizeof, &sympair_cmp);
+
+        //for (u = 0; u < num; u++)
+            //printf("\t\t%.*s\t%u\n", base[u].sym.Sident, base[u].count);
+
+        // Place symbols
+        for (u = 0; u < num; u++)
+        {
+            if (base[u].count >= count)
+            {   uint u2;
+                uint c2;
+
+                u2 = (u + 1 < num) ? u + 1 : u;
+                c2 = base[u2].count;
+                if (c2 < count)
+                    c2 = count;
+                trace_place(base[u].sym,c2);
+            }
+            else
+                break;
+        }
+
+        // Clean up
+        trace_free(base);
+    }
+}
+
+/////////////////////////////////////
+// Initialize and terminate.
+
+static this()
+{
+    trace_init();
+}
+
+static ~this()
+{
+    trace_term();
+}
+
+///////////////////////////////////
+// Report results.
+// Also compute nsymbols.
+
+static void trace_report(Symbol* s)
+{   SymPair* sp;
+    uint count;
+
+    //printf("trace_report()\n");
+    while (s)
+    {   nsymbols++;
+        if (s.Sl)
+            trace_report(s.Sl);
+        fprintf(fplog,"------------------\n");
+        count = 0;
+        for (sp = s.Sfanin; sp; sp = sp.next)
+        {
+            fprintf(fplog,"\t%5d\t%.*s\n", sp.count, sp.sym.Sident);
+            count += sp.count;
+        }
+        fprintf(fplog,"%.*s\t%u\t%lld\t%lld\n",s.Sident,count,s.totaltime,s.functime);
+        for (sp = s.Sfanout; sp; sp = sp.next)
+        {
+            fprintf(fplog,"\t%5d\t%.*s\n",sp.count,sp.sym.Sident);
+        }
+        s = s.Sr;
+    }
+}
+
+////////////////////////////////////
+// Allocate and fill array of symbols.
+
+static void trace_array(Symbol *s)
+{
+    __gshared uint u;
+
+    if (!psymbols)
+    {   u = 0;
+        psymbols = cast(Symbol **)trace_malloc((Symbol *).sizeof * nsymbols);
+    }
+    while (s)
+    {
+        psymbols[u++] = s;
+        trace_array(s.Sl);
+        s = s.Sr;
+    }
+}
+
+
+//////////////////////////////////////
+// Qsort() comparison routine for array of pointers to Symbol's.
+
+static int symbol_cmp(in void* e1, in void* e2)
+{   Symbol** ps1;
+    Symbol** ps2;
+    timer_t diff;
+
+    ps1 = cast(Symbol **)e1;
+    ps2 = cast(Symbol **)e2;
+
+    diff = (*ps2).functime - (*ps1).functime;
+    return (diff == 0) ? 0 : ((diff > 0) ? 1 : -1);
+}
+
+
+///////////////////////////////////
+// Report function timings
+
+static void trace_times(Symbol* root)
+{   uint u;
+    timer_t freq;
+
+    // Sort array
+    qsort(psymbols, nsymbols, (Symbol *).sizeof, &symbol_cmp);
+
+    // Print array
+    QueryPerformanceFrequency(&freq);
+    fprintf(fplog,"\n======== Timer Is %lld Ticks/Sec, Times are in Microsecs ========\n\n",freq);
+    fprintf(fplog,"  Num          Tree        Func        Per\n");
+    fprintf(fplog,"  Calls        Time        Time        Call\n\n");
+    for (u = 0; u < nsymbols; u++)
+    {   Symbol* s = psymbols[u];
+        timer_t tl,tr;
+        timer_t fl,fr;
+        timer_t pl,pr;
+        timer_t percall;
+        SymPair* sp;
+        uint calls;
+        char[] id;
+
+        version (Windows)
+        {
+            char* p = (s.Sident ~ '\0').ptr;
+            p = unmangle_ident(p);
+            if (p)
+                id = p[0 .. strlen(p)];
+        }
+        if (!id)
+            id = s.Sident;
+        calls = 0;
+        for (sp = s.Sfanin; sp; sp = sp.next)
+            calls += sp.count;
+        if (calls == 0)
+            calls = 1;
+
+version (all)
+{
+        tl = (s.totaltime * 1000000) / freq;
+        fl = (s.functime  * 1000000) / freq;
+        percall = s.functime / calls;
+        pl = (s.functime * 1000000) / calls / freq;
+
+        fprintf(fplog,"%7d%12lld%12lld%12lld     %.*s\n",
+            calls,tl,fl,pl,id);
+}
+else
+{
+        tl = s.totaltime / freq;
+        tr = ((s.totaltime - tl * freq) * 10000000) / freq;
+
+        fl = s.functime  / freq;
+        fr = ((s.functime  - fl * freq) * 10000000) / freq;
+
+        percall = s.functime / calls;
+        pl = percall  / freq;
+        pr = ((percall  - pl * freq) * 10000000) / freq;
+
+        fprintf(fplog,"%7d\t%3lld.%07lld\t%3lld.%07lld\t%3lld.%07lld\t%.*s\n",
+            calls,tl,tr,fl,fr,pl,pr,id);
+}
+        if (id !is s.Sident)
+            free(id.ptr);
+    }
+}
+
+
+///////////////////////////////////
+// Initialize.
+
+static void trace_init()
+{
+    if (!trace_inited)
+    {
+        trace_inited = 1;
+
+        {   // See if we can determine the overhead.
+            uint u;
+            timer_t starttime;
+            timer_t endtime;
+            Stack *st;
+
+            st = trace_tos;
+            trace_tos = null;
+            QueryPerformanceCounter(&starttime);
+            for (u = 0; u < 100; u++)
+            {
+                asm
+                {
+                    call _trace_pro_n   ;
+                    db   0              ;
+                    call _trace_epi_n   ;
+                }
+            }
+            QueryPerformanceCounter(&endtime);
+            trace_ohd = (endtime - starttime) / u;
+            //printf("trace_ohd = %lld\n",trace_ohd);
+            if (trace_ohd > 0)
+                trace_ohd--;            // round down
+            trace_tos = st;
+        }
+    }
+}
+
+/////////////////////////////////
+// Terminate.
+
+void trace_term()
+{
+    //printf("trace_term()\n");
+    if (trace_inited == 1)
+    {   Stack *n;
+
+        trace_inited = 2;
+
+        // Free remainder of the stack
+        while (trace_tos)
+        {
+            n = trace_tos.prev;
+            stack_free(trace_tos);
+            trace_tos = n;
+        }
+
+        while (stack_freelist)
+        {
+            n = stack_freelist.prev;
+            stack_free(stack_freelist);
+            stack_freelist = n;
+        }
+
+        // Merge in data from any existing file
+        trace_merge();
+
+        // Report results
+        fplog = fopen(trace_logfilename.ptr, "w");
+        if (fplog)
+        {   nsymbols = 0;
+            trace_report(root);
+            trace_array(root);
+            trace_times(root);
+            fclose(fplog);
+        }
+
+        // Output function link order
+        fpdef = fopen(trace_deffilename.ptr,"w");
+        if (fpdef)
+        {   fprintf(fpdef,"\nFUNCTIONS\n");
+            trace_order(root);
+            fclose(fpdef);
+        }
+
+        trace_free(psymbols);
+        psymbols = null;
+    }
+}
+
+/////////////////////////////////
+// Our storage allocator.
+
+static void *trace_malloc(size_t nbytes)
+{   void *p;
+
+    p = malloc(nbytes);
+    if (!p)
+        exit(EXIT_FAILURE);
+    return p;
+}
+
+static void trace_free(void *p)
+{
+    free(p);
+}
+
+//////////////////////////////////////////////
+//
+
+static Symbol* trace_addsym(char[] id)
+{
+    Symbol** parent;
+    Symbol* rover;
+    Symbol* s;
+    int cmp;
+    char c;
+
+    //printf("trace_addsym('%s',%d)\n",p,len);
+    parent = &root;
+    rover = *parent;
+    while (rover !is null)               // while we haven't run out of tree
+    {
+        cmp = dstrcmp(id, rover.Sident);
+        if (cmp == 0)
+        {
+            return rover;
+        }
+        parent = (cmp < 0) ?            /* if we go down left side      */
+            &(rover.Sl) :               /* then get left child          */
+            &(rover.Sr);                /* else get right child         */
+        rover = *parent;                /* get child                    */
+    }
+    /* not in table, so insert into table       */
+    s = cast(Symbol *)trace_malloc(Symbol.sizeof);
+    memset(s,0,Symbol.sizeof);
+    s.Sident = id;
+    *parent = s;                        // link new symbol into tree
+    return s;
+}
+
+/***********************************
+ * Add symbol s with count to SymPair list.
+ */
+
+static void trace_sympair_add(SymPair** psp, Symbol* s, uint count)
+{   SymPair* sp;
+
+    for (; 1; psp = &sp.next)
+    {
+        sp = *psp;
+        if (!sp)
+        {
+            sp = cast(SymPair *)trace_malloc(SymPair.sizeof);
+            sp.sym = s;
+            sp.count = 0;
+            sp.next = null;
+            *psp = sp;
+            break;
+        }
+        else if (sp.sym == s)
+        {
+            break;
+        }
+    }
+    sp.count += count;
+}
+
+//////////////////////////////////////////////
+//
+
+static void trace_pro(char[] id)
+{
+    Stack* n;
+    Symbol* s;
+    timer_t starttime;
+    timer_t t;
+
+    QueryPerformanceCounter(&starttime);
+    if (id.length == 0)
+        return;
+    if (!trace_inited)
+        trace_init();                   // initialize package
+    n = stack_malloc();
+    n.prev = trace_tos;
+    trace_tos = n;
+    s = trace_addsym(id);
+    trace_tos.sym = s;
+    if (trace_tos.prev)
+    {
+        Symbol* prev;
+        int i;
+
+        // Accumulate Sfanout and Sfanin
+        prev = trace_tos.prev.sym;
+        trace_sympair_add(&prev.Sfanout,s,1);
+        trace_sympair_add(&s.Sfanin,prev,1);
+    }
+    QueryPerformanceCounter(&t);
+    trace_tos.starttime = starttime;
+    trace_tos.ohd = trace_ohd + t - starttime;
+    trace_tos.subtime = 0;
+    //printf("trace_tos.ohd=%lld, trace_ohd=%lld + t=%lld - starttime=%lld\n",
+    //  trace_tos.ohd,trace_ohd,t,starttime);
+}
+
+/////////////////////////////////////////
+//
+
+static void trace_epi()
+{   Stack* n;
+    timer_t endtime;
+    timer_t t;
+    timer_t ohd;
+
+    //printf("trace_epi()\n");
+    if (trace_tos)
+    {
+        timer_t starttime;
+        timer_t totaltime;
+
+        QueryPerformanceCounter(&endtime);
+        starttime = trace_tos.starttime;
+        totaltime = endtime - starttime - trace_tos.ohd;
+        if (totaltime < 0)
+        {   //printf("endtime=%lld - starttime=%lld - trace_tos.ohd=%lld < 0\n",
+            //  endtime,starttime,trace_tos.ohd);
+            totaltime = 0;              // round off error, just make it 0
+        }
+
+        // totaltime is time spent in this function + all time spent in
+        // subfunctions - bookkeeping overhead.
+        trace_tos.sym.totaltime += totaltime;
+
+        //if (totaltime < trace_tos.subtime)
+        //printf("totaltime=%lld < trace_tos.subtime=%lld\n",totaltime,trace_tos.subtime);
+        trace_tos.sym.functime  += totaltime - trace_tos.subtime;
+        ohd = trace_tos.ohd;
+        n = trace_tos.prev;
+        stack_free(trace_tos);
+        trace_tos = n;
+        if (n)
+        {   QueryPerformanceCounter(&t);
+            n.ohd += ohd + t - endtime;
+            n.subtime += totaltime;
+            //printf("n.ohd = %lld\n",n.ohd);
+        }
+    }
+}
+
+
+////////////////////////// FILE INTERFACE /////////////////////////
+
+/////////////////////////////////////
+// Read line from file fp.
+// Returns:
+//      trace_malloc'd line buffer
+//      null if end of file
+
+static char* trace_readline(FILE* fp)
+{   int c;
+    int dim;
+    int i;
+    char *buf;
+
+    //printf("trace_readline(%p)\n", fp);
+    i = 0;
+    dim = 0;
+    buf = null;
+    while (1)
+    {
+        if (i == dim)
+        {   char *p;
+
+            dim += 80;
+            p = cast(char *)trace_malloc(dim);
+            memcpy(p,buf,i);
+            trace_free(buf);
+            buf = p;
+        }
+        c = fgetc(fp);
+        switch (c)
+        {
+            case EOF:
+                if (i == 0)
+                {   trace_free(buf);
+                    return null;
+                }
+            case '\n':
+                goto L1;
+            default:
+                break;
+        }
+        buf[i] = cast(char)c;
+        i++;
+    }
+L1:
+    buf[i] = 0;
+    //printf("line '%s'\n",buf);
+    return buf;
+}
+
+//////////////////////////////////////
+// Skip space
+
+static char *skipspace(char *p)
+{
+    while (isspace(*p))
+        p++;
+    return p;
+}
+
+////////////////////////////////////////////////////////
+// Merge in profiling data from existing file.
+
+static void trace_merge()
+{   FILE *fp;
+    char *buf;
+    char *p;
+    uint count;
+    Symbol *s;
+    SymPair *sfanin;
+    SymPair **psp;
+
+    if (trace_logfilename && (fp = fopen(trace_logfilename.ptr,"r")) !is null)
+    {
+        buf = null;
+        sfanin = null;
+        psp = &sfanin;
+        while (1)
+        {
+            trace_free(buf);
+            buf = trace_readline(fp);
+            if (!buf)
+                break;
+            switch (*buf)
+            {
+                case '=':               // ignore rest of file
+                    trace_free(buf);
+                    goto L1;
+                case ' ':
+                case '\t':              // fan in or fan out line
+                    count = strtoul(buf,&p,10);
+                    if (p == buf)       // if invalid conversion
+                        continue;
+                    p = skipspace(p);
+                    if (!*p)
+                        continue;
+                    s = trace_addsym(p[0 .. strlen(p)]);
+                    trace_sympair_add(psp,s,count);
+                    break;
+                default:
+                    if (!isalpha(*buf))
+                    {
+                        if (!sfanin)
+                            psp = &sfanin;
+                        continue;       // regard unrecognized line as separator
+                    }
+                case '?':
+                case '_':
+                case '$':
+                case '@':
+                    p = buf;
+                    while (isgraph(*p))
+                        p++;
+                    *p = 0;
+                    //printf("trace_addsym('%s')\n",buf);
+                    s = trace_addsym(buf[0 .. strlen(buf)]);
+                    if (s.Sfanin)
+                    {   SymPair *sp;
+
+                        for (; sfanin; sfanin = sp)
+                        {
+                            trace_sympair_add(&s.Sfanin,sfanin.sym,sfanin.count);
+                            sp = sfanin.next;
+                            trace_free(sfanin);
+                        }
+                    }
+                    else
+                    {   s.Sfanin = sfanin;
+                    }
+                    sfanin = null;
+                    psp = &s.Sfanout;
+
+                    {   timer_t t;
+
+                        p++;
+                        count = strtoul(p,&p,10);
+                        t = cast(long)strtoull(p,&p,10);
+                        s.totaltime += t;
+                        t = cast(long)strtoull(p,&p,10);
+                        s.functime += t;
+                    }
+                    break;
+            }
+        }
+    L1:
+        fclose(fp);
+    }
+}
+
+////////////////////////// COMPILER INTERFACE /////////////////////
+
+/////////////////////////////////////////////
+// Function called by trace code in function prolog.
+
+void _trace_pro_n()
+{
+    /* Length of string is either:
+     *  db      length
+     *  ascii   string
+     * or:
+     *  db      0x0FF
+     *  db      0
+     *  dw      length
+     *  ascii   string
+     */
+
+  version (OSX)
+  { // 16 byte align stack
+    asm
+    {   naked                           ;
+        pushad                          ;
+        mov     ECX,8*4[ESP]            ;
+        xor     EAX,EAX                 ;
+        mov     AL,[ECX]                ;
+        cmp     AL,0xFF                 ;
+        jne     L1                      ;
+        cmp     byte ptr 1[ECX],0       ;
+        jne     L1                      ;
+        mov     AX,2[ECX]               ;
+        add     8*4[ESP],3              ;
+        add     ECX,3                   ;
+    L1: inc     EAX                     ;
+        inc     ECX                     ;
+        add     8*4[ESP],EAX            ;
+        dec     EAX                     ;
+        sub     ESP,4                   ;
+        push    ECX                     ;
+        push    EAX                     ;
+        call    trace_pro               ;
+        add     ESP,12                  ;
+        popad                           ;
+        ret                             ;
+    }
+  }
+  else
+  {
+    asm
+    {   naked                           ;
+        pushad                          ;
+        mov     ECX,8*4[ESP]            ;
+        xor     EAX,EAX                 ;
+        mov     AL,[ECX]                ;
+        cmp     AL,0xFF                 ;
+        jne     L1                      ;
+        cmp     byte ptr 1[ECX],0       ;
+        jne     L1                      ;
+        mov     AX,2[ECX]               ;
+        add     8*4[ESP],3              ;
+        add     ECX,3                   ;
+    L1: inc     EAX                     ;
+        inc     ECX                     ;
+        add     8*4[ESP],EAX            ;
+        dec     EAX                     ;
+        push    ECX                     ;
+        push    EAX                     ;
+        call    trace_pro               ;
+        add     ESP,8                   ;
+        popad                           ;
+        ret                             ;
+    }
+  }
+}
+
+/////////////////////////////////////////////
+// Function called by trace code in function epilog.
+
+
+void _trace_epi_n()
+{
+  version (OSX)
+  { // 16 byte align stack
+    asm
+    {   naked   ;
+        pushad  ;
+        sub     ESP,12  ;
+    }
+    trace_epi();
+    asm
+    {
+        add     ESP,12  ;
+        popad   ;
+        ret     ;
+    }
+  }
+  else
+  {
+    asm
+    {   naked   ;
+        pushad  ;
+    }
+    trace_epi();
+    asm
+    {
+        popad   ;
+        ret     ;
+    }
+  }
+}
+
+
+version (Windows)
+{
+    extern (Windows)
+    {
+        export int QueryPerformanceCounter(timer_t *);
+        export int QueryPerformanceFrequency(timer_t *);
+    }
+}
+else version (X86)
+{
+    extern (D)
+    {
+        void QueryPerformanceCounter(timer_t* ctr)
+        {
+            asm
+            {   naked                   ;
+                mov       ECX,EAX       ;
+                rdtsc                   ;
+                mov   [ECX],EAX         ;
+                mov   4[ECX],EDX        ;
+                ret                     ;
+            }
+        }
+
+        void QueryPerformanceFrequency(timer_t* freq)
+        {
+            *freq = 3579545;
+        }
+    }
+}
+else
+{
+    static assert(0);
+}