Improved logging of the various threads of the mount session:

added a thread logging parameter, indicating the thread involved
added startup and finish log messages for threads.

castor/tape/tapeserver/daemon/DiskReadThreadPool.cpp

@@ -26,6 +26,7 @@
 #include <memory>
 #include <sstream>
 #include "castor/tape/tapeserver/daemon/MigrationTaskInjector.hpp"
+#include "log.h"
 namespace castor {
 namespace tape {
 namespace tapeserver {
@@ -80,16 +81,19 @@ namespace daemon {
     return ret;
   }
   void DiskReadThreadPool::DiskReadWorkerThread::run() {
-      std::auto_ptr<DiskReadTaskInterface> task;
-      while(1) {
-        task.reset( _this.popAndRequestMore());
-        if (NULL!=task.get()) {
-          task->execute(lc);
-        }
-        else {
-          break;
-        }
-      } //end of while(1)
+    _this.m_lc.pushOrReplace(log::Param("thread", "DiskRead"));
+    _this.m_lc.log(LOG_DEBUG, "Starting DiskReadWorkerThread");
+    std::auto_ptr<DiskReadTaskInterface> task;
+    while(1) {
+      task.reset( _this.popAndRequestMore());
+      if (NULL!=task.get()) {
+        task->execute(lc);
+      }
+      else {
+        break;
+      }
+    } //end of while(1)
+    _this.m_lc.log(LOG_DEBUG, "Finishing of DiskReadWorkerThread");
   }
   
   tape::threading::AtomicCounter<int> DiskReadThreadPool::DiskReadWorkerThread::m_nbActiveThread(0);

castor/tape/tapeserver/daemon/DiskWriteThreadPool.cpp

@@ -100,7 +100,8 @@ namespace daemon {
     return ret;
   }
   void DiskWriteThreadPool::DiskWriteWorkerThread::run() {
-    m_lc.log(LOG_INFO, "Starting disk write thread");
+    m_lc.pushOrReplace(log::Param("thread", "diskWrite"));
+    m_lc.log(LOG_INFO, "Starting DiskWriteWorkerThread");
     std::auto_ptr<DiskWriteTaskInterface>  task;
     while(1) {
       task.reset(m_parentThreadPool. m_tasks.pop());
@@ -127,7 +128,7 @@ namespace daemon {
         m_parentThreadPool.m_reporter.reportEndOfSessionWithErrors("A thread failed to write a file",SEINTERNAL);
       }
     }
-    m_lc.log(LOG_INFO, "Disk write thread exiting");
+    m_lc.log(LOG_INFO, "Finishing DiskWriteWorkerThread");
   }
 }}}}
 

castor/tape/tapeserver/daemon/MigrationTaskInjector.cpp

@@ -24,6 +24,7 @@
 
 #include "castor/tape/tapeserver/daemon/MigrationTaskInjector.hpp"
 #include "castor/tape/tapegateway/FilesToMigrateList.hpp"
