Back to home page

EIC code displayed by LXR

 
 

    


File indexing completed on 2024-06-29 07:06:07

0001 // SPDX-License-Identifier: LGPL-3.0-or-later
0002 // Copyright (C) 2023, Wouter Deconinck
0003 
0004 #include <JANA/JEventProcessor.h>
0005 
0006 #include <map>
0007 #include <string>
0008 
0009 class JEventProcessorJANATOP : public JEventProcessor
0010 {
0011   private:
0012     enum node_type {
0013         kDefault,
0014         kProcessor,
0015         kFactory,
0016         kCache,
0017         kSource
0018     };
0019 
0020     class CallLink {
0021       public:
0022         std::string caller_name;
0023         std::string caller_tag;
0024         std::string callee_name;
0025         std::string callee_tag;
0026 
0027         bool operator<(const CallLink &link) const {
0028             if (this->caller_name != link.caller_name)
0029                 return this->caller_name < link.caller_name;
0030             if (this->callee_name != link.callee_name)
0031                 return this->callee_name < link.callee_name;
0032             if (this->caller_tag != link.caller_tag)
0033                 return this->caller_tag < link.caller_tag;
0034             return this->callee_tag < link.callee_tag;
0035         }
0036     };
0037 
0038     class CallStats {
0039       public:
0040         CallStats(void) {
0041             from_cache_ms = 0;
0042             from_source_ms = 0;
0043             from_factory_ms = 0;
0044             data_not_available_ms = 0;
0045             Nfrom_cache = 0;
0046             Nfrom_source = 0;
0047             Nfrom_factory = 0;
0048             Ndata_not_available = 0;
0049         }
0050         double from_cache_ms;
0051         double from_source_ms;
0052         double from_factory_ms;
0053         double data_not_available_ms;
0054         unsigned int Nfrom_cache;
0055         unsigned int Nfrom_source;
0056         unsigned int Nfrom_factory;
0057         unsigned int Ndata_not_available;
0058     };
0059 
0060     class FactoryCallStats{
0061       public:
0062         FactoryCallStats(void) {
0063             type = kDefault;
0064             time_waited_on = 0.0;
0065             time_waiting = 0.0;
0066             Nfrom_factory = 0;
0067             Nfrom_source = 0;
0068             Nfrom_cache = 0;
0069         }
0070         node_type type;
0071         double time_waited_on;    // time other factories spent waiting on this factory
0072         double time_waiting;        // time this factory spent waiting on other factories
0073         unsigned int Nfrom_factory;
0074         unsigned int Nfrom_source;
0075         unsigned int Nfrom_cache;
0076     };
0077 
0078   public:
0079 
0080     JEventProcessorJANATOP(): JEventProcessor() {
0081         SetTypeName("JEventProcessorJANATOP");
0082         auto app = japp;
0083     };
0084 
0085     void Init() override { };
0086 
0087     void BeginRun(const std::shared_ptr<const JEvent>& event) override { };
0088 
0089     void Process(const std::shared_ptr<const JEvent>& event) override {
0090         // Get the call stack for ths event and add the results to our stats
0091         auto stack = event->GetJCallGraphRecorder()->GetCallGraph();
0092 
0093         // Lock mutex in case we are running with multiple threads
0094         std::lock_guard<std::mutex> lck(mutex);
0095 
0096         // Loop over the call stack elements and add in the values
0097         for (unsigned int i = 0; i < stack.size(); i++) {
0098 
0099             // Keep track of total time each factory spent waiting and being waited on
0100             std::string nametag1 = MakeNametag(stack[i].caller_name, stack[i].caller_tag);
0101             std::string nametag2 = MakeNametag(stack[i].callee_name, stack[i].callee_tag);
0102 
0103             FactoryCallStats &fcallstats1 = factory_stats[nametag1];
0104             FactoryCallStats &fcallstats2 = factory_stats[nametag2];
0105 
0106             auto delta_t_ms = std::chrono::duration_cast<std::chrono::milliseconds>(stack[i].end_time - stack[i].start_time).count();
0107             fcallstats1.time_waiting += delta_t_ms;
0108             fcallstats2.time_waited_on += delta_t_ms;
0109 
0110             // Get pointer to CallStats object representing this calling pair
0111             CallLink link;
0112             link.caller_name = stack[i].caller_name;
0113             link.caller_tag  = stack[i].caller_tag;
0114             link.callee_name = stack[i].callee_name;
0115             link.callee_tag  = stack[i].callee_tag;
0116             CallStats &stats = call_links[link]; // get pointer to stats object or create if it doesn't exist
0117 
0118             switch(stack[i].data_source){
0119                 case JCallGraphRecorder::DATA_NOT_AVAILABLE:
0120                     stats.Ndata_not_available++;
0121                     stats.data_not_available_ms += delta_t_ms;
0122                     break;
0123                 case JCallGraphRecorder::DATA_FROM_CACHE:
0124                     fcallstats2.Nfrom_cache++;
0125                     stats.Nfrom_cache++;
0126                     stats.from_cache_ms += delta_t_ms;
0127                     break;
0128                 case JCallGraphRecorder::DATA_FROM_SOURCE:
0129                     fcallstats2.Nfrom_source++;
0130                     stats.Nfrom_source++;
0131                     stats.from_source_ms += delta_t_ms;
0132                     break;
0133                 case JCallGraphRecorder::DATA_FROM_FACTORY:
0134                     fcallstats2.Nfrom_factory++;
0135                     stats.Nfrom_factory++;
0136                     stats.from_factory_ms += delta_t_ms;
0137                     break;
0138             }
0139         }
0140     };
0141 
0142     void EndRun() override { };
0143 
0144     void Finish() override {
0145         // In order to get the total time we have to first get a list of
0146         // the event processors (i.e. top-level callers). We can tell
0147         // this just by looking for callers that never show up as callees
0148         std::set<std::string> callers;
0149         std::set<std::string> callees;
0150         for (auto iter = call_links.begin(); iter != call_links.end(); iter++) {
0151             const CallLink &link = iter->first;
0152             std::string caller = MakeNametag(link.caller_name, link.caller_tag);
0153             std::string callee = MakeNametag(link.callee_name, link.callee_tag);
0154             callers.insert(caller);
0155             callees.insert(callee);
0156         }
0157 
0158         // Loop over list a second time so we can get the total ticks for
0159         // the process in order to add the percentage to the label below
0160         double total_ms = 0.0;
0161         for (auto iter = call_links.begin(); iter != call_links.end(); iter++) {
0162             const CallLink &link = iter->first;
0163             const CallStats &stats = iter->second;
0164             std::string caller = MakeNametag(link.caller_name, link.caller_tag);
0165             std::string callee = MakeNametag(link.callee_name, link.callee_tag);
0166             if (callees.find(caller) == callees.end()){
0167                 total_ms += stats.from_factory_ms + stats.from_source_ms + stats.from_cache_ms + stats.data_not_available_ms;
0168             }
0169         }
0170         if (total_ms == 0.0) total_ms = 1.0;
0171 
0172         // Loop over call links
0173         std::cout << "Links:" << std::endl;
0174         std::vector<std::pair<CallLink, CallStats>> call_links_vector{
0175             std::make_move_iterator(std::begin(call_links)),
0176             std::make_move_iterator(std::end(call_links))
0177         };
0178         [[maybe_unused]] auto call_links_compare_time = [](const auto& a, const auto& b) {
0179             return ((a.second.from_factory_ms + a.second.from_source_ms + a.second.from_cache_ms)
0180                   < (b.second.from_factory_ms + b.second.from_source_ms + b.second.from_cache_ms));
0181         };
0182         [[maybe_unused]] auto call_links_compare_N = [](const auto& a, const auto& b) {
0183             return ((a.second.Nfrom_factory + a.second.Nfrom_source + a.second.Nfrom_cache)
0184                   < (b.second.Nfrom_factory + b.second.Nfrom_source + b.second.Nfrom_cache));
0185         };
0186         std::sort(call_links_vector.begin(), call_links_vector.end(), call_links_compare_time);
0187         for (auto iter = call_links_vector.end() - std::min(call_links_vector.size(), 10ul);
0188                   iter != call_links_vector.end(); iter++) {
0189             const CallLink &link = iter->first;
0190             const CallStats &stats = iter->second;
0191 
0192             unsigned int Ntotal = stats.Nfrom_cache + stats.Nfrom_source + stats.Nfrom_factory;
0193 
0194             std::string nametag1 = MakeNametag(link.caller_name, link.caller_tag);
0195             std::string nametag2 = MakeNametag(link.callee_name, link.callee_tag);
0196 
0197             double this_ms = stats.from_factory_ms + stats.from_source_ms + stats.from_cache_ms;
0198             std::string timestr = MakeTimeString(stats.from_factory_ms);
0199             double percent = 100.0 * this_ms / total_ms;
0200             char percentstr[32];
0201             snprintf(percentstr, 32, "%5.1f%%", percent);
0202 
0203             std::cout << Ntotal << " calls, " << timestr << " (" << percentstr << ") ";
0204             std::cout << nametag1 << " -> " << nametag2;
0205             std::cout << std::endl;
0206         }
0207 
0208         // Loop over factories
0209         std::cout << "Factories:" << std::endl;
0210         std::vector<std::pair<std::string, FactoryCallStats>> factory_stats_vector{
0211             std::make_move_iterator(std::begin(factory_stats)),
0212             std::make_move_iterator(std::end(factory_stats))
0213         };
0214         auto factory_stats_compare = [](const auto& a, const auto& b) {
0215             return ((a.second.time_waited_on - a.second.time_waiting)
0216                   < (b.second.time_waited_on - b.second.time_waiting));
0217         };
0218         std::sort(factory_stats_vector.begin(), factory_stats_vector.end(), factory_stats_compare);
0219         for (auto iter = factory_stats_vector.end() - std::min(factory_stats_vector.size(), 10ul);
0220                   iter != factory_stats_vector.end(); iter++) {
0221             FactoryCallStats &fcall_stats = iter->second;
0222             std::string nodename = iter->first;
0223 
0224             // Get time spent in this factory proper
0225             double time_spent_in_factory = fcall_stats.time_waited_on - fcall_stats.time_waiting;
0226             std::string timestr = MakeTimeString(time_spent_in_factory);
0227             double percent = 100.0 * time_spent_in_factory / total_ms;
0228             char percentstr[32];
0229             snprintf(percentstr, 32, "%5.1f%%", percent);
0230 
0231             std::cout << timestr << " (" << percentstr << ") ";
0232             std::cout << nodename;
0233             std::cout << std::endl;
0234         }
0235     };
0236 
0237   private:
0238 
0239     std::mutex mutex;
0240 
0241     std::map<CallLink, CallStats> call_links;
0242     std::map<std::string, FactoryCallStats> factory_stats;
0243 
0244     std::string MakeTimeString(double time_in_ms) {
0245         double order = log10(time_in_ms);
0246         std::stringstream ss;
0247         ss << std::fixed << std::setprecision(2);
0248         if (order < 0) {
0249             ss << time_in_ms*1000.0 << " us";
0250         } else if (order <= 2.0) {
0251             ss << time_in_ms << " ms";
0252         } else {
0253                ss << time_in_ms / 1000.0 << " s";
0254         }
0255         return ss.str();
0256     }
0257 
0258     std::string MakeNametag(const std::string &name, const std::string &tag) {
0259         std::string nametag = name;
0260         if (tag.size() > 0) nametag += ":" + tag;
0261         return nametag;
0262     }
0263 };