bundles/org.simantics.utils.thread/src/org/simantics/utils/threads/logger/ThreadLogVisualizer.java

   1 /*******************************************************************************
   2  * Copyright (c) 2007, 2010 Association for Decentralized Information Management
   3  * in Industry THTH ry.
   4  * All rights reserved. This program and the accompanying materials
   5  * are made available under the terms of the Eclipse Public License v1.0
   6  * which accompanies this distribution, and is available at
   7  * http://www.eclipse.org/legal/epl-v10.html
   8  *
   9  * Contributors:
  10  *     VTT Technical Research Centre of Finland - initial API and implementation
  11  *******************************************************************************/
  12 package org.simantics.utils.threads.logger;
  13
  14 import java.io.DataInput;
  15 import java.io.DataInputStream;
  16 import java.io.EOFException;
  17 import java.io.FileInputStream;
  18 import java.io.FileNotFoundException;
  19 import java.io.IOException;
  20 import java.io.PrintStream;
  21 import java.util.ArrayList;
  22 import java.util.Collections;
  23 import java.util.HashMap;
  24 import java.util.Locale;
  25 import java.util.Map;
  26
  27 public class ThreadLogVisualizer {
  28
  29     // Do not show tasks shorter than 5ms
  30     final public static long DISCARD_LIMIT = 2 * 1000 * 1000;
  31     // 1s columns
  32     final public static long COLUMN_WIDTH = 1000000000;
  33
  34     final int onlyOneThread = -1;
  35
  36     final String colors[] = {
  37                 "#53c0a7",
  38                 "#ca49a1",
  39                 "#64b74e",
  40                 "#a159ca",
  41                 "#b6b345",
  42                 "#656bc5",
  43                 "#da943b",
  44                 "#5e99d3",
  45                 "#d1592b",
  46                 "#418a53",
  47                 "#e16182",
  48                 "#777d34",
  49                 "#ca89ca",
  50                 "#b7754c",
  51                 "#9e4b6b",
  52                 "#cb4347"
  53     };
  54
  55         class Task implements Comparable<Task> {
  56                 String name;
  57                 long beginTime;
  58                 long endTime;
  59                 long threadId;
  60                 long combined = 0;
  61
  62                 public Task(String name, long threadId, long beginTime, long endTime) {
  63                         if(name.length() > 100) name = name.substring(0, 99);
  64                         this.name = name;
  65                         this.threadId = threadId;
  66                         this.beginTime = beginTime;
  67                         this.endTime = endTime;
  68                 }
  69
  70                 @Override
  71                 // Differences will not fit into int
  72                 public int compareTo(Task o) {
  73             if(beginTime > o.beginTime) return 1;
  74             else if(beginTime == o.beginTime) return -1;
  75                     else return -1;
  76                 }
  77         }
  78
  79         ArrayList<Task> tasks = new ArrayList<Task>();
  80
  81         private boolean acceptThread(long threadId) {
  82                 if(onlyOneThread == -1) return true;
  83                 else return (threadId&15) == onlyOneThread;
  84         }
  85
  86         private Map<Long, Task> compositeTasks = new HashMap<>();
  87
  88         public void read(DataInput input) {
  89                 try {
  90                         while(true) {
  91                                 try {
  92                                         String taskName = input.readUTF();
  93                                         long threadId = input.readLong();
  94                                         long beginTime = input.readLong();
  95                                         long endTime = input.readLong();
  96                                         if(!acceptThread(threadId)) continue;
  97                                         if((endTime-beginTime) > DISCARD_LIMIT) {
  98                                                 tasks.add(new Task(taskName, threadId, beginTime, endTime));
  99                                                 Task t = compositeTasks.remove(threadId);
 100                                                 if(t != null) {
 101                                                         if((t.endTime-t.beginTime) > DISCARD_LIMIT) {
 102                                                                 tasks.add(new Task(t.combined + " small tasks", t.threadId, t.beginTime, t.endTime));
 103                                                         }
 104                                                 }
 105                                         } else {
 106                                                 Task t = compositeTasks.get(threadId);
 107                                                 if(t == null) {
 108                                                         t = new Task("", threadId, beginTime, endTime);
 109                                                         compositeTasks.put(threadId, t);
 110                                                 }
 111                                                 if(beginTime - t.endTime > DISCARD_LIMIT) {
 112                                                         tasks.add(new Task(t.combined + " small tasks", t.threadId, t.beginTime, t.endTime));
 113                                                         t = new Task("", threadId, beginTime, endTime);
 114                                                         compositeTasks.put(threadId, t);
 115                                                 }
 116                                                 t.endTime = endTime;
 117                                                 t.combined++;
 118                                                 if((t.endTime-t.beginTime) > DISCARD_LIMIT) {
 119                                                         tasks.add(new Task(t.combined + " small tasks", t.threadId, t.beginTime, t.endTime));
 120                                                         compositeTasks.remove(threadId);
 121                                                 }
 122                                         }
 123                                 } catch(EOFException e) {
 124                                         break;
 125                                 }
 126                         }
 127                 } catch(IOException e) {
 128                 }
 129
 130                 Collections.sort(tasks);
 131         }
 132
 133         class Lane {
 134                 ArrayList<Task> tasks = new ArrayList<Task>();
 135                 long nextTime = 0;
 136         }
 137
 138     public void visualize3(PrintStream s) {
 139
 140         long minTime = Long.MAX_VALUE;
 141         long maxTime = Long.MIN_VALUE;
 142
 143         ArrayList<Lane> lanes = new ArrayList<Lane>();
 144
 145         int laneId = 0;
 146         for(Task task : tasks) {
 147
 148             Lane lane;
 149
 150             minTime = Math.min(minTime, task.beginTime);
 151             maxTime = Math.max(maxTime, task.endTime);
 152
 153             for(int seek = laneId-1; seek >= 0; --seek) {
 154                 if(lanes.get(seek).nextTime < task.beginTime) {
 155                     laneId = seek;
 156                 } else {
 157                     break;
 158                 }
 159             }
 160
 161             if(laneId < lanes.size())
 162                 lane = lanes.get(laneId);
 163             else {
 164                 lane = new Lane();
 165                 lanes.add(lane);
 166             }
 167
 168             lane.tasks.add(task);
 169             lane.nextTime = Math.max(task.endTime, task.beginTime+COLUMN_WIDTH);
 170             System.out.println(task.name + " -> " + laneId + "[" + task.beginTime + "-" + task.endTime + "]");
 171
 172             laneId++;
 173
 174         }
 175
 176         double timeScale = 1e-6;
 177         double rowHeight = 30.0;
 178         Locale locale = Locale.US;
 179         int row = lanes.size();
 180
 181         s.println("<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"no\"?>");
 182         s.println("<svg xmlns=\"http://www.w3.org/2000/svg\" overflow=\"visible\" version=\"1.1\">");
 183         for(long time = minTime ; time < maxTime ; time += 1000000000) {
 184             s.printf(locale,
 185                     "<line x1=\"%f\" y1=\"%f\" x2=\"%f\" y2=\"%f\" stroke=\"grey\"/>\n",
 186                     (time-minTime)*timeScale,
 187                     0.0,
 188                     (time-minTime)*timeScale,
 189                     row*rowHeight);
 190         }
 191         for(int r = 0;r<lanes.size();++r) {
 192             Lane lane = lanes.get(r);
 193             for(Task task : lane.tasks) {
 194                 s.printf(locale,
 195                         "<line x1=\"%f\" y1=\"%f\" x2=\"%f\" y2=\"%f\" stroke=\"black\"/>\n",
 196                         (task.beginTime-minTime)*timeScale,
 197                         r*rowHeight,
 198                         (task.beginTime-minTime)*timeScale,
 199                         (r+1)*rowHeight);
 200                 s.printf(locale,
 201                         "<rect x=\"%f\" y=\"%f\" width=\"%f\" height=\"%f\" fill=\"" + colors[(int)task.threadId & 15] + "\"/>\n",
 202                         (task.beginTime-minTime)*timeScale,
 203                         r*rowHeight,
 204                         (task.endTime-task.beginTime)*timeScale,
 205                         rowHeight);
 206             }
 207             for(Task task : lane.tasks) {
 208                 int time = (int)(1e-6 * (task.endTime-task.beginTime));
 209                 s.printf(locale,
 210                         "<text x=\"%f\" y=\"%f\">%s</text>\n",
 211                         (task.endTime-minTime)*timeScale,
 212                         (r+0.8)*rowHeight,
 213                         Integer.toString(time) + "ms: " + task.name);
 214             }
 215         }
 216         s.println("</svg>");
 217     }
 218
 219         public void visualize2(PrintStream s) {
 220                 long minTime = Long.MAX_VALUE;
 221                 long maxTime = Long.MIN_VALUE;
 222                 ArrayList<Lane> lanes = new ArrayList<Lane>();
 223
 224                 for(Task task : tasks) {
 225                         minTime = Math.min(minTime, task.beginTime);
 226                         maxTime = Math.max(maxTime, task.endTime);
 227                         int laneId;
 228                         for(laneId=0;laneId<lanes.size();++laneId)
 229                                 if(lanes.get(laneId).nextTime < task.beginTime)
 230                                         break;
 231                         Lane lane;
 232                         if(laneId < lanes.size())
 233                                 lane = lanes.get(laneId);
 234                         else {
 235                                 lane = new Lane();
 236                                 lanes.add(lane);
 237                         }
 238                         lane.tasks.add(task);
 239                         lane.nextTime = Math.max(task.endTime, task.beginTime+COLUMN_WIDTH);
 240                         System.out.println(task.name + " -> " + laneId + "[" + task.beginTime + "-" + task.endTime + "]");
 241                 }
 242
 243                 double timeScale = 1e-7*5;
 244                 double rowHeight = 30.0;
 245                 Locale locale = Locale.US;
 246                 int row = lanes.size();
 247
 248                 s.println("<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"no\"?>");
 249                 s.println("<svg xmlns=\"http://www.w3.org/2000/svg\" overflow=\"visible\" version=\"1.1\">");
 250                 for(long time = minTime ; time < maxTime ; time += 1000000000) {
 251                         s.printf(locale,
 252                                         "<line x1=\"%f\" y1=\"%f\" x2=\"%f\" y2=\"%f\" stroke=\"grey\"/>\n",
 253                                         (time-minTime)*timeScale,
 254                                         0.0,
 255                                         (time-minTime)*timeScale,
 256                                         row*rowHeight);
 257                 }
 258                 for(int r = 0;r<lanes.size();++r) {
 259                         Lane lane = lanes.get(r);
 260                         for(Task task : lane.tasks) {
 261                                 s.printf(locale,
 262                                                 "<line x1=\"%f\" y1=\"%f\" x2=\"%f\" y2=\"%f\" stroke=\"black\"/>\n",
 263                                                 (task.beginTime-minTime)*timeScale,
 264                                                 r*rowHeight,
 265                                                 (task.beginTime-minTime)*timeScale,
 266                                                 (r+1)*rowHeight);
 267                                 s.printf(locale,
 268                                                 "<rect x=\"%f\" y=\"%f\" width=\"%f\" height=\"%f\" fill=\"" + colors[(int)task.threadId & 15] + "\"/>\n",
 269                                                 (task.beginTime-minTime)*timeScale,
 270                                                 r*rowHeight,
 271                                                 (task.endTime-task.beginTime)*timeScale,
 272                                                 rowHeight);
 273                         }
 274                         for(Task task : lane.tasks) {
 275                                 s.printf(locale,
 276                                                 "<text x=\"%f\" y=\"%f\">%s</text>\n",
 277                                                 (task.endTime-minTime)*timeScale,
 278                                                 (r+0.8)*rowHeight,
 279                                                 task.name);
 280                         }
 281                 }
 282                 s.println("</svg>");
 283         }
 284
 285         public void visualize(PrintStream s) {
 286                 long minTime = Long.MAX_VALUE;
 287                 long maxTime = Long.MIN_VALUE;
 288                 Map<Long, Integer> threads = new HashMap<Long, Integer>();
 289                 int row = 0;
 290
 291                 for(Task task : tasks) {
 292                         minTime = Math.min(minTime, task.beginTime);
 293                         maxTime = Math.max(maxTime, task.endTime);
 294                         if(!threads.containsKey(task.threadId))
 295                                 threads.put(task.threadId, row++);
 296                 }
 297
 298                 double timeScale = 1e-7*0.8;
 299                 double rowHeight = 60.0;
 300                 Locale locale = Locale.US;
 301                 int textPos[] = new int[row];
 302
 303                 s.println("<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"no\"?>");
 304                 s.println("<svg xmlns=\"http://www.w3.org/2000/svg\" overflow=\"visible\" version=\"1.1\">");
 305                 for(long time = minTime ; time < maxTime ; time += 1000000000) {
 306                         s.printf(locale,
 307                                         "<line x1=\"%f\" y1=\"%f\" x2=\"%f\" y2=\"%f\" stroke=\"grey\"/>\n",
 308                                         (time-minTime)*timeScale,
 309                                         0.0,
 310                                         (time-minTime)*timeScale,
 311                                         row*rowHeight);
 312                 }
 313                 for(Task task : tasks) {
 314                         int r = threads.get(task.threadId);
 315                         s.printf(locale,
 316                                         "<line x1=\"%f\" y1=\"%f\" x2=\"%f\" y2=\"%f\" stroke=\"black\"/>\n",
 317                                         (task.beginTime-minTime)*timeScale,
 318                                         r*rowHeight,
 319                                         (task.beginTime-minTime)*timeScale,
 320                                         (r+1)*rowHeight);
 321                         s.printf(locale,
 322                                         "<rect x=\"%f\" y=\"%f\" width=\"%f\" height=\"%f\" fill=\"" + colors[(int)task.threadId & 15] + "\"/>\n",
 323                                         (task.beginTime-minTime)*timeScale,
 324                                         r*rowHeight,
 325                                         (task.endTime-task.beginTime)*timeScale,
 326                                         rowHeight);
 327                 }
 328                 for(Task task : tasks) {
 329                         int r = threads.get(task.threadId);
 330                         s.printf(locale,
 331                                         "<text x=\"%f\" y=\"%f\">%s</text>\n",
 332                                         (task.endTime-minTime)*timeScale,
 333                                         (r*3+(textPos[r]++)%2+0.5)*rowHeight/3,
 334                                         task.name);
 335                 }
 336                 s.println("</svg>");
 337         }
 338
 339         public static void main(String[] args) {
 340                 try {
 341                         ThreadLogVisualizer visualizer = new ThreadLogVisualizer();
 342                         visualizer.read(new DataInputStream(new FileInputStream(ThreadLogger.LOG_FILE)));
 343                         visualizer.visualize3(new PrintStream(ThreadLogger.LOG_FILE + ".svg"));
 344                 } catch (FileNotFoundException e) {
 345                         // TODO Auto-generated catch block
 346                         e.printStackTrace();
 347                 }
 348         }
 349
 350 }