Changed logging parameters at disk thread pool and task level to remove useless timings

castor/tape/tapeserver/daemon/DiskReadTask.cpp

@@ -105,7 +105,10 @@ void DiskReadTask::execute(log::LogContext& lc) {
         throw castor::tape::Exception(erroMsg);
       }
       m_stats.checkingErrorTime += localTime.secs(utils::Timer::resetCounter);
+      
     } //end of while(migratingFileSize>0)
+    
+    m_stats.filesCount++;
   }
   catch(const castor::tape::exceptions::ErrorFlag&){
    

castor/tape/tapeserver/daemon/DiskReadThreadPool.cpp

@@ -53,7 +53,7 @@ DiskReadThreadPool::~DiskReadThreadPool() {
     delete m_threads.back();
     m_threads.pop_back();
   }
-  m_lc.log(LOG_INFO, "All the DiskReadWorkerThreads have been destroyed");
+  logWithStat(LOG_INFO, "All the DiskReadWorkerThreads have been destroyed");
 }
 
 //------------------------------------------------------------------------------
@@ -113,11 +113,29 @@ DiskReadTask* DiskReadThreadPool::popAndRequestMore(castor::log::LogContext &lc)
   }
   return vrp.value;
 }
+//------------------------------------------------------------------------------
+//addThreadStats
+//------------------------------------------------------------------------------
 void DiskReadThreadPool::addThreadStats(const DiskStats& other){
   castor::tape::threading::MutexLocker lock(&m_statAddingProtection);
   m_pooldStat+=other;
 }
 //------------------------------------------------------------------------------
