Wireshark-bugs: [Wireshark-bugs] [Bug 8720] New: tshark -qz io, stat output inconsistent

Date: Sun, 26 May 2013 21:39:55 +0000
Bug ID 8720
Summary tshark -qz io,stat output inconsistent
Classification Unclassified
Product Wireshark
Version 1.10.0
Hardware x86
OS Windows 7
Status UNCONFIRMED
Severity Minor
Priority Low
Component TShark
Assignee [email protected]
Reporter [email protected]

Created attachment 10843 [details]
Example of trace for which -qz io,stat works as predicted

Build Information:
1.10.0rc2
Windows 7 64 bit
--
I'm skeptical that tshark reliably calculates tcp.time_delta using the -qz
io,stat parameters.

HTTP-GOOD.PCAPNG
In this trace, I capture close to the Client (140.107.9.116), downloading a
file via HTTP from a Server (140.107.74.123) located across a WAN pipe.

Example #1
Here, I ask tshark to sum all the DeltaTs in the trace -- this should equal the
total duration of the trace.

tshark -r http-good.pcapng -o tcp.calculate_timestamps:TRUE -qz
io,stat,0,SUM(tcp.time_delta)tcp.time_delta

===============================================
| IO Statistics                               |
|                                             |
| Interval size: 0.200 secs (dur)             |
| Col 1: Frames and bytes                     |
|     2: SUM(tcp.time_delta)tcp.time_delta    |
|---------------------------------------------|
|                |1                |2         |
| Interval       | Frames |  Bytes |    SUM   |
|---------------------------------------------|
| 0.000 <> 0.200 |    483 | 462710 | 0.200125 |
===============================================

On the surface, this looks plausible:  'Interval size' (duration) = .200s, and
the SUM of all DeltaTs = .200125s
The Wireshark GUI confirms that the trace lasts for .200s


Example #2
Here I ask tshark to sum all the DeltaTs for the Server, i.e. to calculate how
long the Server (+ Network) spent turning around frames:
tshark -r http-good.pcapng -o tcp.calculate_timestamps:TRUE -qz
"io,stat,0,SUM(tcp.time_delta)tcp.time_delta and tcp.srcport==80"

================================================================
| IO Statistics                                                |
|                                                              |
| Interval size: 0.200 secs (dur)                              |
| Col 1: Frames and bytes                                      |
|     2: SUM(tcp.time_delta)tcp.time_delta and tcp.srcport==80 |
|--------------------------------------------------------------|
|                |1                |2         |                |
| Interval       | Frames |  Bytes |    SUM   |                |
|---------------------------------------------|                |
| 0.000 <> 0.200 |    483 | 462710 | 0.193655 |                |
================================================================

Again, this looks plausible, and using Excel, I confirm this SUM.


Example #3
Finally, I ask tshark to sum all the DeltaTs for the Client.
tshark -r http-good.pcapng -o tcp.calculate_timestamps:TRUE -qz
"io,stat,0,SUM(tcp.time_delta)tcp.time_delta and tcp.dstport==80"

================================================================
| IO Statistics                                                |
|                                                              |
| Interval size: 0.200 secs (dur)                              |
| Col 1: Frames and bytes                                      |
|     2: SUM(tcp.time_delta)tcp.time_delta and tcp.dstport==80 |
|--------------------------------------------------------------|
|                |1                |2         |                |
| Interval       | Frames |  Bytes |    SUM   |                |
|---------------------------------------------|                |
| 0.000 <> 0.200 |    483 | 462710 | 0.006470 |                |
================================================================

The result looks plausable, and Excel confirms the calculation.

Also, .193655s + .006470s = .200125s, so the three Examples are
self-consistent.


HTTPD-BAD.PCAPNG
In the bad case, I have captured again close to the Client (140.107.203.6),
which is engaged in multiple conversations with the Server (209.124.184.143).


Example #4
As before, I ask tshark to sum all the DeltaTs in the trace.

tshark -r http-bad.pcapng -o tcp.calculate_timestamps:TRUE -qz
io,stat,0,SUM(tcp.time_delta)tcp.time_delta


