libunity

Merge lp:~mhr3/libunity/easy-tracing into lp:libunity

  1. easy-tracing
  2. Merge into trunk
Proposed by Michal Hruby
Status: Merged
Approved by: Michal Hruby
Approved revision: 311
Merged at revision: 306
Proposed branch: lp:~mhr3/libunity/easy-tracing
Merge into: lp:libunity
Diff against target: 619 lines (+295/-36)
14 files modified
debian/libunity9.symbols (+1/-0)
src/unity-aggregator-scope-private.vala (+20/-9)
src/unity-deprecated-scope-impl.vala (+3/-2)
src/unity-models.vala (+3/-0)
src/unity-scope-dbus-impl.vala (+2/-2)
src/unity-scope-tracker.vala (+3/-2)
src/unity-search.vala (+2/-4)
src/unity-synchronizer.vala (+6/-3)
src/unity-trace.c (+3/-5)
src/unity-trace.h (+3/-1)
test/vala/Makefile.am (+8/-1)
test/vala/test-results-synchronizer.vala (+1/-1)
tools/capture-trace.py (+225/-0)
tools/unity-tool.vala (+15/-6)
To merge this branch: bzr merge lp:~mhr3/libunity/easy-tracing
Reviewer Review Type Date Requested Status
PS Jenkins bot (community) continuous-integration Approve
Paweł Stołowski (community) Approve
Review via email: mp+189497@code.launchpad.net

Commit message

Make tracing easy.

Description of the change

Make tracing easy using new capture_trace.py script in tools/.

To post a comment you must log in.
Revision history for this message
PS Jenkins bot (ps-jenkins) wrote :

PASSED: Continuous integration, rev:302
http://10.97.0.26:8080/job/libunity-ci/125/
Executed test runs:
    SUCCESS: http://10.97.0.26:8080/job/libunity-saucy-amd64-ci/110
    SUCCESS: http://10.97.0.26:8080/job/libunity-saucy-armhf-ci/110
    SUCCESS: http://10.97.0.26:8080/job/libunity-saucy-i386-ci/110

Click here to trigger a rebuild:
http://10.97.0.26:8080/job/libunity-ci/125/rebuild

review: Approve (continuous-integration)
Revision history for this message
PS Jenkins bot (ps-jenkins) wrote :

PASSED: Continuous integration, rev:303
http://10.97.0.26:8080/job/libunity-ci/126/
Executed test runs:
    SUCCESS: http://10.97.0.26:8080/job/libunity-saucy-amd64-ci/111
    SUCCESS: http://10.97.0.26:8080/job/libunity-saucy-armhf-ci/111
    SUCCESS: http://10.97.0.26:8080/job/libunity-saucy-i386-ci/111

Click here to trigger a rebuild:
http://10.97.0.26:8080/job/libunity-ci/126/rebuild

review: Approve (continuous-integration)
Revision history for this message
PS Jenkins bot (ps-jenkins) wrote :

PASSED: Continuous integration, rev:304
http://10.97.0.26:8080/job/libunity-ci/127/
Executed test runs:
    SUCCESS: http://10.97.0.26:8080/job/libunity-saucy-amd64-ci/112
    SUCCESS: http://10.97.0.26:8080/job/libunity-saucy-armhf-ci/112
    SUCCESS: http://10.97.0.26:8080/job/libunity-saucy-i386-ci/112

Click here to trigger a rebuild:
http://10.97.0.26:8080/job/libunity-ci/127/rebuild

review: Approve (continuous-integration)
Revision history for this message
PS Jenkins bot (ps-jenkins) wrote :

FAILED: Continuous integration, rev:306
http://jenkins.qa.ubuntu.com/job/libunity-ci/131/
Executed test runs:
    FAILURE: http://jenkins.qa.ubuntu.com/job/libunity-trusty-amd64-ci/2/console
    FAILURE: http://jenkins.qa.ubuntu.com/job/libunity-trusty-armhf-ci/2/console
    FAILURE: http://jenkins.qa.ubuntu.com/job/libunity-trusty-i386-ci/2/console

Click here to trigger a rebuild:
http://10.97.0.26:8080/job/libunity-ci/131/rebuild

review: Needs Fixing (continuous-integration)
Revision history for this message
PS Jenkins bot (ps-jenkins) wrote :

