Phi: nicer scroll animation for METAR widget
[fg:fgdata.git] / Nasal / debug.nas
1 # debug.nas -- debugging helpers
2 #------------------------------------------------------------------------------
3 #
4 # debug.dump(<variable>)               ... dumps contents of variable to terminal;
5 #                                          abbreviation for print(debug.string(v))
6 #
7 # debug.local([<frame:int>])           ... dump local variables of current
8 #                                          or given frame
9 #
10 # debug.backtrace([<comment:string>]}  ... writes backtrace with local variables
11 #                                          (similar to gdb's "bt full)
12 #
13 # debug.proptrace([<property [, <frames>]]) ... trace property write/add/remove
14 #                                          events under the <property> subtree for
15 #                                          a number of frames. Defaults are "/" and
16 #                                          2 frames (of which the first one is incomplete).
17 #
18 # debug.tree([<property> [, <mode>])   ... dump property tree under property path
19 #                                          or props.Node hash (default: root). If
20 #                                          <mode> is unset or 0, use flat mode
21 #                                          (similar to props.dump()), otherwise
22 #                                          use space indentation
23 #
24 # debug.bt()                           ... abbreviation for debug.backtrace()
25 #
26 # debug.string(<variable>)             ... returns contents of variable as string
27 #
28 # debug.attributes(<property> [, <verb>]) ... returns attribute string for a given property.
29 #                                          <verb>ose is by default 1, and suppressed the
30 #                                          node's refcounter if 0.
31 #
32 # debug.isnan()                            returns 1 if argument is an invalid number (NaN),
33 #                                          0 if it's a valid number, and nil in all other cases
34 #
35 # debug.benchmark(<label:string>, <func> [, <repeat:int> [, <output:vector>]])
36 #                                      ... runs function <repeat> times (default: nil)
37 #                                          and prints total execution time in seconds,
38 #                                          prefixed with <label>, while adding results
39 #                                          to <output>, or returning the only result
40 #                                          if <repeat> is nil.
41 #
42 # debug.benchmark_time(<func> [, <repeat:int> [, <output:vector>]])
43 #                                      ... like debug.benchmark, but returns total
44 #                                          execution time and does not print anything.
45 #
46 # debug.rank(<list:vector> [, <repeat:int>])
47 #                                      ... sorts the list of functions based on execution
48 #                                          time over <repeat> samples (default: 1).
49 #
50 # debug.print_rank(<result:vector>, <names:int>)
51 #                                      ... prints the <result> of debug.rank with <names>
52 #                                          (which can be a vector of [name, func] or
53 #                                          [func, name], or a hash of name:func).
54 #
55 # debug.printerror(<err-vector>)       ... prints error vector as set by call()
56 #
57 # debug.warn(<message>, <level>)       ... generate debug message followed by caller stack trace
58 #                                          skipping <level> caller levels (default: 0).
59 #
60 # debug.propify(<variable>)            ... turn about everything into a props.Node
61 #
62 # CAVE: this file makes extensive use of ANSI color codes. These are
63 #       interpreted by UNIX shells and MS Windows with ANSI.SYS extension
64 #       installed. If the color codes aren't interpreted correctly, then
65 #       set property /sim/startup/terminal-ansi-colors=0
66 #
67
68 # ANSI color code wrappers  (see  $ man console_codes)
69 #
70 var _title       = func(s, color=nil) globals.string.color("33;42;1", s, color); # backtrace header
71 var _section     = func(s, color=nil) globals.string.color("37;41;1", s, color); # backtrace frame
72 var _error       = func(s, color=nil) globals.string.color("31;1",    s, color); # internal errors
73 var _bench       = func(s, color=nil) globals.string.color("37;45;1", s); # benchmark info
74
75 var _nil         = func(s, color=nil) globals.string.color("32", s, color);      # nil
76 var _string      = func(s, color=nil) globals.string.color("31", s, color);      # "foo"
77 var _num         = func(s, color=nil) globals.string.color("31", s, color);      # 0.0
78 var _bracket     = func(s, color=nil) globals.string.color("", s, color);        # [ ]
79 var _brace       = func(s, color=nil) globals.string.color("", s, color);        # { }
80 var _angle       = func(s, color=nil) globals.string.color("", s, color);        # < >
81 var _vartype     = func(s, color=nil) globals.string.color("33", s, color);      # func ghost
82 var _proptype    = func(s, color=nil) globals.string.color("34", s, color);      # BOOL INT LONG DOUBLE ...
83 var _path        = func(s, color=nil) globals.string.color("36", s, color);      # /some/property/path
84 var _internal    = func(s, color=nil) globals.string.color("35", s, color);      # me parents
85 var _varname     = func(s, color=nil) s;                                         # variable_name
86
87
88 ##
89 # Turn p into props.Node (if it isn't yet), or return nil.
90 #
91 var propify = func(p, create = 0) {
92         var type = typeof(p);
93         if (type == "ghost" and ghosttype(p) == "prop")
94                 return props.wrapNode(p);
95         if (type == "scalar" and num(p) == nil)
96                 return props.globals.getNode(p, create);
97         if (isa(p, props.Node))
98                 return p;
99         return nil;
100 }
101
102
103 var tree = func(n = "", graph = 1) {
104         n = propify(n);
105         if (n == nil)
106                 return dump(n);
107         _tree(n, graph);
108 }
109
110
111 var _tree = func(n, graph = 1, prefix = "", level = 0) {
112         var path = n.getPath();
113         var children = n.getChildren();
114         var s = "";
115
116         if (graph) {
117                 s = prefix ~ n.getName();
118                 var index = n.getIndex();
119                 if (index)
120                         s ~= "[" ~ index ~ "]";
121         } else {
122                 s = n.getPath();
123         }
124
125         if (size(children)) {
126                 s ~= "/";
127                 if (n.getType() != "NONE")
128                         s ~= " = " ~ debug.string(n.getValue()) ~ " " ~ attributes(n)
129                                         ~ "    " ~ _section(" PARENT-VALUE ");
130         } else {
131                 s ~= " = " ~ debug.string(n.getValue()) ~ " " ~ attributes(n);
132         }
133
134         if ((var a = n.getAliasTarget()) != nil)
135                 s ~= "  " ~ _title(" alias to ") ~ "  " ~ a.getPath();
136
137         print(s);
138
139         if (n.getType() != "ALIAS")
140                 forindex (var i; children)
141                         _tree(children[i], graph, prefix ~ ".   ", level + 1);
142 }
143
144
145 var attributes = func(p, verbose = 1, color=nil) {
146         var r = p.getAttribute("readable")    ? "" : "r";
147         var w = p.getAttribute("writable")    ? "" : "w";
148         var R = p.getAttribute("trace-read")  ? "R" : "";
149         var W = p.getAttribute("trace-write") ? "W" : "";
150         var A = p.getAttribute("archive")     ? "A" : "";
151         var U = p.getAttribute("userarchive") ? "U" : "";
152         var P = p.getAttribute("preserve")    ? "P" : "";
153         var T = p.getAttribute("tied")        ? "T" : "";
154         var attr = r ~ w ~ R ~ W ~ A ~ U ~ P ~ T;
155         var type = "(" ~ p.getType();
156         if (size(attr))
157                 type ~= ", " ~ attr;
158         if (var l = p.getAttribute("listeners"))
159                 type ~= ", L" ~ l;
160         if (verbose and (var c = p.getAttribute("references")) > 2)
161                 type ~= ", #" ~ (c - 2);
162         return _proptype(type ~ ")", color);
163 }
164
165
166 var _dump_prop = func(p, color=nil) {
167         _path(p.getPath(), color) ~ " = " ~ debug.string(p.getValue(), color)
168                             ~  " "  ~ attributes(p, 1, color);
169 }
170
171
172 var _dump_var = func(v, color=nil) {
173         if (v == "me" or v == "parents")
174                 return _internal(v, color);
175         else
176                 return _varname(v, color);
177 }
178
179
180 var _dump_string = func(str, color=nil) {
181         var s = "'";
182         for (var i = 0; i < size(str); i += 1) {
183                 var c = str[i];
184                 if (c == `\``)
185                         s ~= "\\`";
186                 elsif (c == `\n`)
187                         s ~= "\\n";
188                 elsif (c == `\r`)
189                         s ~= "\\r";
190                 elsif (c == `\t`)
191                         s ~= "\\t";
192                 elsif (globals.string.isprint(c))
193                         s ~= chr(c);
194                 else
195                         s ~= sprintf("\\x%02x", c);
196         }
197         return _string(s ~ "'", color);
198 }
199
200
201 # dump hash keys as variables if they are valid variable names, or as string otherwise
202 var _dump_key = func(s, color=nil) {
203         if (num(s) != nil)
204                 return _num(s, color);
205         if (!size(s))
206                 return _dump_string(s, color);
207         if (!globals.string.isalpha(s[0]) and s[0] != `_`)
208                 return _dump_string(s, color);
209         for (var i = 1; i < size(s); i += 1)
210                 if (!globals.string.isalnum(s[i]) and s[i] != `_`)
211                         return _dump_string(s, color);
212         _dump_var(s, color);
213 }
214
215
216 var string = func(o, color=nil) {
217         var t = typeof(o);
218         if (t == "nil") {
219                 return _nil("nil", color);
220
221         } elsif (t == "scalar") {
222                 return num(o) == nil ? _dump_string(o, color) : _num(o~"", color);
223
224         } elsif (t == "vector") {
225                 var s = "";
226                 forindex (var i; o)
227                         s ~= (i == 0 ? "" : ", ") ~ debug.string(o[i], color);
228                 return _bracket("[", color) ~ s ~ _bracket("]", color);
229
230         } elsif (t == "hash") {
231                 if (contains(o, "parents") and typeof(o.parents) == "vector"
232                                 and size(o.parents) == 1 and o.parents[0] == props.Node)
233                         return _angle("<", color) ~ _dump_prop(o, color) ~ _angle(">", color);
234
235                 var k = keys(o);
236                 var s = "";
237                 forindex (var i; k)
238                         s ~= (i == 0 ? "" : ", ") ~ _dump_key(k[i], color) ~ ": " ~ debug.string(o[k[i]], color);
239                 return _brace("{", color) ~ " " ~ s ~ " " ~ _brace("}", color);
240
241         } elsif (t == "ghost") {
242                 return _angle("<", color) ~ _nil(ghosttype(o), color) ~ _angle(">", color);
243
244         } else {
245                 return _angle("<", color) ~ _vartype(t, color) ~ _angle(">", color);
246         }
247 }
248
249
250 var dump = func(vars...) {
251         if (!size(vars))
252                 return local(1);
253         if (size(vars) == 1)
254                 return print(debug.string(vars[0]));
255         forindex (var i; vars)
256                 print(globals.string.color("33;40;1", "#" ~ i) ~ " ", debug.string(vars[i]));
257 }
258
259
260 var local = func(frame = 0) {
261         var v = caller(frame + 1);
262         print(v == nil ? _error("<no such frame>") : debug.string(v[0]));
263         return v;
264 }
265
266
267 var backtrace = func(desc = nil) {
268         var d = desc == nil ? "" : " '" ~ desc ~ "'";
269         print("\n" ~ _title("\n### backtrace" ~ d ~ " ###"));
270         for (var i = 1; 1; i += 1) {
271                 if ((var v = caller(i)) == nil)
272                         return;
273                 print(_section(sprintf("#%-2d called from %s, line %s:", i - 1, v[2], v[3])));
274                 dump(v[0]);
275         }
276 }
277 var bt = backtrace;
278
279
280 var proptrace = func(root = "/", frames = 2) {
281         var events = 0;
282         var trace = setlistener(propify(root), func(this, base, type) {
283                 events += 1;
284                 if (type > 0)
285                         print(_nil("ADD "), this.getPath());
286                 elsif (type < 0)
287                         print(_num("DEL "), this.getPath());
288                 else
289                         print("SET ", this.getPath(), " = ", debug.string(this.getValue()), " ", attributes(this));
290         }, 0, 2);
291         var mark = setlistener("/sim/signals/frame", func {
292                 print("-------------------- FRAME --------------------");
293                 if (!frames) {
294                         removelistener(trace);
295                         removelistener(mark);
296                         print("proptrace: stop (", events, " calls)");
297                 }
298                 frames -= 1;
299         });
300 }
301
302
303 ##
304 # Executes function fn "repeat" times and prints execution time in seconds. If repeat
305 # is an integer and an optional "output" argument is specified, each test's result
306 # is appended to that vector, then the vector is returned. If repeat is nil, then
307 # the funciton is run once and the result returned. Otherwise, the result is discarded.
308 # Examples:
309 #
310 #     var test = func { getprop("/sim/aircraft"); }
311 #     debug.benchmark("test()/1", test, 1000);
312 #     debug.benchmark("test()/2", func setprop("/sim/aircraft", ""), 1000);
313 #
314 #     var results = debug.benchmark("test()", test, 1000, []);
315 #     print("  Results were:");
316 #     print("    ", debug.string(results));
317 #
318 var benchmark = func(label, fn, repeat = nil, output=nil) {
319         var start = var end = nil;
320         if (repeat == nil) {
321                 start = systime();
322                 output = fn();
323         } elsif (typeof(output) == 'vector') {
324                 start = systime();
325                 for (var i = 0; i < repeat; i += 1)
326                         append(output, fn());
327         } else {
328                 start = systime();
329                 for (var i = 0; i < repeat; i += 1)
330                         fn();
331         }
332         end = systime();
333         print(_bench(sprintf(" %s --> %.6f s ", label, end - start)));
334         return output;
335 }
336
337 var benchmark_time = func(fn, repeat = 1, output = nil) {
338         var start = var end = nil;
339         if (repeat == nil) {
340                 start = systime();
341                 output = fn();
342         } elsif (typeof(output) == 'vector') {
343                 start = systime();
344                 for (var i = 0; i < repeat; i += 1)
345                         append(output, fn());
346         } else {
347                 start = systime();
348                 for (var i = 0; i < repeat; i += 1)
349                         fn();
350         }
351         end = systime();
352         return end - start;
353 }
354
355 ##
356 # Executes each function in the list and returns a sorted vector with the fastest
357 # on top (i.e. first). Each position in the result is a vector of [func, time].
358 #
359 var rank = func(list, repeat = nil) {
360         var result = [];
361         foreach (var fn; list) {
362                 var time = benchmark_time(fn, repeat);
363                 append(result, [fn, time]);
364         }
365         return sort(result, func(a,b) a[1] < b[1] ? -1 : a[1] > b[1] ? 1 : 0);
366 }
367
368 var print_rank = func(label, list, names) {
369         var _vec = (typeof(names) == 'vector');
370         print("Test results for "~label);
371         var first = 1;
372         var longest = list[-1][1];
373         foreach (var item; list) {
374                 var (fn, time) = item;
375                 var name = nil;
376                 if (_vec) {
377                         foreach (var l; names) {
378                                 if (l[1] == fn) {
379                                         name = l[0]; break;
380                                 } elsif (l[0] == fn) {
381                                         name = l[1]; break;
382                                 }
383                         }
384                 } else {
385                         foreach (var name; keys(names)) {
386                                 if (names[name] == fn) break;
387                                 else name = nil;
388                         }
389                 }
390                 if (name == nil) die("function not found");
391                 print("  "~name~(first?" (fastest)":"")~" took "~(time*1000)~" ms ("~(time/longest*100)~"%) time");
392                 first = 0;
393         }
394         return list;
395 }
396
397
398 ##
399 # print error vector as set by call(). By using call() one can execute
400 # code that catches "exceptions" (by a die() call or errors). The Nasal
401 # code doesn't abort in this case. Example:
402 #
403 #     var possibly_buggy = func { ... }
404 #     call(possibly_buggy, nil, var err = []);
405 #     debug.printerror(err);
406 #
407 var printerror = func(err) {
408         if (!size(err))
409                 return;
410         printf("%s:\n at %s, line %d", err[0], err[1], err[2]);
411         for (var i = 3; i < size(err); i += 2)
412                 printf("  called from: %s, line %d", err[i], err[i + 1]);
413 }
414
415
416 # like die(), but code execution continues. The level argument defines
417 # how many caller() levels to omit. One is automatically omitted, as
418 # this would only point to debug.warn(), where the event in question
419 # didn't happen.
420 #
421 var warn = func(msg, level = 0) {
422         var c = caller(level += 1);
423         if (c == nil)
424                 die("debug.warn with invalid level argument");
425         printf("%s:\n  at %s, line %d", msg, c[2], c[3]);
426         while ((c = caller(level += 1)) != nil)
427                 printf("  called from: %s, line %d", c[2], c[3]);
428 }
429
430
431 var isnan = func {
432         call(math.sin, arg, var err = []);
433         return !!size(err);
434 }
435
436
437 # --prop:debug=1 enables debug mode with additional warnings
438 #
439 _setlistener("sim/signals/nasal-dir-initialized", func {
440         if (!getprop("debug"))
441                 return;
442         var writewarn = func(f, p, r) {
443                 if (!r) {
444                         var hint = "";
445                         if ((var n = props.globals.getNode(p)) != nil) {
446                                 if (!n.getAttribute("writable"))
447                                         hint = " (write protected)";
448                                 elsif (n.getAttribute("tied"))
449                                         hint = " (tied)";
450                         }
451                         warn("Warning: " ~ f ~ " -> writing to " ~ p ~ " failed" ~ hint, 2);
452                 }
453                 return r;
454         }
455         setprop = (func { var _ = setprop; func writewarn("setprop",
456                         globals.string.join("", arg[:-2]), call(_, arg)) })();
457         props.Node.setDoubleValue = func writewarn("setDoubleValue", me.getPath(),
458                         props._setDoubleValue(me._g, arg));
459         props.Node.setBoolValue = func writewarn("setBoolValue", me.getPath(),
460                         props._setBoolValue(me._g, arg));
461         props.Node.setIntValue = func writewarn("setIntValue", me.getPath(),
462                         props._setIntValue(me._g, arg));
463         props.Node.setValue = func writewarn("setValue", me.getPath(),
464                         props._setValue(me._g, arg));
465 });
466
467