On Wed, Oct 24, 2012 at 02:56:55PM +0000, Myklebust, Trond wrote:
> OK, I've now posted the patches in the "bugfixes" branch of
>
> git://git.linux-nfs.org/projects/trondmy/linux-nfs.git
Cool, I'll try to get that pulled, compiled and tested by the end of the
day.
>
> By the way, you said that you were using a set of systemtap scripts to debug these races? If you'd be OK sharing those scripts, I'd love to see them. Debugging this kind of race is always difficult...
>
Sure. Attached are a bunch of them. They have very unhelpful names. :)
They progressively get more involved. As I watched their output coupled
with reading the source code, I found new areas I wanted to explore.
The numbered scripts are all aimed at being run with the `-x' flag
pointed at the process doing the stat calls, i.e.:
# stap 1.stp -x $(pgrep hang.py)
The `rpciod.stp' script is just meant to be run without any
qualifications to trace the function calls rpciod is making, i.e.:
# stap rpciod.stp
The script that really allowed me to see the race condition was 14.stp.
It produces a lot of output to poke through, but here is basically what
its doing:
- At the top there are a lot of helper functions. Their basic goals
are to translate from numbers to human readable strings. I.e.
instead of seeing `xs_tcp_send_request' return 0xffffffffffffffe0, I
wanted to see EPIPE. It makes it a lot easier to pour over several
pages of output while testing.
- Below that there are the actual probes for the functions we want to
trace, the gist of which is:
- It watches for a call to `__rpc_execute' for the process id we're
interested in. Once it fires, we use the address of its
task_struct to mark it as being traced via the `trace' array.
- This probe also takes the address of the `struct rpc_task' we're
currently working with and marks it as being traced via the
`task_trace' array. The idea with this is that another one of our
probes enables tracing of `rpc_make_runnable' and on entry into
that call we make sure we're tracing that task. This way we can
catch wake up calls for the task we care about. When we do, we
print that fact and a stack backtrace of how we got there.
- There are many other functions that I ask to trace, but only if
we're tracing the main task via the address of its task_struct
being a valid key in the `trace' array.
- I do something similiar to tracing calls to `rpc_make_runnable' with
sockets. Here we record the `struct sock' address in
`xs_tcp_send_request'. In another probe we enable tracing of
`tcp_set_state' but only for the `struct sock' that we care about.
I'm far from a SystemTap expert, and some of this stuff might not be
particularly safe (i.e. if I'm trying to translate tk_runstate to a
human readable string while something else is updating it on another
CPU). But it all seemed to work "well enough" and give insight into
what was actually happening.
Here is an example snippet of some of the output produced with 14.stp:
-----8<-----
1351091111259227075 [0xffff88060b27d540] 150 hang.py(5560): -> call_transmit: task: tk_status: 0, tk_runstate: RPC_TASK_RUNNING|RPC_TASK_ACTIVE, parms: task=0xffff8806355c9080
1351091111259235702 [0xffff88060b27d540] 159 hang.py(5560): -> xs_tcp_send_request: sock: sock=0xffff880620803140, state: SS_CONNECTING, sk=0xffff880635ded540, sk_state: TCP_ESTABLISHED, sk_err: 0, sk_shutdown: 0, task: tk_status: 0, tk_runstate: RPC_TASK_RUNNING|RPC_TASK_ACTIVE, parms: task=0xffff8806355c9080
1351091111259253562 [0xffff88060b27d540] 177 hang.py(5560): <- xs_tcp_send_request: 0
1351091111259258719 [0xffff88060b27d540] 182 hang.py(5560): -> call_transmit_status: task: tk_status: 0, tk_runstate: RPC_TASK_RUNNING|RPC_TASK_QUEUED|RPC_TASK_ACTIVE, parms: task=0xffff8806355c9080
1351091111259264704 [0xffff88060b27d540] 188 hang.py(5560): <- call_transmit_status:
1351091111259267273 [0xffff88060b27d540] 190 hang.py(5560): <- call_transmit:
1351091111259270415 [0xffff88060b27d540] 193 hang.py(5560): -> out_of_line_wait_on_bit: word: tk_runstate: RPC_TASK_QUEUED|RPC_TASK_ACTIVE, parms: word=0xffff8806355c90f0 bit=0x1 action=0xffffffffa042f930 mode=0x82
1351091111259276940 [0xffff88060b27d540] 200 hang.py(5560): -> rpc_wait_bit_killable: parms: word=0xffff8806355c90f0
1351091117489543178 [0xffff880637daeaa0] swapper -> rpc_make_runnable: task: tk_status: EAGAIN, tk_runstate: RPC_TASK_QUEUED|RPC_TASK_ACTIVE, parms: task=0xffff8806355c9080
0xffffffffa042f840 : rpc_make_runnable+0x0/0x80 [sunrpc]
0xffffffffa042fb5e : rpc_wake_up_task_queue_locked+0x18e/0x270 [sunrpc]
0xffffffffa042fc8e : rpc_wake_up_status+0x4e/0x80 [sunrpc]
0xffffffffa04288ec : xprt_wake_pending_tasks+0x2c/0x30 [sunrpc]
0xffffffffa042b9fd : xs_error_report+0x4d/0x90 [sunrpc]
0xffffffff8148d629 : tcp_reset+0x59/0x70 [kernel]
0xffffffff8148d918 : tcp_validate_incoming+0x2d8/0x3a0 [kernel]
0xffffffff81491006 : tcp_rcv_established+0x2e6/0x800 [kernel]
0xffffffff814990f3 : tcp_v4_do_rcv+0x2e3/0x430 [kernel]
0xffffffff8149a96e : tcp_v4_rcv+0x4fe/0x8d0 [kernel]
0xffffffff8147868d : ip_local_deliver_finish+0xdd/0x2d0 [kernel]
0xffffffff81478918 : ip_local_deliver+0x98/0xa0 [kernel]
0xffffffff81477ddd : ip_rcv_finish+0x12d/0x440 [kernel]
0xffffffff81478365 : ip_rcv+0x275/0x350 [kernel]
0xffffffff81441a5b : __netif_receive_skb+0x49b/0x6f0 [kernel]
0xffffffff81443cd8 : netif_receive_skb+0x58/0x60 [kernel]
0xffffffff81443de0 : napi_skb_finish+0x50/0x70 [kernel]
0xffffffff81446319 : napi_gro_receive+0x39/0x50 [kernel]
0xffffffffa0126f2f [bnx2]
0x0 (inexact)
-----8<-----
Chris
global trace
probe module("sunrpc").function("rpc_call_sync").call {
if (pid() == target()) {
t = task_current()
printf("[0x%x] %s -> %s: %s\n", t, thread_indent(1), probefunc(), $$parms)
trace[t] = 1
}
}
probe module("sunrpc").function("rpc_call_sync").return {
t = task_current()
if (trace[t]) {
printf("[0x%x] %s <- %s: %s\n", t, thread_indent(-1), probefunc(), $$return)
trace[t] = 0
}
}
probe module("sunrpc").function("*").call {
t = task_current()
if (trace[t]) {
printf("[0x%x] %s -> %s: %s\n", t, thread_indent(1), probefunc(), $$parms)
}
}
probe module("sunrpc").function("*").return {
t = task_current()
if (trace[t]) {
printf("[0x%x] %s <- %s: %s\n", t, thread_indent(-1), probefunc(), $$return)
}
}
# vim: ts=2 sts=2 sw=2 et
global trace
probe module("sunrpc").function("__rpc_execute").call {
t = task_current()
if (pid() == target()) {
printf("[0x%x] %s -> %s: %s\n", t, thread_indent(1), probefunc(), $$parms)
trace[t] = 1
}
}
probe module("sunrpc").function("__rpc_execute").return {
t = task_current()
if (trace[t]) {
printf("[0x%x] %s <- %s: %s\n", t, thread_indent(-1), probefunc(), $$return)
trace[t] = 0
}
}
global trace
probe module("sunrpc").function("__rpc_execute").call {
if (pid() == target()) {
t = task_current()
proc = @cast(&$task->tk_msg, "struct rpc_message")->rpc_proc
func = @cast(proc, "struct rpc_procinfo")->p_name
serv = @cast($task->tk_client, "struct rpc_clnt")->cl_server
func_name = kernel_string(func)
serv_name = kernel_string(serv)
printf("[0x%x] %s -> %s: %s: proc_name: %s, server: %s\n", t, thread_indent(1), probefunc(), $$parms, func_name, serv_name)
trace[t] = 1
}
}
probe module("sunrpc").function("__rpc_execute").return {
t = task_current()
if (trace[t]) {
printf("[0x%x] %s <- %s: %s\n", t, thread_indent(-1), probefunc(), $$return)
trace[t] = 0
}
}
probe module("sunrpc").function("*").call {
t = task_current()
if (trace[t]) {
printf("[0x%x] %s -> %s: %s\n", t, thread_indent(1), probefunc(), $$parms)
}
}
probe module("sunrpc").function("*").return {
t = task_current()
if (trace[t]) {
printf("[0x%x] %s <- %s: %s\n", t, thread_indent(-1), probefunc(), $$return)
}
}
# vim: ts=2 sts=2 sw=2 et
global trace
global _errno[134]
probe begin {
_errno[0] = "0"
_errno[1] = "EPERM"
_errno[2] = "ENOENT"
_errno[3] = "ESRCH"
_errno[4] = "EINTR"
_errno[5] = "EIO"
_errno[6] = "ENXIO"
_errno[7] = "E2BIG"
_errno[8] = "ENOEXEC"
_errno[9] = "EBADF"
_errno[10] = "ECHILD"
_errno[11] = "EAGAIN"
_errno[12] = "ENOMEM"
_errno[13] = "EACCES"
_errno[14] = "EFAULT"
_errno[15] = "ENOTBLK"
_errno[16] = "EBUSY"
_errno[17] = "EEXIST"
_errno[18] = "EXDEV"
_errno[19] = "ENODEV"
_errno[20] = "ENOTDIR"
_errno[21] = "EISDIR"
_errno[22] = "EINVAL"
_errno[23] = "ENFILE"
_errno[24] = "EMFILE"
_errno[25] = "ENOTTY"
_errno[26] = "ETXTBSY"
_errno[27] = "EFBIG"
_errno[28] = "ENOSPC"
_errno[29] = "ESPIPE"
_errno[30] = "EROFS"
_errno[31] = "EMLINK"
_errno[32] = "EPIPE"
_errno[33] = "EDOM"
_errno[34] = "ERANGE"
_errno[35] = "EDEADLK"
_errno[36] = "ENAMETOOLONG"
_errno[37] = "ENOLCK"
_errno[38] = "ENOSYS"
_errno[39] = "ENOTEMPTY"
_errno[40] = "ELOOP"
_errno[41] = "UNDEF"
_errno[42] = "ENOMSG"
_errno[43] = "EIDRM"
_errno[44] = "ECHRNG"
_errno[45] = "EL2NSYNC"
_errno[46] = "EL3HLT"
_errno[47] = "EL3RST"
_errno[48] = "ELNRNG"
_errno[49] = "EUNATCH"
_errno[50] = "ENOCSI"
_errno[51] = "EL2HLT"
_errno[52] = "EBADE"
_errno[53] = "EBADR"
_errno[54] = "EXFULL"
_errno[55] = "ENOANO"
_errno[56] = "EBADRQC"
_errno[57] = "EBADSLT"
_errno[58] = "UNDEF"
_errno[59] = "EBFONT"
_errno[60] = "ENOSTR"
_errno[61] = "ENODATA"
_errno[62] = "ETIME"
_errno[63] = "ENOSR"
_errno[64] = "ENONET"
_errno[65] = "ENOPKG"
_errno[66] = "EREMOTE"
_errno[67] = "ENOLINK"
_errno[68] = "EADV"
_errno[69] = "ESRMNT"
_errno[70] = "ECOMM"
_errno[71] = "EPROTO"
_errno[72] = "EMULTIHOP"
_errno[73] = "EDOTDOT"
_errno[74] = "EBADMSG"
_errno[75] = "EOVERFLOW"
_errno[76] = "ENOTUNIQ"
_errno[77] = "EBADFD"
_errno[78] = "EREMCHG"
_errno[79] = "ELIBACC"
_errno[80] = "ELIBBAD"
_errno[81] = "ELIBSCN"
_errno[82] = "ELIBMAX"
_errno[83] = "ELIBEXEC"
_errno[84] = "EILSEQ"
_errno[85] = "ERESTART"
_errno[86] = "ESTRPIPE"
_errno[87] = "EUSERS"
_errno[88] = "ENOTSOCK"
_errno[89] = "EDESTADDRREQ"
_errno[90] = "EMSGSIZE"
_errno[91] = "EPROTOTYPE"
_errno[92] = "ENOPROTOOPT"
_errno[93] = "EPROTONOSUPPORT"
_errno[94] = "ESOCKTNOSUPPORT"
_errno[95] = "EOPNOTSUPP"
_errno[96] = "EPFNOSUPPORT"
_errno[97] = "EAFNOSUPPORT"
_errno[98] = "EADDRINUSE"
_errno[99] = "EADDRNOTAVAIL"
_errno[100] = "ENETDOWN"
_errno[101] = "ENETUNREACH"
_errno[102] = "ENETRESET"
_errno[103] = "ECONNABORTED"
_errno[104] = "ECONNRESET"
_errno[105] = "ENOBUFS"
_errno[106] = "EISCONN"
_errno[107] = "ENOTCONN"
_errno[108] = "ESHUTDOWN"
_errno[109] = "ETOOMANYREFS"
_errno[110] = "ETIMEDOUT"
_errno[111] = "ECONNREFUSED"
_errno[112] = "EHOSTDOWN"
_errno[113] = "EHOSTUNREACH"
_errno[114] = "EALREADY"
_errno[115] = "EINPROGRESS"
_errno[116] = "ESTALE"
_errno[117] = "EUCLEAN"
_errno[118] = "ENOTNAM"
_errno[119] = "ENAVAIL"
_errno[120] = "EISNAM"
_errno[121] = "EREMOTEIO"
_errno[122] = "EDQUOT"
_errno[123] = "ENOMEDIUM"
_errno[124] = "EMEDIUMTYPE"
_errno[125] = "ECANCELED"
_errno[126] = "ENOKEY"
_errno[127] = "EKEYEXPIRED"
_errno[128] = "EKEYREVOKED"
_errno[129] = "EKEYREJECTED"
_errno[130] = "EOWNERDEAD"
_errno[131] = "ENOTRECOVERABLE"
_errno[132] = "ERFKILL"
_errno[133] = "EHWPOISON"
}
function err_num2str:string (error:long) {
error = -error
return (error in _errno ? _errno[error] : sprintf("0x%x", -error))
}
probe module("sunrpc").function("__rpc_execute").call {
if (pid() == target()) {
t = task_current()
p = probefunc()
serv = @cast($task->tk_client, "struct rpc_clnt")->cl_server
serv_name = kernel_string(serv)
proc = @cast(&$task->tk_msg, "struct rpc_message")->rpc_proc
func = @cast(proc, "struct rpc_procinfo")->p_name
func_name = kernel_string(func)
printf("[0x%x] %s -> %s: func: %s, server: %s, parms: %s\n", t, thread_indent(1), p, func_name, serv_name, $$parms)
trace[t] = 1
}
}
probe module("sunrpc").function("__rpc_execute").return {
t = task_current()
p = probefunc()
if (trace[t]) {
printf("[0x%x] %s <- %s: %s\n", t, thread_indent(-1), p, $$return)
trace[t] = 0
}
}
probe module("sunrpc").function("xs_tcp_send_request").call {
t = task_current()
p = probefunc()
if (trace[t]) {
printf("[0x%x] %s -> %s: %s\n", t, thread_indent(1), p, $$parms)
}
}
probe module("sunrpc").function("xs_tcp_send_request").return {
t = task_current()
if (trace[t]) {
printf("[0x%x] %s <- %s: %s\n", t, thread_indent(-1), probefunc(), err_num2str($return))
}
}
# vim: ts=2 sts=2 sw=2 et
global trace
global _errno[134]
probe begin {
_errno[0] = "0"
_errno[1] = "EPERM"
_errno[2] = "ENOENT"
_errno[3] = "ESRCH"
_errno[4] = "EINTR"
_errno[5] = "EIO"
_errno[6] = "ENXIO"
_errno[7] = "E2BIG"
_errno[8] = "ENOEXEC"
_errno[9] = "EBADF"
_errno[10] = "ECHILD"
_errno[11] = "EAGAIN"
_errno[12] = "ENOMEM"
_errno[13] = "EACCES"
_errno[14] = "EFAULT"
_errno[15] = "ENOTBLK"
_errno[16] = "EBUSY"
_errno[17] = "EEXIST"
_errno[18] = "EXDEV"
_errno[19] = "ENODEV"
_errno[20] = "ENOTDIR"
_errno[21] = "EISDIR"
_errno[22] = "EINVAL"
_errno[23] = "ENFILE"
_errno[24] = "EMFILE"
_errno[25] = "ENOTTY"
_errno[26] = "ETXTBSY"
_errno[27] = "EFBIG"
_errno[28] = "ENOSPC"
_errno[29] = "ESPIPE"
_errno[30] = "EROFS"
_errno[31] = "EMLINK"
_errno[32] = "EPIPE"
_errno[33] = "EDOM"
_errno[34] = "ERANGE"
_errno[35] = "EDEADLK"
_errno[36] = "ENAMETOOLONG"
_errno[37] = "ENOLCK"
_errno[38] = "ENOSYS"
_errno[39] = "ENOTEMPTY"
_errno[40] = "ELOOP"
_errno[41] = "UNDEF"
_errno[42] = "ENOMSG"
_errno[43] = "EIDRM"
_errno[44] = "ECHRNG"
_errno[45] = "EL2NSYNC"
_errno[46] = "EL3HLT"
_errno[47] = "EL3RST"
_errno[48] = "ELNRNG"
_errno[49] = "EUNATCH"
_errno[50] = "ENOCSI"
_errno[51] = "EL2HLT"
_errno[52] = "EBADE"
_errno[53] = "EBADR"
_errno[54] = "EXFULL"
_errno[55] = "ENOANO"
_errno[56] = "EBADRQC"
_errno[57] = "EBADSLT"
_errno[58] = "UNDEF"
_errno[59] = "EBFONT"
_errno[60] = "ENOSTR"
_errno[61] = "ENODATA"
_errno[62] = "ETIME"
_errno[63] = "ENOSR"
_errno[64] = "ENONET"
_errno[65] = "ENOPKG"
_errno[66] = "EREMOTE"
_errno[67] = "ENOLINK"
_errno[68] = "EADV"
_errno[69] = "ESRMNT"
_errno[70] = "ECOMM"
_errno[71] = "EPROTO"
_errno[72] = "EMULTIHOP"
_errno[73] = "EDOTDOT"
_errno[74] = "EBADMSG"
_errno[75] = "EOVERFLOW"
_errno[76] = "ENOTUNIQ"
_errno[77] = "EBADFD"
_errno[78] = "EREMCHG"
_errno[79] = "ELIBACC"
_errno[80] = "ELIBBAD"
_errno[81] = "ELIBSCN"
_errno[82] = "ELIBMAX"
_errno[83] = "ELIBEXEC"
_errno[84] = "EILSEQ"
_errno[85] = "ERESTART"
_errno[86] = "ESTRPIPE"
_errno[87] = "EUSERS"
_errno[88] = "ENOTSOCK"
_errno[89] = "EDESTADDRREQ"
_errno[90] = "EMSGSIZE"
_errno[91] = "EPROTOTYPE"
_errno[92] = "ENOPROTOOPT"
_errno[93] = "EPROTONOSUPPORT"
_errno[94] = "ESOCKTNOSUPPORT"
_errno[95] = "EOPNOTSUPP"
_errno[96] = "EPFNOSUPPORT"
_errno[97] = "EAFNOSUPPORT"
_errno[98] = "EADDRINUSE"
_errno[99] = "EADDRNOTAVAIL"
_errno[100] = "ENETDOWN"
_errno[101] = "ENETUNREACH"
_errno[102] = "ENETRESET"
_errno[103] = "ECONNABORTED"
_errno[104] = "ECONNRESET"
_errno[105] = "ENOBUFS"
_errno[106] = "EISCONN"
_errno[107] = "ENOTCONN"
_errno[108] = "ESHUTDOWN"
_errno[109] = "ETOOMANYREFS"
_errno[110] = "ETIMEDOUT"
_errno[111] = "ECONNREFUSED"
_errno[112] = "EHOSTDOWN"
_errno[113] = "EHOSTUNREACH"
_errno[114] = "EALREADY"
_errno[115] = "EINPROGRESS"
_errno[116] = "ESTALE"
_errno[117] = "EUCLEAN"
_errno[118] = "ENOTNAM"
_errno[119] = "ENAVAIL"
_errno[120] = "EISNAM"
_errno[121] = "EREMOTEIO"
_errno[122] = "EDQUOT"
_errno[123] = "ENOMEDIUM"
_errno[124] = "EMEDIUMTYPE"
_errno[125] = "ECANCELED"
_errno[126] = "ENOKEY"
_errno[127] = "EKEYEXPIRED"
_errno[128] = "EKEYREVOKED"
_errno[129] = "EKEYREJECTED"
_errno[130] = "EOWNERDEAD"
_errno[131] = "ENOTRECOVERABLE"
_errno[132] = "ERFKILL"
_errno[133] = "EHWPOISON"
}
function err_num2str:string (error:long) {
error = -error
return (error in _errno ? _errno[error] : sprintf("0x%x", -error))
}
probe module("sunrpc").function("__rpc_execute").call {
if (pid() == target()) {
t = task_current()
p = probefunc()
serv = @cast($task->tk_client, "struct rpc_clnt")->cl_server
serv_name = kernel_string(serv)
proc = @cast(&$task->tk_msg, "struct rpc_message")->rpc_proc
func = @cast(proc, "struct rpc_procinfo")->p_name
func_name = kernel_string(func)
printf("[0x%x] %s -> %s: func: %s, server: %s, parms: %s\n", t, thread_indent(1), p, func_name, serv_name, $$parms)
trace[t] = 1
}
}
probe module("sunrpc").function("__rpc_execute").return {
t = task_current()
p = probefunc()
if (trace[t]) {
printf("[0x%x] %s <- %s: %s\n", t, thread_indent(-1), p, $$return)
trace[t] = 0
}
}
probe module("sunrpc").function("xs_tcp_send_request").call {
t = task_current()
p = probefunc()
if (trace[t] == 1) {
printf("[0x%x] %s -> %s: %s\n", t, thread_indent(1), p, $$parms)
trace[t] = 2
}
}
probe module("sunrpc").function("xs_tcp_send_request").return {
t = task_current()
if (trace[t] == 2) {
printf("[0x%x] %s <- %s: %s\n", t, thread_indent(-1), probefunc(), err_num2str($return))
trace[t] = 1
}
}
probe module("sunrpc").function("*").call,
kernel.function("*@net/ipv4/tcp*").call,
kernel.function("*@net/core/stream.c").call,
kernel.function("*@net/socket.c").call {
t = task_current()
p = probefunc()
if (trace[t] == 2) {
printf("[0x%x] %s -> %s: %s\n", t, thread_indent(1), p, $$parms)
}
}
probe module("sunrpc").function("*").return,
kernel.function("*@net/ipv4/tcp*").return,
kernel.function("*@net/core/stream.c").return,
kernel.function("*@net/socket.c").return {
t = task_current()
p = probefunc()
if (trace[t] == 2) {
printf("[0x%x] %s <- %s: %s\n", t, thread_indent(-1), p, $$return)
}
}
# vim: ts=2 sts=2 sw=2 et
global trace
global _tcp_state[13]
global _sock_state[5]
global _errno[134]
global _sock_sk_shutdown[2]
probe begin {
/* from include/net/tcp_states.h */
_tcp_state[0] = "UNDEF"
_tcp_state[1] = "TCP_ESTABLISHED"
_tcp_state[2] = "TCP_SYN_SENT"
_tcp_state[3] = "TCP_SYN_RECV"
_tcp_state[4] = "TCP_FIN_WAIT1"
_tcp_state[5] = "TCP_FIN_WAIT2"
_tcp_state[6] = "TCP_TIME_WAIT"
_tcp_state[7] = "TCP_CLOSE"
_tcp_state[8] = "TCP_CLOSE_WAIT"
_tcp_state[9] = "TCP_LAST_ACK"
_tcp_state[10] = "TCP_LISTEN"
_tcp_state[11] = "TCP_CLOSING"
_tcp_state[12] = "TCP_MAX_STATES"
/* from include/linux/net.h */
_sock_state[0] = "SS_FREE"
_sock_state[1] = "SS_UNCONNECTED"
_sock_state[2] = "SS_CONNECTING"
_sock_state[3] = "SS_CONNECTED"
_sock_state[4] = "SS_DISCONNECTING"
/* from include/asm-generic/errno-base.h
* and include/asm-generic/errno.h
*/
_errno[0] = "0"
_errno[1] = "EPERM"
_errno[2] = "ENOENT"
_errno[3] = "ESRCH"
_errno[4] = "EINTR"
_errno[5] = "EIO"
_errno[6] = "ENXIO"
_errno[7] = "E2BIG"
_errno[8] = "ENOEXEC"
_errno[9] = "EBADF"
_errno[10] = "ECHILD"
_errno[11] = "EAGAIN"
_errno[12] = "ENOMEM"
_errno[13] = "EACCES"
_errno[14] = "EFAULT"
_errno[15] = "ENOTBLK"
_errno[16] = "EBUSY"
_errno[17] = "EEXIST"
_errno[18] = "EXDEV"
_errno[19] = "ENODEV"
_errno[20] = "ENOTDIR"
_errno[21] = "EISDIR"
_errno[22] = "EINVAL"
_errno[23] = "ENFILE"
_errno[24] = "EMFILE"
_errno[25] = "ENOTTY"
_errno[26] = "ETXTBSY"
_errno[27] = "EFBIG"
_errno[28] = "ENOSPC"
_errno[29] = "ESPIPE"
_errno[30] = "EROFS"
_errno[31] = "EMLINK"
_errno[32] = "EPIPE"
_errno[33] = "EDOM"
_errno[34] = "ERANGE"
_errno[35] = "EDEADLK"
_errno[36] = "ENAMETOOLONG"
_errno[37] = "ENOLCK"
_errno[38] = "ENOSYS"
_errno[39] = "ENOTEMPTY"
_errno[40] = "ELOOP"
_errno[41] = "UNDEF"
_errno[42] = "ENOMSG"
_errno[43] = "EIDRM"
_errno[44] = "ECHRNG"
_errno[45] = "EL2NSYNC"
_errno[46] = "EL3HLT"
_errno[47] = "EL3RST"
_errno[48] = "ELNRNG"
_errno[49] = "EUNATCH"
_errno[50] = "ENOCSI"
_errno[51] = "EL2HLT"
_errno[52] = "EBADE"
_errno[53] = "EBADR"
_errno[54] = "EXFULL"
_errno[55] = "ENOANO"
_errno[56] = "EBADRQC"
_errno[57] = "EBADSLT"
_errno[58] = "UNDEF"
_errno[59] = "EBFONT"
_errno[60] = "ENOSTR"
_errno[61] = "ENODATA"
_errno[62] = "ETIME"
_errno[63] = "ENOSR"
_errno[64] = "ENONET"
_errno[65] = "ENOPKG"
_errno[66] = "EREMOTE"
_errno[67] = "ENOLINK"
_errno[68] = "EADV"
_errno[69] = "ESRMNT"
_errno[70] = "ECOMM"
_errno[71] = "EPROTO"
_errno[72] = "EMULTIHOP"
_errno[73] = "EDOTDOT"
_errno[74] = "EBADMSG"
_errno[75] = "EOVERFLOW"
_errno[76] = "ENOTUNIQ"
_errno[77] = "EBADFD"
_errno[78] = "EREMCHG"
_errno[79] = "ELIBACC"
_errno[80] = "ELIBBAD"
_errno[81] = "ELIBSCN"
_errno[82] = "ELIBMAX"
_errno[83] = "ELIBEXEC"
_errno[84] = "EILSEQ"
_errno[85] = "ERESTART"
_errno[86] = "ESTRPIPE"
_errno[87] = "EUSERS"
_errno[88] = "ENOTSOCK"
_errno[89] = "EDESTADDRREQ"
_errno[90] = "EMSGSIZE"
_errno[91] = "EPROTOTYPE"
_errno[92] = "ENOPROTOOPT"
_errno[93] = "EPROTONOSUPPORT"
_errno[94] = "ESOCKTNOSUPPORT"
_errno[95] = "EOPNOTSUPP"
_errno[96] = "EPFNOSUPPORT"
_errno[97] = "EAFNOSUPPORT"
_errno[98] = "EADDRINUSE"
_errno[99] = "EADDRNOTAVAIL"
_errno[100] = "ENETDOWN"
_errno[101] = "ENETUNREACH"
_errno[102] = "ENETRESET"
_errno[103] = "ECONNABORTED"
_errno[104] = "ECONNRESET"
_errno[105] = "ENOBUFS"
_errno[106] = "EISCONN"
_errno[107] = "ENOTCONN"
_errno[108] = "ESHUTDOWN"
_errno[109] = "ETOOMANYREFS"
_errno[110] = "ETIMEDOUT"
_errno[111] = "ECONNREFUSED"
_errno[112] = "EHOSTDOWN"
_errno[113] = "EHOSTUNREACH"
_errno[114] = "EALREADY"
_errno[115] = "EINPROGRESS"
_errno[116] = "ESTALE"
_errno[117] = "EUCLEAN"
_errno[118] = "ENOTNAM"
_errno[119] = "ENAVAIL"
_errno[120] = "EISNAM"
_errno[121] = "EREMOTEIO"
_errno[122] = "EDQUOT"
_errno[123] = "ENOMEDIUM"
_errno[124] = "EMEDIUMTYPE"
_errno[125] = "ECANCELED"
_errno[126] = "ENOKEY"
_errno[127] = "EKEYEXPIRED"
_errno[128] = "EKEYREVOKED"
_errno[129] = "EKEYREJECTED"
_errno[130] = "EOWNERDEAD"
_errno[131] = "ENOTRECOVERABLE"
_errno[132] = "ERFKILL"
_errno[133] = "EHWPOISON"
}
function err_num2str:string (error:long) {
error = -error
return (error in _errno ? _errno[error] : sprintf("0x%x", -error))
}
function sk_state_num2str:string (state:long) {
return (state in _tcp_state ? _tcp_state[state] : sprintf("0x%x", state))
}
function sock_state_num2str:string (state:long)
{
return (state in _sock_state ? _sock_state[state] : sprintf("0x%x", state))
}
function sk_shutdown_num2str:string (flags:long)
{
/* from include/net/sock.h */
RCV_SHUTDOWN = 1
SEND_SHUTDOWN = 2
retvalue = ""
if (flags & SEND_SHUTDOWN)
_sock_sk_shutdown["SEND_SHUTDOWN"] = 1
if (flags & RCV_SHUTDOWN)
_sock_sk_shutdown["RCV_SHUTDOWN"] = 1
foreach (key in _sock_sk_shutdown) {
sep = retvalue == "" ? "" : "|"
retvalue = sprintf("%s%s%s", retvalue, sep, key)
}
delete _sock_sk_shutdown
return retvalue == "" ? "0" : retvalue
}
function sk2str:string (sk:long)
{
sk_state = sk_state_num2str(@cast(sk, "struct sock")->__sk_common->skc_state)
sk_shutdown = sk_shutdown_num2str(@cast(sk, "struct sock")->sk_shutdown)
sk_err = err_num2str(-(@cast(sk, "struct sock")->sk_err))
return sprintf("sk=0x%x, sk_state: %s, sk_err: %s, sk_shutdown: %s", sk, sk_state, sk_err, sk_shutdown)
}
function sock2str:string (sock:long)
{
sock_state = @cast(sock, "struct socket")->state
sock_sk = @cast(sock, "struct socket")->sk
return sprintf("sock=0x%x, state: %s, %s", sock, sock_state_num2str(sock_state), sk2str(sock_sk))
}
probe module("sunrpc").function("__rpc_execute").call {
if (pid() == target()) {
t = task_current()
p = probefunc()
serv = @cast($task->tk_client, "struct rpc_clnt")->cl_server
serv_name = kernel_string(serv)
proc = @cast(&$task->tk_msg, "struct rpc_message")->rpc_proc
func = @cast(proc, "struct rpc_procinfo")->p_name
func_name = kernel_string(func)
printf("[0x%x] %s -> %s: func: %s, server: %s, parms: %s\n", t, thread_indent(1), p, func_name, serv_name, $$parms)
trace[t] = 1
}
}
probe module("sunrpc").function("__rpc_execute").return {
t = task_current()
p = probefunc()
if (trace[t]) {
printf("[0x%x] %s <- %s: %s\n", t, thread_indent(-1), p, $$return)
trace[t] = 0
}
}
probe module("sunrpc").function("xs_tcp_send_request").call {
t = task_current()
p = probefunc()
if (trace[t] == 1) {
printf("[0x%x] %s -> %s: %s\n", t, thread_indent(1), p, $$parms)
trace[t] = 2
}
}
probe module("sunrpc").function("xs_tcp_send_request").return {
t = task_current()
if (trace[t] == 2) {
printf("[0x%x] %s <- %s: %s\n", t, thread_indent(-1), probefunc(), err_num2str($return))
trace[t] = 1
}
}
probe kernel.function("tcp_sendmsg").call {
t = task_current()
if (trace[t] == 2) {
printf("[0x%x] %s -> %s: sock: %s\n", t, thread_indent(1), probefunc(), sock2str($sock))
}
}
probe kernel.function("tcp_sendmsg").return {
t = task_current()
if (trace[t] == 2) {
printf("[0x%x] %s <- %s: %s\n", t, thread_indent(-1), probefunc(), err_num2str($return))
}
}
probe kernel.function("sk_stream_wait_connect").call {
t = task_current()
if (trace[t] == 2) {
printf("[0x%x] %s -> %s: sk: %s, time_out: %ld\n", t, thread_indent(1), probefunc(), sk2str($sk), kernel_long($timeo_p))
}
}
probe kernel.function("sk_stream_wait_connect").return {
t = task_current()
if (trace[t] == 2) {
printf("[0x%x] %s <- %s: %s\n", t, thread_indent(-1), probefunc(), err_num2str($return))
}
}
# vim: ts=2 sts=2 sw=2 et
global trace
global sk_trace
global task_trace
global _tcp_state[13]
global _sock_state[5]
global _errno[134]
global _task_tk_runstate[3]
global _sock_sk_shutdown[2]
probe begin {
/* from include/net/tcp_states.h */
_tcp_state[0] = "UNDEF"
_tcp_state[1] = "TCP_ESTABLISHED"
_tcp_state[2] = "TCP_SYN_SENT"
_tcp_state[3] = "TCP_SYN_RECV"
_tcp_state[4] = "TCP_FIN_WAIT1"
_tcp_state[5] = "TCP_FIN_WAIT2"
_tcp_state[6] = "TCP_TIME_WAIT"
_tcp_state[7] = "TCP_CLOSE"
_tcp_state[8] = "TCP_CLOSE_WAIT"
_tcp_state[9] = "TCP_LAST_ACK"
_tcp_state[10] = "TCP_LISTEN"
_tcp_state[11] = "TCP_CLOSING"
_tcp_state[12] = "TCP_MAX_STATES"
/* from include/linux/net.h */
_sock_state[0] = "SS_FREE"
_sock_state[1] = "SS_UNCONNECTED"
_sock_state[2] = "SS_CONNECTING"
_sock_state[3] = "SS_CONNECTED"
_sock_state[4] = "SS_DISCONNECTING"
_errno[0] = "0"
_errno[1] = "EPERM"
_errno[2] = "ENOENT"
_errno[3] = "ESRCH"
_errno[4] = "EINTR"
_errno[5] = "EIO"
_errno[6] = "ENXIO"
_errno[7] = "E2BIG"
_errno[8] = "ENOEXEC"
_errno[9] = "EBADF"
_errno[10] = "ECHILD"
_errno[11] = "EAGAIN"
_errno[12] = "ENOMEM"
_errno[13] = "EACCES"
_errno[14] = "EFAULT"
_errno[15] = "ENOTBLK"
_errno[16] = "EBUSY"
_errno[17] = "EEXIST"
_errno[18] = "EXDEV"
_errno[19] = "ENODEV"
_errno[20] = "ENOTDIR"
_errno[21] = "EISDIR"
_errno[22] = "EINVAL"
_errno[23] = "ENFILE"
_errno[24] = "EMFILE"
_errno[25] = "ENOTTY"
_errno[26] = "ETXTBSY"
_errno[27] = "EFBIG"
_errno[28] = "ENOSPC"
_errno[29] = "ESPIPE"
_errno[30] = "EROFS"
_errno[31] = "EMLINK"
_errno[32] = "EPIPE"
_errno[33] = "EDOM"
_errno[34] = "ERANGE"
_errno[35] = "EDEADLK"
_errno[36] = "ENAMETOOLONG"
_errno[37] = "ENOLCK"
_errno[38] = "ENOSYS"
_errno[39] = "ENOTEMPTY"
_errno[40] = "ELOOP"
_errno[41] = "UNDEF"
_errno[42] = "ENOMSG"
_errno[43] = "EIDRM"
_errno[44] = "ECHRNG"
_errno[45] = "EL2NSYNC"
_errno[46] = "EL3HLT"
_errno[47] = "EL3RST"
_errno[48] = "ELNRNG"
_errno[49] = "EUNATCH"
_errno[50] = "ENOCSI"
_errno[51] = "EL2HLT"
_errno[52] = "EBADE"
_errno[53] = "EBADR"
_errno[54] = "EXFULL"
_errno[55] = "ENOANO"
_errno[56] = "EBADRQC"
_errno[57] = "EBADSLT"
_errno[58] = "UNDEF"
_errno[59] = "EBFONT"
_errno[60] = "ENOSTR"
_errno[61] = "ENODATA"
_errno[62] = "ETIME"
_errno[63] = "ENOSR"
_errno[64] = "ENONET"
_errno[65] = "ENOPKG"
_errno[66] = "EREMOTE"
_errno[67] = "ENOLINK"
_errno[68] = "EADV"
_errno[69] = "ESRMNT"
_errno[70] = "ECOMM"
_errno[71] = "EPROTO"
_errno[72] = "EMULTIHOP"
_errno[73] = "EDOTDOT"
_errno[74] = "EBADMSG"
_errno[75] = "EOVERFLOW"
_errno[76] = "ENOTUNIQ"
_errno[77] = "EBADFD"
_errno[78] = "EREMCHG"
_errno[79] = "ELIBACC"
_errno[80] = "ELIBBAD"
_errno[81] = "ELIBSCN"
_errno[82] = "ELIBMAX"
_errno[83] = "ELIBEXEC"
_errno[84] = "EILSEQ"
_errno[85] = "ERESTART"
_errno[86] = "ESTRPIPE"
_errno[87] = "EUSERS"
_errno[88] = "ENOTSOCK"
_errno[89] = "EDESTADDRREQ"
_errno[90] = "EMSGSIZE"
_errno[91] = "EPROTOTYPE"
_errno[92] = "ENOPROTOOPT"
_errno[93] = "EPROTONOSUPPORT"
_errno[94] = "ESOCKTNOSUPPORT"
_errno[95] = "EOPNOTSUPP"
_errno[96] = "EPFNOSUPPORT"
_errno[97] = "EAFNOSUPPORT"
_errno[98] = "EADDRINUSE"
_errno[99] = "EADDRNOTAVAIL"
_errno[100] = "ENETDOWN"
_errno[101] = "ENETUNREACH"
_errno[102] = "ENETRESET"
_errno[103] = "ECONNABORTED"
_errno[104] = "ECONNRESET"
_errno[105] = "ENOBUFS"
_errno[106] = "EISCONN"
_errno[107] = "ENOTCONN"
_errno[108] = "ESHUTDOWN"
_errno[109] = "ETOOMANYREFS"
_errno[110] = "ETIMEDOUT"
_errno[111] = "ECONNREFUSED"
_errno[112] = "EHOSTDOWN"
_errno[113] = "EHOSTUNREACH"
_errno[114] = "EALREADY"
_errno[115] = "EINPROGRESS"
_errno[116] = "ESTALE"
_errno[117] = "EUCLEAN"
_errno[118] = "ENOTNAM"
_errno[119] = "ENAVAIL"
_errno[120] = "EISNAM"
_errno[121] = "EREMOTEIO"
_errno[122] = "EDQUOT"
_errno[123] = "ENOMEDIUM"
_errno[124] = "EMEDIUMTYPE"
_errno[125] = "ECANCELED"
_errno[126] = "ENOKEY"
_errno[127] = "EKEYEXPIRED"
_errno[128] = "EKEYREVOKED"
_errno[129] = "EKEYREJECTED"
_errno[130] = "EOWNERDEAD"
_errno[131] = "ENOTRECOVERABLE"
_errno[132] = "ERFKILL"
_errno[133] = "EHWPOISON"
}
function err_num2str:string (error:long) {
error = -error
return (error in _errno ? _errno[error] : sprintf("0x%x", -error))
}
function sk_state_num2str:string (state:long) {
return (state in _tcp_state ? _tcp_state[state] : sprintf("0x%x", state))
}
function sock_state_num2str:string (state:long)
{
return (state in _sock_state ? _sock_state[state] : sprintf("0x%x", state))
}
function sk_shutdown_num2str:string (flags:long)
{
/* from include/net/sock.h */
RCV_SHUTDOWN = 1
SEND_SHUTDOWN = 2
retvalue = ""
if (flags & SEND_SHUTDOWN)
_sock_sk_shutdown["SEND_SHUTDOWN"] = 1
if (flags & RCV_SHUTDOWN)
_sock_sk_shutdown["RCV_SHUTDOWN"] = 1
foreach (key in _sock_sk_shutdown) {
sep = retvalue == "" ? "" : "|"
retvalue = sprintf("%s%s%s", retvalue, sep, key)
}
delete _sock_sk_shutdown
return retvalue == "" ? "0" : retvalue
}
function sk2str:string (sk:long)
{
sk_state = sk_state_num2str(@cast(sk, "struct sock")->__sk_common->skc_state)
sk_shutdown = sk_shutdown_num2str(@cast(sk, "struct sock")->sk_shutdown)
sk_err = err_num2str(-(@cast(sk, "struct sock")->sk_err))
return sprintf("sk=0x%x, sk_state: %s, sk_err: %s, sk_shutdown: %s", sk, sk_state, sk_err, sk_shutdown)
}
function sock2str:string (sock:long)
{
sock_state = @cast(sock, "struct socket")->state
sock_sk = @cast(sock, "struct socket")->sk
return sprintf("sock=0x%x, state: %s, %s", sock, sock_state_num2str(sock_state), sk2str(sock_sk))
}
function task_runstate_num2str:string (word:long)
{
/* from include/linux/runrpc/sched.h but watch out, needs translation from
* the values there for use in '&' as they use `test_bit'
*/
RPC_TASK_RUNNING = 1
RPC_TASK_QUEUED = 2
RPC_TASK_ACTIVE = 4
retvalue = ""
if (word & RPC_TASK_RUNNING)
_task_tk_runstate["RPC_TASK_RUNNING"] = 1
if (word & RPC_TASK_QUEUED)
_task_tk_runstate["RPC_TASK_QUEUED"] = 1
if (word & RPC_TASK_ACTIVE)
_task_tk_runstate["RPC_TASK_ACTIVE"] = 1
foreach (key in _task_tk_runstate) {
sep = retvalue == "" ? "" : "|"
retvalue = sprintf("%s%s%s", retvalue, sep, key)
}
delete _task_tk_runstate
retvalue = retvalue == "" ? "0" : retvalue
return sprintf("tk_runstate: %s", retvalue)
}
function task2str:string (task:long)
{
tk_runstate = @cast(task, "struct rpc_task", "kernel<linux/sunrpc/sched.h>")->tk_runstate
tk_status = @cast(task, "struct rpc_task", "kernel<linux/sunrpc/sched.h>")->tk_status
return sprintf("tk_status: %s, %s", err_num2str(tk_status), task_runstate_num2str(tk_runstate))
}
probe module("sunrpc").function("__rpc_execute").call {
if (pid() == target()) {
t = task_current()
p = probefunc()
/* pull the server name */
serv = @cast($task->tk_client, "struct rpc_clnt")->cl_server
serv_name = kernel_string(serv)
proc = @cast(&$task->tk_msg, "struct rpc_message")->rpc_proc
func = @cast(proc, "struct rpc_procinfo")->p_name
func_name = kernel_string(func)
printf("%d [0x%x] %s -> %s: func: %s, server: %s, task: %s, parms: %s\n", gettimeofday_ns(), t, thread_indent(1), p, func_name, serv_name, task2str($task), $$parms)
trace[t] = 1
task_trace[$task] = 1
}
}
probe module("sunrpc").function("__rpc_execute").return {
t = task_current()
p = probefunc()
if (trace[t]) {
printf("%d [0x%x] %s <- %s: %s\n", gettimeofday_ns(), t, thread_indent(-1), p, $$return)
trace[t] = 0
delete task_trace
}
}
probe module("sunrpc").function("call_*").call {
t = task_current()
p = probefunc()
if (trace[t]) {
printf("%d [0x%x] %s -> %s: task: %s, parms: %s\n", gettimeofday_ns(), t, thread_indent(1), p, task2str($task), $$parms)
}
}
probe module("sunrpc").function("call_*").return {
t = task_current()
if (trace[t]) {
printf("%d [0x%x] %s <- %s: %s\n", gettimeofday_ns(), t, thread_indent(-1), probefunc(), $$return)
}
}
probe module("sunrpc").function("xs_tcp_send_request").call {
t = task_current()
p = probefunc()
if (trace[t]) {
rq_xprt = @cast($task->tk_rqstp, "struct rpc_rqst")->rq_xprt
sock = @cast(rq_xprt - (& @cast(0, "struct sock_xprt")->xprt), "struct sock_xprt")->sock
sk = @cast(sock, "struct socket")->sk
printf("%d [0x%x] %s -> %s: sock: %s, task: %s, parms: %s\n", gettimeofday_ns(), t, thread_indent(1), p, sock2str(sock), task2str($task), $$parms)
sk_trace[sk] = 1
}
}
probe module("sunrpc").function("xs_tcp_send_request").return {
t = task_current()
if (trace[t]) {
printf("%d [0x%x] %s <- %s: %s\n", gettimeofday_ns(), t, thread_indent(-1), probefunc(), err_num2str($return))
}
}
probe module("sunrpc").function("xs_connect").call {
t = task_current()
if (trace[t]) {
rq_xprt = @cast($task->tk_rqstp, "struct rpc_rqst")->rq_xprt
sock = @cast(rq_xprt - (& @cast(0, "struct sock_xprt")->xprt), "struct sock_xprt")->sock
printf("%d [0x%x] %s -> %s: sock: %s, task: %s, parms: %s\n", gettimeofday_ns(), t, thread_indent(1), probefunc(), sock2str(sock), task2str($task), $$parms)
}
}
probe module("sunrpc").function("xs_connect").return {
t = task_current()
if (trace[t]) {
printf("%d [0x%x] %s <- %s\n", gettimeofday_ns(), t, thread_indent(-1), probefunc())
}
}
probe module("sunrpc").function("rpc_wait_bit_killable").call {
t = task_current()
if (trace[t]) {
printf("%d [0x%x] %s -> %s: parms: %s\n", gettimeofday_ns(), t, thread_indent(1), probefunc(), $$parms)
}
}
probe module("sunrpc").function("rpc_wait_bit_killable").return {
t = task_current()
if (trace[t]) {
printf("%d [0x%x] %s <- %s\n", gettimeofday_ns(), t, thread_indent(-1), probefunc())
}
}
probe kernel.function("sk_stream_wait_connect").call {
t = task_current()
p = probefunc()
if (trace[t]) {
printf("%d [0x%x] %s -> %s: sk: %s, time_out: %d, parms: %s\n", gettimeofday_ns(), t, thread_indent(1), p, sk2str($sk), kernel_long($timeo_p), $$parms)
}
}
probe kernel.function("sk_stream_wait_connect").return {
t = task_current()
if (trace[t]) {
printf("%d [0x%x] %s <- %s: %s\n", gettimeofday_ns(), t, thread_indent(-1), probefunc(), err_num2str($return))
}
}
probe kernel.function("out_of_line_wait_on_bit").call {
t = task_current()
if (trace[t]) {
printf("%d [0x%x] %s -> %s: word: %s, parms: %s\n", gettimeofday_ns(), t, thread_indent(1), probefunc(), task_runstate_num2str(kernel_long($word)), $$parms)
}
}
probe kernel.function("out_of_line_wait_on_bit").return {
t = task_current()
if (trace[t]) {
printf("%d [0x%x] %s <- %s\n", gettimeofday_ns(), t, thread_indent(-1), probefunc())
}
}
probe module("sunrpc").function("rpc_make_runnable").call {
t = task_current()
if (task_trace[$task]) {
printf("%d [0x%x] %s -> %s: task: %s, parms: %s\n", gettimeofday_ns(), t, execname(), probefunc(), task2str($task), $$parms)
print_backtrace()
}
}
probe kernel.function("tcp_set_state").call {
if (sk_trace[$sk]) {
t = task_current()
printf("%d [0x%x] %s -> %s: sk: %s, NEW sk_state: %s\n",
gettimeofday_ns(), t, execname(), probefunc(), sk2str($sk), sk_state_num2str($state))
print_backtrace()
}
}
global trace
global _tcp_state[13]
global _sock_state[5]
global _errno[134]
global _sock_sk_shutdown[2]
probe begin {
/* from include/net/tcp_states.h */
_tcp_state[0] = "UNDEF"
_tcp_state[1] = "TCP_ESTABLISHED"
_tcp_state[2] = "TCP_SYN_SENT"
_tcp_state[3] = "TCP_SYN_RECV"
_tcp_state[4] = "TCP_FIN_WAIT1"
_tcp_state[5] = "TCP_FIN_WAIT2"
_tcp_state[6] = "TCP_TIME_WAIT"
_tcp_state[7] = "TCP_CLOSE"
_tcp_state[8] = "TCP_CLOSE_WAIT"
_tcp_state[9] = "TCP_LAST_ACK"
_tcp_state[10] = "TCP_LISTEN"
_tcp_state[11] = "TCP_CLOSING"
_tcp_state[12] = "TCP_MAX_STATES"
/* from include/linux/net.h */
_sock_state[0] = "SS_FREE"
_sock_state[1] = "SS_UNCONNECTED"
_sock_state[2] = "SS_CONNECTING"
_sock_state[3] = "SS_CONNECTED"
_sock_state[4] = "SS_DISCONNECTING"
_errno[0] = "0"
_errno[1] = "EPERM"
_errno[2] = "ENOENT"
_errno[3] = "ESRCH"
_errno[4] = "EINTR"
_errno[5] = "EIO"
_errno[6] = "ENXIO"
_errno[7] = "E2BIG"
_errno[8] = "ENOEXEC"
_errno[9] = "EBADF"
_errno[10] = "ECHILD"
_errno[11] = "EAGAIN"
_errno[12] = "ENOMEM"
_errno[13] = "EACCES"
_errno[14] = "EFAULT"
_errno[15] = "ENOTBLK"
_errno[16] = "EBUSY"
_errno[17] = "EEXIST"
_errno[18] = "EXDEV"
_errno[19] = "ENODEV"
_errno[20] = "ENOTDIR"
_errno[21] = "EISDIR"
_errno[22] = "EINVAL"
_errno[23] = "ENFILE"
_errno[24] = "EMFILE"
_errno[25] = "ENOTTY"
_errno[26] = "ETXTBSY"
_errno[27] = "EFBIG"
_errno[28] = "ENOSPC"
_errno[29] = "ESPIPE"
_errno[30] = "EROFS"
_errno[31] = "EMLINK"
_errno[32] = "EPIPE"
_errno[33] = "EDOM"
_errno[34] = "ERANGE"
_errno[35] = "EDEADLK"
_errno[36] = "ENAMETOOLONG"
_errno[37] = "ENOLCK"
_errno[38] = "ENOSYS"
_errno[39] = "ENOTEMPTY"
_errno[40] = "ELOOP"
_errno[41] = "UNDEF"
_errno[42] = "ENOMSG"
_errno[43] = "EIDRM"
_errno[44] = "ECHRNG"
_errno[45] = "EL2NSYNC"
_errno[46] = "EL3HLT"
_errno[47] = "EL3RST"
_errno[48] = "ELNRNG"
_errno[49] = "EUNATCH"
_errno[50] = "ENOCSI"
_errno[51] = "EL2HLT"
_errno[52] = "EBADE"
_errno[53] = "EBADR"
_errno[54] = "EXFULL"
_errno[55] = "ENOANO"
_errno[56] = "EBADRQC"
_errno[57] = "EBADSLT"
_errno[58] = "UNDEF"
_errno[59] = "EBFONT"
_errno[60] = "ENOSTR"
_errno[61] = "ENODATA"
_errno[62] = "ETIME"
_errno[63] = "ENOSR"
_errno[64] = "ENONET"
_errno[65] = "ENOPKG"
_errno[66] = "EREMOTE"
_errno[67] = "ENOLINK"
_errno[68] = "EADV"
_errno[69] = "ESRMNT"
_errno[70] = "ECOMM"
_errno[71] = "EPROTO"
_errno[72] = "EMULTIHOP"
_errno[73] = "EDOTDOT"
_errno[74] = "EBADMSG"
_errno[75] = "EOVERFLOW"
_errno[76] = "ENOTUNIQ"
_errno[77] = "EBADFD"
_errno[78] = "EREMCHG"
_errno[79] = "ELIBACC"
_errno[80] = "ELIBBAD"
_errno[81] = "ELIBSCN"
_errno[82] = "ELIBMAX"
_errno[83] = "ELIBEXEC"
_errno[84] = "EILSEQ"
_errno[85] = "ERESTART"
_errno[86] = "ESTRPIPE"
_errno[87] = "EUSERS"
_errno[88] = "ENOTSOCK"
_errno[89] = "EDESTADDRREQ"
_errno[90] = "EMSGSIZE"
_errno[91] = "EPROTOTYPE"
_errno[92] = "ENOPROTOOPT"
_errno[93] = "EPROTONOSUPPORT"
_errno[94] = "ESOCKTNOSUPPORT"
_errno[95] = "EOPNOTSUPP"
_errno[96] = "EPFNOSUPPORT"
_errno[97] = "EAFNOSUPPORT"
_errno[98] = "EADDRINUSE"
_errno[99] = "EADDRNOTAVAIL"
_errno[100] = "ENETDOWN"
_errno[101] = "ENETUNREACH"
_errno[102] = "ENETRESET"
_errno[103] = "ECONNABORTED"
_errno[104] = "ECONNRESET"
_errno[105] = "ENOBUFS"
_errno[106] = "EISCONN"
_errno[107] = "ENOTCONN"
_errno[108] = "ESHUTDOWN"
_errno[109] = "ETOOMANYREFS"
_errno[110] = "ETIMEDOUT"
_errno[111] = "ECONNREFUSED"
_errno[112] = "EHOSTDOWN"
_errno[113] = "EHOSTUNREACH"
_errno[114] = "EALREADY"
_errno[115] = "EINPROGRESS"
_errno[116] = "ESTALE"
_errno[117] = "EUCLEAN"
_errno[118] = "ENOTNAM"
_errno[119] = "ENAVAIL"
_errno[120] = "EISNAM"
_errno[121] = "EREMOTEIO"
_errno[122] = "EDQUOT"
_errno[123] = "ENOMEDIUM"
_errno[124] = "EMEDIUMTYPE"
_errno[125] = "ECANCELED"
_errno[126] = "ENOKEY"
_errno[127] = "EKEYEXPIRED"
_errno[128] = "EKEYREVOKED"
_errno[129] = "EKEYREJECTED"
_errno[130] = "EOWNERDEAD"
_errno[131] = "ENOTRECOVERABLE"
_errno[132] = "ERFKILL"
_errno[133] = "EHWPOISON"
}
/**** Helpers ****/
function err_num2str:string (error:long) {
error = -error
return (error in _errno ? _errno[error] : sprintf("0x%x", -error))
}
function sk_state_num2str:string (state:long) {
return (state in _tcp_state ? _tcp_state[state] : sprintf("0x%x", state))
}
function sock_state_num2str:string (state:long)
{
return (state in _sock_state ? _sock_state[state] : sprintf("0x%x", state))
}
function sk_shutdown_num2str:string (flags:long)
{
/* from include/net/sock.h */
RCV_SHUTDOWN = 1
SEND_SHUTDOWN = 2
retvalue = ""
if (flags & SEND_SHUTDOWN)
_sock_sk_shutdown["SEND_SHUTDOWN"] = 1
if (flags & RCV_SHUTDOWN)
_sock_sk_shutdown["RCV_SHUTDOWN"] = 1
foreach (key in _sock_sk_shutdown) {
sep = retvalue == "" ? "" : "|"
retvalue = sprintf("%s%s%s", retvalue, sep, key)
}
delete _sock_sk_shutdown
return retvalue == "" ? "0" : retvalue
}
function sk2str:string (sk:long)
{
sk_state = sk_state_num2str(@cast(sk, "struct sock")->__sk_common->skc_state)
sk_shutdown = sk_shutdown_num2str(@cast(sk, "struct sock")->sk_shutdown)
sk_err = err_num2str(-(@cast(sk, "struct sock")->sk_err))
return sprintf("sk=0x%x, sk_state: %s, sk_err: %s, sk_shutdown: %s", sk, sk_state, sk_err, sk_shutdown)
}
function sock2str:string (sock:long)
{
sock_state = @cast(sock, "struct socket")->state
sock_sk = @cast(sock, "struct socket")->sk
return sprintf("sock=0x%x, state: %s, %s", sock, sock_state_num2str(sock_state), sk2str(sock_sk))
}
/**** Actual Probes Below ****/
probe module("sunrpc").function("xs_tcp_setup_socket").call {
if (isinstr(execname(), "rpciod")) {
t = task_current()
trace[t] = 1
printf("%d [0x%x]: %s -> %s: parms: %s\n", gettimeofday_ns(), t, thread_indent(1), probefunc(), $$parms)
}
}
probe module("sunrpc").function("xs_tcp_setup_socket").return {
t = task_current()
if (trace[t]) {
printf("%d [0x%x]: %s <- %s: %s\n", gettimeofday_ns(), t, thread_indent(-1), probefunc(), $$return)
}
trace[t] = 0
}
probe kernel.function("kernel_connect").call {
t = task_current()
if (trace[t]) {
printf("%d [0x%x]: %s -> %s: sock: %s, parms: %s\n", gettimeofday_ns(), t, thread_indent(1), probefunc(), sock2str($sock), $$parms)
}
}
probe kernel.function("kernel_connect").return {
t = task_current()
if (trace[t]) {
printf("%d [0x%x]: %s <- %s: %s\n", gettimeofday_ns(), t, thread_indent(-1), probefunc(), err_num2str($return))
}
}
probe module("sunrpc").function("*").call,
kernel.function("*@net/socket.c").call {
t = task_current()
if (trace[t]) {
printf("%d [0x%x]: %s -> %s: parms: %s\n", gettimeofday_ns(), t, thread_indent(1), probefunc(), $$parms)
}
}
probe module("sunrpc").function("*").return,
kernel.function("*@net/socket.c").return {
t = task_current()
if (trace[t]) {
printf("%d [0x%x]: %s <- %s: %s\n", gettimeofday_ns(), t, thread_indent(-1), probefunc(), $$return)
}
}
