ios - print - ¿Por qué el ajuste de os_log() hace que los dobles no se registren correctamente?

swift print console log

Question

Considere el siguiente ejemplo:

import Foundation
import os.log

class OSLogWrapper {

    func logDefault(_ message: StaticString, _ args: CVarArg...) {
        os_log(message, type: .default, args)
    }

    func testWrapper() {
        logDefault("WTF: %f", 1.2345)
    }
}

Si creo una nueva instancia de OSLogWrapper y llamo a testWrapper()

let logger = OSLogWrapper()
logger.testWrapper()

Obtengo la siguiente salida en la consola Xcode:

2018-06-19 18:21:08.327979-0400 WrapperWTF[50240:548958] WTF: 0.000000

He comprobado todo lo que se me ocurre y no puedo hacer caso de lo que está mal aquí. Revisar la documentación no es nada útil.

¡Gracias por la ayuda!

Answer 1

Como mencioné en mi comentario a la respuesta de Rob Mayoff, para cualquiera que experimente el mismo tipo de problema con os_signpost() , aquí hay una clase de envoltorio que os_signpost() respecto:

import Foundation
import os
import _SwiftOSOverlayShims

public final class Signpost {

    private final let log: OSLog

    public init(log: OSLog) {
        self.log = log
    }

    public final func begin(name: StaticString, idObject: AnyObject? = nil) {
        if #available(iOS 12.0, *) {
            signpost(.begin, name: name, idObject: idObject)
        }
    }

    public final func begin(name: StaticString, idObject: AnyObject? = nil, _ format: StaticString, _ arguments: CVarArg...) {
        if #available(iOS 12.0, *) {
            signpost(.begin, name: name, idObject: idObject, format, arguments)
        }
    }

    public final func event(name: StaticString, idObject: AnyObject? = nil) {
        if #available(iOS 12.0, *) {
            signpost(.event, name: name, idObject: idObject)
        }
    }

    public final func event(name: StaticString, idObject: AnyObject? = nil, _ format: StaticString, _ arguments: CVarArg...) {
        if #available(iOS 12.0, *) {
            signpost(.event, name: name, idObject: idObject, format, arguments)
        }
    }

    public final func end(name: StaticString, idObject: AnyObject? = nil) {
        if #available(iOS 12.0, *) {
            signpost(.end, name: name)
        }
    }

    public final func end(name: StaticString, idObject: AnyObject? = nil, _ format: StaticString, _ arguments: CVarArg...) {
        if #available(iOS 12.0, *) {
            signpost(.end, name: name, idObject: idObject, format, arguments)
        }
    }

    @available(iOS 12.0, *)
    private final func signpost(_ type: OSSignpostType, name: StaticString, idObject: AnyObject? = nil) {
        guard log.signpostsEnabled else { return }
        let signpostID = getSignpostId(forObject: idObject)
        os_signpost(type, log: log, name: name, signpostID: signpostID)
    }

    @available(iOS 12.0, *)
    private final func signpost(
        _ type: OSSignpostType,
        dso: UnsafeRawPointer = #dsohandle,
        name: StaticString,
        idObject: AnyObject? = nil,
        _ format: StaticString,
        _ arguments: [CVarArg])
    {
        // This crazy mess is because [CVarArg] gets treated as a single CVarArg and repassing a CVarArg... actually passes a [CVarArg]
        // This was copied from the publicly available Swift source code at https://github.com/apple/swift/blob/master/stdlib/public/SDK/os/os_signpost.swift#L40
        // THIS IS A HACK
        guard log.signpostsEnabled else { return }
        let signpostID = getSignpostId(forObject: idObject)
        guard signpostID != .invalid && signpostID != .null else { return }
        let ra = _swift_os_log_return_address()
        name.withUTF8Buffer { (nameBuf: UnsafeBufferPointer<UInt8>) in
            // Since dladdr is in libc, it is safe to unsafeBitCast
            // the cstring argument type.
            nameBuf.baseAddress!.withMemoryRebound(to: CChar.self, capacity: nameBuf.count) { nameStr in
                format.withUTF8Buffer { (formatBuf: UnsafeBufferPointer<UInt8>) in
                    // Since dladdr is in libc, it is safe to unsafeBitCast
                    // the cstring argument type.
                    formatBuf.baseAddress!.withMemoryRebound(to: CChar.self, capacity: formatBuf.count) { formatStr in
                        withVaList(arguments) { valist in
                            _swift_os_signpost_with_format(dso, ra, log, type, nameStr, signpostID.rawValue, formatStr, valist)
                        }
                    }
                }
            }
        }
    }

    @available(iOS 12.0, *)
    private final func getSignpostId(forObject idObject: AnyObject?) -> OSSignpostID {
        if let idObject = idObject {
            return OSSignpostID(log: log, object: idObject)
        }
        return .exclusive
    }
}

