Add verbose logging

4 files changed, 380 insertions, 3 deletions

diff --git a/CMakeLists.txt b/CMakeLists.txt
index 96ac035..3bde961 100644
--- a/CMakeLists.txt
+++ b/CMakeLists.txt
@@ -2,7 +2,7 @@ cmake_minimum_required(VERSION 3.13)
 project(ur-sfml)
 set(CMAKE_CXX_STANDARD 20)
 set(EXECUTABLE_NAME ur)
-
+set(CMAKE_CXX_FLAGS_DEBUG -DDEBUG)
 # detect windows
 if (WIN32)
   set(SFML_DIR /home/senders/Downloads/SFML-2.5.1/lib/cmake/SFML)
diff --git a/README.md b/README.md
index db32d1b..e9b13b0 100644
--- a/README.md
+++ b/README.md
@@ -59,3 +59,10 @@ make
 
 You can run your windows build via wine64 by bundling your dll and the res folder along side the exe.
 
+### Debug
+
+To enable debug logging use the cmake flags:
+
+```
+cmake -DCMAKE_BUILD_TYPE=Debug
+```
diff --git a/src/log.hpp b/src/log.hpp
new file mode 100644
index 0000000..fcc4e75
--- /dev/null
+++ b/src/log.hpp
@@ -0,0 +1,352 @@
+#ifndef UR_LOG_H
+#define UR_LOG_H
+
+#include "helper.hpp"
+#include <iostream>
+#include <ctime>
+#include <string>
+/**
+ * A very simple stdio/stderr logger
+ */
+namespace Log {
+
+// if we want debug to action
+// will be noop fork, but cleaner for a simple program
+#ifdef DEBUG
+static const bool is_debug = true;
+#else
+static const bool is_debug = false;
+#endif
+// log message constants
+static const std::string L_INFO = "[INFO]";
+static const std::string L_ERROR = "[ERROR]";
+static const std::string L_WARN = "[WARN]";
+static const std::string L_DEBUG = "[DEBUG]";
+
+// wrap <string> to_string to keep all semantics within the log namespace
+//
+// UR SPECIFIC CODE
+std::string
+str(GameState gs)
+{
+  switch (gs) {
+    case WAITING:
+      return "WAITING";
+    case ROLLING:
+      return "ROLLING";
+    case PASSING:
+      return "PASSING";
+    case PLACING:
+      return "PLACING";
+    case GAME_OVER:
+      return "GAME_OVER";
+    default:
+      return "Unknown state: " + std::to_string(gs);
+  }
+}
+// END UR SPECIFIC CODE
+std::string
+str(int i)
+{
+  return std::to_string(i);
+}
+std::string
+str(long i)
+{
+  return std::to_string(i);
+}
+std::string
+str(long long i)
+{
+  return std::to_string(i);
+}
+std::string
+str(unsigned i)
+{
+  return std::to_string(i);
+}
+std::string
+str(unsigned long i)
+{
+  return std::to_string(i);
+}
+std::string
+str(unsigned long long i)
+{
+  return std::to_string(i);
+}
+std::string
+str(float i)
+{
+  return std::to_string(i);
+}
+std::string
+str(double i)
+{
+  return std::to_string(i);
+}
+std::string
+str(long double i)
+{
+  return std::to_string(i);
+}
+// end to_string
+
+// helper functions
+std::string
+now()
+{
+  std::time_t current_time;
+  std::time(&current_time);
+  char now[25];
+  std::strftime(now, sizeof(now), "%FT%T %Z", std::localtime(&current_time));
+
+  return std::string(now);
+}
+// end helper fns
+
+// log functions
+void
+log(std::string msg, std::string level)
+{
+  std::clog << now() << "\t" << level << "\t" << msg << std::endl;
+}
+
+void
+log_d(std::string msg)
+{
+  if (is_debug) {
+    log(msg, L_DEBUG);
+  }
+}
+// end log fns
+
+// DEBUG
+void
+debug()
+{
+  log_d("");
+}
+void
+debug(int msg)
+{
+  log_d(str(msg));
+}
+void
+debug(long msg)
+{
+  log_d(str(msg));
+}
+void
+debug(long long msg)
+{
+  log_d(str(msg));
+}
+void
+debug(unsigned msg)
+{
+  log_d(str(msg));
+}
+void
+debug(unsigned long msg)
+{
+  log_d(str(msg));
+}
+void
+debug(unsigned long long msg)
+{
+  log_d(str(msg));
+}
+void
+debug(float msg)
+{
+  log_d(str(msg));
+}
+void
+debug(double msg)
+{
+  log_d(str(msg));
+}
+void
+debug(long double msg)
+{
+  log_d(str(msg));
+}
+void
+debug(std::string msg)
+{
+  log_d(msg);
+}
+
+// L_INFO
+void
+info()
+{
+  log("", L_INFO);
+}
+void
+info(int msg)
+{
+  log(str(msg), L_INFO);
+}
+void
+info(long msg)
+{
+  log(str(msg), L_INFO);
+}
+void
+info(long long msg)
+{
+  log(str(msg), L_INFO);
+}
+void
+info(unsigned msg)
+{
+  log(str(msg), L_INFO);
+}
+void
+info(unsigned long msg)
+{
+  log(str(msg), L_INFO);
+}
+void
+info(unsigned long long msg)
+{
+  log(str(msg), L_INFO);
+}
+void
+info(float msg)
+{
+  log(str(msg), L_INFO);
+}
+void
+info(double msg)
+{
+  log(str(msg), L_INFO);
+}
+void
+info(long double msg)
+{
+  log(str(msg), L_INFO);
+}
+void
+info(std::string msg)
+{
+  log(msg, L_INFO);
+}
+
+// L_WARN
+void
+warn()
+{
+  log("", L_WARN);
+}
+void
+warn(int msg)
+{
+  log(str(msg), L_WARN);
+}
+void
+warn(long msg)
+{
+  log(str(msg), L_WARN);
+}
+void
+warn(long long msg)
+{
+  log(str(msg), L_WARN);
+}
+void
+warn(unsigned msg)
+{
+  log(str(msg), L_WARN);
+}
+void
+warn(unsigned long msg)
+{
+  log(str(msg), L_WARN);
+}
+void
+warn(unsigned long long msg)
+{
+  log(str(msg), L_WARN);
+}
+void
+warn(float msg)
+{
+  log(str(msg), L_WARN);
+}
+void
+warn(double msg)
+{
+  log(str(msg), L_WARN);
+}
+void
+warn(long double msg)
+{
+  log(str(msg), L_WARN);
+}
+void
+warn(std::string msg)
+{
+  log(msg, L_WARN);
+}
+
+// L_ERROR
+void
+error()
+{
+  log("", L_ERROR);
+}
+void
+error(int msg)
+{
+  log(str(msg), L_ERROR);
+}
+void
+error(long msg)
+{
+  log(str(msg), L_ERROR);
+}
+void
+error(long long msg)
+{
+  log(str(msg), L_ERROR);
+}
+void
+error(unsigned msg)
+{
+  log(str(msg), L_ERROR);
+}
+void
+error(unsigned long msg)
+{
+  log(str(msg), L_ERROR);
+}
+void
+error(unsigned long long msg)
+{
+  log(str(msg), L_ERROR);
+}
+void
+error(float msg)
+{
+  log(str(msg), L_ERROR);
+}
+void
+error(double msg)
+{
+  log(str(msg), L_ERROR);
+}
+void
+error(long double msg)
+{
+  log(str(msg), L_ERROR);
+}
+void
+error(std::string msg)
+{
+  log(msg, L_ERROR);
+}
+}
+#endif
diff --git a/src/ur.cpp b/src/ur.cpp
index 9d42bd7..db9fca6 100644
--- a/src/ur.cpp
+++ b/src/ur.cpp
@@ -1,5 +1,6 @@
 #include "helper.hpp"
 #include "icon.h"
