1 /* -*- mode: C; c-file-style: "gnu"; indent-tabs-mode: nil; -*- */
2
3 #include "config.h"
4
5 #include <string.h>
6
7 #include "cinnamon-perf-log.h"
8
9 typedef struct _CinnamonPerfEvent CinnamonPerfEvent;
10 typedef struct _CinnamonPerfStatistic CinnamonPerfStatistic;
11 typedef struct _CinnamonPerfStatisticsClosure CinnamonPerfStatisticsClosure;
12 typedef union _CinnamonPerfStatisticValue CinnamonPerfStatisticValue;
13 typedef struct _CinnamonPerfBlock CinnamonPerfBlock;
14
15 /**
16 * SECTION:cinnamon-perf-log
17 * @short_description: Event recorder for performance measurement
18 *
19 * CinnamonPerfLog provides a way for different parts of the code to
20 * record information for subsequent analysis and interactive
21 * exploration. Events exist of a timestamp, an event ID, and
22 * arguments to the event.
23 *
24 * Emphasis is placed on storing recorded events in a compact
25 * fashion so log recording disturbs the execution of the program
26 * as little as possible, however events should not be recorded
27 * at too fine a granularity - an event that is recorded once
28 * per frame or once per user action is appropriate, an event that
29 * occurs many times per frame is not.
30 *
31 * Arguments are identified by a D-Bus style signature; at the moment
32 * only a limited number of event signatures are supported to
33 * simplify the code.
34 */
35 struct _CinnamonPerfLog
36 {
37 GObject parent;
38
39 GPtrArray *events;
40 GHashTable *events_by_name;
41 GPtrArray *statistics;
42 GHashTable *statistics_by_name;
43
44 GPtrArray *statistics_closures;
45
46 GQueue *blocks;
47
48 gint64 start_time;
49 gint64 last_time;
50
51 guint statistics_timeout_id;
52
53 guint enabled : 1;
54 };
55
56 struct _CinnamonPerfLogClass
57 {
58 GObjectClass parent_class;
59 };
60
61 struct _CinnamonPerfEvent
62 {
63 guint16 id;
64 char *name;
65 char *description;
66 char *signature;
67 };
68
69 union _CinnamonPerfStatisticValue
70 {
71 int i;
72 gint64 x;
73 };
74
75 struct _CinnamonPerfStatistic
76 {
77 CinnamonPerfEvent *event;
78
79 CinnamonPerfStatisticValue current_value;
80 CinnamonPerfStatisticValue last_value;
81
82 guint initialized : 1;
83 guint recorded : 1;
84 };
85
86 struct _CinnamonPerfStatisticsClosure
87 {
88 CinnamonPerfStatisticsCallback callback;
89 gpointer user_data;
90 GDestroyNotify notify;
91 };
92
93 /* The events in the log are stored in a linked list of fixed size
94 * blocks.
95 *
96 * Note that the power-of-two nature of BLOCK_SIZE here is superficial
97 * since the allocated block has the 'bytes' field and malloc
98 * overhead. The current value is well below the size that will
99 * typically be independently mmapped by the malloc implementation so
100 * it doesn't matter. If we switched to mmapping blocks manually
101 * (perhaps to avoid polluting malloc statistics), we'd want to use a
102 * different value of BLOCK_SIZE.
103 */
104 #define BLOCK_SIZE 8192
105
106 struct _CinnamonPerfBlock
107 {
108 guint32 bytes;
109 guchar buffer[BLOCK_SIZE];
110 };
111
112 /* Number of milliseconds between periodic statistics collection when
113 * events are enabled. Statistics collection can also be explicitly
114 * triggered.
115 */
116 #define STATISTIC_COLLECTION_INTERVAL_MS 5000
117
118 /* Builtin events */
119 enum {
120 EVENT_SET_TIME,
121 EVENT_STATISTICS_COLLECTED
122 };
123
124 G_DEFINE_TYPE(CinnamonPerfLog, cinnamon_perf_log, G_TYPE_OBJECT);
125
126 static gint64
get_time(void)127 get_time (void)
128 {
129 GTimeVal timeval;
130
131 g_get_current_time (&timeval);
132
133 return timeval.tv_sec * G_GINT64_CONSTANT(1000000) + timeval.tv_usec;
134 }
135
136 static void
cinnamon_perf_log_init(CinnamonPerfLog * perf_log)137 cinnamon_perf_log_init (CinnamonPerfLog *perf_log)
138 {
139 perf_log->events = g_ptr_array_new ();
140 perf_log->events_by_name = g_hash_table_new (g_str_hash, g_str_equal);
141 perf_log->statistics = g_ptr_array_new ();
142 perf_log->statistics_by_name = g_hash_table_new (g_str_hash, g_str_equal);
143 perf_log->statistics_closures = g_ptr_array_new ();
144 perf_log->blocks = g_queue_new ();
145
146 /* This event is used when timestamp deltas are greater than
147 * fits in a gint32. 0xffffffff microseconds is about 70 minutes, so this
148 * is not going to happen in normal usage. It might happen if performance
149 * logging is enabled some time after starting Cinnamon */
150 cinnamon_perf_log_define_event (perf_log, "perf.setTime", "", "x");
151 g_assert (perf_log->events->len == EVENT_SET_TIME + 1);
152
153 /* The purpose of this event is to allow us to optimize out storing
154 * statistics that haven't changed. We want to mark every time we
155 * collect statistics even if we don't record any individual
156 * statistics so that we can distinguish sudden changes from gradual changes.
157 *
158 * The argument is the number of microseconds that statistics collection
159 * took; we record that since statistics collection could start taking
160 * significant time if we do things like grub around in /proc/
161 */
162 cinnamon_perf_log_define_event (perf_log, "perf.statisticsCollected",
163 "Finished collecting statistics",
164 "x");
165 g_assert (perf_log->events->len == EVENT_STATISTICS_COLLECTED + 1);
166
167 perf_log->start_time = perf_log->last_time = get_time();
168 }
169
170 static void
cinnamon_perf_log_class_init(CinnamonPerfLogClass * class)171 cinnamon_perf_log_class_init (CinnamonPerfLogClass *class)
172 {
173 }
174
175 /**
176 * cinnamon_perf_log_get_default:
177 *
178 * Gets the global singleton performance log. This is initially disabled
179 * and must be explicitly enabled with cinnamon_perf_log_set_enabled().
180 *
181 * Return value: (transfer none): the global singleton performance log
182 */
183 CinnamonPerfLog *
cinnamon_perf_log_get_default(void)184 cinnamon_perf_log_get_default (void)
185 {
186 static CinnamonPerfLog *perf_log;
187
188 if (perf_log == NULL)
189 perf_log = g_object_new (CINNAMON_TYPE_PERF_LOG, NULL);
190
191 return perf_log;
192 }
193
194 static gboolean
statistics_timeout(gpointer data)195 statistics_timeout (gpointer data)
196 {
197 CinnamonPerfLog *perf_log = data;
198
199 cinnamon_perf_log_collect_statistics (perf_log);
200
201 return TRUE;
202 }
203
204 /**
205 * cinnamon_perf_log_set_enabled:
206 * @perf_log: a #CinnamonPerfLog
207 * @enabled: whether to record events
208 *
209 * Sets whether events are currently being recorded.
210 */
211 void
cinnamon_perf_log_set_enabled(CinnamonPerfLog * perf_log,gboolean enabled)212 cinnamon_perf_log_set_enabled (CinnamonPerfLog *perf_log,
213 gboolean enabled)
214 {
215 enabled = enabled != FALSE;
216
217 if (enabled != perf_log->enabled)
218 {
219 perf_log->enabled = enabled;
220
221 if (enabled)
222 {
223 perf_log->statistics_timeout_id = g_timeout_add (STATISTIC_COLLECTION_INTERVAL_MS,
224 statistics_timeout,
225 perf_log);
226 }
227 else
228 {
229 if (perf_log->statistics_timeout_id){
230 g_source_remove (perf_log->statistics_timeout_id);
231 perf_log->statistics_timeout_id = 0;
232 }
233 }
234 }
235 }
236
237 static CinnamonPerfEvent *
define_event(CinnamonPerfLog * perf_log,const char * name,const char * description,const char * signature)238 define_event (CinnamonPerfLog *perf_log,
239 const char *name,
240 const char *description,
241 const char *signature)
242 {
243 CinnamonPerfEvent *event;
244
245 if (strcmp (signature, "") != 0 &&
246 strcmp (signature, "s") != 0 &&
247 strcmp (signature, "i") != 0 &&
248 strcmp (signature, "x") != 0)
249 {
250 g_warning ("Only supported event signatures are '', 's', 'i', and 'x'\n");
251 return NULL;
252 }
253
254 if (perf_log->events->len == 65536)
255 {
256 g_warning ("Maximum number of events defined\n");
257 return NULL;
258 }
259
260 /* We could do stricter validation, but this will break our JSON dumps */
261 if (strchr (name, '"') != NULL)
262 {
263 g_warning ("Event names can't include '\"'");
264 return NULL;
265 }
266
267 if (g_hash_table_lookup (perf_log->events_by_name, name) != NULL)
268 {
269 g_warning ("Duplicate event for '%s'\n", name);
270 return NULL;
271 }
272
273 event = g_slice_new (CinnamonPerfEvent);
274
275 event->id = perf_log->events->len;
276 event->name = g_strdup (name);
277 event->signature = g_strdup (signature);
278 event->description = g_strdup (description);
279
280 g_ptr_array_add (perf_log->events, event);
281 g_hash_table_insert (perf_log->events_by_name, event->name, event);
282
283 return event;
284 }
285
286 /**
287 * cinnamon_perf_log_define_event:
288 * @perf_log: a #CinnamonPerfLog
289 * @name: name of the event. This should of the form
290 * '<namespace>.<specific event>', for example
291 * 'clutter.stagePaintDone'.
292 * @description: human readable description of the event.
293 * @signature: signature defining the arguments that event takes.
294 * This is a string of type characters, using the same characters
295 * as D-Bus or GVariant. Only a very limited number of signatures
296 * are supported: , '', 's', 'i', and 'x'. This mean respectively:
297 * no arguments, one string, one 32-bit integer, and one 64-bit
298 * integer.
299 *
300 * Defines a performance event for later recording.
301 */
302 void
cinnamon_perf_log_define_event(CinnamonPerfLog * perf_log,const char * name,const char * description,const char * signature)303 cinnamon_perf_log_define_event (CinnamonPerfLog *perf_log,
304 const char *name,
305 const char *description,
306 const char *signature)
307 {
308 define_event (perf_log, name, description, signature);
309 }
310
311 static CinnamonPerfEvent *
lookup_event(CinnamonPerfLog * perf_log,const char * name,const char * signature)312 lookup_event (CinnamonPerfLog *perf_log,
313 const char *name,
314 const char *signature)
315 {
316 CinnamonPerfEvent *event = g_hash_table_lookup (perf_log->events_by_name, name);
317
318 if (G_UNLIKELY (event == NULL))
319 {
320 g_warning ("Discarding unknown event '%s'\n", name);
321 return NULL;
322 }
323
324 if (G_UNLIKELY (strcmp (event->signature, signature) != 0))
325 {
326 g_warning ("Event '%s'; defined with signature '%s', used with '%s'\n",
327 name, event->signature, signature);
328 return NULL;
329 }
330
331 return event;
332 }
333
334 static void
record_event(CinnamonPerfLog * perf_log,gint64 event_time,CinnamonPerfEvent * event,const guchar * bytes,size_t bytes_len)335 record_event (CinnamonPerfLog *perf_log,
336 gint64 event_time,
337 CinnamonPerfEvent *event,
338 const guchar *bytes,
339 size_t bytes_len)
340 {
341 CinnamonPerfBlock *block;
342 size_t total_bytes;
343 guint32 time_delta;
344 guint32 pos;
345
346 if (!perf_log->enabled)
347 return;
348
349 total_bytes = sizeof (gint32) + sizeof (gint16) + bytes_len;
350 if (G_UNLIKELY (bytes_len > BLOCK_SIZE || total_bytes > BLOCK_SIZE))
351 {
352 g_warning ("Discarding oversized event '%s'\n", event->name);
353 return;
354 }
355
356 if (event_time > perf_log->last_time + G_GINT64_CONSTANT(0xffffffff))
357 {
358 perf_log->last_time = event_time;
359 record_event (perf_log, event_time,
360 lookup_event (perf_log, "perf.setTime", "x"),
361 (const guchar *)&event_time, sizeof(gint64));
362 time_delta = 0;
363 }
364 else if (event_time < perf_log->last_time)
365 time_delta = 0;
366 else
367 time_delta = (guint32)(event_time - perf_log->last_time);
368
369 perf_log->last_time = event_time;
370
371 if (perf_log->blocks->tail == NULL ||
372 total_bytes + ((CinnamonPerfBlock *)perf_log->blocks->tail->data)->bytes > BLOCK_SIZE)
373 {
374 block = g_new (CinnamonPerfBlock, 1);
375 block->bytes = 0;
376 g_queue_push_tail (perf_log->blocks, block);
377 }
378 else
379 {
380 block = (CinnamonPerfBlock *)perf_log->blocks->tail->data;
381 }
382
383 pos = block->bytes;
384
385 memcpy (block->buffer + pos, &time_delta, sizeof (guint32));
386 pos += sizeof (guint32);
387 memcpy (block->buffer + pos, &event->id, sizeof (guint16));
388 pos += sizeof (guint16);
389 memcpy (block->buffer + pos, bytes, bytes_len);
390 pos += bytes_len;
391
392 block->bytes = pos;
393 }
394
395 /**
396 * cinnamon_perf_log_event:
397 * @perf_log: a #CinnamonPerfLog
398 * @name: name of the event
399 *
400 * Records a performance event with no arguments.
401 */
402 void
cinnamon_perf_log_event(CinnamonPerfLog * perf_log,const char * name)403 cinnamon_perf_log_event (CinnamonPerfLog *perf_log,
404 const char *name)
405 {
406 CinnamonPerfEvent *event = lookup_event (perf_log, name, "");
407 if (G_UNLIKELY (event == NULL))
408 return;
409
410 record_event (perf_log, get_time(), event, NULL, 0);
411 }
412
413 /**
414 * cinnamon_perf_log_event_i:
415 * @perf_log: a #CinnamonPerfLog
416 * @name: name of the event
417 * @arg: the argument
418 *
419 * Records a performance event with one 32-bit integer argument.
420 */
421 void
cinnamon_perf_log_event_i(CinnamonPerfLog * perf_log,const char * name,gint32 arg)422 cinnamon_perf_log_event_i (CinnamonPerfLog *perf_log,
423 const char *name,
424 gint32 arg)
425 {
426 CinnamonPerfEvent *event = lookup_event (perf_log, name, "i");
427 if (G_UNLIKELY (event == NULL))
428 return;
429
430 record_event (perf_log, get_time(), event,
431 (const guchar *)&arg, sizeof (arg));
432 }
433
434 /**
435 * cinnamon_perf_log_event_x:
436 * @perf_log: a #CinnamonPerfLog
437 * @name: name of the event
438 * @arg: the argument
439 *
440 * Records a performance event with one 64-bit integer argument.
441 */
442 void
cinnamon_perf_log_event_x(CinnamonPerfLog * perf_log,const char * name,gint64 arg)443 cinnamon_perf_log_event_x (CinnamonPerfLog *perf_log,
444 const char *name,
445 gint64 arg)
446 {
447 CinnamonPerfEvent *event = lookup_event (perf_log, name, "x");
448 if (G_UNLIKELY (event == NULL))
449 return;
450
451 record_event (perf_log, get_time(), event,
452 (const guchar *)&arg, sizeof (arg));
453 }
454
455 /**
456 * cinnamon_perf_log_event_s:
457 * @perf_log: a #CinnamonPerfLog
458 * @name: name of the event
459 * @arg: the argument
460 *
461 * Records a performance event with one string argument.
462 */
463 void
cinnamon_perf_log_event_s(CinnamonPerfLog * perf_log,const char * name,const char * arg)464 cinnamon_perf_log_event_s (CinnamonPerfLog *perf_log,
465 const char *name,
466 const char *arg)
467 {
468 CinnamonPerfEvent *event = lookup_event (perf_log, name, "s");
469 if (G_UNLIKELY (event == NULL))
470 return;
471
472 record_event (perf_log, get_time(), event,
473 (const guchar *)arg, strlen (arg) + 1);
474 }
475
476 /**
477 * cinnamon_perf_log_define_statistic:
478 * @perf_log: a #CinnamonPerfLog
479 * @name: name of the statistic and of the corresponding event.
480 * This should follow the same guidelines as for cinnamon_perf_log_define_event()
481 * @description: human readable description of the statistic.
482 * @signature: The type of the data stored for statistic. Must
483 * currently be 'i' or 'x'.
484 *
485 * Defines a statistic. A statistic is a numeric value that is stored
486 * by the performance log and recorded periodically or when
487 * cinnamon_perf_log_collect_statistics() is called explicitly.
488 *
489 * Code that defines a statistic should update it by calling
490 * the update function for the particular data type of the statistic,
491 * such as cinnamon_perf_log_update_statistic_i(). This can be done
492 * at any time, but would normally done inside a function registered
493 * with cinnamon_perf_log_add_statistics_callback(). These functions
494 * are called immediately before statistics are recorded.
495 */
496 void
cinnamon_perf_log_define_statistic(CinnamonPerfLog * perf_log,const char * name,const char * description,const char * signature)497 cinnamon_perf_log_define_statistic (CinnamonPerfLog *perf_log,
498 const char *name,
499 const char *description,
500 const char *signature)
501 {
502 CinnamonPerfEvent *event;
503 CinnamonPerfStatistic *statistic;
504
505 if (strcmp (signature, "i") != 0 &&
506 strcmp (signature, "x") != 0)
507 {
508 g_warning ("Only supported statistic signatures are 'i' and 'x'\n");
509 return;
510 }
511
512 event = define_event (perf_log, name, description, signature);
513 if (event == NULL)
514 return;
515
516 statistic = g_slice_new (CinnamonPerfStatistic);
517 statistic->event = event;
518
519 statistic->initialized = FALSE;
520 statistic->recorded = FALSE;
521
522 g_ptr_array_add (perf_log->statistics, statistic);
523 g_hash_table_insert (perf_log->statistics_by_name, event->name, statistic);
524 }
525
526 static CinnamonPerfStatistic *
lookup_statistic(CinnamonPerfLog * perf_log,const char * name,const char * signature)527 lookup_statistic (CinnamonPerfLog *perf_log,
528 const char *name,
529 const char *signature)
530 {
531 CinnamonPerfStatistic *statistic = g_hash_table_lookup (perf_log->statistics_by_name, name);
532
533 if (G_UNLIKELY (statistic == NULL))
534 {
535 g_warning ("Unknown statistic '%s'\n", name);
536 return NULL;
537 }
538
539 if (G_UNLIKELY (strcmp (statistic->event->signature, signature) != 0))
540 {
541 g_warning ("Statistic '%s'; defined with signature '%s', used with '%s'\n",
542 name, statistic->event->signature, signature);
543 return NULL;
544 }
545
546 return statistic;
547 }
548
549 /**
550 * cinnamon_perf_log_update_statistic_i:
551 * @perf_log: a #CinnamonPerfLog
552 * @name: name of the statistic
553 * @value: new value for the statistic
554 *
555 * Updates the current value of an 32-bit integer statistic.
556 */
557 void
cinnamon_perf_log_update_statistic_i(CinnamonPerfLog * perf_log,const char * name,gint32 value)558 cinnamon_perf_log_update_statistic_i (CinnamonPerfLog *perf_log,
559 const char *name,
560 gint32 value)
561 {
562 CinnamonPerfStatistic *statistic;
563
564 statistic = lookup_statistic (perf_log, name, "i");
565 if (G_UNLIKELY (statistic == NULL))
566 return;
567
568 statistic->current_value.i = value;
569 statistic->initialized = TRUE;
570 }
571
572 /**
573 * cinnamon_perf_log_update_statistic_x:
574 * @perf_log: a #CinnamonPerfLog
575 * @name: name of the statistic
576 * @value: new value for the statistic
577 *
578 * Updates the current value of an 64-bit integer statistic.
579 */
580 void
cinnamon_perf_log_update_statistic_x(CinnamonPerfLog * perf_log,const char * name,gint64 value)581 cinnamon_perf_log_update_statistic_x (CinnamonPerfLog *perf_log,
582 const char *name,
583 gint64 value)
584 {
585 CinnamonPerfStatistic *statistic;
586
587 statistic = lookup_statistic (perf_log, name, "x");
588 if (G_UNLIKELY (statistic == NULL))
589 return;
590
591 statistic->current_value.x = value;
592 statistic->initialized = TRUE;
593 }
594
595 /**
596 * cinnamon_perf_log_add_statistics_callback:
597 * @perf_log: a #CinnamonPerfLog
598 * @callback: function to call before recording statistics
599 * @user_data: data to pass to @callback
600 * @notify: function to call when @user_data is no longer needed
601 *
602 * Adds a function that will be called before statistics are recorded.
603 * The function would typically compute one or more statistics values
604 * and call a function such as cinnamon_perf_log_update_statistic_i()
605 * to update the value that will be recorded.
606 */
607 void
cinnamon_perf_log_add_statistics_callback(CinnamonPerfLog * perf_log,CinnamonPerfStatisticsCallback callback,gpointer user_data,GDestroyNotify notify)608 cinnamon_perf_log_add_statistics_callback (CinnamonPerfLog *perf_log,
609 CinnamonPerfStatisticsCallback callback,
610 gpointer user_data,
611 GDestroyNotify notify)
612 {
613 CinnamonPerfStatisticsClosure *closure = g_slice_new (CinnamonPerfStatisticsClosure);
614
615 closure->callback = callback;
616 closure->user_data = user_data;
617 closure->notify = notify;
618
619 g_ptr_array_add (perf_log->statistics_closures, closure);
620 }
621
622 /**
623 * cinnamon_perf_log_collect_statistics:
624 * @perf_log: a #CinnamonPerfLog
625 *
626 * Calls all the update functions added with
627 * cinnamon_perf_log_add_statistics_callback() and then records events
628 * for all statistics, followed by a perf.statisticsCollected event.
629 */
630 void
cinnamon_perf_log_collect_statistics(CinnamonPerfLog * perf_log)631 cinnamon_perf_log_collect_statistics (CinnamonPerfLog *perf_log)
632 {
633 gint64 event_time = get_time ();
634 gint64 collection_time;
635 guint i;
636
637 if (!perf_log->enabled)
638 return;
639
640 for (i = 0; i < perf_log->statistics_closures->len; i++)
641 {
642 CinnamonPerfStatisticsClosure *closure;
643
644 closure = g_ptr_array_index (perf_log->statistics_closures, i);
645 closure->callback (perf_log, closure->user_data);
646 }
647
648 collection_time = get_time() - event_time;
649
650 for (i = 0; i < perf_log->statistics->len; i++)
651 {
652 CinnamonPerfStatistic *statistic = g_ptr_array_index (perf_log->statistics, i);
653
654 if (!statistic->initialized)
655 continue;
656
657 switch (statistic->event->signature[0])
658 {
659 case 'i':
660 if (!statistic->recorded ||
661 statistic->current_value.i != statistic->last_value.i)
662 {
663 record_event (perf_log, event_time, statistic->event,
664 (const guchar *)&statistic->current_value.i,
665 sizeof (gint32));
666 statistic->last_value.i = statistic->current_value.i;
667 statistic->recorded = TRUE;
668 }
669 break;
670 case 'x':
671 if (!statistic->recorded ||
672 statistic->current_value.x != statistic->last_value.x)
673 {
674 record_event (perf_log, event_time, statistic->event,
675 (const guchar *)&statistic->current_value.x,
676 sizeof (gint64));
677 statistic->last_value.x = statistic->current_value.x;
678 statistic->recorded = TRUE;
679 }
680 break;
681 default:
682 g_warning("cinnamon_perf_log_collect_statistics: default case");
683 break;
684 }
685 }
686
687 record_event (perf_log, event_time,
688 g_ptr_array_index (perf_log->events, EVENT_STATISTICS_COLLECTED),
689 (const guchar *)&collection_time, sizeof (gint64));
690 }
691
692 /**
693 * cinnamon_perf_log_replay:
694 * @perf_log: a #CinnamonPerfLog
695 * @replay_function: (scope call): function to call for each event in the log
696 * @user_data: data to pass to @replay_function
697 *
698 * Replays the log by calling the given function for each event
699 * in the log.
700 */
701 void
cinnamon_perf_log_replay(CinnamonPerfLog * perf_log,CinnamonPerfReplayFunction replay_function,gpointer user_data)702 cinnamon_perf_log_replay (CinnamonPerfLog *perf_log,
703 CinnamonPerfReplayFunction replay_function,
704 gpointer user_data)
705 {
706 gint64 event_time = perf_log->start_time;
707 GList *iter;
708
709 for (iter = perf_log->blocks->head; iter; iter = iter->next)
710 {
711 CinnamonPerfBlock *block = iter->data;
712 guint32 pos = 0;
713
714 while (pos < block->bytes)
715 {
716 CinnamonPerfEvent *event;
717 guint16 id;
718 guint32 time_delta;
719 GValue arg = { 0, };
720
721 memcpy (&time_delta, block->buffer + pos, sizeof (guint32));
722 pos += sizeof (guint32);
723 memcpy (&id, block->buffer + pos, sizeof (guint16));
724 pos += sizeof (guint16);
725
726 if (id == EVENT_SET_TIME)
727 {
728 /* Internal, we don't include in the replay */
729 memcpy (&event_time, block->buffer + pos, sizeof (gint64));
730 pos += sizeof (gint64);
731 continue;
732 }
733 else
734 {
735 event_time += time_delta;
736 }
737
738 event = g_ptr_array_index (perf_log->events, id);
739
740 if (strcmp (event->signature, "") == 0)
741 {
742 /* We need to pass something, so pass an empty string */
743 g_value_init (&arg, G_TYPE_STRING);
744 }
745 else if (strcmp (event->signature, "i") == 0)
746 {
747 gint32 l;
748
749 memcpy (&l, block->buffer + pos, sizeof (gint32));
750 pos += sizeof (gint32);
751
752 g_value_init (&arg, G_TYPE_INT);
753 g_value_set_int (&arg, l);
754 }
755 else if (strcmp (event->signature, "x") == 0)
756 {
757 gint64 l;
758
759 memcpy (&l, block->buffer + pos, sizeof (gint64));
760 pos += sizeof (gint64);
761
762 g_value_init (&arg, G_TYPE_INT64);
763 g_value_set_int64 (&arg, l);
764 }
765 else if (strcmp (event->signature, "s") == 0)
766 {
767 g_value_init (&arg, G_TYPE_STRING);
768 g_value_set_string (&arg, (char *)block->buffer + pos);
769 pos += strlen ((char *)(block->buffer + pos)) + 1;
770 }
771
772 replay_function (event_time, event->name, event->signature, &arg, user_data);
773 g_value_unset (&arg);
774 }
775 }
776 }
777
778 static char *
escape_quotes(const char * input)779 escape_quotes (const char *input)
780 {
781 GString *result;
782 const char *p;
783
784 if (strchr (input, '"') == NULL)
785 return (char *)input;
786
787 result = g_string_new (NULL);
788 for (p = input; *p; p++)
789 {
790 if (*p == '"')
791 g_string_append (result, "\\\"");
792 else
793 g_string_append_c (result, *p);
794 }
795
796 return g_string_free (result, FALSE);
797 }
798
799 static gboolean
write_string(GOutputStream * out,const char * str,GError ** error)800 write_string (GOutputStream *out,
801 const char *str,
802 GError **error)
803 {
804 return g_output_stream_write_all (out, str, strlen (str),
805 NULL, NULL,
806 error);
807 }
808
809 /**
810 * cinnamon_perf_log_dump_events:
811 * @perf_log: a #CinnamonPerfLog
812 * @out: output stream into which to write the event definitions
813 * @error: location to store #GError, or %NULL
814 *
815 * Dump the definition of currently defined events and statistics, formatted
816 * as JSON, to the specified output stream. The JSON output is an array,
817 * with each element being a dictionary of the form:
818 *
819 * { name: <name of event>,
820 * description: <descrition of string,
821 * statistic: true } (only for statistics)
822 *
823 * Return value: %TRUE if the dump succeeded. %FALSE if an IO error occurred
824 */
825 gboolean
cinnamon_perf_log_dump_events(CinnamonPerfLog * perf_log,GOutputStream * out,GError ** error)826 cinnamon_perf_log_dump_events (CinnamonPerfLog *perf_log,
827 GOutputStream *out,
828 GError **error)
829 {
830 GString *output;
831 guint i;
832
833 output = g_string_new (NULL);
834 g_string_append (output, "[ ");
835
836 for (i = 0; i < perf_log->events->len; i++)
837 {
838 CinnamonPerfEvent *event = g_ptr_array_index (perf_log->events, i);
839 char *escaped_description = escape_quotes (event->description);
840 gboolean is_statistic = g_hash_table_lookup (perf_log->statistics_by_name, event->name) != NULL;
841
842 if (i != 0)
843 g_string_append (output, ",\n ");
844
845 g_string_append_printf (output,
846 "{ \"name\": \"%s\",\n"
847 " \"description\": \"%s\"",
848 event->name, escaped_description);
849 if (is_statistic)
850 g_string_append (output, ",\n \"statistic\": true");
851
852 g_string_append (output, " }");
853
854 if (escaped_description != event->description)
855 g_free (escaped_description);
856 }
857
858 g_string_append (output, " ]");
859
860 return write_string (out, g_string_free (output, FALSE), error);
861 }
862
863 typedef struct {
864 GOutputStream *out;
865 GError *error;
866 gboolean first;
867 } ReplayToJsonClosure;
868
869 static void
replay_to_json(gint64 time,const char * name,const char * signature,GValue * arg,gpointer user_data)870 replay_to_json (gint64 time,
871 const char *name,
872 const char *signature,
873 GValue *arg,
874 gpointer user_data)
875 {
876 ReplayToJsonClosure *closure = user_data;
877 char *event_str;
878
879 if (closure->error != NULL)
880 return;
881
882 if (!closure->first)
883 {
884 if (!write_string (closure->out, ",\n ", &closure->error))
885 return;
886 }
887
888 closure->first = FALSE;
889
890 if (strcmp (signature, "") == 0)
891 {
892 event_str = g_strdup_printf ("[%" G_GINT64_FORMAT ", \"%s\"]", time, name);
893 }
894 else if (strcmp (signature, "i") == 0)
895 {
896 event_str = g_strdup_printf ("[%" G_GINT64_FORMAT ", \"%s\", %i]",
897 time,
898 name,
899 g_value_get_int (arg));
900 }
901 else if (strcmp (signature, "x") == 0)
902 {
903 event_str = g_strdup_printf ("[%" G_GINT64_FORMAT ", \"%s\", %"G_GINT64_FORMAT "]",
904 time,
905 name,
906 g_value_get_int64 (arg));
907 }
908 else if (strcmp (signature, "s") == 0)
909 {
910 const char *arg_str = g_value_get_string (arg);
911 char *escaped = escape_quotes (arg_str);
912
913 event_str = g_strdup_printf ("[%" G_GINT64_FORMAT ", \"%s\", \"%s\"]",
914 time,
915 name,
916 g_value_get_string (arg));
917
918 if (escaped != arg_str)
919 g_free (escaped);
920 }
921 else
922 {
923 g_assert_not_reached ();
924 }
925
926 if (!write_string (closure->out, event_str, &closure->error))
927 return;
928 }
929
930 /**
931 * cinnamon_perf_log_dump_log:
932 * @perf_log: a #CinnamonPerfLog
933 * @out: output stream into which to write the event log
934 * @error: location to store #GError, or %NULL
935 *
936 * Writes the performance event log, formatted as JSON, to the specified
937 * output stream. For performance reasons, the output stream passed
938 * in should generally be a buffered (or memory) output stream, since
939 * it will be written to in small pieces. The JSON output is an array
940 * with the elements of the array also being arrays, of the form
941 * '[' <time>, <event name> [, <event_arg>... ] ']'.
942 *
943 * Return value: %TRUE if the dump succeeded. %FALSE if an IO error occurred
944 */
945 gboolean
cinnamon_perf_log_dump_log(CinnamonPerfLog * perf_log,GOutputStream * out,GError ** error)946 cinnamon_perf_log_dump_log (CinnamonPerfLog *perf_log,
947 GOutputStream *out,
948 GError **error)
949 {
950 ReplayToJsonClosure closure;
951
952 closure.out = out;
953 closure.error = NULL;
954 closure.first = TRUE;
955
956 if (!write_string (out, "[ ", &closure.error))
957 return FALSE;
958
959 cinnamon_perf_log_replay (perf_log, replay_to_json, &closure);
960
961 if (closure.error != NULL)
962 {
963 g_propagate_error (error, closure.error);
964 return FALSE;
965 }
966
967 if (!write_string (out, " ]", &closure.error))
968 return FALSE;
969
970 return TRUE;
971 }
972