wonder-mice / zf_log

Core logging library for C/ObjC/C++
MIT License
194 stars 51 forks source link

Nothing logged to syslog on iOS #41

Closed kakyoism closed 4 years ago

kakyoism commented 4 years ago

My setup

Problem

Repro

zf_log_set_tag_prefix("MyHeader");
ZF_LOGW("Hello ZF_LOG!!");
kakyoism commented 4 years ago

I wonder if this has anything to do with having ASL as the backend, syslog works for me. I've never used ASL though.

wonder-mice commented 4 years ago

See custom_output.c, it doesn’t log every where by default, you need to configure it.

wonder-mice commented 4 years ago

Also see ZF_LOG_USE_NSLOG in zf_log.c.

kakyoism commented 4 years ago

@wonder-mice Thanks for the prompt reply. I tried to port the custom_output.c into a barebone iOS app.


//
// ViewController.h
//

#import "ViewController.h"

#include <assert.h>
#if defined(_WIN32) || defined(_WIN64)
    #include <windows.h>
    #define OUTPUT_DEBUG_STRING
#else
    #include <syslog.h>
    #define OUTPUT_SYSLOG
#endif
#include <zf_log.h>

#ifdef OUTPUT_SYSLOG
static int syslog_level(const int lvl)
{
    switch (lvl)
    {
    case ZF_LOG_VERBOSE:
        return LOG_DEBUG;
    case ZF_LOG_DEBUG:
        return LOG_DEBUG;
    case ZF_LOG_INFO:
        return LOG_INFO;
    case ZF_LOG_WARN:
        return LOG_WARNING;
    case ZF_LOG_ERROR:
        return LOG_ERR;
    case ZF_LOG_FATAL:
        return LOG_EMERG;
    default:
        assert(!"can't be");
        return LOG_EMERG;
    }
}
#endif

static void custom_output_callback(const zf_log_message *msg, void *arg)
{
    (void)arg;
    /* p points to the log message end. By default, message is not terminated
     * with 0, but it has some space allocated for EOL area, so there is always
     * some place for terminating zero in the end (see ZF_LOG_EOL_SZ define in
     * zf_log.c).
     */
    *msg->p = 0;
#if defined(OUTPUT_DEBUG_STRING)
    OutputDebugStringA(msg->buf);
#elif defined(OUTPUT_SYSLOG)
    syslog(syslog_level(msg->lvl), "%s", msg->buf);
#else
    #error Unsupported platform
#endif
}

- (void)viewDidLoad {
    [super viewDidLoad];
    // Do any additional setup after loading the view.
    #if defined(OUTPUT_SYSLOG)
        openlog("custom_output", LOG_CONS|LOG_PERROR|LOG_PID, LOG_USER);
    #endif

    const unsigned put_mask =
    #if defined(OUTPUT_SYSLOG)
        ZF_LOG_PUT_STD & !ZF_LOG_PUT_CTX;
    #else
        ZF_LOG_PUT_STD;
    #endif

    zf_log_set_output_v(put_mask, 0, custom_output_callback);

    int argc = 3;
    char* argv[] = {"myprogram", "myparam1", "myparam2"};
    ZF_LOGI("KAKYO: INFO: Number of arguments goes into custom output: %i", argc);
    ZF_LOGW("KAKYO: WARNING: Number of arguments goes into custom output: %i", argc);
    ZF_LOGE("KAKYO: ERROR: Number of arguments goes into custom output: %i", argc);
    ZF_LOGI_MEM(argv, argc * sizeof(*argv), "and argv pointers as well:");

    #if defined(OUTPUT_SYSLOG)
        closelog();
    #endif
}

All the helpers have been copied into the same source files, and the program runs without crashing.

However, I still don't see anything related to the logging code in the syslog, i.e., the one associated with my iPhone OS, viewed from Console.app on macOS.

Could you explain what exactly I should see? Right now what I can see are a few lines in the Xcode console:

