gecko-dev/tools/jprof/stub/libmalloc.cpp

/* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 4 -*- */
// vim:cindent:sw=4:et:ts=8:
/* This Source Code Form is subject to the terms of the Mozilla Public
 * License, v. 2.0. If a copy of the MPL was not distributed with this
 * file, You can obtain one at http://mozilla.org/MPL/2.0/. */

// The linux glibc hides part of sigaction if _POSIX_SOURCE is defined
#if defined(linux)
#undef _POSIX_SOURCE
#undef _SVID_SOURCE
#ifndef _GNU_SOURCE
#define _GNU_SOURCE
#endif
#endif

#include <errno.h>
#if defined(linux)
#include <linux/rtc.h>
#include <pthread.h>
#endif
#include <unistd.h>
#include <fcntl.h>
#include <stdio.h>
#include <stdlib.h>
#include <signal.h>
#include <sys/time.h>
#include <sys/types.h>
#include <sys/ioctl.h>
#include <sys/stat.h>
#include <sys/syscall.h>
#include <ucontext.h>
#include <execinfo.h>

#include "libmalloc.h"
#include "jprof.h"
#include <string.h>
#include <errno.h>
#include <dlfcn.h>

// Must define before including jprof.h
void *moz_xmalloc(size_t size)
{
    return malloc(size);
}

void moz_xfree(void *mem)
{
    free(mem);
}

#ifdef NTO
#include <sys/link.h>
extern r_debug _r_debug;
#else
#include <link.h>
#endif

#define USE_GLIBC_BACKTRACE 1
// To debug, use #define JPROF_STATIC
#define JPROF_STATIC //static

static int gLogFD = -1;
static pthread_t main_thread;

static void startSignalCounter(unsigned long millisec);
static int enableRTCSignals(bool enable);


//----------------------------------------------------------------------
// replace use of atexit()

static void DumpAddressMap();

struct JprofShutdown {
    JprofShutdown() {}
    ~JprofShutdown() {
        DumpAddressMap();
    }
};

static void RegisterJprofShutdown() {
    // This instanciates the dummy class above, and will trigger the class
    // destructor when libxul is unloaded. This is equivalent to atexit(),
    // but gracefully handles dlclose().
    static JprofShutdown t;
}

#if defined(i386) || defined(_i386) || defined(__x86_64__)
JPROF_STATIC void CrawlStack(malloc_log_entry* me,
                             void* stack_top, void* top_instr_ptr)
{
#if USE_GLIBC_BACKTRACE
    // This probably works on more than x86!  But we need a way to get the
    // top instruction pointer, which is kindof arch-specific
    void *array[500];
    int cnt, i;
    u_long numpcs = 0;
    bool tracing = false;

    // This is from glibc.  A more generic version might use
    // libunwind and/or CaptureStackBackTrace() on Windows
    cnt = backtrace(&array[0],sizeof(array)/sizeof(array[0]));

    // StackHook->JprofLog->CrawlStack
    // Then we have sigaction, which replaced top_instr_ptr
    array[3] = top_instr_ptr;
    for (i = 3; i < cnt; i++)
    {
        me->pcs[numpcs++] = (char *) array[i];
    }
    me->numpcs = numpcs;

#else
  // original code - this breaks on many platforms
  void **bp;
#if defined(__i386)
  __asm__( "movl %%ebp, %0" : "=g"(bp));
#elif defined(__x86_64__)
  __asm__( "movq %%rbp, %0" : "=g"(bp));
#else
  // It would be nice if this worked uniformly, but at least on i386 and
  // x86_64, it stopped working with gcc 4.1, because it points to the
  // end of the saved registers instead of the start.
  bp = __builtin_frame_address(0);
#endif
  u_long numpcs = 0;
  bool tracing = false;

  me->pcs[numpcs++] = (char*) top_instr_ptr;

  while (numpcs < MAX_STACK_CRAWL) {
    void** nextbp = (void**) *bp++;
    void* pc = *bp;
    if (nextbp < bp) {
      break;
    }
    if (tracing) {
      // Skip the signal handling.
      me->pcs[numpcs++] = (char*) pc;
    }
    else if (pc == top_instr_ptr) {
      tracing = true;
    }
    bp = nextbp;
  }
  me->numpcs = numpcs;
#endif
}
#endif

