Commit eab120f5 authored by Eric Cano's avatar Eric Cano
Browse files

Changed printout of timings so that they appear in decimal notation without exponent.

Also removed slashes from parameter names.
parent 2f905c4b
......@@ -24,6 +24,7 @@
#pragma once
#include <ostream>
#include <cstdio>
#include "castor/log/Logger.hpp"
namespace castor {
......@@ -159,6 +160,14 @@ class ScopedParamContainer{
m_names.push_back(s);
return *this;
}
ScopedParamContainer& addTiming(const std::string& s,double t){
char buf[100];
std::snprintf(buf, sizeof(buf), "%f", t);
m_context.pushOrReplace(Param(s,buf));
m_names.push_back(s);
return *this;
}
private:
LogContext & m_context;
......
......@@ -157,12 +157,12 @@ 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.add("transferTime", m_stats.transferTime)
.add("checksumingTime",m_stats.checksumingTime)
.add("waitDataTime",m_stats.waitDataTime)
.add("waitReportingTime",m_stats.waitReportingTime)
.add("checkingErrorTime",m_stats.checkingErrorTime)
.add("openingTime",m_stats.openingTime)
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)
.add("payloadTransferSpeedMB/s",
1.0*m_stats.dataVolume/1024/1024/m_stats.transferTime)
.add("FILEID",m_migratedFile->fileid())
......
......@@ -125,10 +125,10 @@ void DiskReadThreadPool::addThreadStats(const DiskStats& other){
//------------------------------------------------------------------------------
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)
params.addTiming("poolTransferTime", m_pooldStat.transferTime)
.addTiming("poolWaitFreeMemoryTime",m_pooldStat.waitFreeMemoryTime)
.addTiming("poolCheckingErrorTime",m_pooldStat.checkingErrorTime)
.addTiming("poolOpeningTime",m_pooldStat.openingTime)
.add("poolFileCount",m_pooldStat.filesCount)
.add("poolDataVolumeInMB", 1.0*m_pooldStat.dataVolume/1024/1024)
.add("Average_Pool_PayloadTransferSpeedMB/s",
......@@ -174,10 +174,10 @@ void DiskReadThreadPool::DiskReadWorkerThread::run() {
void DiskReadThreadPool::DiskReadWorkerThread::
logWithStat(int level, const std::string& message){
log::ScopedParamContainer params(m_lc);
params.add("threadTransferTime", m_threadStat.transferTime)
.add("threadWaitFreeMemoryTime",m_threadStat.waitFreeMemoryTime)
.add("threadCheckingErrorTime",m_threadStat.checkingErrorTime)
.add("threadOpeningTime",m_threadStat.openingTime)
params.addTiming("threadTransferTime", m_threadStat.transferTime)
.addTiming("threadWaitFreeMemoryTime",m_threadStat.waitFreeMemoryTime)
.addTiming("threadCheckingErrorTime",m_threadStat.checkingErrorTime)
.addTiming("threadOpeningTime",m_threadStat.openingTime)
.add("threaDataVolumeInMB", 1.0*m_threadStat.dataVolume/1024/1024)
.add("threadPayloadTransferSpeedMB/s",
1.0*m_threadStat.dataVolume/1024/1024/m_threadStat.transferTime);
......
......@@ -192,13 +192,13 @@ const DiskStats DiskWriteTask::getTaskStats() const{
//------------------------------------------------------------------------------
void DiskWriteTask::logWithStat(int level,const std::string& msg,log::LogContext& lc){
log::ScopedParamContainer params(lc);
params.add("transferTime", m_stats.transferTime)
.add("checksumingTime",m_stats.checksumingTime)
.add("waitDataTime",m_stats.waitDataTime)
.add("waitReportingTime",m_stats.waitReportingTime)
.add("checkingErrorTime",m_stats.checkingErrorTime)
.add("openingTime",m_stats.openingTime)
.add("closingTime",m_stats.closingTime)
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)
.add("payloadTransferSpeedMB/s",
1.0*m_stats.dataVolume/1024/1024/m_stats.transferTime)
.add("FILEID",m_recallingFile->fileid())
......
......@@ -115,14 +115,14 @@ void DiskWriteThreadPool::addThreadStats(const DiskStats& other){
//------------------------------------------------------------------------------
void DiskWriteThreadPool::logWithStat(int level, const std::string& message){
log::ScopedParamContainer params(m_lc);
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)
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)
.add("poolFileCount",m_pooldStat.filesCount)
.add("poolClosingTime", m_pooldStat.closingTime)
.addTiming("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);
......@@ -180,14 +180,14 @@ void DiskWriteThreadPool::DiskWriteWorkerThread::run() {
void DiskWriteThreadPool::DiskWriteWorkerThread::
logWithStat(int level, const std::string& msg) {
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)
params.addTiming("threadTransferTime", m_threadStat.transferTime)
.addTiming("threadChecksumingTime",m_threadStat.checksumingTime)
.addTiming("threadWaitDataTime",m_threadStat.waitDataTime)
.addTiming("threadWaitReportingTime",m_threadStat.waitReportingTime)
.add("threadFileCount",m_threadStat.filesCount)
.add("threadCheckingErrorTime",m_threadStat.checkingErrorTime)
.add("threadOpeningTime",m_threadStat.openingTime)
.add("threadClosingTime", m_threadStat.closingTime)
.addTiming("threadCheckingErrorTime",m_threadStat.checkingErrorTime)
.addTiming("threadOpeningTime",m_threadStat.openingTime)
.addTiming("threadClosingTime", m_threadStat.closingTime)
.add("threaDataVolumeInMB", 1.0*m_threadStat.dataVolume/1024/1024)
.add("threadPayloadTransferSpeedMB/s",
1.0*m_threadStat.dataVolume/1024/1024/m_threadStat.transferTime);
......
......@@ -148,7 +148,7 @@ void castor::tape::tapeserver::daemon::TapeReadSingleThread::run() {
m_stats.mountTime += timer.secs(utils::Timer::resetCounter);
{
castor::log::ScopedParamContainer scoped(m_logContext);
scoped.add("mountTime", m_stats.mountTime);
scoped.addTiming("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.add("positionTime", m_stats.positionTime);
scoped.addTiming("positionTime", m_stats.positionTime);
m_logContext.log(LOG_INFO, "Tape read session session successfully started");
}
m_initialProcess.tapeMountedForRead();
......@@ -220,22 +220,22 @@ void castor::tape::tapeserver::daemon::TapeReadSingleThread::logWithStat(
double sessionTime) {
params.add("type", "read")
.add("VID", m_volInfo.vid)
.add("mountTime", m_stats.mountTime)
.add("positionTime", m_stats.positionTime)
.add("waitInstructionsTime", m_stats.waitInstructionsTime)
.add("checksumingTime", m_stats.checksumingTime)
.add("transferTime", m_stats.transferTime)
.add("waitFreeMemoryTime", m_stats.waitFreeMemoryTime)
.add("waitReportingTime", m_stats.waitReportingTime)
.add("unloadTime", m_stats.unloadTime)
.add("unmountTime", m_stats.unmountTime)
.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)
.add("dataVolume", m_stats.dataVolume)
.add("headerVolume", m_stats.headerVolume)
.add("files", m_stats.filesCount)
.add("dataBandwidthMB/s", 1.0*m_stats.dataVolume
.add("dataBandwidthMBps", 1.0*m_stats.dataVolume
/1000/1000/sessionTime)
.add("driveBandwidthMB/s", 1.0*(m_stats.dataVolume+m_stats.headerVolume)
.add("driveBandwidthMBps", 1.0*(m_stats.dataVolume+m_stats.headerVolume)
/1000/1000/sessionTime)
.add("sessionTime", sessionTime);
.addTiming("sessionTime", sessionTime);
m_logContext.log(level,msg);
}
......@@ -127,12 +127,12 @@ public:
// Log the successful transfer
double fileTime = localTime.secs();
log::ScopedParamContainer params(lc);
params.add("positionTime", localStats.positionTime)
.add("transferTime", localStats.transferTime)
.add("waitFreeMemoryTime",localStats.waitFreeMemoryTime)
.add("waitReportingTime",localStats.waitReportingTime)
params.addTiming("positionTime", localStats.positionTime)
.addTiming("transferTime", localStats.transferTime)
.addTiming("waitFreeMemoryTime",localStats.waitFreeMemoryTime)
.addTiming("waitReportingTime",localStats.waitReportingTime)
.add("dataVolume",localStats.dataVolume)
.add("totalTime", fileTime)
.addTiming("totalTime", fileTime)
.add("driveTransferSpeedMiB/s",
(localStats.dataVolume+localStats.headerVolume)
/1024/1024
......
......@@ -120,7 +120,7 @@ protected:
m_rmc.mountTape(m_volInfo.vid, m_drive.librarySlot,
mode);
const std::string modeAsString = std::string("R")+ ((mode==legacymsg::RmcProxy::MOUNT_MODE_READWRITE) ? "W" : "");
scoped.add("RMCMountTime",timer.secs()).add("mode",modeAsString);
scoped.addTiming("RMCMountTime",timer.secs()).add("mode",modeAsString);
m_logContext.log(LOG_INFO, "Tape Mounted");
}
......
......@@ -91,7 +91,7 @@ tapeFlush(const std::string& message,uint64_t bytes,uint64_t files,
log::ScopedParamContainer params(m_logContext);
params.add("files", files)
.add("bytes", bytes)
.add("flushTime", flushTime);
.addTiming("flushTime", flushTime);
m_logContext.log(LOG_INFO,message);
m_stats.flushTime += flushTime;
......@@ -145,7 +145,7 @@ void castor::tape::tapeserver::daemon::TapeWriteSingleThread::run() {
m_stats.mountTime += timer.secs(utils::Timer::resetCounter);
{
castor::log::ScopedParamContainer scoped(m_logContext);
scoped.add("mountTime", m_stats.mountTime);
scoped.addTiming("mountTime", m_stats.mountTime);
m_logContext.log(LOG_INFO, "Tape mounted and drive ready");
}
......@@ -154,7 +154,7 @@ void castor::tape::tapeserver::daemon::TapeWriteSingleThread::run() {
m_stats.positionTime += timer.secs(utils::Timer::resetCounter);
{
castor::log::ScopedParamContainer scoped(m_logContext);
scoped.add("positionTime", m_stats.positionTime);
scoped.addTiming("positionTime", m_stats.positionTime);
m_logContext.log(LOG_INFO, "Write session initialised, tape VID checked and drive positioned for writing");
}
......@@ -230,23 +230,23 @@ int level,const std::string& msg, log::ScopedParamContainer& params,
double sessionTime){
params.add("type", "write")
.add("VID", m_volInfo.vid)
.add("mountTime", m_stats.mountTime)
.add("positionTime", m_stats.positionTime)
.add("waitInstructionsTime", m_stats.waitInstructionsTime)
.add("checksumingTime", m_stats.checksumingTime)
.add("transferTime", m_stats.transferTime)
.add("waitDataTime", m_stats.waitDataTime)
.add("waitReportingTime", m_stats.waitReportingTime)
.add("flushTime", m_stats.flushTime)
.add("unloadTime", m_stats.unloadTime)
.add("unmountTime", m_stats.unmountTime)
.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)
.add("dataVolume", m_stats.dataVolume)
.add("headerVolume", m_stats.headerVolume)
.add("files", m_stats.filesCount)
.add("dataBandwidthMB/s", 1.0*m_stats.dataVolume
.add("dataBandwidthMBps", 1.0*m_stats.dataVolume
/1000/1000/sessionTime)
.add("driveBandwidthMB/s", 1.0*(m_stats.dataVolume+m_stats.headerVolume)
.add("driveBandwidthMBps", 1.0*(m_stats.dataVolume+m_stats.headerVolume)
/1000/1000/sessionTime)
.add("sessionTime", sessionTime);
.addTiming("sessionTime", sessionTime);
m_logContext.log(level, msg);
}
......@@ -235,13 +235,13 @@ namespace daemon {
void TapeWriteTask::logWithStats(int level, const std::string& msg,
double fileTime,log::LogContext& lc) const{
log::ScopedParamContainer params(lc);
params.add("transferTime", m_taskStats.transferTime)
.add("checksumingTime",m_taskStats.checksumingTime)
.add("waitDataTime",m_taskStats.waitDataTime)
.add("waitReportingTime",m_taskStats.waitReportingTime)
params.addTiming("transferTime", m_taskStats.transferTime)
.addTiming("checksumingTime",m_taskStats.checksumingTime)
.addTiming("waitDataTime",m_taskStats.waitDataTime)
.addTiming("waitReportingTime",m_taskStats.waitReportingTime)
.add("dataVolume",m_taskStats.dataVolume)
.add("headerVolume",m_taskStats.headerVolume)
.add("totalTime", fileTime)
.addTiming("totalTime", fileTime)
.add("driveTransferSpeedMiB/s",
(m_taskStats.dataVolume+m_taskStats.headerVolume)
/1024/1024
......
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