Profiler graph

diff --git a/src/client.cpp b/src/client.cpp
index 2148bfe59b438749d52dcac8ed668c3f6e5d080f..f446200a322060ef1a5d6fae8aaee64fb941a342 100644 (file)
--- a/src/client.cpp
+++ b/src/client.cpp
@@ -656,9 +656,11 @@ void Client::step(float dtime)
                /*infostream<<"Mesh update result queue size is "
                                <<m_mesh_update_thread.m_queue_out.size()
                                <<std::endl;*/
-
+               
+               int num_processed_meshes = 0;
                while(m_mesh_update_thread.m_queue_out.size() > 0)
                {
+                       num_processed_meshes++;
                        MeshUpdateResult r = m_mesh_update_thread.m_queue_out.pop_front();
                        MapBlock *block = m_env.getMap().getBlockNoCreateNoEx(r.p);
                        if(block)
@@ -699,6 +701,8 @@ void Client::step(float dtime)
                                m_con.Send(PEER_ID_SERVER, 1, reply, true);
                        }
                }
+               if(num_processed_meshes > 0)
+                       g_profiler->graphAdd("num_processed_meshes", num_processed_meshes);
        }
 
        /*
@@ -752,6 +756,7 @@ void Client::ReceiveAll()
                
                try{
                        Receive();
+                       g_profiler->graphAdd("client_received_packets", 1);
                }
                catch(con::NoIncomingDataException &e)
                {

diff --git a/src/game.cpp b/src/game.cpp
index 04b9f105d505b4b107f9e471826277ab270c43fa..49f4b4ad902338cfb748a02a8c9f365af679f8cd 100644 (file)
--- a/src/game.cpp
+++ b/src/game.cpp
@@ -55,6 +55,7 @@ with this program; if not, write to the Free Software Foundation, Inc.,
 #include "quicktune_shortcutter.h"
 #include "clientmap.h"
 #include "sky.h"
+#include <list>
 
 /*
        Setting this to 1 enables a special camera mode that forces
@@ -602,6 +603,159 @@ void update_profiler_gui(gui::IGUIStaticText *guitext_profiler,
        }
 }
 
+class ProfilerGraph
+{
+private:
+       struct Piece{
+               Profiler::GraphValues values;
+       };
+       struct Meta{
+               float min;
+               float max;
+               video::SColor color;
+               Meta(float initial=0, video::SColor color=
+                               video::SColor(255,255,255,255)):
+                       min(initial),
+                       max(initial),
+                       color(color)
+               {}
+       };
+       std::list<Piece> m_log;
+public:
+       u32 m_log_max_size;
+
+       ProfilerGraph():
+               m_log_max_size(200)
+       {}
+
+       void put(const Profiler::GraphValues &values)
+       {
+               Piece piece;
+               piece.values = values;
+               m_log.push_back(piece);
+               while(m_log.size() > m_log_max_size)
+                       m_log.erase(m_log.begin());
+       }
+       
+       void draw(s32 x_left, s32 y_bottom, video::IVideoDriver *driver,
+                       gui::IGUIFont* font) const
+       {
+               std::map<std::string, Meta> m_meta;
+               for(std::list<Piece>::const_iterator k = m_log.begin();
+                               k != m_log.end(); k++)
+               {
+                       const Piece &piece = *k;
+                       for(Profiler::GraphValues::const_iterator i = piece.values.begin();
+                                       i != piece.values.end(); i++){
+                               const std::string &id = i->first;
+                               const float &value = i->second;
+                               std::map<std::string, Meta>::iterator j =
+                                               m_meta.find(id);
+                               if(j == m_meta.end()){
+                                       m_meta[id] = Meta(value);
+                                       continue;
+                               }
+                               if(value < j->second.min)
+                                       j->second.min = value;
+                               if(value > j->second.max)
+                                       j->second.max = value;
+                       }
+               }
+
+               // Assign colors
+               static const video::SColor usable_colors[] = {
+                       video::SColor(255,255,100,100),
+                       video::SColor(255,90,225,90),
+                       video::SColor(255,100,100,255)
+               };
+               static const u32 usable_colors_count =
+                               sizeof(usable_colors) / sizeof(*usable_colors);
+               u32 next_color_i = 0;
+               for(std::map<std::string, Meta>::iterator i = m_meta.begin();
+                               i != m_meta.end(); i++){
+                       Meta &meta = i->second;
+                       video::SColor color(255,200,200,200);
+                       if(next_color_i < usable_colors_count)
+                               color = usable_colors[next_color_i++];
+                       meta.color = color;
+               }
+
+               s32 graphh = 50;
+               s32 textx = x_left + m_log_max_size + 15;
+               s32 textx2 = textx + 200 - 15;
+               
+               // Draw background
+               /*{
+                       u32 num_graphs = m_meta.size();
+                       core::rect<s32> rect(x_left, y_bottom - num_graphs*graphh,
+                                       textx2, y_bottom);
+                       video::SColor bgcolor(120,0,0,0);
+                       driver->draw2DRectangle(bgcolor, rect, NULL);
+               }*/
+               
+               s32 meta_i = 0;
+               for(std::map<std::string, Meta>::const_iterator i = m_meta.begin();
+                               i != m_meta.end(); i++){
+                       const std::string &id = i->first;
+                       const Meta &meta = i->second;
+                       s32 x = x_left;
+                       s32 y = y_bottom - meta_i * 50;
+                       float show_min = meta.min;
+                       float show_max = meta.max;
+                       if(show_min >= 0 && show_max >= 0){
+                               if(show_min <= show_max * 0.5)
+                                       show_min = 0;
+                       }
+                       s32 texth = 15;
+                       char buf[10];
+                       snprintf(buf, 10, "%.3g", show_max);
+                       font->draw(narrow_to_wide(buf).c_str(),
+                                       core::rect<s32>(textx, y - graphh,
+                                       textx2, y - graphh + texth),
+                                       meta.color);
+                       snprintf(buf, 10, "%.3g", show_min);
+                       font->draw(narrow_to_wide(buf).c_str(),
+                                       core::rect<s32>(textx, y - texth,
+                                       textx2, y),
+                                       meta.color);
+                       font->draw(narrow_to_wide(id).c_str(),
+                                       core::rect<s32>(textx, y - graphh/2 - texth/2,
+                                       textx2, y - graphh/2 + texth/2),
+                                       meta.color);
+                       for(std::list<Piece>::const_iterator j = m_log.begin();
+                                       j != m_log.end(); j++)
+                       {
+                               const Piece &piece = *j;
+                               float value = 0;
+                               bool value_exists = false;
+                               Profiler::GraphValues::const_iterator k =
+                                               piece.values.find(id);
+                               if(k != piece.values.end()){
+                                       value = k->second;
+                                       value_exists = true;
+                               }
+                               if(!value_exists){
+                                       x++;
+                                       continue;
+                               }
+                               float scaledvalue = 1.0;
+                               if(show_max != show_min)
+                                       scaledvalue = (value - show_min) / (show_max - show_min);
+                               if(scaledvalue == 1.0 && value == 0){
+                                       x++;
+                                       continue;
+                               }
+                               s32 ivalue = scaledvalue * graphh;
+                               driver->draw2DLine(v2s32(x, y),
+                                               v2s32(x, y - ivalue),
+                                               meta.color);
+                               x++;
+                       }
+                       meta_i++;
+               }
+       }
+};
+
 void the_game(
        bool &kill,
        bool random_input,
@@ -938,7 +1092,7 @@ void the_game(
                        L"<Profiler>",
                        core::rect<s32>(0,0,0,0),
                        false, false);
-       guitext_profiler->setBackgroundColor(video::SColor(80,0,0,0));
+       guitext_profiler->setBackgroundColor(video::SColor(120,0,0,0));
        guitext_profiler->setVisible(false);
        
        /*GUIQuickInventory *quick_inventory = new GUIQuickInventory
@@ -968,13 +1122,14 @@ void the_game(
        u32 beginscenetime = 0;
        u32 scenetime = 0;
        u32 endscenetime = 0;
+       u32 alltime = 0;
        
        // A test
        //throw con::PeerNotFoundException("lol");
 
        float recent_turn_speed = 0.0;
-
-       core::list<float> frametime_log;
+       
+       ProfilerGraph graph;
 
        float nodig_delay_timer = 0.0;
        float dig_time = 0.0;
@@ -1000,7 +1155,7 @@ void the_game(
        bool force_fog_off = false;
        bool disable_camera_update = false;
        bool show_debug = g_settings->getBool("show_debug");
-       bool show_debug_frametime = false;
+       bool show_profiler_graph = false;
        u32 show_profiler = 0;
        u32 show_profiler_max = 3;  // Number of pages
 
@@ -1022,9 +1177,12 @@ void the_game(
        // NOTE: So we have to use getTime() and call run()s between them
        u32 lasttime = device->getTimer()->getTime();
 
-       while(device->run() && kill == false)
+       for(;;)
        {
-               //std::cerr<<"frame"<<std::endl;
+               TimeTaker tt_all("mainloop: all");
+
+               if(device->run() == false || kill == true)
+                       break;
 
                if(client.accessDenied())
                {
@@ -1142,16 +1300,6 @@ void the_game(
                g_profiler->add("Elapsed time", dtime);
                g_profiler->avg("FPS", 1./dtime);
 
-               /*
-                       Log frametime for visualization
-               */
-               frametime_log.push_back(dtime);
-               if(frametime_log.size() > 100)
-               {
-                       core::list<float>::Iterator i = frametime_log.begin();
-                       frametime_log.erase(i);
-               }
-
                /*
                        Visualize frametime in terminal
                */
@@ -1434,25 +1582,25 @@ void the_game(
                {
                        // Initial / 3x toggle: Chat only
                        // 1x toggle: Debug text with chat
-                       // 2x toggle: Debug text with frametime
+                       // 2x toggle: Debug text with profiler graph
                        if(!show_debug)
                        {
                                show_debug = true;
-                               show_debug_frametime = false;
+                               show_profiler_graph = false;
                                statustext = L"Debug info shown";
                                statustext_time = 0;
                        }
-                       else if(show_debug_frametime)
+                       else if(show_profiler_graph)
                        {
                                show_debug = false;
-                               show_debug_frametime = false;
-                               statustext = L"Debug info and frametime graph hidden";
+                               show_profiler_graph = false;
+                               statustext = L"Debug info and profiler graph hidden";
                                statustext_time = 0;
                        }
                        else
                        {
-                               show_debug_frametime = true;
-                               statustext = L"Frametime graph shown";
+                               show_profiler_graph = true;
+                               statustext = L"Profiler graph shown";
                                statustext_time = 0;
                        }
                }
@@ -2413,7 +2561,7 @@ void the_game(
                        Drawing begins
                */
 
-               TimeTaker drawtimer("Drawing");
+               TimeTaker tt_draw("mainloop: draw");
 
                
                {
@@ -2479,22 +2627,11 @@ void the_game(
                }
 
                /*
-                       Frametime log
+                       Profiler graph
                */
-               if(show_debug_frametime)
-               {
-                       s32 x = 10;
-                       s32 y = screensize.Y - 10;
-                       for(core::list<float>::Iterator
-                                       i = frametime_log.begin();
-                                       i != frametime_log.end();
-                                       i++)
-                       {
-                               driver->draw2DLine(v2s32(x,y),
-                                               v2s32(x,y-(*i)*1000),
-                                               video::SColor(255,255,255,255));
-                               x++;
-                       }
+               if(show_profiler_graph)
+               {
+                       graph.draw(10, screensize.Y - 10, driver, font);
                }
 
                /*
@@ -2559,7 +2696,8 @@ void the_game(
                        endscenetime = timer.stop(true);
                }
 
-               drawtime = drawtimer.stop(true);
+               drawtime = tt_draw.stop(true);
+               g_profiler->graphAdd("mainloop_draw", (float)drawtime/1000.0f);
 
                /*
                        End of drawing
@@ -2579,6 +2717,16 @@ void the_game(
                        device->setWindowCaption(str.c_str());
                        lastFPS = fps;
                }
+
+               alltime = tt_all.stop(true);
+               g_profiler->graphAdd("mainloop_other", (float)(alltime-drawtime)/1000.0f);
+
+               /*
+                       Log times and stuff for visualization
+               */
+               Profiler::GraphValues values;
+               g_profiler->graphGet(values);
+               graph.put(values);
        }
 
        /*

diff --git a/src/profiler.h b/src/profiler.h
index 7bb3b37508aa2b022762601ae7fc20a2f1ddd63a..938742f225dcf460097667f6c3480da7ee9e97db 100644 (file)
--- a/src/profiler.h
+++ b/src/profiler.h
@@ -25,6 +25,7 @@ with this program; if not, write to the Free Software Foundation, Inc.,
 #include "utility.h"
 #include <jmutex.h>
 #include <jmutexautolock.h>
+#include <map>
 
 /*
        Time profiler
@@ -146,10 +147,30 @@ class Profiler
                }
        }
 
+       typedef std::map<std::string, float> GraphValues;
+
+       void graphAdd(const std::string &id, float value)
+       {
+               JMutexAutoLock lock(m_mutex);
+               std::map<std::string, float>::iterator i =
+                               m_graphvalues.find(id);
+               if(i == m_graphvalues.end())
+                       m_graphvalues[id] = value;
+               else
+                       i->second += value;
+       }
+       void graphGet(GraphValues &result)
+       {
+               JMutexAutoLock lock(m_mutex);
+               result = m_graphvalues;
+               m_graphvalues.clear();
+       }
+
 private:
        JMutex m_mutex;
        core::map<std::string, float> m_data;
        core::map<std::string, int> m_avgcounts;
+       std::map<std::string, float> m_graphvalues;
 };
 
 enum ScopeProfilerType{