Log Literacy: Hunting bugs with Ulbow’s Chart View

Two unconventional tools provided to help you browse the Unified log with Ulbow are its Chart and Frequency views, available in its Window menu. This tutorial illustrates their use to identify a problem in the Twitter app for macOS.

For a couple of weeks now, I’ve noticed the Twitter app pushing the fans to blow in my iMac Pro. With a little experiment, I discovered that much of the time, when the app’s Latest Tweets view is displayed, it stole lots of CPU and hit WindowServer too. Switch to its Notifications view, and the app used little CPU, and WindowServer was far happier too. These are easily seen in the CPU view of Activity Monitor.


Above is typical when the Notifications view is displayed, and below when Latest Tweets is, with the Twitter app using over 100% CPU, and WindowServer at nearly 40%.


Although this could be happening without any trace in the log, I suspected that it should at least give a clue as to whether it was something I could modify myself. I therefore quit all other apps to get as clean log extracts as I could, and at 15:28:00 switched views to Latest Tweets, and ten seconds later switched back to Notifications.

To get the best view of this in Ulbow, I excluded Signposts, as shown in the View menu settings below.


I then set up the Period for 20 seconds from a start time five seconds before I first switched views, 15:27:55, and clicked on Get log to obtain a little more than 6,000 entries.


Rather than wade through all those, I then opened both a Chart and a Frequency view.


The Chart view shows a histogram of the rate of entries being written to the log over the period examined. Hover the pointer over one of the bars, and a Tooltip tells you the time of that collection and how many entries are in it. You can make the bars cover shorter periods of time by tapping on them, and go for longer periods and fewer bars with a two-finger tap. When a tooltip is visible, pressing Command-C copies the time from that, and you can paste it into Ulbow’s date and time box using Command-V.

Looking just at the total count of log entries, there was a peak when I switched view to Latest Tweets, and something of a fall when I returned to Notifications, but it wasn’t that convincing.

I then looked in the Frequency view, where the usual suspects were at the top of the list. However, com.apple.UIKit coming in fourth was unexpected.


I adjusted the time of the log excerpt slightly, to cover the period from 15:27:58 for 22 seconds, and showed com.apple.UIKit in the Chart view.


For the whole of the ten seconds in which Latest Tweets was visible, there was a torrent of entries for the UIKit subsystem that rapidly died away when I switched to view Notifications.

My next step was to browse entries from that subsystem alone. To do that, I built an ad hoc predicate, typing into the Predicate box
subsystem == ""
then pasting in the subsystem name from the Frequency view, between the quotation marks. Over the whole 22 seconds of interest, this only produced 1404 entries.


To see the difference resulting from the two Twitter views, I narrowed the Period to 5 seconds, and looked through just a few hundred entries from 15:28:00 and ten seconds later.


When the Twitter app was taking 100% CPU and bothering WindowServer, entries came thick and fast, mostly with TableView in UIKitCore, with repeated entries recording that focus was failing to update.


Not only were there far fewer entries in the second time period, but they were recording the adding and ending of background tasks, with little about TableViews, and no failures in updating focus.

The experienced reader will by now have spotted something odd: this is from macOS, but all these references are to UIKit, which is iOS and iPadOS equivalent of AppKit (macOS). This is because the Twitter app isn’t a real macOS app at all, but built using Catalyst, so is making calls through the Catalyst port of UIKit.

This is clearly a bug, but whether it’s in the Twitter app or Catalyst it’s impossible to tell from the log. What is clear is that the Twitter app is currently broken in macOS 13.2.1, but as it hasn’t been updated since Friday 13 January, I’d like to thank Elon Musk for screwing up my use of Twitter in yet another way: Tweetbot was a real macOS app, and excellently maintained.