Bug 139391

try rc3. It should be fixed there. If so, please close the bug.

1.0rc3 (build from source) solves the problem for DVD-R.

The bug persists with dual layer DVD-R, both data and video DVD.


After adding files to the project the bar at the bottom of K3b's window shows 7.8 of 8.0 GB used. It remains unchanged until writing finishes. After ejecting and reloading the media to start verifying the bar shows "7.8 GB capacity exceeded by 3.4 GB".

On Saturday 30 December 2006 17:37, Dirk Vormann wrote:
> ------- 1.0rc3 (build from source) solves the problem for DVD-R.


good.

> The bug persists with dual layer DVD-R, both data and video DVD.


not good and weird. I will investigate.

> After adding files to the project the bar at the bottom of K3b's window
> shows 7.8 of 8.0 GB used. It remains unchanged until writing finishes.
> After ejecting and reloading the media to start verifying the bar shows
> "7.8 GB capacity exceeded by 3.4 GB".


that is normal since K3b defaults to 4.4 gb media if no medium is inserted. I 
will try to change it so it is based on the project size.

> The bug persists with dual layer DVD-R, both data and video DVD. 

Is this DVD-Copy or DVD project? And you did test both a Dual layer data project and a video project with 1.0rc3?

BTW: The other thing is changed now.

DVD project only. So far I did not try copying. And yes, it is one data and one video project, both dual layer. Need to get new dual layer media, so I cannot test anything for the next few days.

Sadly I cannot reproduce this. Verification of DL media work here.... at least 
DVD+R DL as that is what I tested so far.

Tested some more.

There are no problems with DVD+R DL Verbatim 43541. (8x, written at recorders maximum speed of 6x, k3b-speed set to auto)

There are problems with DVD-R DL Verbatim 43543. (set to medium's maximum 4x in k3b) However it is no longer all media which fail verifying, only some. So I need to change the report from 'always' to 'more often than not, unpredictable'.

I am no longer certain it is k3b's fault. Might be erratic firmware. MD5-sums for all files written match, though. I still suppose the error to be with verifying, not writing.

Then again, there actually may be writing errors and I am unable to find any. What exactly does k3b test besides comparing files?

On Sunday 07 January 2007 08:17, Dirk Vormann wrote:
> Then again, there actually may be writing errors and I am unable to find
> any. What exactly does k3b test besides comparing files?


K3b calculates the md5 sum of the complete iso filesystem written to the DVD. 
First it is calculated from the data stream burned to the medium. Then it is 
read back from the medium. So in theory there could be read errors in the 
file system structure parts of the image in which case the files would still 
be the same. But it seems very unlikely that this is the case on a regular 
basis. I will try writing a DVD-R DL, too.

You should do further testing (if possible) with an intermediate image that 
you keep. That way you can compare the original burned image and the one read 
back from the written DVD. That is what I will do.

Any news on this one?

RCs are released quicker than I have data for Dual Layer media...


Currently I am writing DVD-R DL Media in three steps.

1) Video (or Data) DVD-project, create image file only. => imagefile1

2) Burn imagefile1 to disk. The verify always succedes. Failed veryfies only happen without intermediate image.

3) Reload written DVD, copy DVD, create image file only. => imagefile2


Result: imagefile1 and imagefile2 differ in size.

This applies to both RC5 and RC6.

> 1) Video (or Data) DVD-project, create image file only. => imagefile1
>
> 2) Burn imagefile1 to disk. The verify always succedes. Failed veryfies
> only happen without intermediate image.
>
> 3) Reload written DVD, copy DVD, create image file only. => imagefile2


Ok, thanks. That helps with finding the problem.

> Result: imagefile1 and imagefile2 differ in size.


this is correct since DVDs are divided in blocks of 16 sectors while the 
images created by k3b are multiples of one sector.

Created attachment 19646 [details]
debugging patch against K3b 1.0rc6

Since I have no way of reproducing the verification problem but others have I
need a way to get more information. Thus, I wrote this patch which hopefully
provides this information.
Please apply it, force a failed verification run, and send me the K3b debugging
output as presented in the debugging window (not the console output, although
both might be best).

SVN commit 633751 by trueg:

* Added more debugging output for better bug hunting
* Fixed Video DVD project size calculation
* Let the MD5 job read all the data and finish gracefully
  instead of stopping it once the verification job "thinks"
  all data is processed.

