KM Engine Crash Report

Questions & Suggestions
1

KM Engine Crash Report

Running Keyboard Maestro 7.3.1 (7.3.1) on macOS 10.11.6

@peternlewis:

It is a very rare event for the KM Engine (or KM app) to crash. In fact, I don't even remember the last time it happened. So when it happened when I was not doing anything special, I was concerned.

Steps to Reproduce Activity Just Before Crash

  1. Put Mac to sleep (using KM Macro)
  2. Hours later, wake Mac
  • The Macro "ON WAKE Actions..." is triggered, as it always is
    • I use this Macro every day on multiple Macs
    • I have never had any problems with it
    • Macro is attached below
  • Macro normally completes
  • A few minutes later, I noticed that another high-frequency trigger macro is NOT firing:
    @MOU Move Mouse to FrontMost Window When Window Changes
    • It is triggered whenever the focused window or focused window frame changes
  • So I manually started the KM Engine from the KM App

Questions from Log

In addition to the KM Engine crash, I did notice two events that I have questions about:

  1. Can KM Macros be triggered when the Mac is in Sleep mode?
  • This seems to have happened at 2017-04-02 23:50:55
  1. What are the errors with reference to file: /Users/peter/. . . ?
  • There is no peter account on my Mac.

KM Engine Log (with my annotations)

## # TRIGGER MACRO TO PUT MAC TO SLEEP ###

2017-04-02 21:12:28 Execute macro ‘[SLEEP] Close Apps, Unmount Drives, & Sleep’ from trigger Do Script
2017-04-02 21:12:30 Execute macro ‘@Finder Get @DropBox @Conflicted Files When Added’ from trigger Anything is added to folder ‘/Users/Shared/Dropbox/AppSync/KM/KM7’ (ignoring partial files)
2017-04-02 21:12:37 Execute macro ‘@Finder Get @DropBox @Conflicted Files When Added’ from trigger Anything is added to folder ‘/Users/Shared/Dropbox/AppSync/KM/KM7’ (ignoring partial files)
2017-04-02 21:13:18 Execute macro ‘@MOU Move Mouse to FrontMost Window When Window Changes’ from trigger Application ‘Finder’ activates
2017-04-02 21:13:18 Assertion Failed: replace,  file: /Users/peter/Keyboard Maestro/Project/Source/Utility/TokenText.mm:286, value: 0
2017-04-02 21:13:18 Execute macro ‘@MOU Move Mouse to FrontMost Window When Window Changes’ from trigger tFocusedWindowFocusedWindowChanges
2017-04-02 21:13:19 Execute macro ‘@MOU Move Mouse to FrontMost Window When Window Changes’ from trigger tFocusedWindowFocusedWindowChanges

## # MAC SHOULD BE ASLEEP AT THIS POINT ###
# 		How could these macros be triggered when Mac is asleep?

2017-04-02 23:50:55 Execute macro ‘@Finder Get @DropBox @Conflicted Files When Added’ from trigger Anything is added to folder ‘/Users/Shared/Dropbox/AppSync/KM/KM7’ (ignoring partial files)
2017-04-02 23:59:59 Execute macro ‘[OL] Manage Outlook 2011 Work Online Time & Battery Usage’ from trigger Every 15 minutes between 8:00-3:00 every day
2017-04-03 01:34:39 Execute macro ‘@Finder Get @DropBox @Conflicted Files When Added’ from trigger Anything is added to folder ‘/Users/Shared/Dropbox/AppSync/KM/KM7’ (ignoring partial files)

## # MAC WOKE FROM SLEEP, AND MACRO IS TRIGGERED ###

2017-04-03 13:47:38 Execute macro ‘ON WAKE Actions to Execute on System @Login & @Wake’ from trigger At System Wake

## # WHAT IS THIS ERROR THAT REFERS TO PETER'S HOME FOLDER??? ###

2017-04-03 13:47:45 Assertion Failed: theErr == 0 ,  file: /Users/peter/Keyboard Maestro/Project/Source/Utility/KBMRunningApplication.mm:34, value: -600
2017-04-03 13:47:45 Assertion Failed: SendProcessCoreEventAE( i_pid, kAEQuitApplication ) == 0 ,  file: /Users/peter/Keyboard Maestro/Project/Source/Utility/KBMRunningApplication.mm:329, value: -600
2017-04-03 13:48:10 Running application query took a while (73895 us)
2017-04-03 13:48:10 Running application query took a while (5524 us)
2017-04-03 13:48:12 Running application query took a while (61756 us)
2017-04-03 13:48:17 Execute macro ‘@MOU Move Mouse to FrontMost Window When Window Changes’ from trigger tFocusedWindowFocusedWindowChanges
2017-04-03 13:48:27 Execute macro ‘@MOU Move Mouse to FrontMost Window When Window Changes’ from trigger tFocusedWindowFocusedWindowsFrameChanged
2017-04-03 13:48:28 Execute macro ‘@MOU Move Mouse to FrontMost Window When Window Changes’ from trigger tFocusedWindowFocusedWindowsFrameChanged
2017-04-03 13:48:28 Execute macro ‘@MOU Move Mouse to FrontMost Window When Window Changes’ from trigger tFocusedWindowFocusedWindowChanges
2017-04-03 13:48:33 Execute macro ‘@MOU Move Mouse to FrontMost Window When Window Changes’ from trigger tFocusedWindowFocusedWindowChanges