//----------------------------------------------------------------------

static int rtcHz;
static int rtcFD = -1;
static bool circular = false;

#if defined(linux) || defined(NTO)
static void DumpAddressMap()
{
  // Turn off the timer so we don't get interrupts during shutdown
#if defined(linux)
  if (rtcHz) {
    enableRTCSignals(false);
  } else
#endif
  {
    startSignalCounter(0);
  }

  int mfd = open(M_MAPFILE, O_CREAT|O_WRONLY|O_TRUNC, 0666);
  if (mfd >= 0) {
    malloc_map_entry mme;
    link_map* map = _r_debug.r_map;
    while (nullptr != map) {
      if (map->l_name && *map->l_name) {
	mme.nameLen = strlen(map->l_name);
	mme.address = map->l_addr;
	write(mfd, &mme, sizeof(mme));
	write(mfd, map->l_name, mme.nameLen);
#if 0
	write(1, map->l_name, mme.nameLen);
	write(1, "\n", 1);
#endif
      }
      map = map->l_next;
    }
    close(mfd);
  }
}
#endif

static bool was_paused = true;

JPROF_STATIC void JprofBufferDump();
JPROF_STATIC void JprofBufferClear();

static void ClearProfilingHook(int signum)
{
    if (circular) {
        JprofBufferClear();
        puts("Jprof: cleared circular buffer.");
    }
}

static void EndProfilingHook(int signum)
{
    if (circular)
        JprofBufferDump();

    DumpAddressMap();
    was_paused = true;
    puts("Jprof: profiling paused.");
}



//----------------------------------------------------------------------
// proper usage would be a template, including the function to find the
// size of an entry, or include a size header explicitly to each entry.
#if defined(linux)
#define DUMB_LOCK()   pthread_mutex_lock(&mutex);
#define DUMB_UNLOCK() pthread_mutex_unlock(&mutex);
#else
#define DUMB_LOCK()   FIXME()
#define DUMB_UNLOCK() FIXME()
#endif


class DumbCircularBuffer
{
public:
    DumbCircularBuffer(size_t init_buffer_size) {
        used = 0;
        buffer_size = init_buffer_size;
        buffer = (unsigned char *) malloc(buffer_size);
        head = tail = buffer;

#if defined(linux)
        pthread_mutexattr_t mAttr;
        pthread_mutexattr_settype(&mAttr, PTHREAD_MUTEX_RECURSIVE_NP);
        pthread_mutex_init(&mutex, &mAttr);
        pthread_mutexattr_destroy(&mAttr);
#endif
    }
    ~DumbCircularBuffer() {
        free(buffer);
#if defined(linux)
        pthread_mutex_destroy (&mutex);
#endif
    }

    void clear() {
        DUMB_LOCK();
        head = tail;
        used = 0;
        DUMB_UNLOCK();
    }

    bool empty() {
        return head == tail;
    }

    size_t space_available() {
        size_t result;
        DUMB_LOCK();
        if (tail > head)
            result = buffer_size - (tail-head) - 1;
        else
            result = head-tail - 1;
        DUMB_UNLOCK();
        return result;
    }

    void drop(size_t size) {
        // assumes correctness!
        DUMB_LOCK();
        head += size;
        if (head >= &buffer[buffer_size])
            head -= buffer_size;
        used--;
        DUMB_UNLOCK();
    }