PASSED: Continuous integration, rev:308
http://jenkins.qa.ubuntu.com/job/libunity-ci/132/
Executed test runs:
    SUCCESS: http://jenkins.qa.ubuntu.com/job/libunity-trusty-amd64-ci/3
    SUCCESS: http://jenkins.qa.ubuntu.com/job/libunity-trusty-armhf-ci/3
    SUCCESS: http://jenkins.qa.ubuntu.com/job/libunity-trusty-i386-ci/3

Click here to trigger a rebuild:
http://10.97.0.26:8080/job/libunity-ci/132/rebuild

review: Approve (continuous-integration)
Revision history for this message
PS Jenkins bot (ps-jenkins) wrote :

PASSED: Continuous integration, rev:309
http://jenkins.qa.ubuntu.com/job/libunity-ci/133/
Executed test runs:
    SUCCESS: http://jenkins.qa.ubuntu.com/job/libunity-trusty-amd64-ci/4
    SUCCESS: http://jenkins.qa.ubuntu.com/job/libunity-trusty-armhf-ci/4
    SUCCESS: http://jenkins.qa.ubuntu.com/job/libunity-trusty-i386-ci/4

Click here to trigger a rebuild:
http://10.97.0.26:8080/job/libunity-ci/133/rebuild

review: Approve (continuous-integration)
Revision history for this message
Paweł Stołowski (stolowski) wrote :

Nice stuff, +1!

review: Approve
Revision history for this message
PS Jenkins bot (ps-jenkins) wrote :

PASSED: Continuous integration, rev:310
http://jenkins.qa.ubuntu.com/job/libunity-ci/134/
Executed test runs:
    SUCCESS: http://jenkins.qa.ubuntu.com/job/libunity-trusty-amd64-ci/5
    SUCCESS: http://jenkins.qa.ubuntu.com/job/libunity-trusty-armhf-ci/5
    SUCCESS: http://jenkins.qa.ubuntu.com/job/libunity-trusty-i386-ci/5

Click here to trigger a rebuild:
http://10.97.0.26:8080/job/libunity-ci/134/rebuild

review: Approve (continuous-integration)
Revision history for this message
PS Jenkins bot (ps-jenkins) wrote :

FAILED: Autolanding.
More details in the following jenkins job:
http://jenkins.qa.ubuntu.com/job/libunity-autolanding/87/
Executed test runs:
    SUCCESS: http://jenkins.qa.ubuntu.com/job/libunity-trusty-amd64-autolanding/2
    SUCCESS: http://jenkins.qa.ubuntu.com/job/libunity-trusty-armhf-autolanding/2
    FAILURE: http://jenkins.qa.ubuntu.com/job/libunity-trusty-i386-autolanding/2/console

review: Needs Fixing (continuous-integration)
Revision history for this message
PS Jenkins bot (ps-jenkins) wrote :

PASSED: Continuous integration, rev:311
http://jenkins.qa.ubuntu.com/job/libunity-ci/135/
Executed test runs:
    SUCCESS: http://jenkins.qa.ubuntu.com/job/libunity-trusty-amd64-ci/6
    SUCCESS: http://jenkins.qa.ubuntu.com/job/libunity-trusty-armhf-ci/6
    SUCCESS: http://jenkins.qa.ubuntu.com/job/libunity-trusty-i386-ci/6

Click here to trigger a rebuild:
http://10.97.0.26:8080/job/libunity-ci/135/rebuild

review: Approve (continuous-integration)
Revision history for this message
Michal Hruby (mhr3) wrote :

