[Freeciv-Dev] Re: Profile.

[Gaute B Strokkenes <gs234@xxxxxxxxx>]

On Fri, 28 Sep 2001, hawk@xxxxxxxxxxxxxxxxxxxxxxx wrote:
> On Fri, Sep 28, 2001 at 02:30:33AM +0200, Gaute B Strokkenes wrote:
>> On Wed, 26 Sep 2001, hawk@xxxxxxxxxxxxxxxxxxxxxxx wrote:
>> 
>> > diff -urd -x prof -X freeciv.current/diff_ignore
>> > work/common/map.c no_check/common/map.c --- work/common/map.c Wed
>> > Sep 26 14:21:08 2001
>> > +++ no_check/common/map.c  Wed Sep 26 18:31:26 2001
>> > @@ -1289,7 +1289,9 @@
>> >  
>> >  int is_real_tile(int x, int y)
>> >  {
>> > -  return 0 <= y && y < map.ysize;
>> > +  int x1 = x, y1 = y;
>> > +
>> > +  return normalize_map_pos(&x1, &y1);
>> >  }

<Scratches head> Why copy x and y into temporaries?  C is call by
value, you know.

>> I would do this the other way round; change the end of
>> normalize_map_pos() to read "return is_real_tile(*x, *y)" and leave
>> is_real_tile() as-is.
> 
> It is one extra function call. This simple change will give us 3-5%
> gain. normalize_map_pos is far more used than is_real_tile.

We can do much better than that.

I now have access to the department computers, so I can finally
profile things without having to be nice to other interactive users
and so on.  So I dug out my patch and profiled it thoroughly.

This is plain CVS from 2001-10-01:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total           
 time   seconds   seconds    calls  ms/call  ms/call  name    
 13.58     76.73    76.73 1785967216     0.00     0.00  normalize_map_pos
  8.01    121.98    45.25   128714     0.35     0.60  really_generate_warmap
  6.91    161.02    39.04 2121701942     0.00     0.00  is_real_tile
  3.22    179.19    18.17 201024486     0.00     0.00  map_get_city
  3.14    196.91    17.72 365062693     0.00     0.00  tech_exists
  2.49    211.00    14.09 257140003     0.00     0.00  map_get_terrain
  2.45    224.84    13.84 381046851     0.00     0.00  map_get_tile
  2.37    238.25    13.41 275235427     0.00     0.00  unit_type_flag
  1.86    248.77    10.52 142113446     0.00     0.00  base_city_map_to_map
  1.71    258.44     9.67 337813644     0.00     0.00  get_invention
  1.59    267.44     9.00 150750666     0.00     0.00  improvement_exists
  1.50    275.94     8.50  3789739     0.00     0.01  road_bonus
  1.32    283.41     7.47 232505521     0.00     0.00  is_valid_city_coords
  1.32    290.87     7.46 78481669     0.00     0.00  get_from_mapqueue
  1.12    297.21     6.34 103005915     0.00     0.00  map_get_continent
  1.10    303.42     6.21 102068073     0.00     0.00  map_get_special
  1.08    309.50     6.08  2410721     0.00     0.01  
player_knows_techs_with_flag
  1.06    315.47     5.97    34225     0.17     2.00  evaluate_improvements
  1.05    321.39     5.92 115789803     0.00     0.00  tech_flag
  1.03    327.20     5.81 143784523     0.00     0.00  genlist_iterator_init
...
  0.00    565.15     0.00        1     0.00     0.00  user_home_dir

CVS from 2001-10-01 with irt.diff applied:

Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total           
 time   seconds   seconds    calls  ms/call  ms/call  name    
 12.20     62.82    62.82 1785967216     0.00     0.00  normalize_map_pos
  9.16    109.98    47.16   128714     0.37     0.57  really_generate_warmap
  3.42    127.58    17.60 365062693     0.00     0.00  tech_exists
  3.18    143.95    16.37 201024486     0.00     0.00  map_get_city
  2.67    157.70    13.75 257140003     0.00     0.00  map_get_terrain
  2.67    171.43    13.73 275235427     0.00     0.00  unit_type_flag
  2.60    184.84    13.41 381046851     0.00     0.00  map_get_tile
  1.88    194.52     9.68 142113446     0.00     0.00  base_city_map_to_map
  1.81    203.85     9.33 337813644     0.00     0.00  get_invention
  1.79    213.05     9.20 150750666     0.00     0.00  improvement_exists
  1.75    222.05     9.00  3789739     0.00     0.00  road_bonus
  1.49    229.74     7.69 232505521     0.00     0.00  is_valid_city_coords
  1.38    236.86     7.12 78481669     0.00     0.00  get_from_mapqueue
  1.35    243.82     6.96  2410721     0.00     0.01  
