Finding offset fails for one drive "file size 0 did not match expected size"

[simpz]

I have been setting up Whipper on all the machines I use. All Fedora 27, and 2 of the 3 machines everything works fine. On one machine with a drive:

HL-DT-ST Model: DVD+-RW GHA2N Rev: A103

Finding the offsets fails with:
% whipper offset find -o 667
/usr/lib/python2.7/site-packages/urllib3/contrib/pyopenssl.py:46: DeprecationWarning: OpenSSL.rand is deprecated - you should use os.urandom instead
import OpenSSL.SSL
Checking device /dev/sr0
Trying read offset 667 ...
WARNING:whipper.program.cdparanoia:file size 0 did not match expected size 52209740
WARNING:whipper.program.cdparanoia:non-integral amount of frames difference
WARNING: cannot rip with offset 667...
No matching offset found.
Consider trying again with a different disc.

I know the offset is 667 for this drive from the database and strangely Morituri can correctly pickup the offset:
% rip offset find -o 667
Checking device /dev/cdrom
Trying read offset 667 ...
** Message: pygobject_register_sinkfunc is deprecated (GstObject)
Offset of device is likely 667, confirming ...

Read offset of device is: 667.
Adding read offset to configuration file.

If I set this as an offset in the config file ripping fails with this error too.

[simpz]

whipper.log

[Germano0]

Drive PIONEER BDC-207D on Fedora 27 and whipper-0.6.0-6.fc27.x86_64

$ whipper drive analyze
/usr/lib/python2.7/site-packages/urllib3/contrib/pyopenssl.py:46: DeprecationWarning: OpenSSL.rand is deprecated - you should use os.urandom instead
  import OpenSSL.SSL
cdparanoia can defeat the audio cache on this drive.
Adding drive cache behaviour to configuration file.

$ whipper offset find -o +667
/usr/lib/python2.7/site-packages/urllib3/contrib/pyopenssl.py:46: DeprecationWarning: OpenSSL.rand is deprecated - you should use os.urandom instead
  import OpenSSL.SSL
Checking device /dev/sr0
Trying read offset 667 ...
WARNING:whipper.program.cdparanoia:file size 0 did not match expected size 53119964
WARNING:whipper.program.cdparanoia:non-integral amount of frames difference
WARNING: cannot rip with offset 667...    
No matching offset found.
Consider trying again with a different disc.

I tried also to not to put + before 667

$ whipper offset find -o 667
/usr/lib/python2.7/site-packages/urllib3/contrib/pyopenssl.py:46: DeprecationWarning: OpenSSL.rand is deprecated - you should use os.urandom instead
  import OpenSSL.SSL
Checking device /dev/sr0
Trying read offset 667 ...
WARNING:whipper.program.cdparanoia:file size 0 did not match expected size 53119964
WARNING:whipper.program.cdparanoia:non-integral amount of frames difference
WARNING: cannot rip with offset 667...    
No matching offset found.
Consider trying again with a different disc.

[PascalMinder]

I have a similar problem with the BH10LS38 drive. According to the DB it should be +667.

But whipper always ends in an error:

whipper offset find -o +667
Checking device /dev/sr0
Trying read offset 667 ...
WARNING:whipper.program.cdparanoia:file size 0 did not match expected size 27217388
WARNING:whipper.program.cdparanoia:non-integral amount of frames difference
WARNING: cannot rip with offset 667...    
No matching offset found.
Consider trying again with a different disc.

[rry1983]

I can confirm both my TSSTcorp DVDWBD SH-B123L and a PLDS DVD+/-RW DH-16AES encounter the same error.

A workaround I found was booting a kernel version earlier than 4.15. In Fedora 4.13.9-300 I am able to rip with no errors.

[RecursiveForest]

If you run the cd-paranoia command provided in the debug log* that supposedly returns a 0 length file manually, is the file still 0? Try replacing the 1[00:00:00.00]-1[...] with 1 if the command fails, and report back at least the lines containing the track offsets in HH:MM:SS.FF notation.

for example (from a cd that happens to be in my drive):

Ripping from sector       0 (track  1 [0:00.00])
          to sector   22364 (track  1 [4:58.14])

does the "to sector ..." track 1 match the offset that whipper is trying?

