[SAMPLE][COMMAND 3/3]BTI: merging command for BTI

classic Classic list List threaded Threaded
1 message Options
Reply | Threaded
Open this post in threaded view
|

[SAMPLE][COMMAND 3/3]BTI: merging command for BTI

Masami Hiramatsu
Hi,

Here is an optional command for BTI. This dumplog command can
merge binary formatted log files. After you run the stap command
with -M and -b, you will
get stpd_cpu* files. Then you can read it by executing following
command:

$ dumplog stpd_cpu*

Also this command can convert binary formatted log files into
a LKST compatible binary log file.

$ dumplog -l stpd_cpu* -o lkst.log

--
Masami HIRAMATSU
2nd Research Dept.
Hitachi, Ltd., Systems Development Laboratory
E-mail: [hidden email]



/*
 Binary data merging program
 
 Copyright (C) HITACHI,LTD. 2005
 WRITTEN BY HITACHI SYSTEMS DEVELOPMENT LABORATORY,
 Created by M.Hiramatsu <[hidden email]>
 
 This program 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.

 This program 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

 */
#include <stdio.h>
#include <stdlib.h>
#define _GNU_SOURCE
#include <getopt.h>
#include <unistd.h>
#include <sys/types.h>

#if 0
#include <linux/lkst.h>
#include <linux/lkst_buffer.h>
#include <linux/lkst_private.h>
#else /* copies of lkst headers */

/* LKST buffer version */
#define LKST_BUF_VER    0x000102        /* major(1B) miner(1B) sub(1B) */

#define LKST_ETYPE_LKST_SYNC_TIME 0xf18

typedef u_int64_t lkst_arg_t;

/*  following 4 lines should be deleted
 *  if they has been already defined. */
typedef int posix_log_recid_t;
typedef int posix_log_facility_t;
typedef int posix_log_severity_t;
typedef int posix_log_procid_t;

#define LOGFILE_MAGIC   0xbeefface
#define LKST_ARCH_NAME_LEN 72
#define PXLOG_BINARY 1
#define LKST_LOG_MAGIC_NUM 0x76758384

/* Logfile Header for evlog compatibility. */
typedef struct log_header {
        uint log_magic; /* Magic number indicating log file */
        long log_version; /* Event logging version */
        posix_log_recid_t last_recid; /* Last recid in log: used by evlogd */
        off_t reserved1;
        uint log_generation; /* Changes during log maintenance */
} log_header_t;
struct posix_log_entry {
        unsigned int log_magic;
        posix_log_recid_t log_recid; /* ID of the event record */
        size_t log_size; /* size of the event record variable data */
        int log_format; /* format of variable data */
        int log_event_type; /* event identification code */
        posix_log_facility_t log_facility; /* event facility code */
        posix_log_severity_t log_severity; /* event severity code */
        uid_t log_uid; /* effective user ID associated with the event */
        gid_t log_gid; /* effective group ID associated with the event */
        pid_t log_pid; /* process ID associated with event */
        pid_t log_pgrp; /* process group associated with event */
        struct timespec log_time; /* event time stamp */
        unsigned int log_flags; /* bitmap of event flag */
        pthread_t log_thread; /* thread ID associated with event */
        posix_log_procid_t log_processor; /* processor ID associated with event */
};

struct lkst_log_record {
        struct posix_log_entry posix; /* log form specified by POSIX */
        lkst_arg_t log_arg1;
                        /* 1st argument acquired at a trace point */
        lkst_arg_t log_arg2;
                        /* 2nd argument acquired at a trace point */
        lkst_arg_t log_arg3;
                        /* 3rd argument acquired at a trace point */
        lkst_arg_t log_arg4;
                        /* 4th argument acquired at a trace point */
};
#endif

#define MAX_TRACE_ARGS 16

struct stp_trace_entry_head {
        unsigned long long tsc;
        int num;
        int pid;
        int cpu;
        int type;
};

#define MAX_TRACE_LOG 32
#define TSC_MAX 0x7fffffffffffffffULL
/*
enum EVENT_TYPE {
#include "tapset/lkst_events.stp"
};
*/

#define ETYPE_SYNCTIME 0

void fprint_entry(FILE * fp, struct stp_trace_entry_head *ent, long args[])
{
        int i;
        fprintf(fp, "[%-10llu] %02d, %-5d: %03d, ",
                ent->tsc, ent->cpu, ent->pid, ent->type);
        for (i = 0; i < ent->num; i++)
                fprintf(fp, "%08lx ", args[i]);
        fprintf(fp, "\n");
}

void fwrite_entry(FILE * fp, struct stp_trace_entry_head *ent, long args[])
{
        fwrite(ent, sizeof(struct stp_trace_entry_head), 1, fp);
        fwrite(args, sizeof(long), ent->num, fp);
}

static unsigned long force_freq = 0;
static struct logtime {
        unsigned long freq;
        long s;
        long ns;
        unsigned long long tsc;
} global_logtime;

static int global_firsttime = 1;

