Merge lp:~gordallott/unity/perf-logger into lp:unity

[Gord Allott]

Adds updates the performance logging code for unity

[Jason Smith (jassmith)]

+1 code looks good, everything seems to be in order

review: Approve

[Jason Smith (jassmith)]

It does have a merge conflict with latest trunk however

=== modified file 'CMakeLists.txt'
--- CMakeLists.txt	2010-11-30 15:44:05 +0000
+++ CMakeLists.txt	2010-12-03 08:41:48 +0000
@@ -82,6 +82,7 @@
                PKGDEPS ${UNITY_PLUGIN_DEPS}
                PLUGINDEPS composite opengl
                CFLAGSADD "-DINSTALLPREFIX='\"${CMAKE_INSTALL_PREFIX}\"' -DPKGDATADIR='\"${CMAKE_INSTALL_PREFIX}/share/unity/3\"' -I${CMAKE_BINARY_DIR}"
+               LIBRARIES "unity"
                )
 
 #
 
=== modified file 'libunity/CMakeLists.txt'
--- libunity/CMakeLists.txt	2010-11-25 12:08:52 +0000
+++ libunity/CMakeLists.txt	2010-12-03 08:41:48 +0000
@@ -50,6 +50,7 @@
 vala_precompile (VALA_C unity-place-activation.vala
                         unity-place-browser.vala
                         unity-place.vala
+                        perf-logger.vala
                  PACKAGES gtk+-2.0 gio-2.0 glib-2.0 gobject-2.0 gee-1.0 dbus-glib-1 gio-unix-2.0
                  OPTIONS --thread
                  CUSTOM_VAPIS ../vapi/dee-1.0.vapi ../vapi/config.vapi
 
=== added file 'libunity/perf-logger-utility.h'
--- libunity/perf-logger-utility.h	1970-01-01 00:00:00 +0000
+++ libunity/perf-logger-utility.h	2010-12-03 08:41:48 +0000
@@ -0,0 +1,34 @@
+/*
+ * Copyright (C) 2009-2010 Canonical Ltd
+ *
+ * This program is free software: you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License version 3 as
+ * published by the Free Software Foundation.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with this program.  If not, see <http://www.gnu.org/licenses/>.
+ *
+ * Authored by Gordon Allott <[e-mail]>
+ *
+ */
+#ifndef _PERF_LOGGER_H_
+#define _PERF_LOGGER_H_
+
+#include <libunity/unity.h>
+
+#define START_FUNCTION() G_STMT_START { \
+                          perf_timeline_logger_start_process (perf_timeline_logger_get_default(), G_STRFUNC);\
+                       } G_STMT_END
+#define LOGGER_START_PROCESS(process) { perf_timeline_logger_start_process (perf_timeline_logger_get_default(), process);}
+
+#define END_FUNCTION() G_STMT_START { \
+                          perf_timeline_logger_end_process (perf_timeline_logger_get_default(), G_STRFUNC);\
+                       } G_STMT_END
+#define LOGGER_END_PROCESS(process) { perf_timeline_logger_end_process (perf_timeline_logger_get_default(), process);}
+
+#endif /* PERF_LOGGER_H */
 
=== renamed file 'unity-private/testing/perf-logger.vala' => 'libunity/perf-logger.vala'
--- unity-private/testing/perf-logger.vala	2010-04-07 14:46:55 +0000
+++ libunity/perf-logger.vala	2010-12-03 08:41:48 +0000
@@ -1,5 +1,5 @@
 /*
- * Copyright (C) 2009 Canonical Ltd
+ * Copyright (C) 2009-2010 Canonical Ltd
  *
  * This program is free software: you can redistribute it and/or modify
  * it under the terms of the GNU General Public License version 3 as
@@ -17,9 +17,8 @@
  *
  */
 
