Ticket #4056: Profiler2.2.patch

source/ps/Profiler2.cpp

@@ -31 +31 @@
 #include "third_party/mongoose/mongoose.h"
 
 #include <iomanip>
+#include <unordered_map>
 
 CProfiler2 g_Profiler2;
 
@@ -80 +81 @@
         std::stringstream stream;
 
         std::string uri = request_info->uri;
-        if (uri == "/overview")
+
+        if (uri == "/download")
         {
+            profiler->SaveToFile();
+        }
+        else if (uri == "/overview")
+        {
             profiler->ConstructJSONOverview(stream);
         }
         else if (uri == "/query")
@@ -191 +197 @@
 void CProfiler2::ShutDownHTTP()
 {
     LOGMESSAGERENDER("Shutting down profiler2 HTTP server");
+
     if (m_MgContext)
     {
         mg_stop(m_MgContext);
@@ -219 +226 @@
 
     ENSURE(!m_GPU); // must shutdown GPU before profiler
 
+    SaveToFile();
+
     if (m_MgContext)
     {
         mg_stop(m_MgContext);
@@ -301 +310 @@
 }
 
 CProfiler2::ThreadStorage::ThreadStorage(CProfiler2& profiler, const std::string& name) :
-    m_Profiler(profiler), m_Name(name), m_BufferPos0(0), m_BufferPos1(0), m_LastTime(timer_Time())
+m_Profiler(profiler), m_Name(name), m_BufferPos0(0), m_BufferPos1(0), m_LastTime(timer_Time()), m_HeldDepth(0)
 {
     m_Buffer = new u8[BUFFER_SIZE];
     memset(m_Buffer, ITEM_NOP, BUFFER_SIZE);
@@ -312 +321 @@
     delete[] m_Buffer;
 }
 
+void CProfiler2::ThreadStorage::Write(EItem type, const void* item, u32 itemSize)
+{
+    if (m_HeldDepth > 0)
+    {
+        WriteHold(type, item, itemSize);
+        return;
+    }
+    // See m_BufferPos0 etc for comments on synchronisation
+
+    u32 size = 1 + itemSize;
+    u32 start = m_BufferPos0;
+    if (start + size > BUFFER_SIZE)
+    {
+        // The remainder of the buffer is too small - fill the rest
+        // with NOPs then start from offset 0, so we don't have to
+        // bother splitting the real item across the end of the buffer
+
+        m_BufferPos0 = size;
+        COMPILER_FENCE; // must write m_BufferPos0 before m_Buffer
+
+        memset(m_Buffer + start, 0, BUFFER_SIZE - start);
+        start = 0;
+    }
+    else
+    {
+        m_BufferPos0 = start + size;
+        COMPILER_FENCE; // must write m_BufferPos0 before m_Buffer
+    }
+
+    m_Buffer[start] = (u8)type;
+    memcpy(&m_Buffer[start + 1], item, itemSize);
+
+    COMPILER_FENCE; // must write m_BufferPos1 after m_Buffer
+    m_BufferPos1 = start + size;
+}
+
+void CProfiler2::ThreadStorage::WriteHold(EItem type, const void* item, u32 itemSize)
+{
+    u32 size = 1 + itemSize;
+
+    if (m_HoldBuffers[m_HeldDepth - 1].pos + size > CProfiler2::HOLD_BUFFER_SIZE)
+        return; // we held on too much data, ignore the rest
+
+    m_HoldBuffers[m_HeldDepth - 1].buffer[m_HoldBuffers[m_HeldDepth - 1].pos] = (u8)type;
+    memcpy(&m_HoldBuffers[m_HeldDepth - 1].buffer[m_HoldBuffers[m_HeldDepth - 1].pos + 1], item, itemSize);
+
+    m_HoldBuffers[m_HeldDepth - 1].pos += size;
+}
+
 std::string CProfiler2::ThreadStorage::GetBuffer()
 {
     // Called from an arbitrary thread (not the one writing to the buffer).
@@ -355 +413 @@
     Write(ITEM_ATTRIBUTE, buffer, 4 + len);
 }
 
+size_t CProfiler2::ThreadStorage::HoldLevel()
+{
+    return m_HeldDepth;
+}
 
+u8 CProfiler2::ThreadStorage::HoldType()
+{
+    return m_HoldBuffers[m_HeldDepth - 1].type;
+}
+
+void CProfiler2::ThreadStorage::PutOnHold(u8 newType)
+{
+    m_HeldDepth++;
+    m_HoldBuffers[m_HeldDepth - 1].clear();
+    m_HoldBuffers[m_HeldDepth - 1].setType(newType);
+}
+
+// this flattens the stack, use it sensibly
+void rewriteBuffer(u8* buffer, u32& bufferSize)
+{
+    double startTime = timer_Time();
+
+    u32 size = bufferSize;
+    u32 readPos = 0;
+
+    double initialTime = -1;
+    double total_time = -1;
+    const char* regionName;
+    std::set<std::string> topLevelArgs;
+
+    typedef std::tuple<const char*, double, std::set<std::string> > infoPerType;
+    std::unordered_map<std::string, infoPerType> timeByType;
+    std::vector<double> last_time_stack;
+    std::vector<const char*> last_names;
+
+    // never too many hacks
+    std::string current_attribute = "";
+    std::map<std::string, double> time_per_attribute;
+
+    // Let's read the first event
+    {
+        u8 type = buffer[readPos];
+        ++readPos;
+        if (type != CProfiler2::ITEM_ENTER)
+        {
+            debug_warn("Profiler2: Condensing a region should run into ITEM_ENTER first");
+            return; // do nothing
+        }
+        CProfiler2::SItem_dt_id item;
+        memcpy(&item, buffer + readPos, sizeof(item));
+        readPos += sizeof(item);
+
+        regionName = item.id;
+        last_names.push_back(item.id);
+        initialTime = (double)item.dt;
+    }
+    int enter = 1;
+    int leaves = 0;
+    // Read subsequent events. Flatten hierarchy because it would get too complicated otherwise.
+    // To make sure time doesn't bloat, subtract time from nested events
+    while (readPos < size)
+    {
+        u8 type = buffer[readPos];
+        ++readPos;
+
+        switch (type)
+        {
+        case CProfiler2::ITEM_NOP:
+        {
+            // ignore
+            break;
+        }
+        case CProfiler2::ITEM_SYNC:
+        {
+            debug_warn("Aggregated regions should not be used across frames");
+            // still try to act sane
+            readPos += sizeof(double);
+            readPos += sizeof(CProfiler2::RESYNC_MAGIC);
+            break;
+        }
+        case CProfiler2::ITEM_EVENT:
+        {
+            // skip for now
+            readPos += sizeof(CProfiler2::SItem_dt_id);
+            break;
+        }
+        case CProfiler2::ITEM_ENTER:
+        {
+            enter++;
+            CProfiler2::SItem_dt_id item;
+            memcpy(&item, buffer + readPos, sizeof(item));
+            readPos += sizeof(item);
+            last_time_stack.push_back((double)item.dt);
+            last_names.push_back(item.id);
+            current_attribute = "";
+            break;
+        }
+        case CProfiler2::ITEM_LEAVE:
+        {
+            CProfiler2::SItem_dt_id item;
+            memcpy(&item, buffer + readPos, sizeof(item));
+            readPos += sizeof(item);
+
+            leaves++;
+            if (last_names.empty())
+            {
+                // we somehow lost the first entry in the process
+                debug_warn("alert %i %i %li", readPos, enter, holdLevel);
+            }
+
+            last_names.pop_back();
+
+            if (last_time_stack.empty())
+            {
+                // this is the leave for the whole scope
+                total_time = item.dt;
+                break;
+            }
+            double time = (double)item.dt - last_time_stack.back();
+
+            std::string name = std::string(item.id);
+            auto TimeForType = timeByType.find(name);
+            if (TimeForType == timeByType.end())
+            {
+                // keep reference to the original char pointer to make sure we don't break things down the line
+                std::get<0>(timeByType[name]) = item.id;
+                std::get<1>(timeByType[name]) = 0;
+            }
+            std::get<1>(timeByType[name]) += time;
+
+            last_time_stack.pop_back();
+            // if we were nested, subtract our time from the below scope by making it look like it starts later
+            if (!last_time_stack.empty())
+                last_time_stack.back() += time;
+
+            if (!current_attribute.empty())
+            {
+                time_per_attribute[current_attribute] += time;
+            }
+
+            break;
+        }
+        case CProfiler2::ITEM_ATTRIBUTE:
+        {
+            // skip for now
+            u32 len;
+            memcpy(&len, buffer + readPos, sizeof(len));
+            ENSURE(len <= CProfiler2::MAX_ATTRIBUTE_LENGTH);
+            readPos += sizeof(len);
+            
+            char message[CProfiler2::MAX_ATTRIBUTE_LENGTH] = {0};
+            memcpy(&message[0], buffer + readPos, len);
+            CStr mess = CStr((const char*)message, len);
+            if (!last_names.empty())
+            {
+                auto it = timeByType.find(std::string(last_names.back()));
+                if (it == timeByType.end())
+                    topLevelArgs.insert(mess);
+                else
+                    std::get<2>(timeByType[std::string(last_names.back())]).insert(mess);
+            }
+            readPos += len;
+            current_attribute = mess;
+            break;
+        }
+        default:
+            debug_warn(L"Invalid profiler item when parsing buffer");
+            continue;
+        }
+    }
+
+    // rewrite the buffer
+    // what we rewrite will always be smaller than the current buffer's size
+    u32 writePos = 0;
+    double curTime = initialTime;
+    // the region enter
+    {
+        CProfiler2::SItem_dt_id item = { curTime, regionName };
+        buffer[writePos] = (u8)CProfiler2::ITEM_ENTER;
+        memcpy(buffer + writePos + 1, &item, sizeof(item));
+        writePos += sizeof(item) + 1;
+        // add a nanosecond for sanity
+        curTime += 0.000001;
+    }
+    // sub-events, aggregated
+    for (auto& type : timeByType)
+    {
+        CProfiler2::SItem_dt_id item = { curTime, std::get<0>(type.second) };
+        buffer[writePos] = (u8)CProfiler2::ITEM_ENTER;
+        memcpy(buffer + writePos + 1, &item, sizeof(item));
+        writePos += sizeof(item) + 1;
+
+        // write relevant attributes if present
+        for (const auto& attrib : std::get<2>(type.second))
+        {
+            buffer[writePos] = (u8)CProfiler2::ITEM_ATTRIBUTE;
+            writePos++;
+            std::string basic = attrib;
+            auto time_attrib = time_per_attribute.find(attrib);
+            if (time_attrib != time_per_attribute.end())
+                basic += " " + CStr::FromInt(1000000*time_attrib->second) + "us";
+
+            u32 length = basic.size();
+            memcpy(buffer + writePos, &length, sizeof(length));
+            writePos += sizeof(length);
+            memcpy(buffer + writePos, basic.c_str(), length);
+            writePos += length;
+        }
+
+        curTime += std::get<1>(type.second);
+        item.dt = curTime;
+        buffer[writePos] = (u8)CProfiler2::ITEM_LEAVE;
+        memcpy(buffer + writePos + 1, &item, sizeof(item));
+        writePos += sizeof(item) + 1;
+    }
+    // the region leave
+    {
+        if (total_time < 0)
+        {
+            total_time = curTime + 0.000001;
+
+            buffer[writePos] = (u8)CProfiler2::ITEM_ATTRIBUTE;
+            writePos++;
+            u32 length = sizeof("buffer overflow");
+            memcpy(buffer + writePos, &length, sizeof(length));
+            writePos += sizeof(length);
+            memcpy(buffer + writePos, "buffer overflow", length);
+            writePos += length;
+        }
+        else if (total_time < curTime)
+        {
+            // this seems to happen on rare occasions.
+            curTime = total_time;
+        }
+        CProfiler2::SItem_dt_id item = { total_time, regionName };
+        buffer[writePos] = (u8)CProfiler2::ITEM_LEAVE;
+        memcpy(buffer + writePos + 1, &item, sizeof(item));
+        writePos += sizeof(item) + 1;
+    }
+    // Time of computation
+    {
+        CProfiler2::SItem_dt_id item = { curTime, "CondenseBuffer" };
+        buffer[writePos] = (u8)CProfiler2::ITEM_ENTER;
+        memcpy(buffer + writePos + 1, &item, sizeof(item));
+        writePos += sizeof(item) + 1;
+    }
+    {
+        CProfiler2::SItem_dt_id item = { curTime + timer_Time() - startTime, "CondenseBuffer" };
+        buffer[writePos] = (u8)CProfiler2::ITEM_LEAVE;
+        memcpy(buffer + writePos + 1, &item, sizeof(item));
+        writePos += sizeof(item) + 1;
+        // add a nanosecond for sanity
+        curTime += 0.000001;
+    }
+    bufferSize = writePos;
+}
+
+void CProfiler2::ThreadStorage::HoldToBuffer(bool condensed)
+{
+    ENSURE(m_HeldDepth);
+    if (condensed)
+    {
+        // rewrite the buffer to show aggregated data
+        rewriteBuffer(m_HoldBuffers[m_HeldDepth - 1].buffer, m_HoldBuffers[m_HeldDepth - 1].pos);
+    }
+
+    if (m_HeldDepth > 1)
+    {
+        // copy onto buffer below
+        HoldBuffer& copied = m_HoldBuffers[m_HeldDepth - 1];
+        HoldBuffer& target = m_HoldBuffers[m_HeldDepth - 2];
+        if (target.pos + copied.pos > HOLD_BUFFER_SIZE)
+            return; // too much data, too bad
+
+        memcpy(&target.buffer[target.pos], copied.buffer, copied.pos);
+
+        target.pos += copied.pos;
+    }
+    else
+    {
+        u32 size = m_HoldBuffers[m_HeldDepth - 1].pos;
+        u32 start = m_BufferPos0;
+        if (start + size > BUFFER_SIZE)
+        {
+            m_BufferPos0 = size;
+            COMPILER_FENCE;
+            memset(m_Buffer + start, 0, BUFFER_SIZE - start);
+            start = 0;
+        }
+        else
+        {
+            m_BufferPos0 = start + size;
+            COMPILER_FENCE; // must write m_BufferPos0 before m_Buffer
+        }
+        memcpy(&m_Buffer[start], m_HoldBuffers[m_HeldDepth - 1].buffer, size);
+        COMPILER_FENCE; // must write m_BufferPos1 after m_Buffer
+        m_BufferPos1 = start + size;
+    }
+    m_HeldDepth--;
+}
+void CProfiler2::ThreadStorage::ThrowawayHoldBuffer()
+{
+    if (!m_HeldDepth)
+        return;
+    m_HeldDepth--;
+}
+
 void CProfiler2::ConstructJSONOverview(std::ostream& stream)
 {
     TIMER(L"profile2 overview");
@@ -438 +802 @@
             pos += sizeof(item);
             if (lastTime >= 0)
             {
-                lastTime = lastTime + (double)item.dt;
-                visitor.OnEvent(lastTime, item.id);
+                //lastTime = lastTime + (double)item.dt;
+                visitor.OnEvent(lastTime + (double)item.dt, item.id);
             }
             break;
         }
@@ -450 +814 @@
             pos += sizeof(item);
             if (lastTime >= 0)
             {
-                lastTime = lastTime + (double)item.dt;
-                visitor.OnEnter(lastTime, item.id);
+                //lastTime = lastTime + (double)item.dt;
+                visitor.OnEnter(lastTime + (double)item.dt, item.id);
             }
             break;
         }
@@ -462 +826 @@
             pos += sizeof(item);
             if (lastTime >= 0)
             {
-                lastTime = lastTime + (double)item.dt;
-                visitor.OnLeave(lastTime, item.id);
+                //lastTime = lastTime + (double)item.dt;
+                visitor.OnLeave(lastTime + (double)item.dt, item.id);
             }
             break;
         }
