[xiph-commits] r15195 - in trunk/cdparanoia: . interface
xiphmont at svn.xiph.org
xiphmont at svn.xiph.org
Fri Aug 22 02:39:07 PDT 2008
Author: xiphmont
Date: 2008-08-22 02:39:06 -0700 (Fri, 22 Aug 2008)
New Revision: 15195
Modified:
trunk/cdparanoia/Makefile.in
trunk/cdparanoia/cachetest.c
trunk/cdparanoia/interface/cdda_interface.h
trunk/cdparanoia/interface/interface.c
trunk/cdparanoia/interface/scsi_interface.c
trunk/cdparanoia/main.c
trunk/cdparanoia/report.c
trunk/cdparanoia/report.h
trunk/cdparanoia/utils.h
Log:
Get a bit more of the current backpedaling into SVN
Modified: trunk/cdparanoia/Makefile.in
===================================================================
--- trunk/cdparanoia/Makefile.in 2008-08-22 07:52:16 UTC (rev 15194)
+++ trunk/cdparanoia/Makefile.in 2008-08-22 09:39:06 UTC (rev 15195)
@@ -25,7 +25,7 @@
LIBDIR=@libdir@
PWD = $(shell pwd)
-OFILES = main.o report.o header.o buffering_write.o
+OFILES = main.o report.o header.o buffering_write.o cachetest.o
export STATIC
export VERSION
Modified: trunk/cdparanoia/cachetest.c
===================================================================
--- trunk/cdparanoia/cachetest.c 2008-08-22 07:52:16 UTC (rev 15194)
+++ trunk/cdparanoia/cachetest.c 2008-08-22 09:39:06 UTC (rev 15195)
@@ -23,9 +23,16 @@
drive will tell if it caches redbook data. None should, many do,
and there's no way in (eg) MMAC/ATAPI to tell a drive not to. SCSI
drives have a FUA facility, but it's not clear how many ignore it.
- For that reason, we need to empirically determine cache size used
- for reads */
+ MMC does specify some cache side effect as part of SET READ AHEAD,
+ but it's not clear we can rely on them. For that reason, we need
+ to empirically determine cache size and strategy used for reads. */
+#include <string.h>
+#include <stdio.h>
+#include "interface/cdda_interface.h"
+#include "report.h"
+#include "cachetest.h"
+
int analyze_timing_and_cache(cdrom_drive *d){
/* Some assumptions about timing:
@@ -34,13 +41,11 @@
average transfer times; on slow setups, the speed of a drive
reading sectors via PIO will not be reliably distinguishable from
the same drive returning data from the cache via pio. We need
- something even more noticable and reliable: the seek time. A
- seek will reliably be approximately 1.5 orders of magnitude
- faster than a sequential sector access or cache hit, and slower
- systems will also tend to have slower seeks. It is unlikely we'd
- ever see a seek latency of under ~10ms given the synchronization
- requirements of a CD and the maximum possible rotational
- velocity.
+ something even more noticable and reliable: the seek time. It is
+ unlikely we'd ever see a seek latency of under ~10ms given the
+ synchronization requirements of a CD and the maximum possible
+ rotational velocity. A cache hit would always be faster, even
+ with PIO.
Further complicating things, we have to watch the data collection
carefully as we're not always going to be on an unloaded system,
@@ -63,13 +68,12 @@
int max_retries=20;
float median;
int offset;
- int debug = d->private->cache_debug;
/* set up a default pessimal take on drive behavior */
//d->private->cache_backseekflush=0;
//d->private->cache_sectors=1200;
- cdmessage(d,"\nChecking drive timing behavior...");
+ reportC("\nChecking drive timing behavior...");
/* find the longest stretch of available audio data */
@@ -89,7 +93,7 @@
}
if(firstsector==-1){
- cdmessage(d,"\n\tNo audio on disc; Cannot determine timing behavior...");
+ reportC("\n\tNo audio on disc; Cannot determine timing behavior...");
return -1;
}
@@ -113,28 +117,24 @@
if(offset<firstsector)break;
memset(histogram,0,sizeof(histogram));
- if((ret=d->read_audio(d,NULL,offset+current+1,1))<0){
+ if((ret=cdda_read(d,NULL,offset+current+1,1))<0){
/* media error! grr! retry elsewhere */
- cdmessage(d,"\n\tWARNING: media error; picking new location and trying again.");
+ reportC("\n\tWARNING: media error; picking new location and trying again.");
continue;
}
- if(debug)
- cdmessage(d,"\n\tSector timings (ms):\n\t");
+ reportC("\n\tSector timings (ms):\n\t");
for(i=0;i<current;i++){
- if(d->read_audio(d,NULL,offset+i,1)<0){
+ if(cdda_read(d,NULL,offset+i,1)<0){
/* media error! grr! retry elsewhere */
- cdmessage(d,"\n\tWARNING: media error; picking new location and trying again.");
+ reportC("\n\tWARNING: media error; picking new location and trying again.");
break;
}
- x = d->private->last_milliseconds;
+ x = cdda_milliseconds(d);
if(x>9999)x=9999;
if(x<0)x=0;
- if(debug){
- snprintf(buffer,80,"%d ",x);
- cdmessage(d,buffer);
- }
+ reportC("%d ",x);
histogram[x]++;
latency[i]=x;
@@ -148,39 +148,28 @@
prev=acc;
acc+=histogram[i];
if(acc>current/2){
- if(debug){
- cdmessage(d,"\n\tSurrounding histogram: ");
- if(i){
- snprintf(buffer,80,"%dms:%d ",i-1,acc-histogram[i]);
- cdmessage(d,buffer);
- }
- snprintf(buffer,80,"%dms:%d ",i,acc);
- cdmessage(d,buffer);
- if(i<999){
- snprintf(buffer,80,"%dms:%d ",i+1,acc+histogram[i+1]);
- cdmessage(d,buffer);
- }
- cdmessage(d,"\n");
- }
+ reportC("\n\tSurrounding histogram: ");
+ if(i)
+ reportC("%dms:%d ",i-1,acc-histogram[i]);
+
+ reportC("%dms:%d ",i,acc);
+ if(i<999)
+ reportC("%dms:%d ",i+1,acc+histogram[i+1]);
+ reportC("\n");
break;
}
}
median = (i*(acc-prev) + (i-1)*prev)/(float)acc;
- if(debug){
- snprintf(buffer,80,"\n\tsmall seek latency (%d sectors): %d ms",current,latency[0]);
- cdmessage(d,buffer);
- snprintf(buffer,80,"\n\tmedian read latency per sector: %.1f ms",median);
- cdmessage(d,buffer);
- }
+ reportC("\n\tsmall seek latency (%d sectors): %d ms",current,latency[0]);
+ reportC("\n\tmedian read latency per sector: %.1f ms",median);
/* verify slow spinup did not compromise median */
for(i=1;i<current;i++)
if(latency[i]>latency[i-1] || latency[i]<=(median+1.))break;
if(i>5){
- if(debug)
- cdmessage(d,"\n\tDrive appears to spin up slowly... retrying...");
+ reportC("\n\tDrive appears to spin up slowly... retrying...");
offset-=current+1;
continue;
}
@@ -193,8 +182,8 @@
if(latency[i]>median*10)acc++;
if(acc){
- cderror(d,"\n\tWARNING: Read timing displayed bursts of unexpected"
- "\n\tlatency; retrying for a clean read.\n");
+ report("\n\tWARNING: Read timing displayed bursts of unexpected"
+ "\n\tlatency; retrying for a clean read.\n");
continue;
}
@@ -202,12 +191,12 @@
}
if(offset<firstsector){
- cderror(d,"\n500: Unable to find sufficiently large area of"
+ report("\n500: Unable to find sufficiently large area of"
"\n\tgood media to perform timing tests. Aborting.\n");
return -500;
}
if(retry==max_retries){
- cderror(d,"\n500: Too many retries; aborting analysis.\n");
+ report("\n500: Too many retries; aborting analysis.\n");
return -500;
}
}
@@ -218,7 +207,7 @@
{
for(i=0;i<max_retries;i++){
if(d->read_audio(d,NULL,offset,1)==1){
- if(d->private->last_milliseconds<median*10) break;
+ if(cdda_milliseconds(d)<median*10) break;
}else{
/* error handling */
@@ -226,10 +215,9 @@
}
if(i<max_retries){
- cdmessage(d,"\n\tCaching test result: DRIVE IS CACHING (bad)\n");
+ reportC("\n\tCaching test result: DRIVE IS CACHING (bad)\n");
}else{
- cdmessage(d,"\n\tCaching test result: Drive is not caching (good)\n");
- d->private->cache_sectors=0;
+ reportC("\n\tCaching test result: Drive is not caching (good)\n");
return 0;
}
}
@@ -240,60 +228,47 @@
- /* bisection search on cache size */
+ /* search on cache size; cache hits are fast, seeks are not, so a
+ linear search through cache hits up to a miss are faster than a
+ bisection */
int lo=1;
int hi=15000;
int current=lo;
int under=1;
+ offset = firstsector;
+
+ reportC("\n");
+
while(current <= hi && under){
- int offset = (lastsector - firstsector - (current+1))/2+firstsector;
int i,j;
under=0;
- {
- char buffer[80];
- snprintf(buffer,80,"\n\tTesting reads for caching (%d sectors):\n\t",current);
- cdmessage(d,buffer);
- }
+ reportC("\r\tInitial fast search for cache size... %d",current-1);
- for(i=0;i<10;i++){
- int sofar=0;
- int fulltime=0;
-
- while(sofar<current){
- for(j=0;;j++){
- int readsectors = d->read_audio(d,NULL,offset+sofar,1);
- if(readsectors<=0){
+ for(i=0;i<10 && !under;i++){
+ for(j=0;;j++){
+ int ret1 = cdda_read(d,NULL,offset+current-1,1);
+ int ret2 = cdda_read(d,NULL,offset,1);
+ if(ret1<=0 || ret2<=0){
+ if(j==2){
+ reportC("\n\tRead error while performing drive cache checks; aborting test.\n");
+ return(-1);
+ }
+ }else{
+ if(cdda_milliseconds(d)==-1){
if(j==2){
- d->enable_cdda(d,0);
- cdmessage(d,"\n\tRead error while performing drive cache checks; aborting test.\n");
+ reportC("\n\tTiming error while performing drive cache checks; aborting test.\n");
return(-1);
}
}else{
- if(d->private->last_milliseconds==-1){
- if(j==2){
- d->enable_cdda(d,0);
- cdmessage(d,"\n\tTiming error while performing drive cache checks; aborting test.\n");
- return(-1);
- }
- }else{
-
- if(sofar==0){
- fprintf(stderr,">%d:%dms ",readsectors, d->private->last_milliseconds);
- fulltime = d->private->last_milliseconds;
- }
- sofar+=readsectors;
- break;
- }
+ if(cdda_milliseconds(d)<10)under=1;
+ break;
}
}
}
- if(fulltime < median*10) under=1;
}
- cdmessage(d,"\n");
-
- current*=2;
+ current++;
}
@@ -301,7 +276,7 @@
/* XXXXXX IN PROGRESS */
- cdmessage(d,"\n");
+ reportC("\n");
return 0;
}
Modified: trunk/cdparanoia/interface/cdda_interface.h
===================================================================
--- trunk/cdparanoia/interface/cdda_interface.h 2008-08-22 07:52:16 UTC (rev 15194)
+++ trunk/cdparanoia/interface/cdda_interface.h 2008-08-22 09:39:06 UTC (rev 15195)
@@ -130,6 +130,8 @@
extern int cdda_open(cdrom_drive *d);
extern long cdda_read(cdrom_drive *d, void *buffer,
long beginsector, long sectors);
+extern int cdda_clear_cache(cdrom_drive *d, int lba, int sectors);
+extern int cdda_milliseconds(cdrom_drive *d);
extern long cdda_track_firstsector(cdrom_drive *d,int track);
extern long cdda_track_lastsector(cdrom_drive *d,int track);
@@ -199,8 +201,6 @@
404: No medium present
405: Option not supported by drive
-500: Drive timing analysis read failure
-501: Drive timing analysis indeterminate
*/
#endif
Modified: trunk/cdparanoia/interface/interface.c
===================================================================
--- trunk/cdparanoia/interface/interface.c 2008-08-22 07:52:16 UTC (rev 15194)
+++ trunk/cdparanoia/interface/interface.c 2008-08-22 09:39:06 UTC (rev 15195)
@@ -128,6 +128,25 @@
return(-400);
}
+/* Failure to clear the cache returns an error code but does not add a
+ message to the message queue; this allows simpler code that assumes
+ it can always issue a cache request, even if it's possible/likely
+ it won't succeed */
+int cdda_clear_cache(cdrom_drive *d, int lba, int sectors){
+ if(!d->opened)return -400;
+ if(!d->private->cache_clear) return -405;
+ return d->private->cache_clear(d,lba,sectors);
+}
+
+/* Returns a (pessimistic) millisecond value for the duration of the
+ last CDROM command; useful for looking for seek operations in the
+ paranoia code. Does not return errors, only < 0 for no
+ measurement.*/
+int cdda_milliseconds(cdrom_drive *d){
+ if(!d->opened)return -1;
+ return d->private->last_milliseconds;
+}
+
void cdda_verbose_set(cdrom_drive *d,int err_action, int mes_action){
d->messagedest=mes_action;
d->errordest=err_action;
Modified: trunk/cdparanoia/interface/scsi_interface.c
===================================================================
--- trunk/cdparanoia/interface/scsi_interface.c 2008-08-22 07:52:16 UTC (rev 15194)
+++ trunk/cdparanoia/interface/scsi_interface.c 2008-08-22 09:39:06 UTC (rev 15195)
@@ -73,14 +73,24 @@
* Updated: but we don't always get -ENOMEM. Sometimes USB drives
* still fail the wrong way. This needs some kernel-land investigation.
*/
+ /* additional reason to use a low sector count by default: the
+ paranoia code now includes code to watch timing during operations
+ that should produce seeks, assuming that cachebusting works
+ properly. If the machine in question is using PIO, larger atomic
+ reads will require enough time to mask seeks. */
+
if (!getenv("CDDA_IGNORE_BUFSIZE_LIMIT")) {
- cur=(cur>1024*64?1024*64:cur);
+ cur=(cur>1024*32?1024*32:cur);
+ }else{
+ cdmessage(d,"\tEnvironment variable CDDA_IGNORE_BUFSIZE_LIMIT set,\n"
+ "\t\tforcing maximum possible sector size. This can break\n"
+ "\t\tspectacularly; use with caution!\n");
}
d->nsectors=cur/CD_FRAMESIZE_RAW;
d->bigbuff=cur;
sprintf(buffer,"\tSetting default read size to %d sectors (%d bytes).\n\n",
- d->nsectors,d->nsectors*CD_FRAMESIZE_RAW);
+ d->nsectors,d->nsectors*CD_FRAMESIZE_RAW);
if(cur==0) exit(1);
@@ -289,7 +299,7 @@
sigprocmask ( SIG_UNBLOCK, &(d->sigset), NULL );
memcpy(sense_buffer,sg_hd->sense_buffer,SG_MAX_SENSE);
- if (status<0)return(TR_EREAD);
+ if (status<0)return status;
if(status != SG_OFF + out_size || sg_hd->result){
if(errno==0)errno=EIO;
@@ -383,7 +393,7 @@
status = check_sbp_error(hdr.status,hdr.sbp);
if(status) return status;
}
- if (status < 0) return TR_EREAD;
+ if (status < 0) return status;
}
/* Failed/Partial DMA transfers occasionally get through. Why? No clue,
@@ -1584,15 +1594,24 @@
if(cdda_track_audiop(d,i)==1){
long firstsector=cdda_track_firstsector(d,i);
long lastsector=cdda_track_lastsector(d,i);
-
- if(mmc_cache_clear(d,firstsector+1,lastsector-firstsector-1)==0){
+ int ret;
+
+ if((ret=mmc_cache_clear(d,firstsector+1,lastsector-firstsector-1))==0){
cdmessage(d,"\tDrive accepted SET READ AHEAD command.\n");
d->private->cache_clear=mmc_cache_clear;
return;
}
+ if(ret==-EPERM){
+ cderror(d,"\nWARNING: Kernel block command filter is refusing to pass the\n"
+ " SET_READ_AHEAD command. Please see:\n"
+ " http://www.xiph.org/paranoia/trouble.html#blockfilter\n\n"
+ " for more information on correcting or working around\n"
+ " the problem.\n\n");
+ break;
+ }
}
}
- cdmessage(d,"\tDrive rejected SET READ AHEAD command; using fallback.\n");
+ cdmessage(d,"\tSET READ AHEAD command failed; using fallback.\n");
}else{
Modified: trunk/cdparanoia/main.c
===================================================================
--- trunk/cdparanoia/main.c 2008-08-22 07:52:16 UTC (rev 15194)
+++ trunk/cdparanoia/main.c 2008-08-22 09:39:06 UTC (rev 15195)
@@ -37,10 +37,8 @@
#include "report.h"
#include "version.h"
#include "header.h"
+#include "cachetest.h"
-extern int verbose;
-extern int quiet;
-
static long parse_offset(cdrom_drive *d, char *offset, int begin){
long track=-1;
long hours=-1;
@@ -265,7 +263,11 @@
" retries without progress.\n"
" -Z --disable-paranoia : disable all paranoia checking\n"
" -Y --disable-extra-paranoia : only do cdda2wav-style overlap checking\n"
-" -X --abort-on-skip : abort on imperfect reads/skips\n\n"
+" -X --abort-on-skip : abort on imperfect reads/skips\n"
+" -U --cache-test : run a complete analysis of drive caching\n"
+" behavior; verifies that cdparanoia is\n"
+" correctly modelling a sprcific drive's\n"
+" cache behavior.\n\n"
"OUTPUT SMILIES:\n"
" :-) Normal operation, low/no jitter\n"
@@ -582,7 +584,7 @@
memset(dispcache,' ',graph);
}
-const char *optstring = "escCn:o:O:d:g:k:S:prRwafvqVQhZz::YXWBi:Tt:l:";
+const char *optstring = "escCn:o:O:d:g:k:S:prRwafvqVQhZz::YXWBi:Tt:l:U";
struct option options [] = {
{"stderr-progress",no_argument,NULL,'e'},
@@ -610,6 +612,7 @@
{"version",no_argument,NULL,'V'},
{"query",no_argument,NULL,'Q'},
{"help",no_argument,NULL,'h'},
+ {"cache-test",no_argument,NULL,'U'},
{"disable-paranoia",no_argument,NULL,'Z'},
{"disable-extra-paranoia",no_argument,NULL,'Y'},
{"abort-on-skip",no_argument,NULL,'X'},
@@ -661,6 +664,7 @@
int output_endian=0; /* -1=host, 0=little, 1=big */
int query_only=0;
int batch=0,i;
+ int run_cache_test=0;
/* full paranoia, but allow skipping */
int paranoia_mode=PARANOIA_MODE_FULL^PARANOIA_MODE_NEVERSKIP;
@@ -767,6 +771,9 @@
case 'Z':
paranoia_mode=PARANOIA_MODE_DISABLE;
break;
+ case 'U':
+ run_cache_test=1;
+ break;
case 'z':
if (optarg) {
max_retries = atoi (optarg);
@@ -807,7 +814,7 @@
else{
logfile=fopen(optarg,"w");
if(logfile==NULL){
- report3("Cannot open log summary file %s: %s",(char*)optarg,
+ report("Cannot open log summary file %s: %s",(char*)optarg,
strerror(errno));
exit(1);
}
@@ -963,6 +970,9 @@
}
}
+ if(run_cache_test)
+ return analyze_timing_and_cache(d);
+
/* Dump the TOC */
if(query_only || verbose)display_toc(d);
if(query_only)exit(0);
@@ -1166,13 +1176,13 @@
out=open(outfile_name,O_RDWR|O_CREAT|O_TRUNC,0666);
if(out==-1){
- report3("Cannot open specified output file %s: %s",outfile_name,
+ report("Cannot open specified output file %s: %s",outfile_name,
strerror(errno));
cdda_close(d);
d=NULL;
exit(1);
}
- report2("outputting to %s\n",outfile_name);
+ report("outputting to %s\n",outfile_name);
if(logfile){
fprintf(logfile,"outputting to %s\n",outfile_name);
fflush(logfile);
@@ -1202,13 +1212,13 @@
out=open(outfile_name,O_RDWR|O_CREAT|O_TRUNC,0666);
if(out==-1){
- report3("Cannot open default output file %s: %s",outfile_name,
+ report("Cannot open default output file %s: %s",outfile_name,
strerror(errno));
cdda_close(d);
d=NULL;
exit(1);
}
- report2("outputting to %s\n",outfile_name);
+ report("outputting to %s\n",outfile_name);
if(logfile){
fprintf(logfile,"outputting to %s\n",outfile_name);
fflush(logfile);
@@ -1237,7 +1247,7 @@
if(buffering_write(out,
((char *)offset_buffer)+offset_buffer_used,
CD_FRAMESIZE_RAW-offset_buffer_used)){
- report2("Error writing output: %s",strerror(errno));
+ report("Error writing output: %s",strerror(errno));
exit(1);
}
}
@@ -1282,7 +1292,7 @@
if(buffering_write(out,((char *)readbuf)+offset_skip,
CD_FRAMESIZE_RAW-offset_skip)){
- report2("Error writing output: %s",strerror(errno));
+ report("Error writing output: %s",strerror(errno));
exit(1);
}
offset_skip=0;
@@ -1327,7 +1337,7 @@
if(buffering_write(out,(char *)offset_buffer,
offset_buffer_used)){
- report2("Error writing output: %s",strerror(errno));
+ report("Error writing output: %s",strerror(errno));
exit(1);
}
}
@@ -1336,7 +1346,7 @@
buffering_close(out);
if(skipped_flag){
/* remove the file */
- report2("\nRemoving aborted file: %s",outfile_name);
+ report("\nRemoving aborted file: %s",outfile_name);
unlink(outfile_name);
/* make the cursor correct if we have another track */
if(batch_track!=-1){
Modified: trunk/cdparanoia/report.c
===================================================================
--- trunk/cdparanoia/report.c 2008-08-22 07:52:16 UTC (rev 15194)
+++ trunk/cdparanoia/report.c 2008-08-22 09:39:06 UTC (rev 15195)
@@ -4,23 +4,3 @@
int quiet=0;
int verbose=CDDA_MESSAGE_FORGETIT;
-void report(char *s){
- if(!quiet){
- fprintf(stderr,s);
- fputc('\n',stderr);
- }
-}
-
-void report2(char *s, char *s2){
- if(!quiet){
- fprintf(stderr,s,s2);
- fputc('\n',stderr);
- }
-}
-
-void report3(char *s, char *s2, char *s3){
- if(!quiet){
- fprintf(stderr,s,s2,s3);
- fputc('\n',stderr);
- }
-}
Modified: trunk/cdparanoia/report.h
===================================================================
--- trunk/cdparanoia/report.h 2008-08-22 07:52:16 UTC (rev 15194)
+++ trunk/cdparanoia/report.h 2008-08-22 09:39:06 UTC (rev 15195)
@@ -1,3 +1,5 @@
-extern void report(char *s);
-extern void report2(char *s, char *s2);
-extern void report3(char *s, char *s2, char *s3);
+extern int verbose;
+extern int quiet;
+
+#define report(...) if(!quiet){fprintf(stderr, __VA_ARGS__);fputc('\n',stderr);}
+#define reportC(...) if(!quiet){fprintf(stderr, __VA_ARGS__);}
Modified: trunk/cdparanoia/utils.h
===================================================================
--- trunk/cdparanoia/utils.h 2008-08-22 07:52:16 UTC (rev 15194)
+++ trunk/cdparanoia/utils.h 2008-08-22 09:39:06 UTC (rev 15195)
@@ -7,7 +7,6 @@
extern long buffering_write(int outf, char *buffer, long num);
extern int buffering_close(int fd);
-
/* I wonder how many alignment issues this is gonna trip in the
future... it shouldn't trip any... I guess we'll find out :) */
More information about the commits
mailing list