+#include "log.hpp"
 #include "random.hpp"
 #include "timedLatch.hpp"
 #include <SFML/Graphics.hpp>
@@ -26,7 +27,7 @@ bool mouse_left_locked = false;
 inline void
 change_state(GameState next)
 {
-  std::cout << "GameState == " << next << std::endl;
+  Log::debug("Changing state " + Log::str(next));
   prev_state = state;
   state = next;
 }
@@ -60,6 +61,7 @@ inline void
 next_turn(std::shared_ptr<std::vector<sf::Sprite>> roll_sprites)
 {
   turn_pid = turn_pid == P1_ID ? P2_ID : P1_ID;
+  Log::debug(turn_pid == P1_ID ? "P1 Turn" : "P2 Turn");
   reset_turn(roll_sprites);
 }
 
@@ -102,10 +104,13 @@ render_dice(sf::RenderWindow* window,
     for (int r : rolls) {
       turn_roll += r;
     }
+    Log::debug("Roll result " + Log::str(turn_roll));
     makeNum(roll_result, turn_roll, textures);
     if (turn_roll == 0 || !hasMoves(active_player, opponent, turn_roll)) {
+      Log::debug("No move, passing");
       change_state(GameState::PASSING);
     } else {
+      Log::debug("Place a piece");
       change_state(GameState::PLACING);
     }
   }
