Added the open and close time in the disk/non-disk time ratio calculation in...

Added the open and close time in the disk/non-disk time ratio calculation in disk tasks (close is the most important).

castor/tape/tapeserver/daemon/DiskReadTask.cpp

@@ -179,8 +179,8 @@ void DiskReadTask::logWithStat(int level,const std::string& msg,log::LogContext&
               m_stats.totalTime?1.0*m_stats.dataVolume/1000/1000/m_stats.totalTime:0)
            .addSnprintfDouble("diskPerformanceMBps",
               m_stats.transferTime?1.0*m_stats.dataVolume/1000/1000/m_stats.transferTime:0)
-           .addSnprintfDouble("readWriteToTransferTimeRatio", 
-              m_stats.transferTime?m_stats.readWriteTime/m_stats.transferTime:0.0)
+           .addSnprintfDouble("openRWCloseToTransferTimeRatio", 
+              m_stats.transferTime?(m_stats.openingTime+m_stats.readWriteTime+m_stats.closingTime)/m_stats.transferTime:0.0)
            .add("FILEID",m_migratedFile->fileid())
            .add("path",m_migratedFile->path());
     lc.log(level,msg);

castor/tape/tapeserver/daemon/DiskReadThreadPool.cpp

@@ -143,8 +143,8 @@ void DiskReadThreadPool::logWithStat(int level, const std::string& message){
            m_pooldStat.totalTime?1.0*m_pooldStat.dataVolume/1000/1000/m_pooldStat.totalTime:0)
         .addSnprintfDouble("poolAverageDiskPerformanceMBps",
            m_pooldStat.transferTime?1.0*m_pooldStat.dataVolume/1000/1000/m_pooldStat.transferTime:0.0)
-        .addSnprintfDouble("poolReadWriteToTransferTimeRatio",
-           m_pooldStat.transferTime?m_pooldStat.readWriteTime/m_pooldStat.transferTime:0.0);
+        .addSnprintfDouble("poolOpenRWCloseToTransferTimeRatio",
+           m_pooldStat.transferTime?(m_pooldStat.openingTime+m_pooldStat.readWriteTime+m_pooldStat.closingTime)/m_pooldStat.transferTime:0.0);
   m_lc.log(level,message);
 }
 //------------------------------------------------------------------------------
@@ -206,8 +206,8 @@ logWithStat(int level, const std::string& message){
               m_threadStat.totalTime?1.0*m_threadStat.dataVolume/1000/1000/m_threadStat.totalTime:0)
            .addSnprintfDouble("threadAverageDiskPerformanceMBps",
               m_threadStat.transferTime?1.0*m_threadStat.dataVolume/1000/1000/m_threadStat.transferTime:0.0)
-           .addSnprintfDouble("threadReadWriteToTransferTimeRatio",
-              m_threadStat.transferTime?m_threadStat.readWriteTime/m_threadStat.transferTime:0.0);
+           .addSnprintfDouble("threadOpenRWCloseToTransferTimeRatio",
+              m_threadStat.transferTime?(m_threadStat.openingTime+m_threadStat.readWriteTime+m_threadStat.closingTime)/m_threadStat.transferTime:0.0);
     m_lc.log(level,message);
 }
 }}}}

castor/tape/tapeserver/daemon/DiskWriteTask.cpp

@@ -77,7 +77,8 @@ bool DiskWriteTask::execute(RecallReportPacker& reporter,log::LogContext& lc,
         // the disk file for writing...
         if (!writeFile.get()) {
           lc.log(LOG_INFO, "About to open disk file for writing");
-          transferTime.reset();
+          // Synchronise the counter with the open time counter.
+          transferTime = localTime;
           writeFile.reset(fileFactory.createWriteFile(m_recallingFile->path()));
           URLcontext.add("actualURL", writeFile->URL());
           lc.log(LOG_INFO, "Opened disk file for writing");
@@ -224,8 +225,8 @@ void DiskWriteTask::logWithStat(int level,const std::string& msg,log::LogContext
               m_stats.totalTime?1.0*m_stats.dataVolume/1000/1000/m_stats.totalTime:0)
            .addSnprintfDouble("diskPerformanceMBps",
               m_stats.transferTime?1.0*m_stats.dataVolume/1000/1000/m_stats.transferTime:0)
-           .addSnprintfDouble("readWriteToTransferTimeRatio", 
-              m_stats.transferTime?m_stats.readWriteTime/m_stats.transferTime:0.0)
+           .addSnprintfDouble("openRWCloseToTransferTimeRatio", 
+              m_stats.transferTime?(m_stats.openingTime+m_stats.readWriteTime+m_stats.closingTime)/m_stats.transferTime:0.0)
            .add("FILEID",m_recallingFile->fileid())
            .add("path",m_recallingFile->path());
     lc.log(level,msg);

castor/tape/tapeserver/daemon/DiskWriteThreadPool.cpp

@@ -137,8 +137,8 @@ void DiskWriteThreadPool::logWithStat(int level, const std::string& message){
            m_pooldStat.totalTime?1.0*m_pooldStat.dataVolume/1000/1000/m_pooldStat.totalTime:0)
         .addSnprintfDouble("poolAverageDiskPerformanceMBps",
            m_pooldStat.transferTime?1.0*m_pooldStat.dataVolume/1000/1000/m_pooldStat.transferTime:0.0)
-        .addSnprintfDouble("poolReadWriteToTransferTimeRatio",
-           m_pooldStat.transferTime?m_pooldStat.readWriteTime/m_pooldStat.transferTime:0.0);
+        .addSnprintfDouble("poolOpenRWCloseToTransferTimeRatio",
+           m_pooldStat.transferTime?(m_pooldStat.openingTime+m_pooldStat.readWriteTime+m_pooldStat.closingTime)/m_pooldStat.transferTime:0.0);
   m_lc.log(level,message);
 }
 //------------------------------------------------------------------------------
@@ -211,8 +211,8 @@ logWithStat(int level, const std::string& msg) {
               m_threadStat.totalTime?1.0*m_threadStat.dataVolume/1000/1000/m_threadStat.totalTime:0)
            .addSnprintfDouble("threadAverageDiskPerformanceMBps",
               m_threadStat.transferTime?1.0*m_threadStat.dataVolume/1000/1000/m_threadStat.transferTime:0.0)
-           .addSnprintfDouble("threadReadWriteToTransferTimeRatio",
-              m_threadStat.transferTime?m_threadStat.readWriteTime/m_threadStat.transferTime:0.0);
+           .addSnprintfDouble("threadOpenRWCloseToTransferTimeRatio",
+              m_threadStat.transferTime?(m_threadStat.openingTime+m_threadStat.readWriteTime+m_threadStat.closingTime)/m_threadStat.transferTime:0.0);
     m_lc.log(level,msg);
 }
 }}}}