benchmark.c

Go to the documentation of this file.

/*
 * $Id: benchmark.c 941 2007-04-11 12:37:21Z bastian $
 *
 * Benchmarking module for Kamailio
 *
 * Copyright (C) 2007 Collax GmbH
 *                    (Bastian Friedrich <bastian.friedrich@collax.com>)
 * Copyright (C) 2007 Voice Sistem SRL
 *
 * This file is part of Kamailio, a free SIP server.
 *
 * Kamailio is free software; you can redistribute it and/or modify
 * it under the terms of the GNU General Public License as published by
 * the Free Software Foundation; either version 2 of the License, or
 * (at your option) any later version
 *
 * Kamailio is distributed in the hope that it will be useful,
 * but WITHOUT ANY WARRANTY; without even the implied warranty of
 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 * GNU General Public License for more details.
 *
 * You should have received a copy of the GNU General Public License
 * along with this program; if not, write to the Free Software
 * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
 *
 */

#define _GNU_SOURCE
#include <string.h>
#include <sys/time.h>
#include <stdlib.h>

#include "../../sr_module.h"
#include "../../lib/kmi/mi.h"
#include "../../mem/mem.h"
#include "../../ut.h"

#include "benchmark.h"

#include "../../mem/shm_mem.h"


MODULE_VERSION

/* Exported functions */
int bm_start_timer(struct sip_msg* _msg, char* timer, char *foobar);
int bm_log_timer(struct sip_msg* _msg, char* timer, char* mystr);

/*
 * Module destroy function prototype
 */
static void destroy(void);


/*
 * Module initialization function prototype
 */
static int mod_init(void);


/*
 * Exported parameters
 * Copied to mycfg on module initialization
 */
static int bm_enable_global = 0;
static int bm_granularity = 1;
static int bm_loglevel = L_INFO;

static int _bm_last_time_diff = 0;

/*
 * Module setup
 */

typedef struct bm_cfg {
        int enable_global;
        int granularity;
        int loglevel;
        /* The internal timers */
        int nrtimers;
        benchmark_timer_t *timers;
        benchmark_timer_t **tindex;
} bm_cfg_t;

/*
 * The setup is located in shared memory so that
 * all instances can access this variable
 */

bm_cfg_t *bm_mycfg = 0;

static inline int fixup_bm_timer(void** param, int param_no);

/*
 * Exported functions
 */
static cmd_export_t cmds[] = {
        { "bm_start_timer", (cmd_function)bm_start_timer, 1, fixup_bm_timer, 0,
                REQUEST_ROUTE|FAILURE_ROUTE|ONREPLY_ROUTE|BRANCH_ROUTE|LOCAL_ROUTE },
        { "bm_log_timer",   (cmd_function)bm_log_timer, 1, fixup_bm_timer, 0,
                REQUEST_ROUTE|FAILURE_ROUTE|ONREPLY_ROUTE|BRANCH_ROUTE|LOCAL_ROUTE },
        {"load_bm",         (cmd_function)load_bm, 0, 0, 0, 0},
        { 0, 0, 0, 0, 0, 0 }
};


/*
 * Exported parameters
 */
static param_export_t params[] = {
        {"enable",      INT_PARAM, &bm_enable_global},
        {"granularity", INT_PARAM, &bm_granularity},
        {"loglevel",    INT_PARAM, &bm_loglevel},
        { 0, 0, 0 }
};


/*
 * Exported MI functions
 */
struct mi_root* mi_bm_enable_global(struct mi_root *cmd, void *param);
struct mi_root* mi_bm_enable_timer(struct mi_root *cmd, void *param);
struct mi_root* mi_bm_granularity(struct mi_root *cmd, void *param);
struct mi_root* mi_bm_loglevel(struct mi_root *cmd, void *param);

static mi_export_t mi_cmds[] = {
        { "bm_enable_global", mi_bm_enable_global,  0,  0,  0  },
        { "bm_enable_timer",  mi_bm_enable_timer,   0,  0,  0  },
        { "bm_granularity",   mi_bm_granularity,    0,  0,  0  },
        { "bm_loglevel",      mi_bm_loglevel,       0,  0,  0  },
        { 0, 0, 0, 0, 0}
};

static int bm_get_time_diff(struct sip_msg *msg, pv_param_t *param, 
                pv_value_t *res);

static pv_export_t mod_items[] = {
        { {"BM_time_diff", sizeof("BM_time_diff")-1}, PVT_OTHER, bm_get_time_diff, 0,
                0, 0, 0, 0 },
        { {0, 0}, 0, 0, 0, 0, 0, 0, 0 }
};

/*
 * Module interface
 */
