lib_timing

interfaces/Crafter.Event.cppm

@@ -61,6 +61,10 @@ namespace Crafter {
     protected:
         std::map<int, std::vector<EventListener<T>*>> listeners;
         
+#ifdef CRAFTER_TIMING
+        std::map<const EventListener<T>*, std::chrono::nanoseconds> listenerTimes;
+#endif
+        
     public:
         EventBase() = default;
         EventBase(EventBase&& other) : listeners(std::move(other.listeners)) {
@@ -97,6 +101,51 @@ namespace Crafter {
                 listeners[listener->priority].end()
             );
         }
+        
+#ifdef CRAFTER_TIMING
+        // Log timing data in a clear manner
+        void LogTiming() const {
+            if (this->listenerTimes.empty()) {
+                return; // No timing data to report
+            }
+            
+            // Create a vector of pairs for sorting
+            std::vector<std::pair<const EventListener<T>*, std::chrono::nanoseconds>> sortedTimes(
+                this->listenerTimes.begin(), 
+                this->listenerTimes.end()
+            );
+            
+            // Sort by duration (descending order)
+            std::sort(sortedTimes.begin(), sortedTimes.end(),
+                [](const auto& a, const auto& b) {
+                    return a.second > b.second;
+                });
+            
+            // Print results
+            for (const auto& pair : sortedTimes) {
+                const auto& listener = pair.first;
+                const auto& duration = pair.second;
+                
+                // Format output based on magnitude
+                if (duration.count() >= 1000000) {
+                    // Milliseconds
+                    std::printf("Listener (priority %d): %.3f ms\n", 
+                               listener->priority, 
+                               static_cast<double>(duration.count()) / 1000000.0);
+                } else if (duration.count() >= 1000) {
+                    // Microseconds
+                    std::printf("Listener (priority %d): %.3f μs\n", 
+                               listener->priority, 
+                               static_cast<double>(duration.count()) / 1000.0);
+                } else {
+                    // Nanoseconds
+                    std::printf("Listener (priority %d): %ld ns\n", 
+                               listener->priority, 
+                               duration.count());
+                }
+            }
+        }
+#endif
     };
 
     // Specialized Event<void> with different Invoke signature
@@ -106,11 +155,26 @@ namespace Crafter {
         using EventBase<void>::EventBase;
         
         void Invoke() {
+#ifdef CRAFTER_TIMING
+            // Clear previous timing data
+            this->listenerTimes.clear();
+            
+            for (const auto& listenerSlice : this->listeners) {
+                for (const auto& listener : listenerSlice.second) {
+                    auto start = std::chrono::high_resolution_clock::now();
+                    listener->function();
+                    auto end = std::chrono::high_resolution_clock::now();
+                    auto duration = std::chrono::duration_cast<std::chrono::nanoseconds>(end - start);
+                    this->listenerTimes[listener] = duration;
+                }
+            }
+#else
             for (const auto& listenerSlice : this->listeners) {
                 for (const auto& listener : listenerSlice.second) {
                     listener->function();
                 }
             }
+#endif
         }
     };
 
@@ -121,11 +185,26 @@ namespace Crafter {
         using EventBase<T>::EventBase;
         
         void Invoke(T data) {
+#ifdef CRAFTER_TIMING
+            // Clear previous timing data
+            this->listenerTimes.clear();
+            
+            for (const auto& listenerSlice : this->listeners) {
+                for (const auto& listener : listenerSlice.second) {
+                    auto start = std::chrono::high_resolution_clock::now();
+                    listener->function(data);
+                    auto end = std::chrono::high_resolution_clock::now();
+                    auto duration = std::chrono::duration_cast<std::chrono::nanoseconds>(end - start);
+                    this->listenerTimes[listener] = duration;
+                }
+            }
+#else
             for (const auto& listenerSlice : this->listeners) {
                 for (const auto& listener : listenerSlice.second) {
                     listener->function(data);
                 }
             }
+#endif
         }
     };
 

project.json

@@ -7,6 +7,11 @@
             "type":"library"
 
         },
+        {
+            "name": "lib-timing",
+            "extends": ["lib"],
+            "defines": [{ "name": "CRAFTER_TIMING" }]
+        },
         {
             "name": "lib-debug",
             "debug" : true,