@@ -522 +886 @@
     void OnLeave(double time, const char* id)
     {
         m_Stream << "[3," << std::fixed << std::setprecision(9) << time;
+
         m_Stream << ",\"" << CStr(id).EscapeToPrintableASCII() << "\"],\n";
     }
 
@@ -596 +961 @@
     }
     stream << "\n]});\n";
 }
+
+CProfile2SpikeRegion::CProfile2SpikeRegion(const char* name, double spikeLimit) :
+    m_Name(name), m_Limit(spikeLimit), m_PushedHold(true)
+{
+    if (g_Profiler2.HoldLevel() < 8 &&  g_Profiler2.HoldType() != CProfiler2::ThreadStorage::BUFFER_AGGREGATE)
+        g_Profiler2.HoldMessages(CProfiler2::ThreadStorage::BUFFER_SPIKE);
+    else
+        m_PushedHold = false;
+    COMPILER_FENCE;
+    g_Profiler2.RecordRegionEnter(m_Name);
+    m_StartTime = g_Profiler2.GetTime();
+}
+CProfile2SpikeRegion::~CProfile2SpikeRegion()
+{
+    double time = g_Profiler2.GetTime();
+    g_Profiler2.RecordRegionLeave(m_Name);
+    bool shouldWrite = time - m_StartTime > m_Limit;
+
+    if (m_PushedHold)
+        g_Profiler2.StopHoldingMessages(shouldWrite);
+}
+
+CProfile2AggregatedRegion::CProfile2AggregatedRegion(const char* name, double spikeLimit) :
+    m_Name(name), m_Limit(spikeLimit), m_PushedHold(true)
+{
+    if (g_Profiler2.HoldLevel() < 8 && g_Profiler2.HoldType() != CProfiler2::ThreadStorage::BUFFER_AGGREGATE)
+        g_Profiler2.HoldMessages(CProfiler2::ThreadStorage::BUFFER_AGGREGATE);
+    else
+        m_PushedHold = false;
+    COMPILER_FENCE;
+    g_Profiler2.RecordRegionEnter(m_Name);
+    m_StartTime = g_Profiler2.GetTime();
+}
+CProfile2AggregatedRegion::~CProfile2AggregatedRegion()
+{
+    double time = g_Profiler2.GetTime();
+    g_Profiler2.RecordRegionLeave(m_Name);
+    bool shouldWrite = time - m_StartTime > m_Limit;
+
+    if (m_PushedHold)
+        g_Profiler2.StopHoldingMessages(shouldWrite, true);
+}