BUG: 139084, 139391


 M  +26 -5     jobs/k3bdatatrackreader.cpp  
 M  +8 -3      jobs/k3bverificationjob.cpp  
 M  +9 -1      projects/datacd/k3bisoimager.cpp  
 M  +15 -2     projects/videodvd/k3bvideodvdimager.cpp  
 M  +3 -0      projects/videodvd/k3bvideodvdimager.h  
 M  +20 -4     tools/k3bactivepipe.cpp  
 M  +10 -0     tools/k3bactivepipe.h  
 M  +3 -0      tools/k3bmd5job.cpp  


--- trunk/extragear/multimedia/k3b/libk3b/jobs/k3bdatatrackreader.cpp #633750:633751
@@ -184,10 +184,13 @@
   }
 
   emitInfoMessage( i18n("Reading with sector size %1.").arg(m_usedSectorSize), K3bJob::INFO );
-  kdDebug() << "(K3bDataTrackReader::WorkThread) reading sectors " 
-	    << m_firstSector.lba() << " to " << m_lastSector.lba() 
-	    << " (" << (m_lastSector.lba() - m_firstSector.lba() + 1) 
-	    << ") with sector size: " << m_usedSectorSize << endl;
+  emitDebuggingOutput( "K3bDataTrackReader", 
+		       QString("reading sectors %1 to %2 with sector size %3. Length: %4 sectors, %5 bytes.")
+		       .arg( m_firstSector.lba() )
+		       .arg( m_lastSector.lba() )
+		       .arg( m_usedSectorSize )
+		       .arg( m_lastSector.lba() - m_firstSector.lba() + 1 )
+		       .arg( Q_UINT64(m_usedSectorSize) * (Q_UINT64)(m_lastSector.lba() - m_firstSector.lba() + 1) ) );
 
   QFile file;
   if( m_fd == -1 ) {
@@ -236,9 +239,11 @@
   }
 
   kdDebug() << "(K3bDataTrackReader) using buffer size of " << s_bufferSizeSectors << " blocks." << endl;
+  emitDebuggingOutput( "K3bDataTrackReader", QString("using buffer size of %1 blocks.").arg( s_bufferSizeSectors ) );
 
   // 2. get it on
   K3b::Msf currentSector = m_firstSector;
+  K3b::Msf totalReadSectors;
   m_nextReadSector = 0;
   m_errorSectorCount = 0;
   bool writeError = false;
@@ -264,12 +269,17 @@
 	readSectors = maxReadSectors;
     }
 
