Created attachment 9786 [details]
IO Graph screenshot of the SMB2 example
Build Information:
Version 1.9.0 (SVN Rev Unknown from unknown)
Copyright 1998-2013 Gerald Combs <[email protected]> and contributors.
This is free software; see the source for copying conditions. There is NO
warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.
Compiled (32-bit) with GTK+ 2.24.14, with Cairo 1.10.2, with Pango 1.30.1, with
GLib 2.34.1, with WinPcap (4_1_2), with libz 1.2.5, without POSIX capabilities,
without libnl, with SMI 0.4.8, with c-ares 1.7.1, with Lua 5.1, without Python,
with GnuTLS 2.12.18, with Gcrypt 1.4.6, with MIT Kerberos, with GeoIP, with
PortAudio V19-devel (built Jan 7 2013), with AirPcap.
Running on 64-bit Windows 7 Service Pack 1, build 7601, with WinPcap version
4.1.2 (packet.dll version 4.1.0.2001), based on libpcap version 1.0 branch
1_0_rel0b (20091008), GnuTLS 2.12.18, Gcrypt 1.4.6, without AirPcap.
Built using Microsoft Visual C++ 10.0 build 40219
==============================================================================
--
Multiple requests or replies in a single frame cause inaccuracy in tshark’s ‘-z
io,stat’ and Wireshark’s IO Graph statistics. This problem affects SMB2,
iSCSI, NFSv3 SMB, and any other dissector protocol that are “tapable” and allow
for multiple requests and responses in a single frame.
SMB2
For example, capture "fr1-2reqs.cap" (attached) has one frame which contains
one Create(5) and one GetInfo(16) request. When the following filter is
applied in Wireshark, it should return zero frames because a Create request
doesn’t have a ‘smb2.file_info.infolevel’ field:
smb2.cmd == 5 && smb2.file_info.infolevel
GetInfo requests do include that field so IO Graph and '-z io,stat' should
return 0 but instead return 2 as shown in the "IO-Graph-SMB2.png" attachment
and the following:
# tshark -n -q -r "fr1-2reqs.cap" -z io,stat,0,"COUNT(smb2.cmd)smb2.cmd == 5 &&
smb2.file_info.infolevel"
===================================================================
| IO Statistics |
| |
| Interval size: 0.000 secs (dur) |
| Col 1: COUNT(smb2.cmd)smb2.cmd == 5 && smb2.file_info.infolevel |
|-----------------------------------------------------------------|
| |1 | |
| Interval | COUNT | |
|------------------------| |
| 0.000 <> 0.000 | 2 | |
===================================================================
A view of the code reveals that the following steps were taken:
1. It counted the number of ‘smb.cmd’ target fields in the frame and found that
there were 2.
2. It called the (aptly named) routine “ANY_EQ” to test if any of the smb.cmd
fields in the frame matched the first filter, ‘smb2.cmd == 5’ (Create). It
found that the first request did match so there was no need to test the GetInfo
request because the filter criteria had been met.
3. It tested the 2nd filter, "smb2.file_info.infolevel" against the Create
request which failed and again against the GetInfo request which passed so it
also considered this filter to have passed.
4. Since both filters passed, it concluded the two smb.cmd fields in the frame
had met the filter criteria.
This bug affects the SUM and AVG functions as well. The attached capture
'fr1-2reqs-fr2-2resps.cap' there is a Create and a GetInfo response in frame 2.
The smb2.time (SRT) values are both 0.001025 (1ms). As can be seen, the second
SUM should have been 0.001025 but since the smb2.cmd==5 was true for one of the
two requests, it counted the SRT values of both:
# tshark -q -r "fr1-2reqs-fr2-2resps.cap" -z
io,stat,0,"SUM(smb2.time)smb2.time","SUM(smb2.time)smb2.time && smb2.cmd == 5"
===================================================
| IO Statistics |
| |
| Interval size: 0.001 secs (dur) |
| Col 1: SUM(smb2.time)smb2.time |
| 2: SUM(smb2.time)smb2.time && smb2.cmd == 5 |
|-------------------------------------------------|
| |1 |2 | |
| Interval | SUM | SUM | |
|--------------------------------------| |
| 0.000 <> 0.001 | 0.002050 | 0.002050 | |
===================================================
NFSv3
The same happens with NFSv3. I tested a capture which had a single frame with
1 LOOKUP, 1 READ, and 4 GETATTR responses. I set the target field to
‘nfs.procedure_v3’ and applied filter “(nfs.procedure_v3 == 3) && (frame.number
== 635)” where procedure 3 is a LOOKUP. Both tools returned a COUNT of 6
rather than 1.
iSCSI
I tested iSCSI capture ‘writes__16_in_frame_1811.pcapng’ that contained 16
Write requests in a single frame. I set the target field to
‘iscsi.initiatortasktag’ and applied the filter “(frame.number == 1811) &&
(iscsi.initiatortasktag == 0x419b89d0)”. Both tools returned a COUNT of 16
rather than 1.
SMB
I tested capture 'SMB\fr-30986-has-5-SFI-and 1-QFI.cap’ (available upon
request) which has 6 calls in frame 30986, 5 Set_File_Infos and 1
Query_File_Info. The tools show that there are 6 smb.cmd fields in that frame
but when the QFI was filtered for (‘frame.number==30986 and smb.trans2.cmd ==
0x0007’) it returned a count of 6 rather than 1.
===============================================================================
The tap system must corrected to apply the entire filter string to *each*
request or response in the frame in the same manner as it does when there is
only one request or response in the frame.
===============================================================================
This bug can and has caused major inaccuracy in the io,stat and IO Graph
statistics upon which our organization heavily relies.