[Ian Schorr <spamcontrol2@xxxxxxxxxxx>]

Actually, those numbers may be somewhat skewed because of paradoxical 
recursion that didn't quite resolve right in the output, and some other 
things.  I'm still fairly confident about the compare_proto_id and 
epan_dissect_run numbers, but let me look into the others a bit closer.

I also forgot to mention that I removed my preferences file before 
starting, so there were performed with "default" prefs...

Ian

Ian Schorr wrote:

> 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.
> > )