+    totalReadSectors += readSectors;
+
     int readBytes = readSectors * m_usedSectorSize;
 
     if( m_fd != -1 ) {
       if( ::write( m_fd, reinterpret_cast<void*>(buffer), readBytes ) != readBytes ) {
 	kdDebug() << "(K3bDataTrackReader::WorkThread) error while writing to fd " << m_fd 
 		  << " current sector: " << (currentSector.lba()-m_firstSector.lba()) << endl;
+	emitDebuggingOutput( "K3bDataTrackReader", 
+			     QString("Error while writing to fd %1. Current sector is %2.")
+			     .arg(m_fd).arg(currentSector.lba()-m_firstSector.lba()) );
 	writeError = true;
 	break;
       }
@@ -278,6 +288,9 @@
       if( file.writeBlock( reinterpret_cast<char*>(buffer), readBytes ) != readBytes ) {
 	kdDebug() << "(K3bDataTrackReader::WorkThread) error while writing to file " << m_imagePath
 		  << " current sector: " << (currentSector.lba()-m_firstSector.lba()) << endl;
+	emitDebuggingOutput( "K3bDataTrackReader", 
+			     QString("Error while writing to file %1. Current sector is %2.")
+			     .arg(m_imagePath).arg(currentSector.lba()-m_firstSector.lba()) );
 	writeError = true;
 	break;
       }
@@ -316,6 +329,11 @@
   m_device->close();
   delete [] buffer;
 
+  emitDebuggingOutput( "K3bDataTrackReader", 
+		       QString("Read a total of %1 sectors (%2 bytes)")
+		       .arg(totalReadSectors.lba())
+		       .arg((Q_UINT64)totalReadSectors.lba()*(Q_UINT64)m_usedSectorSize) );
+
   if( m_canceled )
     emitCanceled();
 
@@ -368,7 +386,7 @@
 // here we read every single sector for itself to find the troubleing ones
 bool K3bDataTrackReader::WorkThread::retryRead( unsigned char* buffer, unsigned long startSector, unsigned int len )
 {
-
+  emitDebuggingOutput( "K3bDataTrackReader", QString( "Problem while reading. Retrying from sector %1.").arg(startSector) );
   emitInfoMessage( i18n("Problem while reading. Retrying from sector %1.").arg(startSector), K3bJob::WARNING );
 
   int sectorsRead = -1;
@@ -387,12 +405,15 @@
     if( !success ) {
       if( m_ignoreReadErrors ) {
 	emitInfoMessage( i18n("Ignoring read error in sector %1.").arg(sector), K3bJob::ERROR );
+	emitDebuggingOutput( "K3bDataTrackReader", QString( "Ignoring read error in sector %1.").arg(sector) );
+
 	++m_errorSectorCount;
 	//	  ::memset( &buffer[i], 0, 1 );
 	success = true;
       }
       else {
 	emitInfoMessage( i18n("Error while reading sector %1.").arg(sector), K3bJob::ERROR );
+	emitDebuggingOutput( "K3bDataTrackReader", QString( "Read error in sector %1.").arg(sector) );
 	break;
       }
     }
--- trunk/extragear/multimedia/k3b/libk3b/jobs/k3bverificationjob.cpp #633750:633751
@@ -95,6 +95,8 @@
   d->md5Job = new K3bMd5Job( this );
   connect( d->md5Job, SIGNAL(infoMessage(const QString&, int)), this, SIGNAL(infoMessage(const QString&, int)) );
   connect( d->md5Job, SIGNAL(finished(bool)), this, SLOT(slotMd5JobFinished(bool)) );
+  connect( d->md5Job, SIGNAL(debuggingOutput(const QString&, const QString&)), 
+	   this, SIGNAL(debuggingOutput(const QString&, const QString&)) );
 }
 
 
@@ -255,10 +257,10 @@
       d->dataTrackReader->setSectorRange( d->toc[d->tracks[trackIndex].trackNumber-1].firstSector(),
 					  d->toc[d->tracks[trackIndex].trackNumber-1].firstSector() + d->currentTrackSize -1 );
     
+    d->md5Job->setMaxReadSize( d->currentTrackSize.mode1Bytes() );
+
     d->dataTrackReader->writeToFd( d->pipe.in() );
     d->dataTrackReader->start();
-
-    d->md5Job->setMaxReadSize( d->currentTrackSize.mode1Bytes() );
   }
   else {
     // FIXME: handle audio tracks
@@ -310,7 +312,10 @@
     d->md5Job->cancel();
   else {
     d->alreadyReadSectors += trackLength( d->currentTrackIndex );
-    d->md5Job->stop();
+
+    // close the pipe and let the md5 job finish gracefully
+    d->pipe.closeIn();
+    //    d->md5Job->stop();
   }
 }
 
--- trunk/extragear/multimedia/k3b/libk3b/projects/datacd/k3bisoimager.cpp #633750:633751
@@ -163,6 +163,10 @@
 
   d->pipe->close();
 
+  emit debuggingOutput( "K3bIsoImager", 
+			QString("Pipe throughput: %1 bytes read, %2 bytes written.")
+			.arg(d->pipe->bytesRead()).arg(d->pipe->bytesWritten()) );
+
   if( d->imageFile.isOpen() ) {
     d->imageFile.close();
 
@@ -321,8 +325,8 @@
     s += *it + " ";
   }
   kdDebug() << s << endl << flush;
+  emit debuggingOutput("mkisofs calculate size command:", s);
 
-
   // since output changed during mkisofs version changes we grab both
   // stdout and stderr
 
@@ -404,6 +408,10 @@
       m_mkisofsPrintSizeResult = m_collectedMkisofsPrintSizeStderr.mid( pos+33 ).toInt( &success );
   }
 
+  emit debuggingOutput( "K3bIsoImager", 
+			QString("mkisofs print size result: %1 (%2 bytes)")
+			.arg(m_mkisofsPrintSizeResult)
+			.arg(Q_UINT64(m_mkisofsPrintSizeResult)*2048ULL) );
 
   cleanup();
 
--- trunk/extragear/multimedia/k3b/libk3b/projects/videodvd/k3bvideodvdimager.cpp #633750:633751
@@ -58,6 +58,20 @@
 
 void K3bVideoDvdImager::start()
 {
+  fixVideoDVDSettings();
+  K3bIsoImager::start();
+}
+
+
+void K3bVideoDvdImager::init()
+{
+  fixVideoDVDSettings();
+  K3bIsoImager::init();
+}
+
+
+void K3bVideoDvdImager::fixVideoDVDSettings()
+{
   // Video DVD defaults, we cannot set these in K3bVideoDvdDoc since they
   // will be overwritten in the burn dialog unless we create some K3bVideoDVDIsoOptions
   // class with different defaults. But since the whole Video DVD project is a hack we
@@ -70,13 +84,12 @@
   o.setCreateRockRidge(false); 
   o.setCreateUdf(true); 
   d->doc->setIsoOptions( o ); 
-
-  K3bIsoImager::start();
 }
 
 
 void K3bVideoDvdImager::calculateSize()
 {
+  fixVideoDVDSettings();
   K3bIsoImager::calculateSize();
 }
 
