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

[Masami Hiramatsu <hiramatu at sdl dot hitachi dot co dot jp>]

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: hiramatu@sdl.hitachi.co.jp


/*
 Binary data merging program
 
 Copyright (C) HITACHI,LTD. 2005
 WRITTEN BY HITACHI SYSTEMS DEVELOPMENT LABORATORY,
 Created by M.Hiramatsu <hiramatu@sdl.hitachi.co.jp>
  
 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;
}