From 4edd6e2f83f2ec5482959d46f360891efbfd875c Mon Sep 17 00:00:00 2001
From: NatureFreshMilk <naturefreshmilk@github.com>
Date: Fri, 11 Jan 2019 14:17:16 +0100
Subject: [PATCH] render timing

---
 .gitignore                        |  1 +
 mapblockparser/metadata.go        |  2 +-
 mapblockrenderer/logger.go        | 10 ++++++++++
 mapblockrenderer/renderer.go      | 13 +++++++++++++
 mapblockrenderer/renderer_test.go | 27 +++++++++++++++++++++++----
 5 files changed, 48 insertions(+), 5 deletions(-)
 create mode 100644 mapblockrenderer/logger.go

diff --git a/.gitignore b/.gitignore
index 803b0fa..b7541de 100644
--- a/.gitignore
+++ b/.gitignore
@@ -1,2 +1,3 @@
 mapserver
 world.mt
+output
diff --git a/mapblockparser/metadata.go b/mapblockparser/metadata.go
index 870cbc8..5c22e8f 100644
--- a/mapblockparser/metadata.go
+++ b/mapblockparser/metadata.go
@@ -50,7 +50,7 @@ func parseMetadata(mapblock *MapBlock, data []byte) (int, error) {
 
 	metadata := buf.Bytes()
 
-	log.WithFields(logrus.Fields{"metadata-length": len(metadata)}).Debug("Parsing metadata")
+	log.WithFields(logrus.Fields{"metadata-length": len(metadata)}).Trace("Parsing metadata")
 
 	offset := 0
 	version := metadata[offset]
diff --git a/mapblockrenderer/logger.go b/mapblockrenderer/logger.go
new file mode 100644
index 0000000..9245403
--- /dev/null
+++ b/mapblockrenderer/logger.go
@@ -0,0 +1,10 @@
+package mapblockrenderer
+
+import (
+  "github.com/sirupsen/logrus"
+)
+
+var log *logrus.Entry
+func init(){
+	log = logrus.WithFields(logrus.Fields{"prefix": "mapblockrenderer"})
+}
diff --git a/mapblockrenderer/renderer.go b/mapblockrenderer/renderer.go
index 59861ba..7b2ebcf 100644
--- a/mapblockrenderer/renderer.go
+++ b/mapblockrenderer/renderer.go
@@ -7,6 +7,8 @@ import (
 	"image"
 	"image/draw"
 	"errors"
+	"time"
+	"github.com/sirupsen/logrus"
 )
 
 type MapBlockRenderer struct {
@@ -32,6 +34,13 @@ func (r *MapBlockRenderer) Render(pos1, pos2 coords.MapBlockCoords) (*image.NRGB
 	if pos1.Z != pos2.Z {
 		return nil, errors.New("Z does not line up")
 	}
+	
+	start := time.Now()
+	defer func(){
+		t := time.Now()
+		elapsed := t.Sub(start)
+		log.WithFields(logrus.Fields{"elapsed":elapsed}).Debug("Rendering completed")
+	}()
 
 	upLeft := image.Point{0, 0}
 	lowRight := image.Point{IMG_SIZE, IMG_SIZE}
@@ -98,5 +107,9 @@ func (r *MapBlockRenderer) Render(pos1, pos2 coords.MapBlockCoords) (*image.NRGB
 		}
 	}
 
+	if foundBlocks == 0 {
+		return nil, nil
+	}
+
 	return img, nil
 }
diff --git a/mapblockrenderer/renderer_test.go b/mapblockrenderer/renderer_test.go
index 2fa8bf2..d1cfc60 100644
--- a/mapblockrenderer/renderer_test.go
+++ b/mapblockrenderer/renderer_test.go
@@ -5,14 +5,19 @@ import (
 	"io/ioutil"
 	"mapserver/coords"
 	"testing"
+  "fmt"
 	"mapserver/testutils"
 	"mapserver/db"
   "mapserver/colormapping"
   "mapserver/mapblockaccessor"
   "image/png"
+  "github.com/sirupsen/logrus"
+  "time"
 )
 
 func TestSimpleRender(t *testing.T) {
+  logrus.SetLevel(logrus.InfoLevel)
+
   tmpfile, err := ioutil.TempFile("", "TestMigrate.*.sqlite")
   if err != nil {
     panic(err)
@@ -38,9 +43,23 @@ func TestSimpleRender(t *testing.T) {
   }
 
   r := NewMapBlockRenderer(cache, c)
-  img, _ := r.Render(coords.NewMapBlockCoords(0, 10, 0), coords.NewMapBlockCoords(0, -1, 0))
+  os.Mkdir("../output", 0755)
+
+  for x := -3; x < 3; x++ {
+    for z := -3; z < 3; z++ {
+      img, _ := r.Render(coords.NewMapBlockCoords(x, 10, z), coords.NewMapBlockCoords(x, -1, z))
+
+      if img != nil {
+        f, _ := os.Create(fmt.Sprintf("../output/image_%d_%d.png", x, z))
+        start := time.Now()
+        png.Encode(f, img)
+        f.Close()
+        t := time.Now()
+        elapsed := t.Sub(start)
+        log.WithFields(logrus.Fields{"elapsed":elapsed}).Debug("Encoding completed")
+
+      }
+    }
+  }
 
-  f, _ := os.Create("image.png")
-  png.Encode(f, img)
-  f.Close()
 }