Wireshark-dev: Re: [Wireshark-dev] RFC: sorted value_string + bsearch

From: Jakub Zawadzki <darkjames@xxxxxxxxxxxxxxxx>
Date: Tue, 27 Apr 2010 09:47:38 +0200
On Tue, Apr 27, 2010 at 08:49:23AM +0200, Jakub Zawadzki wrote:
> On Tue, Apr 27, 2010 at 08:15:35AM +0200, Anders Broman wrote:
> > Can you provide an example use of the new value_string_ext as well?
> 
> Can you do some benchmarks? :)

mine, only dns packets: 
  Number of packets:   504
  Average packet size: 139.48 bytes

With patch (10 tests):
 Dissecting 504 packets [dissector 518 times called] took: 170,739 (avg: 0,329612 ms)
 Dissecting 504 packets [dissector 518 times called] took: 170,801 (avg: 0,329732 ms)
 Dissecting 504 packets [dissector 518 times called] took: 171,339 (avg: 0,33077 ms)
 Dissecting 504 packets [dissector 518 times called] took: 168,666 (avg: 0,32561 ms)
 Dissecting 504 packets [dissector 518 times called] took: 172,598 (avg: 0,333201 ms)
 Dissecting 504 packets [dissector 518 times called] took: 170,86 (avg: 0,329846 ms)
 Dissecting 504 packets [dissector 518 times called] took: 168,016 (avg: 0,324355 ms)
 Dissecting 504 packets [dissector 518 times called] took: 172,864 (avg: 0,333714 ms)
 Dissecting 504 packets [dissector 518 times called] took: 171,585 (avg: 0,331245 ms)
 Dissecting 504 packets [dissector 518 times called] took: 167,077 (avg: 0,322542 ms)
===
sum 1704,55 ms (avg pp: 0,329063 ms)

Without patch (10 tests):
 Dissecting 504 packets [dissector 518 times called] took: 171,819 (avg: 0,331697 ms)
 Dissecting 504 packets [dissector 518 times called] took: 169,629 (avg: 0,327469 ms)
 Dissecting 504 packets [dissector 518 times called] took: 172,228 (avg: 0,332486 ms)
 Dissecting 504 packets [dissector 518 times called] took: 170,728 (avg: 0,329591 ms)
 Dissecting 504 packets [dissector 518 times called] took: 170,775 (avg: 0,329681 ms)
 Dissecting 504 packets [dissector 518 times called] took: 172,792 (avg: 0,333575 ms)
 Dissecting 504 packets [dissector 518 times called] took: 171,081 (avg: 0,330272 ms)
 Dissecting 504 packets [dissector 518 times called] took: 173,242 (avg: 0,334444 ms)
 Dissecting 504 packets [dissector 518 times called] took: 171,269 (avg: 0,330635 ms)
 Dissecting 504 packets [dissector 518 times called] took: 170,413 (avg: 0,328982 ms)
=== 
sum 1713,98 ms (avg pp: 0,330885 ms)

Avg time spend in dissecting with patch is 170,4 +- 1%, within avg time without patch.
(my statistical english is really bad...)

Maybe function pointer to match_str* would be better instead of switch,
but still it doesn't seem to be worth (at least for dns)

Attaching profiling code.
diff --git a/epan/packet.c b/epan/packet.c
index ef7de29..22cf2c0 100644
--- a/epan/packet.c
+++ b/epan/packet.c
@@ -294,6 +294,7 @@ final_registration_all_protocols(void)
 			&call_final_registration_routine, NULL);
 }
 
+#define ENABLE_PROFILE
 
 /* Creates the top-most tvbuff and calls dissect_frame() */
 void
@@ -325,6 +326,10 @@ dissect_packet(epan_dissect_t *edt, union wtap_pseudo_header *pseudo_header,
 	EP_CHECK_CANARY(("before dissecting frame %d",fd->num));
 
 	TRY {
+#ifdef ENABLE_PROFILE
+		GTimer *timer = g_timer_new();
+		gdouble elapsed;
+#endif
 		edt->tvb = tvb_new_real_data(pd, fd->cap_len, fd->pkt_len);
 		/* Add this tvbuffer into the data_src list */
 		packet_add_new_data_source(&edt->pi, edt->tree, edt->tvb, "Frame");
@@ -335,7 +340,11 @@ dissect_packet(epan_dissect_t *edt, union wtap_pseudo_header *pseudo_header,
 		 * in this function. */
 		if(frame_handle != NULL)
 		  call_dissector(frame_handle, edt->tvb, &edt->pi, edt->tree);
-
+#ifdef ENABLE_PROFILE
+		elapsed = g_timer_elapsed(timer, NULL) * 1000.0;
+		g_print("%u: %g ms\n", fd->num, elapsed);
+		g_timer_destroy(timer);
+#endif
 	}
 	CATCH(BoundsError) {
 		g_assert_not_reached();