+//logWithStat
+//------------------------------------------------------------------------------
+void DiskReadThreadPool::logWithStat(int level, const std::string& message){
+  log::ScopedParamContainer params(m_lc);
+     params.add("poolTransferTime", m_pooldStat.transferTime)
+           .add("poolWaitFreeMemoryTime",m_pooldStat.waitFreeMemoryTime)
+           .add("poolCheckingErrorTime",m_pooldStat.checkingErrorTime)
+           .add("poolOpeningTime",m_pooldStat.openingTime)
+           .add("poolFileCount",m_pooldStat.filesCount)
+           .add("poolDataVolumeInMB", 1.0*m_pooldStat.dataVolume/1024/1024)
+           .add("Average_Pool_PayloadTransferSpeedMB/s",
+                   1.0*m_pooldStat.dataVolume/1024/1024/m_pooldStat.transferTime);
+    m_lc.log(level,message);
+}
+//------------------------------------------------------------------------------
 // DiskReadWorkerThread::run
 //------------------------------------------------------------------------------
 void DiskReadThreadPool::DiskReadWorkerThread::run() {
@@ -157,9 +175,7 @@ void DiskReadThreadPool::DiskReadWorkerThread::
 logWithStat(int level, const std::string& message){
   log::ScopedParamContainer params(m_lc);
      params.add("threadTransferTime", m_threadStat.transferTime)
-           .add("threadChecksumingTime",m_threadStat.checksumingTime)
-           .add("threadWaitDataTime",m_threadStat.waitDataTime)
-           .add("threadWaitReportingTime",m_threadStat.waitReportingTime)
+           .add("threadWaitFreeMemoryTime",m_threadStat.waitFreeMemoryTime)
            .add("threadCheckingErrorTime",m_threadStat.checkingErrorTime)
            .add("threadOpeningTime",m_threadStat.openingTime)
            .add("threaDataVolumeInMB", 1.0*m_threadStat.dataVolume/1024/1024)

castor/tape/tapeserver/daemon/DiskReadThreadPool.hpp

@@ -99,6 +99,13 @@ public:
       m_injector = injector;
   }
 private:
+  /**
+   * When the last thread finish, we log all m_pooldStat members + message
+   * at the given level
+   * @param level
+   * @param message
+   */
+  void logWithStat(int level, const std::string& message);
   /** 
    * Get the next task to execute and if there is not enough tasks in queue,
    * it will ask the TaskInjector to get more jobs.

castor/tape/tapeserver/daemon/DiskWriteTask.cpp

@@ -75,7 +75,7 @@ bool DiskWriteTask::execute(RecallReportPacker& reporter,log::LogContext& lc) {
         
         checksum = mb->m_payload.adler32(checksum);
         m_stats.checksumingTime+=localTime.secs(utils::Timer::resetCounter);
-         
+       
         blockId++;
       } //end if block non NULL
       else { 
@@ -84,6 +84,7 @@ bool DiskWriteTask::execute(RecallReportPacker& reporter,log::LogContext& lc) {
         //silent data loss
         ourFile.close();
         m_stats.closingTime +=localTime.secs(utils::Timer::resetCounter);
+        m_stats.filesCount++;
         break;
       }
     } //end of while(1)
@@ -91,6 +92,7 @@ bool DiskWriteTask::execute(RecallReportPacker& reporter,log::LogContext& lc) {
     m_stats.waitReportingTime+=localTime.secs(utils::Timer::resetCounter);
     logWithStat(LOG_DEBUG, "File successfully transfered to disk",lc);
     
+    //everything went well, return true
     return true;
   } //end of try
   catch(const castor::exception::Exception& e){
@@ -107,6 +109,9 @@ bool DiskWriteTask::execute(RecallReportPacker& reporter,log::LogContext& lc) {
     releaseAllBlock();
     
     reporter.reportFailedJob(*m_recallingFile,e.getMessageValue(),e.code());
+    m_stats.waitReportingTime+=localTime.secs(utils::Timer::resetCounter);
+    
+    //got an exception, return false
     return false;
   }
 }

castor/tape/tapeserver/daemon/DiskWriteThreadPool.cpp

@@ -115,17 +115,17 @@ void DiskWriteThreadPool::addThreadStats(const DiskStats& other){
 //------------------------------------------------------------------------------
 void DiskWriteThreadPool::logWithStat(int level, const std::string& message){
   log::ScopedParamContainer params(m_lc);
-     params.add("threadTransferTime", m_pooldStat.transferTime)
-           .add("threadChecksumingTime",m_pooldStat.checksumingTime)
-           .add("threadWaitDataTime",m_pooldStat.waitDataTime)
-           .add("threadWaitReportingTime",m_pooldStat.waitReportingTime)
-           .add("threadCheckingErrorTime",m_pooldStat.checkingErrorTime)
-           .add("threadOpeningTime",m_pooldStat.openingTime)
-           .add("threadClosingTime", m_pooldStat.closingTime)
-           .add("threaDataVolumeInMB", 1.0*m_pooldStat.dataVolume/1024/1024)
-           .add("threadPayloadTransferSpeedMB/s",
+     params.add("poolTransferTime", m_pooldStat.transferTime)
+           .add("poolChecksumingTime",m_pooldStat.checksumingTime)
+           .add("poolWaitDataTime",m_pooldStat.waitDataTime)
+           .add("poolWaitReportingTime",m_pooldStat.waitReportingTime)
+           .add("poolCheckingErrorTime",m_pooldStat.checkingErrorTime)
+           .add("poolOpeningTime",m_pooldStat.openingTime)
+           .add("poolFileCount",m_pooldStat.filesCount)
+           .add("poolClosingTime", m_pooldStat.closingTime)
+           .add("poolDataVolumeInMB", 1.0*m_pooldStat.dataVolume/1024/1024)
+           .add("poolPayloadTransferSpeedMB/s",
                    1.0*m_pooldStat.dataVolume/1024/1024/m_pooldStat.transferTime);
-           ;
     m_lc.log(level,message);
 }
 //------------------------------------------------------------------------------
@@ -184,6 +184,7 @@ logWithStat(int level, const std::string& msg) {
            .add("threadChecksumingTime",m_threadStat.checksumingTime)
            .add("threadWaitDataTime",m_threadStat.waitDataTime)
            .add("threadWaitReportingTime",m_threadStat.waitReportingTime)
+           .add("threadFileCount",m_threadStat.filesCount)
            .add("threadCheckingErrorTime",m_threadStat.checkingErrorTime)
            .add("threadOpeningTime",m_threadStat.openingTime)
            .add("threadClosingTime", m_threadStat.closingTime)