source/ps/Profiler2.h

@@ -91 +91 @@
 class CProfiler2
 {
     friend class CProfiler2GPU_base;
-
+    friend class CProfile2SpikeRegion;
+    friend class CProfile2AggregatedRegion;
 public:
     // Items stored in the buffers:
 
@@ -123 +124 @@
 private:
     // TODO: what's a good size?
     // TODO: different threads might want different sizes
-    static const size_t BUFFER_SIZE = 1024*1024;
+    static const size_t BUFFER_SIZE = 10*1024*1024;
+    static const size_t HOLD_BUFFER_SIZE = 128 * 1024;
 
     /**
      * Class instantiated in every registered thread.
@@ -135 +137 @@
         ThreadStorage(CProfiler2& profiler, const std::string& name);
         ~ThreadStorage();
     
+        enum { BUFFER_NORMAL, BUFFER_SPIKE, BUFFER_AGGREGATE };
+
         void RecordSyncMarker(double t)
         {
             // Store the magic string followed by the absolute time
@@ -153 +157 @@
             // (to save memory) without suffering from precision problems
             SItem_dt_id item = { (float)(t - m_LastTime), id };
             Write(type, &item, sizeof(item));
-            m_LastTime = t;
+            //m_LastTime = t;
         }
 
         void RecordFrameStart(double t)
@@ -172 +176 @@
             va_end(argp);
         }
 
+        size_t HoldLevel();
+        u8 HoldType();
+        void PutOnHold(u8 type);
+        void HoldToBuffer(bool condensed);
+        void ThrowawayHoldBuffer();
+
         CProfiler2& GetProfiler()
         {
             return m_Profiler;
@@ -193 +203 @@
         /**
          * Store an item into the buffer.
          */
-        void Write(EItem type, const void* item, u32 itemSize)
-        {
-            // See m_BufferPos0 etc for comments on synchronisation
+        void Write(EItem type, const void* item, u32 itemSize);
 
-            u32 size = 1 + itemSize;
-            u32 start = m_BufferPos0;
-            if (start + size > BUFFER_SIZE)
-            {
-                // The remainder of the buffer is too small - fill the rest
-                // with NOPs then start from offset 0, so we don't have to
-                // bother splitting the real item across the end of the buffer
+        void WriteHold(EItem type, const void* item, u32 itemSize);
 
-                m_BufferPos0 = size;
-                COMPILER_FENCE; // must write m_BufferPos0 before m_Buffer
-
-                memset(m_Buffer + start, 0, BUFFER_SIZE - start);
-                start = 0;
-            }
-            else
-            {
-                m_BufferPos0 = start + size;
-                COMPILER_FENCE; // must write m_BufferPos0 before m_Buffer
-            }
-
-            m_Buffer[start] = (u8)type;
-            memcpy(&m_Buffer[start + 1], item, itemSize);
-            
-            COMPILER_FENCE; // must write m_BufferPos1 after m_Buffer
-            m_BufferPos1 = start + size;
-        }
-
         CProfiler2& m_Profiler;
         std::string m_Name;
 
@@ -231 +214 @@
 
         u8* m_Buffer;
 
+        struct HoldBuffer
+        {
+            friend class ThreadStorage;
+        public:
+            HoldBuffer()
+            {
+                buffer = new u8[HOLD_BUFFER_SIZE];
+                memset(buffer, ITEM_NOP, HOLD_BUFFER_SIZE);
+                pos = 0;
+            }
+            ~HoldBuffer()
+            {
+                delete[] buffer;
+            }
+            void clear()
+            {
+                pos = 0;
+            }
+            void setType(u8 newType)
+            {
+                type = newType;
+            }
+            u8* buffer;
+            u32 pos;
+            u8 type;
+        };
+
+        HoldBuffer m_HoldBuffers[8];
+        size_t m_HeldDepth;
+
         // To allow hopefully-safe reading of the buffer from a separate thread,
         // without any expensive synchronisation in the recording thread,
         // two copies of the current buffer write position are stored.
@@ -327 +340 @@
         GetThreadStorage().Record(ITEM_ENTER, GetTime(), id);
     }
 
