Skip to content
Snippets Groups Projects
Commit 3e8f43a0 authored by Jan David Mol's avatar Jan David Mol
Browse files

bug 1362: reduce logging in production, switchable through commandOLAP

parent 8c3c9eb7
No related branches found
No related tags found
No related merge requests found
...@@ -471,7 +471,7 @@ static void *pollThread(void *) ...@@ -471,7 +471,7 @@ static void *pollThread(void *)
} }
if (useInterrupts) { if (useInterrupts) {
LOG_INFO_STR( "FCNP: Received " << nrInterrupts << " vc0 interrupts" ); LOG_DEBUG_STR( "FCNP: Received " << nrInterrupts << " vc0 interrupts" );
stopped = true; stopped = true;
} }
...@@ -602,7 +602,7 @@ static void drainFIFO() ...@@ -602,7 +602,7 @@ static void drainFIFO()
} }
if (quadsToRead > 0) if (quadsToRead > 0)
LOG_INFO_STR( "FCNP: Dropped " << quadsToRead << " lingering quadwords from packets of a previous job" ); LOG_DEBUG_STR( "FCNP: Dropped " << quadsToRead << " lingering quadwords from packets of a previous job" );
while (-- quadsToRead >= 0) while (-- quadsToRead >= 0)
_bgp_QuadLoad(vc0 + _BGP_TRx_Sx, 0); _bgp_QuadLoad(vc0 + _BGP_TRx_Sx, 0);
...@@ -629,7 +629,7 @@ static void drainFIFO() ...@@ -629,7 +629,7 @@ static void drainFIFO()
} }
if (dropped > 0) if (dropped > 0)
LOG_INFO_STR( "FCNP: Dropped " << dropped << " lingering packets from previous job" ); LOG_DEBUG_STR( "FCNP: Dropped " << dropped << " lingering packets from previous job" );
} }
......
...@@ -65,6 +65,12 @@ static void handleCommand(const std::string &command) ...@@ -65,6 +65,12 @@ static void handleCommand(const std::string &command)
} }
} else if (command == "quit") { } else if (command == "quit") {
quit = true; quit = true;
#if defined HAVE_BGP
} else if (command == "debug") {
LOGCOUT_SETLEVEL(8);
} else if (command == "nodebug") {
LOGCOUT_SETLEVEL(4);
#endif
} else if (command == "") { } else if (command == "") {
// quietly drop empty commands // quietly drop empty commands
} else if (myPsetNumber == 0) { } else if (myPsetNumber == 0) {
...@@ -82,12 +88,14 @@ static void commandMaster() ...@@ -82,12 +88,14 @@ static void commandMaster()
SocketStream sk("0.0.0.0", 4000, SocketStream::TCP, SocketStream::Server); SocketStream sk("0.0.0.0", 4000, SocketStream::TCP, SocketStream::Server);
LOG_INFO( "Command server ready" );
while (!quit) { while (!quit) {
std::string command; std::string command;
try { try {
command = sk.readLine(); command = sk.readLine();
LOG_DEBUG_STR("read command: " << command); LOG_INFO_STR("read command: " << command);
} catch (Stream::EndOfStreamException &) { } catch (Stream::EndOfStreamException &) {
sk.reaccept(); sk.reaccept();
continue; continue;
......
...@@ -439,6 +439,13 @@ int main(int argc, char **argv) ...@@ -439,6 +439,13 @@ int main(int argc, char **argv)
#if defined HAVE_BGP #if defined HAVE_BGP
INIT_LOGGER_WITH_SYSINFO(str(format("IONProc@%02d") % myPsetNumber)); INIT_LOGGER_WITH_SYSINFO(str(format("IONProc@%02d") % myPsetNumber));
bool isProduction = argc > 1 && argv[1][0] == '1';
if (isProduction) {
LOGCOUT_SETLEVEL(4); // do not show debug info
} else {
LOGCOUT_SETLEVEL(8); // show debug info
}
#elif defined HAVE_LOG4CPLUS #elif defined HAVE_LOG4CPLUS
// do nothing // do nothing
#elif defined HAVE_LOG4CXX #elif defined HAVE_LOG4CXX
......
...@@ -42,6 +42,8 @@ ...@@ -42,6 +42,8 @@
#include <boost/format.hpp> #include <boost/format.hpp>
using boost::format; using boost::format;
#define LOG_CONDITION (myPsetNumber == 0)
namespace LOFAR { namespace LOFAR {
namespace RTCP { namespace RTCP {
...@@ -63,11 +65,13 @@ Job::Job(const char *parsetName) ...@@ -63,11 +65,13 @@ Job::Job(const char *parsetName)
checkParset(); checkParset();
LOG_INFO_STR(itsLogPrefix << "----- Creating new observation");
LOG_DEBUG_STR(itsLogPrefix << "usedCoresInPset = " << itsParset.usedCoresInPset());
itsNrRuns = static_cast<unsigned>(ceil((itsParset.stopTime() - itsParset.startTime()) / itsParset.CNintegrationTime())); itsNrRuns = static_cast<unsigned>(ceil((itsParset.stopTime() - itsParset.startTime()) / itsParset.CNintegrationTime()));
if (LOG_CONDITION) {
LOG_INFO_STR(itsLogPrefix << "----- Creating new job");
LOG_DEBUG_STR(itsLogPrefix << "usedCoresInPset = " << itsParset.usedCoresInPset());
LOG_DEBUG_STR(itsLogPrefix << "itsNrRuns = " << itsNrRuns); LOG_DEBUG_STR(itsLogPrefix << "itsNrRuns = " << itsNrRuns);
}
// synchronize roughly every 5 seconds to see if the job is cancelled // synchronize roughly every 5 seconds to see if the job is cancelled
itsNrRunTokensPerBroadcast = static_cast<unsigned>(ceil(5.0 / itsParset.CNintegrationTime())); itsNrRunTokensPerBroadcast = static_cast<unsigned>(ceil(5.0 / itsParset.CNintegrationTime()));
...@@ -86,7 +90,8 @@ Job::~Job() ...@@ -86,7 +90,8 @@ Job::~Job()
delete itsJobThread; delete itsJobThread;
jobQueue.remove(this); jobQueue.remove(this);
LOG_INFO_STR(itsLogPrefix << "----- Observation " << (itsIsRunning ? "ended" : "cancelled") << " successfully"); if (LOG_CONDITION)
LOG_INFO_STR(itsLogPrefix << "----- Job " << (itsIsRunning ? "finished" : "cancelled") << " successfully");
} }
...@@ -530,13 +535,14 @@ template <typename SAMPLE_TYPE> void Job::doObservation() ...@@ -530,13 +535,14 @@ template <typename SAMPLE_TYPE> void Job::doObservation()
unsigned nrparts = itsParset.nrPartsPerStokes(); unsigned nrparts = itsParset.nrPartsPerStokes();
unsigned nrbeams = itsParset.flysEye() ? itsParset.nrMergedStations() : itsParset.nrPencilBeams(); unsigned nrbeams = itsParset.flysEye() ? itsParset.nrMergedStations() : itsParset.nrPencilBeams();
if (LOG_CONDITION)
LOG_INFO_STR(itsLogPrefix << "----- Observation start"); LOG_INFO_STR(itsLogPrefix << "----- Observation start");
// first: send configuration to compute nodes so they know what to expect // first: send configuration to compute nodes so they know what to expect
if (!configureCNs()) { if (!configureCNs()) {
unconfigureCNs(); unconfigureCNs();
if (LOG_CONDITION)
LOG_INFO_STR(itsLogPrefix << "----- Observation finished"); LOG_INFO_STR(itsLogPrefix << "----- Observation finished");
return; return;
} }
...@@ -626,8 +632,6 @@ template <typename SAMPLE_TYPE> void Job::doObservation() ...@@ -626,8 +632,6 @@ template <typename SAMPLE_TYPE> void Job::doObservation()
continue; continue;
} }
LOG_DEBUG_STR(itsLogPrefix << "Setting up output " << p.outputNr << " (" << p.name << ")");
outputSections[output] = new OutputSection(itsParset, cores, list, maxlistsize, p, &createCNstream); outputSections[output] = new OutputSection(itsParset, cores, list, maxlistsize, p, &createCNstream);
} }
...@@ -667,6 +671,7 @@ template <typename SAMPLE_TYPE> void Job::doObservation() ...@@ -667,6 +671,7 @@ template <typename SAMPLE_TYPE> void Job::doObservation()
unconfigureCNs(); unconfigureCNs();
if (LOG_CONDITION)
LOG_INFO_STR(itsLogPrefix << "----- Observation finished"); LOG_INFO_STR(itsLogPrefix << "----- Observation finished");
} }
......
...@@ -54,6 +54,8 @@ LogThread::LogThread(unsigned nrRspBoards, std::string stationName) ...@@ -54,6 +54,8 @@ LogThread::LogThread(unsigned nrRspBoards, std::string stationName)
LogThread::~LogThread() LogThread::~LogThread()
{ {
itsShouldStop = true; itsShouldStop = true;
itsThread.abort(); // mainly to shorten the sleep() call
} }
...@@ -123,7 +125,7 @@ void LogThread::mainLoop() ...@@ -123,7 +125,7 @@ void LogThread::mainLoop()
readCPUstats(previousLoad); readCPUstats(previousLoad);
#endif #endif
LOG_DEBUG("LogThread running"); //LOG_DEBUG("LogThread running");
// non-atomic updates from other threads cause race conditions, but who cares // non-atomic updates from other threads cause race conditions, but who cares
...@@ -160,11 +162,11 @@ void LogThread::mainLoop() ...@@ -160,11 +162,11 @@ void LogThread::mainLoop()
writeCPUstats(logStr); writeCPUstats(logStr);
#endif #endif
LOG_INFO(logStr.str()); LOG_INFO_STR(logStr.str());
sleep(1); sleep(1);
} }
LOG_DEBUG("LogThread stopped"); //LOG_DEBUG("LogThread stopped");
} }
} // namespace RTCP } // namespace RTCP
......
...@@ -54,7 +54,7 @@ class LogThread ...@@ -54,7 +54,7 @@ class LogThread
std::string itsStationName; std::string itsStationName;
volatile bool itsShouldStop; volatile bool itsShouldStop;
Thread itsThread; InterruptibleThread itsThread;
#if defined HAVE_BGP_ION #if defined HAVE_BGP_ION
struct CPUload { struct CPUload {
......
...@@ -171,7 +171,7 @@ void OutputSection::droppingData(unsigned subband) ...@@ -171,7 +171,7 @@ void OutputSection::droppingData(unsigned subband)
void OutputSection::notDroppingData(unsigned subband) void OutputSection::notDroppingData(unsigned subband)
{ {
if (itsDroppedCount[subband] > 0) { if (itsDroppedCount[subband] > 0) {
LOG_WARN_STR(itsLogPrefix << " index " << setw(3) << itsItemList[subband].second << "] Dropped " << itsDroppedCount[subband] << " integration time(s)" ); LOG_WARN_STR(itsLogPrefix << " index " << setw(3) << itsItemList[subband].second << "] Dropped " << itsDroppedCount[subband] << " blocks" );
itsDroppedCount[subband] = 0; itsDroppedCount[subband] = 0;
} }
} }
......
...@@ -144,12 +144,12 @@ void OutputThread::mainLoop() ...@@ -144,12 +144,12 @@ void OutputThread::mainLoop()
std::auto_ptr<Stream> streamToStorage; std::auto_ptr<Stream> streamToStorage;
std::string outputDescriptor = getStreamDescriptorBetweenIONandStorage(itsParset, itsServer, itsFilename); std::string outputDescriptor = getStreamDescriptorBetweenIONandStorage(itsParset, itsServer, itsFilename);
LOG_INFO_STR(itsLogPrefix << "Creating connection to " << outputDescriptor << "..."); LOG_DEBUG_STR(itsLogPrefix << "Creating connection to " << outputDescriptor << "...");
try { try {
streamToStorage.reset(createStream(outputDescriptor, false)); streamToStorage.reset(createStream(outputDescriptor, false));
LOG_INFO_STR(itsLogPrefix << "Creating connection to " << outputDescriptor << ": done"); LOG_DEBUG_STR(itsLogPrefix << "Creating connection to " << outputDescriptor << ": done");
} catch (SystemCallException &ex) { } catch (SystemCallException &ex) {
if (ex.error == EINTR) { if (ex.error == EINTR) {
LOG_WARN_STR(itsLogPrefix << "Connection to " << outputDescriptor << " aborted"); LOG_WARN_STR(itsLogPrefix << "Connection to " << outputDescriptor << " aborted");
...@@ -194,7 +194,7 @@ void OutputThread::mainLoop() ...@@ -194,7 +194,7 @@ void OutputThread::mainLoop()
delete streamToStorage.release(); // close socket delete streamToStorage.release(); // close socket
LOG_INFO_STR(itsLogPrefix << "Connection to " << outputDescriptor << " closed"); LOG_DEBUG_STR(itsLogPrefix << "Connection to " << outputDescriptor << " closed");
} }
} // namespace RTCP } // namespace RTCP
......
...@@ -51,7 +51,7 @@ class OutputThread ...@@ -51,7 +51,7 @@ class OutputThread
bool waitForDone(const struct timespec &timespec); bool waitForDone(const struct timespec &timespec);
void abort(); void abort();
static const unsigned maxSendQueueSize = 2; // use 2 if you run out of memory, but test carefully to avoid data loss static const unsigned maxSendQueueSize = 3; // use 2 if you run out of memory, but test carefully to avoid data loss
Queue<StreamableData *> itsFreeQueue, itsSendQueue; Queue<StreamableData *> itsFreeQueue, itsSendQueue;
......
...@@ -9,7 +9,6 @@ from CommandClient import sendCommand ...@@ -9,7 +9,6 @@ from CommandClient import sendCommand
from ObservationID import ObservationID from ObservationID import ObservationID
from Parset import Parset from Parset import Parset
from Stations import Stations,overrideRack from Stations import Stations,overrideRack
from util.Hosts import ropen,rmkdir,rexists,runlink,rsymlink
from util.dateutil import format from util.dateutil import format
import sys import sys
import signal import signal
......
...@@ -129,7 +129,7 @@ class Parset(util.Parset.Parset): ...@@ -129,7 +129,7 @@ class Parset(util.Parset.Parset):
self.setdefault("OLAP.Correlator.integrationTime",1); self.setdefault("OLAP.Correlator.integrationTime",1);
if "OLAP.Stokes.channelsPerSubband" not in self or int(self["OLAP.Stokes.channelsPerSubband"]) == 0: if "OLAP.Stokes.channelsPerSubband" not in self or int(self["OLAP.Stokes.channelsPerSubband"]) == 0:
self["OLAP.Stokes.channelsPerSubband"] = self["Observation.nrChannelsPerSubband"] self["OLAP.Stokes.channelsPerSubband"] = self["Observation.channelsPerSubband"]
self.setdefault('OLAP.Storage.Filtered.namemask','L${OBSID}_SB${SUBBAND}.filtered') self.setdefault('OLAP.Storage.Filtered.namemask','L${OBSID}_SB${SUBBAND}.filtered')
......
...@@ -2,7 +2,7 @@ ...@@ -2,7 +2,7 @@
from util.Commands import SyncCommand,AsyncCommand,mpikill,backquote,PIPE from util.Commands import SyncCommand,AsyncCommand,mpikill,backquote,PIPE
from util.Aborter import runUntilSuccess,runFunc from util.Aborter import runUntilSuccess,runFunc
from Locations import Locations,Hosts from Locations import Locations,Hosts,isProduction
import Logger import Logger
import os import os
import Partitions import Partitions
...@@ -182,6 +182,7 @@ class IONProcSection(Section): ...@@ -182,6 +182,7 @@ class IONProcSection(Section):
"%s" % (Locations.files["ionproc"],), "%s" % (Locations.files["ionproc"],),
# arguments # arguments
"%d" % (int(isProduction()),),
] ]
......
0% Loading or .
You are about to add 0 people to the discussion. Proceed with caution.
Please register or to comment