--- trunk/extragear/multimedia/k3b/libk3b/projects/videodvd/k3bvideodvdimager.h #633750:633751
@@ -39,6 +39,7 @@
 
  public slots:
   virtual void start();
+  virtual void init();
   virtual void calculateSize();
 
  protected:
@@ -51,6 +52,8 @@
   virtual void slotReceivedStderr( const QString& );
 
  private:
+  void fixVideoDVDSettings();
+
   class Private;
   Private* d;
 };
--- trunk/extragear/multimedia/k3b/libk3b/tools/k3bactivepipe.cpp #633750:633751
@@ -40,17 +40,20 @@
 
   void run() {
     kdDebug() << "(K3bActivePipe) started thread." << endl;
+    bytesRead = bytesWritten = 0;
     buffer.resize( 10*2048 );
     ssize_t r = 0;
-    ssize_t total = 0;
     while( ( r = m_pipe->read( buffer.data(), buffer.size() ) ) > 0 ) {
 
+      bytesRead += r;
+
       // write it out
       ssize_t w = 0;
       ssize_t ww = 0;
       while( w < r ) {
 	if( ( ww = m_pipe->write( buffer.data()+w, r-w ) ) > 0 ) {
 	  w += ww;
+	  bytesWritten += ww;
 	}
 	else {
 	  kdDebug() << "(K3bActivePipe) write failed." << endl;
@@ -58,10 +61,8 @@
 	  return;
 	}
       }
-
-      total += r;
     }
-    kdDebug() << "(K3bActivePipe) thread done: " << r << " (total bytes: " << total << ")" << endl;
+    kdDebug() << "(K3bActivePipe) thread done: " << r << " (total bytes read/written: " << bytesRead << "/" << bytesWritten << ")" << endl;
     close( closeWhenDone );
   }
 
@@ -115,6 +116,9 @@
   bool closeFdToWriteTo;
 
   QByteArray buffer;
+
+  Q_UINT64 bytesRead;
+  Q_UINT64 bytesWritten;
 };
 
 
@@ -237,3 +241,15 @@
     return false;
   return true;
 }
+
+
+Q_UINT64 K3bActivePipe::bytesRead() const
+{
+  return d->bytesRead;
+}
+
+
+Q_UINT64 K3bActivePipe::bytesWritten() const
+{
+  return d->bytesWritten;
+}
--- trunk/extragear/multimedia/k3b/libk3b/tools/k3bactivepipe.h #633750:633751
@@ -99,6 +99,16 @@
    */
   int out() const;
 
+  /**
+   * The number of bytes that have been read.
+   */
+  Q_UINT64 bytesRead() const;
+
+  /**
+   * The number of bytes that have been written.
+   */
+  Q_UINT64 bytesWritten() const;
+
  protected:
   /**
    * Reads the data from the source.
--- trunk/extragear/multimedia/k3b/libk3b/tools/k3bmd5job.cpp #633750:633751
@@ -204,6 +204,7 @@
 
     if( readSize <= 0 ) {
       //      kdDebug() << "(K3bMd5Job) reached max size of " << d->maxSize << ". Stopping." << endl;
+      emit debuggingOutput( "K3bMd5Job", QString("Reached max read of %1. Stopping after %2 bytes.").arg(d->maxSize).arg(d->readData) );
       stopAll();
       emit percent( 100 );
       jobFinished(true);
@@ -257,6 +258,7 @@
       }
       else if( read == 0 ) {
 	//	kdDebug() << "(K3bMd5Job) read all data. Total size: " << d->readData << ". Stopping." << endl;
+	emit debuggingOutput( "K3bMd5Job", QString("All data read. Stopping after %1 bytes.").arg(d->readData) );
 	stopAll();
 	emit percent( 100 );
 	jobFinished(true);
@@ -301,6 +303,7 @@
 
 void K3bMd5Job::stop()
 {
+  emit debuggingOutput( "K3bMd5Job", QString("Stopped manually after %1 bytes.").arg(d->readData) );
   stopAll();
   jobFinished( true );
 }