os_log Unified Logging not anymore tide to stderr in iOS 17?

Previously, were you using this approach only when being debugged? Or using it when the app was run in the normal way, that is, launched from the Home screen?

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

Great question! During debugging, the readabilityHandler isn't invoked (which isn't an issue as we can view logs in Xcode 15's new debug console). When running the app normally, the readabilityHandler is only invoked sporadically. To clarify, our logs (using Logger) aren't captured, while those from other frameworks do trigger the readabilityHandler.

I’m still quite confused here )-: Let’s focus on iOS 16 for the moment; we can talk about iOS 17 in a bit.

It sounds like, on iOS 16:

• You have code that creates a pipe.

• And dup’s the write side down to stdout and stderr.

• It monitors the read side with FileHandle, writing the results to a file.

• You leave this installed in your releases build.

• When you run the app from the Home screen, the resulting file does not contain log entries that you wrote using Logger.

• But it does contain log entries written by other frameworks running in your process.

Is that right?

If so, what logging API are these frameworks using?

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

Okay, so the following is happening on iOS 16 and works as expected:

1. I have code that creates two pipes (one for input and one for output).
2. Using dup2 redirect data sent to output to stderr
3. Using dup2 redirect data sent to stderr to input
4. It monitors the input using FileHandle, writing the results to a file.
5. I leave this installed in my release build
6. When I run the app from the Home screen, the resulting file does contain log entries I wrote using Logger
7. It also does contain log entries written by other framework running in my process.

On iOS 16 when debugging:

1. Code still the same
2. It monitors the input using FileHandle, writing the results to a file.
3. I start the app using Xcode and debug it on a simulator/device
4. The resulting file does contain log entries I wrote using Logger
5. It also does contain log entries written by other framework running in my process.

So basically on iOS 16 it works flawless.

Now...

On iOS 17 when running in release:

1. Code still the same
2. It monitors the input using FileHandle, writing the results to a file.
3. I leave this installed in my release build
4. When I run the app from the Home screen, the resulting file does not contain log entries I wrote using Logger
5. But it does contain log entries written by other framework running in my process.

On iOS 17 when running in debug:

1. Code still the same
2. It monitors the input using FileHandle, writing the results to a file.
3. I start the app using Xcode and debug it on a simulator/device
4. The resulting file does not contain log entries I wrote using Logger
5. It also does not contain log entries written by other framework running in my process.

I forgot to mention, that I cannot verify what logging API this framework is using, since it's a proprietary framework and they deliver it to us as already compiled binary.

Thanks for the detailed description of what you’re seeing.

