Monitor the response time of the NFS server using tshark and lua

The other day, I faced a task, how to determine how much time the NFS server spends on a request.
It turned out that it is not so easy to see. But the favorite hammer tool - wireshark came to the rescue. For wireshak, you can write your own extension on LUA.



The idea is simple: we take the NFS request and put it in a hashmap, and when we see the answer, we consider
time difference:
')

if msgtyp == 0 then packets[xid] = { timestamp = frameepochtime, source = tostring(ipsrc), destination = tostring(ipdst), op_code = nfs_op }; else local l = packets[xid] if l ~= nul then packets[xid] = nil local time_delta = frameepochtime - l.timestamp if time_delta > min_time_delta then print(frametime .. " " .. l.source .. " <=> " .. l.destination .. " " .. string.format("%.3f",time_delta) .. " " .. l.op_code) end end 

Full code is available here.

Runs just from the command line.

 $ tshark -q -X lua_script:nfs.lua -f "port 2049" 

Result:

 "Aug 27, 2014 16: 44: 43.000 CEST" aaaa: bbbb: ccc: 10a0 :: 1: 7f <=> aaaa: bbbb: ccc: 10bf :: 1: 8c 0.001 v4_EXCHANGE_ID
 "Aug 27, 2014 16: 44: 43.000 CEST" aaaa: bbbb: ccc: 10a0 :: 1: 7f <=> aaaa: bbbb: ccc: 10bf :: 1: 8c 0.001 v4_CREATE_SESSION
 "Aug 27, 2014 16: 44: 43.000 CEST" aaaa: bbbb: ccc: 10a0 :: 1: 7f <=> aaaa: bbbb: ccc: 10bf :: 1: 8c 0.001 v4_PUTROOTFH
 "Aug 27, 2014 16: 44: 43.000 CEST" aaaa: bbbb: ccc: 10a0 :: 1: 7f <=> aaaa: bbbb: ccc: 10bf :: 1: 8c 0.002 v4_RECLAIM_COMPLETE
 "Aug 27, 2014 16: 44: 43.000 CEST" aaaa: bbbb: ccc: 10a0 :: 1: 7f <=> aaaa: bbbb: ccc: 10bf :: 1: 8c 0.001 v4_PUTROOTFH
 "Aug 27, 2014 16: 44: 43.000 CEST" aaaa: bbbb: ccc: 10a0 :: 1: 7f <=> aaaa: bbbb: ccc: 10bf :: 1: 8c 0.001 v4_DESTROY_SESSION
 "Aug 27, 2014 16: 44: 43.000 CEST" ab161.127 <=> ab191.140 0.001 v4_EXCHANGE_ID
 "Aug 27, 2014 16: 44: 43.000 CEST" ab161.127 <=> ab191.140 0.001 v4_CREATE_SESSION
 "Aug 27, 2014 16: 44: 43.000 CEST" ab161.127 <=> ab191.140 0.003 v4_PUTROOTFH
 "Aug 27, 2014 16: 44: 43.000 CEST" ab161.127 <=> ab191.140 0.002 v4_RECLAIM_COMPLETE
 "Aug 27, 2014 16: 44: 43.000 CEST" ab161.127 <=> ab191.140 0.004 v4_PUTROOTFH

Maybe someone has similar practices? Share!

Lua Support in Wireshark
Wireshark LUA wiki