-namespace Unity
+namespace Perf
 {
-  
   public class ProcessInfo
   {
     public ProcessInfo (string name)
@@ -32,82 +31,86 @@
     public double start;
     public double end;
   }
-  
+
   public static TimelineLogger? timeline_singleton;
-  public static bool is_logging; 
-  
+  public static bool is_logging;
+
   public class TimelineLogger : Object
   {
     private Timer global_timer;
     private Gee.HashMap<string, ProcessInfo> process_map;
-    
-    public static unowned Unity.TimelineLogger get_default ()
+
+    public static unowned Perf.TimelineLogger get_default ()
     {
-      if (Unity.timeline_singleton == null)
+      if (Perf.timeline_singleton == null)
       {
-        Unity.timeline_singleton = new Unity.TimelineLogger ();
+        Perf.timeline_singleton = new Perf.TimelineLogger ();
       }
-      
-      return Unity.timeline_singleton;
+
+      return Perf.timeline_singleton;
     }
-    
+
     construct
     {
       this.process_map = new Gee.HashMap<string, ProcessInfo> ();
-      this.global_timer = new Timer ();      
+      this.global_timer = new Timer ();
       this.global_timer.start ();
     }
-    
+
     public void start_process (string name)
     {
+      debug ("shoop de whoop");
       if (name in this.process_map.keys)
       {
         warning ("already started process: %s", name);
         return;
       }
-      
+
       var info = new ProcessInfo (name);
       this.process_map[name] = info;
       info.start = this.global_timer.elapsed ();
     }
-    
+
     public void end_process (string name)
     {
+      debug ("shonk le donk");
       double end_time = this.global_timer.elapsed ();
-      
+      print ("the end time is %f", end_time);
+
       if (name in this.process_map.keys)
       {
         this.process_map[name].end = end_time;
       }
-      else 
+      else
       {
         warning ("process %s not started", name);
       }
     }
-    
+
     public void write_log (string filename)
     {
       debug ("Writing performance log file: %s...", filename);
       var log_file = File.new_for_path (filename);
       FileOutputStream file_stream;
-      try 
+      try
       {
         if (!log_file.query_exists (null)) {
           file_stream = log_file.create (FileCreateFlags.NONE, null);
         }
-        else 
+        else
         {
           file_stream = log_file.replace (null, false, FileCreateFlags.NONE, null);
         }
-        
+
         var output_stream = new DataOutputStream (file_stream);
-        
+
         foreach (ProcessInfo info in this.process_map.values)
         {
-          string outline = "%s, %f, %f\n".printf(info.name, info.start, info.end);
-            output_stream.put_string (outline, null); 
+          string name = info.name.replace (",", ";");
+          string outline = "%s, %f, %f\n".printf(name, info.start, info.end);
+            output_stream.put_string (outline, null);
         }
-        
+
         file_stream.close (null);
       } catch (Error e)
       {
 
=== modified file 'src/unity.cpp'
--- src/unity.cpp	2010-11-26 09:11:52 +0000
+++ src/unity.cpp	2010-12-03 08:41:48 +0000
@@ -39,6 +39,8 @@
 
 #include <core/atoms.h>
 
+#include "../libunity/perf-logger-utility.h"
+
 /* Set up vtable symbols */
 COMPIZ_PLUGIN_20090315 (unityshell, UnityPluginVTable);
 
@@ -49,10 +51,10 @@
 {
     /* reset matrices */
     glPushAttrib (GL_VIEWPORT_BIT | GL_ENABLE_BIT | GL_TEXTURE_BIT | GL_COLOR_BUFFER_BIT);
-    
+
     glMatrixMode (GL_PROJECTION);
     glPushMatrix ();
-    
+
     glMatrixMode (GL_MODELVIEW);
     glPushMatrix ();
 
@@ -139,19 +141,19 @@
     std::vector<nux::Geometry>::iterator it;
     std::vector<nux::Geometry> dirty = wt->GetDrawList ();
     nux::Geometry geo;
-	    
+
     for (it = dirty.begin (); it != dirty.end (); it++)
     {
        	geo = *it;
       	cScreen->damageRegion (CompRegion (geo.x, geo.y, geo.width, geo.height));
     }
-	    
+
     geo = wt->GetWindowCompositor ().GetTooltipMainWindowGeometry();
     cScreen->damageRegion (CompRegion (geo.x, geo.y, geo.width, geo.height));
     cScreen->damageRegion (CompRegion (lastTooltipArea.x, lastTooltipArea.y, lastTooltipArea.width, lastTooltipArea.height));
-	    
+
     lastTooltipArea = geo;
-    
+
     wt->ClearDrawList ();
 }
 
@@ -165,7 +167,7 @@
     {
 	wt->ProcessForeignEvent (event, NULL);
     }
-}			
+}
 
 
 gboolean
@@ -258,7 +260,7 @@
  * stacked on top of one of the nux input windows
  * and if so paint nux and stop us from painting
  * other windows or on top of the whole screen */
-bool 
+bool
 UnityWindow::glDraw (const GLMatrix 	&matrix,
 		     GLFragment::Attrib &attrib,
 		     const CompRegion 	&region,
@@ -278,7 +280,7 @@
     }
 
     bool ret = gWindow->glDraw (matrix, attrib, region, mask);
-    
+
     return ret;
 }
 
@@ -293,7 +295,7 @@
 }
 
 /* Configure callback for the launcher window */
