From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (qmail 30352 invoked by alias); 15 Dec 2005 08:21:56 -0000 Received: (qmail 30324 invoked by uid 22791); 15 Dec 2005 08:21:52 -0000 X-Spam-Status: No, hits=-2.3 required=5.0 tests=AWL,BAYES_00,UNPARSEABLE_RELAY X-Spam-Check-By: sourceware.org Received: from mail4.hitachi.co.jp (HELO mail4.hitachi.co.jp) (133.145.228.5) by sourceware.org (qpsmtpd/0.31) with ESMTP; Thu, 15 Dec 2005 08:21:44 +0000 Received: from mlsv8.hitachi.co.jp (unknown [133.145.228.16]) by mail4.hitachi.co.jp (Postfix) with ESMTP id 0A9E533CD7 for ; Thu, 15 Dec 2005 17:21:41 +0900 (JST) Received: from mfilter-s6.hitachi.co.jp by mlsv8.hitachi.co.jp (8.12.11/8.12.11) id jBF8Le9J023785; Thu, 15 Dec 2005 17:21:40 +0900 Received: from vshuts2.hitachi.co.jp (unverified) by mfilter-s6.hitachi.co.jp (Content Technologies SMTPRS 4.3.17) with SMTP id ; Thu, 15 Dec 2005 17:21:40 +0900 Received: from hsdlgw92.sdl.hitachi.co.jp ([133.144.7.20]) by vshuts2.hitachi.co.jp with SMTP id M2005121517214030546 ; Thu, 15 Dec 2005 17:21:40 +0900 Received: from vgate2.sdl.hitachi.co.jp by hsdlgw92.sdl.hitachi.co.jp (8.9.3/3.7W01100113) id RAA03532; Thu, 15 Dec 2005 17:21:37 +0900 Received: from maila.sdl.hitachi.co.jp ([133.144.14.196]) by vgate2.sdl.hitachi.co.jp (SAVSMTP 3.1.1.32) with SMTP id M2005121517213725612 ; Thu, 15 Dec 2005 17:21:37 +0900 Received: from [192.168.16.226] ([192.168.16.226]) by maila.sdl.hitachi.co.jp (8.13.1/3.7W04031011) with ESMTP id jBF8LbT4006991; Thu, 15 Dec 2005 17:21:37 +0900 Message-ID: <43A12794.5030908@sdl.hitachi.co.jp> Date: Thu, 15 Dec 2005 08:32:00 -0000 From: Masami Hiramatsu User-Agent: Mozilla Thunderbird 1.0.7 (Windows/20050923) X-Accept-Language: ja, en-us, en MIME-Version: 1.0 To: systemtap@sources.redhat.com Cc: Satoshi Oshima , Hideo Aoki , Yumiko Sugita Subject: [SAMPLE][COMMAND 3/3]BTI: merging command for BTI Content-Type: multipart/mixed; boundary="------------060204040106050306090805" X-Virus-Checked: Checked by ClamAV on sourceware.org X-IsSubscribed: yes Mailing-List: contact systemtap-help@sourceware.org; run by ezmlm Precedence: bulk List-Subscribe: List-Post: List-Help: , Sender: systemtap-owner@sourceware.org X-SW-Source: 2005-q4/txt/msg00446.txt.bz2 This is a multi-part message in MIME format. --------------060204040106050306090805 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Content-length: 510 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 --------------060204040106050306090805 Content-Type: text/plain; name="dumplog.c" Content-Transfer-Encoding: 7bit Content-Disposition: inline; filename="dumplog.c" Content-length: 8303 /* Binary data merging program Copyright (C) HITACHI,LTD. 2005 WRITTEN BY HITACHI SYSTEMS DEVELOPMENT LABORATORY, Created by M.Hiramatsu 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 #include #define _GNU_SOURCE #include #include #include #if 0 #include #include #include #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 [-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; } --------------060204040106050306090805--