Trying to investigate & debug the keepalive series I decided we
needed a better way to trace the RPC protocol than the regular
debug messages. Ideally we'd have a wireshark dissector but that
seems like it will be an awful lot of work todo. So instead I
have added a few systemtap probes to the RPC call which fire
everytime an RPC message is queued for dispatch, or a completed
RPC message is read off the wire
Now I can see all communications using a script like this
# cat > watch.stp <<EOF
function msginfo(prefix, prog, version, proc, type, status, serial)
{
if (type == 0)
typestr = "call"
else if (type == 1)
typestr = "reply"
else if (type == 2)
typestr = "message"
else if (type == 3)
typestr = "stream"
else
typestr = "unknown"
if (status == 0)
statusstr = "ok"
else if (status == 1)
statusstr = "error"
else if (status == 2)
statusstr = "continue"
else
statusstr = "unknown"
printf("%s program: %-10d version: %d procedure: %-4d type: %u:%-9s status: %u:%-9s serial: %-4d\n",
prefix, prog, version, proc, type, typestr, status, statusstr, serial);
}
probe libvirt.rpc.server_msg_rx {
msginfo(">S", prog, vers, proc, type, status, serial)
}
probe libvirt.rpc.server_msg_tx {
msginfo("<S", prog, vers, proc, type, status, serial)
}
probe libvirt.rpc.client_msg_rx {
msginfo("<C", prog, vers, proc, type, status, serial)
}
probe libvirt.rpc.client_msg_tx {
msginfo(">C", prog, vers, proc, type, status, serial)
}
EOF
# stap watch.stp
>C program: 536903814 version: 1 procedure: 66 type: 0:call status: 0:ok serial: 0
>S program: 536903814 version: 1 procedure: 66 type: 0:call status: 0:ok serial: 0
<S program: 536903814 version: 1 procedure: 66 type: 1:reply status: 0:ok serial: 0
<C program: 536903814 version: 1 procedure: 66 type: 1:reply status: 0:ok serial: 0
>C program: 536903814 version: 1 procedure: 1 type: 0:call status: 0:ok serial: 1
>S program: 536903814 version: 1 procedure: 1 type: 0:call status: 0:ok serial: 1
<S program: 536903814 version: 1 procedure: 1 type: 1:reply status: 0:ok serial: 1
<C program: 536903814 version: 1 procedure: 1 type: 1:reply status: 0:ok serial: 1
>C program: 536903814 version: 1 procedure: 110 type: 0:call status: 0:ok serial: 2
>S program: 536903814 version: 1 procedure: 110 type: 0:call status: 0:ok serial: 2
<S program: 536903814 version: 1 procedure: 110 type: 1:reply status: 0:ok serial: 2
<C program: 536903814 version: 1 procedure: 110 type: 1:reply status: 0:ok serial: 2
>C program: 536903814 version: 1 procedure: 23 type: 0:call status: 0:ok serial: 3
>S program: 536903814 version: 1 procedure: 23 type: 0:call status: 0:ok serial: 3
<S program: 536903814 version: 1 procedure: 23 type: 1:reply status: 0:ok serial: 3
<C program: 536903814 version: 1 procedure: 23 type: 1:reply status: 0:ok serial: 3
>C program: 536903814 version: 1 procedure: 19 type: 0:call status: 0:ok serial: 4
>S program: 536903814 version: 1 procedure: 19 type: 0:call status: 0:ok serial: 4
<S program: 536903814 version: 1 procedure: 19 type: 1:reply status: 0:ok serial: 4
<C program: 536903814 version: 1 procedure: 19 type: 1:reply status: 0:ok serial: 4
>C program: 536903814 version: 1 procedure: 16 type: 0:call status: 0:ok serial: 5
>S program: 536903814 version: 1 procedure: 16 type: 0:call status: 0:ok serial: 5
<S program: 536903814 version: 1 procedure: 16 type: 1:reply status: 0:ok serial: 5
<C program: 536903814 version: 1 procedure: 16 type: 1:reply status: 0:ok serial: 5
>C program: 536903814 version: 1 procedure: 151 type: 0:call status: 0:ok serial: 6
>S program: 536903814 version: 1 procedure: 151 type: 0:call status: 0:ok serial: 6
<S program: 536903814 version: 1 procedure: 151 type: 1:reply status: 0:ok serial: 6
<C program: 536903814 version: 1 procedure: 151 type: 1:reply status: 0:ok serial: 6
>C program: 536903814 version: 1 procedure: 15 type: 0:call status: 0:ok serial: 7
>S program: 536903814 version: 1 procedure: 15 type: 0:call status: 0:ok serial: 7
<S program: 536903814 version: 1 procedure: 15 type: 1:reply status: 0:ok serial: 7
<C program: 536903814 version: 1 procedure: 15 type: 1:reply status: 0:ok serial: 7
>C program: 536903814 version: 1 procedure: 183 type: 0:call status: 0:ok serial: 8
>S program: 536903814 version: 1 procedure: 183 type: 0:call status: 0:ok serial: 8
<S program: 536903814 version: 1 procedure: 183 type: 1:reply status: 0:ok serial: 8
<C program: 536903814 version: 1 procedure: 183 type: 1:reply status: 0:ok serial: 8
>C program: 536903814 version: 1 procedure: 122 type: 0:call status: 0:ok serial: 9
>S program: 536903814 version: 1 procedure: 122 type: 0:call status: 0:ok serial: 9
<S program: 536903814 version: 1 procedure: 122 type: 1:reply status: 0:ok serial: 9
<C program: 536903814 version: 1 procedure: 122 type: 1:reply status: 0:ok serial: 9
>C program: 536903814 version: 1 procedure: 121 type: 0:call status: 0:ok serial: 10
>S program: 536903814 version: 1 procedure: 121 type: 0:call status: 0:ok serial: 10
<S program: 536903814 version: 1 procedure: 121 type: 1:reply status: 0:ok serial: 10
<C program: 536903814 version: 1 procedure: 121 type: 1:reply status: 0:ok serial: 10
>C program: 536903814 version: 1 procedure: 2 type: 0:call status: 0:ok serial: 11
>S program: 536903814 version: 1 procedure: 2 type: 0:call status: 0:ok serial: 11
<S program: 536903814 version: 1 procedure: 2 type: 1:reply status: 0:ok serial: 11
<C program: 536903814 version: 1 procedure: 2 type: 1:reply status: 0:ok serial: 11
Is the trace information resulting from 'virsh dominfo $VM'
An RPC call shoudl result in 4 messages, tx by client, rx
by server, tx by server and rx by client. An async event
will only result in 2 messages, tx by server, rx by client
and so on.
A further enhancement I want to make is to make the rpc
generator script, spit out a systemtap function for
converting procedure numbers into function/event names,
as well as adding helper functions for converting program
type and status numbers into friendly strings
--
libvir-list mailing list
libvir-list@xxxxxxxxxx
https://www.redhat.com/mailman/listinfo/libvir-list