diff --git a/scheduler/Scheduler.cpp b/scheduler/Scheduler.cpp index f4263436dc68613b39355e08c0e7edef12791272..035919bb29adccbb5dcfb2f7f6b4f8845439b905 100644 --- a/scheduler/Scheduler.cpp +++ b/scheduler/Scheduler.cpp @@ -349,8 +349,7 @@ common::dataStructures::DesiredDriveState Scheduler::getDesiredDriveState(const if (d.driveName == driveName) { auto schedulerDbTime = t.secs(); log::ScopedParamContainer spc(lc); - spc.add("drive", driveName) - .add("schedulerDbTime", schedulerDbTime); + spc.add("schedulerDbTime", schedulerDbTime); lc.log(log::INFO, "In Scheduler::getDesiredDriveState(): success."); return d.desiredDriveState; } @@ -361,16 +360,15 @@ common::dataStructures::DesiredDriveState Scheduler::getDesiredDriveState(const //------------------------------------------------------------------------------ // setDesiredDriveState //------------------------------------------------------------------------------ -void Scheduler::setDesiredDriveState(const common::dataStructures::SecurityIdentity &cliIdentity, const std::string &driveName, const bool up, const bool force, log::LogContext & lc) { +void Scheduler::setDesiredDriveState(const common::dataStructures::SecurityIdentity &cliIdentity, const std::string &unitName, const bool up, const bool force, log::LogContext & lc) { utils::Timer t; common::dataStructures::DesiredDriveState desiredDriveState; desiredDriveState.up = up; desiredDriveState.forceDown = force; - m_db.setDesiredDriveState(driveName, desiredDriveState); + m_db.setDesiredDriveState(unitName, desiredDriveState); auto schedulerDbTime = t.secs(); log::ScopedParamContainer spc(lc); - spc.add("drive", driveName) - .add("up", up?"up":"down") + spc.add("up", up?"up":"down") .add("force", force?"yes":"no") .add("schedulerDbTime", schedulerDbTime); lc.log(log::INFO, "In Scheduler::setDesiredDriveState(): success."); @@ -385,8 +383,7 @@ void Scheduler::reportDriveStatus(const common::dataStructures::DriveInfo& drive m_db.reportDriveStatus(driveInfo, type, status, time(NULL)); auto schedulerDbTime = t.secs(); log::ScopedParamContainer spc(lc); - spc.add("drive", driveInfo.driveName) - .add("schedulerDbTime", schedulerDbTime); + spc.add("schedulerDbTime", schedulerDbTime); lc.log(log::INFO, "In Scheduler::reportDriveStatus(): success."); } diff --git a/scheduler/Scheduler.hpp b/scheduler/Scheduler.hpp index 49a9f93ee29cce89fd462bc83feb474400cca052..ff7e17851511222f55d7447a0a5c1e7ce5f323a4 100644 --- a/scheduler/Scheduler.hpp +++ b/scheduler/Scheduler.hpp @@ -209,12 +209,12 @@ public: * object store for the requested drive status. The status is reset to down by the drives * on hardware failures. * @param cliIdentity The identity of the user requesting the drive to put up of down. - * @param driveName The drive name + * @param unitName The drive name * @param up indicates whether the drive should be put up or down. * @param force indicates whether we want to force the drive to be up. */ //TODO: replace the 2 bools with a structure. void setDesiredDriveState(const cta::common::dataStructures::SecurityIdentity &cliIdentity, - const std::string &driveName, const bool up, const bool force, log::LogContext & lc); + const std::string &unitName, const bool up, const bool force, log::LogContext & lc); /** * Reports the state of the drive to the object store. This information is then reported diff --git a/tapeserver/castor/tape/tapeserver/daemon/DataTransferSession.cpp b/tapeserver/castor/tape/tapeserver/daemon/DataTransferSession.cpp index b3b36033921823609272065ad4af8e79b672a29e..c81e4f4643a1b3d7f9bb5e8271f0651255d388e2 100644 --- a/tapeserver/castor/tape/tapeserver/daemon/DataTransferSession.cpp +++ b/tapeserver/castor/tape/tapeserver/daemon/DataTransferSession.cpp @@ -86,6 +86,7 @@ castor::tape::tapeserver::daemon::Session::EndOfSessionAction cta::log::LogContext lc(m_log); // Create a sticky thread name, which will be overridden by the other threads lc.pushOrReplace(cta::log::Param("thread", "MainThread")); + lc.pushOrReplace(cta::log::Param("unitName", m_driveConfig.unitName)); // 2a) Determine if we want to mount at all (for now) // This variable will allow us to see if we switched from down to up and start a diff --git a/tapeserver/daemon/DriveHandler.cpp b/tapeserver/daemon/DriveHandler.cpp index 9cc0de04c84d637daf9fb1630fb0c6d2ef3ebd94..b315078a4dc9a41b8de1c7fb2bc0fd7757536cda 100644 --- a/tapeserver/daemon/DriveHandler.cpp +++ b/tapeserver/daemon/DriveHandler.cpp @@ -165,7 +165,7 @@ SubprocessHandler::ProcessingStatus DriveHandler::fork() { } } catch (cta::exception::Exception & ex) { cta::log::ScopedParamContainer params(m_processManager.logContext()); - params.add("DriveUnit", m_configLine.unitName) + params.add("unitName", m_configLine.unitName) .add("Error", ex.getMessageValue()); m_processManager.logContext().log(log::ERR, "Failed to fork drive process. Initiating shutdown with SIGTERM."); // Wipe all previous states as we are shutting down @@ -231,7 +231,7 @@ void DriveHandler::kill() { // If we have a subprocess, kill it and wait for completion (if needed). We do not need to keep // track of the exit state as kill() means we will not be called anymore. log::ScopedParamContainer params(m_processManager.logContext()); - params.add("DriveUnit", m_configLine.unitName); + params.add("unitName", m_configLine.unitName); if (m_pid != -1) { params.add("SubProcessId", m_pid); // The socket pair will be reopened on the next fork. Clean it up. @@ -255,6 +255,7 @@ void DriveHandler::kill() { m_sessionEndContext.pushOrReplace({"Error_sessionKilled", "1"}); m_sessionEndContext.pushOrReplace({"killSignal", WTERMSIG(status)}); m_sessionEndContext.pushOrReplace({"status", "failure"}); + m_sessionEndContext.pushOrReplace({"unitName",m_configLine.unitName}); m_sessionEndContext.log(cta::log::INFO, "Tape session finished"); m_sessionEndContext.clear(); m_pid=-1; @@ -272,7 +273,7 @@ void DriveHandler::kill() { //------------------------------------------------------------------------------ SubprocessHandler::ProcessingStatus DriveHandler::processEvent() { log::ScopedParamContainer params(m_processManager.logContext()); - params.add("DriveUnit", m_configLine.unitName); + params.add("unitName", m_configLine.unitName); // Read from the socket pair try { serializers::WatchdogMessage message; @@ -373,7 +374,7 @@ SubprocessHandler::ProcessingStatus DriveHandler::processStartingUp(serializers: // We expect to reach this state from pending fork. This is the first signal from the new process. // Check the transition is expected. This is non-fatal as the drive session has the last word anyway. log::ScopedParamContainer params(m_processManager.logContext()); - params.add("DriveUnit", m_configLine.unitName); + params.add("unitName", m_configLine.unitName); if (m_sessionState!=SessionState::PendingFork || m_sessionType!=SessionType::Undetermined) { params.add("ExpectedState", session::toString(SessionState::PendingFork)) .add("ActualState", session::toString(m_sessionState)) @@ -402,7 +403,7 @@ SubprocessHandler::ProcessingStatus DriveHandler::processScheduling(serializers: // We are either going to schedule // Check the transition is expected. This is non-fatal as the drive session has the last word anyway. log::ScopedParamContainer params(m_processManager.logContext()); - params.add("DriveUnit", m_configLine.unitName); + params.add("unitName", m_configLine.unitName); std::set<SessionState> expectedStates = { SessionState::StartingUp, SessionState::Scheduling }; if (!expectedStates.count(m_sessionState) || m_sessionType != SessionType::Undetermined || @@ -438,7 +439,7 @@ SubprocessHandler::ProcessingStatus DriveHandler::processChecking(serializers::W // We expect to come from statup/undefined and to get into checking/cleanup // As usual, subprocess has the last word. log::ScopedParamContainer params(m_processManager.logContext()); - params.add("DriveUnit", m_configLine.unitName); + params.add("unitName", m_configLine.unitName); if (m_sessionState!=SessionState::StartingUp || m_sessionType!=SessionType::Undetermined|| (SessionType)message.sessiontype()!=SessionType::Cleanup) { params.add("PreviousState", session::toString(m_sessionState)) @@ -472,7 +473,7 @@ SubprocessHandler::ProcessingStatus DriveHandler::processMounting(serializers::W // The only transition expected is from scheduling. Several sessions types are possible // As usual, subprocess has the last word. log::ScopedParamContainer params(m_processManager.logContext()); - params.add("DriveUnit", m_configLine.unitName); + params.add("unitName", m_configLine.unitName); std::set<SessionType> expectedNewTypes= { SessionType::Archive, SessionType::Retrieve, SessionType::Label }; if (m_sessionState!=SessionState::Scheduling || m_sessionType!=SessionType::Undetermined|| @@ -510,7 +511,7 @@ SubprocessHandler::ProcessingStatus DriveHandler::processRunning(serializers::Wa // We expect the type not to change (and to be in the right range) // As usual, subprocess has the last word. log::ScopedParamContainer params(m_processManager.logContext()); - params.add("DriveUnit", m_configLine.unitName); + params.add("unitName", m_configLine.unitName); std::set<SessionState> expectedStates = { SessionState::Mounting, SessionState::Running }; std::set<SessionType> expectedTypes = { SessionType::Archive, SessionType::Retrieve, SessionType::Label }; if (!expectedStates.count(m_sessionState) || @@ -554,7 +555,7 @@ SubprocessHandler::ProcessingStatus DriveHandler::processUnmounting(serializers: // of checking in the case of the cleanup session. // As usual, subprocess has the last word. log::ScopedParamContainer params(m_processManager.logContext()); - params.add("DriveUnit", m_configLine.unitName); + params.add("unitName", m_configLine.unitName); std::set<std::tuple<SessionState, SessionType>> expectedStateTypes = { std::make_tuple( SessionState::Running, SessionType::Archive ), @@ -587,7 +588,7 @@ SubprocessHandler::ProcessingStatus DriveHandler::processDrainingToDisk(serializ // This status transition is expected from unmounting, and only for retrieve sessions. // As usual, subprocess has the last word. log::ScopedParamContainer params(m_processManager.logContext()); - params.add("DriveUnit", m_configLine.unitName); + params.add("unitName", m_configLine.unitName); if (SessionState::Unmounting != m_sessionState || SessionType::Retrieve != m_sessionType) { params.add("PreviousState", session::toString(m_sessionState)) @@ -613,7 +614,7 @@ SubprocessHandler::ProcessingStatus DriveHandler::processShutingDown(serializers // This status transition is expected from unmounting, and only for retrieve sessions. // As usual, subprocess has the last word. log::ScopedParamContainer params(m_processManager.logContext()); - params.add("DriveUnit", m_configLine.unitName); + params.add("unitName", m_configLine.unitName); std::set<SessionState> expectedStates = { SessionState::Unmounting, SessionState::DrainingToDisk }; if (!expectedStates.count(m_sessionState)) { params.add("PreviousState", session::toString(m_sessionState)) @@ -639,7 +640,7 @@ SubprocessHandler::ProcessingStatus DriveHandler::processFatal(serializers::Watc // This status indicates that the session cannot be run and the server should // shut down (central storage unavailable). log::ScopedParamContainer params(m_processManager.logContext()); - params.add("DriveUnit", m_configLine.unitName); + params.add("unitName", m_configLine.unitName); m_sessionState=(SessionState)message.sessionstate(); m_sessionType=(SessionType)message.sessiontype(); m_sessionVid=""; @@ -701,7 +702,7 @@ SubprocessHandler::ProcessingStatus DriveHandler::processSigChild() { // be picked up) and -1 if the process is entirely gone. // Of course we might not have a child process to begin with. log::ScopedParamContainer params(m_processManager.logContext()); - params.add("DriveUnit", m_configLine.unitName); + params.add("unitName", m_configLine.unitName); if (-1 == m_pid) return m_processingStatus; int processStatus; int rc=::waitpid(m_pid, &processStatus, WNOHANG); @@ -711,7 +712,7 @@ SubprocessHandler::ProcessingStatus DriveHandler::processSigChild() { } catch (exception::Exception &ex) { cta::log::ScopedParamContainer params(m_processManager.logContext()); params.add("pid", m_pid) - .add("driveUnit", m_configLine.unitName) + .add("unitName", m_configLine.unitName) .add("Message", ex.getMessageValue()) .add("SessionState", session::toString(m_sessionState)) .add("SessionType", toString(m_sessionType)); @@ -764,6 +765,7 @@ SubprocessHandler::ProcessingStatus DriveHandler::processSigChild() { m_sessionEndContext.pushOrReplace({"status", "failure"}); } // In all cases we log the end of the session. + m_sessionEndContext.pushOrReplace({"unitName",m_configLine.unitName}); m_sessionEndContext.moveToTheEndIfPresent("status"); m_sessionEndContext.log(cta::log::INFO, "Tape session finished"); m_sessionEndContext.clear(); @@ -780,7 +782,7 @@ SubprocessHandler::ProcessingStatus DriveHandler::processTimeout() { // Process manager found that we timed out. Let's log why and kill the child process, // if any (there should be one). log::ScopedParamContainer params(m_processManager.logContext()); - params.add("driveUnit", m_configLine.unitName); + params.add("unitName", m_configLine.unitName); if (-1 == m_pid) { m_processManager.logContext().log(log::ERR, "In DriveHandler::processTimeout(): Received timeout without child process present."); m_processManager.logContext().log(log::INFO, "Re-launching child process."); @@ -938,7 +940,7 @@ int DriveHandler::runChild() { // 1) Special case first, if we crashed in a cleaner session, we put the drive down if (m_previousSession == PreviousSession::Crashed && m_previousType == SessionType::Cleanup) { log::ScopedParamContainer params(lc); - params.add("driveUnit", m_configLine.unitName); + params.add("unitName", m_configLine.unitName); lc.log(log::ERR, "In DriveHandler::runChild(): the cleaner session crashed. Putting the drive down."); // Get hold of the scheduler. try { @@ -989,7 +991,7 @@ int DriveHandler::runChild() { { log::ScopedParamContainer params(lc); params.add("VID", m_previousVid) - .add("driveUnit", m_configLine.unitName) + .add("unitName", m_configLine.unitName) .add("PreviousState", session::toString(m_sessionState)) .add("PreviousType", session::toString(m_sessionType)); lc.log(log::INFO, "In DriveHandler::runChild(): starting cleaner after crash with tape potentially loaded."); @@ -1056,7 +1058,7 @@ int DriveHandler::runChild() { if (m_previousSession == PreviousSession::Initiating) { // Log that we put the drive's desired state to down and do it. log::ScopedParamContainer params(lc); - params.add("Drive", m_configLine.unitName); + params.add("unitName", m_configLine.unitName); lc.log(log::INFO, "Setting the drive down at daemon startup"); try { // Before setting the desired state as down, we have to make sure the drive exists in the registry. @@ -1100,7 +1102,7 @@ int DriveHandler::runChild() { SubprocessHandler::ProcessingStatus DriveHandler::shutdown() { // TODO: improve in the future (preempt the child process) log::ScopedParamContainer params(m_processManager.logContext()); - params.add("Drive", m_configLine.unitName); + params.add("unitName", m_configLine.unitName); m_processManager.logContext().log(log::INFO, "In DriveHandler::shutdown(): simply killing the process."); kill(); m_sessionState = SessionState::Shutdown;