TIG-3421 Add actor debug information to actors (mongodb#652)

src/cast_core/src/HelloWorld.cpp

@@ -39,6 +39,10 @@ struct HelloWorld::PhaseConfig {
 
 void HelloWorld::run() {
     for (auto&& config : _loop) {
+        // Note that this gets printed before any rate-limiting occurs.
+        // I.e an actor may print "Starting ... execution" then be rate-limited
+        // because rate-limiting is part of the inner actor iteration.
+        BOOST_LOG_TRIVIAL(debug) << "Starting " << this->actorInfo() << " execution";
         for (auto _ : config) {
             auto ctx = config->operation.start();
             BOOST_LOG_TRIVIAL(info) << config->message;
@@ -51,6 +55,7 @@ void HelloWorld::run() {
             config->syntheticOperation.report(metrics::clock::now(),
                                               std::chrono::milliseconds{_helloCounter});
         }
+        BOOST_LOG_TRIVIAL(debug) << "Ended " << this->actorInfo() << " execution";
     }
 }
 

src/gennylib/include/gennylib/Actor.hpp

@@ -15,6 +15,8 @@
 #ifndef HEADER_00818641_6D7B_4A3D_AFC6_38CC0DBAD99B_INCLUDED
 #define HEADER_00818641_6D7B_4A3D_AFC6_38CC0DBAD99B_INCLUDED
 
+#include <string>
+
 namespace genny {
 
 using ActorId = unsigned int;
@@ -79,6 +81,15 @@ class Actor {
      */
     // static std::string_view defaultName()
 
+
+    /**
+     * @return info string containing the actor type, name and id
+     * Can be used for debug logging.
+     */
+    std::string actorInfo() const {
+        return _actorInfo;
+    }
+
     /**
      * The main method of an actor. Will be run in its own thread.
      * This is only intended to be called by workload drivers.
@@ -96,6 +107,7 @@ class Actor {
 
 private:
     ActorId _id;
+    std::string _actorInfo;
 };
 
 }  // namespace genny

src/gennylib/include/gennylib/context.hpp

@@ -337,6 +337,8 @@ class ActorContext final : public v1::HasNode {
         : v1::HasNode{node}, _workload{&workloadContext}, _phaseContexts{} {
         _phaseContexts = constructPhaseContexts(_node, this);
         auto threads = (*this)["Threads"].maybe<int>().value_or(1);
+        _actorType = (*this)["Type"].maybe<std::string>().value_or("no_type");
+        _actorName = (*this)["Name"].maybe<std::string>().value_or("no_name");
         _nextActorId = this->workload().claimActorIds(threads);
     }
 
@@ -353,6 +355,14 @@ class ActorContext final : public v1::HasNode {
         return _nextActorId++;
     }
 
+    /**
+     * @param id for this actor
+     * @return info string containing the actor type, name and id
+     */
+    std::string actorInfo(ActorId id) const {
+        return _actorType + "::" + _actorName + "::" + std::to_string(id);
+    }
+
     /**
      * @return top-level workload configuration
      */
@@ -449,6 +459,8 @@ class ActorContext final : public v1::HasNode {
     WorkloadContext* _workload;
     std::unordered_map<PhaseNumber, std::unique_ptr<PhaseContext>> _phaseContexts;
 
+    std::string _actorType;
+    std::string _actorName;
     std::atomic<ActorId> _nextActorId;
 };
 

src/gennylib/src/Actor.cpp

@@ -19,5 +19,6 @@
 #include <gennylib/context.hpp>
 
 namespace genny {
-Actor::Actor(ActorContext& context) : _id{context.nextActorId()} {}
+Actor::Actor(ActorContext& context)
+    : _id{context.nextActorId()}, _actorInfo{context.actorInfo(_id)} {}
 }  // namespace genny

src/gennylib/src/Orchestrator.cpp

@@ -86,7 +86,7 @@ PhaseNumber Orchestrator::awaitPhaseStart(bool block, int addTokens) {
         for (auto&& cb : _prePhaseHooks) {
             cb(this);
         }
-        BOOST_LOG_TRIVIAL(debug) << "Beginning phase " << currentPhase;
+        BOOST_LOG_TRIVIAL(info) << "Beginning phase " << currentPhase;
         _phaseChange.notify_all();
         state = State::PhaseStarted;
     } else {
@@ -137,7 +137,7 @@ bool Orchestrator::awaitPhaseEnd(bool block, int removeTokens) {
 
     if (_currentTokens <= 0) {
         ++_current;
-        BOOST_LOG_TRIVIAL(debug) << "Ended phase " << (this->_current - 1);
+        BOOST_LOG_TRIVIAL(info) << "Ended phase " << (this->_current - 1);
         _phaseChange.notify_all();
         state = State::PhaseEnded;
     } else {