    bool insert(void *data, size_t size) {
        // can fail if not enough space in the entire buffer
        DUMB_LOCK();
        if (space_available() < size)
            return false;

        size_t max_without_wrap = &buffer[buffer_size] - tail;
        size_t initial = size > max_without_wrap ? max_without_wrap : size;
#if DEBUG_CIRCULAR
        fprintf(stderr,"insert(%d): max_without_wrap %d, size %d, initial %d\n",used,max_without_wrap,size,initial);
#endif
        memcpy(tail,data,initial);
        tail += initial;
        data = ((char *)data)+initial;
        size -= initial;
        if (size != 0) {
#if DEBUG_CIRCULAR
            fprintf(stderr,"wrapping by %d bytes\n",size);
#endif
            memcpy(buffer,data,size);
            tail = &(((unsigned char *)buffer)[size]);
        }
            
        used++;
        DUMB_UNLOCK();

        return true;
    }

    // for external access to the buffer (saving)
    void lock() {
        DUMB_LOCK();
    }

    void unlock() {
        DUMB_UNLOCK();
    }

    // XXX These really shouldn't be public...
    unsigned char *head;
    unsigned char *tail;
    unsigned int used;
    unsigned char *buffer;
    size_t buffer_size;

private:
    pthread_mutex_t mutex;
};

class DumbCircularBuffer *JprofBuffer;

JPROF_STATIC void
JprofBufferInit(size_t size)
{
    JprofBuffer = new DumbCircularBuffer(size);
}

JPROF_STATIC void
JprofBufferClear()
{
    fprintf(stderr,"Told to clear JPROF circular buffer\n");
    JprofBuffer->clear();
}

JPROF_STATIC size_t
JprofEntrySizeof(malloc_log_entry *me)
{
    return offsetof(malloc_log_entry, pcs) + me->numpcs*sizeof(char*);
}

JPROF_STATIC void
JprofBufferAppend(malloc_log_entry *me)
{
    size_t size = JprofEntrySizeof(me);

    do {
        while (JprofBuffer->space_available() < size &&
               JprofBuffer->used > 0) {
#if DEBUG_CIRCULAR
            fprintf(stderr,"dropping entry: %d in use, %d free, need %d, size_to_free = %d\n",
                    JprofBuffer->used,JprofBuffer->space_available(),size,JprofEntrySizeof((malloc_log_entry *) JprofBuffer->head));
#endif
            JprofBuffer->drop(JprofEntrySizeof((malloc_log_entry *) JprofBuffer->head));
        }
        if (JprofBuffer->space_available() < size)
            return;

    } while (!JprofBuffer->insert(me,size));
}

JPROF_STATIC void
JprofBufferDump()
{
    JprofBuffer->lock();
#if DEBUG_CIRCULAR
    fprintf(stderr,"dumping JP_CIRCULAR buffer, %d of %d bytes\n",
            JprofBuffer->tail > JprofBuffer->head ? 
              JprofBuffer->tail - JprofBuffer->head :
              JprofBuffer->buffer_size + JprofBuffer->tail - JprofBuffer->head,
            JprofBuffer->buffer_size);
#endif
    if (JprofBuffer->tail >= JprofBuffer->head) {
        write(gLogFD, JprofBuffer->head, JprofBuffer->tail - JprofBuffer->head);
    } else {
        write(gLogFD, JprofBuffer->head, &(JprofBuffer->buffer[JprofBuffer->buffer_size]) - JprofBuffer->head);
        write(gLogFD, JprofBuffer->buffer, JprofBuffer->tail - JprofBuffer->buffer);
    }
    JprofBuffer->clear();
    JprofBuffer->unlock();
}

//----------------------------------------------------------------------

JPROF_STATIC void
JprofLog(u_long aTime, void* stack_top, void* top_instr_ptr)
{
  // Static is simply to make debugging tolerable
  static malloc_log_entry me;

  me.delTime = aTime;
  me.thread = syscall(SYS_gettid); //gettid();
  if (was_paused) {
      me.flags = JP_FIRST_AFTER_PAUSE;
      was_paused = 0;
  } else {
      me.flags = 0;
  }

  CrawlStack(&me, stack_top, top_instr_ptr);

#ifndef NTO
  if (circular) {
      JprofBufferAppend(&me);
  } else {
      write(gLogFD, &me, JprofEntrySizeof(&me));
  }
#else
      printf("Neutrino is missing the pcs member of malloc_log_entry!! \n");
#endif
}

