Improved granularity of SCSI log time measurement and added absolute timestamp

This commit is contained in:
Thomas Schmitt 2013-06-09 15:26:32 +00:00
parent aac571ad56
commit 7d44b745a8
12 changed files with 112 additions and 52 deletions

View File

@ -1 +1 @@
#define Cdrskin_timestamP "2013.05.30.133008"
#define Cdrskin_timestamP "2013.06.09.152602"

View File

@ -1,7 +1,7 @@
/* -*- indent-tabs-mode: t; tab-width: 8; c-basic-offset: 8; -*- */
/* Copyright (c) 2004 - 2006 Derek Foreman, Ben Jansens
Copyright (c) 2006 - 2012 Thomas Schmitt <scdbackup@gmx.net>
Copyright (c) 2006 - 2013 Thomas Schmitt <scdbackup@gmx.net>
Provided under GPL version 2 or later.
*/
@ -31,6 +31,7 @@
#include "libburn.h"
#include "drive.h"
#include "transport.h"
#include "util.h"
/* ts A60825 : The storage location for back_hacks.h variables. */
#define BURN_BACK_HACKS_INIT 1
@ -43,6 +44,9 @@ struct libdax_msgs *libdax_messenger= NULL;
int burn_running = 0;
double lib_start_time;
/* ts A60813 : GNU/Linux: whether to use O_EXCL on open() of device files
ts B00212 : FreeBSD: whether to use flock(LOCK_EX) after open()
*/
@ -136,6 +140,8 @@ int burn_initialize(void)
if (burn_running)
return 1;
lib_start_time = burn_get_time(0);
burn_support_untested_profiles = 0;
ret = burn_msgs_initialize();
if (ret <= 0)

View File

@ -1,10 +1,17 @@
/* -*- indent-tabs-mode: t; tab-width: 8; c-basic-offset: 8; -*- */
/* Copyright (c) 2004 - 2006 Derek Foreman, Ben Jansens
Copyright (c) 2006 - 2013 Thomas Schmitt <scdbackup@gmx.net>
Provided under GPL version 2 or later.
*/
#ifndef BURN__INIT_H
#define BURN__INIT_H
extern int burn_running;
extern double lib_start_time;
/** Indicator for burn_drive_get_status() wether a signal hit parts of the
thread team.
0= all works well ,

View File

@ -1,7 +1,7 @@
/* -*- indent-tabs-mode: t; tab-width: 8; c-basic-offset: 8; -*- */
/*
Copyright (c) 2006 - 2011 Thomas Schmitt <scdbackup@gmx.net>
Copyright (c) 2006 - 2013 Thomas Schmitt <scdbackup@gmx.net>
Provided under GPL version 2 or later
and under FreeBSD license revised, i.e. without advertising clause.
*/
@ -861,8 +861,11 @@ int sg_issue_command(struct burn_drive *d, struct command *c)
memset(&ccb->csio.sense_data, 0, sizeof(ccb->csio.sense_data));
memset(c->sense, 0, sizeof(c->sense));
c->start_time = burn_get_time(0);
err = cam_send_ccb(d->cam, ccb);
c->end_time = burn_get_time(0);
ignore_error = sense_len = 0;
/* ts B00325 : CAM_AUTOSNS_VALID advised by Alexander Motin */
if (ccb->ccb_h.status & CAM_AUTOSNS_VALID) {
@ -959,19 +962,12 @@ int sg_issue_command(struct burn_drive *d, struct command *c)
c->sense[13] = 0x00;
done = 1;
}
/* >>> Need own duration time measurement.
Then remove bit1 from flag.
*/
}
done = scsi_eval_cmd_outcome(d, c, fp, c->sense,
sense_len, 0, start_time,
timeout_ms, i,
2 | !!ignore_error);
sense_len, start_time,
timeout_ms, i, !!ignore_error);
if (d->cancel)
done = 1;
} else {
done = 1;
}
} while (!done);
ret = 1;
ex:;

View File

