NSLog and os_log only work in Xcode

I'm testing code on OS 10.12. My NSLog statements work as expected in XCode however in my release builds they do not write to the Console. My understanding is that NSLog was supposed to be shimmed to os_log.


In order to get around the issue I built a small class which tests the OS version and uses NSLog if < 10.12, otherwise os_log. Once again the messages show up in XCode but do not appear in the console (on 10.12).


I've tested every level of os_log support and even a custom log. All work in Xcode, none with the console when running 'live'. I've tested that the os_log levels are enabled and they seem to be.


The documentation is extremely limited. There is sample code for the iPhone, but I can't find anything for a Mac. The iPhone code seems to be doing pretty much what I'm doing.


I must be missing something basic. Any help would be appreciated.

Accepted Reply

Surely there must be some methof of getting the messages to persist.

There’s been a whole bunch of change in this space. Frankly, I’m not fully up to speed on it myself, but a good place to start would be the WWDC 2016 Session 721 Unified Logging and Activity Tracing, which points you to the

log
tool, which has a snazzy man page.

Share and Enjoy

Quinn “The Eskimo!”
Apple Developer Relations, Developer Technical Support, Core OS/Hardware

let myEmail = "eskimo" + "1" + "@apple.com"

Replies

Seems Xcode 8 has gutted purposeful logging for the dev (along with layouts) - might need to find something else to focus on, such as screenshots and localizations, until the real Xcode returns from orbit.


All the pandas are sad over this one...

You’re talking about Mac programs running on the Mac, right? And you’re testing on 10.12?

If so, I tried this out and it works for me. Here’s what I did:

  1. In Xcode 8, I created a simple tool project with the code shown below.

  2. I launched Console app.

  3. I selected my Mac in the Devices list in the sidebar.

  4. I entered “qqq” into the search field.

  5. In Terminal, I ran my tool.

I see both the

NSLog
and
os_log
entries show up in Console.

Please try this out for yourself and let me know if you see the same results.

Share and Enjoy

Quinn “The Eskimo!”
Apple Developer Relations, Developer Technical Support, Core OS/Hardware

let myEmail = "eskimo" + "1" + "@apple.com"
@import Foundation;

#include <os/log.h>

int main(int argc, char **argv) {
    #pragma unused(argc)
    #pragma unused(argv)
    int                retVal;

    @autoreleasepool {
        NSLog(@"QQQ from NSLog");
        os_log(OS_LOG_DEFAULT, "QQQ from os_log");

        retVal = EXIT_SUCCESS;
    }

    return retVal;
}

Thanks for the reply. I've created a project identical to yours and ran it. The messages do appear in the Console.


I ran my code again and the messages did not appear.


I finally figured out that the messages (from both apps) only appear in the Console if it is running when the messages are generated. The messages do not persist. I've even attempted creating a custom log and that again only appears if Console is running. I've tried using os_log_error and that doesn't do any better.


Surely there must be some methof of getting the messages to persist.


Thanks!

Surely there must be some methof of getting the messages to persist.

There’s been a whole bunch of change in this space. Frankly, I’m not fully up to speed on it myself, but a good place to start would be the WWDC 2016 Session 721 Unified Logging and Activity Tracing, which points you to the

log
tool, which has a snazzy man page.

Share and Enjoy

Quinn “The Eskimo!”
Apple Developer Relations, Developer Technical Support, Core OS/Hardware

let myEmail = "eskimo" + "1" + "@apple.com"

After far too many hours of playing aroung and watching WWDC videos, I came to the same conclusion. You pretty much have to use the log tool!


However, the log tool will show thousands of AppKit type messages which will totally confuse a user. To handles this I've prefixed all my log messages with:


(Appname-App)


and I'm be recommending the following log command:


log show --predicate 'process == "AppName" and eventMessage beginswith "(AppName-App)"'

