From 4a9afb424637e0dd29adfaa0bacb476b5887d67d Mon Sep 17 00:00:00 2001 From: Edgaru089 Date: Mon, 21 Feb 2022 12:24:05 +0800 Subject: [PATCH] refactor debug info, measure render times --- internal/game/imgui.go | 7 ++- internal/game/logic.go | 9 +++- internal/io/io.go | 21 +++++++- internal/render/render_world.go | 60 +++++++---------------- internal/render/render_world_debuginfo.go | 56 +++++++++++++++++++++ internal/util/clock.go | 28 +++++++++++ 6 files changed, 135 insertions(+), 46 deletions(-) create mode 100644 internal/render/render_world_debuginfo.go create mode 100644 internal/util/clock.go diff --git a/internal/game/imgui.go b/internal/game/imgui.go index 5e217e7..bea0e13 100644 --- a/internal/game/imgui.go +++ b/internal/game/imgui.go @@ -52,13 +52,17 @@ func (g *Game) initImgui(win *glfw.Window) { } func (g *Game) imgui() { + + io.Diagnostics.CgoCalls = runtime.NumCgoCall() - g.gui.lastframeCgoCalls + g.gui.lastframeCgoCalls = runtime.NumCgoCall() + if io.ShowDebugInfo { imgui.SetNextWindowPosV(imgui.Vec2{}, imgui.ConditionAlways, imgui.Vec2{}) imgui.SetNextWindowSize(imgui.Vec2{X: float32(io.DisplaySize[0]), Y: float32(io.DisplaySize[1])}) if igwrap.Begin("F3", nil, igwrap.WindowFlagsOverlay) { igwrap.TextBackground("Gl01 compiled by %s/%s [%s/%s] (120AVG) %.1f FPS (%.3f frame)", runtime.Compiler, runtime.Version(), runtime.GOOS, runtime.GOARCH, imgui.CurrentIO().Framerate(), 1000/imgui.CurrentIO().Framerate()) igwrap.TextBackground("GLFW %s, Dear ImGUI %s", glfw.GetVersionString(), imgui.Version()) - igwrap.TextBackground("CgoCalls:%d (%d lastframe), Goroutines:%d", runtime.NumCgoCall(), runtime.NumCgoCall()-g.gui.lastframeCgoCalls, runtime.NumGoroutine()) + igwrap.TextBackground("CgoCalls:%d (%d lastframe), Goroutines:%d", g.gui.lastframeCgoCalls, io.Diagnostics.CgoCalls, runtime.NumGoroutine()) igwrap.TextBlank() pos := g.player.Position() @@ -66,7 +70,6 @@ func (g *Game) imgui() { imgui.End() } } - g.gui.lastframeCgoCalls = runtime.NumCgoCall() if imgui.BeginV("Player", nil, imgui.WindowFlagsAlwaysAutoResize) { pos := g.player.Position() diff --git a/internal/game/logic.go b/internal/game/logic.go index 4059ada..d6d5a88 100644 --- a/internal/game/logic.go +++ b/internal/game/logic.go @@ -9,6 +9,7 @@ import ( "edgaru089.ml/go/gl01/internal/igwrap/backend" "edgaru089.ml/go/gl01/internal/io" "edgaru089.ml/go/gl01/internal/render" + "edgaru089.ml/go/gl01/internal/util" "edgaru089.ml/go/gl01/internal/util/itype" "edgaru089.ml/go/gl01/internal/world" "edgaru089.ml/go/gl01/internal/world/worldgen" @@ -174,7 +175,8 @@ const airAccel = 0.1 // Update updates the game state, not necessarily in the main thread. func (g *Game) Update(win *glfw.Window, delta time.Duration) { backend.NewFrame() - imgui.ShowDemoWindow(nil) + + clock := util.NewClock() if !g.paused { @@ -242,7 +244,12 @@ func (g *Game) Update(win *glfw.Window, delta time.Duration) { g.player.SetSpeed(itype.Vec3d{}) } + io.Diagnostics.Times.Logic = clock.Restart() + + imgui.ShowDemoWindow(nil) g.imgui() + + io.Diagnostics.Times.GUI = clock.Restart() } // Render, called with a OpenGL context, renders the game. diff --git a/internal/io/io.go b/internal/io/io.go index b0565df..7a3ba8e 100644 --- a/internal/io/io.go +++ b/internal/io/io.go @@ -1,6 +1,10 @@ package io -import "edgaru089.ml/go/gl01/internal/util/itype" +import ( + "time" + + "edgaru089.ml/go/gl01/internal/util/itype" +) var ( DisplaySize itype.Vec2i // Size of the window viewport in pixels. @@ -13,4 +17,19 @@ var ( RenderPos, RenderDir itype.Vec3d // Position and Direction of view for the current render pass. Might be different for e.g. lighting passes ShowDebugInfo bool // Show debug info (F3 screen)? + + // Per-Frame Diagnostics information + Diagnostics struct { + CgoCalls int64 // Cgo calls in the last frame + Times struct { // Times spent + GUI, Logic, Render time.Duration + RenderPasses struct { + Depthmap, + Geometry, + SSAO, + Lighting, + Postfx time.Duration + } + } + } ) diff --git a/internal/render/render_world.go b/internal/render/render_world.go index 18c753a..854cad5 100644 --- a/internal/render/render_world.go +++ b/internal/render/render_world.go @@ -2,7 +2,6 @@ package render import ( "errors" - "math" "math/rand" "time" "unsafe" @@ -305,6 +304,9 @@ var ( ) func (r *WorldRenderer) Render(world *world.World, view *View) { + allclock := util.NewClock() + lastclock := util.NewClock() + io.RenderPos = io.ViewPos io.RenderDir = io.ViewDir @@ -337,6 +339,8 @@ func (r *WorldRenderer) Render(world *world.World, view *View) { gl.Enable(gl.DEPTH_TEST) gl.DepthFunc(gl.LESS) + lastclock.Restart() + // 1. Render to depth map gl.Viewport(0, 0, int32(ShadowmapSize[0]), int32(ShadowmapSize[1])) gl.BindFramebuffer(gl.FRAMEBUFFER, r.depthmap.fbo) @@ -356,6 +360,8 @@ func (r *WorldRenderer) Render(world *world.World, view *View) { world.Render() world.RenderWater() + io.Diagnostics.Times.RenderPasses.Depthmap = lastclock.Restart() + // 2. Geometry pass, render to G-buffer io.RenderPos = io.ViewPos io.RenderDir = io.ViewDir @@ -376,6 +382,8 @@ func (r *WorldRenderer) Render(world *world.World, view *View) { world.Render() + io.Diagnostics.Times.RenderPasses.Geometry = lastclock.Restart() + // 3/1. SSAO pass gl.BindFramebuffer(gl.FRAMEBUFFER, r.ssao.fbo) gl.ClearColor(1, 1, 1, 1) @@ -386,7 +394,6 @@ func (r *WorldRenderer) Render(world *world.World, view *View) { r.ssao.shader.SetUniformMat4("view", view.View()) r.ssao.shader.SetUniformMat4("projection", view.Perspective()) r.ssao.shader.SetUniformVec3f("viewPos", view.EyePos) - r.ssao.shader.SetUniformFloat("time", float32(time.Since(r.startTime).Seconds())) DrawScreenQuad() @@ -398,6 +405,8 @@ func (r *WorldRenderer) Render(world *world.World, view *View) { DrawScreenQuad() + io.Diagnostics.Times.RenderPasses.SSAO = lastclock.Restart() + // 4. Render the actual output with deferred lighting gl.BindFramebuffer(gl.FRAMEBUFFER, r.output.fbo) gl.ClearColor(0, 0, 0, 0) @@ -412,6 +421,8 @@ func (r *WorldRenderer) Render(world *world.World, view *View) { DrawScreenQuad() + io.Diagnostics.Times.RenderPasses.Lighting = lastclock.Restart() + // 5. Render water gl.Enable(gl.DEPTH_TEST) gl.DepthFunc(gl.LESS) @@ -445,46 +456,11 @@ func (r *WorldRenderer) Render(world *world.World, view *View) { DrawScreenQuad() - // Show G-buffers? + io.Diagnostics.Times.RenderPasses.Postfx = lastclock.Restart() + io.Diagnostics.Times.Render = allclock.Elapsed() + + // Show Information? if io.ShowDebugInfo { - imgui.SetNextWindowPosV(imgui.Vec2{X: float32(r.lastDisplaySize[0]), Y: 0}, imgui.ConditionAlways, imgui.Vec2{X: 1, Y: 0}) - if igwrap.Begin("Renderer Textures/Outputs", nil, igwrap.WindowFlagsOverlay) { - imgui.PushStyleVarVec2(imgui.StyleVarItemSpacing, imgui.Vec2{}) - - imageSize := r.lastDisplaySize.ToFloat32().Multiply(0.25) - imageSize[1] -= imgui.CurrentStyle().WindowPadding().Y / 2 - imageSize[0] = imageSize[1] / float32(r.lastDisplaySize[1]) * float32(r.lastDisplaySize[0]) - - igwrap.Image(r.gbuffer.pos, imageSize, itype.Rectf{0, 0, 1, 1}) - igwrap.Image(r.gbuffer.norm, imageSize, itype.Rectf{0, 0, 1, 1}) - igwrap.Image(r.gbuffer.color, imageSize, itype.Rectf{0, 0, 1, 1}) - igwrap.Image(r.ssao.ambient, imageSize, itype.Rectf{0, 0, 1, 1}) - - imgui.PopStyleVar() - imgui.End() - } - - if igwrap.Begin("F3", nil, 0) { - imgui.PushStyleColor(imgui.StyleColorButton, imgui.Vec4{0, 0, 0, 0.5}) - imgui.PushStyleColor(imgui.StyleColorButtonHovered, imgui.Vec4{0, 0, 0, 0.6}) - imgui.PushStyleColor(imgui.StyleColorButtonActive, imgui.Vec4{0, 0, 0, 0.8}) - igwrap.TextBlank() - isize := asset.WorldTextureAtlas.ImageSize - igwrap.TextBackground("Texture Atlas Size: (%dx%d)", isize[0], isize[1]) - imgui.SameLine() - igwrap.TextBackground("[Hover]") - if imgui.IsItemHoveredV(imgui.HoveredFlagsAllowWhenDisabled) { - _, wheely := imgui.CurrentIO().MouseWheel() - if math.Abs(float64(wheely)) > 1e-3 { - atlasScale = util.Maxf(1, atlasScale+wheely) - } - imgui.BeginTooltip() - igwrap.Image(r.texture.Handle(), isize.ToFloat32().Multiply(atlasScale), itype.Rectf{0, 0, 1, 1}) - imgui.EndTooltip() - } - - imgui.PopStyleColorV(3) - imgui.End() - } + r.renderDebugInfo() } } diff --git a/internal/render/render_world_debuginfo.go b/internal/render/render_world_debuginfo.go new file mode 100644 index 0000000..773d34b --- /dev/null +++ b/internal/render/render_world_debuginfo.go @@ -0,0 +1,56 @@ +package render + +import ( + "math" + "time" + + "edgaru089.ml/go/gl01/internal/asset" + "edgaru089.ml/go/gl01/internal/igwrap" + "edgaru089.ml/go/gl01/internal/io" + "edgaru089.ml/go/gl01/internal/util" + "edgaru089.ml/go/gl01/internal/util/itype" + "github.com/inkyblackness/imgui-go/v4" +) + +func (r *WorldRenderer) renderDebugInfo() { + // Render information + if igwrap.Begin("F3", nil, 0) { + igwrap.TextBlank() + + igwrap.TextBackground("WorldRender: lastframe %.3fms", float64(io.Diagnostics.Times.Render.Nanoseconds())/float64(time.Millisecond)) + + isize := asset.WorldTextureAtlas.ImageSize + igwrap.TextBackground("Texture Atlas Size: (%dx%d)", isize[0], isize[1]) + imgui.SameLine() + igwrap.TextBackground("[Hover]") + if imgui.IsItemHoveredV(imgui.HoveredFlagsAllowWhenDisabled) { + _, wheely := imgui.CurrentIO().MouseWheel() + if math.Abs(float64(wheely)) > 1e-3 { + atlasScale = util.Maxf(1, atlasScale+wheely) + } + imgui.BeginTooltip() + igwrap.Image(r.texture.Handle(), isize.ToFloat32().Multiply(atlasScale), itype.Rectf{0, 0, 1, 1}) + imgui.EndTooltip() + } + + imgui.End() + } + + imgui.SetNextWindowPosV(imgui.Vec2{X: float32(r.lastDisplaySize[0]), Y: 0}, imgui.ConditionAlways, imgui.Vec2{X: 1, Y: 0}) + if igwrap.Begin("Renderer Textures/Outputs", nil, igwrap.WindowFlagsOverlay) { + imgui.PushStyleVarVec2(imgui.StyleVarItemSpacing, imgui.Vec2{}) + + imageSize := r.lastDisplaySize.ToFloat32().Multiply(0.25) + imageSize[1] -= imgui.CurrentStyle().WindowPadding().Y / 2 + imageSize[0] = imageSize[1] / float32(r.lastDisplaySize[1]) * float32(r.lastDisplaySize[0]) + + igwrap.Image(r.gbuffer.pos, imageSize, itype.Rectf{0, 0, 1, 1}) + igwrap.Image(r.gbuffer.norm, imageSize, itype.Rectf{0, 0, 1, 1}) + igwrap.Image(r.gbuffer.color, imageSize, itype.Rectf{0, 0, 1, 1}) + igwrap.Image(r.ssao.ambient, imageSize, itype.Rectf{0, 0, 1, 1}) + + imgui.PopStyleVar() + imgui.End() + } + +} diff --git a/internal/util/clock.go b/internal/util/clock.go new file mode 100644 index 0000000..918a12d --- /dev/null +++ b/internal/util/clock.go @@ -0,0 +1,28 @@ +package util + +import "time" + +// Clock is a clock to measure elapsed time. +// It is a shorthand for the time.Since() and time.Now() combo. +type Clock struct { + t time.Time +} + +// NewClock returns a new clock. +// It also starts it. +func NewClock() (c *Clock) { + return &Clock{t: time.Now()} +} + +// Restart resets the start time. +// It also returns the elapsed time. +func (c *Clock) Restart() (t time.Duration) { + t = time.Since(c.t) + c.t = time.Now() + return +} + +// Elapsed returns the elapsed time. +func (c *Clock) Elapsed() time.Duration { + return time.Since(c.t) +}