-void 
+void
 UnityScreen::launcherWindowConfigureCallback(int WindowWidth, int WindowHeight, nux::Geometry& geo, void *user_data)
 {
     int OurWindowHeight = WindowHeight - 24;
@@ -301,23 +303,25 @@
 }
 
 /* Configure callback for the panel window */
-void 
+void
 UnityScreen::panelWindowConfigureCallback(int WindowWidth, int WindowHeight, nux::Geometry& geo, void *user_data)
 {
     geo = nux::Geometry(0, 0, WindowWidth, 24);
 }
 
 /* Start up nux after OpenGL is initialized */
-void 
+void
 UnityScreen::initUnity(nux::NThread* thread, void* InitData)
 {
+    START_FUNCTION ();
     initLauncher(thread, InitData);
-      
+
     nux::ColorLayer background(nux::Color(0x00000000));
     static_cast<nux::WindowThread*>(thread)->SetWindowBackgroundPaintLayer(&background);
+    END_FUNCTION ();
 }
 
-void 
+void
 UnityScreen::onRedrawRequested ()
 {
   damageNuxRegions ();
@@ -342,6 +346,13 @@
     }
 }
 
+static gboolean
+write_logger_data_to_disk (gpointer data)
+{
+  perf_timeline_logger_write_log (perf_timeline_logger_get_default (), "/tmp/unity-perf.log");
+  return FALSE;
+}
+
 UnityScreen::UnityScreen (CompScreen *screen) :
     PluginClassHandler <UnityScreen, CompScreen> (screen),
     screen (screen),
