trace_futexes.d revision 299705
1#!/usr/sbin/dtrace -qs
2
3/*-
4 * Copyright (c) 2011-2012 Alexander Leidinger <netchild@FreeBSD.org>
5 * All rights reserved.
6 *
7 * Redistribution and use in source and binary forms, with or without
8 * modification, are permitted provided that the following conditions
9 * are met:
10 * 1. Redistributions of source code must retain the above copyright
11 *    notice, this list of conditions and the following disclaimer
12 *    in this position and unchanged.
13 * 2. Redistributions in binary form must reproduce the above copyright
14 *    notice, this list of conditions and the following disclaimer in the
15 *    documentation and/or other materials provided with the distribution.
16 *
17 * THIS SOFTWARE IS PROVIDED BY THE AUTHOR ``AS IS'' AND ANY EXPRESS OR
18 * IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES
19 * OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE DISCLAIMED.
20 * IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR ANY DIRECT, INDIRECT,
21 * INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT
22 * NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
23 * DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
24 * THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
25 * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF
26 * THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
27 *
28 * $FreeBSD: stable/10/sys/compat/linux/trace_futexes.d 299705 2016-05-14 00:35:49Z pfg $
29 */
30
31/**
32 * Trace futex operations:
33 *  - internal locks
34 *  - size of the futex list
35 *  - report error conditions (emulation errors, kernel errors,
36 *    programming errors)
37 *  - execution time (wallclock) of futex related functions
38 */
39
40#pragma D option specsize=32m
41
42/* Error conditions */
43linuxulator*:futex:futex_get:error,
44linuxulator*:futex:futex_sleep:requeue_error,
45linuxulator*:futex:futex_sleep:sleep_error,
46linuxulator*:futex:futex_wait:copyin_error,
47linuxulator*:futex:futex_wait:itimerfix_error,
48linuxulator*:futex:futex_wait:sleep_error,
49linuxulator*:futex:futex_atomic_op:missing_access_check,
50linuxulator*:futex:futex_atomic_op:unimplemented_op,
51linuxulator*:futex:futex_atomic_op:unimplemented_cmp,
52linuxulator*:futex:linux_sys_futex:unimplemented_clockswitch,
53linuxulator*:futex:linux_sys_futex:copyin_error,
54linuxulator*:futex:linux_sys_futex:unhandled_efault,
55linuxulator*:futex:linux_sys_futex:unimplemented_lock_pi,
56linuxulator*:futex:linux_sys_futex:unimplemented_unlock_pi,
57linuxulator*:futex:linux_sys_futex:unimplemented_trylock_pi,
58linuxulator*:futex:linux_sys_futex:unimplemented_wait_requeue_pi,
59linuxulator*:futex:linux_sys_futex:unimplemented_cmp_requeue_pi,
60linuxulator*:futex:linux_sys_futex:unknown_operation,
61linuxulator*:futex:linux_get_robust_list:copyout_error,
62linuxulator*:futex:handle_futex_death:copyin_error,
63linuxulator*:futex:fetch_robust_entry:copyin_error,
64linuxulator*:futex:release_futexes:copyin_error
65{
66	printf("ERROR: %s in %s:%s:%s\n", probename, probeprov, probemod,
67	    probefunc);
68	stack();
69	ustack();
70}
71
72linuxulator*:futex:linux_sys_futex:invalid_cmp_requeue_use,
73linuxulator*:futex:linux_sys_futex:deprecated_requeue,
74linuxulator*:futex:linux_set_robust_list:size_error
75{
76	printf("WARNING: %s:%s:%s:%s in application %s, maybe an application error?\n",
77	    probename, probeprov, probemod, probefunc, execname);
78	stack();
79	ustack();
80}
81
82
83/* Per futex checks/statistics */
84
85linuxulator*:futex:futex:create
86{
87	++futex_count;
88	@max_futexes = max(futex_count);
89}
90
91linuxulator*:futex:futex:destroy
92/futex_count == 0/
93{
94	printf("ERROR: Request to destroy a futex which was not created,\n");
95	printf("       or this script was started after some futexes where\n");
96	printf("       created. Stack trace:\n");
97	stack();
98	ustack();
99}
100
101linuxulator*:futex:futex:destroy
102{
103	--futex_count;
104}
105
106
107/* Internal locks */
108
109linuxulator*:locks:futex_mtx:locked
110{
111	++check[probefunc, arg0];
112	@stats[probefunc] = count();
113
114	ts[probefunc] = timestamp;
115	spec[probefunc] = speculation();
116	printf("Stacktrace of last lock operation of the %s:\n", probefunc);
117	stack();
118}
119
120linuxulator*:locks:futex_mtx:unlock
121/check[probefunc, arg0] == 0/
122{
123	printf("ERROR: unlock attempt of unlocked %s (%p),", probefunc, arg0);
124	printf("       missing SDT probe in kernel, or dtrace program started");
125	printf("       while the %s was already held (race condition).", probefunc);
126	printf("       Stack trace follows:");
127	stack();
128}
129
130linuxulator*:locks:futex_mtx:unlock
131{
132	discard(spec[probefunc]);
133	spec[probefunc] = 0;
134	--check[probefunc, arg0];
135}
136
137/* Timeout handling for internal locks */
138
139tick-10s
140/spec["futex_mtx"] != 0 && timestamp - ts["futex_mtx"] >= 9999999000/
141{
142	commit(spec["futex_mtx"]);
143	spec["futex_mtx"] = 0;
144}
145
146
147/* Timing statistings */
148
149linuxulator*:futex::entry
150{
151	self->time[probefunc] = timestamp;
152	@calls[probeprov, execname, probefunc] = count();
153}
154
155linuxulator*:futex::return
156/self->time[probefunc] != 0/
157{
158	this->timediff = self->time[probefunc] - timestamp;
159
160        @timestats[probeprov, execname, probefunc] = quantize(this->timediff);
161        @longest[probeprov, probefunc] = max(this->timediff);
162
163        self->time[probefunc] = 0;
164}
165
166
167/* Statistics */
168
169END
170{
171	printf("Number of locks per type:");
172	printa(@stats);
173	printf("Number of maximum number of futexes in the futex list:");
174	printa(@max_futexes);
175	printf("Number of futexes still existing: %d", futex_count);
176	printf("Number of calls per provider/application/kernel function:");
177	printa(@calls);
178	printf("Wallclock-timing statistics per provider/application/kernel function (in ns):");
179	printa(@timestats);
180	printf("Longest running (wallclock!) functions per provider (in ns):");
181	printa(@longest);
182}
183