void fwrite_header(FILE * fp, struct stp_trace_entry_head *ent, long args[])
{
        log_header_t logh = {
                .log_magic = LOGFILE_MAGIC,
                .log_version = 0,
        };
        struct posix_log_entry posix_entry = {
                .log_size = (sizeof(int) * 2 +
                             sizeof(char) * LKST_ARCH_NAME_LEN),
                .log_format = PXLOG_BINARY,
        };
        struct lkst_log_record lkst_sync_time = {
                .posix = {
                          .log_event_type = LKST_ETYPE_LKST_SYNC_TIME,
                          .log_size = (sizeof(u_int64_t) * 4),
                          .log_magic = LKST_LOG_MAGIC_NUM,
                          .log_format = PXLOG_BINARY,
                          .log_time = {args[0],
                                       (args[1]%1000000) * 1000},
                          },
                .log_arg1 = ent->tsc,
                .log_arg2 = args[2] * 1000,
        };
        int endian_big = 0, buf_ver = LKST_BUF_VER;
        char arch[LKST_ARCH_NAME_LEN] = "i386";
        if (force_freq) lkst_sync_time.log_arg2 = force_freq;
        global_logtime.s = args[0];
        global_logtime.ns = (args[1]%1000000) * 1000;
        global_logtime.freq = args[2] * 1000;
        global_logtime.tsc = ent->tsc;
        fwrite(&logh, sizeof(log_header_t), 1, fp);
        fwrite(&posix_entry, sizeof(struct posix_log_entry), 1, fp);
        fwrite(&endian_big, sizeof(int), 1, fp);
        fwrite(&buf_ver, sizeof(int), 1, fp);
        fwrite(arch, sizeof(char), LKST_ARCH_NAME_LEN, fp);

        fwrite(&lkst_sync_time, sizeof(struct lkst_log_record), 1, fp);
}

#define NS_IN_SEC 1000000000

void flkst_entry(FILE * fp, struct stp_trace_entry_head *ent, long args[])
{
        if (global_firsttime) {
                if (ent->type != ETYPE_SYNCTIME) {
                        fprintf(stderr, "error: input files don't start with synctime event!\n");
                        exit(-10);
                }
                global_firsttime = 0;
                fwrite_header(fp, ent, args);
                return ;
        } else {
                struct lkst_log_record rec = {
                        .posix = {
                                .log_event_type = ent->type,
                                .log_size = (sizeof(u_int64_t) * 4),
                                .log_magic = LKST_LOG_MAGIC_NUM,
                                .log_format = PXLOG_BINARY,
                                .log_pid = ent->pid,
                                .log_processor = ent->cpu,
                        },
                        .log_arg1 = args[0],
                        .log_arg2 = args[1],
                        .log_arg3 = args[2],
                        .log_arg4 = args[3],
                };
                long long difftsc = ent->tsc - global_logtime.tsc;
                unsigned long s,ns;
                s = (unsigned long) (difftsc / global_logtime.freq);
                ns = (unsigned long) ((difftsc % global_logtime.freq) *
                                      NS_IN_SEC / global_logtime.freq);
                rec.posix.log_time.tv_sec = s + global_logtime.s;
                rec.posix.log_time.tv_nsec = ns + global_logtime.ns;
                if (rec.posix.log_time.tv_nsec > NS_IN_SEC ) {
                        rec.posix.log_time.tv_nsec -= NS_IN_SEC;
                        rec.posix.log_time.tv_sec ++;
                }
                fwrite(&rec, sizeof(struct lkst_log_record), 1, fp);
        }
}



void fread_next(FILE * fp, struct stp_trace_entry_head *ent)
{
        fread(ent, sizeof(struct stp_trace_entry_head), 1, fp);
        if (feof(fp)) {
                ent->tsc = TSC_MAX;
        }
}

void merge_output(int numfp, FILE * fp[], FILE * ofp, int fmt)
{
        struct stp_trace_entry_head ent[MAX_TRACE_LOG];
        long args[MAX_TRACE_ARGS];
        int i, min;

        for (i = 0; i < numfp; i++) {
                fread_next(fp[i], &ent[i]);
        }

        while (1) {
                min = 0;
                for (i = 0; i < numfp; i++) {
                        if (ent[min].tsc > ent[i].tsc)
                                min = i;
                }
                if (ent[min].tsc == TSC_MAX)
                        break;

                fread(args, sizeof(long), ent[min].num, fp[min]);
                switch (fmt) {
                case 1:
                        fwrite_entry(ofp, &ent[min], args);
                        break;
                case 2:
                        flkst_entry(ofp, &ent[min], args);
                        break;
                default:
                        fprint_entry(ofp, &ent[min], args);
                }
                fread_next(fp[min], &ent[min]);
        }
}

int main(int argc, char *argv[])
{
        FILE *fp[MAX_TRACE_LOG], *ofp = stdout;
        int flag = 0, i, c;

        if (argc < 2) {
                fprintf(stderr,
                        "usage: dumplog <stpfile(s)> [-b|-l][-o outfile]\n"
                        "-b : merge and output as binary\n"
                        "-l : merge and convert to LKST Logfile\n");
                return -1;
        }
        while ((c = getopt(argc, argv, "blo:")) != -1) {
                switch (c) {
                case 'b':
                        flag = 1;
                        break;
                case 'l':
                        flag = 2;
                        break;
                case 'o':
                        ofp = fopen(optarg, "w");
                        break;
                }
        }
        i = optind;
        while (i < argc) {
                if ((fp[i - optind] = fopen(argv[i], "r")) == NULL) {
                        fprintf(stderr, "Error: failed to open %s\n", argv[i]);
                        return -2;
                }
                fseek(fp[i - optind], 0, SEEK_SET);
                if (++i >= MAX_TRACE_LOG) {
                        fprintf(stderr, "Error: too many files\n");
                        return -3;
                }
        }

        merge_output(i - optind, fp, ofp, flag);
        return 0;
}