@@ -349,35 +360,37 @@
     gScreen (GLScreen::get (screen)),
     doShellRepaint (false)
 {
+    START_FUNCTION ();
     int (*old_handler) (Display *, XErrorEvent *);
     old_handler = XSetErrorHandler (NULL);
-    
+
     g_thread_init (NULL);
     dbus_g_thread_init ();
     gtk_init (NULL, NULL);
-    
+
     XSetErrorHandler (old_handler);
 
     /* Wrap compiz interfaces */
     ScreenInterface::setHandler (screen);
     CompositeScreenInterface::setHandler (cScreen);
     GLScreenInterface::setHandler (gScreen);
-    
+
     StartupNotifyService::Default ()->SetSnDisplay (screen->snDisplay (), screen->screenNum ());
 
     nux::NuxInitialize (0);
-    wt = nux::CreateFromForeignWindow (cScreen->output (), 
-                                       glXGetCurrentContext (),	
+    wt = nux::CreateFromForeignWindow (cScreen->output (),
+                                       glXGetCurrentContext (),
                                        &UnityScreen::initUnity,
                                        this);
-    
+
     wt->RedrawRequested.connect (sigc::mem_fun (this, &UnityScreen::onRedrawRequested));
-    
+    END_FUNCTION ();
+    g_timeout_add (10, write_logger_data_to_disk, NULL);
     wt->Run (NULL);
     uScreen = this;
 
     debugger = new IntrospectionDBusInterface (this);
-	
+
     PluginAdapter::Initialize (screen);
 
     optionSetLauncherAutohideNotify (boost::bind (&UnityScreen::optionChanged, this, _1, _2));
@@ -393,25 +406,28 @@
 /* Can't create windows until after we have initialized everything */
 gboolean UnityScreen::strutHackTimeout (gpointer data)
 {
-    UnityScreen *self = (UnityScreen*) data;  
-    
+    UnityScreen *self = (UnityScreen*) data;
+
     if (!self->launcher->AutohideEnabled ())
     {
         self->launcherWindow->InputWindowEnableStruts(false);
         self->launcherWindow->InputWindowEnableStruts(true);
     }
-    
+
     self->panelWindow->InputWindowEnableStruts(false);
     self->panelWindow->InputWindowEnableStruts(true);
-    
+
     return FALSE;
 }
 
 /* Start up the launcher */
 void UnityScreen::initLauncher (nux::NThread* thread, void* InitData)
 {
+  START_FUNCTION ();
+
   UnityScreen *self = (UnityScreen*) InitData;
-  
+
+  LOGGER_START_PROCESS ("initLauncher-Launcher");
   self->launcherWindow = new nux::BaseWindow(TEXT(""));
   self->launcher = new Launcher(self->launcherWindow);
   self->AddChild (self->launcher);
@@ -434,8 +450,10 @@
   self->launcherWindow->InputWindowEnableStruts(true);
 
   self->launcher->SetIconSize (54, 48);
+  LOGGER_END_PROCESS ("initLauncher-Launcher");
 
   /* Setup panel */
+  LOGGER_START_PROCESS ("initLauncher-Panel");
   self->panelView = new PanelView ();
   self->AddChild (self->panelView);
 
@@ -454,10 +472,12 @@
   self->panelWindow->SetBackgroundColor(nux::Color(0x00000000));
   self->panelWindow->SetBlurredBackground(false);
   self->panelWindow->ShowWindow(true);
-  self->panelWindow->EnableInputWindow(true);  
+  self->panelWindow->EnableInputWindow(true);
   self->panelWindow->InputWindowEnableStruts(true);
-  
+  LOGGER_END_PROCESS ("initLauncher-Panel");
   g_timeout_add (2000, &UnityScreen::strutHackTimeout, self);
+
+  END_FUNCTION ();
 }
 
 /* Window init */
 
=== modified file 'tools/CMakeLists.txt'
--- tools/CMakeLists.txt	2010-11-25 15:56:14 +0000
+++ tools/CMakeLists.txt	2010-12-03 08:41:48 +0000
@@ -1,5 +1,5 @@
 #
 # Some unity tools
 #
-install(FILES migrate_favorites.py PERMISSIONS OWNER_READ OWNER_WRITE OWNER_EXECUTE GROUP_READ GROUP_EXECUTE WORLD_READ WORLD_EXECUTE DESTINATION ${CMAKE_INSTALL_PREFIX}/lib/unity/)
+install(FILES makebootchart.py migrate_favorites.py PERMISSIONS OWNER_READ OWNER_WRITE OWNER_EXECUTE GROUP_READ GROUP_EXECUTE WORLD_READ WORLD_EXECUTE DESTINATION ${CMAKE_INSTALL_PREFIX}/lib/unity/)
 
 
=== modified file 'tools/makebootchart.py'
--- tools/makebootchart.py	2010-01-15 12:28:51 +0000
+++ tools/makebootchart.py	2010-12-03 08:41:48 +0000
@@ -24,8 +24,8 @@
 import math
 import random
 from string import Template
-from socket import gethostname 
-from datetime import datetime 
+from socket import gethostname
+from datetime import datetime
 import re
 import subprocess
 
@@ -39,22 +39,22 @@
   if x["start"] - y["start"] < 0:
     return -1
   else:
-    return +1    
-    
+    return +1
+
 def gatherinfo (filename):
   date =  datetime.fromtimestamp(os.path.getmtime(filename))
-  
+
   cpufile = open ("/proc/cpuinfo")
   cpuinfo = cpufile.read (10024)
   cpure = re.search (r"^model name\s*: (.*$)", cpuinfo, re.MULTILINE)
   cpu = cpure.group(1)
-  
+
   gpu_prog = subprocess.Popen("glxinfo", stdout=subprocess.PIPE)
-  gpu_prog.wait () 
+  gpu_prog.wait ()
   gpuinfo = gpu_prog.stdout.read (10024)
   gpure = re.search (r"^OpenGL renderer string: (.*$)", gpuinfo, re.MULTILINE)
   gpu = gpure.group (1)
-  
+
   return {"hostname":gethostname(),
           "date": date.strftime("%A, %d. %B %Y %I:%M%p"),
           "uname": " ".join (os.uname ()),
@@ -67,14 +67,14 @@
 bar_height = 16
 
 def draw_bg_graph (ctx, seconds, height):
-  
+
   total_width = seconds * width_multiplier
   ctx.set_source_rgba (0.0, 0.0, 0.0, 0.25)
-  
+
   ctx.move_to (0, 0)
   ctx.line_to (total_width, 0)
   ctx.stroke ()
-  
+
   per_ten = 0
   for pos in xrange (0, int(total_width), int (0.01 * width_multiplier)):
     ctx.set_line_width (1)
@@ -90,67 +90,67 @@
     ctx.move_to (pos, 0)
     ctx.line_to (pos, height)
     ctx.stroke ()
-    
+
     per_ten += 1
     per_ten %= 10
 
 def build_graph (data, filename, info):
-  
+
   padding_left = 6
   padding_right = 100
   padding_top = 6
   padding_bottom = 6
-  
+
   total_size = 0.0
   for item in data:
     if item['end'] > total_size:
       total_size = item['end']
-      
+
   width = total_size * width_multiplier + padding_left + padding_right
   height = (len(data) * (bar_height)) + 80 + padding_bottom + padding_top
-  surface = cairo.SVGSurface(filename, width, height)
-  
+  surface = cairo.SVGSurface(filename, max (width, 800), max (height, 600))
+
   ctx = cairo.Context (surface)
 
   #fill background
   ctx.set_source_rgb (1, 1, 1)
-  ctx.rectangle (0, 0, width, height)
+  ctx.rectangle (0, 0,  max (width, 800), max (height, 600))
   ctx.fill ()
-  
+
   #print header
   info['total_time'] = "%s secs" % total_size
   sheader = header.substitute(info)
-  
+
   ctx.translate (padding_left, padding_top)
   ctx.set_source_rgb (0, 0, 0)
   for line in sheader.split("\n"):
     ctx.translate (0, 12)
     ctx.show_text (line)
     ctx.fill ()
-  
-  ctx.translate (0, 12)
-  
-  draw_bg_graph (ctx, total_size, len (data) * bar_height + 16)
-  
+
+  ctx.translate (6, 12)
+
+  draw_bg_graph (ctx, total_size + 0.5, max (len (data) * bar_height + 64, 500))
+
   ctx.set_line_width (1)
   for item in data:
     x = item['start'] * width_multiplier
     x1 = (item['end'] - item['start']) * width_multiplier
     ctx.translate (x, 0)
-    
+
     ctx.set_source_rgba (0.35, 0.65, 0.8, 0.5)
     ctx.rectangle (0, 0, x1, 16)
     ctx.fill ()
-    
+
     ctx.set_source_rgba (0.35, 0.65, 0.8, 1.0)
     ctx.rectangle (0, 0, x1, 16)
     ctx.stroke ()
-    
+
     ctx.translate (8, 10)
     ctx.set_source_rgb (0.0, 0.0, 0.0)
-    ctx.show_text ("%s %.2f seconds" % (item['name'], round (item["end"] - item["start"], 2)))
+    ctx.show_text ("%s %.4f seconds" % (item['name'], item["end"] - item["start"]))
     ctx.fill()
-    
+
     ctx.translate (-x-8, 6)
 
 def build_data_structure (input):
@@ -162,13 +162,13 @@
     start = float(row[1])
     end = float(row[2])
     structure.append ({"name": name, "start": start, "end": end})
-  
+
   structure.sort (sort_by_domain)
   return structure
-    
+
 
 def usage():
-  print "use --input=filename.log and --output=filename.svg :)" 
+  print "use --input=filename.log and --output=filename.svg :)"
 
 def main():
 
@@ -179,7 +179,7 @@
     print str(err) # will print something like "option -a not recognized"
     usage()
     sys.exit(2)
-    
+
   output = None
   input = None
   for o, a in opts:
@@ -196,7 +196,7 @@
   if (not output or not input):
     usage()
     sys.exit()
-    
+
   data = build_data_structure (input)
   info = gatherinfo (input)
   build_graph (data, output, info)