+    void RecordRegionEnter(const char* id, double time)
+    {
+        GetThreadStorage().Record(ITEM_ENTER, time, id);
+    }
+
     void RecordRegionLeave(const char* id)
     {
         GetThreadStorage().Record(ITEM_LEAVE, GetTime(), id);
@@ -346 +364 @@
     void RecordGPURegionLeave(const char* id);
 
     /**
+    * Hold onto messages until a call to release or write the held messages.
+    */
+    size_t HoldLevel()
+    {
+        return GetThreadStorage().HoldLevel();
+    }
+
+    u8 HoldType()
+    {
+        return GetThreadStorage().HoldType();
+    }
+
+    void HoldMessages(u8 type)
+    {
+        GetThreadStorage().PutOnHold(type);
+    }
+
+    void StopHoldingMessages(bool writeToBuffer, bool condensed = false)
+    {
+        if (writeToBuffer)
+            GetThreadStorage().HoldToBuffer(condensed);
+        else
+            GetThreadStorage().ThrowawayHoldBuffer();
+    }
+
+    /**
      * Call in any thread to produce a JSON representation of the general
      * state of the application.
      */
@@ -424 +468 @@
     {
         g_Profiler2.RecordRegionLeave(m_Name);
     }
+protected:
+    const char* m_Name;
+};
+
+/**
+* Scope-based enter/leave helper.
+*/
+class CProfile2SpikeRegion
+{
+public:
+    CProfile2SpikeRegion(const char* name, double spikeLimit);
+    ~CProfile2SpikeRegion();
 private:
     const char* m_Name;
+    double m_Limit;
+    double m_StartTime;
+    bool m_PushedHold;
 };
 
 /**
+* Scope-based enter/leave helper.
+*/
+class CProfile2AggregatedRegion
+{
+public:
+    CProfile2AggregatedRegion(const char* name, double spikeLimit);
+    ~CProfile2AggregatedRegion();
+private:
+    const char* m_Name;
+    double m_Limit;
+    double m_StartTime;
+    bool m_PushedHold;
+};
+
+/**
  * Scope-based GPU enter/leave helper.
  */
 class CProfile2GPURegion
@@ -455 +529 @@
  */
 #define PROFILE2(region) CProfile2Region profile2__(region)
 