struct module_exports exports = {
        "benchmark", 
        DEFAULT_DLFLAGS,
        cmds,       /* Exported functions */
        params,     /* Exported parameters */
        0,          /* exported statistics */
        mi_cmds,    /* exported MI functions */
        mod_items,  /* exported pseudo-variables */
        0,          /* extra processes */
        mod_init,   /* module initialization function */
        0,          /* response function */
        destroy,    /* destroy function */
        0           /* child initialization function */
};


/****************/


/*
 * mod_init
 * Called by openser at init time
 */
static int mod_init(void) {
        if(register_mi_mod(exports.name, mi_cmds)!=0)
        {
                LM_ERR("failed to register MI commands\n");
                return -1;
        }

        bm_mycfg = (bm_cfg_t*)shm_malloc(sizeof(bm_cfg_t));
        memset(bm_mycfg, 0, sizeof(bm_cfg_t));
        bm_mycfg->enable_global = bm_enable_global;
        bm_mycfg->granularity   = bm_granularity;
        bm_mycfg->loglevel      = bm_loglevel;

        return 0;
}


/*
 * destroy
 * called by openser at exit time
 */
static void destroy(void)
{
        benchmark_timer_t *bmt = 0;
        benchmark_timer_t *bmp = 0;

        if(bm_mycfg!=NULL) 
        {
                /* free timers list */
                bmt = bm_mycfg->timers;
                while(bmt)
                {
                        bmp = bmt;
                        bmt = bmt->next;
                        shm_free(bmp);
                }
                if(bm_mycfg->tindex) shm_free(bm_mycfg->tindex);
                shm_free(bm_mycfg);
        }
}

void bm_reset_timer(int i)
{
        if(bm_mycfg==NULL || bm_mycfg->tindex[i]==NULL)
                return;
        bm_mycfg->tindex[i]->calls = 0;
        bm_mycfg->tindex[i]->sum = 0;
        bm_mycfg->tindex[i]->last_max = 0;
        bm_mycfg->tindex[i]->last_min = 0xffffffff;
        bm_mycfg->tindex[i]->last_sum = 0;
        bm_mycfg->tindex[i]->global_max = 0;
        bm_mycfg->tindex[i]->global_min = 0xffffffff;
}

void reset_timers(void)
{
        int i;
        if(bm_mycfg==NULL)
                return;

        for (i = 0; i < bm_mycfg->nrtimers; i++)
                bm_reset_timer(i);
}

inline int timer_active(unsigned int id)
{
        if (bm_mycfg->enable_global > 0 || bm_mycfg->timers[id].enabled > 0)
                return 1;
        else
                return 0;
}


int _bm_start_timer(unsigned int id)
{
        if (timer_active(id))
        {
                if(bm_get_time(bm_mycfg->tindex[id]->start)!=0)
                {
                        LM_ERR("error getting current time\n");
                        return -1;
                }
        }

        return 1;
}

int bm_start_timer(struct sip_msg* _msg, char* timer, char *foobar)
{
        return _bm_start_timer((unsigned int)(unsigned long)timer);
}


int _bm_log_timer(unsigned int id)
{
        /* BM_CLOCK_REALTIME */
        bm_timeval_t now;
        unsigned long long tdiff;

        if (!timer_active(id))
                return 1;

        if(bm_get_time(&now)<0)
        {
                LM_ERR("error getting current time\n");
                return -1;
        }
        
        tdiff = bm_diff_time(bm_mycfg->tindex[id]->start, &now);
        _bm_last_time_diff = (int)tdiff;

        /* What to do
         * - update min, max, sum
         * - if granularity hit: Log, reset min/max
         */

        bm_mycfg->tindex[id]->sum += tdiff;
        bm_mycfg->tindex[id]->last_sum += tdiff;
        bm_mycfg->tindex[id]->calls++;
        
        if (tdiff < bm_mycfg->tindex[id]->last_min)
                bm_mycfg->tindex[id]->last_min = tdiff;

        if (tdiff > bm_mycfg->tindex[id]->last_max)
                bm_mycfg->tindex[id]->last_max = tdiff;

        if (tdiff < bm_mycfg->tindex[id]->global_min)
                bm_mycfg->tindex[id]->global_min = tdiff;

        if (tdiff > bm_mycfg->tindex[id]->global_max)
                bm_mycfg->tindex[id]->global_max = tdiff;


        if ((bm_mycfg->tindex[id]->calls % bm_mycfg->granularity) == 0)
        {
                LM_GEN1(bm_mycfg->loglevel, "benchmark (timer %s [%d]): %llu ["
                        " msgs/total/min/max/avg - LR:"
                        " %i/%llu/%llu/%llu/%f | GB: %llu/%llu/%llu/%llu/%f]\n",
                        bm_mycfg->tindex[id]->name,
                        id,
                        tdiff,
                        bm_mycfg->granularity,
                        bm_mycfg->tindex[id]->last_sum,
                        bm_mycfg->tindex[id]->last_min,
                        bm_mycfg->tindex[id]->last_max,
                        ((double)bm_mycfg->tindex[id]->last_sum)/bm_mycfg->granularity,
                        bm_mycfg->tindex[id]->calls,
                        bm_mycfg->tindex[id]->sum,
                        bm_mycfg->tindex[id]->global_min,
                        bm_mycfg->tindex[id]->global_max,
                        ((double)bm_mycfg->tindex[id]->sum)/bm_mycfg->tindex[id]->calls);

                bm_mycfg->tindex[id]->last_sum = 0;
                bm_mycfg->tindex[id]->last_max = 0;
                bm_mycfg->tindex[id]->last_min = 0xffffffff;
        }

        return 1;
}       

