2001-05-23 15:26:42 +02:00
|
|
|
/*
|
|
|
|
* PROGRAM: JRD Access Method
|
2004-11-10 05:26:45 +01:00
|
|
|
* MODULE: Analyse.cpp
|
2001-05-23 15:26:42 +02:00
|
|
|
* DESCRIPTION: I/O trace analysis
|
|
|
|
*
|
|
|
|
* The contents of this file are subject to the Interbase Public
|
|
|
|
* License Version 1.0 (the "License"); you may not use this file
|
|
|
|
* except in compliance with the License. You may obtain a copy
|
|
|
|
* of the License at http://www.Inprise.com/IPL.html
|
|
|
|
*
|
|
|
|
* Software distributed under the License is distributed on an
|
|
|
|
* "AS IS" basis, WITHOUT WARRANTY OF ANY KIND, either express
|
|
|
|
* or implied. See the License for the specific language governing
|
|
|
|
* rights and limitations under the License.
|
|
|
|
*
|
|
|
|
* The Original Code was created by Inprise Corporation
|
|
|
|
* and its predecessors. Portions created by Inprise Corporation are
|
|
|
|
* Copyright (C) Inprise Corporation.
|
|
|
|
*
|
|
|
|
* All Rights Reserved.
|
|
|
|
* Contributor(s): ______________________________________.
|
|
|
|
*/
|
|
|
|
|
2007-08-29 12:35:16 +02:00
|
|
|
#include "firebird.h"
|
2002-06-29 10:49:39 +02:00
|
|
|
|
2007-08-29 12:35:16 +02:00
|
|
|
#ifdef HAVE_TIMES
|
2001-05-23 15:26:42 +02:00
|
|
|
#include <sys/types.h>
|
|
|
|
#include <sys/times.h>
|
2007-08-29 12:35:16 +02:00
|
|
|
#endif
|
2009-05-29 13:27:41 +02:00
|
|
|
#ifdef TIME_WITH_SYS_TIME
|
2002-09-18 14:50:13 +02:00
|
|
|
# include <sys/time.h>
|
|
|
|
# include <time.h>
|
|
|
|
#else
|
2009-05-29 13:27:41 +02:00
|
|
|
# ifdef HAVE_SYS_TIME_H
|
2002-09-18 14:50:13 +02:00
|
|
|
# include <sys/time.h>
|
|
|
|
# else
|
|
|
|
# include <time.h>
|
|
|
|
# endif
|
|
|
|
#endif
|
2001-05-23 15:26:42 +02:00
|
|
|
|
2009-02-08 12:38:00 +01:00
|
|
|
#ifdef HAVE_IO_H
|
2007-08-29 12:35:16 +02:00
|
|
|
#include <io.h> // open, close
|
|
|
|
#endif
|
|
|
|
|
2004-04-29 00:36:29 +02:00
|
|
|
#include <stdio.h>
|
2001-05-23 15:26:42 +02:00
|
|
|
#include <errno.h>
|
2007-08-29 12:35:16 +02:00
|
|
|
#include "../jrd/jrd.h"
|
|
|
|
#include "../jrd/ods.h"
|
|
|
|
#include "../jrd/perf.h"
|
|
|
|
|
2016-05-25 14:14:01 +02:00
|
|
|
using namespace syscall_io;
|
|
|
|
|
2007-08-29 12:35:16 +02:00
|
|
|
#ifndef HAVE_TIMES
|
|
|
|
static time_t times(struct tms*);
|
|
|
|
#endif
|
|
|
|
|
|
|
|
|
|
|
|
using namespace Ods;
|
2001-05-23 15:26:42 +02:00
|
|
|
|
2004-11-10 05:26:45 +01:00
|
|
|
static void analyse(int, const SCHAR*, const pag*, int);
|
2009-01-14 12:10:48 +01:00
|
|
|
static SLONG get_long();
|
2001-05-23 15:26:42 +02:00
|
|
|
static void db_error(int);
|
2007-08-29 12:35:16 +02:00
|
|
|
static void db_open(const char*, USHORT);
|
2001-05-23 15:26:42 +02:00
|
|
|
static PAG db_read(SLONG);
|
|
|
|
|
2004-04-29 00:36:29 +02:00
|
|
|
static FILE *trace;
|
2001-05-23 15:26:42 +02:00
|
|
|
static int file;
|
|
|
|
|
2009-05-17 13:20:43 +02:00
|
|
|
// Physical IO trace events
|
2001-05-23 15:26:42 +02:00
|
|
|
|
2009-05-17 13:20:43 +02:00
|
|
|
//const SSHORT trace_create = 1;
|
2004-05-17 02:21:46 +02:00
|
|
|
const SSHORT trace_open = 2;
|
|
|
|
const SSHORT trace_page_size = 3;
|
|
|
|
const SSHORT trace_read = 4;
|
|
|
|
const SSHORT trace_write = 5;
|
|
|
|
const SSHORT trace_close = 6;
|
2001-05-23 15:26:42 +02:00
|
|
|
|
|
|
|
static USHORT page_size;
|
2007-08-29 12:35:16 +02:00
|
|
|
static pag* global_buffer;
|
2001-05-23 15:26:42 +02:00
|
|
|
|
2004-05-17 02:21:46 +02:00
|
|
|
const int MAX_PAGES = 50000;
|
2001-05-23 15:26:42 +02:00
|
|
|
|
|
|
|
static USHORT read_counts[MAX_PAGES], write_counts[MAX_PAGES];
|
|
|
|
|
|
|
|
|
|
|
|
void main( int argc, char **argv)
|
|
|
|
{
|
|
|
|
/**************************************
|
|
|
|
*
|
|
|
|
* m a i n
|
|
|
|
*
|
|
|
|
**************************************
|
|
|
|
*
|
|
|
|
* Functional description
|
|
|
|
* Replay all I/O to compute overhead of I/O system.
|
|
|
|
*
|
|
|
|
**************************************/
|
|
|
|
|
2004-11-10 05:26:45 +01:00
|
|
|
bool detail = true;
|
2001-05-23 15:26:42 +02:00
|
|
|
|
2004-11-10 05:26:45 +01:00
|
|
|
char** end;
|
2008-12-05 02:20:14 +01:00
|
|
|
for (end = argv + argc, ++argv; argv < end; argv++)
|
2007-08-29 12:35:16 +02:00
|
|
|
{
|
|
|
|
const char* s = *argv;
|
|
|
|
if (*s++ == '-')
|
2008-01-16 08:40:12 +01:00
|
|
|
{
|
|
|
|
if (UPPER(*s) == 'S')
|
2003-08-26 08:56:42 +02:00
|
|
|
detail = false;
|
2008-01-16 08:40:12 +01:00
|
|
|
}
|
2001-05-23 15:26:42 +02:00
|
|
|
}
|
|
|
|
|
2007-08-29 12:35:16 +02:00
|
|
|
SLONG reads = 0, writes = 0;
|
2016-05-30 16:50:02 +02:00
|
|
|
trace = os_utils::fopen("trace.log", "r");
|
2001-05-23 15:26:42 +02:00
|
|
|
page_size = 1024;
|
2004-11-10 05:26:45 +01:00
|
|
|
SLONG sequence = 0;
|
2001-05-23 15:26:42 +02:00
|
|
|
|
2007-08-29 12:35:16 +02:00
|
|
|
struct tms before;
|
|
|
|
time_t elapsed = times(&before);
|
2001-05-23 15:26:42 +02:00
|
|
|
|
2009-01-18 12:29:24 +01:00
|
|
|
SCHAR string[128] = "";
|
|
|
|
|
2004-11-10 05:26:45 +01:00
|
|
|
const pag* page;
|
|
|
|
SSHORT event;
|
2004-04-29 00:36:29 +02:00
|
|
|
while ((event = getc(trace)) != trace_close && event != EOF)
|
2008-01-16 08:40:12 +01:00
|
|
|
{
|
2007-08-29 12:35:16 +02:00
|
|
|
switch (event)
|
|
|
|
{
|
2001-05-23 15:26:42 +02:00
|
|
|
case trace_open:
|
2007-08-29 12:35:16 +02:00
|
|
|
{
|
|
|
|
const SLONG length = getc(trace);
|
2009-05-17 13:20:43 +02:00
|
|
|
SLONG n = length;
|
2007-08-29 12:35:16 +02:00
|
|
|
SCHAR* p = string;
|
|
|
|
while (--n >= 0)
|
|
|
|
*p++ = getc(trace);
|
|
|
|
*p = 0;
|
|
|
|
db_open(string, length);
|
|
|
|
}
|
2001-05-23 15:26:42 +02:00
|
|
|
break;
|
|
|
|
|
|
|
|
case trace_page_size:
|
|
|
|
page_size = get_long();
|
|
|
|
if (global_buffer)
|
|
|
|
free(global_buffer);
|
|
|
|
break;
|
|
|
|
|
|
|
|
case trace_read:
|
2009-05-17 13:20:43 +02:00
|
|
|
{
|
|
|
|
const SLONG n = get_long();
|
|
|
|
if (n < MAX_PAGES)
|
|
|
|
++read_counts[n];
|
2008-12-05 02:20:14 +01:00
|
|
|
|
2009-05-17 13:20:43 +02:00
|
|
|
if (detail && (page = db_read(n)))
|
|
|
|
analyse(n, "Read", page, ++sequence);
|
|
|
|
reads++;
|
|
|
|
}
|
2001-05-23 15:26:42 +02:00
|
|
|
break;
|
|
|
|
|
|
|
|
case trace_write:
|
2009-05-17 13:20:43 +02:00
|
|
|
{
|
|
|
|
const SLONG n = get_long();
|
|
|
|
if (n < MAX_PAGES)
|
|
|
|
++write_counts[n];
|
2008-12-05 02:20:14 +01:00
|
|
|
|
2009-05-17 13:20:43 +02:00
|
|
|
if (detail && (page = db_read(n)))
|
|
|
|
analyse(n, "Write", page, ++sequence);
|
|
|
|
writes++;
|
|
|
|
}
|
2001-05-23 15:26:42 +02:00
|
|
|
break;
|
|
|
|
|
|
|
|
default:
|
2004-04-29 00:36:29 +02:00
|
|
|
printf("don't understand event %d\n", event);
|
2001-05-23 15:26:42 +02:00
|
|
|
abort();
|
|
|
|
}
|
2008-01-16 08:40:12 +01:00
|
|
|
}
|
2001-05-23 15:26:42 +02:00
|
|
|
|
2007-08-29 12:35:16 +02:00
|
|
|
struct tms after;
|
2001-05-23 15:26:42 +02:00
|
|
|
elapsed = times(&after) - elapsed;
|
2004-11-10 05:26:45 +01:00
|
|
|
const SLONG cpu = after.tms_utime - before.tms_utime;
|
|
|
|
const SLONG system = after.tms_stime - before.tms_stime;
|
2001-05-23 15:26:42 +02:00
|
|
|
|
2004-04-29 00:36:29 +02:00
|
|
|
printf
|
2001-05-23 15:26:42 +02:00
|
|
|
("File: %s:\n elapsed = %d.%.2d, cpu = %d.%.2d, system = %d.%.2d, reads = %d, writes = %d\n",
|
|
|
|
string, elapsed / 60, (elapsed % 60) * 100 / 60, cpu / 60,
|
|
|
|
(cpu % 60) * 100 / 60, system / 60, (system % 60) * 100 / 60, reads,
|
|
|
|
writes);
|
|
|
|
|
2004-04-29 00:36:29 +02:00
|
|
|
printf("High activity pages:\n");
|
2001-05-23 15:26:42 +02:00
|
|
|
|
2004-11-10 05:26:45 +01:00
|
|
|
const USHORT *r, *w;
|
2009-05-17 13:20:43 +02:00
|
|
|
SLONG n;
|
2009-05-20 02:45:45 +02:00
|
|
|
|
2009-01-18 12:29:24 +01:00
|
|
|
for (r = read_counts, w = write_counts, n = 0; n < MAX_PAGES; n++, r++, w++)
|
2004-11-10 05:26:45 +01:00
|
|
|
{
|
2009-07-03 12:44:55 +02:00
|
|
|
if (*r > 1 || *w > 1)
|
|
|
|
{
|
2001-05-23 15:26:42 +02:00
|
|
|
sprintf(string, " Read: %d, write: %d", *r, *w);
|
|
|
|
if (page = db_read(n))
|
|
|
|
analyse(n, string, page, 0);
|
|
|
|
}
|
2004-11-10 05:26:45 +01:00
|
|
|
}
|
2001-05-23 15:26:42 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
|
2004-11-10 05:26:45 +01:00
|
|
|
static void analyse( int number, const SCHAR* string, const pag* page, int sequence)
|
2001-05-23 15:26:42 +02:00
|
|
|
{
|
|
|
|
/**************************************
|
|
|
|
*
|
|
|
|
* a n a l y s e
|
|
|
|
*
|
|
|
|
**************************************
|
|
|
|
*
|
|
|
|
* Functional description
|
|
|
|
* Analyse a page event.
|
|
|
|
*
|
|
|
|
**************************************/
|
|
|
|
|
|
|
|
if (sequence)
|
2004-04-29 00:36:29 +02:00
|
|
|
printf("%d. %s\t%d\t\t", sequence, string, number);
|
2001-05-23 15:26:42 +02:00
|
|
|
else
|
2004-04-29 00:36:29 +02:00
|
|
|
printf("%s\t%d\t\t", string, number);
|
2001-05-23 15:26:42 +02:00
|
|
|
|
2009-01-18 12:29:24 +01:00
|
|
|
switch (page->pag_type)
|
|
|
|
{
|
2001-05-23 15:26:42 +02:00
|
|
|
case pag_header:
|
2004-04-29 00:36:29 +02:00
|
|
|
printf("Header page\n");
|
2001-05-23 15:26:42 +02:00
|
|
|
break;
|
|
|
|
|
|
|
|
case pag_pages:
|
2004-04-29 00:36:29 +02:00
|
|
|
printf("Page inventory page\n");
|
2001-05-23 15:26:42 +02:00
|
|
|
break;
|
|
|
|
|
|
|
|
case pag_transactions:
|
2004-04-29 00:36:29 +02:00
|
|
|
printf("Transaction inventory page\n");
|
2001-05-23 15:26:42 +02:00
|
|
|
break;
|
|
|
|
|
|
|
|
case pag_pointer:
|
2004-04-29 00:36:29 +02:00
|
|
|
printf("Pointer page, relation %d, sequence %d\n",
|
2007-08-29 12:35:16 +02:00
|
|
|
((pointer_page*) page)->ppg_relation, ((pointer_page*) page)->ppg_sequence);
|
2001-05-23 15:26:42 +02:00
|
|
|
break;
|
|
|
|
|
|
|
|
case pag_data:
|
2004-04-29 00:36:29 +02:00
|
|
|
printf("Data page, relation %d, sequence %d\n",
|
2007-08-29 12:35:16 +02:00
|
|
|
((data_page*) page)->dpg_relation, ((data_page*) page)->dpg_sequence);
|
2001-05-23 15:26:42 +02:00
|
|
|
break;
|
|
|
|
|
|
|
|
case pag_root:
|
2004-04-29 00:36:29 +02:00
|
|
|
printf("Index root page, relation %d\n",
|
2004-02-20 07:43:27 +01:00
|
|
|
((index_root_page*) page)->irt_relation);
|
2001-05-23 15:26:42 +02:00
|
|
|
break;
|
|
|
|
|
|
|
|
case pag_index:
|
2004-04-29 00:36:29 +02:00
|
|
|
printf("B-Tree page, relation %d, index %d, level %d\n",
|
2007-08-29 12:35:16 +02:00
|
|
|
((btree_page*) page)->btr_relation, ((btree_page*) page)->btr_id,
|
|
|
|
((btree_page*) page)->btr_level);
|
2001-05-23 15:26:42 +02:00
|
|
|
break;
|
|
|
|
|
|
|
|
case pag_blob:
|
2009-01-18 12:29:24 +01:00
|
|
|
printf("Blob page\n\tFlags: %x, lead page: %d, sequence: %d, length: %d\n\t",
|
2008-01-16 08:40:12 +01:00
|
|
|
page->pag_flags, ((blob_page*) page)->blp_lead_page,
|
|
|
|
((blob_page*) page)->blp_sequence, ((blob_page*) page)->blp_length);
|
2001-05-23 15:26:42 +02:00
|
|
|
break;
|
|
|
|
|
|
|
|
default:
|
2004-04-29 00:36:29 +02:00
|
|
|
printf("Unknown type %d\n", page->pag_type);
|
2001-05-23 15:26:42 +02:00
|
|
|
break;
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
|
2009-01-14 12:10:48 +01:00
|
|
|
static SLONG get_long()
|
2001-05-23 15:26:42 +02:00
|
|
|
{
|
|
|
|
/**************************************
|
|
|
|
*
|
|
|
|
* g e t _ l o n g
|
|
|
|
*
|
|
|
|
**************************************
|
|
|
|
*
|
|
|
|
* Functional description
|
|
|
|
*
|
|
|
|
**************************************/
|
|
|
|
union {
|
|
|
|
SLONG l;
|
|
|
|
SSHORT i;
|
|
|
|
SCHAR c;
|
|
|
|
} value;
|
|
|
|
|
2004-11-10 05:26:45 +01:00
|
|
|
SCHAR* p = (SCHAR *) & value.l;
|
2007-08-29 12:35:16 +02:00
|
|
|
SLONG i = getc(trace);
|
|
|
|
const SLONG x = i;
|
2001-05-23 15:26:42 +02:00
|
|
|
|
|
|
|
while (--i >= 0)
|
2004-04-29 00:36:29 +02:00
|
|
|
*p++ = getc(trace);
|
2001-05-23 15:26:42 +02:00
|
|
|
|
|
|
|
if (x == 1)
|
|
|
|
return value.c;
|
2007-08-29 12:35:16 +02:00
|
|
|
|
|
|
|
if (x == 2)
|
2001-05-23 15:26:42 +02:00
|
|
|
return value.i;
|
2007-08-29 12:35:16 +02:00
|
|
|
|
|
|
|
return value.l;
|
2001-05-23 15:26:42 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
|
|
static void db_error( int status)
|
|
|
|
{
|
|
|
|
/**************************************
|
|
|
|
*
|
|
|
|
* d b _ e r r o r
|
|
|
|
*
|
|
|
|
**************************************
|
|
|
|
*
|
|
|
|
* Functional description
|
|
|
|
*
|
|
|
|
**************************************/
|
|
|
|
|
2004-04-29 00:36:29 +02:00
|
|
|
printf(strerror(status));
|
2001-05-23 15:26:42 +02:00
|
|
|
abort();
|
|
|
|
}
|
|
|
|
|
|
|
|
|
2007-08-29 12:35:16 +02:00
|
|
|
static void db_open( const char* file_name, USHORT file_length)
|
2001-05-23 15:26:42 +02:00
|
|
|
{
|
|
|
|
/**************************************
|
|
|
|
*
|
|
|
|
* d b _ o p e n
|
|
|
|
*
|
|
|
|
**************************************
|
|
|
|
*
|
|
|
|
* Functional description
|
|
|
|
* Open a database file.
|
|
|
|
*
|
|
|
|
**************************************/
|
|
|
|
|
2014-12-17 15:31:02 +01:00
|
|
|
if ((file = os_utils::open(file_name, 2)) == -1)
|
2001-05-23 15:26:42 +02:00
|
|
|
db_error(errno);
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
|
|
static PAG db_read( SLONG page_number)
|
|
|
|
{
|
|
|
|
/**************************************
|
|
|
|
*
|
|
|
|
* d b _ r e a d
|
|
|
|
*
|
|
|
|
**************************************
|
|
|
|
*
|
|
|
|
* Functional description
|
|
|
|
* Read a database page.
|
|
|
|
*
|
|
|
|
**************************************/
|
|
|
|
|
2009-01-18 12:29:24 +01:00
|
|
|
const FB_UINT64 offset = ((FB_UINT64) page_number) * ((FB_UINT64) page_size);
|
2002-06-29 10:49:39 +02:00
|
|
|
|
2001-05-23 15:26:42 +02:00
|
|
|
if (!global_buffer)
|
2007-08-29 12:35:16 +02:00
|
|
|
global_buffer = (pag*) malloc(page_size);
|
2001-05-23 15:26:42 +02:00
|
|
|
|
2016-05-30 16:50:02 +02:00
|
|
|
if (os_utils::lseek (file, offset, 0) == -1)
|
2001-05-23 15:26:42 +02:00
|
|
|
db_error(errno);
|
|
|
|
|
|
|
|
if (read(file, global_buffer, page_size) == -1)
|
|
|
|
db_error(errno);
|
|
|
|
|
|
|
|
return global_buffer;
|
|
|
|
}
|
2007-08-29 12:35:16 +02:00
|
|
|
|
|
|
|
|
|
|
|
#ifndef HAVE_TIMES
|
|
|
|
static time_t times(struct tms* buffer)
|
|
|
|
{
|
|
|
|
/**************************************
|
|
|
|
*
|
|
|
|
* t i m e s
|
|
|
|
*
|
|
|
|
**************************************
|
|
|
|
*
|
|
|
|
* Functional description
|
|
|
|
* Emulate the good old unix call "times". Only both with user time.
|
|
|
|
*
|
|
|
|
**************************************/
|
|
|
|
|
|
|
|
buffer->tms_utime = clock();
|
|
|
|
return buffer->tms_utime;
|
|
|
|
}
|
2001-05-23 15:26:42 +02:00
|
|
|
#endif
|