==============================================
| IO Statistics                              |
|                                            |
| Interval size: 11.1 secs (dur)             |
| Col 1: Frames and bytes                    |
|     2: SUM(tcp.time_delta)tcp.time_delta   |
|--------------------------------------------|
|              |1                |2          |
| Interval     | Frames |  Bytes |    SUM    |
|--------------------------------------------|
|  0.0 <> 11.1 |    473 | 349155 | 23.817352 |
==============================================

But this time, the result is not plausible:  the trace lasts 11.s, yet the sum
of all DeltaTs is more than twice that, at 23.817352s
The GUI confirms that the total trace time is ~11.1s, ditto with Excel.


Example #5
Here, I ask tshark to sum all the DeltaTs for frames emitted by the Client:

tshark -r http-bad.pcapng -o tcp.calculate_timestamps:TRUE -qz "i
o,stat,0,SUM(tcp.time_delta)tcp.time_delta and tcp.dstport==80"

================================================================
| IO Statistics                                                |
|                                                              |
| Interval size: 11.1 secs (dur)                               |
| Col 1: Frames and bytes                                      |
|     2: SUM(tcp.time_delta)tcp.time_delta and tcp.dstport==80 |
|--------------------------------------------------------------|
|              |1                |2          |                 |
| Interval     | Frames |  Bytes |    SUM    |                 |
|--------------------------------------------|                 |
|  0.0 <> 11.1 |    473 | 349155 | 22.416886 |                 |
================================================================

Again, the results are not plausible.


Example #6
Ditto for asking tshark to sum all the DeltaTs for frames emitted by the
Server.

tshark -r http-bad.pcapng -o tcp.calculate_timestamps:TRUE -qz
"io,stat,0,SUM(tcp.time_delta)tcp.time_delta and tcp.srcport==80"

================================================================
| IO Statistics                                                |
|                                                              |
| Interval size: 11.1 secs (dur)                               |
| Col 1: Frames and bytes                                      |
|     2: SUM(tcp.time_delta)tcp.time_delta and tcp.srcport==80 |
|--------------------------------------------------------------|
|              |1                |2         |                  |
| Interval     | Frames |  Bytes |    SUM   |                  |
|-------------------------------------------|                  |
|  0.0 <> 11.1 |    473 | 349155 | 1.400466 |                  |
================================================================

At least the Sums are internally consistent:
22.416886s + 1.400466s = 23.817352s

And the direction is consistent:  I know from other analysis that in this
example the Client contributes almost all of the trace time, so I am
unsurprised that the Client Time (1.400466s) is substantially less than the
Server Time (22.416886).  But since the total trace time is only ~11.1s, I am
skeptical of both Sums.


AVERAGE
Let's try the AVERAGE function:

httpd-good.pcapng
tshark -r http-good.pcapng -o tcp.calculate_timestamps:TRUE -qz
io,stat,0,AVG(tcp.time_delta)tcp.time_delta

===============================================
| IO Statistics                               |
|                                             |
| Interval size: 0.200 secs (dur)             |
| Col 1: Frames and bytes                     |
|     2: AVG(tcp.time_delta)tcp.time_delta    |
|---------------------------------------------|
|                |1                |2         |
| Interval       | Frames |  Bytes |    AVG   |
|---------------------------------------------|
| 0.000 <> 0.200 |    483 | 462710 | 0.000414 |
===============================================

The result is plausible ... and Excel concurs, telling me that the Average is
.000414


httpd-bad.pcapng
tshark -r http-bad.pcapng -o tcp.calculate_timestamps:TRUE -qz
io,stat,0,AVG(tcp.time_delta)tcp.time_delta

=============================================
| IO Statistics                             |
|                                           |
| Interval size: 11.1 secs (dur)            |
| Col 1: Frames and bytes                   |
|     2: AVG(tcp.time_delta)tcp.time_delta  |
|-------------------------------------------|
|              |1                |2         |
| Interval     | Frames |  Bytes |    AVG   |
|-------------------------------------------|
|  0.0 <> 11.1 |    473 | 349155 | 0.050354 |
=============================================

Again, this result is plausible ... but Excel disagrees; Excel calculates an
Average of .023518s

I will attach to this bug:

http-good.pcapng
http-good.csv
http-good.xlsx

http-bad.pcapng
http-bad.csv
httpd-bad.xlsx

--sk


You are receiving this mail because:
  • You are watching all bug changes.