(*) DEBUG:whipper.program.cdparanoia:Running cd-paranoia --stderr-progress --sample-offset=667 --force-cdrom-device /dev/sr0 1[00:00:00.00]-1[00:04:55.72] /tmp/tmpjLoljc.track01.offset667.whipper.wav in @simpz 's case.

[rry1983]

Tested a disc that refuses to rip no matter what I try. Received the same error.

"WARNING:whipper.program.cdparanoia:non-integral amount of frames difference"
"WARNING:whipper.program.cdparanoia:file size 0 did not match expected size 42444236"
The debug file in /tmp/tmp3CF3Lo.whipper.wav is a 0 byte file.  Tested another disc which refuses to rip and its debug file in /tmp/tmphrk67w.whipper.wav is also an empty 0 byte file.

[RecursiveForest]

Can you explain what "The debug file in /tmp/..." means-- I can't tell if you're referring to log messages that say "file size 0 did not match ...", the /tmp file as ripped by whipper, or files you ripped with cd-paranoia by hand that you've named the same as the files whipper tried.

If you rip the file with no offset passed to cd-paranoia, does it still return an empty file?

[rry1983]

Sorry for being vague in my last response. I think I was describing the output files themselves being created as 0 byte files. This is the output I receive if I run whipper in Debug with the offset of my drive forced (6).

DEBUG:whipper.program.cdparanoia:Ripping from 0 to 18045 (inclusive)
DEBUG:whipper.program.cdparanoia:Starting at track 1, offset 0
DEBUG:whipper.program.cdparanoia:Stopping at track 1, offset 18045
DEBUG:whipper.program.cdparanoia:Running cd-paranoia --stderr-progress --sample-offset=6 --force-cdrom-device /dev/sr0 1[00:00:00.00]-1[00:04:00.45] /tmp/tmp9VJMBH.whipper.wav
WARNING:whipper.program.cdparanoia:file size 0 did not match expected size 42444236
WARNING:whipper.program.cdparanoia:non-integral amount of frames difference
DEBUG:whipper.program.cdparanoia:getTrackQuality: frames 18046, reads 0
DEBUG:whipper.program.cdparanoia:stop: exception FileSizeError(u'/tmp/tmp9VJMBH.whipper.wav', 'File size 0 did not match expected size 42444236')
DEBUG:whipper.command.cd:Got exception TaskException(FileSizeError(u'/tmp/tmp9VJMBH.whipper.wav', 'File size 0 did not match expected size 42444236'), 'exception %(exc)s at %(filename)s:%(line)s: ') on try 1

---

I next ran a wrong command to test your suggestion. The results may be useful.

I run cdparanoia manually it does rip the disc to .wav files with no problem. Here is output it gives for track 1.

cdparanoia III release 10.2 (September 11, 2008)
 
Ripping from sector       0 (track  1 [0:00.00])
	  to sector  251591 (track 12 [8:46.73])

outputting to track01.cdda.wav

 (== PROGRESS == [                              | 018045 00 ] == :^D * ==)

If I run cd-paranoia I get an error.

cdparanoia III release 10.2 libcdio 0.94
(C) 2001 Monty <monty@xiph.org> and Xiphophorus
(C) 2004, 2005, 2008 Rocky Bernstein <rocky@gnu.org>
(C) 2014 Robert Kausch <robert.kausch@freac.org>

Report bugs to bug-libcdio@gnu.org

++ WARN: error in ioctl CDROMREADTOCHDR: No medium found

Selected span contains non audio track at track 13.  Aborting.

I am hoping this information is helpful in solving this issue.

[RecursiveForest]

Thank you. If you could please use triple-backticks to quote large sections of console text it would make your reports easier to read.

Can you also please post the full command line you used with cdparanoia and cd-paranoia to rip the discs? I'm not sure if you ran them with a specific (correct? incorrect?) offset, or no offset at all.

It'd also be helpful to paste the musicbrainz URL for the CD in question.

Interesting that this is looking to be a divergence in behaviour between cdparanoia and libcdio's cd-paranoia.

[rry1983]

If I run cd-paranoia with forced offset I get this:

$ cd-paranoia -B -d /dev/sr0 -o 6
cdparanoia III release 10.2 libcdio 0.94
(C) 2001 Monty <monty@xiph.org> and Xiphophorus
(C) 2004, 2005, 2008 Rocky Bernstein <rocky@gnu.org>
(C) 2014 Robert Kausch <robert.kausch@freac.org>

