How to determine why my spotlight importer is not working?

In situations like this the first step is to split the problem into parts:

• Is the system not running your importer?

• Is the system running your importer but it’s not producing the correct results?

• Is your importer producing the correct results but the system isn’t picking them up?

I usually debug this by adding log points to the start and end of my importer. As the importer runs in a fairly tight sandbox (hence those kCFPreferencesCurrentUser messages), it’s best to use the system log for this. See Generating Log Messages from Your Code.

Oh, the other thing I do is re-test on a fresh machine. Spotlight has a lot of persistent state (not a surprise!) and it’s not unusual for it to end up tied up in knots on development machines. By testing on a fresh machine you can confirm that this is a real problem rather than just some wonkiness on your development Mac.

I usually do this testing on a VM; see my Testing a Notarised Product post for a general outline of my process (although that post is focused on a very different issue).

Share and Enjoy
—
Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

What does this mean:

Sandbox: logd_helper(614) deny(1) file-read-data /Applications/apps/Valerie.app/Contents/Library/Spotlight/ValerieSpotlightImporter.mdimporter/Contents/MacOS/ValerieSpotlightImporter

It means that the sandbox prevented the logd_helper process from reading the file /Applications/apps/Valerie.app/Contents/Library/Spotlight/ValerieSpotlightImporter.mdimporter/Contents/MacOS/ValerieSpotlightImporter.

This is not the App Sandbox, because logd_helper is not an app. The App Sandbox is based on an underlying sandbox technology that’s applied to many system components. However, many concepts are shared between the two so you can get some background into the concept of sandbox violations by reading the App Sandbox Design Guide.

Note that logd_helper is associated with the logging subsystem (see the logd_helper man page) and thus this is unlikely to be related to your original Spotlight issue.

Share and Enjoy
—
Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

I was wondering whether it was related to the ability of my importer to write messages to the system log. I added logging to the importer but have seen no messages.

What I do see is a fantastic number of messsages like this:

Aug 13 06:31:00 2020 com.apple.xpc.launchd[1] (com.apple.mdworker.shared.1B000000-0500-0000-0000-000000000000[7793]): Service exited due to SIGKILL | sent by mds[95]
Aug 13 06:31:00 2020 com.apple.xpc.launchd[1] (com.apple.mdworker.shared.11000000-0700-0000-0000-000000000000[7795]): Service exited due to SIGKILL | sent by mds[95]
Aug 13 06:31:00 2020 com.apple.xpc.launchd[1] (com.apple.mdworker.shared.1D000000-0200-0000-0000-000000000000[7784]): Service exited due to SIGKILL | sent by mds[95]
Aug 13 06:31:00 2020 com.apple.xpc.launchd[1] (com.apple.mdworker.shared.1F000000-0400-0000-0000-000000000000[7800]): Service exited due to SIGKILL | sent by mds[95]

I have made some progress thanks to your suggestions. I installed the application in a clean 11.5.2 system on a VM. I waited until mdimport -L showed my importer, then saved a document. I then did a Spotlight search and the new document was successfully found!

The remaining issues:

1. Although I added logging using os_log as you suggested, I have yet to see any log messages in system.log. Any ideas on what might be going wrong? I double checked the importer binary to be sure that it contained my message strings, which it did.

For example:

    os_log_t LOG = os_log_create("org.violetlib.valerie", "metadata");
    os_log_info(LOG, "Metadata requested for %{public}@", pathToFile);

Should I expect to see this output in Console's system.log?

1. I would really like this importer to work on my development system, but I have no desire to do a fresh OS install. Do you have any suggestions on how to get it working or how to find out which bit of persistent state is causing the problem?

Thanks!

I have made some progress

Yay!

Although I added logging using os_log as you suggested, I have yet to see any log messages in system.log. Any ideas on what might be going wrong?

It looks like you’re logging at the .info level. Did you enable that in Console (via Action > Include Info Messages)?

If that doesn’t help, trying creating a new test app that logs using the same code you use in your importer. Can you see that in Console?

Do you have any suggestions on how to get it working or how to find out which bit of persistent state is causing the problem?

Nothing specific to your situation. However, my next step in debugging any problem like this (after trying it on a VM :-) is to try it from a new user account. That’ll tell you whether the problem is tied to your user account or to the system as a whole.

Share and Enjoy
—
Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

Regarding the logging, I wrote a test app. Logging statements can be seen in the debug log under Xcode, but when run independently, nothing shows up in system.log (even looking at the file directly).

#import "AppDelegate.h"
#include <os/log.h>

@interface AppDelegate ()
@end

@implementation AppDelegate
- (void)applicationDidFinishLaunching:(NSNotification *)aNotification {
    os_log_t LOG = os_log_create("test.test.test", "testing");
    os_log_info(LOG, "Testing OS Logging Info");
    os_log_error(LOG, "Testing OS Logging Error");
    os_log_info(OS_LOG_DEFAULT, "Testing OS Logging Info Default");
    os_log_error(OS_LOG_DEFAULT, "Testing OS Logging Error Default");}
@end

Regarding the problem on my development system, I ran the application from another account and Spotlight was successfully updated. So I guess that means the problem is tied to my user account.

Slightly off topic, but I used fast user switching to run under the second account and found that my application would not start (*) under the second account unless I quit the application under my main account. Is that normal?

*Actually, it started but immediately terminated with no logged error message.

nothing shows up in system.log (even looking at the file directly)

The system.log file is no longer the definitive store for… well… the system log. The system log is store in a location private to logd, which exports specific log entries to system.log as a compatibility measure.

The best way to monitor the real system log is via the Console app. Or, if you prefer the command line, use the log tool (see its man page).

I used fast user switching to run under the second account and found that my application would not start … under the second account unless I quit the application under my main account. Is that normal?

There’s an Info.plist property that controls this [1]. However, it’s more likely that your app is relying on some global resource and terminating when it fails to get that. Run the app in the debugger and set a breakpoint on exit. What does the backtrace look like?

Share and Enjoy
—
Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

[1] It might be LSMultipleInstancesProhibited, but the docs are kinda vague.

Good news. The importer is now working on my development system. Of course, I have no idea why. Hopefully, it will keep working.

Also, I figured out the logging situation, which is not exactly as you described. First, the log messages show up on the main Console.app display, not the system.log display. Second, error messages are displayed but info messages are not, even if Action: Include Info Messages is enabled. (Is this a bug?) When I changed the basic log messages to error, they show up.

Thank you for your assistance!