Skip to content
GitLab
Commit e267869a authored by Eric Cano's avatar Eric Cano
Browse files

Fixes to statistcs printing

parent 11f96763
Hide whitespace changes
Inline Side-by-side
castor/log/LogContext.hpp
View file @ e267869a
......@@ -161,7 +161,7 @@ class ScopedParamContainer{
return *this;
}
ScopedParamContainer& addTiming(const std::string& s,double t){
ScopedParamContainer& addSnprintfDouble(const std::string& s,double t){
char buf[100];
std::snprintf(buf, sizeof(buf), "%f", t);
m_context.pushOrReplace(Param(s,buf));
......
castor/tape/tapeserver/daemon/DiskReadTask.cpp
View file @ e267869a
......@@ -163,14 +163,14 @@ void DiskReadTask::circulateAllBlocks(size_t fromBlockId, MemBlock * mb){
//------------------------------------------------------------------------------
void DiskReadTask::logWithStat(int level,const std::string& msg,log::LogContext& lc){
log::ScopedParamContainer params(lc);
params.addTiming("transferTime", m_stats.transferTime)
.addTiming("checksumingTime",m_stats.checksumingTime)
.addTiming("waitDataTime",m_stats.waitDataTime)
.addTiming("waitReportingTime",m_stats.waitReportingTime)
.addTiming("checkingErrorTime",m_stats.checkingErrorTime)
.addTiming("openingTime",m_stats.openingTime)
.addTiming("totalTime", m_stats.totalTime)
.add("filePayloadTransferSpeedMBps",
params.addSnprintfDouble("transferTime", m_stats.transferTime)
.addSnprintfDouble("checksumingTime",m_stats.checksumingTime)
.addSnprintfDouble("waitDataTime",m_stats.waitDataTime)
.addSnprintfDouble("waitReportingTime",m_stats.waitReportingTime)
.addSnprintfDouble("checkingErrorTime",m_stats.checkingErrorTime)
.addSnprintfDouble("openingTime",m_stats.openingTime)
.addSnprintfDouble("totalTime", m_stats.totalTime)
.addSnprintfDouble("filePayloadTransferSpeedMBps",
m_stats.totalTime?1.0*m_stats.dataVolume/1000/1000/m_stats.totalTime:0)
.add("FILEID",m_migratedFile->fileid())
.add("path",m_migratedFile->path());
......
castor/tape/tapeserver/daemon/DiskReadThreadPool.cpp
View file @ e267869a
......@@ -131,14 +131,14 @@ void DiskReadThreadPool::addThreadStats(const DiskStats& other){
void DiskReadThreadPool::logWithStat(int level, const std::string& message){
m_pooldStat.totalTime = m_totalTime.secs();
log::ScopedParamContainer params(m_lc);
params.addTiming("poolTransferTime", m_pooldStat.transferTime)
.addTiming("poolWaitFreeMemoryTime",m_pooldStat.waitFreeMemoryTime)
.addTiming("poolCheckingErrorTime",m_pooldStat.checkingErrorTime)
.addTiming("poolOpeningTime",m_pooldStat.openingTime)
.addTiming("poolRealTime",m_pooldStat.totalTime)
params.addSnprintfDouble("poolTransferTime", m_pooldStat.transferTime)
.addSnprintfDouble("poolWaitFreeMemoryTime",m_pooldStat.waitFreeMemoryTime)
.addSnprintfDouble("poolCheckingErrorTime",m_pooldStat.checkingErrorTime)
.addSnprintfDouble("poolOpeningTime",m_pooldStat.openingTime)
.addSnprintfDouble("poolRealTime",m_pooldStat.totalTime)
.add("poolFileCount",m_pooldStat.filesCount)
.add("poolDataVolumeInMB", 1.0*m_pooldStat.dataVolume/1000/1000)
.add("AveragePoolPayloadTransferSpeedMBps",
.add("poolDataVolume", m_pooldStat.dataVolume)
.addSnprintfDouble("AveragePoolPayloadTransferSpeedMBps",
m_pooldStat.totalTime?1.0*m_pooldStat.dataVolume/1000/1000/m_pooldStat.totalTime:0);
m_lc.log(level,message);
}
......@@ -189,15 +189,15 @@ void DiskReadThreadPool::DiskReadWorkerThread::run() {
void DiskReadThreadPool::DiskReadWorkerThread::
logWithStat(int level, const std::string& message){
log::ScopedParamContainer params(m_lc);
params.addTiming("threadTransferTime", m_threadStat.transferTime)
.addTiming("threadWaitFreeMemoryTime",m_threadStat.waitFreeMemoryTime)
.addTiming("threadCheckingErrorTime",m_threadStat.checkingErrorTime)
.addTiming("threadOpeningTime",m_threadStat.openingTime)
.addTiming("threadTotalTime",m_threadStat.totalTime)
.add("threaDataVolumeInMB", 1.0*m_threadStat.dataVolume/1000/1000)
.add("threadPayloadTransferSpeedMBps",
params.addSnprintfDouble("threadTransferTime", m_threadStat.transferTime)
.addSnprintfDouble("threadWaitFreeMemoryTime",m_threadStat.waitFreeMemoryTime)
.addSnprintfDouble("threadCheckingErrorTime",m_threadStat.checkingErrorTime)
.addSnprintfDouble("threadOpeningTime",m_threadStat.openingTime)
.addSnprintfDouble("threadTotalTime",m_threadStat.totalTime)
.addSnprintfDouble("threaDataVolumeInMB", 1.0*m_threadStat.dataVolume/1000/1000)
.addSnprintfDouble("threadPayloadTransferSpeedMBps",
m_threadStat.totalTime?1.0*m_threadStat.dataVolume/1000/1000/m_threadStat.totalTime:0)
.addTiming("totalTime",m_threadStat.totalTime);
.addSnprintfDouble("totalTime",m_threadStat.totalTime);
m_lc.log(level,message);
}
}}}}
......
castor/tape/tapeserver/daemon/DiskWriteTask.cpp
View file @ e267869a
......@@ -206,15 +206,15 @@ const DiskStats DiskWriteTask::getTaskStats() const{
//------------------------------------------------------------------------------
void DiskWriteTask::logWithStat(int level,const std::string& msg,log::LogContext& lc){
log::ScopedParamContainer params(lc);
params.addTiming("transferTime", m_stats.transferTime)
.addTiming("checksumingTime",m_stats.checksumingTime)
.addTiming("waitDataTime",m_stats.waitDataTime)
.addTiming("waitReportingTime",m_stats.waitReportingTime)
.addTiming("checkingErrorTime",m_stats.checkingErrorTime)
.addTiming("openingTime",m_stats.openingTime)
.addTiming("closingTime",m_stats.closingTime)
.addTiming("totalTime", m_stats.totalTime)
.add("filePayloadTransferSpeedMBps",
params.addSnprintfDouble("transferTime", m_stats.transferTime)
.addSnprintfDouble("checksumingTime",m_stats.checksumingTime)
.addSnprintfDouble("waitDataTime",m_stats.waitDataTime)
.addSnprintfDouble("waitReportingTime",m_stats.waitReportingTime)
.addSnprintfDouble("checkingErrorTime",m_stats.checkingErrorTime)
.addSnprintfDouble("openingTime",m_stats.openingTime)
.addSnprintfDouble("closingTime",m_stats.closingTime)
.addSnprintfDouble("totalTime", m_stats.totalTime)
.addSnprintfDouble("filePayloadTransferSpeedMBps",
m_stats.totalTime?1.0*m_stats.dataVolume/1000/1000/m_stats.totalTime:0)
.add("FILEID",m_recallingFile->fileid())
.add("path",m_recallingFile->path());
......
castor/tape/tapeserver/daemon/DiskWriteThreadPool.cpp
View file @ e267869a
......@@ -123,18 +123,18 @@ void DiskWriteThreadPool::addThreadStats(const DiskStats& other){
void DiskWriteThreadPool::logWithStat(int level, const std::string& message){
m_pooldStat.totalTime = m_totalTime.secs();
log::ScopedParamContainer params(m_lc);
params.addTiming("poolTransferTime", m_pooldStat.transferTime)
.addTiming("poolChecksumingTime",m_pooldStat.checksumingTime)
.addTiming("poolWaitDataTime",m_pooldStat.waitDataTime)
.addTiming("poolWaitReportingTime",m_pooldStat.waitReportingTime)
.addTiming("poolCheckingErrorTime",m_pooldStat.checkingErrorTime)
.addTiming("poolOpeningTime",m_pooldStat.openingTime)
.addTiming("poolClosingTime", m_pooldStat.closingTime)
.addTiming("poolRealTime",m_pooldStat.totalTime)
params.addSnprintfDouble("poolTransferTime", m_pooldStat.transferTime)
.addSnprintfDouble("poolChecksumingTime",m_pooldStat.checksumingTime)
.addSnprintfDouble("poolWaitDataTime",m_pooldStat.waitDataTime)
.addSnprintfDouble("poolWaitReportingTime",m_pooldStat.waitReportingTime)
.addSnprintfDouble("poolCheckingErrorTime",m_pooldStat.checkingErrorTime)
.addSnprintfDouble("poolOpeningTime",m_pooldStat.openingTime)
.addSnprintfDouble("poolClosingTime", m_pooldStat.closingTime)
.addSnprintfDouble("poolRealTime",m_pooldStat.totalTime)
.add("poolFileCount",m_pooldStat.filesCount)
.add("poolDataVolumeInMB", 1.0*m_pooldStat.dataVolume/1024/1024)
.add("AveragePoolPayloadTransferSpeedMBps",
m_pooldStat.totalTime?1.0*m_pooldStat.dataVolume/1000/1000/m_pooldStat.transferTime:0);
.add("poolDataVolume", m_pooldStat.dataVolume)
.addSnprintfDouble("AveragePoolPayloadTransferSpeedMBps",
m_pooldStat.totalTime?1.0*m_pooldStat.dataVolume/1000/1000/m_pooldStat.totalTime:0);
m_lc.log(level,message);
}
//------------------------------------------------------------------------------
......@@ -192,14 +192,14 @@ void DiskWriteThreadPool::DiskWriteWorkerThread::run() {
void DiskWriteThreadPool::DiskWriteWorkerThread::
logWithStat(int level, const std::string& msg) {
log::ScopedParamContainer params(m_lc);
params.addTiming("threadTransferTime", m_threadStat.transferTime)
.addTiming("threadChecksumingTime",m_threadStat.checksumingTime)
.addTiming("threadWaitDataTime",m_threadStat.waitDataTime)
.addTiming("threadWaitReportingTime",m_threadStat.waitReportingTime)
.addTiming("threadCheckingErrorTime",m_threadStat.checkingErrorTime)
.addTiming("threadOpeningTime",m_threadStat.openingTime)
.addTiming("threadClosingTime", m_threadStat.closingTime)
.addTiming("threadTotalTime",m_threadStat.totalTime)
params.addSnprintfDouble("threadTransferTime", m_threadStat.transferTime)
.addSnprintfDouble("threadChecksumingTime",m_threadStat.checksumingTime)
.addSnprintfDouble("threadWaitDataTime",m_threadStat.waitDataTime)
.addSnprintfDouble("threadWaitReportingTime",m_threadStat.waitReportingTime)
.addSnprintfDouble("threadCheckingErrorTime",m_threadStat.checkingErrorTime)
.addSnprintfDouble("threadOpeningTime",m_threadStat.openingTime)
.addSnprintfDouble("threadClosingTime", m_threadStat.closingTime)
.addSnprintfDouble("threadTotalTime",m_threadStat.totalTime)
.add("threaDataVolumeInMB", 1.0*m_threadStat.dataVolume/1000/1000)
.add("threadFileCount",m_threadStat.filesCount)
.add("threadPayloadTransferSpeedMBps",
......
castor/tape/tapeserver/daemon/TapeReadSingleThread.cpp
View file @ e267869a
......@@ -148,7 +148,7 @@ void castor::tape::tapeserver::daemon::TapeReadSingleThread::run() {
m_stats.mountTime += timer.secs(castor::utils::Timer::resetCounter);
{
castor::log::ScopedParamContainer scoped(m_logContext);
scoped.addTiming("mountTime", m_stats.mountTime);
scoped.addSnprintfDouble("mountTime", m_stats.mountTime);
m_logContext.log(LOG_INFO, "Tape mounted and drive ready");
}
// Then we have to initialise the tape read session
......@@ -157,7 +157,7 @@ void castor::tape::tapeserver::daemon::TapeReadSingleThread::run() {
//and then report
{
castor::log::ScopedParamContainer scoped(m_logContext);
scoped.addTiming("positionTime", m_stats.positionTime);
scoped.addSnprintfDouble("positionTime", m_stats.positionTime);
m_logContext.log(LOG_INFO, "Tape read session session successfully started");
}
m_initialProcess.tapeMountedForRead();
......@@ -221,16 +221,15 @@ void castor::tape::tapeserver::daemon::TapeReadSingleThread::logWithStat(
int level, const std::string& msg, log::ScopedParamContainer& params) {
params.add("type", "read")
.add("VID", m_volInfo.vid)
.addTiming("mountTime", m_stats.mountTime)
.addTiming("positionTime", m_stats.positionTime)
.addTiming("waitInstructionsTime", m_stats.waitInstructionsTime)
.addTiming("checksumingTime", m_stats.checksumingTime)
.addTiming("transferTime", m_stats.transferTime)
.addTiming("waitFreeMemoryTime", m_stats.waitFreeMemoryTime)
.addTiming("waitReportingTime", m_stats.waitReportingTime)
.addTiming("unloadTime", m_stats.unloadTime)
.addTiming("unmountTime", m_stats.unmountTime)
.addTiming("totalTime", m_stats.totalTime)
.addSnprintfDouble("mountTime", m_stats.mountTime)
.addSnprintfDouble("positionTime", m_stats.positionTime)
.addSnprintfDouble("waitInstructionsTime", m_stats.waitInstructionsTime)
.addSnprintfDouble("transferTime", m_stats.transferTime)
.addSnprintfDouble("waitFreeMemoryTime", m_stats.waitFreeMemoryTime)
.addSnprintfDouble("waitReportingTime", m_stats.waitReportingTime)
.addSnprintfDouble("unloadTime", m_stats.unloadTime)
.addSnprintfDouble("unmountTime", m_stats.unmountTime)
.addSnprintfDouble("totalTime", m_stats.totalTime)
.add("dataVolume", m_stats.dataVolume)
.add("headerVolume", m_stats.headerVolume)
.add("files", m_stats.filesCount)
......
castor/tape/tapeserver/daemon/TapeReadTask.hpp
View file @ e267869a
......@@ -135,11 +135,11 @@ public:
// Hardcoded header size for lack of a better mechanism
// Head + trailer, 3 * 80 bytes each
localStats.headerVolume = (2 * 3 * 80);
params.addTiming("positionTime", localStats.positionTime)
.addTiming("transferTime", localStats.transferTime)
.addTiming("waitFreeMemoryTime",localStats.waitFreeMemoryTime)
.addTiming("waitReportingTime",localStats.waitReportingTime)
.addTiming("totalTime", localStats.totalTime)
params.addSnprintfDouble("positionTime", localStats.positionTime)
.addSnprintfDouble("transferTime", localStats.transferTime)
.addSnprintfDouble("waitFreeMemoryTime",localStats.waitFreeMemoryTime)
.addSnprintfDouble("waitReportingTime",localStats.waitReportingTime)
.addSnprintfDouble("totalTime", localStats.totalTime)
.add("dataVolume",localStats.dataVolume)
.add("driveTransferSpeedMBps",
localStats.totalTime?(1.0*localStats.dataVolume+1.0*localStats.headerVolume)
......
castor/tape/tapeserver/daemon/TapeSingleThreadInterface.hpp
View file @ e267869a
......@@ -118,7 +118,7 @@ protected:
castor::utils::Timer timer;
m_mc.mountTapeReadOnly(m_volInfo.vid, m_drive.librarySlot.str());
const std::string modeAsString = "R";
scoped.addTiming("MCMountTime",timer.secs()).add("mode",modeAsString);
scoped.addSnprintfDouble("MCMountTime",timer.secs()).add("mode",modeAsString);
if(mediachanger::TAPE_LIBRARY_TYPE_MANUAL !=
m_drive.librarySlot.getLibraryType()) {
m_logContext.log(LOG_INFO, "Tape mounted for read-only access");
......@@ -144,7 +144,7 @@ protected:
castor::utils::Timer timer;
m_mc.mountTapeReadWrite(m_volInfo.vid, m_drive.librarySlot.str());
const std::string modeAsString = "RW";
scoped.addTiming("MCMountTime",timer.secs()).add("mode",modeAsString);
scoped.addSnprintfDouble("MCMountTime",timer.secs()).add("mode",modeAsString);
m_logContext.log(LOG_INFO, "Tape mounted for read/write access");
}
catch (castor::exception::Exception & ex) {
......
castor/tape/tapeserver/daemon/TapeWriteSingleThread.cpp
View file @ e267869a
......@@ -94,7 +94,7 @@ tapeFlush(const std::string& message,uint64_t bytes,uint64_t files,
log::ScopedParamContainer params(m_logContext);
params.add("files", files)
.add("bytes", bytes)
.addTiming("flushTime", flushTime);
.addSnprintfDouble("flushTime", flushTime);
m_logContext.log(LOG_INFO,message);
m_stats.flushTime += flushTime;
......@@ -148,7 +148,7 @@ void castor::tape::tapeserver::daemon::TapeWriteSingleThread::run() {
m_stats.mountTime += timer.secs(castor::utils::Timer::resetCounter);
{
castor::log::ScopedParamContainer scoped(m_logContext);
scoped.addTiming("mountTime", m_stats.mountTime);
scoped.addSnprintfDouble("mountTime", m_stats.mountTime);
m_logContext.log(LOG_INFO, "Tape mounted and drive ready");
}
......@@ -157,7 +157,7 @@ void castor::tape::tapeserver::daemon::TapeWriteSingleThread::run() {
m_stats.positionTime += timer.secs(castor::utils::Timer::resetCounter);
{
castor::log::ScopedParamContainer scoped(m_logContext);
scoped.addTiming("positionTime", m_stats.positionTime);
scoped.addSnprintfDouble("positionTime", m_stats.positionTime);
m_logContext.log(LOG_INFO, "Write session initialised, tape VID checked and drive positioned for writing");
}
......@@ -255,17 +255,17 @@ void castor::tape::tapeserver::daemon::TapeWriteSingleThread::logWithStats(
int level,const std::string& msg, log::ScopedParamContainer& params){
params.add("type", "write")
.add("VID", m_volInfo.vid)
.addTiming("mountTime", m_stats.mountTime)
.addTiming("positionTime", m_stats.positionTime)
.addTiming("waitInstructionsTime", m_stats.waitInstructionsTime)
.addTiming("checksumingTime", m_stats.checksumingTime)
.addTiming("transferTime", m_stats.transferTime)
.addTiming("waitDataTime", m_stats.waitDataTime)
.addTiming("waitReportingTime", m_stats.waitReportingTime)
.addTiming("flushTime", m_stats.flushTime)
.addTiming("unloadTime", m_stats.unloadTime)
.addTiming("unmountTime", m_stats.unmountTime)
.addTiming("totalTime", m_stats.totalTime)
.addSnprintfDouble("mountTime", m_stats.mountTime)
.addSnprintfDouble("positionTime", m_stats.positionTime)
.addSnprintfDouble("waitInstructionsTime", m_stats.waitInstructionsTime)
.addSnprintfDouble("checksumingTime", m_stats.checksumingTime)
.addSnprintfDouble("transferTime", m_stats.transferTime)
.addSnprintfDouble("waitDataTime", m_stats.waitDataTime)
.addSnprintfDouble("waitReportingTime", m_stats.waitReportingTime)
.addSnprintfDouble("flushTime", m_stats.flushTime)
.addSnprintfDouble("unloadTime", m_stats.unloadTime)
.addSnprintfDouble("unmountTime", m_stats.unmountTime)
.addSnprintfDouble("totalTime", m_stats.totalTime)
.add("dataVolume", m_stats.dataVolume)
.add("headerVolume", m_stats.headerVolume)
.add("files", m_stats.filesCount)
......
castor/tape/tapeserver/daemon/TapeWriteTask.cpp
View file @ e267869a
......@@ -262,11 +262,11 @@ namespace daemon {
void TapeWriteTask::logWithStats(int level, const std::string& msg,
log::LogContext& lc) const{
log::ScopedParamContainer params(lc);
params.addTiming("transferTime", m_taskStats.transferTime)
.addTiming("checksumingTime",m_taskStats.checksumingTime)
.addTiming("waitDataTime",m_taskStats.waitDataTime)
.addTiming("waitReportingTime",m_taskStats.waitReportingTime)
.addTiming("totalTime", m_taskStats.totalTime)
params.addSnprintfDouble("transferTime", m_taskStats.transferTime)
.addSnprintfDouble("checksumingTime",m_taskStats.checksumingTime)
.addSnprintfDouble("waitDataTime",m_taskStats.waitDataTime)
.addSnprintfDouble("waitReportingTime",m_taskStats.waitReportingTime)
.addSnprintfDouble("totalTime", m_taskStats.totalTime)
.add("dataVolume",m_taskStats.dataVolume)
.add("headerVolume",m_taskStats.headerVolume)
.add("driveTransferSpeedMBps",m_taskStats.totalTime?
......
castor/tape/tapeserver/daemon/TaskWatchDog.hpp
View file @ e267869a
......@@ -260,7 +260,7 @@ private:
virtual void logStuckFile() {
castor::log::ScopedParamContainer params(m_lc);
params.addTiming("TimeSinceLastBlockMove", m_blockMovementTimer.usecs())
params.addSnprintfDouble("TimeSinceLastBlockMove", m_blockMovementTimer.usecs())
.add("Path",m_file.path())
.add("FILEID",m_file.fileid())
.add("fSeq",m_file.fseq());
......
Supports Markdown
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment

imprint | privacy | Conditions of Use