better timing

examples/HelloAnimation/main.cpp

@@ -36,6 +36,7 @@ int main() {
         if(anim.currentFrame == anim.keyframes.size()-1) {
             anim.Start(time.now);
         }
+        window.LogTiming();
     });
     
     element.buffer = {{255, 0, 0 ,255}, {0, 255, 0 ,255}};

implementations/Crafter.Graphics-Window.cpp

@@ -60,3 +60,18 @@ void Window::ScaleMouse(Transform& element) {
 // 	element.scaled.x = MappedToPixelBoundless(element.anchorX, boundlessWidth) - MappedToPixelBoundless(element.anchorOffsetX, element.scaled.width) + PixelToMappedBoundless(parent.scaled.x, width);
 //     element.scaled.y = MappedToPixelBoundless(element.anchorY, boundlessHeight) - MappedToPixelBoundless(element.anchorOffsetY, element.scaled.height) + PixelToMappedBoundless(parent.scaled.y, height);
 }
+
+#ifdef CRAFTER_TIMING
+void Window::LogTiming() {
+    std::cout << std::format("Update: {}", duration_cast<std::chrono::milliseconds>(totalUpdate)) << std::endl;
+    for (const std::pair<const EventListener<FrameTime>*, std::chrono::nanoseconds>& entry : updateTimings) {
+        std::cout << std::format("\t{} {}", reinterpret_cast<const void*>(entry.first), duration_cast<std::chrono::microseconds>(entry.second)) << std::endl;
+    }
+    std::cout << std::format("Render: {}", duration_cast<std::chrono::milliseconds>(totalRender)) << std::endl;
+    for (const std::tuple<const RenderingElement*, std::uint_fast32_t, std::uint_fast32_t, std::chrono::nanoseconds>& entry : renderTimings) {
+        std::cout << std::format("\t{} {}x{} {}", reinterpret_cast<const void*>(std::get<0>(entry)), std::get<1>(entry), std::get<2>(entry), duration_cast<std::chrono::microseconds>(std::get<3>(entry))) << std::endl;
+    }
+    std::cout << std::format("Vblank: {}", duration_cast<std::chrono::milliseconds>(vblank)) << std::endl;
+    std::cout << std::format("Total: {}", duration_cast<std::chrono::milliseconds>(totalUpdate+totalRender+vblank)) << std::endl;
+}
+#endif

implementations/Crafter.Graphics-Window_wayland.cpp

