Ronnie,
I haven't done a "formal" test, per se, but I ran a couple of quick
tests out of curiosity and thought I'd share the results.
I used a file I had sitting around - a 124,568 packet trace containing
primarily CIFS traffic.
I ran two tests with profiling enabled: One where I simply opened the
file, then exited the program, and another where I opened the file, then
refiltered using "smb" as a display filter, then exited the program.
Both tests gave me nearly identical results as far as the most "costly"
procedures, so I'll concentrate just on the second test.
The function consuming the most time was epan/proto.c:compare_proto_id,
at 22.9%, 8.14s, and 777,148,074 calls (nearly more calls, I believe,
than to all other functions combined).
add_packet_to_packet_list actually came in at #5, with 7.6%, 2.64s -
including time spend in its child functions (epan_dissect_run, mostly
(5.1%/1.8s), which in turn spent the majority of its time in
dissect_packet (5.1%, 1.71s)).
compare_proto_id appeared to be a called by g_list_find_custom. It
accounted for an additional 5.9%/2.11s, for a total of 28.8% spent in
this particular function (when added to the time spent in its child
function, compare_proto_id)
proto_tree_add_pi appeared to be more "expensive" (10.0%, 2.82s) than
add_packet_to_packet_list, and proto_tree_add_uint (6.7%, 2.01s).
The test system is an Apple G5 running OS X 10.3, with GTK+ 1.2.10,
Ethereal 0.9.16 with no special GCC flags and "configure --without-plugins".
Let me know if you want me to do a more "formal" test, and upload the
trace to some shared area (perhaps Gerald wouldn't mind setting up an
area temporarily on ftp.ethereal.com, or do we already have something
like that?).
Ian
Ronnie Sahlberg wrote:
Good point.
I never noticed that the number of sessions affected the refilter speed.
The type of traffic (some reassembled PDUs take much longer than others to
dissect) I know would affect it but never knew the number of sessions
did.
The problem now is that fore VERY large captures, ethereal is always slow
under all circumstances.
So let us start with just a simple random generic capture and measure for it
to try to keep the number of variables low.
(If it is as you say the number of sessions affect it as well, do you mean
the number of TCP sessions or what kind of sessions?
At some point, when the worst performance problem has been addressed this
would be a very interesting area to look at.
(I could create different synthetic capture files to measure with, same
number of packets, same payload just different number of sessions)
Make a note that you have observed the number of sessions to possibly have
an effect on the dissection speed so we dont forget to look at
it furhter down the track
)
I currently belive that during refiltering of a capture, most time would be
spent inside file.c/add_packet_to_packet_list().
It would be VERY VERY useful to verify that this assumption is correct.
I would really like someone to look at gprof data and analyze where most
time is consumed to either verify my claim add_packet_to_packet_list()
or to invalidate it.
The thing inside this function I think consumes the most cpu I belive would
be where we call epan_dissect_run() and perform a full dissection of the
packet.
As I see it, apart from the initial time we encounter the packet during file
read (or live capture) there are not that many instances where we really
must
dissect the packet at all.
OK. If we select a packet in the list so it gets displayed in the dissect
pane that might be an exception but that is not something that we do 100.000
times
per capture anyway so the performance of that is irrelevant.
We might also need to do a full rescan/redissect of all packets IF we have
changed the preferences in such a way that the packets will be dissected
differently or when we have changed stuff using DecodeAs.
However, for me and many other users, the MAIN reason ethereal rescans the
packet list is because we have applied or changed a filter. Some users will
filter and refilter a capture file over and over and over, ten, twenty,
thirty if not more times for each capture they work with.
Or see when a ConversationList dislog or a ServiceResponseTime dialog is
opened.
Well enough of that. To my idea:
Hypothesis: A significant part of the slowness of ethereal when refiltering
a capture file comes from the expensive calls to epan_dissect_run() called
from add_packet_to_packet_list() in file.c
Potential fix: Reduce the number of calls made to epan_dissect_run() at the
expense of additional memory requirements (enabled by a preference)
Assuming that most of the time we perform a full rescan/redissect of the
capture file is when we really just want to reapply a display filter. (and
are not doing anything that affects how a packet is dissected).
What do we need in order to refilter the packet list if we do not allow
calling epan_dissect_run()?
1, We need to remember all COL values for all packets so that we can just
reapply them when adding the packet to the packetlist without calling the
dissector and recreating them that way. This will consume additional
memory.
2, For every packet we need to keep a list of all the hf_fields that were
encountered in the packet.
This list contains the index of the hf variable as well as the value it
has.
Nothing else needs to be stored there (in order to reduce the impact on
memory)
This list may NOT be pruned as the edt structs are. This is because we
want to be able to still use this list even after the filters have changed
and thus
the pruning would be different. No pruning.
The "ApplyFilterToEdtStructure" fucntions would need to be changed (or
duplicated) so they could operate on the list in 2 instead of the edt
structure.
This function might also need to be looked at so that it would be efficient
even for very large lists (no pruning)
1 would allow us to rebuild the packet list without needing to call the
dissector (?)
2 would allow us to refilter the entire trace without calling any
dissectors.
ideas, comments?
Right now it would be nice if someone could create a capture as I proposed
earlier and use GPROF to check where most of the CPU is spent when
refiltering the capture. To verify if my assumptions are correct or
invalidate them.
(
As a nice benefit in the future, IF we were to have that list of fields for
each packet, easily available, we could do things like merging this list
between packets.
Say #6 is the Call and #27 is the Response.
Since these packets are paired we could merge the lists from these two
packets into a single one.
Then when searcing for something that occured in the Response packet, we
would automatically also pick up the matching Call packet sinte their lists
were merged.
I.e filtering for smb.error==foo would both find the Response that barfed
saying foo but also teh matched Call to this Response.
That would also be useful.
)