File indexing completed on 2025-01-18 09:55:45
0001
0002
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;
0072 double time_waiting;
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
0091 auto stack = event->GetJCallGraphRecorder()->GetCallGraph();
0092
0093
0094 std::lock_guard<std::mutex> lck(mutex);
0095
0096
0097 for (unsigned int i = 0; i < stack.size(); i++) {
0098
0099
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
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];
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
0146
0147
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
0159
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
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
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
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 };