@@ -136,13 +136,16 @@ void WindowWayland::StartSync() {
 
 
 
-void RenderElement(Transform* transform, WindowWayland* window) {
+void WindowWayland::RenderElement(Transform* transform) {
 	RenderingElement* element = dynamic_cast<RenderingElement*>(transform);
 	if(element) {
+		#ifdef CRAFTER_TIMING
+		auto start = std::chrono::high_resolution_clock::now();
+		#endif
 		for (std::int_fast32_t x = element->scaled.x; x - element->scaled.x < element->scaled.width; x++) {
 			for (std::int_fast32_t y = element->scaled.y; y - element->scaled.y < element->scaled.height; y++) {
-				if (x >= 0 && x <  window->width && y >= 0 && y <  window->height) {
+				if (x >= 0 && x <  width && y >= 0 && y <  height) {
-					Pixel_BU8_GU8_RU8_AU8& dst = window->framebuffer[y * window->width + x];
+					Pixel_BU8_GU8_RU8_AU8& dst = framebuffer[y * width + x];
 					const Pixel_BU8_GU8_RU8_AU8& src = element->bufferScaled[(y - element->scaled.y) * element->scaled.width + (x - element->scaled.x)];
 
 					float srcA = src.a / 255.0f;
@@ -160,11 +163,15 @@ void RenderElement(Transform* transform, WindowWayland* window) {
 				}
 			}
 		}
+		#ifdef CRAFTER_TIMING
+		auto end = std::chrono::high_resolution_clock::now();
+		renderTimings.push_back({element, element->scaled.width, element->scaled.height, end-start});
+		#endif
 	}
 
     std::sort(transform->children.begin(), transform->children.end(), [](Transform* a, Transform* b){ return a->z < b->z; });
     for(Transform* child : transform->children) {
-		RenderElement(child, window);
+		this->RenderElement(child);
 	}
 }
 
@@ -172,13 +179,13 @@ void WindowWayland::Render() {
 	std::sort(elements.begin(), elements.end(), [](Transform* a, Transform* b){ return a->z < b->z; });
 
 	for (std::uint_fast32_t x = 0; x < width; x++) {
-        for (std::uint_fast32_t y = 0; y - height; y++) {
+        for (std::uint_fast32_t y = 0; y < height; y++) {
 			framebuffer[y * width + x] = {0,0,0,0};
 		}
 	}
 
     for(Transform* child : elements) {
-		RenderElement(child, this);
+		RenderElement(child);
 	}
 
     wl_surface_attach(surface, buffer, 0, 0);
@@ -238,38 +245,39 @@ std::chrono::time_point<std::chrono::high_resolution_clock> framEnd;
 
 void WindowWayland::wl_surface_frame_done(void* data, struct wl_callback *cb, uint32_t time)
 {
-	#ifdef CRAFTER_TIMING
 	auto start = std::chrono::high_resolution_clock::now();
-	auto vblank = duration_cast<std::chrono::milliseconds>(start - framEnd);
-	#endif
 	wl_callback_destroy(cb);
 	WindowWayland* window = reinterpret_cast<WindowWayland*>(data);
+	#ifdef CRAFTER_TIMING
+	window->vblank = duration_cast<std::chrono::milliseconds>(start - window->frameEnd);
+	#endif
 
     if(window->updating) {
         cb = wl_surface_frame(window->surface);
 	    wl_callback_add_listener(cb, &WindowWayland::wl_callback_listener, window);
 		window->onUpdate.Invoke({start, start-window->lastFrameBegin});
 		#ifdef CRAFTER_TIMING
-		std::chrono::nanoseconds totalUpdate = std::chrono::nanoseconds(0);
+		window->totalUpdate = std::chrono::nanoseconds(0);
+		window->updateTimings.clear();
 		for (const std::pair<const EventListener<FrameTime>*, std::chrono::nanoseconds>& entry : window->onUpdate.listenerTimes) {
-			totalUpdate += entry.second;
+			window->updateTimings.push_back(entry);
+			window->totalUpdate += entry.second;
     	}
-		std::cout << std::format("Update: {}", duration_cast<std::chrono::milliseconds>(totalUpdate)) << std::endl;
+		#endif
-		for (const std::pair<const EventListener<FrameTime>*, std::chrono::nanoseconds>& entry : window->onUpdate.listenerTimes) {
+		#ifdef CRAFTER_TIMING
-			std::cout << std::format("\t{} {}", reinterpret_cast<const void*>(entry.first), entry.second) << std::endl;
+		auto renderStart = std::chrono::high_resolution_clock::now();
-    	}
+		window->renderTimings.clear();
-		auto startRender = std::chrono::high_resolution_clock::now();
 		#endif
 		window->Render();
 		#ifdef CRAFTER_TIMING
-		auto endRender = std::chrono::high_resolution_clock::now();
+		auto renderEnd = std::chrono::high_resolution_clock::now();
-		auto end = std::chrono::high_resolution_clock::now();
+		window->totalRender = renderEnd - renderStart;
-		std::cout << std::format("Render: {}, Vblank: {}, Total: {}", duration_cast<std::chrono::milliseconds>(endRender - startRender), vblank, duration_cast<std::chrono::milliseconds>(totalUpdate+(endRender - startRender)+vblank)) << std::endl;
 		#endif
+		
     }
 
 	#ifdef CRAFTER_TIMING
-	framEnd = std::chrono::high_resolution_clock::now();
+	window->frameEnd = std::chrono::high_resolution_clock::now();
 	#endif
 	window->lastFrameBegin = start;
 }

interfaces/Crafter.Graphics-Window.cppm

@@ -45,6 +45,7 @@ import Crafter.Event;
 
 export namespace Crafter {
     class Transform;
+    class RenderingElement;
     class Window {
         public:
         std::uint_fast32_t width; 
@@ -68,6 +69,16 @@ export namespace Crafter {
         void ScaleElement(Transform& element);
         void ScaleMouse(Transform& element, Transform& parent);
         void ScaleMouse(Transform& element);
+        #ifdef CRAFTER_TIMING
+        std::chrono::nanoseconds totalUpdate;
+        std::vector<std::pair<const EventListener<FrameTime>*, std::chrono::nanoseconds>> updateTimings;
+        std::chrono::nanoseconds totalRender;
+        std::vector<std::tuple<const RenderingElement*, std::uint_fast32_t, std::uint_fast32_t, std::chrono::nanoseconds>> renderTimings;
+        std::chrono::nanoseconds vblank;
+        std::chrono::nanoseconds totalFrame;
+        std::chrono::time_point<std::chrono::high_resolution_clock> frameEnd;
+        void LogTiming();
+        #endif
     };
 
     class WindowKeyboard {
@@ -145,6 +156,7 @@ export namespace Crafter {
         xkb_keymap* xkb_keymap;
         xkb_context* xkb_context = xkb_context_new(XKB_CONTEXT_NO_FLAGS);
         xkb_state* xkb_state;
+        void RenderElement(Transform* transform);
         void Render() override;
         void StartSync() override;
         void StartUpdate() override;