Answer 2

El compilador implementa los argumentos variadic convirtiendo cada argumento al tipo variadic declarado, empaquetándolos en una Array de ese tipo y pasando esa matriz a la función variadic. En el caso de testWrapper , el tipo de variable declarado es CVarArg , por lo que cuando testWrapper llama a logDefault , esto es lo que sucede bajo las cubiertas: testWrapper 1.2345 a un CVarArg , crea un Array<CVarArg> y lo pasa a logDefault como args .

Luego, logDefault llama a os_log y le pasa ese Array<CVarArg> como argumento. Este es el error en su código. El error es bastante sutil. El problema es que os_log no toma un argumento Array<CVarArg> ; os_log es en sí mismo variadic sobre CVarArg . Así que Swift convierte args (un Array<CVarArg> ) a CVarArg , y pega a CVarArg en otro Array<CVarArg> . La estructura se ve así:

Array<CVarArg> created in `logDefault`
  |
  +--> CVarArg (element at index 0)
         |
         +--> Array<CVarArg> (created in `testWrapper`)
                |
                +--> CVarArg (element at index 0)
                       |
                       +--> 1.2345 (a Double)

Luego, logDefault pasa esta nueva Array<CVarArg> a os_log . Entonces, le está pidiendo a os_log que formatee su primer elemento, que es (más o menos) un Array<CVarArg> , usando %f , que es una tontería, y resulta que obtiene 0.000000 como resultado. (Digo "más o menos" porque aquí hay algunas sutilezas que explico más adelante).

Entonces, logDefault pasa su Array<CVarArg> entrante Array<CVarArg> como uno de los muchos parámetros variad potencialmente a os_log , pero lo que realmente quiere que logDefault haga es pasar esa Array<CVarArg> entrante Array<CVarArg> como el conjunto completo de parámetros os_log a os_log , sin ningún cambio envolviendolo Esto a veces se llama "argumento splatting" en otros idiomas.

Lamentablemente para usted, Swift aún no tiene una sintaxis para la distribución de argumentos. Se ha discutido más de una vez en Swift-Evolution ( en este hilo, por ejemplo ), pero aún no hay una solución en el horizonte.

La solución habitual para este problema es buscar una función complementaria que tome los argumentos variadic ya agrupados como un solo argumento. A menudo, el acompañante tiene una v agregada al nombre de la función. Ejemplos:

• printf (variadic) y vprintf (toma un va_list , el equivalente de C de Array<CVarArg> )
• NSLog (variadic) y NSLogv (toma un va_list )
• -[NSString initWithFormat:] (variadic) y -[NSString WithFormat:arguments:] (toma una va_list )

Así que puedes ir buscando un os_logv . Lamentablemente, no encontrarás uno. No hay un complemento documentado de os_log que tome argumentos pre-empaquetados.

Tienes dos opciones en este punto:

• os_log envolver os_log en su propio envoltorio variadic, porque simplemente no hay una buena manera de hacerlo, o

• Sigue el consejo de Kamran (en su comentario sobre tu pregunta) y usa %@ lugar de %f . Pero tenga en cuenta que solo puede tener un único %@ (y ningún otro especificador de formato) en su cadena de mensajes, porque solo está pasando un solo argumento a os_log . La salida se ve así:

  2018-06-20 02:22:56.132704-0500 test[39313:6086331] WTF: (
      "1.2345"
  )

También puede presentar un radar de solicitud de mejora en https://bugreport.apple.com solicitando una función os_logv , pero no debe esperar que se implemente pronto.

Eso es todo. Haga una de esas dos cosas, tal vez un radar y siga adelante con su vida. Seriamente. Deja de leer aquí. No hay nada bueno después de esta línea.