If you just want to filter out messages, you can do that with a saved search in the new Console app. I suggested this to another developer and they reported that it worked for them.

Share and Enjoy

Quinn “The Eskimo!”
Apple Developer Relations, Developer Technical Support, Core OS/Hardware

let myEmail = "eskimo" + "1" + "@apple.com"

Thanks. It seems as if 'log' has access to the data always. I can't get Console to display my application messages unless the Console was open when the messages were generated. The saved searches do not appear to help this issue. Now it is entirely possible that I'm missing something :-)

Hi.


is there an official API for getting the log output from a process? Think, wtiting a custom debugger, or a custom "Terminal" application.


We have an IDE that supports debugging Cocoa (and other) apps, and i find that NSLog output isn't accessible via either StdOut or StdErr (both of which our dbegger captures for the debuggee) under Sierra, however, when i run my debuggee app in Terminal.app, it can see NSLogs just fine.


One alternative i considered/tried was running "log" as a secondary task and capture its output, but it seems to be way behind and inefficient, certaily not suitable for gertting the log messages "live" and showing them inline while debuggging, within the ocntext of other app output.


In the docs for the new logging features, i see only the os_log client APIs (ie for creating logs) documented, but nothing about accessing them (aside from Consiole.app and the `log` executable)


What are Xcode and Terminal.app doing to capture NSLog output?


thanx,

marc

As I mentioned earlier, I’m not really up to speed on all aspects of the new logging system. I recommend that you open a DTS tech support incident so that I, or one of my colleagues, can investigate it properly.

Share and Enjoy

Quinn “The Eskimo!”
Apple Developer Relations, Developer Technical Support, Core OS/Hardware

let myEmail = "eskimo" + "1" + "@apple.com"

Done, thanx!

The sample app for the new logging "Paper Company (Swift)" seems to work just fine.. has just what you would expect from the os_log statements in the code. Likewise the console works as advertised.

BUT my app would not work like the sample until a Build setting was added. I have NOT noticed this setting any where in the documentation but it made me happy with logging again.

The setting is found in the Targets section of the top level xCode window. On the Build Settings page add in "User-Defined" a new section = ASSETCATALOG_COMPRESSION. Under it add two lines: Debug = lossless and Release = respect-asset-catalog.

Look at the sample app for example.

Why this works?? I sure don't know !!!! Any ideas? Any place where this is documented or explained?

i can reproduce the logging problems on 10.12


1.) NSLog() in production apps only 'works' if Console.app is running. else those are ignored

2.) asl_add_log_file() to log to a file is completely broken and no-op if compiling on 10.12. of course you won't even get a warning if compiling for older systems.


ASL has been a disaster since day one and OSL made things even worse. logging is one of the worst aspects of macOS.

Xcode 9.2, Latest Mac OS SDK - 10.13, (a bit old) Objective-C project, running on Mac OS 10.12 - Same sad behavior. The saddest thing is, I cannot even KNOW if my logs are persisted anywhere or not.


I need to deploy my Mac Application to clients, and I rely on logs on their Macs for catching failures and other issues "in the field". I am not talking about crashes, but just internal logic issues in the app.


I have tried NSLog() and followed closely the new unified logger APIs. I've watched the WWDC video, read the documentation, downloaded the Sample app (Paper Company) and even copied actual source lines to my code


--- to no avail. I cannot find any of my log lines neither in the Consoled App, nor using the "log" command line.


To make it clear - I specifically tried the error and failure log levels that should ALWAYS persist - just for proving that any logging persists.


I am getting quite desperate on this, and soon I will be retreating into one of the lousy open-source text-based log-writing utilities on the net. Yes - they ****, and they do not integrate with the OS, and they are bloating the disk with garbage - but I need logs, and MacOS (also iOS) have been depriving me of that functionality for quite a while.


If anyone learns something new about this (@ eskimo...) please add a note here sometime.

It looks as if Console is only for real-time log display. It just doesn't go into the past (at least not for my App).