+#define PROFILE2_IFSPIKE(region, limit) CProfile2SpikeRegion profile2__(region, limit)
+
 #define PROFILE2_GPU(region) CProfile2GPURegion profile2gpu__(region)
 
 /**

source/tools/profiler2/profiler2.html

@@ -6 +6 @@
 $(refresh);
 </script>
 <style>
-canvas { border: 1px #ddd solid; }
+canvas { border: 1px #ddd solid; display:block;}
 #tooltip { background: #ffd; padding: 4px; font: 12px sans-serif; border: 1px #880 solid; }
 #tooltip.long { -moz-column-count: 2; }
+#choices p { margin:2px; cursor:pointer;}
+#choices p:hover { background:#eee;}
+#choices p.active { background:#fee;}
 </style>
 
 <button onclick="refresh()">Refresh</button>
+<button onclick="SaveAsFile()">Save as File</button>
+
+<button onclick="gather_stable_data()">Condense</button>
+
 <br>
 <div id="timelines"></div>
 
+<div id="infodepth">
+<button onclick="output_graph_for_type('FlushDestroyedComponents')">output_graph_for_type</button>
+<button onclick="output_time_graph_for_type('FlushDestroyedComponents')">output_time_graph_for_type</button>
+<input type="file" id="ComparisonFile" name="files[]" />
+<div style="float:right; overflow-y:scroll; width:600px;height:600px" id="choices">
+<h3>Choices</h3>
+</div>
+    <canvas id="typical" width="600" height="600"></canvas>
+</div>
 <div id="tooltip" style="position: absolute; visibility: hidden"></div>
 
 Search: <input id="regionsearch" oninput="search_regions(this.value)">

source/tools/profiler2/profiler2.js

@@ -7 +7 @@
 var ITEM_LEAVE = 3;
 var ITEM_ATTRIBUTE = 4;
 
+var g_used_colours = {};
 
+
+var g_data;
+
+var g_last_stable_frame = 0;
+var g_stable_data = {};
+var g_statistical_data = {};
+
+var g_ActiveElement;
+
 function hslToRgb(h, s, l, a)
 {
     var r, g, b;
@@ -46 +56 @@
     return hslToRgb(hs[id % hs.length], ss[Math.floor(id / hs.length) % ss.length], ls[Math.floor(id / (hs.length*ss.length)) % ls.length], 1);
 }
 
-var g_used_colours = {};
-
-
-var g_data;
-
 function refresh()
 {
-    if (1)
+    if (0)
         refresh_live();
     else
-        refresh_jsonp('../../../binaries/system/profile2.jsonp');
+        refresh_jsonp('C:/Users/ironweb-15/AppData/Local/0ad/logs/profile2.jsonp');
 }
 
 function concat_events(data)
@@ -88 +93 @@
 
         rebuild_canvases();
         update_display(range);
+        recompute_choices(0);
     };
 
     script.src = url;
@@ -109 +115 @@
             threads.forEach(function(thread) {
                 refresh_thread(thread, callback_data);
             });
+            setTimeout(refresh, 2000);
         },
         error: function (jqXHR, textStatus, errorThrown) {
             alert('Failed to connect to server ("'+textStatus+'")');
+            refresh=refresh_jsonp
         }
     });
 }
@@ -143 +151 @@
         }
     });
 }
+function gather_stable_data()
+{
+    if (!g_stable_data.threads)
+    {
+        g_stable_data = {};
+        g_statistical_data = {};
+        for (let thread in g_data.threads)
+        {
+            g_stable_data[thread] = {"frames" : [], "events" : []}
+            g_statistical_data[thread] = {"evt_dur_avg" : {}, "evt_dur_total" : {}}
+        }
+    }
 
+    for (let thread in g_data.threads)
+    {
+        let in_data = g_data.threads[thread].processed_events;
+        if (!in_data)
+            in_data = compute_intervals(g_data.threads[thread].data.events, {})
+        if (!in_data)
+            continue;
+        let out_data = g_stable_data[thread];
+        let startTime = 0;
+
+        for (let i = 0; i < in_data.frames.length; ++i)
+            if (in_data.frames[i].t0 > g_last_stable_frame)
+            {
+                startTime = in_data.frames[i].t0;
+                out_data.frames = out_data.frames.concat(in_data.frames.slice(i));
+                break;
+            }
+        g_last_stable_frame = in_data.frames[in_data.frames.length-1].t1;
+        // get all relevant events
+        for (let evt in in_data.intervals)
+        {
+            let event = in_data.intervals[evt];
+            let time = event.t0;
+            if (time < startTime)
+                continue;
+
+            if (!out_data.events[event.id])
+            {
+                out_data.events[event.id] = [];
+                g_statistical_data[thread].evt_dur_avg[event.id] = event.duration;
+                g_statistical_data[thread].evt_dur_total[event.id] = 0;
+            }
+            g_statistical_data[thread].evt_dur_avg[event.id] = g_statistical_data[thread].evt_dur_avg[event.id] * 0.99 + event.duration * 0.01;
+            g_statistical_data[thread].evt_dur_total[event.id] += event.duration;
+
+            if (event.duration > 5e-3)
+            {
+                out_data.events.push(event);
+            }
+        }
+    }
+    var blob = new Blob([JSON.stringify(g_statistical_data)], {type: "application/json"});
+    var url  = URL.createObjectURL(blob);
+    window.open(url);
+    var blob = new Blob([JSON.stringify(g_stable_data)], {type: "application/json"});
+    var url  = URL.createObjectURL(blob);
+    window.open(url);
+}
+
+function SaveAsFile()
+{
+    $.ajax({
+        url: 'http://127.0.0.1:8000/download',
+        success: function () {
+        },
+        error: function (jqXHR, textStatus, errorThrown) {
+        }
+    });
+}
+
 function rebuild_canvases()
 {
     g_data.canvas_frames = $('<canvas width="1600" height="128"></canvas>').get(0);
-    g_data.canvas_zoom = $('<canvas width="1600" height="128"></canvas>').get(0);
+    g_data.canvas_zoom = $('<canvas width="1600" height="192"></canvas>').get(0);
     g_data.text_output = $('<pre></pre>').get(0);
     
     set_frames_zoom_handlers(g_data.canvas_frames);
@@ -160 +240 @@
     });
     $('#timelines').append(g_data.canvas_zoom);
     $('#timelines').append(g_data.text_output);
+    $('#timelines').append(g_data.canvas_typical);
 }
 
 function update_display(range)
@@ -190 +271 @@
         set_zoom_handlers(processed_main, processed_data, thread.canvas, g_data.canvas_zoom);
         set_tooltip_handlers(thread.canvas);
     });
- }
+}
 
 function display_top_items(data, output)
 {
@@ -226 +307 @@
     var tmin, tmax;
     
     var frames = [];
-    var last_frame_time = undefined;
+    var last_frame_time_start = undefined;
+    var last_frame_time_end = undefined;
     for (var i = 0; i < data.length; ++i)
     {
         if (data[i][0] == ITEM_EVENT && data[i][2] == '__framestart')
         {
-            var t = data[i][1];
-            if (last_frame_time)
-                frames.push({'t0': last_frame_time, 't1': t});
-            last_frame_time = t;
+            if (last_frame_time_end)
+                frames.push({'t0': last_frame_time_start, 't1': last_frame_time_end});
+            last_frame_time_start = data[i][1];
         }
+        if (data[i][0] == ITEM_LEAVE && data[i][2] == 'frame')
+        {
+            last_frame_time_end = data[i][1];
+        }
     }
     
     if (range.numframes)
@@ -360 +445 @@
     var stack = [];
     var lastT = 0;
     var lastWasEvent = false;
+ 
     for (var i = start; i <= end; ++i)
     {
         if (data[i][0] == ITEM_EVENT)
@@ -373 +459 @@
         else if (data[i][0] == ITEM_ENTER)
         {
 //            if (data[i][1] < lastT)
-//                console.log('Time went backwards: ' + (data[i][1] - lastT));
+//                console.log('Time - ENTER  went backwards: ' + (data[i][1] - lastT) + " - " + JSON.stringify(data[i]));
 
             stack.push({'t0': data[i][1], 'id': data[i][2]});
 
@@ -383 +469 @@
         else if (data[i][0] == ITEM_LEAVE)
         {
 //            if (data[i][1] < lastT)
-//                console.log('Time went backwards: ' + (data[i][1] - lastT));
+//                console.log('Time - LEAVE  went backwards: ' + (data[i][1] - lastT) + " - " + JSON.stringify(data[i]));
 
             lastT = data[i][1];
             lastWasEvent = false;
@@ -390 +476 @@
             
             if (!stack.length)
                 continue;
+
             var interval = stack.pop();
 
+
+
             if (data[i][2] != interval.id && data[i][2] != '(ProfileStop)')
-                alert('inconsistent interval ids ('+interval.id+' / '+data[i][2]+')');
+                console.log('inconsistent interval ids ('+interval.id+' / '+data[i][2]+')');
 
             if (!g_used_colours[interval.id])
                 g_used_colours[interval.id] = new_colour(num_colours++);
@@ -403 +492 @@
             interval.t1 = data[i][1];
             interval.duration = interval.t1 - interval.t0;
             interval.depth = stack.length;
-            
             intervals.push(interval);
+            if (interval.id == "Script" && interval.attrs && interval.attrs.length)
+            {
+                let curT = interval.t0;
+                for (let subItem in interval.attrs)
+                {
+                    let sub = interval.attrs[subItem];
+                    if (sub.search("buffer") != -1)
+                        continue;
+                    let newInterv = {};
+                    newInterv.t0 = curT;
+                    newInterv.duration = +sub.replace(/.+? ([.0-9]+)us/, "$1")/1000000;
+                    newInterv.t1 = curT + newInterv.duration;
+                    curT += newInterv.duration;
+                    newInterv.id = "Script:" + sub.replace(/(.+?) ([.0-9]+)us/, "$1");
+                    newInterv.colour = g_used_colours[interval.id];
+                    newInterv.depth = interval.depth+1;
+                    intervals.push(newInterv);
+               }
+            }
         }
         else if (data[i][0] == ITEM_ATTRIBUTE)
         {
@@ -454 +561 @@
         }
     };
     
-//    var y_per_second = 1000;
-    var y_per_second = 100;
+    // log 100 scale, skip < 15 ms (60fps) 
+    var scale = x => 1 - Math.max(0, Math.log(1 + (x-15)/10) / Math.log(100));
 
-    [16, 33, 200, 500].forEach(function(t) {
-        var y1 = canvas.height;
-        var y0 = y1 - t/1000*y_per_second;
-        var y = Math.floor(y0) + 0.5;
-
-        ctx.beginPath();
-        ctx.moveTo(xpadding, y);
-        ctx.lineTo(canvas.width - xpadding, y);
-        ctx.strokeStyle = 'rgb(255, 0, 0)';
-        ctx.stroke();
-        ctx.fillStyle = 'rgb(255, 0, 0)';
-        ctx.fillText(t+'ms', 0, y-2);
-    });
-
     ctx.strokeStyle = 'rgb(0, 0, 0)';
     ctx.fillStyle = 'rgb(255, 255, 255)';
     for (var i = 0; i < data.frames.length; ++i)
@@ -481 +574 @@
         var x0 = xpadding + dx*(frame.t0 - tmin);
         var x1 = x0 + dx*duration;
         var y1 = canvas.height;
-        var y0 = y1 - duration*y_per_second;
+        var y0 = y1 * scale(duration*1000);
         
         ctx.beginPath();
         ctx.rect(x0, y0, x1-x0, y1-y0);
@@ -504 +597 @@
         });
     }
 
+    [16, 33, 200, 500].forEach(function(t) {
+        var y1 = canvas.height;
+        var y0 = y1 * scale(t);
+        var y = Math.floor(y0) + 0.5;
+
+        ctx.beginPath();
+        ctx.moveTo(xpadding, y);
+        ctx.lineTo(canvas.width - xpadding, y);
+        ctx.strokeStyle = 'rgb(255, 0, 0)';
+        ctx.stroke();
+        ctx.fillStyle = 'rgb(255, 0, 0)';
+        ctx.fillText(t+'ms', 0, y-2);
+    });
+
     ctx.strokeStyle = 'rgba(0, 0, 255, 0.5)';
     ctx.fillStyle = 'rgba(128, 128, 255, 0.2)';
     ctx.beginPath();
@@ -534 +641 @@
         
         var x = time_to_x(event.t);
         var y = 32;
+
+        if (x < 2)
+            continue;
         
         var x0 = x;
         var x1 = x;
@@ -611 +721 @@
     var precision = -3;
     while ((tmax-tmin)*Math.pow(10, 3+precision) < 25)
         ++precision;
+    if (precision > 20)
+        precision = 20;
+    if (precision < 0)
+        precision = 0;
     var ticks_per_sec = Math.pow(10, 3+precision);
     var major_tick_interval = 5;
     for (var i = 0; i < (tmax-tmin)*ticks_per_sec; ++i)
@@ -634 +748 @@
         if (interval.tmax <= tmin || interval.tmin > tmax)
             continue;
 
+        var x0 = Math.floor(time_to_x(interval.t0));
+        var x1 = Math.floor(time_to_x(interval.t1));
+        //if (x1-x0 < 1)
+        //    continue;
+        var y0 = padding_top + interval.depth * BAR_SPACING;
+        var y1 = y0 + BAR_SPACING;
+        
         var label = interval.id;
         if (interval.attrs)
         {
@@ -642 +763 @@
             else
                 label += ' [...]';
         }
-        var x0 = Math.floor(time_to_x(interval.t0));
-        var x1 = Math.floor(time_to_x(interval.t1));
-        var y0 = padding_top + interval.depth * BAR_SPACING;
-        var y1 = y0 + BAR_SPACING;
-        
+
         ctx.fillStyle = interval.colour;
         ctx.strokeStyle = 'black';
         ctx.beginPath();
@@ -723 +840 @@
         var relativeY = event.pageY - this.offsetTop;
         
 //        var width = 0.001 + 0.5 * relativeY / canvas0.height;
-        var width = 0.001 + 5 * relativeY / canvas0.height;
+        var width = relativeY / canvas0.height;
+        width = width*width;
+        width *= zdata.x_to_t(canvas0.width)/10;
 
         var tavg = zdata.x_to_t(relativeX);
         var tmax = tavg + width/2;
@@ -759 +878 @@
         }
         
         var relativeX = event.pageX - this.offsetLeft;
-        var relativeY = event.pageY - this.offsetTop;
-        var width = 8 + 64 * relativeY / canvas0.height;
+        var relativeY = (event.pageY + this.offsetTop) / canvas0.height;
+        relativeY = relativeY - 0.5;
+        relativeY *= 10;
+        relativeY *= relativeY;
+        var width = relativeY / canvas0.height;
+        width = width*width;
+        width = 6 + width * x_to_time(canvas0.width)/10;
         var zoom = { tmin: x_to_time(relativeX-width/2), tmax: x_to_time(relativeX+width/2) };
         display_hierarchy(main_data, data, canvas0, hdata.range, zoom);
         display_hierarchy(main_data, data, canvas1, zoom, undefined);
@@ -821 +945 @@
     $(canvas).mousemove(function(event) {
         do_tooltip.call(this, event);
     });
+    $(canvas).mouseleave(function(event) {
+        $('#tooltip').css('visibility', 'hidden');
+    });
 }
 
 function search_regions(query)
@@ -846 +973 @@
     {
         out.append($('<tr><td>?</td><td>' + found[i].id + '</td><td>' + (found[i].duration*1000) + '</td></tr>'));
     }
-}
- No newline at end of file
+}
+
+function output_graph_for_type(type, useLog)
+{
+    // Search through out processed intervals for those matching type and keep them in a vector.
+    var canvas = document.getElementById("typical");
+    var context = canvas.getContext("2d");
+    context.clearRect(0, 0, canvas.width, canvas.height);
+    canvas._tooltips = [];
+
+    var events = [];
+    var eventsByFrame = [];
+    var useLogScale = useLog;
+
+    var max = 0;
+    var avg = 0;
+    var data = compute_intervals(g_data.threads[0].data.events, {});
+    var currFrame = 0;
+    for (var i = 0; i < data.intervals.length; i++)
+    {
+        let interval = data.intervals[i];
+        if (interval.id == type)
+        {
+            let frame = currFrame;
+            eventsByFrame.push(0);
+            while (frame < data.frames.length && data.frames[frame].t1 < interval.t0)
+            {
+                eventsByFrame.push(0);
+                frame++
+            }
+            eventsByFrame[frame] += interval.duration;
+        }
+    };
+    let event_count = 0;
+    for (var i = 0; i < eventsByFrame.length; i++)
+    {
+        if (!eventsByFrame[i])
+            continue;
+        event_count++;
+        events.push(eventsByFrame[i]);
+        avg += +eventsByFrame[i];
+        if (eventsByFrame[i] > max)
+            max = eventsByFrame[i];
+    }
+    console.log(avg);
+    avg /= event_count;
+
+    if (useLogScale == undefined && max > avg * 3)
+        useLogScale = true;
+    events.sort();
+
+    var maxXScale = Math.ceil(max*20)/20;
+    var maxYScaleNb = 0;
+    var maxYScaleTime = 0;
+    
+    let p = 0;
+    for (var i = 0; i < canvas.width; i++)
+    {
+        let nbForX = 0;
+        let timeForX = 0;
+        while (events[p] < maxXScale*(i/canvas.width))
+        {
+            timeForX += events[p];
+            nbForX++;
+            p++;
+        }
+        if (Math.ceil(nbForX/100.0)*100.0 > maxYScaleNb)
+            maxYScaleNb = Math.ceil(nbForX/100.0)*100.0;
+        if (Math.ceil(timeForX*10)/10 > maxYScaleTime)
+            maxYScaleTime = Math.ceil(timeForX*10)/10;
+    }
+    p = 0;
+    var maxx = max * (events.length);
+    for (var i = 0; i < canvas.width; i++)
+    {
+        let nbForX = 0;
+        let timeForX = 0;
+
+
+        let i0 = i/canvas.width*maxXScale;
+        let i1 = (i+1)/canvas.width*maxXScale;
+
+        if (useLogScale)
+        {
+            i0 = maxXScale - Math.log10(1 + (1-i/canvas.width) * 9)*maxXScale;
+            i1 = maxXScale - Math.log10(1 + (1-(i+1)/canvas.width) * 9)*maxXScale;
+        }
+
+        while (events[p] < i1)
+        {
+            timeForX += events[p];
+            nbForX++;
+            p++;
+        }
+
+        context.globalCompositeOperation = "lighter";
+
+        context.beginPath();
+        context.fillStyle="rgba(0,0,255,1)";
+        context.fillRect(i,canvas.height,1,-timeForX/maxYScaleTime*canvas.height);
+
+        context.beginPath();
+        context.fillStyle="rgba(255,0,0,1)";
+        context.fillRect(i,canvas.height,1,-nbForX/maxYScaleNb*canvas.height);
+
+        canvas._tooltips.push({
+                'x0': i, 'x1': i+1,
+                'y0': 0, 'y1': canvas.height,
+                'text': function(nb,t) { return function() { return (nb + " events at " + Math.round(t*10000)/10 + "ms"); } }(nbForX,i1)
+            });
+    }
+    if (useLogScale)
+    {
+        for (var i = 1; i < 4; i++)
+        {
+            let xv = i/5;
+            let val = maxXScale - Math.log10(1 + (1-xv) * 9)*maxXScale;
+            context.beginPath();
+            context.lineWidth="1";
+            context.strokeStyle = "rgba(0,0,0,0.2)";
+            context.moveTo(xv*canvas.width,20);
+            context.lineTo(xv*canvas.width,canvas.height);
+            context.stroke();
+            context.fillStyle = "gray";
+            context.font = "10px Arial";
+            context.textAlign="center"; 
+            context.fillText(Math.round(val*1000) + "ms",xv*canvas.width,12);
+        };
+    }
+    set_tooltip_handlers(canvas);
+}
+
+
+function output_time_graph_for_type(type, useLog)
+{
+    // Search through out processed intervals for those matching type and keep them in a vector.
+    var canvas = document.getElementById("typical");
+    var context = canvas.getContext("2d");
+    context.clearRect(0, 0, canvas.width, canvas.height);
+    canvas._tooltips = [];
+
+    TimeByFrame = [];
+    
+    var max = 0;
+    var avg = 0;
+    var currFrame = 0;
+    var data = compute_intervals(g_data.threads[0].data.events, {});
+    for (var i = 0; i < data.intervals.length; i++)
+    {
+        TimeByFrame.push(0);
+        let interval = data.intervals[i];
+        if (interval.id == type)
+        {
+            let frame = currFrame;
+            while (frame < data.frames.length && data.frames[frame].t1 < interval.t0)
+                frame++
+            TimeByFrame[frame] += interval.duration;
+            if (TimeByFrame[frame] > max)
+                max = TimeByFrame[frame];
+            avg += interval.duration;
+            currFrame = frame;
+        }
+    };
+
+    for (var i = 0; i < data.frames.length; i++)
+    {
+        let xScale = data.frames.length/canvas.width;
+
+        let y = TimeByFrame[i]/max;
+        if (max > avg*5)
+            y = Math.log10(1 + TimeByFrame[i]/max * 9);
+
+        context.beginPath();
+        context.lineWidth="6";
+        context.fillStyle="rgba(0,0,255,1)";
+        context.fillRect(i/xScale,canvas.height,1/xScale,-y*canvas.height);
+
+        canvas._tooltips.push({
+                'x0': i/xScale, 'x1': (i+1)/xScale,
+                'y0': 0, 'y1': canvas.height,
+                'text': function(frame,t) { return function() { return ("Frame " + frame + ": " + t*1000 + "ms"); } }(i,TimeByFrame[i])
+            });
+    }
+    set_tooltip_handlers(canvas);
+}
+
+function recompute_choices(thread)
+{
+    var choices = document.getElementById("choices");
+    var types = {};
+    var data = compute_intervals(g_data.threads[thread].data.events, {});
+    for (let i = 0; i < data.intervals.length; i++)
+        types[data.intervals[i].id] = 0;
+    
+    var sorted_keys = Object.keys(types).sort();
+
+    for (let key in sorted_keys)
+    {
+        let type = sorted_keys[key];
+        let p = document.createElement("p");
+        p.textContent = type;
+
+        choices.appendChild(p);
+        p.onclick = function()
+        {
+            choices.parentNode.querySelector("button:first-child").onclick = function() { output_graph_for_type(type); };
+            choices.parentNode.querySelector("button:last-of-type").onclick = function() { output_time_graph_for_type(type); };
+
+            var allP = choices.querySelectorAll("p");
+            for (let item in allP)
+            {
+                allP[item] . className = "";
+            }
+            p.className = "active";
+            g_ActiveElement = p.textContent;
+        }
+    }
+}
+
+function compareTwoTypes(type, dataB)
+{
+    TimeByFrameA = [];
+    TimeByFrameB = [];
+    
+    var maxA = 0;
+    var maxB = 0;
+    var avgA = [];
+    var avgB = [];
+    var countA = 0;
+    var countB = 0;
+
+    var dataA = compute_intervals(g_data.threads[0].data.events, {});
+
+    let ComputePerFrame = function(data, TimeByFrame)
+    {
+        let currFrame = 0;
+        for (var i = 0; i < data.intervals.length; i++)
+        {
+            TimeByFrame.push(0);
+            let interval = data.intervals[i];
+            if (interval.id == type)
+            {
+                while (currFrame < data.frames.length && data.frames[currFrame].t1 < interval.t0)
+                    currFrame++
+                TimeByFrame[currFrame] += interval.duration;
+            }
+        };
+    }
+    ComputePerFrame(dataA,TimeByFrameA);
+    ComputePerFrame(dataB,TimeByFrameB);
+    let statA = {"avg":[],"max":0,"count":0};
+    let statB = {"avg":[],"max":0,"count":0};
+    let StatPerFrame = function(statRet, TimeByFrame)
+    {
+        for (var i = 0; i < TimeByFrame.length; i++)
+        {
+            if (!TimeByFrame[i])
+                continue;
+            statRet.avg.push(TimeByFrame[i]);
+            if (TimeByFrame[i] > statRet.max)
+                statRet.max = TimeByFrame[i];
+            statRet.count++;
+        }
+    }
+    StatPerFrame(statA,TimeByFrameA);
+    StatPerFrame(statB,TimeByFrameB);
+
+    // pick the median
+    statA.avg.sort();
+    statB.avg.sort();
+    statA.avg = statA.avg[Math.round(statA.avg.length/2)];
+    statB.avg = statB.avg[Math.round(statB.avg.length/2)];
+
+    if (!statA.avg)
+        statA.avg = 0;
+    if (!statB.avg)
+        statB.avg = 0;
+
+    let canvas = null;
+
+    // compare frame by frame.
+    // draw a canvas with two lines.
+    canvas = document.createElement("canvas");
+    canvas.width = 1000;
+    canvas.height = 400;
+    let context = canvas.getContext("2d");
+
+    context.globalCompositeOperation = "lighten";
+
+    let framesBetter = 0;
+    let betterSum = 0;
+    let avgDiffPerFrame = 0;
+
+    let maxAB = Math.max(statA.max,statB.max);
+    let nbFrames = Math.min(dataA.frames.length,dataB.frames.length);
+    let logScale = x => Math.log10(1 + x * 9);
+    let improvLine = 0,lastImprovLine = 0;
+    // Draw frame by frame for each;
+    for (var i = 0; i < nbFrames - 1; i++)
+    {
+        improvLine += TimeByFrameA[i] - TimeByFrameB[i];
+        avgDiffPerFrame += TimeByFrameA[i] - TimeByFrameB[i]; 
+        if (TimeByFrameA[i] < TimeByFrameB[i])
+            betterSum++;
+        else if (TimeByFrameA[i] > TimeByFrameB[i])
+            betterSum--;
+
+        if (TimeByFrameA[i] <= TimeByFrameB[i])
+            framesBetter++;
+
+        let y0 = TimeByFrameA[i]/maxAB * canvas.height;
+        let y1 = TimeByFrameA[i+1]/maxAB * canvas.height;
+        let x0 = i/dataB.frames.length*canvas.width;
+        let x1 = (i+1)/dataB.frames.length*canvas.width;
+        if (maxAB > statA.avg*5 && maxAB > statB.avg*5)
+        {
+            y0 = logScale(TimeByFrameA[i]/maxAB) * canvas.height;
+            y1 = logScale(TimeByFrameA[i+1]/maxAB) * canvas.height;
+        }
+        context.beginPath();
+        context.lineWidth=0.5;
+        context.moveTo(x0, canvas.height - y0);
+        context.lineTo(x1, canvas.height - y1);
+        context.strokeStyle = "red";
+        context.stroke();
+
+        y0 = TimeByFrameB[i]/maxAB * canvas.height;
+        y1 = TimeByFrameB[i+1]/maxAB * canvas.height;
+        x0 = i/dataB.frames.length*canvas.width;
+        x1 = (i+1)/dataB.frames.length*canvas.width;
+        if (maxAB > statA.avg*5 && maxAB > statB.avg*5)
+        {
+            y0 = logScale(TimeByFrameB[i]/maxAB) * canvas.height;
+            y1 = logScale(TimeByFrameB[i+1]/maxAB) * canvas.height;
+        }
+
+        context.beginPath();
+        context.lineWidth=0.5;
+        context.moveTo(x0, canvas.height - y0);
+        context.lineTo(x1, canvas.height - y1);
+        context.strokeStyle = "blue";
+        context.stroke();
+
+        context.beginPath();
+        context.lineWidth=0.5;
+        context.moveTo(x0, 200 + lastImprovLine/nbFrames*10000);
+        context.lineTo(x1, 200 + improvLine/nbFrames*10000);
+        context.strokeStyle = "green";
+        context.stroke();
+
+        lastImprovLine = improvLine;
+    }
+    let res = document.getElementById("ComparisonResult");
+    if (res)
+        res.parentNode.removeChild(res);
+    res = document.createElement("div");
+    res.id="ComparisonResult";
+
+    let smRound = (x, y) => Math.round(x*y*1000)/y;
+
+    res.innerHTML = "<h4>Comparison of " + type + "</h4>";
+    res.innerHTML += "<p>Max: " + smRound(statA.max,10) + "ms - " + statB.max + "ms</p>";
+    res.innerHTML += "<p>Average: " + statA.avg + " - " + statB.avg + "</p>";
+    res.innerHTML += "<p>Count: " + statA.count + " - " + statB.count + "</p>";
+    res.innerHTML += "<p>Average difference per frame: " + avgDiffPerFrame/nbFrames*1000 + "ms</p>"
+    res.innerHTML += "<p>In number of frames: " + betterSum + "</p>";
+    res.innerHTML += "<p>% of Frames where current is better: " + Math.round(framesBetter/nbFrames*100) + "%</p>";
+    res.appendChild(canvas);
+
+    document.querySelector("body").appendChild(res);
+}
+
+function compareWith(other)
+{
+    // let's compute. If we fail at any point, warn
+    try
+    {
+        let out_data_other;
+        var script = document.createElement('script');
+        window.profileDataCB = function(data)
+        {
+            script.parentNode.removeChild(script);
+
+            let events = concat_events(data.threads[0].data);
+            out_data_other = compute_intervals(events, {});
+            if (!out_data_other.intervals.length)
+            {
+                console.log("failed to parse intervals");
+                return;
+            }
+            // We have intervals. Let's compare them with the active
+            compareTwoTypes(g_ActiveElement, out_data_other);
+        };
+
+        script.innerHTML = other;
+        document.body.appendChild(script);
+
+    } catch(e)
+    {
+        console.log("Failed to Parse File");
+    }
+}
+
+function loadComparisonFile(evt) {
+    var file = evt.target.files[0];
+    if (!file)
+        return;
+    evt.target.value = null;
+    var reader = new FileReader();
+
+    reader.onload = (function(theFile) {
+        return function(e)
+        {
+            compareWith(e.target.result);
+        };
+    })(file);
+
+    reader.readAsText(file);
+}
+
+window.onload = function()  { document.getElementById('ComparisonFile').addEventListener('change', loadComparisonFile, false); }
+ No newline at end of file