static int realTime;

/* Lets interrupt at 10 Hz.  This is so my log files don't get too large.
 * This can be changed to a faster value latter.  This timer is not
 * programmed to reset, even though it is capable of doing so.  This is
 * to keep from getting interrupts from inside of the handler.
*/
static void startSignalCounter(unsigned long millisec)
{
    struct itimerval tvalue;

    tvalue.it_interval.tv_sec = 0;
    tvalue.it_interval.tv_usec = 0;
    tvalue.it_value.tv_sec = millisec/1000;
    tvalue.it_value.tv_usec = (millisec%1000)*1000;

    if (realTime) {
        setitimer(ITIMER_REAL, &tvalue, nullptr);
    } else {
        setitimer(ITIMER_PROF, &tvalue, nullptr);
    }
}

static long timerMilliSec = 50;

#if defined(linux)
static int setupRTCSignals(int hz, struct sigaction *sap)
{
    /* global */ rtcFD = open("/dev/rtc", O_RDONLY);
    if (rtcFD < 0) {
        perror("JPROF_RTC setup: open(\"/dev/rtc\", O_RDONLY)");
        return 0;
    }

    if (sigaction(SIGIO, sap, nullptr) == -1) {
        perror("JPROF_RTC setup: sigaction(SIGIO)");
        return 0;
    }

    if (ioctl(rtcFD, RTC_IRQP_SET, hz) == -1) {
        perror("JPROF_RTC setup: ioctl(/dev/rtc, RTC_IRQP_SET, $JPROF_RTC_HZ)");
        return 0;
    }

    if (ioctl(rtcFD, RTC_PIE_ON, 0) == -1) {
        perror("JPROF_RTC setup: ioctl(/dev/rtc, RTC_PIE_ON)");
        return 0;
    }

    if (fcntl(rtcFD, F_SETSIG, 0) == -1) {
        perror("JPROF_RTC setup: fcntl(/dev/rtc, F_SETSIG, 0)");
        return 0;
    }

    if (fcntl(rtcFD, F_SETOWN, getpid()) == -1) {
        perror("JPROF_RTC setup: fcntl(/dev/rtc, F_SETOWN, getpid())");
        return 0;
    }

    return 1;
}

static int enableRTCSignals(bool enable)
{
    static bool enabled = false;
    if (enabled == enable) {
        return 0;
    }
    enabled = enable;
    
    int flags = fcntl(rtcFD, F_GETFL);
    if (flags < 0) {
        perror("JPROF_RTC setup: fcntl(/dev/rtc, F_GETFL)");
        return 0;
    }

    if (enable) {
        flags |= FASYNC;
    } else {
        flags &= ~FASYNC;
    }

    if (fcntl(rtcFD, F_SETFL, flags) == -1) {
        if (enable) {
            perror("JPROF_RTC setup: fcntl(/dev/rtc, F_SETFL, flags | FASYNC)");
        } else {
            perror("JPROF_RTC setup: fcntl(/dev/rtc, F_SETFL, flags & ~FASYNC)");
        }            
        return 0;
    }

    return 1;
}
#endif

JPROF_STATIC void StackHook(
int signum,
siginfo_t *info,
void *ucontext)
{
    static struct timeval tFirst;
    static int first=1;
    size_t millisec = 0;

#if defined(linux)
    if (rtcHz && pthread_self() != main_thread) {
      // Only collect stack data on the main thread, for now.
      return;
    }
#endif

    if(first && !(first=0)) {
        puts("Jprof: received first signal");
#if defined(linux)
        if (rtcHz) {
            enableRTCSignals(true);
        } else
#endif
        {
            gettimeofday(&tFirst, 0);
            millisec = 0;
        }
    } else {
#if defined(linux)
        if (rtcHz) {
            enableRTCSignals(true);
        } else
#endif
        {
            struct timeval tNow;
            gettimeofday(&tNow, 0);
            double usec = 1e6*(tNow.tv_sec - tFirst.tv_sec);
            usec += (tNow.tv_usec - tFirst.tv_usec);
            millisec = static_cast<size_t>(usec*1e-3);
        }
    }

    gregset_t &gregs = ((ucontext_t*)ucontext)->uc_mcontext.gregs;
#ifdef __x86_64__
    JprofLog(millisec, (void*)gregs[REG_RSP], (void*)gregs[REG_RIP]);
#else
    JprofLog(millisec, (void*)gregs[REG_ESP], (void*)gregs[REG_EIP]);
#endif

    if (!rtcHz)
        startSignalCounter(timerMilliSec);
}