The command 'log show' does very similar to the Console App - and I was not able to extract my log lines.


However - when I do the 'log collect' ritual, saving a huge bunch of data on my desktop, in a .logarchive bundle - then log show can extract all my persistent log lines from that archive - with the same --predicates as you described. A good filtering mechanism (at least better then prefixing all your messages) would be to set up your own "subsystem", and filter by that.

I'm still working on it, and get frustrated more and more - because my clients are now going to need to learn to use the terminal, and have root privileges (to collect logs) and run a minute-long command just to be able to send me my Apps logs.

That's what I call "Beautiful" new technology... Hail Apple.


Another question - to what log level/type NSLog() maps to? I need to continue using NSLog() for my clients running on older systems.

I’m not having any problems here. First, I created a small test project that logs some stuff.

#include <os/log.h>
#include <stdlib.h>

int main(int argc, char **argv) {
    #pragma unused(argc)
    #pragma unused(argv)

    os_log(OS_LOG_DEFAULT, "qqq default");
    os_log_info(OS_LOG_DEFAULT, "qqq info");
    os_log_debug(OS_LOG_DEFAULT, "qqq debug");
    os_log_error(OS_LOG_DEFAULT, "qqq error");

    return EXIT_SUCCESS;
}

I then tested in two different scenarios, as explained below.

In the first scenario I wanted to test log streaming. Here’s how I did this:

  1. I restored a virtual machine (VM) to a fresh 10.13.3 snapshot.

  2. I copied my test tool to the VM.

    $ scp LogTest virtual-high.local.:

    .

  3. Within the VM I opened a Terminal window and entered the following command.

    $ log stream --level=debug --predicate 'eventMessage contains "qqq"'

    .

  4. I opened another Terminal window and ran my test tool.

    $ ./LogTest 
    $

    .

  5. The first Terminal window showed all my log output.

    $ log stream --level=debug --predicate 'eventMessage contains "qqq"'
    Filtering the log data using "eventMessage CONTAINS "qqq""
    Timestamp              Thread Type    Activity PID TTL  
    … 03:19:04.504214-0700 0x1a6a Default 0x0      681 LogTest: qqq default
    … 03:19:04.504676-0700 0x1a6a Info    0x0      681 LogTest: qqq info
    … 03:19:04.504696-0700 0x1a6a Debug   0x0      681 LogTest: qqq debug
    … 03:19:04.504724-0700 0x1a6a Error   0x0      681 LogTest: qqq error
    ^C

    .

In the second scenario I wanted to explore the “in the field” case. Here’s what I did:

  1. I restored my VM back to its 10.13.3 snapshot.

  2. I copied my test tool to the VM again.

  3. Within the VM I opened a Terminal window and ran my test program.

    $ ./LogTest 
    $

    .

  4. I then ran sysdiagnose:

    $ sudo sysdiagnose

    .

  5. I authenticated, authorised, and waited for

    sysdiagnose
    to complete.
  6. I copied the resulting log back to my main Mac, also running 10.13.3

  7. I unpacked the log and then opened

    system_logs.logarchive
    in Console.
  8. In Console, I made sure that Include Info Messages and Include Debug Messages, both on the Action menu, were checked.

  9. I then entered “qqq” in the search box and pressed Return.

  10. Here’s what I see:

    default 2018-03-19 03:19:58.336030 -0700 LogTest qqq default
    info    2018-03-19 03:19:58.336039 -0700 LogTest qqq info
    error   2018-03-19 03:19:58.336047 -0700 LogTest qqq error

    .

This is pretty much what I expected. The only oddity is that the debug message wasn’t captured by the sysdiagnose log, which is not hugely weird.

Share and Enjoy

Quinn “The Eskimo!”
Apple Developer Relations, Developer Technical Support, Core OS/Hardware

let myEmail = "eskimo" + "1" + "@apple.com"