int bm_log_timer(struct sip_msg* _msg, char* timer, char* mystr)
{
        return _bm_log_timer((unsigned int)(unsigned long)timer);
}

int _bm_register_timer(char *tname, int mode, unsigned int *id)
{
        benchmark_timer_t *bmt = 0;
        benchmark_timer_t **tidx = 0;

        if(tname==NULL || id==NULL || bm_mycfg==NULL || strlen(tname)==0
                        || strlen(tname)>BM_NAME_LEN-1)
                return -1;

        bmt = bm_mycfg->timers;
        while(bmt)
        {
                if(strcmp(bmt->name, tname)==0)
                {
                        *id = bmt->id;
                        return 0;
                }
                bmt = bmt->next;
        }
        if(mode==0)
                return -1;

        bmt = (benchmark_timer_t*)shm_malloc(sizeof(benchmark_timer_t));

        if(bmt==0)
        {
                LM_ERR("no more shm\n");
                return -1;
        }
        memset(bmt, 0, sizeof(benchmark_timer_t));

        /* private memory, otherwise we have races */
        bmt->start = (bm_timeval_t*)pkg_malloc(sizeof(bm_timeval_t)); 
        if(bmt->start == NULL)
        {
                shm_free(bmt);
                LM_ERR("no more pkg\n");
                return -1;
        }
        memset(bmt->start, 0, sizeof(bm_timeval_t)); 

        strcpy(bmt->name, tname);
        if(bm_mycfg->timers==0)
        {
                bmt->id = 0;
                bm_mycfg->timers = bmt;
        } else {
                bmt->id = bm_mycfg->timers->id+1;
                bmt->next = bm_mycfg->timers;
                bm_mycfg->timers = bmt;
        }

        /* do the indexing */
        if(bmt->id%10==0)
        {
                if(bm_mycfg->tindex!=NULL)
                        tidx = bm_mycfg->tindex;
                bm_mycfg->tindex = (benchmark_timer_t**)shm_malloc((10+bmt->id)*
                                                                sizeof(benchmark_timer_t*));
                if(bm_mycfg->tindex==0)
                {
                        LM_ERR("no more share memory\n");
                        if(tidx!=0)
                                shm_free(tidx);
                        return -1;
                }
                memset(bm_mycfg->tindex, 0, (10+bmt->id)*sizeof(benchmark_timer_t*));
                if(tidx!=0)
                {
                        memcpy(bm_mycfg->tindex, tidx, bmt->id*sizeof(benchmark_timer_t*));
                        shm_free(tidx);
                }
        }
        bm_mycfg->tindex[bmt->id] = bmt;
        bm_mycfg->nrtimers = bmt->id + 1;
        bm_reset_timer(bmt->id);
        *id = bmt->id;
        LM_DBG("timer [%s] added with index <%u>\n", bmt->name, bmt->id);

        return 0;
}

int load_bm( struct bm_binds *bmb)
{
        if(bmb==NULL)
                return -1;

        bmb->bm_register = _bm_register_timer;
        bmb->bm_start    = _bm_start_timer;
        bmb->bm_log          = _bm_log_timer;

        return 1;
}


static inline char * pkg_strndup( char* _p, int _len)
{
        char *s;

        s = (char*)pkg_malloc(_len+1);
        if (s==NULL)
                return NULL;
        memcpy(s,_p,_len);
        s[_len] = 0;
        return s;
}



struct mi_root* mi_bm_enable_global(struct mi_root *cmd, void *param)
{
        struct mi_node *node;

        char *p1, *e1;
        long int v1;

        node = cmd->node.kids;

        if ((node == NULL) || (node->next != NULL))
                return init_mi_tree( 400, MI_MISSING_PARM_S, MI_MISSING_PARM_LEN);