De acuerdo, seguiste leyendo. Echemos un vistazo debajo del capó de os_log . Resulta que la implementación de la función Swift os_log es parte del código fuente público de Swift :

@_exported import os
@_exported import os.log
import _SwiftOSOverlayShims

@available(macOS 10.14, iOS 12.0, watchOS 5.0, tvOS 12.0, *)
public func os_log(
  _ type: OSLogType,
  dso: UnsafeRawPointer = #dsohandle,
  log: OSLog = .default,
  _ message: StaticString,
  _ args: CVarArg...)
{
  guard log.isEnabled(type: type) else { return }
  let ra = _swift_os_log_return_address()

  message.withUTF8Buffer { (buf: UnsafeBufferPointer<UInt8>) in
    // Since dladdr is in libc, it is safe to unsafeBitCast
    // the cstring argument type.
    buf.baseAddress!.withMemoryRebound(
      to: CChar.self, capacity: buf.count
    ) { str in
      withVaList(args) { valist in
        _swift_os_log(dso, ra, log, type, str, valist)
      }
    }
  }
}

Así que resulta que hay una versión de os_log , llamada _swift_os_log , que toma argumentos pre-empaquetados. El envoltorio Swift usa withVaList (que está documentado) para convertir el Array<CVarArg> en una va_list y lo pasa a _swift_os_log , que también es parte del código fuente público de Swift . No me molestaré en citar su código aquí porque es largo y en realidad no necesitamos verlo.

De todos modos, aunque no esté documentado, podemos llamar a _swift_os_log . Básicamente podemos copiar el código fuente de os_log y convertirlo en su función logDefault :

func logDefaultHack(_ message: StaticString, dso: UnsafeRawPointer = #dsohandle, _ args: CVarArg...) {
    let ra = _swift_os_log_return_address()
    message.withUTF8Buffer { (buf: UnsafeBufferPointer<UInt8>) in
        buf.baseAddress!.withMemoryRebound(to: CChar.self, capacity: buf.count) { str in
            withVaList(args) { valist in
                _swift_os_log(dso, ra, .default, .default, str, valist)
            }
        }
    }
}

Y funciona. Código de prueba:

func testWrapper() {
    logDefault("WTF: %f", 1.2345)
    logDefault("WTF: %@", 1.2345)
    logDefaultHack("Hack: %f", 1.2345)
}

Salida:

2018-06-20 02:22:56.131875-0500 test[39313:6086331] WTF: 0.000000
2018-06-20 02:22:56.132704-0500 test[39313:6086331] WTF: (
    "1.2345"
)
2018-06-20 02:22:56.132807-0500 test[39313:6086331] Hack: 1.234500

¿Recomendaría esta solución? No. Demonios no. Las os_log internas de os_log son un detalle de implementación y es probable que cambien en futuras versiones de Swift. Así que no confíes en ellos de esta manera. Pero es interesante mirar debajo de las sábanas de todos modos.

Una última cosa. ¿Por qué el compilador no se queja de convertir Array<CVarArg> a CVarArg ? ¿Y por qué funciona la sugerencia de Kamran (de usar %@ )?

Resulta que estas preguntas tienen la misma respuesta: es porque Array es "puenteable" a un objeto Objective-C. Específicamente:

• Foundation (en las plataformas Apple) hace que Array ajuste al protocolo _ObjectiveCBridgeable . Implementa el enlace de Array a Objective-C devolviendo un NSArray .

• Foundation también hace que Array ajuste al protocolo CVarArg .

• La función withVaList le pide a cada CVarArg que se convierta a su _cVarArgEncoding .

• La implementación predeterminada de _cVarArgEncoding , para un tipo que se ajusta tanto a _ObjectiveCBridgeable como a CVarArg , devuelve el objeto Objective-C puente.

• La conformidad de Array a CVarArg significa que el compilador no se quejará de (silenciosamente) convertir un Array<CVarArg> en un CVarArg y CVarArg en otro Array<CVarArg> .

Esta conversión silenciosa suele ser un error (como lo fue en su caso), por lo que sería razonable que el compilador advirtiera al respecto y le permitiera silenciar la advertencia con un lanzamiento explícito (por ejemplo, args as CVarArg ). Puede presentar un informe de error en https://bugs.swift.org si lo desea.