@@ -188,6 +193,7 @@ render_dice(sf::RenderWindow* window,
 int
 main()
 {
+  Log::info("Starting ur");
   const std::shared_ptr<std::vector<sf::Texture>> textures =
     loadTextures(TEXTURE_PATH);
 
@@ -212,6 +218,7 @@ main()
   const std::shared_ptr<std::vector<sf::Sprite>> start_sprites =
     createStartSprites(textures);
 
+  Log::info("Assets loaded");
   sf::Sprite p1Score;
   p1Score.setPosition(pos(0, SPRITE_ROWS - 1));
   makeNum(&p1Score, 0, textures);
@@ -249,12 +256,14 @@ main()
   ur::TimedLatch rolling_animation_timer(sf::seconds(3));
   ur::TimedLatch rolling_animation_frame_pause_timer(sf::milliseconds(100));
 
+  Log::info("Starting game");
   while (window.isOpen()) {
 
     sf::Event event;
     while (window.pollEvent(event)) {
       if (event.type == sf::Event::Closed ||
           sf::Keyboard::isKeyPressed(sf::Keyboard::Q)) {
+        Log::info("Quiting game");
         window.close();
       }
 
@@ -270,7 +279,7 @@ main()
           for (auto& s : (*roll_sprites)) {
             // zoom sprite bounds
             if (s.getGlobalBounds().contains(mPos)) {
-              std::cout << "Roll!" << std::endl;
+              Log::debug("Rolling");
               // setup for rolling
               rolling_animation_timer.start();
               change_state(GameState::ROLLING);
@@ -294,6 +303,7 @@ main()
             if (p.sprite.getGlobalBounds().contains(mPos)) {
               grabbed_piece = &p;
               grabbed_piece_origin = grabbed_piece->sprite.getPosition();
+              Log::debug("Grabbed piece " + Log::str(grabbed_piece->id));
               break;
             }
           }
@@ -301,6 +311,7 @@ main()
           for (auto& s : (*pass_sprites)) {
             // zoom sprite bounds
             if (s.getGlobalBounds().contains(mPos)) {
+              Log::debug("Passing");
               next_turn(roll_sprites);
               break;
             }
@@ -340,6 +351,7 @@ main()
                   if (takenPieceId >= 0) {
                     for (auto& ep : (*enemyPieces)) {
                       if (ep.id == takenPieceId) {
+                        Log::debug("Captured piece " + Log::str(takenPieceId) + " returning to board side");
                         ep.sprite.setPosition(ep.origin);
                         ep.position = -1;
                       }
@@ -348,6 +360,7 @@ main()
                   grabbed_piece->sprite.setPosition(s.getPosition());
 
                   if (bp.position == (grabbed_piece->position + turn_roll)) {
+                    Log::debug("Placed piece in position " + Log::str(bp.position));
                     grabbed_piece->position = bp.position;
                     in_place = true;
                   }
@@ -362,9 +375,11 @@ main()
             if (grabbed_piece->position == EXIT_SPACE) {
               if (p1_turn()) {
                 makeNum(&p1Score, ++p1->score, textures);
+                Log::debug("P1 scored. Score " + Log::str(p1->score) + ". Clearing piece " + Log::str(grabbed_piece->id));
                 clearPiece(p1->pieces, grabbed_piece);
               } else {
                 makeNum(&p2Score, ++p2->score, textures);
+                Log::debug("P2 scored. Score " + Log::str(p2->score) + ". Clearing piece " + Log::str(grabbed_piece->id));
                 clearPiece(p2->pieces, grabbed_piece);
               }
             } else {
@@ -379,11 +394,14 @@ main()
             if (!reroll) {
               next_turn(roll_sprites);
             } else {
+              Log::debug("Player re-rolls");
               reset_turn(roll_sprites);
             }
           } else {
+            Log::debug("Resetting piece position");
             grabbed_piece->sprite.setPosition(grabbed_piece_origin);
           }
+          Log::debug("Release piece");
           grabbed_piece = nullptr;
         }
       }