[Richard Sharpe <rsharpe@xxxxxxxxxxxxxxxxx>]

On Sat, 15 Nov 2003, Newbie 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.

Can you send us the output of gprof?

Also, what flags did you give to gcc to generate the profiling stuff?

I would like to add a target to the Makefile that will allow us to build a 
profile-ready program. However, it might be better to add it to configure.
 
> 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.
> >)
> >  
> >
> 
> _______________________________________________
> Ethereal-dev mailing list
> Ethereal-dev@xxxxxxxxxxxx
> http://www.ethereal.com/mailman/listinfo/ethereal-dev
> 

-- 
Regards
-----
Richard Sharpe, rsharpe[at]ns.aus.com, rsharpe[at]samba.org, 
sharpe[at]ethereal.com, http://www.richardsharpe.com