        p1 = pkg_strndup(node->value.s, node->value.len);

        v1 = strtol(p1, &e1, 0);

        if ((*e1 != '\0') || (*p1 == '\0')) {
                pkg_free(p1);
                return init_mi_tree( 400, MI_BAD_PARM_S, MI_BAD_PARM_LEN);
        }

        if ((v1 < -1) || (v1 > 1)) {
                pkg_free(p1);
                return init_mi_tree( 400, MI_BAD_PARM_S, MI_BAD_PARM_LEN);
        }

        bm_mycfg->enable_global = v1;

        pkg_free(p1);
        return init_mi_tree( 200, MI_OK_S, MI_OK_LEN);
}

struct mi_root* mi_bm_enable_timer(struct mi_root *cmd, void *param)
{
        struct mi_node *node;

        char *p1, *p2, *e2;
        long int v2;
        unsigned int id;

        node = cmd->node.kids;

        if ((node == NULL) || (node->next == NULL) || (node->next->next != NULL))
                return init_mi_tree( 400, MI_MISSING_PARM_S, MI_MISSING_PARM_LEN);

        p1 = pkg_strndup(node->value.s, node->value.len);

        if(_bm_register_timer(p1, 0, &id)!=0)
        {
                pkg_free(p1);
                return init_mi_tree( 400, MI_BAD_PARM_S, MI_BAD_PARM_LEN);
        }
        p2 = pkg_strndup(node->next->value.s, node->next->value.len);
        v2 = strtol(p2, &e2, 0);
        
        pkg_free(p1);
        pkg_free(p2);

        if (*e2 != '\0' || *p2 == '\0')
                return init_mi_tree( 400, MI_BAD_PARM_S, MI_BAD_PARM_LEN);

        if ((v2 < 0) || (v2 > 1))
                return init_mi_tree( 400, MI_BAD_PARM_S, MI_BAD_PARM_LEN);

        bm_mycfg->timers[id].enabled = v2;

        return init_mi_tree( 200, MI_OK_S, MI_OK_LEN);
}

struct mi_root* mi_bm_granularity(struct mi_root *cmd, void *param)
{
        struct mi_node *node;

        char *p1, *e1;
        long int v1;

        node = cmd->node.kids;

        if ((node == NULL) || (node->next != NULL))
                return init_mi_tree( 400, MI_MISSING_PARM_S, MI_MISSING_PARM_LEN);

        p1 = pkg_strndup(node->value.s, node->value.len);

        v1 = strtol(p1, &e1, 0);

        pkg_free(p1);

        if ((*e1 != '\0') || (*p1 == '\0'))
                return init_mi_tree( 400, MI_BAD_PARM_S, MI_BAD_PARM_LEN);

        if (v1 < 1)
                return init_mi_tree( 400, MI_BAD_PARM_S, MI_BAD_PARM_LEN);

        bm_mycfg->granularity = v1;

        return init_mi_tree( 200, MI_OK_S, MI_OK_LEN);
}

struct mi_root* mi_bm_loglevel(struct mi_root *cmd, void *param)
{
        struct mi_node *node;

        char *p1, *e1;
        long int v1;

        node = cmd->node.kids;

        if ((node == NULL) || (node->next != NULL))
                return init_mi_tree( 400, MI_MISSING_PARM_S, MI_MISSING_PARM_LEN);

        p1 = pkg_strndup(node->value.s, node->value.len);

        v1 = strtol(p1, &e1, 0);
        
        pkg_free(p1);

        if ((*e1 != '\0') || (*p1 == '\0'))
                return init_mi_tree( 400, MI_BAD_PARM_S, MI_BAD_PARM_LEN);

        if ((v1 < -3) || (v1 > 4)) /* Maximum log levels */
                return init_mi_tree( 400, MI_BAD_PARM_S, MI_BAD_PARM_LEN);

        bm_mycfg->enable_global = v1;

        return init_mi_tree( 200, MI_OK_S, MI_OK_LEN);
}
static int bm_get_time_diff(struct sip_msg *msg, pv_param_t *param,
                pv_value_t *res)
{
        if(msg==NULL)
                return -1;
        return pv_get_sintval(msg, param, res, _bm_last_time_diff);
}


static inline int fixup_bm_timer(void** param, int param_no)
{
        unsigned int tid = 0;
        if (param_no == 1)
        {
                if((_bm_register_timer((char*)(*param), 1, &tid))!=0)
                {
                        LM_ERR("cannot register timer [%s]\n", (char*)(*param));
                        return E_UNSPEC;
                }
                pkg_free(*param);
                *param = (void*)(unsigned long)tid;
        }
        return 0;
}

/* End of file */