Why is this system (running only a thousand simple GenServers) slow?

(this is just a guess)

It’s Timex.

yeah, remove the timex stuff.

I’m not sure how much File.io you are doing - but perhaps add an alternative :ets persistence layer, just to see.

@outlog The one thing I was able to read from Observer’s summary page, was the fact that there was barely any file IO happening. The only time the Persistence layer is used, is when the servers start, and after that only when a player makes a change. (So not!! every update).

I will try out what happens when not using Timex .

It’s only the first “tick” that is slow as you are replaying all ticks from last_player_tick_datetime up until now (in tick_until_updated(state)) .. those stamps are from around 2017-05-31 19:43:27.753034Z - so that makes for a lot of operations times 1000 (~350 million “ticks” - which have sub ops) - and then if timex is a bit on the slow side…

Quick and dirty fix in Game.PlayerServer - persist the data after they have been replayed up until now - so future launches will be faster. by your design the launch will replay ticks - which I suppose is fine.
Else you have to update the last_player_tick_datetime to now when loading the player.

add:

  defhandleinfo :first_tick!, state: state do
    updated_state = tick_until_updated(state)
    GamePersistence.Persistence.persist_player(updated_state)
    send_next_tick()
    broadcast_update(updated_state)
    new_state(updated_state)
  end

and then in the init replace send_next_tick() with :erlang.send_after(1, self(), :first_tick!)

Then wait out a first launch and subsequent ones will be faster.

Given that CPU usage is 100% and you don’t observe I/O load, then it’s possible that your work is spent in each PlayerServer.

You could verify this by experimentally finding a smaller number of player servers which puts your CPU below 100% (say at 90% or so). Then you would have enough CPU available to work with tools such as observer. If in the processes tab you constantly see your player servers at the top, it should be a proof that these are the processes consuming your CPU.

Going further, you could use eprof to get some pointers about where you spend most of your time. This SO answer by Fred give some quickstart pointers.

If you’re able to find a sequential piece of code which causes your problem, you can drill into it further with the fprof Task.

IME reading the output of these profilers will usually require some meditation, so don’t be surprised if you’re not immediately able to find the cause. But most often you should be able to get to the root cause of your bottlenecks, or at least narrow down the problematic area.

Combining these techniques with some cheap trickery, such as commenting or stubbing out suspicious pieces of the code should help you find the problematic parts of your code.

I didn’t wait for the replays but did a single launch with the map put line in effect(and the first_tick changes above):

  def load_player(user_id) do
    case File.read(filepath(user_id)) do
      {:ok, data} ->
        user_state = :erlang.binary_to_term(data)
        #user_state = Map.put(user_state, :last_player_tick_datetime, Timex.now())
        {:ok, user_state}
      _ ->
        :error
    end
  end

then added 10000 players and it’s running fine at 16% cpu..

@outlog This change was indeed all that was needed; Depending on how long it was ago that the application was started for the last time, CPU load will stay at 100% for a while. But after a few minutes the system will have catched up with the current time. Ensuring that this does not need to be recomputed again is definitely a smart idea.

I am absolutely amazed. Running the system now with 10_000 players, and after the initial updates are done, CPU load drops to much lower levels. I expect that I could easily run twenty or thirty thousand players (and possibly even more if the mix environment would be set to production, and deployed to an otherwise empty virtual private server.) I am extremely happy! This is definitely Fast Enough .

@sasajuric Thank you for your very detailed description on how to profile a system. For good measure, I have run eprof to check what is going on during starting up, and indeed all the time is spent during the starting procedure of the PlayerServers.

great, you still need to add a “now and then” write to persistence function - so the persisted data doesn’t drift that far behind as the server runs.. (and refactor my “fixes” when you are at it)

I would look at not using Timex, but hey if it works and is fast enough;-)