+#include "log.h"
 
 namespace{
 
@@ -103,6 +104,8 @@ namespace daemon {
  
 //------------------------------------------------------------------------------  
   void MigrationTaskInjector::WorkerThread::run(){
+    _this.m_lc.pushOrReplace(Param("thread", "MigrationTaskInjector"));
+    _this.m_lc.log(LOG_DEBUG, "Starting MigrationTaskInjector thread");
     while(1){
       Request req = _this.m_queue.pop();
       client::ClientProxy::RequestReport reqReport;
@@ -121,6 +124,7 @@ namespace daemon {
         _this.injectBulkMigrations(filesToMigrateList->filesToMigrate());
       }
     }
+    _this.m_lc.log(LOG_DEBUG, "Finishing MigrationTaskInjector thread");
   }
 
 

castor/tape/tapeserver/daemon/MountSession.cpp

@@ -53,6 +53,8 @@ void castor::tape::tapeserver::daemon::MountSession::execute()
 throw (castor::tape::Exception) {
   // 1) Prepare the logging environment
   LogContext lc(m_logger);
+  // Create a sticky thread name, which will be overridden by the other threads
+  lc.pushOrReplace(Param("thread", "mainThread"));
   LogContext::ScopedParam sp01(lc, Param("clientHost", m_request.clientHost));
   LogContext::ScopedParam sp02(lc, Param("clientPort", m_request.clientPort));
   LogContext::ScopedParam sp03(lc, Param("mountTransactionId", m_request.volReqId));

castor/tape/tapeserver/daemon/RecallReportPacker.cpp

@@ -26,6 +26,7 @@
 #include "castor/tape/tapegateway/FileRecalledNotificationStruct.hpp"
 #include "castor/tape/tapegateway/FileRecalledNotificationStruct.hpp"
 #include "castor/log/Logger.hpp"
+#include "log.h"
 
 namespace{
   struct failedReportRecallResult : public castor::tape::Exception{
@@ -94,9 +95,9 @@ void RecallReportPacker::flush(){
     client::ClientInterface::RequestReport chrono;
     try{
       m_client.reportRecallResults(*m_listReports,chrono);
-      logRequestReport(chrono,"reportRecallResults'is successful");
-      
-      logReport(m_listReports->failedRecalls(),"file failed to be recalled");
+      logRequestReport(chrono,"RecallReportList successfully transmitted to client (contents follow)");
+
+      logReport(m_listReports->failedRecalls(),"A file failed to be recalled");
       logReport(m_listReports->successfulRecalls(),"A file was successfully recalled");
     }
    catch(const castor::tape::Exception& e){
@@ -162,6 +163,8 @@ m_parent(parent) {
 }
 
 void RecallReportPacker::WorkerThread::run(){
+  m_parent.m_lc.pushOrReplace(Param("thread", "RecallReportPacker"));
+  m_parent.m_lc.log(LOG_DEBUG, "Starting RecallReportPacker thread");
   client::ClientInterface::RequestReport chrono;
   try{
       while(1) {    
@@ -196,5 +199,6 @@ void RecallReportPacker::WorkerThread::run(){
     //either from the catch a few lines above or directly from rep->execute
     m_parent.logRequestReport(chrono,"tried to report endOfSession(WithError) and got an exception, cant do much more",LOG_ERR);
   }
+  m_parent.m_lc.log(LOG_DEBUG, "Finishing RecallReportPacker thread");
 }
 }}}}

castor/tape/tapeserver/daemon/RecallTaskInjector.cpp

@@ -4,6 +4,7 @@
 #include "castor/tape/tapegateway/FilesToRecallList.hpp"
 #include "castor/tape/tapeserver/utils/suppressUnusedVariable.hpp"
 #include "castor/tape/tapegateway/FileToRecallStruct.hpp"
+#include "log.h"
 #include <stdint.h>
 
 using castor::log::LogContext;
@@ -105,6 +106,8 @@ bool RecallTaskInjector::synchronousInjection(uint64_t maxFiles, uint64_t byteSi
 void RecallTaskInjector::WorkerThread::run()
 {
   using castor::log::LogContext;
+  _this.m_lc.pushOrReplace(Param("thread", "recallTaskInjector"));
+  _this.m_lc.log(LOG_DEBUG, "Starting RecallTaskInjector thread");
   
       while (1) {
         Request req = _this.m_queue.pop();
@@ -146,6 +149,7 @@ void RecallTaskInjector::WorkerThread::run()
       } catch (castor::tape::threading::noMore) {
         _this.m_lc.log(LOG_INFO,"In RecallJobInjector::WorkerThread::run(): Drained the request queue. We're now empty. Finishing");
       }
+  _this.m_lc.log(LOG_DEBUG, "Finishing RecallTaskInjector thread");
 }
 
 } //end namespace daemon

castor/tape/tapeserver/daemon/TapeReadSingleThread.hpp

@@ -66,6 +66,7 @@ private:
   
   virtual void run() {
     // First we have to initialise the tape read session
+    m_logContext.pushOrReplace(log::Param("thread", "tapeRead"));
     std::auto_ptr<castor::tape::tapeFile::ReadSession> rs;
     try {
       rs.reset(new castor::tape::tapeFile::ReadSession(m_drive, m_vid));