The first part of the series on getting started with Instruments we had a look at the interface. In the second part we did some test preparation. Today we are finally going to do some testing.

Refresher

Here is a refresher on the interface of Instruments:

  • Select Time Profiler when starting Instruments.
  • Select the process you want to analyse.
  • Start analysing by clicking on the button with the red bubble.
  • Wait 10-20 seconds and click on the same button again.

In the first article I also mentioned the weight column. That’s going to be our focus now. We also need to do a game of clicking. We are going to look for anything odd. Which is about as clear as mud so we are going to look at three examples.

Checking a slowdown

In part 1 I mentioned that users had complained that my app was getting slower and slower when it worked. We are going to look at that first.

Here is a screenshot from Instruments directly after starting to archive emails in my app Mail Archiver.First test on slowdown in Mail Archiver

There is a Main thread that uses 12% CPU time. The main working thread uses 81.6%. I opened the thread a bit. At that level everything looks okay.

Have a look at the same situation a couple of hours later:

Holy guacamole. The screenshot shows the same level of detail again with the main working thread selected. At CPU Usage we see that the app uses 100% of the CPU. The main working thread uses 0.2%. All the rest is used by the Main thread which doesn’t really do anything. Clearly something is wrong here.

Now we need to find the culprit.

I clicked the thread with the 99.7% open until I found 2 lines with 51.8% and 47.5% like this:

Then it was just a matter of checking the data in those 2 lines until I found the root cause of my problem:

Finding root cause for slowness in Instruments

“SAConnection:IsAlive” is from the MBS plugin and uses almost half of the CPU time. I sent the trace information to Christian Schmitz. An hour later I had an updated plugin and I was happy.

What is the Main thread doing?

In the first screenshot we see that the Main thread uses about 12% CPU. I thought that a bit high and had a look what the thread is doing. Remember: look at the weight of a line and then click open the interesting lines.

I got this here:Investigating the Main thread

Mail Archiver has a dynamic dock icon which shows the number of archived emails. That is supposed to use 5% of the CPU? That seemed like a quick candidate for optmimization. However, the code for the dock icon is simple. There is a gradient in a rectangle with a mask and a number. The dock is updated once a second.

So I checked everything with my trusty test account. This time just in the debugger. I took out the code for updating the dock icon and ran the test again. Archiving was faster. Too fast. I put the code back in and archiving stayed fast.

My application can archive emails for hours and hours. Investigating each and every nook and cranny is impossible. If a user gets a speed improvement from 10 hours to 9 hours 50 minutes he/she won’t even notice that. Therefore I wouldn’t have investigated the 5% weight line. But I thought it would be something stupid. It wasn’t. I’m not sure if there is something else going on.

Archiving large emails

Most users have lots of small emails. However, now and then there are large emails. The largest email I have is 320 megabytes. Archiving those monsters has always been a bit slow. So we are going to look at those emails now.

I make a nice folder with copies of copies of that lovely email in Finder:

Almost 4 gigabyte should be enough for testing.

Here is my first test result:

The 12 emails turned out to be total overkill. I let Instruments run 80 seconds and stopped it at the 4th email.

The selected lines in the screenshot are the uninteresting ones. In those classes the database is written to. My iMac has an HFS+ volume with a Fusion drive. Speed isn’t as fast as on an SSD. It would be interesting though to redo the test on my laptop. The Air has an SSD and runs Catalina with APFS. One user of my app wrote me that archiving is 4 times faster after she bought an SSD.

An email has a tree structure. The data is only in the leaves. That means that the emails parsing has 3 parts:

  1. Read all the data for an email.
  2. Split the data so that I get to the data in the leaves.
  3. Put the data together. Some data is redundant, some is not. Sometimes the order of the data can change.

Here you can see part 1 where the data is read:

One of the things I do to prepare the data for parsing is replacing all the line endings so that I get only one type of line ending. I will need to investigate if using a memoryblock is faster.

Here is the second part of parsing emails:

The first selected line shows the method which starts splitting the data. Selected lines 2 and 3 show the interesting stuff I found. Likely I can’t do anything about base64 decoding. The email is split into parts with a regex which is what we are seeing in line 3. The MBS plugin nowadays has multi-threaded methods for Regex. Those might help here.

That’s it for today. In the first example I found the problem easily after I knew what to look for. The data in the second example turned out to be misleading. Or I didn’t have a good test or something else is going on. For the third test I have some ideas what I might test to further speed up the core functionality of my app. But I will also need to do more testing.