Again, I’m going to focus on the iOS 16 side of this, and for good reason. Your description of the iOS 16 behaviour doesn’t match my reality (-: This suggests that something else is going on your project.

Lemme start with my reality! Swift’s Logger type is just a front end to the system log. This does not log to stdout or stderr unless you take unsupported actions to enable that (like setting OS_ACTIVITY_DT_MODE). You wrote:

Okay, so the following is happening on iOS 16 and works as expected:

…

6. When I run the app from the Home screen, the resulting file does contain log entries I wrote using Logger

which is clearly at odds with my reality. So, just to be sure, I set up a test for this.

Consider the code pasted in below. It’s a simple implementation of the technique you’ve described. I added this code to an newly created project and:

• Implemented updateUI() to update a pair of labels with the counts

• Added three buttons that call printToStdout(), printToStderr(), and logWithLogger()

I used Xcode to build and run this on my iOS test device running 16.7. I then stopped it and ran it again from the Home screen. Finally, I tapped all three buttons. The stdout and stderr buttons updated the labels. The Logger button did not.

I’ve no idea how you’re main app is capturing Logger output on iOS 16. I suspect that you, or one of the libraries you’re using, is doing something unsupported to enable this.

My advice is that you create a small test app with the code below to verify my results. I expect you’ll see the same results as me. If not, we should talk some more (-:

If you do see the same results as me, you can then compare your test app with your main app to see why they behave differently.

And once you’ve worked out why this is working on iOS 16, we can talk about what you can do on iOS 17!

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

var pipeStdoutQ: Pipe? = nil
var pipeStderrQ: Pipe? = nil

func hookStdoutAndStderr() {
    func hook(_ fd: FileDescriptor, _ accumulate: @escaping (Int) -> Void) -> Pipe {
        let pipe = Pipe()
        let write = FileDescriptor(rawValue: pipe.fileHandleForWriting.fileDescriptor)
        _ = try! write.duplicate(as: fd)
        pipe.fileHandleForReading.readabilityHandler = { fh in
            let count = fh.availableData.count
            DispatchQueue.main.async {
                accumulate(count)
            }
        }
        return pipe
    }
    self.pipeStdoutQ = hook(.standardOutput, { self.stdoutCount += $0 })
    self.pipeStderrQ = hook(.standardError, { self.stderrCount += $0 })
}

var stdoutCount: Int = 0 { didSet {
    self.updateUI()
} }
var stderrCount: Int = 0 { didSet {
    self.updateUI()
} }

func printToStdout() {
    let msg = "stdout says Hello Cruel World! \(Date())\n"
    write(STDOUT_FILENO, msg, msg.utf8.count)
}

func printToStderr() {
    let msg = "stderr says Goodbye Cruel World! \(Date())\n"
    write(STDERR_FILENO, msg, msg.utf8.count)
}

let log = Logger(subsystem: "com.example.apple-samplecode.Test739047", category: "app")

func logWithLogger() {
    log.log("Logger says Hello Cruel World! \(Date())")
}

I want to express my gratitude for your detailed response and the effort you put into addressing my previous query. Your input is highly appreciated! :D

I implemented your provided code in a new project by simply copying and pasting it. This code offers a straightforward UI for triggering various logging events, making it easy to test different scenarios.

//
//  ContentView.swift
//  LoggingTest
//

import SwiftUI
import OSLog

struct ContentView: View {
	@StateObject private var loggerModel = LoggerModel()

    var body: some View {
        VStack {
			Spacer()
			HStack {
				VStack {
					Text("Stdout Counter")
					Text("\(loggerModel.stdoutCount)")
				}
				VStack {
					Text("Stderr Counter")
					Text("\(loggerModel.stderrCount)")
				}
			}
			Spacer()
			Button("printToStdout") {
				loggerModel.printToStdout()
			}
			Button("printToStderr") {
				loggerModel.printToStderr()
			}
			Button("logWithLogger") {
				loggerModel.logWithLogger()
			}
			Spacer()
		}
        .padding()
    }

	
}

//
//  LoggerModel.swift
//  LoggingTest
//

import Foundation
import OSLog
import System

final class LoggerModel: ObservableObject {
	@Published var stdoutCount: Int = 0
	@Published var stderrCount: Int = 0

	var pipeStdoutQ: Pipe? = nil
	var pipeStderrQ: Pipe? = nil

	init() {
		hookStdoutAndStderr()
	}

	func hookStdoutAndStderr() {
		func hook(_ fd: FileDescriptor, _ accumulate: @escaping (Int) -> Void) -> Pipe {
			let pipe = Pipe()
			let write = FileDescriptor(rawValue: pipe.fileHandleForWriting.fileDescriptor)
			_ = try! write.duplicate(as: fd)
			pipe.fileHandleForReading.readabilityHandler = { fh in
				let count = fh.availableData.count
				DispatchQueue.main.async {
					accumulate(count)
				}
			}
			return pipe
		}
		self.pipeStdoutQ = hook(.standardOutput, { self.stdoutCount += $0 })
		self.pipeStderrQ = hook(.standardError, { self.stderrCount += $0 })
	}

	func printToStdout() {
		let msg = "stdout says Hello Cruel World! \(Date())\n"
		write(STDOUT_FILENO, msg, msg.utf8.count)
	}

	func printToStderr() {
		let msg = "stderr says Goodbye Cruel World! \(Date())\n"
		write(STDERR_FILENO, msg, msg.utf8.count)
	}

	let log = Logger(subsystem: "com.example.apple-samplecode.Test739047", category: "app")

	func logWithLogger() {
		log.log("Logger says Hello Cruel World! \(Date())")
	}
}

My observations on iPadOS 16.7 are as follows:

When launching the app via the Xcode debugger:

1. App starts with Stdout Counter and Stderr Counter of 0.
2. I tap on printToStdout and launch printToStdout --> Stdout Counter has a counter of 57.
3. I tap on printToStderr and launch printToStderr --> Stderr Counter has a counter of 59.
4. I tap on logWithLogger and launch logWithLogger --> Stderr Counter has a counter of 180.

However, when the app is terminated and relaunched directly from the home screen:

1. App starts with Stdout Counter and Stderr Counter of 0.
2. I tap on printToStdout and launch printToStdout --> Stdout Counter has a counter of 57.
3. I tap on printToStderr and launch printToStderr --> Stderr Counter has a counter of 59.
4. I tap on logWithLogger and launch logWithLogger --> Stderr Counter stays at 59.

After these results, I had to double-check again on my project to see if my findings are correct based on my recent comment. And it truly seems like I, my findings were wrong. Sorry on my behalf for wasting your time :/

Based on both observations, it appears that, for the readabilityHandler to be triggered (outside of debugging), the low-level write() API is the way to go. My questions are now the following:

1. Why is it logged when using the debugger but outside (starting from the home screen) the logs coming from Logger are not invoking readabilityHandler?
2. Is there a more Swift-friendly approach to writing logs to a file, or if this method is discouraged, and if so, what alternatives might be recommended for collecting log files.

Thank you once again for your invaluable assistance and patience in addressing this matter. Your insights are greatly appreciated. And apologize again for any confusions :/

1. Why is it logged when using the debugger but outside (starting from the home screen) the logs coming from Logger are not invoking readabilityHandler?

This behaviour only makes sense from a historical perspective (-:

When you run a program under Xcode, it connects std{in,out,err} to a pseudo terminal [1]. This is what allows you to capture the output from print, respond to readline requests, and so on.

Prior to Xcode 15, Xcode was not integrated with the system log. So, if folks adopted Logger [2] they wouldn’t see any output. Needless to say, they weren’t happy about that.

To get around this the system log folks added a hack affordance for Xcode, namely the OS_ACTIVITY_DT_MODE environment variable. For more background on this, see Your Friend the System Log. This is set by Xcode, which is why you see system log entries reflected to stderr. It isn’t set when you run the app from the Home screen, which is why you don’t see the behaviour there.

With Xcode 15’s shiny new system log support we no longer need this affordance. I’m not actually sure what its final fate is, that is, whether it still actually works. Maybe one day I’ll look into that, but it’s not actually that relevant because this is feature was only ever intended to be used during development. Relying on it in production would be a mistake.

2. Is there a more Swift-friendly approach to writing logs to a file

There is no supported way to hook Logger so that it writes to a file. There are other options, although none of them are perfect [3]. I touch on this in Your Friend the System Log. Please read that through and then write back if you have follow-up questions.

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

[1] The exact behaviour is configurable in the Options tab of the scheme editor.

[2] Or one its predecessors.

[3] I don’t believe a perfect logging API is possible, because different clients prioritise different features.