DTrace support: function calls, GC activity, line execution

Tested on macOS 10.11 dtrace, Ubuntu 16.04 SystemTap, and libbcc.

Largely based by an initial patch by Jes?s Cea Avi?n, with some
influence from Dave Malcolm's SystemTap patch and Nikhil Benesch's
unification patch.

Things deliberately left out for simplicity:
- ustack helpers, I have no way of testing them at this point since
they are Solaris-specific
- PyFrameObject * in function__entry/function__return, this is
SystemTap-specific
- SPARC support
- dynamic tracing
- sys module dtrace facility introspection

All of those might be added later.

16 files changed, 285 insertions, 0 deletions

diff --git a/Lib/test/dtracedata/assert_usable.d b/Lib/test/dtracedata/assert_usable.d
new file mode 100644
index 0000000000..0b2d4da66e
--- /dev/null
+++ b/Lib/test/dtracedata/assert_usable.d
@@ -0,0 +1,5 @@
+BEGIN
+{
+    printf("probe: success\n");
+    exit(0);
+}
diff --git a/Lib/test/dtracedata/assert_usable.stp b/Lib/test/dtracedata/assert_usable.stp
new file mode 100644
index 0000000000..88e7e68e2c
--- /dev/null
+++ b/Lib/test/dtracedata/assert_usable.stp
@@ -0,0 +1,5 @@
+probe begin
+{
+  println("probe: success")
+  exit ()
+}
diff --git a/Lib/test/dtracedata/call_stack.d b/Lib/test/dtracedata/call_stack.d
new file mode 100644
index 0000000000..450e939d4f
--- /dev/null
+++ b/Lib/test/dtracedata/call_stack.d
@@ -0,0 +1,31 @@
+self int indent;
+
+python$target:::function-entry
+/copyinstr(arg1) == "start"/
+{
+    self->trace = 1;
+}
+
+python$target:::function-entry
+/self->trace/
+{
+    printf("%d\t%*s:", timestamp, 15, probename);
+    printf("%*s", self->indent, ""); 
+    printf("%s:%s:%d\n", basename(copyinstr(arg0)), copyinstr(arg1), arg2);
+    self->indent++;
+}
+
+python$target:::function-return
+/self->trace/
+{
+    self->indent--;
+    printf("%d\t%*s:", timestamp, 15, probename);
+    printf("%*s", self->indent, ""); 
+    printf("%s:%s:%d\n", basename(copyinstr(arg0)), copyinstr(arg1), arg2);
+}
+
+python$target:::function-return
+/copyinstr(arg1) == "start"/
+{
+    self->trace = 0;
+}
diff --git a/Lib/test/dtracedata/call_stack.d.expected b/Lib/test/dtracedata/call_stack.d.expected
new file mode 100644
index 0000000000..27849d1549
--- /dev/null
+++ b/Lib/test/dtracedata/call_stack.d.expected
@@ -0,0 +1,18 @@
+ function-entry:call_stack.py:start:23
+ function-entry: call_stack.py:function_1:1
+ function-entry:  call_stack.py:function_3:9
+function-return:  call_stack.py:function_3:10
+function-return: call_stack.py:function_1:2
+ function-entry: call_stack.py:function_2:5
+ function-entry:  call_stack.py:function_1:1
+ function-entry:   call_stack.py:function_3:9
+function-return:   call_stack.py:function_3:10
+function-return:  call_stack.py:function_1:2
+function-return: call_stack.py:function_2:6
+ function-entry: call_stack.py:function_3:9
+function-return: call_stack.py:function_3:10
+ function-entry: call_stack.py:function_4:13
+function-return: call_stack.py:function_4:14
+ function-entry: call_stack.py:function_5:18
+function-return: call_stack.py:function_5:21
+function-return:call_stack.py:start:28
diff --git a/Lib/test/dtracedata/call_stack.py b/Lib/test/dtracedata/call_stack.py
new file mode 100644
index 0000000000..ee9f3ae8d6
--- /dev/null
+++ b/Lib/test/dtracedata/call_stack.py
@@ -0,0 +1,30 @@
+def function_1():
+    function_3(1, 2)
+
+# Check stacktrace
+def function_2():
+    function_1()
+
+# CALL_FUNCTION_VAR
+def function_3(dummy, dummy2):
+    pass
+
+# CALL_FUNCTION_KW
+def function_4(**dummy):
+    return 1
+    return 2  # unreachable
+
+# CALL_FUNCTION_VAR_KW
+def function_5(dummy, dummy2, **dummy3):
+    if False:
+        return 7
+    return 8
+
+def start():
+    function_1()
+    function_2()
+    function_3(1, 2)
+    function_4(test=42)
+    function_5(*(1, 2), **{"test": 42})
+
+start()
diff --git a/Lib/test/dtracedata/call_stack.stp b/Lib/test/dtracedata/call_stack.stp
new file mode 100644
index 0000000000..54082c202f
--- /dev/null
+++ b/Lib/test/dtracedata/call_stack.stp
@@ -0,0 +1,41 @@
+global tracing
+
+function basename:string(path:string)
+{
+    last_token = token = tokenize(path, "/");
+    while (token != "") {
+        last_token = token;
+        token = tokenize("", "/");
+    }
+    return last_token;
+}
+
+probe process.mark("function__entry")
+{
+    funcname = user_string($arg2);
+
+    if (funcname == "start") {
+        tracing = 1;
+    }
+}
+
+probe process.mark("function__entry"), process.mark("function__return")
+{
+    filename = user_string($arg1);
+    funcname = user_string($arg2);
+    lineno = $arg3;
+
+    if (tracing) {
+        printf("%d\t%s:%s:%s:%d\n", gettimeofday_us(), $$name,
+               basename(filename), funcname, lineno);
+    }
+}
+
+probe process.mark("function__return")
+{
+    funcname = user_string($arg2);
+
+    if (funcname == "start") {
+        tracing = 0;
+    }
+}
diff --git a/Lib/test/dtracedata/call_stack.stp.expected b/Lib/test/dtracedata/call_stack.stp.expected
new file mode 100644
index 0000000000..32cf396f82
--- /dev/null
+++ b/Lib/test/dtracedata/call_stack.stp.expected
@@ -0,0 +1,14 @@
+function__entry:call_stack.py:start:23
+function__entry:call_stack.py:function_1:1
+function__return:call_stack.py:function_1:2
+function__entry:call_stack.py:function_2:5
+function__entry:call_stack.py:function_1:1
+function__return:call_stack.py:function_1:2
+function__return:call_stack.py:function_2:6
+function__entry:call_stack.py:function_3:9
+function__return:call_stack.py:function_3:10
+function__entry:call_stack.py:function_4:13
+function__return:call_stack.py:function_4:14
+function__entry:call_stack.py:function_5:18
+function__return:call_stack.py:function_5:21
+function__return:call_stack.py:start:28
diff --git a/Lib/test/dtracedata/gc.d b/Lib/test/dtracedata/gc.d
new file mode 100644
index 0000000000..4d91487b7e
--- /dev/null
+++ b/Lib/test/dtracedata/gc.d
@@ -0,0 +1,18 @@
+python$target:::function-entry
+/copyinstr(arg1) == "start"/
+{
+    self->trace = 1;
+}
+
+python$target:::gc-start,
+python$target:::gc-done
+/self->trace/
+{
+    printf("%d\t%s:%ld\n", timestamp, probename, arg0);
+}
+
+python$target:::function-return
+/copyinstr(arg1) == "start"/
+{
+    self->trace = 0;
+}
diff --git a/Lib/test/dtracedata/gc.d.expected b/Lib/test/dtracedata/gc.d.expected
new file mode 100644
index 0000000000..8e5ac2a6d5
--- /dev/null
+++ b/Lib/test/dtracedata/gc.d.expected
@@ -0,0 +1,8 @@
+gc-start:0
+gc-done:0
+gc-start:1
+gc-done:0
+gc-start:2
+gc-done:0
+gc-start:2
+gc-done:1
diff --git a/Lib/test/dtracedata/gc.py b/Lib/test/dtracedata/gc.py
new file mode 100644
index 0000000000..144a783b7b
--- /dev/null
+++ b/Lib/test/dtracedata/gc.py
@@ -0,0 +1,13 @@
+import gc
+
+def start():
+    gc.collect(0)
+    gc.collect(1)
+    gc.collect(2)
+    l = []
+    l.append(l)
+    del l
+    gc.collect(2)
+
+gc.collect()
+start()
diff --git a/Lib/test/dtracedata/gc.stp b/Lib/test/dtracedata/gc.stp
new file mode 100644
index 0000000000..162c6d3a22
--- /dev/null
+++ b/Lib/test/dtracedata/gc.stp
@@ -0,0 +1,26 @@
+global tracing
+
+probe process.mark("function__entry")
+{
+    funcname = user_string($arg2);
+
+    if (funcname == "start") {
+        tracing = 1;
+    }
+}
+
+probe process.mark("gc__start"), process.mark("gc__done")
+{
+    if (tracing) {
+        printf("%d\t%s:%ld\n", gettimeofday_us(), $$name, $arg1);
+    }
+}
+
+probe process.mark("function__return")
+{
+    funcname = user_string($arg2);
+
+    if (funcname == "start") {
+        tracing = 0;
+    }
+}
diff --git a/Lib/test/dtracedata/gc.stp.expected b/Lib/test/dtracedata/gc.stp.expected
new file mode 100644
index 0000000000..7e6e6227fb
--- /dev/null
+++ b/Lib/test/dtracedata/gc.stp.expected
@@ -0,0 +1,8 @@
+gc__start:0
+gc__done:0
+gc__start:1
+gc__done:0
+gc__start:2
+gc__done:0
+gc__start:2
+gc__done:1
diff --git a/Lib/test/dtracedata/instance.py b/Lib/test/dtracedata/instance.py
new file mode 100644
index 0000000000..f1421378b0
--- /dev/null
+++ b/Lib/test/dtracedata/instance.py
@@ -0,0 +1,24 @@
+import gc
+
+class old_style_class():
+    pass
+class new_style_class(object):
+    pass
+
+a = old_style_class()
+del a
+gc.collect()
+b = new_style_class()
+del b
+gc.collect()
+
+a = old_style_class()
+del old_style_class
+gc.collect()
+b = new_style_class()
+del new_style_class
+gc.collect()
+del a
+gc.collect()
+del b
+gc.collect()
diff --git a/Lib/test/dtracedata/line.d b/Lib/test/dtracedata/line.d
new file mode 100644
index 0000000000..03f22db6fc
--- /dev/null
+++ b/Lib/test/dtracedata/line.d
@@ -0,0 +1,7 @@
+python$target:::line
+/(copyinstr(arg1)=="test_line")/
+{
+    printf("%d\t%s:%s:%s:%d\n", timestamp,
+        probename, basename(copyinstr(arg0)),
+        copyinstr(arg1), arg2);
+}
diff --git a/Lib/test/dtracedata/line.d.expected b/Lib/test/dtracedata/line.d.expected
new file mode 100644
index 0000000000..9b16ce76ee
--- /dev/null
+++ b/Lib/test/dtracedata/line.d.expected
@@ -0,0 +1,20 @@
+line:line.py:test_line:2
+line:line.py:test_line:3
+line:line.py:test_line:4
+line:line.py:test_line:5
+line:line.py:test_line:6
+line:line.py:test_line:7
+line:line.py:test_line:8
+line:line.py:test_line:9
+line:line.py:test_line:10
+line:line.py:test_line:11
+line:line.py:test_line:4
+line:line.py:test_line:5
+line:line.py:test_line:6
+line:line.py:test_line:7
+line:line.py:test_line:8
+line:line.py:test_line:10
+line:line.py:test_line:11
+line:line.py:test_line:4
+line:line.py:test_line:12
+line:line.py:test_line:13
diff --git a/Lib/test/dtracedata/line.py b/Lib/test/dtracedata/line.py
new file mode 100644
index 0000000000..0930ff391f
--- /dev/null
+++ b/Lib/test/dtracedata/line.py
@@ -0,0 +1,17 @@
+def test_line():
+    a = 1
+    print('# Preamble', a)
+    for i in range(2):
+        a = i
+        b = i+2
+        c = i+3
+        if c < 4:
+            a = c
+        d = a + b +c
+        print('#', a, b, c, d)
+    a = 1
+    print('# Epilogue', a)
+
+
+if __name__ == '__main__':
+    test_line()