@ -1,7 +1,7 @@
/* -*- indent-tabs-mode: t; tab-width: 8; c-basic-offset: 8; -*- */
/*
Copyright (c) 2009 - 2011 Thomas Schmitt <scdbackup@gmx.net>
Copyright (c) 2009 - 2013 Thomas Schmitt <scdbackup@gmx.net>
Provided under GPL version 2 or later.
*/
@ -669,9 +669,12 @@ int sg_issue_command(struct burn_drive *d, struct command *c)
for(i = 0; !done; i++) {
memset(c->sense, 0, sizeof(c->sense));
c->start_time = burn_get_time(0);
i_status = mmc_run_cmd(p_cdio, timeout_ms, &cdb, e_direction,
dxfer_len, c->page->data);
c->end_time = burn_get_time(0);
sense_valid = mmc_last_cmd_sense(p_cdio, &sense_pt);
if (sense_valid >= 18) {
memcpy(c->sense, (unsigned char *) sense_pt,
@ -717,7 +720,7 @@ int sg_issue_command(struct burn_drive *d, struct command *c)
else
sense_len = 0;
done = scsi_eval_cmd_outcome(d, c, fp, c->sense, sense_len,
0, start_time, timeout_ms, i, 2);
start_time, timeout_ms, i, 0);
if (d->cancel)
done = 1;

View File

@ -1,7 +1,7 @@
/* -*- indent-tabs-mode: t; tab-width: 8; c-basic-offset: 8; -*- */
/* Copyright (c) 2004 - 2006 Derek Foreman, Ben Jansens
Copyright (c) 2006 - 2011 Thomas Schmitt <scdbackup@gmx.net>
Copyright (c) 2006 - 2013 Thomas Schmitt <scdbackup@gmx.net>
Provided under GPL version 2 or later.
*/
@ -404,8 +404,8 @@ static int sgio_log_cmd(unsigned char *cmd, int cmd_len, FILE *fp_in, int flag)
/* ts B11110 */
static int sgio_log_reply(unsigned char *opcode, int data_dir,
unsigned char *data, int dxfer_len,
void *fp_in, unsigned char sense[18],
int sense_len, int duration, int flag)
void *fp_in, unsigned char sense[18], int sense_len,
double duration, int flag)
{
int ret;
@ -420,6 +420,7 @@ static int sgio_test(int fd)
unsigned char test_ops[] = { 0, 0, 0, 0, 0, 0 };
sg_io_hdr_t s;
int ret;
double c_start_time, c_end_time;
memset(&s, 0, sizeof(sg_io_hdr_t));
s.interface_id = 'S';
@ -430,10 +431,12 @@ static int sgio_test(int fd)
sgio_log_cmd(s.cmdp, s.cmd_len, NULL, 0);
c_start_time = burn_get_time(0);
ret= ioctl(fd, SG_IO, &s);
c_end_time = burn_get_time(0);
sgio_log_reply(s.cmdp, NO_TRANSFER, NULL, 0,
NULL, s.sbp, s.sb_len_wr, s.duration, 0);
sgio_log_reply(s.cmdp, NO_TRANSFER, NULL, 0, NULL,
s.sbp, s.sb_len_wr, c_end_time - c_start_time, 0);
return ret;
}
@ -446,6 +449,7 @@ static int sgio_inquiry_cd_drive(int fd, char *fname)
unsigned char *sense = NULL;
char *msg = NULL, *msg_pt;
int ret = 0, i;
double c_start_time, c_end_time;
BURN_ALLOC_MEM(buf, struct buffer, 1);
BURN_ALLOC_MEM(sense, unsigned char, 128);
@ -465,7 +469,9 @@ static int sgio_inquiry_cd_drive(int fd, char *fname)
sgio_log_cmd(s.cmdp, s.cmd_len, NULL, 0);
c_start_time = burn_get_time(0);
ret = ioctl(fd, SG_IO, &s);
c_end_time = burn_get_time(0);
if (ret == -1) {
sprintf(msg,
"INQUIRY on '%s' : ioctl(SG_IO) failed , errno= %d",
@ -476,8 +482,8 @@ static int sgio_inquiry_cd_drive(int fd, char *fname)
goto ex;
}
sgio_log_reply(s.cmdp, FROM_DRIVE, buf->data, s.dxfer_len,
NULL, s.sbp, s.sb_len_wr, s.duration, 0);
sgio_log_reply(s.cmdp, FROM_DRIVE, buf->data, s.dxfer_len, NULL,
s.sbp, s.sb_len_wr, c_end_time - c_start_time, 0);
if (s.sb_len_wr > 0 || s.host_status != Libburn_sg_host_oK ||
s.driver_status != Libburn_sg_driver_oK) {
@ -1992,8 +1998,12 @@ int sg_issue_command(struct burn_drive *d, struct command *c)
for(i = 0; !done; i++) {
memset(c->sense, 0, sizeof(c->sense));
c->start_time = burn_get_time(0);
err = ioctl(d->fd, SG_IO, &s);
c->end_time = burn_get_time(0);
/* ts A61010 */
/* a ssert(err != -1); */
if (err == -1) {
@ -2009,7 +2019,7 @@ int sg_issue_command(struct burn_drive *d, struct command *c)
{ret = -1; goto ex;}
}
done = scsi_eval_cmd_outcome(d, c, fp, s.sbp, s.sb_len_wr,
s.duration, start_time, s.timeout, i, 0);
start_time, s.timeout, i, 0);
if (d->cancel)
done = 1;
}

View File

@ -1,7 +1,7 @@
/* -*- indent-tabs-mode: t; tab-width: 8; c-basic-offset: 8; -*- */
/*
Copyright (c) 2010 - 2011 Thomas Schmitt <scdbackup@gmx.net>
Copyright (c) 2010 - 2013 Thomas Schmitt <scdbackup@gmx.net>
Provided under GPL version 2 or later.
*/
@ -637,8 +637,12 @@ int sg_issue_command(struct burn_drive *d, struct command *c)
for(i = 0; !done; i++) {
memset(c->sense, 0, sizeof(c->sense));
c->start_time = burn_get_time(0);
ret = ioctl(d->fd, USCSICMD, &cgc);
c->end_time = burn_get_time(0);
/* For cgc.uscsi_status see SAM-3 5.3.1, Table 22
0 = GOOD , 2 = CHECK CONDITION : Sense Data are delivered
8 = BUSY
@ -669,8 +673,8 @@ int sg_issue_command(struct burn_drive *d, struct command *c)
sense_len = 18;
else
sense_len = 0;
done = scsi_eval_cmd_outcome(d, c, fp, c->sense, sense_len, 0,
start_time, timeout_ms, i, 2);
done = scsi_eval_cmd_outcome(d, c, fp, c->sense, sense_len,
start_time, timeout_ms, i, 0);
if (d->cancel)
done = 1;

View File

@ -1,7 +1,7 @@
/* -*- indent-tabs-mode: t; tab-width: 8; c-basic-offset: 8; -*- */
/* Copyright (c) 2004 - 2006 Derek Foreman, Ben Jansens
Copyright (c) 2006 - 2012 Thomas Schmitt <scdbackup@gmx.net>
Copyright (c) 2006 - 2013 Thomas Schmitt <scdbackup@gmx.net>
Provided under GPL version 2 or later.
*/
@ -33,6 +33,7 @@
#include "debug.h"
#include "options.h"
#include "init.h"
#include "util.h"
#include "libdax_msgs.h"
extern struct libdax_msgs *libdax_messenger;
@ -1649,9 +1650,8 @@ int scsi_log_cmd(struct command *c, void *fp_in, int flag)
*/
int scsi_log_reply(unsigned char *opcode, int data_dir, unsigned char *data,
int dxfer_len, void *fp_in, unsigned char sense[18],
int sense_len, int duration, int flag)
int sense_len, double duration, int flag)
{
char durtxt[20];
FILE *fp = fp_in;
int key, asc, ascq, i, l;
@ -1667,20 +1667,18 @@ int scsi_log_reply(unsigned char *opcode, int data_dir, unsigned char *data,
for (i = 0 ; i < l; i++)
fprintf(fp, " %2.2X", sense[i]);
fprintf(fp, "\n");
durtxt[0] = 0;
if (!(flag & 2))
sprintf(durtxt, " (%6d ms)", duration);
spc_decode_sense(sense, 0, &key, &asc, &ascq);
fprintf(fp, "+++ key=%X asc=%2.2Xh ascq=%2.2Xh%s\n",
fprintf(fp, "+++ key=%X asc=%2.2Xh ascq=%2.2Xh\n",
(unsigned int) key, (unsigned int) asc,
(unsigned int) ascq, durtxt);
(unsigned int) ascq);
} else {
scsi_show_command_reply(opcode, data_dir, data,
dxfer_len, fp, 0);
if (!(flag & 2))
fprintf(fp,"%6d ms\n", duration);
}
if (!(flag & 2))
fprintf(fp, " %6.f us [ %.f ]\n",
duration * 1.0e6,
(burn_get_time(0) - lib_start_time) * 1.0e6);
if (burn_sg_log_scsi & 4)
fflush(fp);
}
@ -1698,16 +1696,19 @@ int scsi_log_reply(unsigned char *opcode, int data_dir, unsigned char *data,
@param flag bit0 causes an error message
bit1 do not print duration
*/
int scsi_log_err(struct command *c, void *fp_in, unsigned char sense[18],
int sense_len, int duration, int flag)
int scsi_log_err(struct burn_drive *d, struct command *c,
void *fp_in, unsigned char sense[18],
int sense_len, int flag)
{
int ret;
unsigned char *data = NULL;
if (c->page != NULL)
data = c->page->data;
ret= scsi_log_reply(c->opcode, c->dir, data, c->dxfer_len ,
fp_in, sense, sense_len, duration, flag);
fp_in, sense, sense_len,
c->end_time - c->start_time, flag);
return ret;
}
@ -1720,7 +1721,7 @@ int scsi_log_err(struct command *c, void *fp_in, unsigned char sense[18],
*/
int scsi_eval_cmd_outcome(struct burn_drive *d, struct command *c, void *fp,
unsigned char *sense, int sense_len,
int duration, time_t start_time, int timeout_ms,
time_t start_time, int timeout_ms,
int loop_count, int flag)
{
enum response outcome;
@ -1728,7 +1729,7 @@ int scsi_eval_cmd_outcome(struct burn_drive *d, struct command *c, void *fp,
char *msg = NULL;
if (burn_sg_log_scsi & 3)
scsi_log_err(c, fp, sense, sense_len, duration,
scsi_log_err(d, c, fp, sense, sense_len,
(sense_len > 0) | (flag & 2));
if (sense_len <= 0)
{done = 1; goto ex;}

View File

@ -1,7 +1,7 @@
/* -*- indent-tabs-mode: t; tab-width: 8; c-basic-offset: 8; -*- */
/* Copyright (c) 2004 - 2006 Derek Foreman, Ben Jansens
Copyright (c) 2006 - 2012 Thomas Schmitt <scdbackup@gmx.net>
Copyright (c) 2006 - 2013 Thomas Schmitt <scdbackup@gmx.net>
Provided under GPL version 2 or later.
*/
@ -87,15 +87,16 @@ int scsi_log_cmd(struct command *c, void *fp, int flag);
*/
int scsi_log_reply(unsigned char *opcode, int data_dir, unsigned char *data,
int dxfer_len, void *fp_in, unsigned char sense[18],
int sense_len, int duration, int flag);
int sense_len, double duration, int flag);
/* ts A91221 (former sg_log_err ts A91108) */
/** Legacy frontend to scsi_log_reply().
@param flag bit0 causes an error message
bit1 do not print duration
*/
int scsi_log_err(struct command *c, void *fp, unsigned char sense[18],
int sense_len, int duration, int flag);
int scsi_log_err(struct burn_drive *d, struct command *c,
void *fp, unsigned char sense[18],
int sense_len, int flag);
/* ts B00728 */
int spc_decode_sense(unsigned char *sense, int senselen,
@ -109,7 +110,7 @@ int spc_decode_sense(unsigned char *sense, int senselen,
*/
int scsi_eval_cmd_outcome(struct burn_drive *d, struct command *c, void *fp_in,
unsigned char *sense, int sense_len,
int duration, time_t start_time, int timeout_ms,
time_t start_time, int timeout_ms,
int loop_count, int flag);

View File

@ -1,7 +1,7 @@
/* -*- indent-tabs-mode: t; tab-width: 8; c-basic-offset: 8; -*- */
/* Copyright (c) 2004 - 2006 Derek Foreman, Ben Jansens
Copyright (c) 2006 - 2012 Thomas Schmitt <scdbackup@gmx.net>
Copyright (c) 2006 - 2013 Thomas Schmitt <scdbackup@gmx.net>
Provided under GPL version 2 or later.
*/
@ -65,6 +65,10 @@ struct command
int retry;
struct buffer *page;
int timeout; /* milliseconds */
double start_time;
double end_time;
};
struct burn_scsi_inquiry_data

View File

@ -1,6 +1,6 @@
/* Copyright (c) 2004 - 2006 Derek Foreman, Ben Jansens
Copyright (c) 2006 - 2010 Thomas Schmitt <scdbackup@gmx.net>
Copyright (c) 2006 - 2013 Thomas Schmitt <scdbackup@gmx.net>
Provided under GPL version 2 or later.
*/
@ -15,6 +15,9 @@
#include <stdlib.h>
#include <stdio.h>
#include <time.h>
#include <sys/time.h>
/* ts A80914 : This is unneeded. Version info comes from libburn.h.
#include "v ersion.h"
@ -342,3 +345,25 @@ void burn_int_to_lsb(int val, char *target)
}
/* ts B30609 */
double burn_get_time(int flag)
{
int ret;
struct timeval tv;
#ifdef Xorriso_use_clock_gettime_monotoniC
struct timespec tp;
ret = clock_gettime(CLOCK_MONOTONIC, &tp)
if (ret == 0)
return ((double) tp.tv_sec) + ((double) tp.tv_nsec) * 1.0e-9;
#endif /* Xorriso_use_clock_gettime_monotoniC */
ret = gettimeofday(&tv, NULL);
if (ret == 0)
return ((double) tv.tv_sec) + ((double) tv.tv_usec) * 1.0e-6;
return (double) time(NULL);
}

View File

@ -11,4 +11,7 @@ char *burn_printify(char *msg);
/* ts B30521 */
void burn_int_to_lsb(int val, char *target);
/* ts B30609 */
double burn_get_time(int flag);
#endif