## # KM ENGINE AUTO-STOPPED OR CRASHED AT THIS POINT ###
## # WHY?

2017-04-03 14:06:23 Engine Starting 7.3.1
2017-04-03 14:06:23 Old engine details remains a running process Running Engine Details/313
2017-04-03 14:06:23 Start Watching HID Devices
2017-04-03 14:06:24 Execute macro ‘@MOU Move Mouse to FrontMost Window When Window Changes’ from trigger tFocusedWindowFocusedWindowChanges
2017-04-03 14:06:24 Starting web server on ports 4490 and 4491

My On Wake Macro

Uploaded in DISABLED state.
ON WAKE Actions to Execute on System @Login & @Wake.kmmacros (42 KB)

2

As an aside, can you talk about this macro? I can't immediately picture its use or usefulness. Thanks.

3

Yes, crashes in Keyboard Maestro are very rare, at least based on the crash reports I get there are roughly one crash per 7-user-years, though obviously some people will see more crashes than others, and if you manage to find a repeatable crash then you might get a bunch.

The vast majority of remaining crash reports appear to be a low level system synchronisation failure. It might be due to some misuse of API or error in my code, or it may be due to some bug in the system itself. But there is no consistency on what Keyboard Maestro is doing at the time of the crashes, so I have no real idea what might be causing them. Which is a shame, since I suspect it might resolve 90% of the remaining crashes.

You say "Steps to Reproduce" - but does this actually reproduce the crash, or it just happened once?

Keyboard Maestro cannot trigger macros while the Mac is asleep. However a sleeping Mac can wake for various reasons. Especially if it is connected to power, but even if not. That said, the state of the Mac while sleeping is rather odd, and so macros that trigger while the Mac is mostly asleep might well fail for other reasons.

They are just strings. They just reference a specific location in the code where an assertion happens so I can find it. They don't refer to files or file access attempts on your Mac per se, they are just text that is recorded in the logs for my benefit when debugging an issue.

They generally indicate that something unexpected has gone wrong. In theory, they should always indicate a programming error on my part, but in practice they often indicate that something that should not be possible to happen has happened - they are especially common related to the system’s NSRunningApplication API which often gives broken and incorrect results.

The specific case, the assertion in TokenText.mm:286 indicates that the replacement string for the token was nil, which it should never be. It should be the empty string. Do you know what token it was?

The assertion KBMRunningApplication.mm:34 and KBMRunningApplication.mm:329 indicates that the attempt to send the quit event to the process failed with error -600 (procNotFound ) which is a system generic error that means the process that it was trying to quit could not be found, perhaps because it had already quit, or probably because the NSRunningApplication lied about it being running at all.

Presumably the ON WAKE Actions macro quits something?

You would have to look at the crash report to attempt to determine that. I checked my crash logs and only found one from you in 2016.

This might indicate that the engine was still running, but not functioning for some reason.

That's about all I can suggest.

4

Poor choice of words on my part. So far, it has crashed only once.
These are simply the steps immediately preceding the crash.

OK, thanks for that explanation.

I did just think of one case that might cause my Mac to wake.
I have it set to wake on network request, and I have recently shared an external drive connected to it. Could be that I inadvertently tried to access that shared drive from my other Mac.

I don't have a clue. How would I find out?

I believe it has only one quit: System Preferences

Peter, thank you very much for your quick and thorough response.

I don't think I'm going to worry about the crash, unless it happens again, but I doubt that it will. :wink:

5

Have a look at what tokens the @MOU Move Mouse to FrontMost Window When Window Changes macro uses (directly or indirectly if it executes other macros).

That one is a bug I should fix, though it is likely caused by not being able to read whatever state was being requested by the token, but even so it should never result in nil being used. And I don't like not knowing the cause.

But it's no big deal, it can't cause any problem since nil is treated like an empty string anyway.

6

Peter, this is a long and complicated macro that uses lots of tokens.
So, if it is no big deal, I'd just as soon ignore the problem for now.
If i get another crash, then I'll dig into this.

7

This first text token assertion definitely wasn't the cause of the crash. The very next line of code after that assertion that the input replacement parameter is unexpectedly nil converts the nil into an empty string.

8

Peter, I got an official crash report notice this morning when I launched KM app. I submitted it. From the date it looked like the crash I reported above.

9

Yep, I think I can see it, although it has a different email address from the one you usually use.

If so, it crashed in the Directory Monitor trigger code, detecting some change in a folder.

It’s the only crash I have recorded in that routine, so it is likely not really related to that, probably something else was broken earlier and that routine just fell victim to the corruption that followed.

In the absence of repeatability or any other crashes like it, it is unlikely we’ll ever find the cause.

10

Got another crash report earlier today when I first launched KM app.
Submitted with my forum email.

11

It looks like the same crash, something related to the DirectoryMonitor trigger.

I checked further and I have no other crash reports related to DirectoryMonitor since 2015, so the crash is specific to your case. As such, I’d either investigate what might be unusual about your folder change macros (referencing an unusual or unmounted drive for example), or restart on the possibility that there is some sort of memory corruption in the system.