Report bugs to bug-libcdio@gnu.org

Forcing search overlap to 6 sectors; ignoring autosense
Selected span contains non audio track at track 13.  Aborting.

If I run cdparanoid with same forced offset I get this:

cdparanoia -B -d /dev/sr0 -o 6
cdparanoia III release 10.2 (September 11, 2008)

Forcing search overlap to 6 sectors; ignoring autosense
Ripping from sector       0 (track  1 [0:00.00])
	  to sector  251591 (track 12 [8:46.73])

outputting to track01.cdda.wav

 (== PROGRESS == [                              | 018045 00 ] == :^D * ==)

The musicbrainz URL is: https://musicbrainz.org/cdtoc/attach?toc=1+12+251742+150+18196+35827+49678+67595+94386+115802+132031+153418+174992+196843+212218&tracks=12&id=DdgxjFT7gVEdHxKuxi5SdDK9kJg-

I am also going to attach the whole debug log file to this posting.

whipper.log

[simpz]

Sorry not been repsonding quickly, the machine with this issue wasn't nearby.

But stealing the more cd-paranoia command from the log file:

DEBUG:whipper.program.cdparanoia:Running cd-paranoia --stderr-progress --sample-offset=667 --force-cdrom-device /dev/sr0 1[00:00:00.00]-1[00:04:55.72] /tmp/tmpMaZjhE.track01.offset667.whipper.wav
WARNING:whipper.program.cdparanoia:file size 0 did not match expected size 52209740
WARNING:whipper.program.cdparanoia:non-integral amount of frames difference
DEBUG:whipper.program.cdparanoia:getTrackQuality: frames 22198, reads 0

I get the following output:

% grep cd-paranoia whipper.log 
DEBUG:whipper.program.cdparanoia:Running cd-paranoia --stderr-progress --sample-offset=667 --force-cdrom-device /dev/sr0 1[00:00:00.00]-1[00:04:55.72] /tmp/tmpMaZjhE.track01.offset667.whipper.wav

% cd-paranoia --stderr-progress --sample-offset=667 --force-cdrom-device /dev/sr0 '1[00:00:00.00]-1[00:04:55.72]' /tmp/tmpMaZjhE.track01.offset667.whipper.wav
Sending all callback output to stderr for wrapper script
cdparanoia III release 10.2 libcdio 0.94
(C) 2001 Monty <monty@xiph.org> and Xiphophorus
(C) 2004, 2005, 2008 Rocky Bernstein <rocky@gnu.org>
(C) 2014 Robert Kausch <robert.kausch@freac.org>

Report bugs to bug-libcdio@gnu.org

Time/sector offset goes beyond end of specified track.

The generated wav file is zero length.

@simpz: Could you try adding --force-overread to the arguments of the cd-paranoia command you executed? I think this issue might be related to the fact that your offset is quite large. (You need to be on cd-paranoia version 10.2+0.94+2 for this argument to be added.)

I think @rry1983's problem is a different problem from the others in this issue, not sure what the problem is there (especially because changing kernel versions fixed it), but it's probably related to the fact that cd-paranoia uses libcdio to communicate with the drive, while cdparanoia implemented the communication itself, AFAIK.

@rry1983: This probably won't matter, but you didn't force offset on the commands you executed. You used -o which forces the overlap search window size. To force the offset you need to use -O. (This is true for both cdparanoia and cd-paranoia.)

[simpz]

Maybe my cd-paranoia isn't new enough (even though this is the one shipped in the Fedora 27 repo which is usually pretty bleeding edge):

% cd-paranoia  -V
cdparanoia III release 10.2 libcdio 0.94
(C) 2001 Monty <monty@xiph.org> and Xiphophorus
(C) 2004, 2005, 2008 Rocky Bernstein <rocky@gnu.org>
(C) 2014 Robert Kausch <robert.kausch@freac.org>

Report bugs to bug-libcdio@gnu.org

As I get
cd-paranoia: unrecognized option '--force-overread'

As far as I can tell, Fedora 27 branched off from rawhide on the 15th of august last year. cd-paranoia 10.2+0.94+2 was released on the 23rd of august last year, so I guess it makes sense that that version is not in Fedora 27.