Tuesday, December 24, 2013

How to debug Sun RPC

I bet you used to debug web services via some sniffer like wireshark. This is possible because of protocol simplicity (yes, event if it is SOAP with attachments it is still simple text xml based protocol).
Sun RPC is rather popular IPC mechanism on Linux, it reminds Java Sun RMI by its nature. Sun RPC is complex, binary and uses multiple connections. In brief there is an rpcbind daemon (or portmapper in other words) that is a registry of services, client asks rpcbind about port of specific service and then connects directly to service. For instance, NFS is build around Sun RPC, nfs-server uses 2049 port by default but it can be registered on any other port and clients still can find it by registry (nfs-utils prior to 1.2 has hardcoded 2049 port though).

So how to deal with this if you hit some trouble? There is an rpcdebug util
The rpcdebug command allows an administrator to set and clear the Linux kernel's NFS client and server debug flags. Setting these flags causes the kernel to emit messages to the system log in response to NFS activity; this is typically useful when debugging NFS problems.
rpcdebug -vh
usage: rpcdebug [-v] [-h] [-m module] [-s flags...|-c flags...]
       set or cancel debug flags.

Module     Valid flags
rpc        xprt call debug nfs auth bind sched trans svcsock svcdsp misc cache all
nfs        vfs dircache lookupcache pagecache proc xdr file root callback client mount all
nfsd       sock fh export svc proc fileop auth repcache xdr lockd all
nlm        svc client clntlock svclock monitor clntsubs svcsubs hostcache xdr all

rpcdebug -m rpc -s all
rpc        xprt call debug nfs auth bind sched trans svcsock svcdsp misc cache
See /var/log/syslog
...
Jan  6 13:40:58 HDC05 kernel: [1430624.387439] RPC:       set up transport to address addr=10.1.2.11 port=48355 proto=udp
Jan  6 13:40:58 HDC05 kernel: [1430624.387533] RPC:       created transport ffff88000eb2c000 with 16 slots
Jan  6 13:40:58 HDC05 kernel: [1430624.387588] RPC:       creating mount client for db01 (xprt ffff88000eb2c000)
Jan  6 13:40:58 HDC05 kernel: [1430624.387672] RPC:       creating UNIX authenticator for client ffff88002f863200
Jan  6 13:40:58 HDC05 kernel: [1430624.389041] RPC:     0 holding NULL cred ffffffffa0118da0
Jan  6 13:40:58 HDC05 kernel: [1430624.389091] RPC:       new task initialized, procpid 21435
Jan  6 13:40:58 HDC05 kernel: [1430624.389142] RPC:       allocated task ffff88002b3fe1c0
Jan  6 13:40:58 HDC05 kernel: [1430624.389192] RPC:   850 __rpc_execute flags=0x280
Jan  6 13:40:58 HDC05 kernel: [1430624.389240] RPC:   850 call_start mount3 proc NULL (sync)
Jan  6 13:40:58 HDC05 kernel: [1430624.389290] RPC:   850 call_reserve (status 0)
...

No comments:

Post a Comment