Using console statements to find where a procedure crashes is unreliable

I have a procedure that has been unstable under PanX 10.2 and repeatedly tried to pin down the problem by putting console statements at each step of the procedure. I thought if then checked the console after a crash that I could conclude the crash occurred between two particular console statements-after the last one that appeared in the console and before the next one.
But I now know that is wrong. My procedure adds several rows to the database. There is console statement before each one. The result was the last console statement appeared before the first row was added, BUT several rows were actually added before the crash but the console statement that appeared before them, except the first one, did not appear in the console. Obviously the procedure had gotten much further along and the console statements had not yet been posted.
I have been asserting that the assignment statement was causing crashes because the console statement before the assignment was present but not the one after. This conclusion can no longer be accepted. The problem must lie elsewhere.
Relying on this erroneous methodology has led me to spend a lot of time on the wrong thing. No wonder I couldn’t make a dent.

Tom, I often rely on a floating stop to narrow down where problems are surfacing in a procedure. I first use a startdatabasechange at the top of the procedure so I can easily revert back to my starting condition. I then try placing a stop after the procedure line just before the line I think might be causing the problem. If it still crashes I’ll move the stop to an earlier position and if it does not crash I’ll move it down a line and keep trying until I find the problem line. You can usually narrow down to the problem code fairly quickly.

I don’t personally use the Console app, and I don’t know the details of how the system transmits the messages from Panorama to the console. So I don’t know if message could get lost if Panorama crashes. I know that Apple did make a huge change in in how the system logs work a couple of releases ago, maybe 10.13? There were some WWDC talks about it. I know I’ve seen chatter on developer forums that system logs are much less useful than they used to be, but I don’t understand the details.

I’m pretty sure that if you launch Panorama via Terminal.app the then message won’t get lost – you’ll see all console output right up to a crash. I’ve added a feature in the upcoming b7 release to make it easier to launc Panorama via Terminal.app, but it’s not that hard now. First open Terminal.app, then enter this command:

/Applications/PanoramaX.app/Contents/MacOS/PanoramaX

(If your copy of PanoramaX.app is in a different folder, substitute the actual path.)

When run this way, all of Panorama’s console output will appear in the terminal window. Note that you cannot close the terminal window or quit Terminal.app, as that will force quit Panorama (it will warn you before it does this).

I use this technique all the time. Usually I’m using it with Xcode, not Terminal.app, but it works exactly the same way (and I have used Terminal.app quite a bit, especially with Panorama X Server, where I can’t use Xcode). I’ve never seen a lost message. Using logging to track down problems can be tedious, but it’s often the best way. The new instrumentation in b7 makes it significantly easier than using console statements, especially since you can usually leave the instrumentation in permanently.

I consider this excellent news. I was completely baffled that the assignment statement was causing crashes. Hopefully with non-erroneous methodology the real culprit will be found quickly.