NS_EXPORT_(void) setupProfilingStuff(void)
{
    static int gFirstTime = 1;
    char filename[2048]; // XXX fix

    if(gFirstTime && !(gFirstTime=0)) {
	int  startTimer = 1;
	int  doNotStart = 1;
	int  firstDelay = 0;
        int  append = O_TRUNC;
        char *tst  = getenv("JPROF_FLAGS");

	/* Options from JPROF_FLAGS environment variable:
	 *   JP_DEFER  -> Wait for a SIGPROF (or SIGALRM, if JP_REALTIME
	 *               is set) from userland before starting
	 *               to generate them internally
	 *   JP_START  -> Install the signal handler
	 *   JP_PERIOD -> Time between profiler ticks
	 *   JP_FIRST  -> Extra delay before starting
	 *   JP_REALTIME -> Take stack traces in intervals of real time
	 *               rather than time used by the process (and the
	 *               system for the process).  This is useful for
	 *               finding time spent by the X server.
         *   JP_APPEND -> Append to jprof-log rather than overwriting it.
         *               This is somewhat risky since it depends on the
         *               address map staying constant across multiple runs.
         *   JP_FILENAME -> base filename to use when saving logs.  Note that
         *               this does not affect the mapfile.
         *   JP_CIRCULAR -> use a circular buffer of size N, write/clear on SIGUSR1
         *
         * JPROF_SLAVE is set if this is not the first process.
	*/

        circular = false;

	if(tst) {
	    if(strstr(tst, "JP_DEFER"))
	    {
		doNotStart = 0;
		startTimer = 0;
	    }
	    if(strstr(tst, "JP_START")) doNotStart = 0;
	    if(strstr(tst, "JP_REALTIME")) realTime = 1;
	    if(strstr(tst, "JP_APPEND")) append = O_APPEND;

	    char *delay = strstr(tst,"JP_PERIOD=");
	    if(delay) {
                double tmp = strtod(delay+strlen("JP_PERIOD="), nullptr);
                if (tmp>=1e-3) {
		    timerMilliSec = static_cast<unsigned long>(1000 * tmp);
                } else {
                    fprintf(stderr,
                            "JP_PERIOD of %g less than 0.001 (1ms), using 1ms\n",
                            tmp);
                    timerMilliSec = 1;
                }
	    }

	    char *circular_op = strstr(tst,"JP_CIRCULAR=");
	    if(circular_op) {
                size_t size = atol(circular_op+strlen("JP_CIRCULAR="));
                if (size < 1000) {
                    fprintf(stderr,
                            "JP_CIRCULAR of %d less than 1000, using 10000\n",
                            size);
                    size = 10000;
                }
                JprofBufferInit(size);
                fprintf(stderr,"JP_CIRCULAR buffer of %d bytes\n",size);
                circular = true;
	    }

	    char *first = strstr(tst, "JP_FIRST=");
	    if(first) {
                firstDelay = atol(first+strlen("JP_FIRST="));
	    }

            char *rtc = strstr(tst, "JP_RTC_HZ=");
            if (rtc) {
#if defined(linux)
                rtcHz = atol(rtc+strlen("JP_RTC_HZ="));
                timerMilliSec = 0; /* This makes JP_FIRST work right. */
                realTime = 1; /* It's the _R_TC and all.  ;) */

#define IS_POWER_OF_TWO(x) (((x) & ((x) - 1)) == 0)

                if (!IS_POWER_OF_TWO(rtcHz) || rtcHz < 2) {
                    fprintf(stderr, "JP_RTC_HZ must be power of two and >= 2, "
                            "but %d was provided; using default of 2048\n",
                            rtcHz);
                    rtcHz = 2048;
                }
#else
                fputs("JP_RTC_HZ found, but RTC profiling only supported on "
                      "Linux!\n", stderr);
                  
#endif
            }
            char *f = strstr(tst,"JP_FILENAME=");
            if (f)
                f = f + strlen("JP_FILENAME=");
            else
                f = M_LOGFILE;

            char *is_slave = getenv("JPROF_SLAVE");
            if (!is_slave)
                setenv("JPROF_SLAVE","", 0);

            int pid = syscall(SYS_gettid); //gettid();
            if (is_slave)
                snprintf(filename,sizeof(filename),"%s-%d",f,pid);
            else
                snprintf(filename,sizeof(filename),"%s",f);

            // XXX FIX! inherit current capture state!
	}

	if(!doNotStart) {

	    if(gLogFD<0) {
		gLogFD = open(filename, O_CREAT | O_WRONLY | append, 0666);
		if(gLogFD<0) {
		    fprintf(stderr, "Unable to create " M_LOGFILE);
		    perror(":");
		} else {
		    struct sigaction action;
		    sigset_t mset;

		    // Dump out the address map when we terminate
		    RegisterJprofShutdown();

		    main_thread = pthread_self();
                    //fprintf(stderr,"jprof: main_thread = %u\n",
                    //        (unsigned int)main_thread);

                    // FIX!  probably should block these against each other
                    // Very unlikely.
		    sigemptyset(&mset);
		    action.sa_handler = nullptr;
		    action.sa_sigaction = StackHook;
		    action.sa_mask  = mset;
		    action.sa_flags = SA_RESTART | SA_SIGINFO;
#if defined(linux)
                    if (rtcHz) {
                        if (!setupRTCSignals(rtcHz, &action)) {
                            fputs("jprof: Error initializing RTC, NOT "
                                  "profiling\n", stderr);
                            return;
                        }
                    }

                    if (!rtcHz || firstDelay != 0)
#endif
                    {
                        if (realTime) {
                            sigaction(SIGALRM, &action, nullptr);
                        }
                    }
                    // enable PROF in all cases to simplify JP_DEFER/pause/restart
                    sigaction(SIGPROF, &action, nullptr);

		    // make it so a SIGUSR1 will stop the profiling
		    // Note:  It currently does not close the logfile.
		    // This could be configurable (so that it could
		    // later be reopened).

		    struct sigaction stop_action;
		    stop_action.sa_handler = EndProfilingHook;
		    stop_action.sa_mask  = mset;
		    stop_action.sa_flags = SA_RESTART;
		    sigaction(SIGUSR1, &stop_action, nullptr);

		    // make it so a SIGUSR2 will clear the circular buffer

		    stop_action.sa_handler = ClearProfilingHook;
		    stop_action.sa_mask  = mset;
		    stop_action.sa_flags = SA_RESTART;
		    sigaction(SIGUSR2, &stop_action, nullptr);

                    printf("Jprof: Initialized signal handler and set "
                           "timer for %lu %s, %d s "
                           "initial delay\n",
                           rtcHz ? rtcHz : timerMilliSec, 
                           rtcHz ? "Hz" : "ms",
                           firstDelay);

		    if(startTimer) {
#if defined(linux)
                        /* If we have an initial delay we can just use
                           startSignalCounter to set up a timer to fire the
                           first stackHook after that delay.  When that happens
                           we'll go and switch to RTC profiling. */
                        if (rtcHz && firstDelay == 0) {
                            puts("Jprof: enabled RTC signals");
                            enableRTCSignals(true);
                        } else
#endif
                        {
                            puts("Jprof: started timer");
                            startSignalCounter(firstDelay*1000 + timerMilliSec);
                        }
		    }
		}
	    }
	}
    } else {
        printf("setupProfilingStuff() called multiple times\n");
    }
}