Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Added timestamps to externalGenerator output #38857

Merged
merged 1 commit into from
Jul 27, 2022
Merged

Added timestamps to externalGenerator output #38857

Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
54 changes: 35 additions & 19 deletions GeneratorInterface/Core/bin/externalGenerator.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@
#include <thread>
#include <memory>
#include <filesystem>
#include <ctime>

#include "FWCore/TestProcessor/interface/TestProcessor.h"

Expand Down Expand Up @@ -43,6 +44,20 @@ CMS_THREAD_SAFE static std::string s_uniqueID;

//NOTE: Can use TestProcessor as the harness for the worker

namespace {
//Based on MessageLogger time handling
constexpr char timeFormat[] = "dd-Mon-yyyy hh:mm:ss TZN ";
constexpr size_t kTimeSize = sizeof(timeFormat);
std::array<char, kTimeSize> formattedTime() {
auto t = time(nullptr);
std::array<char, kTimeSize> ts;

struct tm timebuf;
std::strftime(ts.data(), ts.size(), "%d-%b-%Y %H:%M:%S %Z", localtime_r(&t, &timebuf));
return ts;
}
} // namespace

using namespace edm::shared_memory;
class Harness {
public:
Expand Down Expand Up @@ -88,7 +103,7 @@ namespace {

void atexit_handler() {
if (s_sharedLock) {
std::cerr << s_uniqueID << " process: early exit called: unlock\n";
std::cerr << s_uniqueID << " process: early exit called: unlock " << formattedTime().data() << "\n";
s_sharedLock->unlock();
}
}
Expand Down Expand Up @@ -175,7 +190,7 @@ int main(int argc, char* argv[]) {

monitorThread.setAction([lockPtr]() {
if (lockPtr) {
std::cerr << s_uniqueID << " process: SIGNAL CAUGHT: unlock\n";
std::cerr << s_uniqueID << " process: SIGNAL CAUGHT: unlock " << formattedTime().data() << "\n";
lockPtr->unlock();
}
});
Expand All @@ -188,7 +203,7 @@ int main(int argc, char* argv[]) {
std::atexit(atexit_handler);
auto releaseLock = []() {
if (s_sharedLock) {
std::cerr << s_uniqueID << " process: terminate called: unlock\n";
std::cerr << s_uniqueID << " process: terminate called: unlock " << formattedTime().data() << "\n";
s_sharedLock->unlock();
s_sharedLock = nullptr;
//deactivate the abort signal
Expand All @@ -212,7 +227,7 @@ int main(int argc, char* argv[]) {
ROOTDeserializer<edm::RandomNumberGeneratorState, ReadBuffer> random_deserializer(sm_readbuffer);

presentState = "reading configuration";
std::cerr << uniqueID << " process: initializing " << std::endl;
std::cerr << uniqueID << " process: initializing " << formattedTime().data() << std::endl;
int nlines;
std::cin >> nlines;

Expand All @@ -237,30 +252,30 @@ int main(int argc, char* argv[]) {
std::set_terminate(releaseLock);

if (verbose) {
std::cerr << uniqueID << " process: done initializing" << std::endl;
std::cerr << uniqueID << " process: done initializing " << formattedTime().data() << std::endl;
}
presentState = "finished initialization";
communicationChannel.workerSetupDone();

presentState = "waiting for transition";
if (verbose)
std::cerr << uniqueID << " process: waiting " << counter << std::endl;
std::cerr << uniqueID << " process: waiting " << counter << " " << formattedTime().data() << std::endl;
communicationChannel.handleTransitions([&](edm::Transition iTransition, unsigned long long iTransitionID) {
++counter;
switch (iTransition) {
case edm::Transition::BeginRun: {
presentState = "beginRun transition";
if (verbose)
std::cerr << uniqueID << " process: start beginRun " << std::endl;
std::cerr << uniqueID << " process: start beginRun " << formattedTime().data() << std::endl;
if (verbose)
std::cerr << uniqueID << " process: end beginRun " << std::endl;
std::cerr << uniqueID << " process: end beginRun " << formattedTime().data() << std::endl;

break;
}
case edm::Transition::BeginLuminosityBlock: {
presentState = "begin lumi";
if (verbose)
std::cerr << uniqueID << " process: start beginLumi " << std::endl;
std::cerr << uniqueID << " process: start beginLumi " << formattedTime().data() << std::endl;
auto randState = random_deserializer.deserialize();
presentState = "deserialized random state in begin lumi";
if (verbose)
Expand All @@ -274,7 +289,7 @@ int main(int argc, char* argv[]) {
presentState = "serialize lumi";
bl_serializer.serialize(value);
if (verbose)
std::cerr << uniqueID << " process: end beginLumi " << std::endl;
std::cerr << uniqueID << " process: end beginLumi " << formattedTime().data() << std::endl;
if (verbose)
std::cerr << uniqueID << " rand " << value.randomState_.state_.size() << " " << value.randomState_.seed_
<< std::endl;
Expand All @@ -283,7 +298,7 @@ int main(int argc, char* argv[]) {
case edm::Transition::Event: {
presentState = "begin event";
if (verbose)
std::cerr << uniqueID << " process: event " << counter << std::endl;
std::cerr << uniqueID << " process: event " << counter << " " << formattedTime().data() << std::endl;
presentState = "deserialized random state in event";
auto randState = random_deserializer.deserialize();
randomService->setState(randState.state_, randState.seed_);
Expand All @@ -293,7 +308,7 @@ int main(int argc, char* argv[]) {
value.randomState_.seed_ = randomService->mySeed();

if (verbose)
std::cerr << uniqueID << " process: event " << counter << std::endl;
std::cerr << uniqueID << " process: event " << counter << " " << formattedTime().data() << std::endl;

presentState = "serialize event";
serializer.serialize(value);
Expand All @@ -306,28 +321,28 @@ int main(int argc, char* argv[]) {
case edm::Transition::EndLuminosityBlock: {
presentState = "begin end lumi";
if (verbose)
std::cerr << uniqueID << " process: start endLumi " << std::endl;
std::cerr << uniqueID << " process: start endLumi " << formattedTime().data() << std::endl;
presentState = "processing end lumi";
auto value = harness.getEndLumiValue();

presentState = "serialize end lumi";
el_serializer.serialize(value);
if (verbose)
std::cerr << uniqueID << " process: end endLumi " << std::endl;
std::cerr << uniqueID << " process: end endLumi " << formattedTime().data() << std::endl;

break;
}
case edm::Transition::EndRun: {
presentState = "begin end run";
if (verbose)
std::cerr << uniqueID << " process: start endRun " << std::endl;
std::cerr << uniqueID << " process: start endRun " << formattedTime().data() << std::endl;
presentState = "process end run";
auto value = harness.getEndRunValue();

presentState = "serialize end run";
er_serializer.serialize(value);
if (verbose)
std::cerr << uniqueID << " process: end endRun " << std::endl;
std::cerr << uniqueID << " process: end endRun " << formattedTime().data() << std::endl;

break;
}
Expand All @@ -337,19 +352,20 @@ int main(int argc, char* argv[]) {
}
presentState = "notifying and waiting after " + presentState;
if (verbose)
std::cerr << uniqueID << " process: notifying and waiting " << counter << std::endl;
std::cerr << uniqueID << " process: notifying and waiting " << counter << " " << std::endl;
});
}
} catch (std::exception const& iExcept) {
std::cerr << "%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%\n"
<< s_uniqueID << " process: caught exception \n"
<< iExcept.what() << "\n"
<< iExcept.what() << " " << formattedTime().data() << "\n"
<< " while " << presentState << "\n"
<< "%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%\n";
return 1;
} catch (...) {
std::cerr << "%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%\n"
<< s_uniqueID << " process: caught unknown exception\n while " << presentState << "\n"
<< s_uniqueID << " process: caught unknown exception " << formattedTime().data() << "\n while "
<< presentState << "\n"
<< "%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%\n";
return 1;
}
Expand Down