player_knows_techs_with_flag
  1.30    250.51     6.69    34225     0.20     1.87  evaluate_improvements
  1.28    257.12     6.61 103005915     0.00     0.00  map_get_continent
  1.15    263.06     5.94 102068073     0.00     0.00  map_get_special
  1.15    268.96     5.90 109005167     0.00     0.00  city_got_building
  1.14    274.84     5.88     7853     0.75     4.10  ai_manage_explorer
  1.13    280.67     5.83  3357402     0.00     0.01  invasion_funct
...
  0.00    515.12     0.00        1     0.00     0.00  user_home_dir

This is CVS from 2001-10-01 with irt.diff, but with IN_RANGE() changed
to do the obvious thing:

Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total           
 time   seconds   seconds    calls  ms/call  ms/call  name    
 12.21     62.54    62.54 1785967216     0.00     0.00  normalize_map_pos
  8.95    108.39    45.85   128714     0.36     0.57  really_generate_warmap
  3.42    125.93    17.54 365062693     0.00     0.00  tech_exists
  3.18    142.20    16.27 201024486     0.00     0.00  map_get_city
  2.93    157.23    15.03 381046851     0.00     0.00  map_get_tile
  2.72    171.15    13.92 257140003     0.00     0.00  map_get_terrain
  2.66    184.75    13.60 275235427     0.00     0.00  unit_type_flag
  1.93    194.64     9.89 142113446     0.00     0.00  base_city_map_to_map
  1.82    203.97     9.33 337813644     0.00     0.00  get_invention
  1.73    212.85     8.88 150750666     0.00     0.00  improvement_exists
  1.67    221.41     8.56  3789739     0.00     0.00  road_bonus
  1.49    229.05     7.64 232505521     0.00     0.00  is_valid_city_coords
  1.41    236.28     7.23 78481669     0.00     0.00  get_from_mapqueue
  1.30    242.96     6.68 103005915     0.00     0.00  map_get_continent
  1.30    249.62     6.66    34225     0.19     1.85  evaluate_improvements
  1.22    255.87     6.25  2410721     0.00     0.01  
player_knows_techs_with_flag
  1.20    262.01     6.14  3357402     0.00     0.01  invasion_funct
  1.18    268.03     6.02 78322495     0.00     0.00  add_to_mapqueue
  1.17    274.02     5.99 102068073     0.00     0.00  map_get_special
  1.16    279.94     5.92 109005167     0.00     0.00  city_got_building
...
  0.00    512.15     0.00        1     0.00     0.00  user_home_dir

So the absolute gain is 565.15 - 512.15 = 53 seconds, which is 9.4% of
the total.  Not only have the 39.04 seconds billed to is_real_tile()
vanished, but we have also gained 14 seconds in other functions.  If
we look at the places which call is_real_tile(), such as
map_get_city() which went from 18.17 to 16.27 seconds, it is not hard
to see where those seconds came from: it is the function call overhead
of is_real_tile() that has vanished.

Another observation is that the speed gained by inlining
is_real_tile() in normaliz_map_pos() is only 76.73 - 62.54 = 14.19
seconds, or 2.5% of the total.

Additionally, the version without an IN_RANGE() macro is just slightly
faster than the one without.  I'm tempted to put this down to fuzz,
but in any case it is clear that IN_RANGE() does not provide any
measurable gains, so I see no point in using it.

In short, my approach works significantly faster than yours.  If you
agree, then I will produce an updated patch.

Anyone who wishes to have a look at these profiles will be able to
find them shortly at 

  http://www.srcf.ucam.org:~gs234/public_html/gmon.out.2001-10-01.bz2
  http://www.srcf.ucam.org:~gs234/public_html/gmon.out.2001-10-01-irt.bz2
  http://www.srcf.ucam.org:~gs234/public_html/gmon.out.2001-10-01-irt-alt.bz2

respectively.

-- 
Big Gaute                               http://www.srcf.ucam.org/~gs234/
NOW, I'm supposed to SCRAMBLE two, and HOLD th' MAYO!!