Looks like unrelated race in Dee that caused a failure here.

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
1=== modified file 'debian/libunity9.symbols'
2--- debian/libunity9.symbols 2013-10-24 15:19:00 +0000
3+++ debian/libunity9.symbols 2013-10-25 14:15:10 +0000
4@@ -689,6 +689,7 @@
5 unity_string_array_wrapper_take_strings@Base 4.0.6
6 unity_trace_log_object_real@Base 5.0.0
7 unity_trace_log_object_va@Base 5.0.0
8+ unity_trace_tracepoint_va@Base 0replaceme
9 unity_track_metadata_construct@Base 4.0.0
10 unity_track_metadata_construct_full@Base 5.92.0
11 unity_track_metadata_get_album@Base 4.0.0
12
13=== modified file 'src/unity-aggregator-scope-private.vala'
14--- src/unity-aggregator-scope-private.vala 2013-10-24 11:27:10 +0000
15+++ src/unity-aggregator-scope-private.vala 2013-10-25 14:15:10 +0000
16@@ -1194,13 +1194,13 @@
17 if (measure_requests) search_start_time = get_monotonic_time ();
18 int64 search_end_time = search_start_time;
19
20- Unity.Trace.tracepoint ("%s run start: %s", Log.METHOD, owner.id);
21-
22 var glib_cancellable = search_cancellable.get_gcancellable ();
23 ulong canc_sig_id = 0;
24 uint canc_src_id = 0;
25 bool was_cancelled = false;
26
27+ Unity.Trace.tracepoint ("search:start::scope=%s;query=%s", owner.id, search_string);
28+
29 // danger ahead, we're running the search in (possibly) different thread
30 // and at the same time waiting for the cancellable while holding
31 // channel lock (ChannelState set to SEARCH_ACTIVE), other searches won't
32@@ -1246,6 +1246,8 @@
33 yield;
34 }
35
36+ Unity.Trace.tracepoint ("search:end::scope=%s;query=%s", owner.id, search_string);
37+
38 if (search_cancellable.is_cancelled ())
39 {
40 throw new ScopeError.SEARCH_CANCELLED ("Search '%s' was cancelled", search_string);
41@@ -1262,8 +1264,6 @@
42 response.insert (key, variant);
43 }
44
45- Unity.Trace.tracepoint ("%s run end: %s", Log.METHOD, owner.id);
46-
47 result_set.flush ();
48 response[SEARCH_SEQNUM_HINT] = new Variant.uint64 (channel.get_last_seqnum ());
49 if (measure_requests)
50@@ -1351,10 +1351,21 @@
51 if (category_merger is CategoryMergerByScope)
52 (category_merger as CategoryMergerByScope).add_scope_mapping (owner, master_scope_id);
53
54- var channel = get_channel_by_id (channel_id);
55- yield _scopes.push_wrapper (channel, search_string, ChannelType.GLOBAL,
56- master_scope_id, scope_id,
57- results_model, category_ids, cancellable);
58+ Unity.Trace.tracepoint ("push:start::scope=%s;target=%s;query=%s",
59+ master_scope_id, scope_id, search_string);
60+
61+ try
62+ {
63+ var channel = get_channel_by_id (channel_id);
64+ yield _scopes.push_wrapper (channel, search_string, ChannelType.GLOBAL,
65+ master_scope_id, scope_id,
66+ results_model, category_ids, cancellable);
67+ }
68+ finally
69+ {
70+ Unity.Trace.tracepoint ("push:end::scope=%s;target=%s;query=%s",
71+ master_scope_id, scope_id, search_string);
72+ }
73 }
74
75 public void push_filter_settings (string channel_id, FilterSet filters)
76@@ -1456,7 +1467,7 @@
77 }
78
79 _channels[channel.id] = channel;
80- _scopes.register_channel (channel.id, channel.backend_model, merge_strategy);
81+ _scopes.register_channel (owner.id, channel.id, channel.backend_model, merge_strategy);
82
83 out_hints = new HashTable<string, Variant> (str_hash, str_equal);
84 out_hints[CHANNEL_SWARM_NAME_HINT] = new Variant.string (model_name);
85
86=== modified file 'src/unity-deprecated-scope-impl.vala'
87--- src/unity-deprecated-scope-impl.vala 2013-09-24 08:57:39 +0000
88+++ src/unity-deprecated-scope-impl.vala 2013-10-25 14:15:10 +0000
89@@ -491,7 +491,7 @@
90 if (measure_requests) search_start_time = get_monotonic_time ();
91 int64 search_end_time = search_start_time;
92
93- Unity.Trace.tracepoint ("%s run start: %s", Log.METHOD, owner.id);
94+ Unity.Trace.tracepoint ("search:start::scope=%s", owner.id);
95
96 new_search.run_async (() =>
97 {
98@@ -506,7 +506,8 @@
99 result[SEARCH_SEQNUM_HINT] = new Variant.uint64 (channel.get_last_seqnum ());
100 }
101
102- Unity.Trace.tracepoint ("%s run end: %s", Log.METHOD, owner.id);
103+ Unity.Trace.tracepoint ("search:end::scope=%s", owner.id);
104+
105 if (measure_requests)
106 {
107 int64 delta_us = search_end_time - search_start_time;
108
109=== modified file 'src/unity-models.vala'
110--- src/unity-models.vala 2013-07-17 15:18:49 +0000
111+++ src/unity-models.vala 2013-10-25 14:15:10 +0000
112@@ -119,6 +119,7 @@
113 var sm = flush_model as Dee.SharedModel;
114 if (sm != null)
115 {
116+ Unity.Trace.tracepoint ("flush::%s", sm.get_swarm_name ());
117 sm.flush_revision_queue ();
118 }
119 }
120@@ -195,6 +196,7 @@
121 return;
122 }
123
124+ Unity.Trace.tracepoint ("diff:start::%s", get_swarm_name ());
125 var script = Utils.Diff.run ((int) this_rows, (int) target_rows,
126 (index_a, index_b) =>
127 {
128@@ -249,6 +251,7 @@
129 }
130 }
131 }
132+ Unity.Trace.tracepoint ("diff:end::%s", get_swarm_name ());
133
134 assert (get_n_rows () == target_model.get_n_rows ());
135 }
136
137=== modified file 'src/unity-scope-dbus-impl.vala'
138--- src/unity-scope-dbus-impl.vala 2013-09-24 08:57:39 +0000
139+++ src/unity-scope-dbus-impl.vala 2013-10-25 14:15:10 +0000
140@@ -566,7 +566,7 @@
141 if (measure_requests) search_start_time = get_monotonic_time ();
142 int64 search_end_time = search_start_time;
143
144- Unity.Trace.tracepoint ("%s run start: %s", Log.METHOD, _dbus_name);
145+ Unity.Trace.tracepoint ("search:start::scope=%s;query=%s", _dbus_name, normalized_query);
146
147 if (force_sync_requests)
148 {
149@@ -590,7 +590,7 @@
150 yield;
151 }
152
153- Unity.Trace.tracepoint ("%s run end: %s", Log.METHOD, _dbus_name);
154+ Unity.Trace.tracepoint ("search:end::scope=%s;query=%s", _dbus_name, normalized_query);
155
156 // FIXME: handle no-reply-hint etc!
157 if (!cancellable.is_cancelled ())
158
159=== modified file 'src/unity-scope-tracker.vala'
160--- src/unity-scope-tracker.vala 2013-09-24 08:57:39 +0000
161+++ src/unity-scope-tracker.vala 2013-10-25 14:15:10 +0000
162@@ -224,12 +224,13 @@
163 return "%p::%d".printf (proxy, (int) channel_type);
164 }
165
166- public void register_channel (string master_channel_id,
167+ public void register_channel (string owner_scope_id,
168+ string master_channel_id,
169 Dee.SerializableModel model,
170 MergeStrategy merge_strategy)
171 {
172 // create new synchronizer for this channel
173- var synchronizer = new ResultsSynchronizer (model);
174+ var synchronizer = new ResultsSynchronizer (model, owner_scope_id);
175 synchronizer.merge_strategy = merge_strategy;
176 synchronizers[master_channel_id] = synchronizer;
177 }
178
179=== modified file 'src/unity-search.vala'
180--- src/unity-search.vala 2013-07-22 14:02:05 +0000
181+++ src/unity-search.vala 2013-10-25 14:15:10 +0000
182@@ -176,10 +176,10 @@
183 }
184 var agg_scope = owner as AggregatorScope;
185 var canc = search_context.cancellable.get_gcancellable ();
186- Unity.Trace.tracepoint ("%s start: %s, query=%s", Log.METHOD, scope_id, search_string);
187+ Unity.Trace.tracepoint ("subsearch:start::scope=%s;target=%s;query=%s", agg_scope.id, scope_id, search_string);
188 var res = yield agg_scope.search_scope (this, scope_id, search_string,
189 search_type, hints, canc);
190- Unity.Trace.tracepoint ("%s end: %s, query=%s", Log.METHOD, scope_id, search_string);
191+ Unity.Trace.tracepoint ("subsearch:end::scope=%s;target=%s;query=%s", agg_scope.id, scope_id, search_string);
192 return res;
193 }
194
195@@ -190,11 +190,9 @@
196 if (search_context.cancellable.is_cancelled ()) return;
197 var agg_scope = owner as AggregatorScope;
198 var canc = search_context.cancellable.get_gcancellable ();
199- Unity.Trace.tracepoint ("%s start: %s", Log.METHOD, scope_id);
200 yield agg_scope.push_results (channel_id, search_string,
201 scope_id, results_model,
202 category_ids, canc);
203- Unity.Trace.tracepoint ("%s end: %s", Log.METHOD, scope_id);
204 }
205
206 public void push_filter_settings (FilterSet filters)
207
208=== modified file 'src/unity-synchronizer.vala'
209--- src/unity-synchronizer.vala 2013-05-10 12:14:18 +0000
210+++ src/unity-synchronizer.vala 2013-10-25 14:15:10 +0000
211@@ -38,6 +38,7 @@
212 }
213
214 public unowned Dee.Model receiver { get; construct; }
215+ public string owner_scope_id { get; construct; }
216 public MergeStrategy merge_strategy { get; set; }
217
218 private Gee.Set<Dee.Model> _providers;
219@@ -50,9 +51,9 @@
220 private Quark scope_id_quark = Quark.from_string ("scope-id");
221 private uint _clear_seq_num = 1;
222
223- internal ResultsSynchronizer (Dee.Model receiver)
224+ internal ResultsSynchronizer (Dee.Model receiver, string scope_id)
225 {
226- Object (receiver:receiver);
227+ Object (receiver:receiver, owner_scope_id: scope_id);
228 }
229
230 construct
231@@ -184,9 +185,11 @@
232 private void transaction_finished (Dee.SharedModel model,
233 uint64 begin_sn, uint64 end_sn)
234 {
235+ unowned string scope_id = model.get_qdata<string> (scope_id_quark);
236+ Unity.Trace.tracepoint ("changeset::scope=%s;target=%s", owner_scope_id, scope_id);
237 if (model in _providers)
238 {
239- transaction_complete (model, model.get_qdata<string> (scope_id_quark));
240+ transaction_complete (model, scope_id);
241 }
242 }
243
244
245=== modified file 'src/unity-trace.c'
246--- src/unity-trace.c 2013-04-04 06:49:22 +0000
247+++ src/unity-trace.c 2013-10-25 14:15:10 +0000
248@@ -58,14 +58,12 @@
249 va_end (args);
250 }
251
252-#ifdef ENABLE_LTTNG
253-
254 void
255-unity_trace_tracepoint_real (const gchar *format, va_list args)
256+unity_trace_tracepoint_va (const gchar *format, va_list args)
257 {
258+#ifdef ENABLE_LTTNG
259 gchar *tmp = g_strdup_vprintf (format, args);
260 tracepoint (libunity, message, tmp);
261 g_free (tmp);
262+#endif
263 }
264-
265-#endif
266
267=== modified file 'src/unity-trace.h'
268--- src/unity-trace.h 2013-04-04 11:47:25 +0000
269+++ src/unity-trace.h 2013-10-25 14:15:10 +0000
270@@ -90,11 +90,13 @@
271 #endif /* ENABLE_UNITY_TRACE_LOG */
272
273 #ifdef ENABLE_LTTNG
274+void unity_trace_tracepoint_va (const gchar *format, va_list args);
275+
276 static void unity_trace_tracepoint (const gchar *format, ...)
277 {
278 va_list args;
279 va_start (args, format);
280- unity_trace_tracepoint_real (format, args);
281+ unity_trace_tracepoint_va (format, args);
282 va_end (args);
283 }
284 #else
285
286=== modified file 'test/vala/Makefile.am'
287--- test/vala/Makefile.am 2013-07-04 23:07:03 +0000
288+++ test/vala/Makefile.am 2013-10-25 14:15:10 +0000
289@@ -52,7 +52,12 @@
290 $(top_builddir)/src/libunity.la \
291 $(top_builddir)/protocol/libunity-protocol-private.la \
292 $(top_builddir)/extras/libunity-extras.la \
293- $(LIBUNITY_LIBS)
294+ $(LIBUNITY_LIBS) \
295+ $(NULL)
296+
297+if ENABLE_LTTNG
298+test_libs += -lurcu-bp
299+endif
300
301 TEST_PROGS += test-vala test-scope test-blacklist-crash test-extras
302
303@@ -86,6 +91,8 @@
304 nodist_test_blacklist_crash_SOURCES = $(test_blacklist_crash_VALASOURCES:.vala=.c)
305
306 test_extras_LDADD = $(test_libs)
307+test_extras_LDFLAGS = -static
308+
309 test_extras_VALASOURCES = \
310 test-preview-player-iface.vala \
311 test-utils.vala \
312
313=== modified file 'test/vala/test-results-synchronizer.vala'
314--- test/vala/test-results-synchronizer.vala 2013-02-26 14:04:40 +0000
315+++ test/vala/test-results-synchronizer.vala 2013-10-25 14:15:10 +0000
316@@ -40,7 +40,7 @@
317 var provider2 = new Dee.SequenceModel ();
318 provider2.set_schema_full (RESULTS_SCHEMA);
319 provider2.set_data<string> ("scope-id", "scope2");
320- var res_sync = new Internal.ResultsSynchronizer (receiver);
321+ var res_sync = new Internal.ResultsSynchronizer (receiver, "master.scope");
322 res_sync.add_provider (provider1, "scope1");
323 res_sync.add_provider (provider2, "scope2");
324
325
326=== added file 'tools/capture-trace.py'
327--- tools/capture-trace.py 1970-01-01 00:00:00 +0000
328+++ tools/capture-trace.py 2013-10-25 14:15:10 +0000
329@@ -0,0 +1,225 @@
330+#!/usr/bin/env python
331+
332+import os, sys
333+import subprocess
334+import re
335+
336+"""
337+# This script has two modes of operation:
338+#
339+# 1) Capture a trace and generate a html visualization.
340+# To use this mode just run `./capture_trace.py`. This will setup a lttng
341+# session, enable all userspace trace events and spawns a subshell where
342+# you can for example run libunity-tool to perform a search on a scope.
343+# When the subshell exits, tracing is stopped and visualization is generated.
344+#
345+# 2) Only generate a html visualization of a previously captured trace.
346+# Use `./capture_trace.py /path/to/lttng/trace_dir`.
347+#
348+# Note that use use the first mode you need to have lttng installed
349+# and libunity compiled with --enable-lttng option.
350+# Required packages (besides requirements for libunity's --enable-lttng):
351+# sudo apt-get install lttng-tools babeltrace
352+"""
353+
354+"""
355+# --- Manually capturing a trace
356+# lttng create session_name
357+# lttng enable-event -u -a
358+# lttng start
359+# --- start home scope with lttng-enabled branch of libunity, perform a search
360+# lttng stop
361+# lttng destroy
362+# --- view the trace in cli
363+# babeltrace ~/lttng_traces/<session_name dir>
364+"""
365+def capture_lttng_trace():
366+ session = subprocess.check_output(["lttng", "create", "libunity-trace"], stdin=subprocess.PIPE)
367+ trace_started = False
368+ try:
369+ subprocess.check_output(["lttng", "enable-event", "-u", "-a"], stdin=subprocess.PIPE)
370+ subprocess.check_output(["lttng", "start"], stdin=subprocess.PIPE)
371+ trace_started = True
372+ sys.stderr.write("Trace running... Close this sub-shell with Ctrl+D to finish\n")
373+ subprocess.check_call(["bash"]) # let this inherit our stdin
374+ except subprocess.CalledProcessError as cpe:
375+ if trace_started:
376+ # bash will return non-zero exit code if you for example Ctrl+C
377+ # a program within it, let's just ignore those errors
378+ msg = "Warning: subshell returned error: " + str(cpe.returncode)
379+ sys.stderr.write(msg + "\n")
380+ else: raise
381+ finally:
382+ if trace_started:
383+ subprocess.check_output(["lttng", "stop"], stdin=subprocess.PIPE)
384+ subprocess.check_output(["lttng", "destroy", "libunity-trace"], stdin=subprocess.PIPE)
385+
386+ match = re.findall(r'Traces will be written in (.+)', session)
387+ if len(match) > 0: return match[0]
388+ return None
389+
390+# trace event example
391+"""
392+[20:00:30.697493680] (+0.000014138) miso-ThinkPad:unity-scope-hom:26439 libunity:message: { cpu_id = 0 }, { message = "flush::com.canonical.Unity.Master.Scope.home.T296521243842038" }
393+"""
394+
395+def parse_trace_line(line):
396+ pattern = re.compile(r'^\[(?P<timestamp>[0-9:\.]+)\].+?{ message = "(?P<msg>[^"]+)"')
397+ match = pattern.match(line)
398+ timestamp = match.group("timestamp")
399+ msg = match.group("msg")
400+ msg_parts = msg.split("::", 2)
401+ if len(msg_parts) > 1:
402+ msg_type = msg_parts[0]
403+ msg = {}
404+ for kv in msg_parts[1].split(";"):
405+ items = kv.split("=", 2)
406+ if len(items) > 1:
407+ msg[items[0]] = items[1]
408+ else:
409+ msg['content'] = items[0]
410+ else:
411+ msg_type = "other"
412+ msg = {'content': msg}
413+
414+ return (timestamp, msg_type, msg)
415+
416+def find_end_event(events, searched_event, event_type):
417+ for i in range(len(events)):
418+ event = events[i]
419+ if event[1] == event_type and event[2] == searched_event[2]:
420+ return i
421+ return -1
422+
423+def pair_events(events):
424+ paired = []
425+ i = 0
426+ while i < len(events):
427+ event = events[i]
428+ event_type = event[1]
429+ if event_type.endswith(":start"):
430+ group = event[1].split(":", 2)[0]
431+ j = find_end_event(events[i+1:], event, group + ":end")
432+ if j >= 0:
433+ end_event = events.pop(i+j+1)
434+ paired.append((event, end_event))
435+ i = i+1
436+ continue
437+ paired.append((event, None))
438+ i = i+1
439+
440+ return paired
441+
442+COLOR_FOR_EVENT = {
443+ 'search': "'#394a6b'",
444+ 'subsearch': "'#109618'",
445+ 'changeset': "'#990099'",
446+ 'diff': "'#e57357'",
447+ 'flush': "'#ff9900'",
448+ 'push': "'#0099c6'"
449+}
450+
451+def produce_html(trace_name, pairs):
452+ base = """<html><head><title>%s</title></head><body>
453+<script type="text/javascript" src="https://www.google.com/jsapi?autoload={'modules':[{'name':'visualization',
454+ 'version':'1','packages':['timeline']}]}"></script>
455+<script type="text/javascript">
456+
457+google.setOnLoadCallback(drawChart);
458+function drawChart() {
459+ var dataTable = new google.visualization.DataTable();
460+
461+ dataTable.addColumn({ type: 'string', id: 'group' });
462+ dataTable.addColumn({ type: 'string', id: 'id' });
463+ dataTable.addColumn({ type: 'string', id: 'data' });
464+ dataTable.addColumn({ type: 'datetime', id: 'Start' });
465+ dataTable.addColumn({ type: 'datetime', id: 'End' });
466+
467+ dataTable.addRows([
468+ %s
469+ ]);
470+
471+ var view = new google.visualization.DataView(dataTable);
472+ view.setColumns([0,1,3,4]);
473+
474+ var container = document.getElementById('example2.1');
475+ var chart = new google.visualization.Timeline(container);
476+
477+ chart.draw(view);
478+}
479+</script>
480+
481+<div id="example2.1" style="height: 100%%;"></div>
482+</body></html>"""
483+ rows = []
484+ colors = []
485+ for pair in pairs:
486+ (start_event, end_event) = pair
487+ (timestamp, event_type, metadata) = start_event
488+ has_end_ts = end_event is not None
489+
490+ group = event_type if not event_type.endswith(":start") else event_type.split(":", 2)[0]
491+ color = COLOR_FOR_EVENT[group] if group in COLOR_FOR_EVENT else "'#c60000'"
492+ has_scope_id = 'scope' in metadata
493+ scope_id = metadata['scope'] if has_scope_id else metadata['content']
494+ if has_scope_id: del metadata['scope']
495+ else:
496+ if group in ['changeset', 'flush', 'diff']:
497+ match = re.match(r'com.canonical.Unity\.Master\.Scope\.(\w+)\.T', scope_id)
498+ if match: scope_id = "%s.scope" % match.group(1)
499+ data = str(metadata).replace("'", "\\'")
500+
501+ # we're loosing our lovely nanosecond precision :(
502+ map_to_int = lambda x: int(x[0:3])
503+ start_date = map(map_to_int, re.findall(r'\d+', timestamp))
504+ end_date = start_date
505+ if has_end_ts:
506+ end_date = map(map_to_int, re.findall(r'\d+', end_event[0]))
507+
508+ event_name = "%s - %s" % (group, metadata['target']) if 'target' in metadata else group
509+ data_tuple = (scope_id, group, data, ",".join(map(str,start_date)), ",".join(map(str, end_date)))
510+ data_format = "[ '%s', '%s', '%s', new Date(0,0,0,%s), new Date(0,0,0,%s) ]"
511+ data_row = data_format % data_tuple
512+ rows.append(data_row)
513+ colors.append(color)
514+ return base % ("Analysis of %s" % trace_name, ",\n".join(rows))
515+
516+def get_events_from_babeltrace(trace_dir):
517+ events = []
518+ all_events = subprocess.check_output(["babeltrace", trace_dir])
519+ lines = filter(None, all_events.split("\n"))
520+ for line in lines:
521+ event = parse_trace_line(line)
522+ events.append(event)
523+ return events
524+
525+def main(args):
526+ output_name = None
527+ if len(args) > 1:
528+ trace_dir = args[1]
529+ else:
530+ trace_dir = capture_lttng_trace()
531+
532+ if trace_dir:
533+ basename = os.path.basename(trace_dir)
534+ if not basename:
535+ basename = os.path.basename(os.path.dirname(trace_dir))
536+ output_name = "%s.html" % basename
537+
538+ events = get_events_from_babeltrace(trace_dir)
539+ if len(events) == 0:
540+ raise RuntimeError("There are 0 events in the trace")
541+ pairs = pair_events(events)
542+ html = produce_html(trace_dir, pairs)
543+
544+ if output_name:
545+ sys.stderr.write("Writing output to '%s'\n" % output_name)
546+ f = open(output_name, 'w')
547+ f.write(html)
548+ f.close()
549+ else:
550+ print html
551+
552+if __name__ == "__main__":
553+ main (sys.argv)
554+
555
556=== modified file 'tools/unity-tool.vala'
557--- tools/unity-tool.vala 2013-10-04 16:08:32 +0000
558+++ tools/unity-tool.vala 2013-10-25 14:15:10 +0000
559@@ -35,6 +35,7 @@
560 public static bool print_search_reply;
561 public static bool dump_results;
562 public static bool dump_filters;
563+ public static bool diff_changes;
564
565 public static bool test_server_mode;
566 public static string[] test_cases;
567@@ -104,6 +105,10 @@
568 "Use private channel for results transfer", null
569 },
570 {
571+ "diff-changes", 'd', 0, OptionArg.NONE, out Options.diff_changes,
572+ "Use diff channel", null
573+ },
574+ {
575 "test-server-mode", 0, 0, OptionArg.NONE, out Options.test_server_mode,
576 "Run a collection of test scripts", null
577 },
578@@ -238,12 +243,10 @@
579 // Get proxy
580 string channel_id;
581 Dee.SerializableModel results_model;
582- var flags = Options.private_channel ?
583- ChannelFlags.PRIVATE : ChannelFlags.NONE;
584 var proxy = get_scope_proxy (Options.scope_dbus_name,
585 Options.scope_dbus_path,
586 (ChannelType) Options.search_type,
587- flags,
588+ get_global_channel_flags (),
589 out channel_id, out results_model);
590
591 // Performing search
592@@ -508,18 +511,24 @@
593 return Test.run ();
594 }
595
596+ private static ChannelFlags get_global_channel_flags ()
597+ {
598+ var flags = ChannelFlags.NONE;
599+ if (Options.private_channel) flags |= ChannelFlags.PRIVATE;
600+ if (Options.diff_changes) flags |= ChannelFlags.DIFF_CHANGES;
601+ return flags;
602+ }
603+
604 private static void call_scope_search (string search_string,
605 int search_type)
606 {
607 string channel_id;
608 Dee.SerializableModel results_model;
609
610- var flags = Options.private_channel ?
611- ChannelFlags.PRIVATE : ChannelFlags.NONE;
612 var proxy = get_scope_proxy (Options.scope_dbus_name,
613 Options.scope_dbus_path,
614 (ChannelType) search_type,
615- flags,
616+ get_global_channel_flags (),
617 out channel_id, out results_model);
618
619 var ml = new MainLoop ();

Subscribers

People subscribed via source and target branches