[Freeciv-Dev] (PR#11562) Freeciv Server Performance

["Mike Kaufman" <kaufman@xxxxxxxxxxxxxxxxxxxxxx>]

<URL: http://bugs.freeciv.org/Ticket/Display.html?id=11562 >

After a comment on this list mentioned how slow S2_0 was compared to
1.14.2, I decided to see if there was any data to back up the statement.
This is only the speed of the server, not the client.

To make a long story short: The new server is slow as molasses.

Method: since autogames are very different between versions, my metric was
to take a very large later stage game created by a 1.14.2 server and time 
several turns using each version. The AI will make different decisions, but
over a small timeframe, should not change the game too much to poison the
method.

I used games of 1, 2, and 5 turns.

script used to create the games:

set aifill 30
set space 0
set saveturns 2
set endyear 3000
set timeout -1
set xsize 100
set ysize 100
hard
create Caesar
start


Pentium4 2.53 GHz Linux 2.6 512MB Ram 1GB Swap  SCSI Ultra160 10000rpm
mostly idle processor (X, xmms running ;)

read script:

set endyear <year+n turns>
set saveturns 0
start

time ser -r readscript -f test+<date>.sav.gz

1 turn

year            1000            2001            2101
-----------------------------------------------------------
cvs-1.14.2      r 0m4.831s      r 0m5.975s      r 0m11.889s
 -g -O2         u 0m4.733s      u 0m5.784s      u 0m11.707s
 debug=some     s 0m0.064s      s 0m0.087s      s 0m0.110s

cvs-S2_0        r 0m9.185s      r 0m22.939s     r 0m40.391s
 -g -O2         u 0m8.934s      u 0m20.849s     u 0m39.802s
 debug=some     s 0m0.074s      s 0m0.159s      s 0m0.220s

cvs-HEAD        r 0m9.618s      r 0m21.419s     r 0m40.669s
 -g -O2         u 0m9.173s      u 0m21.178s     u 0m40.257s
 debug=some     s 0m0.097s      s 0m0.142s      s 0m0.214s

cvs-1.14.2      r 0m4.797s      r 0m5.605s      r 0m11.396s
 -g -O2         u 0m4.659s      u 0m5.471s      u 0m11.165s
 debug=no       s 0m0.076s      s 0m0.098s      s 0m0.113s

cvs-S2_0        r 0m7.512s      r 0m17.089s     r 0m31.791s
 -g -O2         u 0m7.355s      u 0m16.842s     u 0m31.363s
 debug=no       s 0m0.085s      s 0m0.149s      s 0m0.224s


2 turns

year            1000            2001            2101
-----------------------------------------------------------
cvs-1.14.2      r 0m4.896s      r 0m8.021s      r 0m21.454s
 -g -O2         u 0m4.756s      u 0m7.873s      u 0m21.169s
 debug=some     s 0m0.066s      s 0m0.087s      s 0m0.152s

cvs-S2_0        r 0m9.119s      r 0m28.778s     r 1m11.929s
 -g -O2         u 0m8.942s      u 0m28.308s     u 1m11.323s
 debug=some     s 0m0.100s      s 0m0.173s      s 0m0.328s

cvs-HEAD        r 0m9.385s      r 0m29.395s     r 1m11.264s
 -g -O2         u 0m9.198s      u 0m29.079s     u 1m10.463s
 debug=some     s 0m0.104s      s 0m0.182s      s 0m0.309s

cvs-1.14.2      r 0m4.790s      r 0m7.604s      r 0m15.690s
 -g -O2         u 0m4.674s      u 0m7.434s      u 0m15.443s
 debug=no       s 0m0.074s      s 0m0.105s      s 0m0.144s

cvs-S2_0        r 0m7.481s      r 0m23.515s     r 0m45.324s
 -g -O2         u 0m7.329s      u 0m23.169s     u 0m44.699s
 debug=no       s 0m0.093s      s 0m0.174s      s 0m0.261s



5 turns

year            1000            2001            2101
-----------------------------------------------------------
cvs-1.14.2      r 0m4.849s      r 0m13.631s     r 0m31.342s
 -g -O2         u 0m4.756s      u 0m13.407s     u 0m31.040s
 debug=some     s 0m0.046s      s 0m0.131s      s 0m0.187s

cvs-S2_0        r 0m9.129s      r 0m50.832s     r 1m46.354s
 -g -O2         u 0m8.965s      u 0m50.192s     u 1m45.355s
 debug=some     s 0m0.091s      s 0m0.308s      s 0m0.502s

cvs-HEAD        r 0m9.398s      r 0m52.146s     r 1m42.134s
 -g -O2         u 0m9.202s      u 0m51.614s     u 1m40.914s
 debug=some     s 0m0.118s      s 0m0.315s      s 0m0.509s

cvs-1.14.2      r 0m4.733s      r 0m12.676s     r 0m29.398s
 -g -O2         u 0m4.638s      u 0m12.444s     u 0m28.997s
 debug=no       s 0m0.067s      s 0m0.136s      s 0m0.192s

cvs-S2_0        r 0m7.470s      r 0m42.098s     r 1m29.443s
 -g -O2         u 0m7.307s      u 0m41.605s     u 1m28.576s
 debug=no       s 0m0.093s      s 0m0.265s      s 0m0.464s


Observations:

on the S2_0 and HEAD versions, there is an annoyingly long wait after game 
start but before con_prompt_init(). This may be the entire difference on 
1 turn games.

Sanity checking on game loading (by S2_0 and HEAD) found some savegame 
errors for the 2001 and 2101 games.

Loading the game and rulesets are probably the majority of the time on 1
turn games.

In the later stages, S2_0 and HEAD are insanely slow compared to 1.14.2
Taking 2 and 3 times as long is simply unacceptable.

Waiting 30-40sec on turn done on a P4 is bad enough. I dare not see 
how pubserver handles this!

Serious thought about optimization is warranted here.

If people have any patches or scripts they use to measure server
performance, then by all means, post them here.

If someone would like to post a recent profile, that would be nice too.

-mike