[RFC/PATCH] TCP and Unix socket accept queue time examples

[Eric Wong <normalperson at yhbt dot net>]

These examples can be useful for measuring how long it
took an application to accept a newly-connected client.
---
 This is my first submission to SystemTap, comments greatly appreciated!

 .../network/tcp_acceptq_time.meta                  | 13 ++++++++
 .../network/tcp_acceptq_time.stp                   | 17 +++++++++++
 .../network/unix_acceptq_time.meta                 | 13 ++++++++
 .../network/unix_acceptq_time.stp                  | 35 ++++++++++++++++++++++
 4 files changed, 78 insertions(+)
 create mode 100644 testsuite/systemtap.examples/network/tcp_acceptq_time.meta
 create mode 100755 testsuite/systemtap.examples/network/tcp_acceptq_time.stp
 create mode 100644 testsuite/systemtap.examples/network/unix_acceptq_time.meta
 create mode 100755 testsuite/systemtap.examples/network/unix_acceptq_time.stp

diff --git a/testsuite/systemtap.examples/network/tcp_acceptq_time.meta b/testsuite/systemtap.examples/network/tcp_acceptq_time.meta
new file mode 100644
index 0000000..a2f5f81
--- /dev/null
+++ b/testsuite/systemtap.examples/network/tcp_acceptq_time.meta
@@ -0,0 +1,13 @@
+title: Accept Queue time for TCP sockets
+name: tcp_acceptq_time.stp
+version: 1.0
+author: Eric Wong
+keywords: network queue accept tcp
+subsystem: network
+status: experimental
+exit: user-controlled
+output: trace
+scope: system-wide
+description: Print out executable name, PID and time an accepted TCP socket spent in the listen queue
+test_check: stap -p4 tcp_acceptq_time.stp
+test_installcheck: stap tcp_acceptq_time.stp -c "sleep 0.2"
diff --git a/testsuite/systemtap.examples/network/tcp_acceptq_time.stp b/testsuite/systemtap.examples/network/tcp_acceptq_time.stp
new file mode 100755
index 0000000..b979804
--- /dev/null
+++ b/testsuite/systemtap.examples/network/tcp_acceptq_time.stp
@@ -0,0 +1,17 @@
+#! /usr/bin/env stap
+
+/* wrap-around just in case */
+global tcp_acceptq_start%
+
+probe kernel.function("sk_acceptq_added") {
+	tcp_acceptq_start[$sk] = cpu_clock_us(0)
+}
+
+probe kernel.function("sk_acceptq_removed") {
+	started = tcp_acceptq_start[$sk]
+	if (started) {
+		delete tcp_acceptq_start[$sk]
+		diff = cpu_clock_us(0) - started
+		printf("%s[%d] %ld\n", execname(), pid(), diff)
+	}
+}
diff --git a/testsuite/systemtap.examples/network/unix_acceptq_time.meta b/testsuite/systemtap.examples/network/unix_acceptq_time.meta
new file mode 100644
index 0000000..7ed5c88
--- /dev/null
+++ b/testsuite/systemtap.examples/network/unix_acceptq_time.meta
@@ -0,0 +1,13 @@
+title: Accept Queue time for Unix stream sockets
+name: unix_acceptq_time.stp
+version: 1.0
+author: Eric Wong
+keywords: network queue accept unix listen
+subsystem: network
+status: experimental
+exit: user-controlled
+output: trace
+scope: system-wide
+description: Print out executable name, PID and time an accepted Unix socket spent in the listen queue
+test_check: stap -p4 unix_acceptq_time.stp
+test_installcheck: stap unix_acceptq_time.stp -c "sleep 0.2"
diff --git a/testsuite/systemtap.examples/network/unix_acceptq_time.stp b/testsuite/systemtap.examples/network/unix_acceptq_time.stp
new file mode 100755
index 0000000..e514d6d
--- /dev/null
+++ b/testsuite/systemtap.examples/network/unix_acceptq_time.stp
@@ -0,0 +1,35 @@
+#! /usr/bin/env stap
+
+/* wrap-around just in case there are more unix_create1() callers */
+global unix_acceptq_start%
+
+/*
+ * Linux 3.6.x only has two unix_create1() callers:
+ * - unix_stream_connect() - we care about this
+ * - unix_create()         - we do not care about this
+ */
+probe kernel.function("unix_create1").return {
+	unix_acceptq_start[$return] = cpu_clock_us(0)
+}
+
+/*
+ * we only care about unix_create1() called from unix_stream_connect(),
+ * so avoid wasting space here.
+ * Maybe future (or past) kernels had more unix_create1() callers,
+ * wraparound for the unix_acceptq_start array will prevent us from hitting limits
+ */
+probe kernel.function("unix_create").return {
+	delete unix_acceptq_start[$return]
+}
+
+probe kernel.function("unix_accept").return {
+	if ($return != 0)
+		next
+	sk = @cast($newsock, "struct socket")->sk
+	started = unix_acceptq_start[sk]
+	if (started) {
+		delete unix_acceptq_start[sk]
+		diff = cpu_clock_us(0) - started
+		printf("%s[%d] %ld\n", execname(), pid(), diff)
+	}
+}
-- 
Eric Wong