Following on from an earlier posting about using XDebug to profile PHP code, I had a 10 minute session (all I could spare over the busy weekend) to profile Partholan and take a peek at its performance in more detail. Last I used XDebug I was sticking with version 1, this time I was using version 2beta5 which outputs a cachgrind file you can read using KCacheGrind or WinCacheGrind.

Without the time to setup a series of tests, I took something simple – a run of an user save operation used with Quantum Star SE’s Installer. This at least drags in Database interaction and uses more of Partholan’s basics. I’ll stick the graphic below:

KCacheGrind ScreenshotThe “Self” column is most interesting as it excludes calls to other functions and only counts time executing that function’s code. “Incl.” or Inclusive includes everything – and is most useful where a function uses mostly PHP internal functions. The graphic above is out of whack since SHA256 class has a huge impact – excluding it should be more representative of Partholan as more commonly used.

The first run produced results. If you examine the graphic you may notice something a little weird. Partholan uses a helper class (ApplicationHelper) and a data access class (DataAcess) to manage database connections and interactions. These are largely dependent on ADOdb-Lite. What’s interesting is that the initial run highlighted an undetected bug – there are 3 calls to ApplicationHelper::getDAO, and ApplicationHelper::connect(). These are both linked since getDAO() always calls connect() – the problem is we’re looking at code for connecting to the database, a task we need only perform once, and for which getDAO() was written as a singleton!

I’m sure there was a measurable performance improvement from fixing the three expensive calls (via ADOdb-Lite) to mysqli_real_connect() this evokes, and it goes to show that not all bugs are so easily detected by simply “using” the application. In the end the problem was the singleton’s static variable calling a new object instance by reference (this cannot be maintained as a static value, so the static kept returning to its NULL value after use).

Stupid little bug – it was a simple type in adding an extra & character but it resulted in a devious bug that would have escaped notice for a long time had I not used XDebug to profile.

One flaw in the test used for the screenshot was my test case was using feyd’s SHA256 class. This practically sucks execution time, making 312 calls to several functions. I think in total it took up about 45% or more of the total execution time – its minor really, the class is only used for hashing passwords – so it’s not an area needing optimisation. Once I remove it from the test and with that static reference bug fixed, the test should show more interesting results that are more obvious indicators of where and if optimisation is required!

Related posts:

  1. Partholan – finally I get to apply a little Gaelic!
  2. Partholan 0.18 – its finished but is it optimised???
  3. Partholan 0.09 Progress