2019-11-14 19:44:24.535668+0800 hello_zflog[5268:1548106] 
2019-11-14 19:44:27.165700+0800 hello_zflog[5268:1548106] 
2019-11-14 19:44:28.116835+0800 hello_zflog[5268:1548106] 
2019-11-14 19:44:28.861495+0800 hello_zflog[5268:1548106] 

They clearly correspond to my ZF_LOG calls, but the messages don't look like what I feed the API calls.

kakyoism commented 4 years ago

Progress: I can finally see it.

I modified the callback to using msg->msg_b, and force showing everything.

#import "ViewController.h"

#include <assert.h>
#if defined(_WIN32) || defined(_WIN64)
    #include <windows.h>
    #define OUTPUT_DEBUG_STRING
#else
    #include <syslog.h>
    #define OUTPUT_SYSLOG
#endif
#include <zf_log.h>

#ifdef OUTPUT_SYSLOG
static int syslog_level(const int lvl)
{
    switch (lvl)
    {
    case ZF_LOG_VERBOSE:
        return LOG_DEBUG;
    case ZF_LOG_DEBUG:
        return LOG_DEBUG;
    case ZF_LOG_INFO:
        return LOG_INFO;
    case ZF_LOG_WARN:
        return LOG_WARNING;
    case ZF_LOG_ERROR:
        return LOG_ERR;
    case ZF_LOG_FATAL:
        return LOG_EMERG;
    default:
        assert(!"can't be");
        return LOG_EMERG;
    }
}
#endif

static void custom_output_callback(const zf_log_message *msg, void *arg)
{
    (void)arg;
    /* p points to the log message end. By default, message is not terminated
     * with 0, but it has some space allocated for EOL area, so there is always
     * some place for terminating zero in the end (see ZF_LOG_EOL_SZ define in
     * zf_log.c).
     */
    *msg->p = 0;
#if defined(OUTPUT_DEBUG_STRING)
    OutputDebugStringA(msg->buf);
#elif defined(OUTPUT_SYSLOG)
    syslog(syslog_level(msg->lvl), "%s", msg->msg_b);
#else
    #error Unsupported platform
#endif
}

//
// main
//

@interface ViewController ()

@end

@implementation ViewController

- (void)viewDidLoad {
    [super viewDidLoad];
    // Do any additional setup after loading the view.
//    #if defined(OUTPUT_SYSLOG)
//        openlog("custom_output", LOG_CONS|LOG_PERROR|LOG_PID, LOG_USER);
//    #endif

    const unsigned put_mask = ZF_LOG_PUT_STD;

    zf_log_set_output_v(put_mask, 0, custom_output_callback);

    int argc = 3;
    char* argv[3] = {"myprogram", "myparam1", "myparam2"};
    ZF_LOGI("ME: INFO: Number of arguments goes into custom output: %i", argc);
    ZF_LOGW("ME: WARNING: Number of arguments goes into custom output: %i", argc);
    ZF_LOGE("ME: ERROR: Number of arguments goes into custom output: %i", argc);
    ZF_LOGI_MEM(argv, argc * sizeof(*argv), "and argv pointers as well:");

//    #if defined(OUTPUT_SYSLOG)
//        closelog();
//    #endif
}

this brings me to expected messages in Xcode console, and Console.app under my phone's name. But it takes a few seconds to show up, which was probably because the existing syslog is too big and takes a while to load up.

2019-11-14 20:18:24.768797+0800 hello_zflog[5304:1559498] KAKYO: INFO: Number of arguments goes into custom output: 3
2019-11-14 20:18:24.768957+0800 hello_zflog[5304:1559498] KAKYO: WARNING: Number of arguments goes into custom output: 3
2019-11-14 20:18:24.769110+0800 hello_zflog[5304:1559498] KAKYO: ERROR: Number of arguments goes into custom output: 3
2019-11-14 20:18:24.769210+0800 hello_zflog[5304:1559498] and argv pointers as well:
2019-11-14 20:18:24.769287+0800 hello_zflog[5304:1559498] 9aa4b80001000000a4a4b80001000000ada4b80001000000                  ????????????????????????