7a32351bd59d1e2038d3a77613f6ce6a1edfb8db
[ust.git] / libust / marker.c
1 /*
2 * Copyright (C) 2007 Mathieu Desnoyers
3 *
4 * This library is free software; you can redistribute it and/or
5 * modify it under the terms of the GNU Lesser General Public
6 * License as published by the Free Software Foundation; either
7 * version 2.1 of the License, or (at your option) any later version.
8 *
9 * This library is distributed in the hope that it will be useful,
10 * but WITHOUT ANY WARRANTY; without even the implied warranty of
11 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
12 * Lesser General Public License for more details.
13 *
14 * You should have received a copy of the GNU Lesser General Public
15 * License along with this library; if not, write to the Free Software
16 * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA
17 */
18
19 #include <stdlib.h>
20 #include <errno.h>
21 #define _LGPL_SOURCE
22 #include <urcu-bp.h>
23 #include <urcu/rculist.h>
24 #include <urcu/hlist.h>
25
26 #include <ust/core.h>
27 #include <ust/marker.h>
28 #include <ust/tracepoint.h>
29
30 #include "usterr.h"
31 #include "channels.h"
32 #include "tracercore.h"
33 #include "tracer.h"
34
35 __thread long ust_reg_stack[500];
36 volatile __thread long *ust_reg_stack_ptr = (long *) 0;
37
38 extern struct marker __start___markers[] __attribute__((visibility("hidden")));
39 extern struct marker __stop___markers[] __attribute__((visibility("hidden")));
40
41 /* Set to 1 to enable marker debug output */
42 static const int marker_debug;
43
44 /*
45 * markers_mutex nests inside module_mutex. Markers mutex protects the builtin
46 * and module markers and the hash table.
47 */
48 static DEFINE_MUTEX(markers_mutex);
49
50 static CDS_LIST_HEAD(libs);
51
52
53 void lock_markers(void)
54 {
55 pthread_mutex_lock(&markers_mutex);
56 }
57
58 void unlock_markers(void)
59 {
60 pthread_mutex_unlock(&markers_mutex);
61 }
62
63 /*
64 * Marker hash table, containing the active markers.
65 * Protected by module_mutex.
66 */
67 #define MARKER_HASH_BITS 6
68 #define MARKER_TABLE_SIZE (1 << MARKER_HASH_BITS)
69 static struct cds_hlist_head marker_table[MARKER_TABLE_SIZE];
70
71 /*
72 * Note about RCU :
73 * It is used to make sure every handler has finished using its private data
74 * between two consecutive operation (add or remove) on a given marker. It is
75 * also used to delay the free of multiple probes array until a quiescent state
76 * is reached.
77 * marker entries modifications are protected by the markers_mutex.
78 */
79 struct marker_entry {
80 struct cds_hlist_node hlist;
81 char *format;
82 char *name;
83 /* Probe wrapper */
84 void (*call)(const struct marker *mdata, void *call_private, struct registers *regs, ...);
85 struct marker_probe_closure single;
86 struct marker_probe_closure *multi;
87 int refcount; /* Number of times armed. 0 if disarmed. */
88 struct rcu_head rcu;
89 void *oldptr;
90 int rcu_pending;
91 u16 channel_id;
92 u16 event_id;
93 unsigned char ptype:1;
94 unsigned char format_allocated:1;
95 char channel[0]; /* Contains channel'\0'name'\0'format'\0' */
96 };
97
98 #ifdef CONFIG_MARKERS_USERSPACE
99 static void marker_update_processes(void);
100 #else
101 static void marker_update_processes(void)
102 {
103 }
104 #endif
105
106 /**
107 * __mark_empty_function - Empty probe callback
108 * @mdata: marker data
109 * @probe_private: probe private data
110 * @call_private: call site private data
111 * @fmt: format string
112 * @...: variable argument list
113 *
114 * Empty callback provided as a probe to the markers. By providing this to a
115 * disabled marker, we make sure the execution flow is always valid even
116 * though the function pointer change and the marker enabling are two distinct
117 * operations that modifies the execution flow of preemptible code.
118 */
119 notrace void __mark_empty_function(const struct marker *mdata,
120 void *probe_private, struct registers *regs, void *call_private, const char *fmt, va_list *args)
121 {
122 }
123 //ust// EXPORT_SYMBOL_GPL(__mark_empty_function);
124
125 /*
126 * marker_probe_cb Callback that prepares the variable argument list for probes.
127 * @mdata: pointer of type struct marker
128 * @call_private: caller site private data
129 * @...: Variable argument list.
130 *
131 * Since we do not use "typical" pointer based RCU in the 1 argument case, we
132 * need to put a full cmm_smp_rmb() in this branch. This is why we do not use
133 * rcu_dereference() for the pointer read.
134 */
135 notrace void marker_probe_cb(const struct marker *mdata,
136 void *call_private, struct registers *regs, ...)
137 {
138 va_list args;
139 char ptype;
140
141 /*
142 * rcu_read_lock_sched does two things : disabling preemption to make
143 * sure the teardown of the callbacks can be done correctly when they
144 * are in modules and they insure RCU read coherency.
145 */
146 //ust// rcu_read_lock_sched_notrace();
147 ptype = mdata->ptype;
148 if (likely(!ptype)) {
149 marker_probe_func *func;
150 /* Must read the ptype before ptr. They are not data dependant,
151 * so we put an explicit cmm_smp_rmb() here. */
152 cmm_smp_rmb();
153 func = mdata->single.func;
154 /* Must read the ptr before private data. They are not data
155 * dependant, so we put an explicit cmm_smp_rmb() here. */
156 cmm_smp_rmb();
157 va_start(args, regs);
158 func(mdata, mdata->single.probe_private, regs, call_private,
159 mdata->format, &args);
160 va_end(args);
161 } else {
162 struct marker_probe_closure *multi;
163 int i;
164 /*
165 * Read mdata->ptype before mdata->multi.
166 */
167 cmm_smp_rmb();
168 multi = mdata->multi;
169 /*
170 * multi points to an array, therefore accessing the array
171 * depends on reading multi. However, even in this case,
172 * we must insure that the pointer is read _before_ the array
173 * data. Same as rcu_dereference, but we need a full cmm_smp_rmb()
174 * in the fast path, so put the explicit cmm_barrier here.
175 */
176 cmm_smp_read_barrier_depends();
177 for (i = 0; multi[i].func; i++) {
178 va_start(args, regs);
179 multi[i].func(mdata, multi[i].probe_private,
180 regs, call_private, mdata->format, &args);
181 va_end(args);
182 }
183 }
184 //ust// rcu_read_unlock_sched_notrace();
185 }
186 //ust// EXPORT_SYMBOL_GPL(marker_probe_cb);
187
188 /*
189 * marker_probe_cb Callback that does not prepare the variable argument list.
190 * @mdata: pointer of type struct marker
191 * @call_private: caller site private data
192 * @...: Variable argument list.
193 *
194 * Should be connected to markers "MARK_NOARGS".
195 */
196 static notrace void marker_probe_cb_noarg(const struct marker *mdata,
197 void *call_private, struct registers *regs, ...)
198 {
199 va_list args; /* not initialized */
200 char ptype;
201
202 //ust// rcu_read_lock_sched_notrace();
203 ptype = mdata->ptype;
204 if (likely(!ptype)) {
205 marker_probe_func *func;
206 /* Must read the ptype before ptr. They are not data dependant,
207 * so we put an explicit cmm_smp_rmb() here. */
208 cmm_smp_rmb();
209 func = mdata->single.func;
210 /* Must read the ptr before private data. They are not data
211 * dependant, so we put an explicit cmm_smp_rmb() here. */
212 cmm_smp_rmb();
213 func(mdata, mdata->single.probe_private, regs, call_private,
214 mdata->format, &args);
215 } else {
216 struct marker_probe_closure *multi;
217 int i;
218 /*
219 * Read mdata->ptype before mdata->multi.
220 */
221 cmm_smp_rmb();
222 multi = mdata->multi;
223 /*
224 * multi points to an array, therefore accessing the array
225 * depends on reading multi. However, even in this case,
226 * we must insure that the pointer is read _before_ the array
227 * data. Same as rcu_dereference, but we need a full cmm_smp_rmb()
228 * in the fast path, so put the explicit cmm_barrier here.
229 */
230 cmm_smp_read_barrier_depends();
231 for (i = 0; multi[i].func; i++)
232 multi[i].func(mdata, multi[i].probe_private, regs,
233 call_private, mdata->format, &args);
234 }
235 //ust// rcu_read_unlock_sched_notrace();
236 }
237
238 static void free_old_closure(struct rcu_head *head)
239 {
240 struct marker_entry *entry = _ust_container_of(head,
241 struct marker_entry, rcu);
242 free(entry->oldptr);
243 /* Make sure we free the data before setting the pending flag to 0 */
244 cmm_smp_wmb();
245 entry->rcu_pending = 0;
246 }
247
248 static void debug_print_probes(struct marker_entry *entry)
249 {
250 int i;
251
252 if (!marker_debug)
253 return;
254
255 if (!entry->ptype) {
256 DBG("Single probe : %p %p",
257 entry->single.func,
258 entry->single.probe_private);
259 } else {
260 for (i = 0; entry->multi[i].func; i++)
261 DBG("Multi probe %d : %p %p", i,
262 entry->multi[i].func,
263 entry->multi[i].probe_private);
264 }
265 }
266
267 static struct marker_probe_closure *
268 marker_entry_add_probe(struct marker_entry *entry,
269 marker_probe_func *probe, void *probe_private)
270 {
271 int nr_probes = 0;
272 struct marker_probe_closure *old, *new;
273
274 WARN_ON(!probe);
275
276 debug_print_probes(entry);
277 old = entry->multi;
278 if (!entry->ptype) {
279 if (entry->single.func == probe &&
280 entry->single.probe_private == probe_private)
281 return ERR_PTR(-EBUSY);
282 if (entry->single.func == __mark_empty_function) {
283 /* 0 -> 1 probes */
284 entry->single.func = probe;
285 entry->single.probe_private = probe_private;
286 entry->refcount = 1;
287 entry->ptype = 0;
288 debug_print_probes(entry);
289 return NULL;
290 } else {
291 /* 1 -> 2 probes */
292 nr_probes = 1;
293 old = NULL;
294 }
295 } else {
296 /* (N -> N+1), (N != 0, 1) probes */
297 for (nr_probes = 0; old[nr_probes].func; nr_probes++)
298 if (old[nr_probes].func == probe
299 && old[nr_probes].probe_private
300 == probe_private)
301 return ERR_PTR(-EBUSY);
302 }
303 /* + 2 : one for new probe, one for NULL func */
304 new = zmalloc((nr_probes + 2) * sizeof(struct marker_probe_closure));
305 if (new == NULL)
306 return ERR_PTR(-ENOMEM);
307 if (!old)
308 new[0] = entry->single;
309 else
310 memcpy(new, old,
311 nr_probes * sizeof(struct marker_probe_closure));
312 new[nr_probes].func = probe;
313 new[nr_probes].probe_private = probe_private;
314 entry->refcount = nr_probes + 1;
315 entry->multi = new;
316 entry->ptype = 1;
317 debug_print_probes(entry);
318 return old;
319 }
320
321 static struct marker_probe_closure *
322 marker_entry_remove_probe(struct marker_entry *entry,
323 marker_probe_func *probe, void *probe_private)
324 {
325 int nr_probes = 0, nr_del = 0, i;
326 struct marker_probe_closure *old, *new;
327
328 old = entry->multi;
329
330 debug_print_probes(entry);
331 if (!entry->ptype) {
332 /* 0 -> N is an error */
333 WARN_ON(entry->single.func == __mark_empty_function);
334 /* 1 -> 0 probes */
335 WARN_ON(probe && entry->single.func != probe);
336 WARN_ON(entry->single.probe_private != probe_private);
337 entry->single.func = __mark_empty_function;
338 entry->refcount = 0;
339 entry->ptype = 0;
340 debug_print_probes(entry);
341 return NULL;
342 } else {
343 /* (N -> M), (N > 1, M >= 0) probes */
344 for (nr_probes = 0; old[nr_probes].func; nr_probes++) {
345 if ((!probe || old[nr_probes].func == probe)
346 && old[nr_probes].probe_private
347 == probe_private)
348 nr_del++;
349 }
350 }
351
352 if (nr_probes - nr_del == 0) {
353 /* N -> 0, (N > 1) */
354 entry->single.func = __mark_empty_function;
355 entry->refcount = 0;
356 entry->ptype = 0;
357 } else if (nr_probes - nr_del == 1) {
358 /* N -> 1, (N > 1) */
359 for (i = 0; old[i].func; i++)
360 if ((probe && old[i].func != probe) ||
361 old[i].probe_private != probe_private)
362 entry->single = old[i];
363 entry->refcount = 1;
364 entry->ptype = 0;
365 } else {
366 int j = 0;
367 /* N -> M, (N > 1, M > 1) */
368 /* + 1 for NULL */
369 new = zmalloc((nr_probes - nr_del + 1) * sizeof(struct marker_probe_closure));
370 if (new == NULL)
371 return ERR_PTR(-ENOMEM);
372 for (i = 0; old[i].func; i++)
373 if ((probe && old[i].func != probe) ||
374 old[i].probe_private != probe_private)
375 new[j++] = old[i];
376 entry->refcount = nr_probes - nr_del;
377 entry->ptype = 1;
378 entry->multi = new;
379 }
380 debug_print_probes(entry);
381 return old;
382 }
383
384 /*
385 * Get marker if the marker is present in the marker hash table.
386 * Must be called with markers_mutex held.
387 * Returns NULL if not present.
388 */
389 static struct marker_entry *get_marker(const char *channel, const char *name)
390 {
391 struct cds_hlist_head *head;
392 struct cds_hlist_node *node;
393 struct marker_entry *e;
394 size_t channel_len = strlen(channel) + 1;
395 size_t name_len = strlen(name) + 1;
396 u32 hash;
397
398 hash = jhash(channel, channel_len-1, 0) ^ jhash(name, name_len-1, 0);
399 head = &marker_table[hash & ((1 << MARKER_HASH_BITS)-1)];
400 cds_hlist_for_each_entry(e, node, head, hlist) {
401 if (!strcmp(channel, e->channel) && !strcmp(name, e->name))
402 return e;
403 }
404 return NULL;
405 }
406
407 /*
408 * Add the marker to the marker hash table. Must be called with markers_mutex
409 * held.
410 */
411 static struct marker_entry *add_marker(const char *channel, const char *name,
412 const char *format)
413 {
414 struct cds_hlist_head *head;
415 struct cds_hlist_node *node;
416 struct marker_entry *e;
417 size_t channel_len = strlen(channel) + 1;
418 size_t name_len = strlen(name) + 1;
419 size_t format_len = 0;
420 u32 hash;
421
422 hash = jhash(channel, channel_len-1, 0) ^ jhash(name, name_len-1, 0);
423 if (format)
424 format_len = strlen(format) + 1;
425 head = &marker_table[hash & ((1 << MARKER_HASH_BITS)-1)];
426 cds_hlist_for_each_entry(e, node, head, hlist) {
427 if (!strcmp(channel, e->channel) && !strcmp(name, e->name)) {
428 DBG("Marker %s.%s busy", channel, name);
429 return ERR_PTR(-EBUSY); /* Already there */
430 }
431 }
432 /*
433 * Using zmalloc here to allocate a variable length element. Could
434 * cause some memory fragmentation if overused.
435 */
436 e = zmalloc(sizeof(struct marker_entry)
437 + channel_len + name_len + format_len);
438 if (!e)
439 return ERR_PTR(-ENOMEM);
440 memcpy(e->channel, channel, channel_len);
441 e->name = &e->channel[channel_len];
442 memcpy(e->name, name, name_len);
443 if (format) {
444 e->format = &e->name[name_len];
445 memcpy(e->format, format, format_len);
446 if (strcmp(e->format, MARK_NOARGS) == 0)
447 e->call = marker_probe_cb_noarg;
448 else
449 e->call = marker_probe_cb;
450 trace_mark(metadata, core_marker_format,
451 "channel %s name %s format %s",
452 e->channel, e->name, e->format);
453 } else {
454 e->format = NULL;
455 e->call = marker_probe_cb;
456 }
457 e->single.func = __mark_empty_function;
458 e->single.probe_private = NULL;
459 e->multi = NULL;
460 e->ptype = 0;
461 e->format_allocated = 0;
462 e->refcount = 0;
463 e->rcu_pending = 0;
464 cds_hlist_add_head(&e->hlist, head);
465 return e;
466 }
467
468 /*
469 * Remove the marker from the marker hash table. Must be called with mutex_lock
470 * held.
471 */
472 static int remove_marker(const char *channel, const char *name)
473 {
474 struct cds_hlist_head *head;
475 struct cds_hlist_node *node;
476 struct marker_entry *e;
477 int found = 0;
478 size_t channel_len = strlen(channel) + 1;
479 size_t name_len = strlen(name) + 1;
480 u32 hash;
481 int ret;
482
483 hash = jhash(channel, channel_len-1, 0) ^ jhash(name, name_len-1, 0);
484 head = &marker_table[hash & ((1 << MARKER_HASH_BITS)-1)];
485 cds_hlist_for_each_entry(e, node, head, hlist) {
486 if (!strcmp(channel, e->channel) && !strcmp(name, e->name)) {
487 found = 1;
488 break;
489 }
490 }
491 if (!found)
492 return -ENOENT;
493 if (e->single.func != __mark_empty_function)
494 return -EBUSY;
495 cds_hlist_del(&e->hlist);
496 if (e->format_allocated)
497 free(e->format);
498 ret = ltt_channels_unregister(e->channel);
499 WARN_ON(ret);
500 /* Make sure the call_rcu has been executed */
501 //ust// if (e->rcu_pending)
502 //ust// rcu_cmm_barrier_sched();
503 free(e);
504 return 0;
505 }
506
507 /*
508 * Set the mark_entry format to the format found in the element.
509 */
510 static int marker_set_format(struct marker_entry *entry, const char *format)
511 {
512 entry->format = strdup(format);
513 if (!entry->format)
514 return -ENOMEM;
515 entry->format_allocated = 1;
516
517 trace_mark(metadata, core_marker_format,
518 "channel %s name %s format %s",
519 entry->channel, entry->name, entry->format);
520 return 0;
521 }
522
523 /*
524 * Sets the probe callback corresponding to one marker.
525 */
526 static int set_marker(struct marker_entry *entry, struct marker *elem,
527 int active)
528 {
529 int ret = 0;
530 WARN_ON(strcmp(entry->name, elem->name) != 0);
531
532 if (entry->format) {
533 if (strcmp(entry->format, elem->format) != 0) {
534 ERR("Format mismatch for probe %s (%s), marker (%s)",
535 entry->name,
536 entry->format,
537 elem->format);
538 return -EPERM;
539 }
540 } else {
541 ret = marker_set_format(entry, elem->format);
542 if (ret)
543 return ret;
544 }
545
546 /*
547 * probe_cb setup (statically known) is done here. It is
548 * asynchronous with the rest of execution, therefore we only
549 * pass from a "safe" callback (with argument) to an "unsafe"
550 * callback (does not set arguments).
551 */
552 elem->call = entry->call;
553 elem->channel_id = entry->channel_id;
554 elem->event_id = entry->event_id;
555 /*
556 * Sanity check :
557 * We only update the single probe private data when the ptr is
558 * set to a _non_ single probe! (0 -> 1 and N -> 1, N != 1)
559 */
560 WARN_ON(elem->single.func != __mark_empty_function
561 && elem->single.probe_private != entry->single.probe_private
562 && !elem->ptype);
563 elem->single.probe_private = entry->single.probe_private;
564 /*
565 * Make sure the private data is valid when we update the
566 * single probe ptr.
567 */
568 cmm_smp_wmb();
569 elem->single.func = entry->single.func;
570 /*
571 * We also make sure that the new probe callbacks array is consistent
572 * before setting a pointer to it.
573 */
574 rcu_assign_pointer(elem->multi, entry->multi);
575 /*
576 * Update the function or multi probe array pointer before setting the
577 * ptype.
578 */
579 cmm_smp_wmb();
580 elem->ptype = entry->ptype;
581
582 if (elem->tp_name && (active ^ _imv_read(elem->state))) {
583 WARN_ON(!elem->tp_cb);
584 /*
585 * It is ok to directly call the probe registration because type
586 * checking has been done in the __trace_mark_tp() macro.
587 */
588
589 if (active) {
590 /*
591 * try_module_get should always succeed because we hold
592 * markers_mutex to get the tp_cb address.
593 */
594 //ust// ret = try_module_get(__module_text_address(
595 //ust// (unsigned long)elem->tp_cb));
596 //ust// BUG_ON(!ret);
597 ret = tracepoint_probe_register_noupdate(
598 elem->tp_name,
599 elem->tp_cb, NULL);
600 } else {
601 ret = tracepoint_probe_unregister_noupdate(
602 elem->tp_name,
603 elem->tp_cb, NULL);
604 /*
605 * tracepoint_probe_update_all() must be called
606 * before the module containing tp_cb is unloaded.
607 */
608 //ust// module_put(__module_text_address(
609 //ust// (unsigned long)elem->tp_cb));
610 }
611 }
612 elem->state__imv = active;
613
614 return ret;
615 }
616
617 /*
618 * Disable a marker and its probe callback.
619 * Note: only waiting an RCU period after setting elem->call to the empty
620 * function insures that the original callback is not used anymore. This insured
621 * by rcu_read_lock_sched around the call site.
622 */
623 static void disable_marker(struct marker *elem)
624 {
625 int ret;
626
627 /* leave "call" as is. It is known statically. */
628 if (elem->tp_name && _imv_read(elem->state)) {
629 WARN_ON(!elem->tp_cb);
630 /*
631 * It is ok to directly call the probe registration because type
632 * checking has been done in the __trace_mark_tp() macro.
633 */
634 ret = tracepoint_probe_unregister_noupdate(elem->tp_name,
635 elem->tp_cb, NULL);
636 WARN_ON(ret);
637 /*
638 * tracepoint_probe_update_all() must be called
639 * before the module containing tp_cb is unloaded.
640 */
641 //ust// module_put(__module_text_address((unsigned long)elem->tp_cb));
642 }
643 elem->state__imv = 0;
644 elem->single.func = __mark_empty_function;
645 /* Update the function before setting the ptype */
646 cmm_smp_wmb();
647 elem->ptype = 0; /* single probe */
648 /*
649 * Leave the private data and channel_id/event_id there, because removal
650 * is racy and should be done only after an RCU period. These are never
651 * used until the next initialization anyway.
652 */
653 }
654
655 /*
656 * is_marker_enabled - Check if a marker is enabled
657 * @channel: channel name
658 * @name: marker name
659 *
660 * Returns 1 if the marker is enabled, 0 if disabled.
661 */
662 int is_marker_enabled(const char *channel, const char *name)
663 {
664 struct marker_entry *entry;
665
666 pthread_mutex_lock(&markers_mutex);
667 entry = get_marker(channel, name);
668 pthread_mutex_unlock(&markers_mutex);
669
670 return entry && !!entry->refcount;
671 }
672
673 /**
674 * marker_update_probe_range - Update a probe range
675 * @begin: beginning of the range
676 * @end: end of the range
677 *
678 * Updates the probe callback corresponding to a range of markers.
679 */
680 void marker_update_probe_range(struct marker *begin,
681 struct marker *end)
682 {
683 struct marker *iter;
684 struct marker_entry *mark_entry;
685
686 pthread_mutex_lock(&markers_mutex);
687 for (iter = begin; iter < end; iter++) {
688 mark_entry = get_marker(iter->channel, iter->name);
689 if (mark_entry) {
690 set_marker(mark_entry, iter, !!mark_entry->refcount);
691 /*
692 * ignore error, continue
693 */
694
695 /* This is added for UST. We emit a core_marker_id event
696 * for markers that are already registered to a probe
697 * upon library load. Otherwise, no core_marker_id will
698 * be generated for these markers. Is this the right thing
699 * to do?
700 */
701 trace_mark(metadata, core_marker_id,
702 "channel %s name %s event_id %hu "
703 "int #1u%zu long #1u%zu pointer #1u%zu "
704 "size_t #1u%zu alignment #1u%u",
705 iter->channel, iter->name, mark_entry->event_id,
706 sizeof(int), sizeof(long), sizeof(void *),
707 sizeof(size_t), ltt_get_alignment());
708 } else {
709 disable_marker(iter);
710 }
711 }
712 pthread_mutex_unlock(&markers_mutex);
713 }
714
715 static void lib_update_markers(void)
716 {
717 struct lib *lib;
718
719 /* FIXME: we should probably take a mutex here on libs */
720 //ust// pthread_mutex_lock(&module_mutex);
721 cds_list_for_each_entry(lib, &libs, list)
722 marker_update_probe_range(lib->markers_start,
723 lib->markers_start + lib->markers_count);
724 //ust// pthread_mutex_unlock(&module_mutex);
725 }
726
727 /*
728 * Update probes, removing the faulty probes.
729 *
730 * Internal callback only changed before the first probe is connected to it.
731 * Single probe private data can only be changed on 0 -> 1 and 2 -> 1
732 * transitions. All other transitions will leave the old private data valid.
733 * This makes the non-atomicity of the callback/private data updates valid.
734 *
735 * "special case" updates :
736 * 0 -> 1 callback
737 * 1 -> 0 callback
738 * 1 -> 2 callbacks
739 * 2 -> 1 callbacks
740 * Other updates all behave the same, just like the 2 -> 3 or 3 -> 2 updates.
741 * Site effect : marker_set_format may delete the marker entry (creating a
742 * replacement).
743 */
744 static void marker_update_probes(void)
745 {
746 /* Core kernel markers */
747 //ust// marker_update_probe_range(__start___markers, __stop___markers);
748 /* Markers in modules. */
749 //ust// module_update_markers();
750 lib_update_markers();
751 tracepoint_probe_update_all();
752 /* Update immediate values */
753 core_imv_update();
754 //ust// module_imv_update(); /* FIXME: need to port for libs? */
755 marker_update_processes();
756 }
757
758 /**
759 * marker_probe_register - Connect a probe to a marker
760 * @channel: marker channel
761 * @name: marker name
762 * @format: format string
763 * @probe: probe handler
764 * @probe_private: probe private data
765 *
766 * private data must be a valid allocated memory address, or NULL.
767 * Returns 0 if ok, error value on error.
768 * The probe address must at least be aligned on the architecture pointer size.
769 */
770 int marker_probe_register(const char *channel, const char *name,
771 const char *format, marker_probe_func *probe,
772 void *probe_private)
773 {
774 struct marker_entry *entry;
775 int ret = 0, ret_err;
776 struct marker_probe_closure *old;
777 int first_probe = 0;
778
779 pthread_mutex_lock(&markers_mutex);
780 entry = get_marker(channel, name);
781 if (!entry) {
782 first_probe = 1;
783 entry = add_marker(channel, name, format);
784 if (IS_ERR(entry))
785 ret = PTR_ERR(entry);
786 if (ret)
787 goto end;
788 ret = ltt_channels_register(channel);
789 if (ret)
790 goto error_remove_marker;
791 ret = ltt_channels_get_index_from_name(channel);
792 if (ret < 0)
793 goto error_unregister_channel;
794 entry->channel_id = ret;
795 ret = ltt_channels_get_event_id(channel, name);
796 if (ret < 0)
797 goto error_unregister_channel;
798 entry->event_id = ret;
799 ret = 0;
800 trace_mark(metadata, core_marker_id,
801 "channel %s name %s event_id %hu "
802 "int #1u%zu long #1u%zu pointer #1u%zu "
803 "size_t #1u%zu alignment #1u%u",
804 channel, name, entry->event_id,
805 sizeof(int), sizeof(long), sizeof(void *),
806 sizeof(size_t), ltt_get_alignment());
807 } else if (format) {
808 if (!entry->format)
809 ret = marker_set_format(entry, format);
810 else if (strcmp(entry->format, format))
811 ret = -EPERM;
812 if (ret)
813 goto end;
814 }
815
816 /*
817 * If we detect that a call_rcu is pending for this marker,
818 * make sure it's executed now.
819 */
820 //ust// if (entry->rcu_pending)
821 //ust// rcu_cmm_barrier_sched();
822 old = marker_entry_add_probe(entry, probe, probe_private);
823 if (IS_ERR(old)) {
824 ret = PTR_ERR(old);
825 if (first_probe)
826 goto error_unregister_channel;
827 else
828 goto end;
829 }
830 pthread_mutex_unlock(&markers_mutex);
831
832 /* Activate marker if necessary */
833 marker_update_probes();
834
835 pthread_mutex_lock(&markers_mutex);
836 entry = get_marker(channel, name);
837 if (!entry)
838 goto end;
839 //ust// if (entry->rcu_pending)
840 //ust// rcu_cmm_barrier_sched();
841 entry->oldptr = old;
842 entry->rcu_pending = 1;
843 /* write rcu_pending before calling the RCU callback */
844 cmm_smp_wmb();
845 //ust// call_rcu_sched(&entry->rcu, free_old_closure);
846 synchronize_rcu(); free_old_closure(&entry->rcu);
847 goto end;
848
849 error_unregister_channel:
850 ret_err = ltt_channels_unregister(channel);
851 WARN_ON(ret_err);
852 error_remove_marker:
853 ret_err = remove_marker(channel, name);
854 WARN_ON(ret_err);
855 end:
856 pthread_mutex_unlock(&markers_mutex);
857 return ret;
858 }
859 //ust// EXPORT_SYMBOL_GPL(marker_probe_register);
860
861 /**
862 * marker_probe_unregister - Disconnect a probe from a marker
863 * @channel: marker channel
864 * @name: marker name
865 * @probe: probe function pointer
866 * @probe_private: probe private data
867 *
868 * Returns the private data given to marker_probe_register, or an ERR_PTR().
869 * We do not need to call a synchronize_sched to make sure the probes have
870 * finished running before doing a module unload, because the module unload
871 * itself uses stop_machine(), which insures that every preempt disabled section
872 * have finished.
873 */
874 int marker_probe_unregister(const char *channel, const char *name,
875 marker_probe_func *probe, void *probe_private)
876 {
877 struct marker_entry *entry;
878 struct marker_probe_closure *old;
879 int ret = -ENOENT;
880
881 pthread_mutex_lock(&markers_mutex);
882 entry = get_marker(channel, name);
883 if (!entry)
884 goto end;
885 //ust// if (entry->rcu_pending)
886 //ust// rcu_cmm_barrier_sched();
887 old = marker_entry_remove_probe(entry, probe, probe_private);
888 pthread_mutex_unlock(&markers_mutex);
889
890 marker_update_probes();
891
892 pthread_mutex_lock(&markers_mutex);
893 entry = get_marker(channel, name);
894 if (!entry)
895 goto end;
896 //ust// if (entry->rcu_pending)
897 //ust// rcu_cmm_barrier_sched();
898 entry->oldptr = old;
899 entry->rcu_pending = 1;
900 /* write rcu_pending before calling the RCU callback */
901 cmm_smp_wmb();
902 //ust// call_rcu_sched(&entry->rcu, free_old_closure);
903 synchronize_rcu(); free_old_closure(&entry->rcu);
904 remove_marker(channel, name); /* Ignore busy error message */
905 ret = 0;
906 end:
907 pthread_mutex_unlock(&markers_mutex);
908 return ret;
909 }
910 //ust// EXPORT_SYMBOL_GPL(marker_probe_unregister);
911
912 static struct marker_entry *
913 get_marker_from_private_data(marker_probe_func *probe, void *probe_private)
914 {
915 struct marker_entry *entry;
916 unsigned int i;
917 struct cds_hlist_head *head;
918 struct cds_hlist_node *node;
919
920 for (i = 0; i < MARKER_TABLE_SIZE; i++) {
921 head = &marker_table[i];
922 cds_hlist_for_each_entry(entry, node, head, hlist) {
923 if (!entry->ptype) {
924 if (entry->single.func == probe
925 && entry->single.probe_private
926 == probe_private)
927 return entry;
928 } else {
929 struct marker_probe_closure *closure;
930 closure = entry->multi;
931 for (i = 0; closure[i].func; i++) {
932 if (closure[i].func == probe &&
933 closure[i].probe_private
934 == probe_private)
935 return entry;
936 }
937 }
938 }
939 }
940 return NULL;
941 }
942
943 /**
944 * marker_probe_unregister_private_data - Disconnect a probe from a marker
945 * @probe: probe function
946 * @probe_private: probe private data
947 *
948 * Unregister a probe by providing the registered private data.
949 * Only removes the first marker found in hash table.
950 * Return 0 on success or error value.
951 * We do not need to call a synchronize_sched to make sure the probes have
952 * finished running before doing a module unload, because the module unload
953 * itself uses stop_machine(), which insures that every preempt disabled section
954 * have finished.
955 */
956 int marker_probe_unregister_private_data(marker_probe_func *probe,
957 void *probe_private)
958 {
959 struct marker_entry *entry;
960 int ret = 0;
961 struct marker_probe_closure *old;
962 char *channel = NULL, *name = NULL;
963
964 pthread_mutex_lock(&markers_mutex);
965 entry = get_marker_from_private_data(probe, probe_private);
966 if (!entry) {
967 ret = -ENOENT;
968 goto end;
969 }
970 //ust// if (entry->rcu_pending)
971 //ust// rcu_cmm_barrier_sched();
972 old = marker_entry_remove_probe(entry, NULL, probe_private);
973 channel = strdup(entry->channel);
974 name = strdup(entry->name);
975 pthread_mutex_unlock(&markers_mutex);
976
977 marker_update_probes();
978
979 pthread_mutex_lock(&markers_mutex);
980 entry = get_marker(channel, name);
981 if (!entry)
982 goto end;
983 //ust// if (entry->rcu_pending)
984 //ust// rcu_cmm_barrier_sched();
985 entry->oldptr = old;
986 entry->rcu_pending = 1;
987 /* write rcu_pending before calling the RCU callback */
988 cmm_smp_wmb();
989 //ust// call_rcu_sched(&entry->rcu, free_old_closure);
990 synchronize_rcu(); free_old_closure(&entry->rcu);
991 /* Ignore busy error message */
992 remove_marker(channel, name);
993 end:
994 pthread_mutex_unlock(&markers_mutex);
995 free(channel);
996 free(name);
997 return ret;
998 }
999 //ust// EXPORT_SYMBOL_GPL(marker_probe_unregister_private_data);
1000
1001 /**
1002 * marker_get_private_data - Get a marker's probe private data
1003 * @channel: marker channel
1004 * @name: marker name
1005 * @probe: probe to match
1006 * @num: get the nth matching probe's private data
1007 *
1008 * Returns the nth private data pointer (starting from 0) matching, or an
1009 * ERR_PTR.
1010 * Returns the private data pointer, or an ERR_PTR.
1011 * The private data pointer should _only_ be dereferenced if the caller is the
1012 * owner of the data, or its content could vanish. This is mostly used to
1013 * confirm that a caller is the owner of a registered probe.
1014 */
1015 void *marker_get_private_data(const char *channel, const char *name,
1016 marker_probe_func *probe, int num)
1017 {
1018 struct cds_hlist_head *head;
1019 struct cds_hlist_node *node;
1020 struct marker_entry *e;
1021 size_t channel_len = strlen(channel) + 1;
1022 size_t name_len = strlen(name) + 1;
1023 int i;
1024 u32 hash;
1025
1026 hash = jhash(channel, channel_len-1, 0) ^ jhash(name, name_len-1, 0);
1027 head = &marker_table[hash & ((1 << MARKER_HASH_BITS)-1)];
1028 cds_hlist_for_each_entry(e, node, head, hlist) {
1029 if (!strcmp(channel, e->channel) && !strcmp(name, e->name)) {
1030 if (!e->ptype) {
1031 if (num == 0 && e->single.func == probe)
1032 return e->single.probe_private;
1033 } else {
1034 struct marker_probe_closure *closure;
1035 int match = 0;
1036 closure = e->multi;
1037 for (i = 0; closure[i].func; i++) {
1038 if (closure[i].func != probe)
1039 continue;
1040 if (match++ == num)
1041 return closure[i].probe_private;
1042 }
1043 }
1044 break;
1045 }
1046 }
1047 return ERR_PTR(-ENOENT);
1048 }
1049 //ust// EXPORT_SYMBOL_GPL(marker_get_private_data);
1050
1051 /**
1052 * markers_compact_event_ids - Compact markers event IDs and reassign channels
1053 *
1054 * Called when no channel users are active by the channel infrastructure.
1055 * Called with lock_markers() and channel mutex held.
1056 */
1057 //ust// void markers_compact_event_ids(void)
1058 //ust// {
1059 //ust// struct marker_entry *entry;
1060 //ust// unsigned int i;
1061 //ust// struct hlist_head *head;
1062 //ust// struct hlist_node *node;
1063 //ust// int ret;
1064 //ust//
1065 //ust// for (i = 0; i < MARKER_TABLE_SIZE; i++) {
1066 //ust// head = &marker_table[i];
1067 //ust// hlist_for_each_entry(entry, node, head, hlist) {
1068 //ust// ret = ltt_channels_get_index_from_name(entry->channel);
1069 //ust// WARN_ON(ret < 0);
1070 //ust// entry->channel_id = ret;
1071 //ust// ret = _ltt_channels_get_event_id(entry->channel,
1072 //ust// entry->name);
1073 //ust// WARN_ON(ret < 0);
1074 //ust// entry->event_id = ret;
1075 //ust// }
1076 //ust// }
1077 //ust// }
1078
1079 //ust//#ifdef CONFIG_MODULES
1080
1081 /*
1082 * Returns 0 if current not found.
1083 * Returns 1 if current found.
1084 */
1085 int lib_get_iter_markers(struct marker_iter *iter)
1086 {
1087 struct lib *iter_lib;
1088 int found = 0;
1089
1090 //ust// pthread_mutex_lock(&module_mutex);
1091 cds_list_for_each_entry(iter_lib, &libs, list) {
1092 if (iter_lib < iter->lib)
1093 continue;
1094 else if (iter_lib > iter->lib)
1095 iter->marker = NULL;
1096 found = marker_get_iter_range(&iter->marker,
1097 iter_lib->markers_start,
1098 iter_lib->markers_start + iter_lib->markers_count);
1099 if (found) {
1100 iter->lib = iter_lib;
1101 break;
1102 }
1103 }
1104 //ust// pthread_mutex_unlock(&module_mutex);
1105 return found;
1106 }
1107
1108 /**
1109 * marker_get_iter_range - Get a next marker iterator given a range.
1110 * @marker: current markers (in), next marker (out)
1111 * @begin: beginning of the range
1112 * @end: end of the range
1113 *
1114 * Returns whether a next marker has been found (1) or not (0).
1115 * Will return the first marker in the range if the input marker is NULL.
1116 */
1117 int marker_get_iter_range(struct marker **marker, struct marker *begin,
1118 struct marker *end)
1119 {
1120 if (!*marker && begin != end) {
1121 *marker = begin;
1122 return 1;
1123 }
1124 if (*marker >= begin && *marker < end)
1125 return 1;
1126 return 0;
1127 }
1128 //ust// EXPORT_SYMBOL_GPL(marker_get_iter_range);
1129
1130 static void marker_get_iter(struct marker_iter *iter)
1131 {
1132 int found = 0;
1133
1134 /* Core kernel markers */
1135 if (!iter->lib) {
1136 /* ust FIXME: how come we cannot disable the following line? we shouldn't need core stuff */
1137 found = marker_get_iter_range(&iter->marker,
1138 __start___markers, __stop___markers);
1139 if (found)
1140 goto end;
1141 }
1142 /* Markers in modules. */
1143 found = lib_get_iter_markers(iter);
1144 end:
1145 if (!found)
1146 marker_iter_reset(iter);
1147 }
1148
1149 void marker_iter_start(struct marker_iter *iter)
1150 {
1151 marker_get_iter(iter);
1152 }
1153 //ust// EXPORT_SYMBOL_GPL(marker_iter_start);
1154
1155 void marker_iter_next(struct marker_iter *iter)
1156 {
1157 iter->marker++;
1158 /*
1159 * iter->marker may be invalid because we blindly incremented it.
1160 * Make sure it is valid by marshalling on the markers, getting the
1161 * markers from following modules if necessary.
1162 */
1163 marker_get_iter(iter);
1164 }
1165 //ust// EXPORT_SYMBOL_GPL(marker_iter_next);
1166
1167 void marker_iter_stop(struct marker_iter *iter)
1168 {
1169 }
1170 //ust// EXPORT_SYMBOL_GPL(marker_iter_stop);
1171
1172 void marker_iter_reset(struct marker_iter *iter)
1173 {
1174 iter->lib = NULL;
1175 iter->marker = NULL;
1176 }
1177 //ust// EXPORT_SYMBOL_GPL(marker_iter_reset);
1178
1179 #ifdef CONFIG_MARKERS_USERSPACE
1180 /*
1181 * must be called with current->user_markers_mutex held
1182 */
1183 static void free_user_marker(char __user *state, struct cds_hlist_head *head)
1184 {
1185 struct user_marker *umark;
1186 struct cds_hlist_node *pos, *n;
1187
1188 cds_hlist_for_each_entry_safe(umark, pos, n, head, hlist) {
1189 if (umark->state == state) {
1190 cds_hlist_del(&umark->hlist);
1191 free(umark);
1192 }
1193 }
1194 }
1195
1196 /*
1197 * Update current process.
1198 * Note that we have to wait a whole scheduler period before we are sure that
1199 * every running userspace threads have their markers updated.
1200 * (synchronize_sched() can be used to insure this).
1201 */
1202 //ust// void marker_update_process(void)
1203 //ust// {
1204 //ust// struct user_marker *umark;
1205 //ust// struct hlist_node *pos;
1206 //ust// struct marker_entry *entry;
1207 //ust//
1208 //ust// pthread_mutex_lock(&markers_mutex);
1209 //ust// pthread_mutex_lock(&current->group_leader->user_markers_mutex);
1210 //ust// if (strcmp(current->comm, "testprog") == 0)
1211 //ust// DBG("do update pending for testprog");
1212 //ust// hlist_for_each_entry(umark, pos,
1213 //ust// &current->group_leader->user_markers, hlist) {
1214 //ust// DBG("Updating marker %s in %s", umark->name, current->comm);
1215 //ust// entry = get_marker("userspace", umark->name);
1216 //ust// if (entry) {
1217 //ust// if (entry->format &&
1218 //ust// strcmp(entry->format, umark->format) != 0) {
1219 //ust// WARN("error, wrong format in process %s",
1220 //ust// current->comm);
1221 //ust// break;
1222 //ust// }
1223 //ust// if (put_user(!!entry->refcount, umark->state)) {
1224 //ust// WARN("Marker in %s caused a fault",
1225 //ust// current->comm);
1226 //ust// break;
1227 //ust// }
1228 //ust// } else {
1229 //ust// if (put_user(0, umark->state)) {
1230 //ust// WARN("Marker in %s caused a fault", current->comm);
1231 //ust// break;
1232 //ust// }
1233 //ust// }
1234 //ust// }
1235 //ust// clear_thread_flag(TIF_MARKER_PENDING);
1236 //ust// pthread_mutex_unlock(&current->group_leader->user_markers_mutex);
1237 //ust// pthread_mutex_unlock(&markers_mutex);
1238 //ust// }
1239
1240 /*
1241 * Called at process exit and upon do_execve().
1242 * We assume that when the leader exits, no more references can be done to the
1243 * leader structure by the other threads.
1244 */
1245 void exit_user_markers(struct task_struct *p)
1246 {
1247 struct user_marker *umark;
1248 struct cds_hlist_node *pos, *n;
1249
1250 if (thread_group_leader(p)) {
1251 pthread_mutex_lock(&markers_mutex);
1252 pthread_mutex_lock(&p->user_markers_mutex);
1253 cds_hlist_for_each_entry_safe(umark, pos, n, &p->user_markers,
1254 hlist)
1255 free(umark);
1256 INIT_HLIST_HEAD(&p->user_markers);
1257 p->user_markers_sequence++;
1258 pthread_mutex_unlock(&p->user_markers_mutex);
1259 pthread_mutex_unlock(&markers_mutex);
1260 }
1261 }
1262
1263 int is_marker_enabled(const char *channel, const char *name)
1264 {
1265 struct marker_entry *entry;
1266
1267 pthread_mutex_lock(&markers_mutex);
1268 entry = get_marker(channel, name);
1269 pthread_mutex_unlock(&markers_mutex);
1270
1271 return entry && !!entry->refcount;
1272 }
1273 //ust// #endif
1274
1275 int marker_module_notify(struct notifier_block *self,
1276 unsigned long val, void *data)
1277 {
1278 struct module *mod = data;
1279
1280 switch (val) {
1281 case MODULE_STATE_COMING:
1282 marker_update_probe_range(mod->markers,
1283 mod->markers + mod->num_markers);
1284 break;
1285 case MODULE_STATE_GOING:
1286 marker_update_probe_range(mod->markers,
1287 mod->markers + mod->num_markers);
1288 break;
1289 }
1290 return 0;
1291 }
1292
1293 struct notifier_block marker_module_nb = {
1294 .notifier_call = marker_module_notify,
1295 .priority = 0,
1296 };
1297
1298 //ust// static int init_markers(void)
1299 //ust// {
1300 //ust// return register_module_notifier(&marker_module_nb);
1301 //ust// }
1302 //ust// __initcall(init_markers);
1303 /* TODO: call marker_module_nb() when a library is linked at runtime (dlopen)? */
1304
1305 #endif /* CONFIG_MODULES */
1306
1307 void ltt_dump_marker_state(struct ust_trace *trace)
1308 {
1309 struct marker_entry *entry;
1310 struct ltt_probe_private_data call_data;
1311 struct cds_hlist_head *head;
1312 struct cds_hlist_node *node;
1313 unsigned int i;
1314
1315 pthread_mutex_lock(&markers_mutex);
1316 call_data.trace = trace;
1317 call_data.serializer = NULL;
1318
1319 for (i = 0; i < MARKER_TABLE_SIZE; i++) {
1320 head = &marker_table[i];
1321 cds_hlist_for_each_entry(entry, node, head, hlist) {
1322 __trace_mark(0, metadata, core_marker_id,
1323 &call_data,
1324 "channel %s name %s event_id %hu "
1325 "int #1u%zu long #1u%zu pointer #1u%zu "
1326 "size_t #1u%zu alignment #1u%u",
1327 entry->channel,
1328 entry->name,
1329 entry->event_id,
1330 sizeof(int), sizeof(long),
1331 sizeof(void *), sizeof(size_t),
1332 ltt_get_alignment());
1333 if (entry->format)
1334 __trace_mark(0, metadata,
1335 core_marker_format,
1336 &call_data,
1337 "channel %s name %s format %s",
1338 entry->channel,
1339 entry->name,
1340 entry->format);
1341 }
1342 }
1343 pthread_mutex_unlock(&markers_mutex);
1344 }
1345 //ust// EXPORT_SYMBOL_GPL(ltt_dump_marker_state);
1346
1347 static void (*new_marker_cb)(struct marker *) = NULL;
1348
1349 void marker_set_new_marker_cb(void (*cb)(struct marker *))
1350 {
1351 new_marker_cb = cb;
1352 }
1353
1354 static void new_markers(struct marker *start, struct marker *end)
1355 {
1356 if(new_marker_cb) {
1357 struct marker *m;
1358 for(m=start; m < end; m++) {
1359 new_marker_cb(m);
1360 }
1361 }
1362 }
1363
1364 int marker_register_lib(struct marker *markers_start, int markers_count)
1365 {
1366 struct lib *pl;
1367
1368 pl = (struct lib *) zmalloc(sizeof(struct lib));
1369
1370 pl->markers_start = markers_start;
1371 pl->markers_count = markers_count;
1372
1373 /* FIXME: maybe protect this with its own mutex? */
1374 lock_markers();
1375 cds_list_add(&pl->list, &libs);
1376 unlock_markers();
1377
1378 new_markers(markers_start, markers_start + markers_count);
1379
1380 /* FIXME: update just the loaded lib */
1381 lib_update_markers();
1382
1383 DBG("just registered a markers section from %p and having %d markers", markers_start, markers_count);
1384
1385 return 0;
1386 }
1387
1388 int marker_unregister_lib(struct marker *markers_start)
1389 {
1390 struct lib *lib;
1391
1392 /*FIXME: implement; but before implementing, marker_register_lib must
1393 have appropriate locking. */
1394
1395 lock_markers();
1396
1397 /* FIXME: we should probably take a mutex here on libs */
1398 //ust// pthread_mutex_lock(&module_mutex);
1399 cds_list_for_each_entry(lib, &libs, list) {
1400 if(lib->markers_start == markers_start) {
1401 struct lib *lib2free = lib;
1402 cds_list_del(&lib->list);
1403 free(lib2free);
1404 break;
1405 }
1406 }
1407
1408 unlock_markers();
1409
1410 return 0;
1411 }
1412
1413 static int initialized = 0;
1414
1415 void __attribute__((constructor)) init_markers(void)
1416 {
1417 if(!initialized) {
1418 marker_register_lib(__start___markers, (((long)__stop___markers)-((long)__start___markers))/sizeof(struct marker));
1419 initialized = 1;
1420 }
1421 }
1422
1423 void __attribute__((constructor)) destroy_markers(void)
1424 {
1425 marker_unregister_lib(__start___markers);
1426 }
This page took 0.055303 seconds and 3 git commands to generate.