An Sample Code for threads control - A Wrap for service/thread start/stop/periodical run

multi-thread programming設計很常見, 寫法上與功能上也都很相似, 最基本的幾個操作就是, create/start/stop/periodical run/destroy等等. 最好還能monitor這些thread狀況, 比如被執行幾次, 執行時間多久, 是否有dead lock等等, 於是就寫了這個pattern, 提供這類功能.

service-reg.h

#ifndef SERVICE_REG_H
#define SERVICE_REG_H
#include <sys/time.h>

typedef void *(*srv_fp) (void *);

char * srv_dump(char *buf, int sz);

int _srv_reg(char *srv_name, srv_fp fp, char *fp_name, void *srv_data);
#define srv_reg(srv_name, fp, srv_data) _srv_reg(srv_name, fp, #fp, srv_data)
int srv_start(char *srv_name); // run forever without any delay
int srv_stop(char *srv_name);
int srv_unreg(char *srv_name);
int srv_start_periodical(char *srv_name, unsigned long sec, unsigned long nsec); // run forever with delay

#define SRV_NO_MEM -1

#endif

service-reg.c

#include <pthread.h>
#include <string.h>
#include <stdio.h>
#include <stdlib.h>
#include <unistd.h>
#include <errno.h>
#include <ctype.h>
#include <time.h>
#include <sys/time.h>
#include <sys/timerfd.h>
#include <stdint.h>
#include <unistd.h>
#include "service-reg.h"
#include "lookup_table.h"

#define SEC2NSEC 1000000000.0

struct srv_info {
    void *srv_data;
    char *srv_name;
    srv_fp fp;
    int in_fp;
    char *fp_name;
    unsigned run_cnt;
    pthread_t thread_id; /* ID returned by pthread_create() */
    pthread_cond_t cond;
    pthread_mutex_t mutex;
    struct srv_info *next;
    volatile int running; /* 1 for running, 0 for stop */
    struct timespec active_time;
    struct timespec last_enter;
    struct timespec last_exit;
    int tm_fd; /* used to delay */
};

struct srv_tab {
    pthread_mutex_t mutex;
    struct srv_info *list;
    unsigned int num_srv;
} srv_tab = {
    .mutex = PTHREAD_MUTEX_INITIALIZER,
    .list = NULL,
    .num_srv = 0,
};

static void _srv_update_active_time(struct srv_info *s)
{
    clock_gettime(CLOCK_MONOTONIC, &(s->last_exit));

    s->active_time.tv_sec += s->last_exit.tv_sec - s->last_enter.tv_sec;
    if (s->last_exit.tv_nsec > s->last_enter.tv_nsec) {
        s->active_time.tv_nsec += s->last_exit.tv_nsec - s->last_enter.tv_nsec;
    } else {
        s->active_time.tv_sec--;
        s->active_time.tv_nsec += SEC2NSEC + s->last_exit.tv_nsec - s->last_enter.tv_nsec;
    }

    if (s->active_time.tv_nsec >= SEC2NSEC) {
        s->active_time.tv_nsec -= SEC2NSEC;
        s->active_time.tv_sec++;
    }
}

static void *_srv_wrap(void *v)
{
    struct srv_info *s = (struct srv_info *) v;
    while (1) {
recheck:
        if (s->running == 0) {
stoprun:
            pthread_cond_wait(&(s->cond), &(s->mutex));
            goto recheck;
        }

        /* if timer is enabled, than wait */
again:
        if (s->tm_fd != -1) {
            uint64_t exp;
            ssize_t sz;
            sz = read(s->tm_fd, &exp, sizeof(exp));
            if (sz != sizeof(exp)) {
                printf("timerfd_settime failed: s->tm_fd:%d, errno:%d/%s\n",
                            s->tm_fd, errno, strerror(errno));
                if (errno == EINTR) {
                    goto again;
                }
            }

            if (s->running == 0) {
                goto stoprun;
            }
        }

        clock_gettime(CLOCK_MONOTONIC, &(s->last_enter));
        s->in_fp = 1;
        s->fp(s->srv_data);
        s->in_fp = 0;
        _srv_update_active_time(s);
        s->run_cnt++;
    }
    return NULL;
}

int srv_init(void)
{
    return 0;
}

char * srv_dump(char *buf, int sz)
{
    struct srv_info *s;
    char *p = buf;
    int i = 0;
    struct timespec cur_clk;
    struct itimerspec cur_timer;

    clock_gettime(CLOCK_MONOTONIC, &cur_clk);

    if (buf == NULL) {
        return NULL;
    }

    memset(buf, 0, sz);
    pthread_mutex_lock(&(srv_tab.mutex));
    s = srv_tab.list;

    p += snprintf(p, sz - (buf - p), "cur-clk: %f\n", cur_clk.tv_sec + cur_clk.tv_nsec/SEC2NSEC);
    p += snprintf(p, sz - (buf - p), "id   srv_name    running/in_fp\t\tfp/fname/dp\n");
    p += snprintf(p, sz - (buf - p), "\t\t\trun-cnt/run-time\tenter-clk/leave-clk\n");
    p += snprintf(p, sz - (buf - p), "\t\t\ttm_fd/next_expir/perodic\n");
    while (s != NULL) {
        p += snprintf(p, sz - (buf - p), "%-8d%-16s%2d/%-2d\t\t%16p/%s/%-16p\t\t\t\n",
                        i++, s->srv_name, s->running, s->in_fp, s->fp, s->fp_name, s->srv_data);
        p += snprintf(p, sz - (buf - p), "\t\t   %10d/%-12f\t%12f/%-12f\n",
                        s->run_cnt,
                        s->active_time.tv_sec + s->active_time.tv_nsec/SEC2NSEC,
                        s->last_enter.tv_sec + s->last_enter.tv_nsec/SEC2NSEC,
                        s->last_exit.tv_sec + s->last_exit.tv_nsec/SEC2NSEC);
        if (s->tm_fd != -1) {
            if (timerfd_gettime(s->tm_fd, &cur_timer) < 0) {
                printf("timerfd_get failed: errno:%d/%s\n", errno, strerror(errno));
                p += snprintf(p, sz - (buf - p), "\t\t   %6d\n", s->tm_fd);
            } else {
                p += snprintf(p, sz - (buf - p), "\t\t   %6d/%f/%-16f\n",
                                s->tm_fd, cur_timer.it_value.tv_sec + cur_timer.it_value.tv_nsec/SEC2NSEC,
                                cur_timer.it_interval.tv_sec + cur_timer.it_interval.tv_nsec/SEC2NSEC);
            }
        }
        s = s->next;
    }
    pthread_mutex_unlock(&(srv_tab.mutex));
    return buf;
}

int _srv_reg(char *srv_name, srv_fp fp, char *fp_name, void *srv_data)
{
    struct srv_info *s = (struct srv_info *) malloc(sizeof(struct srv_info));
    if (s == NULL) {
        return SRV_NO_MEM;
    }
    memset(s, 0, sizeof(struct srv_info));
    s->fp = fp;
    s->srv_data = srv_data;
    s->srv_name = strdup(srv_name);
    s->fp_name = strdup(fp_name);
    pthread_cond_init(&s->cond, NULL);
    pthread_mutex_init(&s->mutex, NULL);
    s->tm_fd = -1;

    if (!s->srv_name) {
        free(s);
        return SRV_NO_MEM;
    }

    /* insert into tab */
    pthread_mutex_lock(&(srv_tab.mutex));
    s->next = srv_tab.list;
    srv_tab.list = s;
    srv_tab.num_srv++;
    pthread_mutex_unlock(&(srv_tab.mutex));

    /* create the thread */
    pthread_create(&s->thread_id, NULL , _srv_wrap, s);
    return 0;
}

static int _srv_update_timer(struct srv_info *s, unsigned long sec, unsigned long nsec)
{
    struct timespec now_tm;
    struct itimerspec new_tm;

    if (s->tm_fd < 0) {
        s->tm_fd = timerfd_create(CLOCK_MONOTONIC, 0);
        if (s->tm_fd < 0) {
            printf("timerfd_create failed: errno:%d/%s\n", errno, strerror(errno));
            return -1;
        }
    }

    if (clock_gettime(CLOCK_MONOTONIC, &now_tm) == -1) {
        printf("timerfd_create failed: errno:%d/%s\n", errno, strerror(errno));
        return -1;
    }

    new_tm.it_value.tv_sec = now_tm.tv_sec + sec;
    new_tm.it_value.tv_nsec = now_tm.tv_nsec + nsec;

    new_tm.it_interval.tv_sec = sec;
    new_tm.it_interval.tv_nsec = nsec;

    if (timerfd_settime(s->tm_fd, TFD_TIMER_ABSTIME, &new_tm, NULL) < 0) {
        printf("timerfd_settime failed: errno:%d/%s\n", errno, strerror(errno));
        return -1;
    }

    return 0;
}

inline static int _srv_name_equal(struct srv_info *s, char *srv_name)
{
    return strlen(s->srv_name) == strlen(srv_name) && !strcmp(s->srv_name, srv_name);
}

static int _srv_set_running(char *srv_name, int running, unsigned long sec, unsigned long nsec)
{
    struct srv_info *s;
    int ret = 0;

    pthread_mutex_lock(&(srv_tab.mutex));
    s = srv_tab.list;
    while (s != NULL) {
        if (_srv_name_equal(s, srv_name)) {
            s->running = running;
            if (sec || nsec) {
                ret = _srv_update_timer(s, sec, nsec);
            } else {
                /* reset timer to zero */
                _srv_update_timer(s, 0, 0);
                /* clear timer */
                close(s->tm_fd);
                s->tm_fd = -1;
            }
            pthread_cond_signal(&s->cond);
            pthread_mutex_unlock(&(srv_tab.mutex));
            return ret;
        }
        s = s->next;
    }
    pthread_mutex_unlock(&(srv_tab.mutex));

    return -1;
}

int srv_start(char *srv_name)
{
    return _srv_set_running(srv_name, 1 /* running */, 0 /* delay.sec */, 0 /* delay.nsec */);
}

int srv_stop(char *srv_name)
{
    return _srv_set_running(srv_name, 0 /* running */, 0 /* delay.sec */, 0 /* delay.nsec */);
}

static int _srv_free(struct srv_info *s)
{
    int ret;
    s->running = 0;

    /* cancel the thread */
    ret = pthread_cancel(s->thread_id);
    if (ret != 0) {
        printf("pthread_cancel failed: %d/%d\n", ret, errno);
        /* FIXME */
    }

    ret = pthread_join(s->thread_id, NULL);
    if (ret != 0) {
        printf("pthread_join failed: %d/%d\n", ret, errno);
        /* FIXME */
    }

    /* free resouce */
    pthread_cond_destroy(&(s->cond));
    pthread_mutex_destroy(&(s->mutex));
    free(s->srv_name);
    free(s->fp_name);
    if (s->tm_fd != -1) {
        close(s->tm_fd);
    }
    free(s);
    return ret;
}

int srv_unreg(char *srv_name)
{
    struct srv_info **s, *sn = NULL;
    int ret;
    s = &(srv_tab.list);
    pthread_mutex_lock(&(srv_tab.mutex));
    while ((*s) != NULL) {
        if (_srv_name_equal(*s, srv_name)) {
            sn = *s;
            *s = (*s)->next;
            srv_tab.num_srv--;
            break;
        }
        s = &((*s)->next);
    }
    pthread_mutex_unlock(&(srv_tab.mutex));
    if (sn) {
        ret = _srv_free(sn);
    }

    return 0;
}

int srv_start_periodical(char *srv_name, unsigned long sec, unsigned long nsec)
{
    return _srv_set_running(srv_name, 1 /* running */, sec /* delay.sec */,  nsec /* delay.nsec */);
}

main.c (test program)

#include <stdio.h>
#include <stdlib.h>
#include <unistd.h>
#include <time.h>
#include <stdarg.h>
#include "service-reg.h"

int pr(const char *fmt, ...)
{
    va_list ap;
    int ret;
    struct timespec cur_clk;
    clock_gettime(CLOCK_MONOTONIC, &cur_clk);

    printf("***CLK: %f\n", cur_clk.tv_sec + cur_clk.tv_nsec/1000000000.0);
    va_start(ap, fmt);
    ret = vprintf(fmt, ap);
    va_end(ap);
    return ret;
}

void *sms_service(void *v)
{
    int *i = (int *) v;
    pr("   ->hello, %p/%d, srv_start_periodical %d\n", v, (*i)++, 2);
    pr("   ->%d\n", srv_start_periodical("brook", 2, 0));
}

int main(int argc, char *argv[])
{
    int i = 0, data = 0, ret;
    char name[] = "brook", buf[1024];

    pr("srv_reg %s\n", name);
    srv_reg(name, sms_service, (void*)&data);

    pr("srv_start %s\n", name);
    srv_start(name);

    pr("sleep 3\n");
    sleep(3);
    sleep(3);

    pr("srv_stop %s\n", name);
    srv_stop(name);

    pr("srv_start_periodical %s with %dsec\n", name, 1);
    srv_start_periodical(name, 1, 0);

    pr("srv_dump %s\n", name);
    pr("%s\n", srv_dump(buf, sizeof(buf)));

    pr("sleep 2\n");
    sleep(2);

    pr("srv_unreg %s\n", name);
    srv_unreg(name);

    pr("over\n");
    return 0;
}

執行結果

brook@vista:~$ ./service-reg
***CLK: 7914669.498393
srv_reg brook
***CLK: 7914669.498469
srv_start brook
***CLK: 7914669.498481
sleep 3
***CLK: 7914669.498531
        ->hello, 0x7ffc24e80df8/0, srv_start_periodical 2
***CLK: 7914669.498541
        ->0
***CLK: 7914671.498595
        ->hello, 0x7ffc24e80df8/1, srv_start_periodical 2
***CLK: 7914671.498647
        ->0
***CLK: 7914672.498576
srv_stop brook
***CLK: 7914672.498599
srv_start_periodical brook with 1sec
***CLK: 7914672.498606
srv_dump brook
***CLK: 7914672.498621
        ->hello, 0x7ffc24e80df8/2, srv_start_periodical 2
***CLK: 7914672.498662
        ->0
***CLK: 7914672.498625
cur-clk: 7914672.498611
id      srv_name        running/in_fp           fp/fname/dp
                        run-cnt/run-time        enter-clk/leave-clk
                        tm_fd/next_expir/perodic
0       brook            1/0                    0x40106f/sms_service/0x7ffc24e80df8
                            2/0.000082          7914671.498594/7914671.498656
                        3/0.999982/1.000000

***CLK: 7914672.498680
sleep 2
***CLK: 7914674.498698
        ->hello, 0x7ffc24e80df8/3, srv_start_periodical 2
***CLK: 7914674.498730
        ->0
***CLK: 7914674.498742
srv_unreg brook
***CLK: 7914674.498997
over

An Sample Code for Syslogd - A log pattern with categorize, level and format II

這一篇是根據An Sample Code for Syslogd - A log pattern with categorize, level and format的變形, 主要是針對某些log屬於多重類型(type)的設計, 主要差異用了標記為紅色

brook-log.h

#ifndef _LOG_H_
#define _LOG_H_
#include <syslog.h>
#include <unistd.h>
#include <sys/syscall.h>

/*************************************************
 * TYPE
 *************************************************/
enum log_type {
/* 這裡我先設定有三個類別，分別為AT，CORE與DB，之後請自行新增刪減修改 */
    LOG_TYPE_AT,
    LOG_TYPE_CORE,
    LOG_TYPE_DB,
    LOG_TYPE_MAX
};

#define LOG_TYPE_BIT(t) (1 << (LOG_TYPE_##t))

/***** internal function for MACRO used *****/
void _log_type_toggle(enum log_type type);
void _log_type_clr(enum log_type type);
void _log_type_set(enum log_type type);

/***** public function to enable/disable log on certain type *****/
#define log_type_toggle(type) _log_type_toggle(LOG_TYPE_##type)
#define log_type_clr(type) _log_type_clr(LOG_TYPE_##type)
#define log_type_set(type) _log_type_set(LOG_TYPE_##type)

char *get_log_type_status(void);


/*************************************************
 * Format
 *************************************************/
enum log_fmt {
    LOG_FMT_FUNC_AND_LINE,
    LOG_FMT_TID, ///<thread ID.
    LOG_FMT_LOG_TYPE,
    LOG_FMT_LOG_LEVEL,
    LOG_FMT_MAX,
};

/***** internal function for MACRO used *****/
void _log_fmt_toggle(enum log_fmt fmt);
void _log_fmt_set(enum log_fmt fmt);
void _log_fmt_clr(enum log_fmt fmt);
int _log_fmt_is_set(enum log_fmt fmt);

/***** public function to enable/disable certain format type *****/
#define log_fmt_toggle(fmt) _log_fmt_toggle(LOG_FMT_##fmt)
#define log_fmt_set(fmt) _log_fmt_set(LOG_FMT_##fmt)
#define log_fmt_clr(fmt) _log_fmt_clr(LOG_FMT_##fmt)
#define log_fmt_is_set(fmt) _log_fmt_is_set(LOG_FMT_##fmt)


/*************************************************
 * Level
 *************************************************/
/***** internal function for MACRO used *****/
int _log_type_level_is(enum log_type type, int *level);
int _log_type_level_set(enum log_type type, int level);

/***** public function to set debug level. the level is leveraged from syslog *****/
#define log_type_level_is(type, level) _log_type_level_is(LOG_TYPE_##type, level)
#define log_type_level_set(type, level) _log_type_level_set(LOG_TYPE_##type, LOG_##level)

void log_pr(int type, int level, char const *const fmt,...);

const char *log_type_str(int type);
#define _log_pr(type, level, fmt, ...)                 \
do {                                                    \
        unsigned char func[36] = {}, tid[16] = {}, tp[16] = {}, lv[16] = {};\
        if (log_fmt_is_set(FUNC_AND_LINE)) {    \
                snprintf(func, sizeof(func) - 1, "%s(#%d), ", __FUNCTION__, __LINE__);   \
        }                                               \
                                                        \
        if (log_fmt_is_set(TID)) {              \
                snprintf(tid, sizeof(tid) - 1, "TID:%ld, ", getpid());       \
        }                                               \
                                                        \
        if (log_fmt_is_set(LOG_TYPE)) {         \
                snprintf(tp, sizeof(tp) - 1, "%s, ", log_type_str(type));     \
        }                                               \
        if (log_fmt_is_set(LOG_LEVEL)) {         \
                snprintf(tp, sizeof(lv) - 1, "%s, ", #level);     \
        }                                               \
        log_pr(type, LOG_##level, "%s%s%s%s"fmt, func, tid, tp, lv, ##__VA_ARGS__);     \
} while(0)

/***** public function *****/
/* 請呼叫下面MACRO來印log */
#define pr_emerg(type, fmt, ...)  _log_pr(type, EMERG, fmt, ##__VA_ARGS__)
#define pr_alert(type, fmt, ...)  _log_pr(type, ALERT, fmt, ##__VA_ARGS__)
#define pr_crit(type, fmt, ...)   _log_pr(type, CRIT, fmt, ##__VA_ARGS__)
#define pr_err(type, fmt, ...)    _log_pr(type, ERR, fmt, ##__VA_ARGS__)
#define pr_warn(type, fmt, ...)   _log_pr(type, WARNING, fmt, ##__VA_ARGS__)
#define pr_notice(type, fmt, ...) _log_pr(type, NOTICE, fmt, ##__VA_ARGS__)
#define pr_info(type, fmt, ...)   _log_pr(type, INFO, fmt, ##__VA_ARGS__)
#define pr_dbg(type, fmt, ...)    _log_pr(type, DEBUG, fmt, ##__VA_ARGS__)

#endif

brook-log.c

#include <stdio.h>
#include <stdarg.h>
#include <syslog.h>
#include "brook-log.h"

#define DEFAULT_LOG_TYPE ((1 << LOG_TYPE_AT) | \
   (1 << LOG_TYPE_CORE) | \
   (1 << LOG_TYPE_DB))

#define DEFAULT_LOG_FMT ((1 << LOG_FMT_FUNC_AND_LINE) | \
   (1 << LOG_FMT_TID) | \
   (1 << LOG_FMT_LOG_TYPE))

static unsigned int _log_types = DEFAULT_LOG_TYPE;
static unsigned int _log_fmts = DEFAULT_LOG_FMT;

#define DEFAULT_LOG_OPTION (LOG_CONS | LOG_NDELAY)
#define DEFAULT_LOG_FACILITY LOG_LOCAL0
#define DEFAULT_LOG_LEVEL LOG_INFO

char const *const level_str[] = {
    [LOG_EMERG] = "EMERG",
    [LOG_ALERT] = "ALERT",
    [LOG_CRIT] = "CRIT",
    [LOG_ERR] = "ERR",
    [LOG_WARNING] = "WARN",
    [LOG_NOTICE] = "NOTICE",
    [LOG_INFO] = "INFO",
    [LOG_DEBUG] = "DEBUG",
};

char const *const level_fmt_str[] = {
    [LOG_FMT_FUNC_AND_LINE] = "FUNC_AND_LINE",
    [LOG_FMT_TID] = "TID",
    [LOG_FMT_LOG_TYPE] = "LOG_TYPE",
};

#define AR_SZ(a) (sizeof(a)/sizeof(a[0]))

#define BIT_SET(_v, _b) \
do {   \
 (_v) |= (1 << (_b));\
} while(0)

#define BIT_CLR(_v, _b) \
do {   \
 (_v) &= ~(1 << (_b));\
} while(0)

#define BIT_TOGGLE(_v, _b)  \
do {    \
 (_v) ^= (1 << (_b)); \
} while(0)

int _log_fmt_is_set(enum log_fmt fmt)
{
    if (_log_fmts & (1 << fmt)) {
        return 1;
    }
    return 0;
}

void _log_fmt_set(enum log_fmt fmt)
{
    BIT_SET(_log_fmts, fmt);
}

void _log_fmt_clr(enum log_fmt fmt)
{
    BIT_CLR(_log_fmts, fmt);
}

void _log_fmt_toggle(enum log_fmt fmt)
{
    BIT_TOGGLE(_log_fmts, fmt);
}

struct log_type_str_and_level {
    char const *const name;
    int level;
} log_type_str_and_level[] = {
/* TYPE有增減，請更新這個ARRAY */
    [LOG_TYPE_AT] = { "AT", DEFAULT_LOG_LEVEL },
    [LOG_TYPE_CORE] = { "CORE", DEFAULT_LOG_LEVEL },
    [LOG_TYPE_DB] = { "DB", DEFAULT_LOG_LEVEL },
    [LOG_TYPE_MAX] = { "MAX", DEFAULT_LOG_LEVEL },
};

char const *log_type_str(int type)
{
    int i;
    char buf[64], *p;
    p = buf;
    memset(buf, 0, sizeof(buf));
    for (i = 0; i < AR_SZ(log_type_str_and_level); i++, type >>= 1) {
        if (type & 1) {
            p += snprintf(p, 64 - (p - buf), "%s/", log_type_str_and_level[i].name);
        }
    }
    return buf;
}

int _log_type_level_is(enum log_type type, int *level)
{
    if (type >= 0 && type < AR_SZ(log_type_str_and_level)) {
        *level = log_type_str_and_level[type].level;
        return 0;
    }
    return -1;
}

int _log_type_level_set(enum log_type type, int level)
{
    if (type >= 0 && type < AR_SZ(log_type_str_and_level) && level >= 0 && level <= LOG_DEBUG) {
        log_type_str_and_level[type].level = level;
        return 0;
    }
    return -1;
}

int log_type_is_set(enum log_type type)
{
    if (_log_types & (1 << type)) {
        return 1;
    }
    return 0;
}

void _log_type_set(enum log_type type)
{
    BIT_SET(_log_types, type);
}

void _log_type_clr(enum log_type type)
{
    BIT_CLR(_log_types, type);
}

void _log_type_toggle(enum log_type type)
{
    BIT_TOGGLE(_log_types, type);
}

void log_pr(int type, int level, char const *const fmt,...)
{
    va_list ap;
    int i;

    if (_log_types & type) {
        for (i = 0; i < AR_SZ(log_type_str_and_level); i++) {
            if (log_type_str_and_level[i].level >= level) {

                va_start(ap, fmt);
                vsyslog(LOG_MAKEPRI(LOG_LOCAL0, level), fmt, ap);
                va_end(ap);
                return;
            }
        }
    }
}

char *get_log_type_status_str(void)
{
    int i = 0, re_sz;
    static char buf[1024], *p;

    p = buf;
    re_sz = sizeof(buf);
    p += snprintf(p, re_sz, "%2s %-16s %-10s %-12s\r\n", "id", "type", "status", "level");

    for (i = 0; i < AR_SZ(log_type_str_and_level); i++) {
        re_sz = sizeof(buf) - (p - buf);
        if (re_sz < 1) {
            break;
        }
        p += snprintf(p, re_sz, "%2d %-16s %-10s %-12s\r\n", i, log_type_str_and_level[i].name,
              log_type_is_set((enum log_type)i) ? "enabled" : "disabled",
                      level_str[log_type_str_and_level[i].level]);
    }
    return buf;
}

char *get_log_fmt_status_str(void)
{
    int i = 0, re_sz;
    static char buf[256], *p;

    p = buf;
    re_sz = sizeof(buf);
    p += snprintf(p, re_sz, "%2s %-16s %-12s\r\n", "id", "fmt", "status");

    for (i = 0; i < AR_SZ(level_fmt_str); i++) {
        re_sz = sizeof(buf) - (p - buf);
        if (re_sz < 1) {
            break;
        }
        p += snprintf(p, re_sz, "%2d %-16s %-12s\r\n", i, level_fmt_str[i],
              _log_fmt_is_set((enum log_fmt)i) ? "enabled" : "disabled");
    }
    return buf;
}

void init_brook_log(void)
{
    openlog(NULL, DEFAULT_LOG_OPTION, DEFAULT_LOG_FACILITY);
}

void exit_brook_log(void)
{
    closelog();
}

void init_brook_log() __attribute__((constructor(101)));
void exit_brook_log() __attribute__((destructor(101)));

main.c

#include <stdio.h>
#include "brook-log.h"

int main(int argc, char *argv[])
{
    pr_info(LOG_TYPE_BIT(AT) | LOG_TYPE_BIT(CORE), "AT=%d", 0);

    log_type_clr(AT);
    pr_info(LOG_TYPE_BIT(AT) | LOG_TYPE_BIT(CORE), "AT=%d", 1);
    pr_info(LOG_TYPE_BIT(AT), "AT=%d", 11);
    pr_info(LOG_TYPE_BIT(CORE), "AT=%d", 12);

    log_type_set(AT);
    pr_info(LOG_TYPE_BIT(AT) | LOG_TYPE_BIT(CORE), "AT=%d", 2);


    log_fmt_toggle(FUNC_AND_LINE);
    pr_info(LOG_TYPE_BIT(AT) | LOG_TYPE_BIT(CORE), "AT=%d", 3);

    log_fmt_clr(TID);
    pr_info(LOG_TYPE_BIT(AT) | LOG_TYPE_BIT(CORE), "AT=%d", 4);

    log_type_level_set(AT, ERR);
    pr_info(LOG_TYPE_BIT(AT) | LOG_TYPE_BIT(CORE), "AT=%d", 5);

    return 0;
}

結果

brook@vista:~/sample/syslog$ gcc main.c brook-log.c -o brook-log
brook@vista:~/sample/syslog$ brook-log
brook@vista:~/sample/syslog$ tail /var/log/local.log
Nov 26 09:51:26 vista brook-log: main(#6), TID:21487, AT/CORE/, AT=0
Nov 26 09:51:26 vista brook-log: main(#9), TID:21487, AT/CORE/, AT=1
Nov 26 09:51:26 vista brook-log: main(#11), TID:21487, CORE/, AT=12
Nov 26 09:51:26 vista brook-log: main(#14), TID:21487, AT/CORE/, AT=2
Nov 26 09:51:26 vista brook-log: TID:21487, AT/CORE/, AT=3
Nov 26 09:51:26 vista brook-log: AT/CORE/, AT=4
Nov 26 09:51:26 vista brook-log: AT/CORE/, AT=5

note for "The Art of Readable Code" - CH7 Making Control Flow Easy to Read

CH7, Making Control Flow Easy to Read

The Order of Arguments in Conditionals
if (a > b) 左側通常是會有變化數值, 右側是比較基準, 通常是常數,

如 if (length >= 10)
會比下面這行容易閱讀 
if (10 <= length)

returning early from a function 與 minimize nesting
盡量讓function提早返回與減少巢狀結構可以增加閱讀性, 如

if (do_auth() != true) {
    do_auth_failed();
    return;
}

if (permission_check() != SUPER) {
    do_permission_check_failed();
    return;
}

do_something();

會比下面寫法容易閱讀
if (do_auth() == true) {
    if (check_permission() == SUPER) {
        do_something();
    } else {
        do_permission_check_failed();
    {
} else {
    do_auth_failed();
}

參考資料:
1. The Art of Readable Code

dtc - Device Tree Compiler

從dtc manpage可以簡略瞭解一下DTC(Device Tree Compiler)功能, 就是將device-tree的format轉成另一種format, 其input格式有三種,

1. dts - device tree source text
2. dtb - device tree blob
3. fs - /proc/device-tree style directory

而output格式也有三種,

1. dts - device tree source text
2. dtb - device tree blob
3. asm - assembler source

而dtc支援的phandle可支援三種

1. legacy - "linux,phandle" properties only
2. epapr - "phandle" properties only
3. both - Both "linux,phandle" and "phandle" properties

根據Device Tree Mysteries,

what is the reason for having a phandle? 
It is really just a hack to get around the fact that device tree does 
not have a pointer data type. 
It is a way to reference 
"that node over there that is related to this node for some reason". 

簡單來說, phandler就是pointer data type, 用個例子說明

pic@10000000 {
    phandle = < 1 >;
};

A phandle value of 1 is defined. 
Another device node could reference the pic node with a
phandle value of 1:

uart@20000000 {
    interrupt-parent = > 1 >;
};

"phandle = < 1 >"的"1"是一個隨意的unit32數值, 只要不衝突即可, 但是這並不是很好記, 所以DTC貼心的可以用lable來建立phandle,如下範例

PIC_3: pic@10000000 {
    interrupt-controller;
};

uart@20000000 {
    interrupt-parent = < &PIC_3 >;
};

這裡的"&"是告訴DTC後面接一個字串, 是個phandle參考到某個lable, 然後DTC就會幫user建立unit32的數值, 建立出phandle. 除此之外也可以使用full path來取代lable, 如下範例

/{
    soc {
        PIC_3: pic@10000000 {
            interrupt-controller;
        };
    };

    uart@20000000 {
        interrupt-parent = < &PIC_3 >;
    };

    uart@30000000 {
        interrupt-parent = < &{/soc/pic@10000000} >;
    };
};

下面再用一個例子同時說明DTC與phandle

brook@vista:~/dts$ cat test_phandle.dts
/dts-v1/;
/{
    soc {
        PIC_3: pic@10000000 {
           interrupt-controller;
        };
    };

    uart@20000000 {
        interrupt-parent = < &PIC_3 >;
    };

    uart@30000000 {
        interrupt-parent = < &{/soc/pic@10000000} >;
    };
};
brook@vista:~/dts$ dtc -O dtb -I dts test_phandle.dts > test_phandle.dtb
brook@vista:~/dts$ dtc -O dts -I dtb test_phandle.dtb
/dts-v1/;

/ {

        soc {

                pic@10000000 {
                        interrupt-controller;
                        linux,phandle = <0x1>;
                        phandle = <0x1>;
                };
        };

        uart@20000000 {
                interrupt-parent = <0x1>;
        };

        uart@30000000 {
                interrupt-parent = <0x1>;
        };
};

這篇文章主要簡單講解利用dtc來轉換dtb與dts, 順帶說明一下phandle是一種pointer data type, 與其基本原理

參考資料:
• Device Tree Mysteries
• Device Tree Compiler Manual
• Device Tree Source Format (version 1)
• Device Tree Usage

note for "The Art of Readable Code" - CH6 Making Comments Precise and Compact

CH6, Making Comments Precise and Compact

Comments should have a high information-to-space ratio.當你準備寫註解時, 請盡可能的精簡, 因為註解會佔版面, 而且需要時間了解

// CategoryType -> (score, weight)
typedef hash_map<int, pair<float, float> > ScoreMap;
會比下面例子精簡
// The int is the CategoryType.
// The first float in the inner pair is the 'score',
// the second is the 'weight'.
typedef hash_map<int, pair<float, float> > ScoreMap;

// Return the number of lines in this file.
int CountLines(string filename) { ... }
這段註解不精確, 因為一行有很多種定義, 下面例子會相對精準
// Count how many newline bytes ('\n') are in the file.
int CountLines(string filename) { ... }

Use Input/Output Examples That Illustrate Corner Cases有時候用範例當註解可以更容易讓人理解,比如

// Rearrange 'v' so that elements < pivot come before those >= pivot;
// Then return the largest 'i' for which v[i] < pivot (or -1 if none are < pivot)
// Example: Partition([8 5 9 8 2], 8) might result in [5 2 | 8 9 8] and return 1
int Partition(vector<int>* v, int pivot);

"Named Function Parameter” Comments即在function參數上加上註解

Connect(/* timeout_ms = */ 10, /* use_encryption = */ false);

參考資料:
1. The Art of Readable Code

note for "The Art of Readable Code" - CH5 Knowing What to Comment

CH5, Knowing What to Comment

The purpose of commenting is to help the reader know as much as the writer did.千萬別為了註解而註解, 因為凌亂的畫面, 不會讓人對程式碼更清晰

無意義的註解範例

// The class definition for Account
    class Account {
      public:
        // Constructor
Account();
        // Set the profit member to a new value
        void SetProfit(double profit);
        // Return the profit from this Account
        double GetProfit();
    };

不要註解不好的名稱, 直接修正名稱

// Enforce limits on the Reply as stated in the Request,
// such as the number of items returned, or total byte size, etc. 
void CleanReply(Request request, Reply reply);
直接修改上述function name從CleanReply()改為EnforceLimitsFromRequest()會比註解一堆來得有意義,
// Make sure 'reply' meets the count/byte/etc. limits from the 'request' 
void EnforceLimitsFromRequest(Request request, Reply reply);

Recording Your Thoughts / directory commentary,註解重要的紀錄,比如以下幾個註解

// This heuristic might miss a few words. That's OK; solving this 100% is hard.
...
// This class is getting messy. Maybe we should create a 'ResourceNode' subclass to
// help organize things.
...

Comment the Flaws in Your Code,程式會不斷的被修改, 不要害怕記錄這些需要改進的地方, 以下是常用的標記

TODO:	Stuff I haven’t gotten around to yet
FIXME:	Known-broken code here
HACK:	Admittedly inelegant solution to a problem
XXX:	Danger! major problem here

// TODO: move this into sched_fork()
...
// FIXME: do we need to worry about rq being invalidated by the
...

Summary Comments,對一些code給予一些comment, 比如

# Find all the items that customers purchased for themselves.
    for customer_id in all_customers:
        for sale in all_sales[customer_id].sales:
            if sale.recipient == customer_id:
                ...

def GenerateUserReport():
    # Acquire a lock for this user
    ...

    # Read user's info from the database
    ...

    # Write info to a file
    ...

    # Release the lock for this user
    ...

參考資料:
1. The Art of Readable Code

note for "The Art of Readable Code" - CH3 & CH4

CH3, Names That Can’t Be Misconstrued

Actively scrutinize your names by asking yourself, “What other meanings could someone interpret from this name?”

1. 比如results = Database.all_objects.filter("year <= 2011")的結果是<= 2011還是過濾了<= 2011的結果？如果用select()或exclude()會更為明確



2. 對於含有邊界意思的, 可以使用"min_"與"max_"加以辨識.



3. 對於閉區間使用first與end, 而半開放區間使用begin與end, 因為這些已經在C++中成為慣例了.



4. 關於bool則可以加上is, has, can, should等意思會更明確, 如

bool user_is_authed = true
會比下面這行更容易被明確
bool read_password = true




5. get*()(開頭的function), 通常指直接回傳內部成員, 如果還需要計算, 最好改用compute*()或count*(),

CH4, Aesthetics

這個章節是在講述, 好的排版會讓人更容易看懂code, 以下是我摘要的幾個範例

1. 給予參數一些註解

public class PerformanceTester {
   // TcpConnectionSimulator(throughput, latency, jitter, packet_loss)
   //                            [Kbps]   [ms]     [ms]    [percent]
   public static final TcpConnectionSimulator wifi =
       new TcpConnectionSimulator(500,     80,     200,     1);
   public static final TcpConnectionSimulator t3_fiber =
       new TcpConnectionSimulator(45000,   10,       0,     0);
   public static final TcpConnectionSimulator cell =
       new TcpConnectionSimulator(100,    400,     250,     5);
}



2. 讓參數對齊

CheckFullName("Doug Adams"  , "Mr. Douglas Adams" , "");
CheckFullName(" Jake Brown ", "Mr. Jake Brown III", "");
CheckFullName("No Such Guy" , ""                  , "no match found");
CheckFullName("John"        , ""                  , "more than one result");



3. 段落分明

def suggest_new_friends(user, email_password):
  # Get the user's friends' email addresses.
  friends = user.friends()
  friend_emails = set(f.email for f in friends)

  # Import all email addresses from this user's email account.
  contacts = import_contacts(user.email, email_password)
  contact_emails = set(c.email for c in contacts)

  # Find matching users that they aren't already friends with.
  non_friend_emails = contact_emails - friend_emails
  suggested_friends = User.objects.select(email__in=non_friend_emails)

Consistent style is more important than the “right” style. 無論你是用什麼coding style, 一致性會比你用“對”的style更重要.

參考資料:
• The Art of Readable Code

note for "The Art of Readable Code" - CH1 & CH2

CH1, Code Should Be Easy to Understand

Code should be written to minimize the time it would take for someone else to understand it.

越容易理解的code是越好的, 雖然減少程式碼數量是很好的目標, 但是縮短理解的時間是更為重要的, 甚至於超越效能, 比如

bucket = FindBucket(key);
if (bucket != NULL) assert(!bucket->IsOccupied());
會比下面這行更容易被理解
assert((!(bucket = FindBucket(key))) || !bucket->IsOccupied());

CH2, Pack information into your names

提高可讀性可以從"好的名稱", "好的註解", "簡潔的編排方式"著手, 比如, 將資訊放入名稱中

void download_page(url);
或
void fetch_page(url);
會比下面這行更容易被理解
void get_page(url);

名稱選擇上也需要注意, 比如open(), begin(), create(), launch()會比start()來的明確, 盡量用明確的命名, 比如tmp_file會比tmp更明確, 比如

var start = (new Date()).getTime();
...
var elasped = (new Date()).getTime();
..
會比下面這行更容易被明確
var ms_start = (new Date()).getTime();
...
var ms_elasped = (new Date()).getTime();
..

排除不必要的詞彙, 比如

ToString();
會比下面這行更簡潔
ConveterToString();

ServerLoop();
會比下面這行更簡潔
DoServerLoop();

我也習慣在static function,使用"_"開頭, 比如

static void _sleep();
void sleep();

Pack information into your names的幾個重點

• Use specific words—for example, instead of Get, words like Fetch or Download might be
better, depending on the context.
• Avoid generic names like tmp and retval, unless there’s a specific reason to use them.
• Use concrete names that describe things in more detail—the name ServerCanStart() is
vague compared to CanListenOnPort().
• Attach important details to variable names—for example, append _ms to a variable
whose value is in milliseconds or prepend raw_ to an unprocessed variable that needs
escaping.
• Use longer names for larger scopes—don’t use cryptic one- or two-letter names for
variables that span multiple screens; shorter names are better for variables that span only
a few lines.
• Use capitalization, underscores, and so on in a meaningful way—for example, you
can append “_” to class members to distinguish them from local variables.

參考資料:
• The Art of Readable Code

Note for Yocto Project Reference Manual v2.4 - ch8.141 update-alternatives.bbclass

當有多個recipes提供相同的命令時, update-alternatives.bbclass可以幫你做替代("alternative"), 例如，可以從busybox，binutils和elfutils中使用ar命令。 update-alternatives.bbclass會幫你重新命名，以便安裝多個package而不會發生衝突。無論安裝或隨後刪除哪些package，ar命令仍然有效。
要使用update-alternatives.bbclass，你需要為這個package定義一些變量：
ALTERNATIVE_ = "name1 name2 name3 ..."
列出所有這個package的alternatives指令

設定name這個命令的link的路徑
ALTERNATIVE_LINK_NAME[name] = "target"

設定該package的預設priority，數值越大，priority越高
ALTERNATIVE_PRIORITY

針對特定命令另外設定priority，數值越大，priority越高
ALTERNATIVE_PRIORITY[name] = "20"

範例

brook這個package的檔案結構

brook@vista:~/oe-core/meta/recipes-devtools/brook$ tree
.
|-- brook-1.0.0
|   |-- brookbox
|   |-- copyright
|   `-- insmod
`-- brook_1.0.0.bb

1 directory, 4 files

brookbox類似busybox，後面會有多個檔案link到該檔案，而insmod是一個獨立檔案

brook_1.0.0.bb

SUMMARY = "Brook demo update-alternatives"
DESCRIPTION = "This package is used for Brook to demo update-alternatives"
LICENSE = "GPLv2+"
LIC_FILES_CHKSUM = "file://${WORKDIR}/copyright;md5=afcc69d729fbf1d0a2af28ce44a23991 \
"
SRC_URI = "file://insmod \
        file://copyright \
        file://brookbox \
"
inherit update-alternatives

ALTERNATIVE_${PN} = "insmod route reboot shutdown poweroff"
ALTERNATIVE_PRIORITY = "100"

ALTERNATIVE_LINK_NAME[insmod] = "${base_sbindir}/insmod"
ALTERNATIVE_PRIORITY[insmod] = "50"

ALTERNATIVE_LINK_NAME[route] = "${base_sbindir}/route"
ALTERNATIVE_PRIORITY[route] = "50"

ALTERNATIVE_LINK_NAME[reboot] = "${base_sbindir}/reboot"

ALTERNATIVE_LINK_NAME[shutdown] = "${base_sbindir}/shutdown"
ALTERNATIVE_PRIORITY[shutdown] = "10"

ALTERNATIVE_LINK_NAME[poweroff] = "${base_sbindir}/poweroff"
ALTERNATIVE_PRIORITY[poweroff] = "500"

do_install () {
        install -d                              ${D}${base_sbindir}
        install -m 0755    ${WORKDIR}/insmod    ${D}${base_sbindir}/insmod
        install -m 0755    ${WORKDIR}/brookbox  ${D}${base_sbindir}/brook
        ln -s ${base_sbindir}/brook ${D}${base_sbindir}/route
        ln -s ${base_sbindir}/brook ${D}${base_sbindir}/reboot
        ln -s ${base_sbindir}/brook ${D}${base_sbindir}/shutdown
        ln -s ${base_sbindir}/brook ${D}${base_sbindir}/poweroff
}

sysvinit也同時註冊了reboot，shutdown與poweroff，其priority都是200，而這裡的priority分別為100，10，500，所以最後結果如下

brook@vista:~/oe-core/build/tmp-glibc/work/oe-linux-gnueabi/image/1.0-r0/rootfs$ ls -al sbin/|grep brook
-rwxr-xr-x  1 jenkins jenkins      6 Dec  9 22:17 brook
lrwxrwxrwx  1 jenkins jenkins     18 Dec  9 22:17 insmod -> /sbin/insmod.brook
-rwxr-xr-x  1 jenkins jenkins      6 Dec  9 22:17 insmod.brook
lrwxrwxrwx  1 jenkins jenkins     20 Dec  9 22:17 poweroff -> /sbin/poweroff.brook
lrwxrwxrwx  1 jenkins jenkins     11 Dec  9 22:17 poweroff.brook -> /sbin/brook
lrwxrwxrwx  1 jenkins jenkins     11 Dec  9 22:17 reboot.brook -> /sbin/brook
lrwxrwxrwx  1 jenkins jenkins     17 Dec  9 22:17 route -> /sbin/route.brook
lrwxrwxrwx  1 jenkins jenkins     11 Dec  9 22:17 route.brook -> /sbin/brook
lrwxrwxrwx  1 jenkins jenkins     11 Dec  9 22:17 shutdown.brook -> /sbin/brook

reboot與shutdown都小於sysvinit，所以不適用brook，poweroff高於sysvinit，所以使用brook這個package提供的命令

參考資料:
• Yocto Project Reference Manual 2.4

An Sample Code for Syslogd - A log pattern with categorize, level and format

寫程式常常需要有log system用於debug，大程式常常會有很多thread或是模組，我們想根據模組分類，並且給予log特定等級，如ERR/INFO/DEBUG等等，也會希望多打印一些資訊，如function name，TPID等等，這裡就是要提供這些功能的sample code，此外，根據syslog_r for Linux?說的According to the POSIX specification, the syslog function is already thread-safe, and so implemented in Linux. So syslog_r is unnecessary - use syslog if you need a reentrant logger function.

brook-log.h

#ifndef _LOG_H_
#define _LOG_H_
#include <syslog.h>
#include <unistd.h>
#include <sys/syscall.h>

/*************************************************
 * TYPE
 *************************************************/
enum log_type {
/* 這裡我先設定有三個類別，分別為AT，CORE與DB，之後請自行新增刪減修改 */
       LOG_TYPE_AT,
       LOG_TYPE_CORE,
       LOG_TYPE_DB,
       LOG_TYPE_MAX
};

/***** internal function for MACRO used *****/
void _log_type_toggle(enum log_type type);
void _log_type_clr(enum log_type type);
void _log_type_set(enum log_type type);

/***** public function to enable/disable log on certain type *****/
#define log_type_toggle(type) _log_type_toggle(LOG_TYPE_##type)
#define log_type_clr(type) _log_type_clr(LOG_TYPE_##type)
#define log_type_set(type) _log_type_set(LOG_TYPE_##type)

char *get_log_type_status(void);


/*************************************************
 * Format
 *************************************************/
enum log_fmt {
 LOG_FMT_FUNC_AND_LINE,
 LOG_FMT_TID, ///< thread ID.
 LOG_FMT_LOG_TYPE,
 LOG_FMT_LOG_LEVEL,
 LOG_FMT_MAX,
};

/***** internal function for MACRO used *****/
void _log_fmt_toggle(enum log_fmt fmt);
void _log_fmt_set(enum log_fmt fmt);
void _log_fmt_clr(enum log_fmt fmt);
int _log_fmt_is_set(enum log_fmt fmt);

/***** public function to enable/disable certain format type *****/
#define log_fmt_toggle(fmt) _log_fmt_toggle(LOG_FMT_##fmt)
#define log_fmt_set(fmt) _log_fmt_set(LOG_FMT_##fmt)
#define log_fmt_clr(fmt) _log_fmt_clr(LOG_FMT_##fmt)
#define log_fmt_is_set(fmt) _log_fmt_is_set(LOG_FMT_##fmt)


/*************************************************
 * Level
 *************************************************/
/***** internal function for MACRO used *****/
int _log_type_level_is(enum log_type type, int *level);
int _log_type_level_set(enum log_type type, int level);

/***** public function to set debug level. the level is leveraged from syslog *****/
#define log_type_level_is(type, level) _log_type_level_is(LOG_TYPE_##type, level)
#define log_type_level_set(type, level) _log_type_level_set(LOG_TYPE_##type, LOG_##level)

void log_pr(enum log_type type, int level, char const * const fmt, ...);

#define _log_pr(type, level, fmt, ...)                 \
do {                                                    \
        unsigned char func[36] = {}, tid[16] = {}, tp[16] = {}, lv[16] = {};\
        if (log_fmt_is_set(FUNC_AND_LINE)) {    \
                snprintf(func, sizeof(func) - 1, "%s(#%d), ", __FUNCTION__, __LINE__);   \
        }                                               \
                                                        \
        if (log_fmt_is_set(TID)) {              \
                snprintf(tid, sizeof(tid) - 1, "TID:%ld, ", syscall(__NR_gettid));       \
        }                                               \
                                                        \
        if (log_fmt_is_set(LOG_TYPE)) {         \
                snprintf(tp, sizeof(tp) - 1, "%s, ", #type);     \
        }                                               \
        if (log_fmt_is_set(LOG_TYPE)) {         \
                snprintf(tp, sizeof(lv) - 1, "%s, ", #level);     \
        }                                               \
        log_pr(LOG_TYPE_##type, LOG_##level, "%s%s%s%s"fmt, func, tid, tp, lv, ##__VA_ARGS__);     \
} while(0)

/***** public function *****/
/* 請呼叫下面MACRO來印log */
#define pr_emerg(type, fmt, ...)  _log_pr(type, EMERG, fmt, ##__VA_ARGS__)
#define pr_alert(type, fmt, ...)  _log_pr(type, ALERT, fmt, ##__VA_ARGS__)
#define pr_crit(type, fmt, ...)   _log_pr(type, CRIT, fmt, ##__VA_ARGS__)
#define pr_err(type, fmt, ...)    _log_pr(type, ERR, fmt, ##__VA_ARGS__)
#define pr_warn(type, fmt, ...)   _log_pr(type, WARNING, fmt, ##__VA_ARGS__)
#define pr_notice(type, fmt, ...) _log_pr(type, NOTICE, fmt, ##__VA_ARGS__)
#define pr_info(type, fmt, ...)   _log_pr(type, INFO, fmt, ##__VA_ARGS__)
#define pr_dbg(type, fmt, ...)    _log_pr(type, DEBUG, fmt, ##__VA_ARGS__)

#endif

brook-log.c

#include <stdio.h>
#include <stdarg.h>
#include <syslog.h>
#include "brook-log.h"

#define DEFAULT_LOG_TYPE ((1 << LOG_TYPE_AT) | \
   (1 << LOG_TYPE_CORE) | \
   (1 << LOG_TYPE_DB))

#define DEFAULT_LOG_FMT ((1 << LOG_FMT_FUNC_AND_LINE) | \
   (1 << LOG_FMT_TID) | \
   (1 << LOG_FMT_LOG_TYPE))

static unsigned int _log_types = DEFAULT_LOG_TYPE;
static unsigned int _log_fmts = DEFAULT_LOG_FMT;

#define DEFAULT_LOG_OPTION (LOG_CONS | LOG_NDELAY)
#define DEFAULT_LOG_FACILITY LOG_LOCAL0
#define DEFAULT_LOG_LEVEL LOG_INFO

char const * const level_str[] = {
 [LOG_EMERG] = "EMERG",
 [LOG_ALERT] = "ALERT",
 [LOG_CRIT] = "CRIT",
 [LOG_ERR] = "ERR",
 [LOG_WARNING] = "WARN",
 [LOG_NOTICE] = "NOTICE",
 [LOG_INFO] = "INFO",
 [LOG_DEBUG] = "DEBUG",
};

char const * const level_fmt_str[] = {
 [LOG_FMT_FUNC_AND_LINE] = "FUNC_AND_LINE",
 [LOG_FMT_TID] = "TID",
 [LOG_FMT_LOG_TYPE] = "LOG_TYPE",
};

#define AR_SZ(a) (sizeof(a)/sizeof(a[0]))

#define BIT_SET(_v, _b) \
do {   \
 (_v) |= (1 << (_b));\
} while(0)

#define BIT_CLR(_v, _b) \
do {   \
 (_v) &= ~(1 << (_b));\
} while(0)

#define BIT_TOGGLE(_v, _b)  \
do {    \
 (_v) ^= (1 <<(_b)); \
} while(0)

int _log_fmt_is_set(enum log_fmt fmt)
{
 if (_log_fmts & (1 << fmt)) {
  return 1;
 }
 return 0;
}

void _log_fmt_set(enum log_fmt fmt)
{
 BIT_SET(_log_fmts, fmt);
}

void _log_fmt_clr(enum log_fmt fmt)
{
 BIT_CLR(_log_fmts, fmt);
}

void _log_fmt_toggle(enum log_fmt fmt)
{
 BIT_TOGGLE(_log_fmts, fmt);
}

struct log_type_str_and_level {
 char const * const name;
 int level;
} log_type_str_and_level [] = {
/* TYPE有增減，請更新這個ARRAY */
 [LOG_TYPE_AT] = { "AT", DEFAULT_LOG_LEVEL},
 [LOG_TYPE_CORE] = { "CORE", DEFAULT_LOG_LEVEL},
 [LOG_TYPE_DB] = { "DB", DEFAULT_LOG_LEVEL},
 [LOG_TYPE_MAX] = { "MAX", DEFAULT_LOG_LEVEL},
};

int _log_type_level_is(enum log_type type, int *level)
{
 if (type >= 0 && type < AR_SZ(log_type_str_and_level)) {
  *level = log_type_str_and_level[type].level;
  return 0;
 }
 return -1;
}

int _log_type_level_set(enum log_type type, int level)
{
 if (type >= 0 && type < AR_SZ(log_type_str_and_level) && level >= 0 && level <= LOG_DEBUG) {
  log_type_str_and_level[type].level = level;
  return 0;
 }
 return -1;
}

int log_type_is_set(enum log_type type)
{
 if (_log_types & (1 << type)) {
  return 1;
 }
 return 0;
}

void _log_type_set(enum log_type type)
{
 BIT_SET(_log_types, type);
}

void _log_type_clr(enum log_type type)
{
 BIT_CLR(_log_types, type);
}

void _log_type_toggle(enum log_type type)
{
 BIT_TOGGLE(_log_types, type);
}

void log_pr(enum log_type type, int level, char const * const fmt, ...)
{
 va_list ap;
 if ((_log_types & (1 << type)) && (log_type_str_and_level[type].level >= level)) {
  va_start(ap, fmt);
  vsyslog(LOG_MAKEPRI(LOG_LOCAL0, level), fmt, ap);
  va_end(ap);
 }
}

char *get_log_type_status_str(void)
{
 int i = 0, re_sz;
 static char buf[1024], *p;

 p = buf;
 re_sz = sizeof(buf);
 p += snprintf(p, re_sz, "%2s %-16s %-10s %-12s\r\n", "id", "type", "status", "level");

 for (i = 0; i < AR_SZ(log_type_str_and_level); i++) {
  re_sz = sizeof(buf) - (p - buf);
  if (re_sz < 1) {
   break;
  }
  p += snprintf(p, re_sz, "%2d %-16s %-10s %-12s\r\n", i, log_type_str_and_level[i].name,
   log_type_is_set((enum log_type)i) ? "enabled" : "disabled",
   level_str[log_type_str_and_level[i].level]);
 }
 return buf;
}

char *get_log_fmt_status_str(void)
{
 int i = 0, re_sz;
 static char buf[256], *p;

 p = buf;
 re_sz = sizeof(buf);
 p += snprintf(p, re_sz, "%2s %-16s %-12s\r\n", "id", "fmt", "status");

 for (i = 0; i < AR_SZ(level_fmt_str); i++) {
  re_sz = sizeof(buf) - (p - buf);
  if (re_sz < 1) {
   break;
  }
  p += snprintf(p, re_sz, "%2d %-16s %-12s\r\n", i, level_fmt_str[i],
   _log_fmt_is_set((enum log_fmt)i) ? "enabled" : "disabled");
 }
 return buf;
}

void init_brook_log(void)
{
 openlog(NULL, DEFAULT_LOG_OPTION, DEFAULT_LOG_FACILITY);
}

void exit_brook_log(void)
{
 closelog();
}

void init_brook_log() __attribute__ ((constructor (101)));
void exit_brook_log() __attribute__ ((destructor (101)));

main.c

#include <stdio.h>
#include "brook-log.h"

int main(int argc, char *argv[])
{
 pr_info(AT, "AT=%d", 0);

 log_type_clr(AT);
 pr_info(AT, "AT=%d", 1);

 log_type_set(AT);
 pr_info(AT, "AT=%d", 2);


 log_fmt_toggle(FUNC_AND_LINE);
 pr_info(AT, "AT=%d", 3);

 log_fmt_clr(TID);
 pr_info(AT, "AT=%d", 4);

 log_type_level_set(AT, ERR);
 pr_info(AT, "AT=%d", 5);

 return 0;
}

結果

brook@vista:~/sample/syslog$ gcc main.c brook-log.c -o brook-log
brook@vista:~/sample/syslog$ brook-log
brook@vista:~/sample/syslog$ tail /var/log/local.log
Nov 26 09:51:26 vista brook-log: main(#6), TID:21765, INFO, AT=0
Nov 26 09:51:26 vista brook-log: main(#12), TID:21765, INFO, AT=2
Nov 26 09:51:26 vista brook-log: TID:21765, INFO, AT=3
Nov 26 09:51:26 vista brook-log: INFO, AT=4

MQTT sample code using libmosquitto

Sample code for publisher

#include <errno.h>
#include <fcntl.h>
#include <stdio.h>
#include <unistd.h>
#include <stdlib.h>
#include <string.h>
#include <mosquitto.h>

// Server connection parameters
#define MQTT_HOSTNAME "localhost"
#define MQTT_PORT 1883
#define MQTT_TOPIC "/brook"

struct brook_obj {
 unsigned long long published;
 unsigned long long connected;
 unsigned long long disconnected;
 unsigned long long loged;
};

/*
 mosq the mosquitto instance making the callback.
 obj the user data provided in mosquitto_new
 rc the return code of the connection response, one of:
*/
static void connect_cb(struct mosquitto *mosq, void *obj, int rc)
{
 struct brook_obj *bobj = (struct brook_obj*) obj;
 bobj->connected++;
        printf("%s(), connect:%llu, published:%llu, loged:%llu, rc:%d\n",
  __FUNCTION__, bobj->connected, bobj->published, bobj->loged, rc);
}

static void publish_cb(struct mosquitto *mosq, void *obj, int mid)
{
 struct brook_obj *bobj = (struct brook_obj*) obj;
 bobj->published++;
        printf("%s(), connect:%llu, published:%llu, loged:%llu, mid:%d\n",
  __FUNCTION__, bobj->connected, bobj->published, bobj->loged, mid);
}

static void log_cb(struct mosquitto *mosq, void *obj, int level, const char *str)
{
 struct brook_obj *bobj = (struct brook_obj*) obj;
 bobj->loged++;
        printf("%s(), connect:%llu, published:%llu, loged:%llu, level:%d,\n\tstr:%s\n",
  __FUNCTION__, bobj->connected, bobj->published, bobj->loged, level, str);
}

static void disconnect_cb(struct mosquitto *mosq, void *obj, int rc)
{
 struct brook_obj *bobj = (struct brook_obj*) obj;
 bobj->disconnected++;
        printf("%s(), connect:%llu, published:%llu, loged:%llu, disconnected:%llu\n",
  __FUNCTION__, bobj->connected, bobj->published, bobj->loged, bobj->disconnected);
}

/*
 * Start here
 */
int main (int argc, char **argv)
{
 char clientid[24], text[20];
 struct mosquitto *mosq = NULL;
 unsigned long long i;
 int rc, major, minor, rev;
 struct brook_obj brook_obj = {};

 /* Must be called before any other mosquitto functions.
    This function is not thread safe. */
  mosquitto_lib_init();

  rc = mosquitto_lib_version(&major, &minor, &rev);
  fprintf(stdout, "rc:%d, major:%d, minor:%d, rev:%d\n",
  rc, major, minor, rev);

  memset(clientid, 0, sizeof(clientid));
  snprintf(clientid, sizeof(clientid) - 1, "cid-pub-%d", getpid());
  mosq = mosquitto_new(clientid, true, &brook_obj);
 if (!mosq) {
  fprintf (stderr, "new mosq failed \n");
  exit(-1);
 }

  rc = mosquitto_tls_opts_set(mosq, 1, "tlsv1", NULL);
 if (rc) {
  fprintf (stderr, "set tls failed %d\n", rc);
  exit (-1);
 }

  rc = mosquitto_tls_set(mosq, "ca/client/ca.crt", NULL, "ca/client/client.crt", "ca/client/client.key", NULL);
  if (rc) {
  fprintf (stderr, "set tls failed %d\n", rc);
  exit (-1);
  }

   rc = mosquitto_tls_insecure_set(mosq, true);
  if (rc) {
  fprintf (stderr, "set insecure failed %d\n", rc);
  exit (-1);
  }

 // Set callback function
  mosquitto_connect_callback_set(mosq, connect_cb);
  mosquitto_publish_callback_set(mosq, publish_cb);
  mosquitto_log_callback_set(mosq, log_cb);
  mosquitto_disconnect_callback_set(mosq, disconnect_cb);

  rc = mosquitto_connect(mosq, MQTT_HOSTNAME, MQTT_PORT, 60);
  if (rc) {
   fprintf (stderr, "Can't connect to Mosquitto server. %d\n", rc);
   exit (-1);
  }

  for (i = 0; i < 10 ;i++) {
   sprintf(text, "%llu", i);
   printf("send %d, %s\n", (int)strlen(text), text);
   // Publish the message to the topic
  rc = mosquitto_publish(mosq, NULL, MQTT_TOPIC, strlen(text), text, 2, false);
  if (rc) {
   fprintf (stderr, "Can't publish to Mosquitto server\n");
   exit (-1);
  }
  if (!(i % 3)) {
   do {
    rc = mosquitto_loop(mosq, 3, 1);
    fprintf (stdout, "mosquitto_loop %d, published:%llu, i:%llu\n",
      rc, brook_obj.published, i);
   } while(rc == 0 && brook_obj.published < i);
  }
 }

 do {
  rc = mosquitto_loop(mosq, 3, 1);
  fprintf (stdout, "mosquitto_loop %d, published:%llu, i:%llu\n",
    rc, brook_obj.published, i);
 } while(rc == 0 && brook_obj.published != i);

 // Tidy up
 mosquitto_disconnect(mosq);
 mosquitto_destroy(mosq);
 mosquitto_lib_cleanup();

 return 0;
}

Sample code subscriber

#include <signal.h>
#include <stdlib.h>
#include <stdio.h>
#include <stdint.h>
#include <string.h>

#include <sys/types.h>
#include <unistd.h>

#include <mosquitto.h>

#define MQTT_HOSTNAME "localhost" 
#define MQTT_PORT 1883 
#define MQTT_TOPIC "/brook/#"

struct brook_obj {
 unsigned long long msgs;
 unsigned long long connected;
 unsigned long long disconnected;
 unsigned long long loged;
 unsigned long long subscribed;
 unsigned long long unsubscribed;
};

/*
 mosq the mosquitto instance making the callback.
 obj the user data provided in mosquitto_new
 rc the return code of the connection response, one of:
*/
static void connect_cb(struct mosquitto *mosq, void *obj, int rc)
{
 struct brook_obj *bobj = (struct brook_obj*) obj;
 bobj->connected++;
 printf("%s(), connect:%llu, msgs:%llu, loged:%llu, rc:%d\n",
  __FUNCTION__, bobj->connected, bobj->msgs, bobj->loged, rc);
}

static void log_cb(struct mosquitto *mosq, void *obj, int level, const char *str)
{
 struct brook_obj *bobj = (struct brook_obj*) obj;
 bobj->loged++;
 printf("%s(), connect:%llu, msgs:%llu, loged:%llu, level:%d,\n\tstr:%s\n",
  __FUNCTION__, bobj->connected, bobj->msgs, bobj->loged, level, str);
}

static void disconnect_cb(struct mosquitto *mosq, void *obj, int rc)
{
 struct brook_obj *bobj = (struct brook_obj*) obj;
 bobj->disconnected++;
 printf("%s(), connect:%llu, msgs:%llu, loged:%llu, disconnected:%llu\n",
  __FUNCTION__, bobj->connected, bobj->msgs, bobj->loged, bobj->disconnected);
}

static void message_cb(struct mosquitto *mosq, void *obj, const struct mosquitto_message *message)
{
 struct brook_obj *bobj = (struct brook_obj*) obj;
 bobj->msgs++;
 bool match = 0;
 static unsigned long long i = 0, j = 0;

 printf("%s(), connect:%llu, msgs:%llu, loged:%llu, disconnected:%llu\n",
  __FUNCTION__, bobj->connected, bobj->msgs, bobj->loged, bobj->disconnected);
 printf("%s(), got message mid:%d, '%.*s' for topic '%s'\n",
  __FUNCTION__, message->mid, message->payloadlen, (char*) message->payload, message->topic);

 mosquitto_topic_matches_sub(MQTT_TOPIC, message->topic, &match);
 if (match) {
  printf("got matched topic to %s\n", MQTT_TOPIC);
 }
}

static void unsubscribe_cb(struct mosquitto *mosq, void *obj, int mid)
{
 struct brook_obj *bobj = (struct brook_obj*) obj;
 bobj->unsubscribed++;
 printf("%s(), connect:%llu, msgs:%llu, loged:%llu, disconnected:%llu, unsubscribed:%llu\n",
  __FUNCTION__, bobj->connected, bobj->msgs, bobj->loged, bobj->disconnected,
  bobj->unsubscribed);
}

static void subscribe_cb(struct mosquitto *mosq, void *obj, int mid, int qos_count, const int *granted_qos)
{
 int i;
 struct brook_obj *bobj = (struct brook_obj*) obj;
 bobj->subscribed++;
 printf("%s(), mid:%d, qos_count:%d\n",
  __FUNCTION__, mid, qos_count);
 for (i = 0; i < qos_count; i++) {
  printf("\tQ[%d]:%d\n", i, granted_qos[i]);
 }
 printf("%s(), connect:%llu, msgs:%llu, loged:%llu, disconnected:%llu, subscribed:%llu\n",
  __FUNCTION__, bobj->connected, bobj->msgs, bobj->loged, bobj->disconnected,
  bobj->subscribed);
}

int main(int argc, char *argv[])
{
 char clientid[24];
 struct mosquitto *mosq;
 int rc = 0;
 struct brook_obj brook_obj = {};

 mosquitto_lib_init();

 memset(clientid, 0, sizeof(clientid));
 snprintf(clientid, sizeof(clientid) - 1, "cid-sub-%d", getpid());
 mosq = mosquitto_new(clientid, true, &brook_obj);
 if (!mosq) {
  fprintf (stderr, "new mosq failed\n");
  exit(-1);
 }

 rc = mosquitto_tls_opts_set(mosq, 1, "tlsv1", NULL);
 if (rc) {
  fprintf (stderr, "set tls opt failed %d\n", rc);
  exit(-1);
 }

 rc = mosquitto_tls_insecure_set(mosq, true);
 if (rc) {
  fprintf (stderr, "set insecure failed %d\n", rc);
  exit(-1);
 }

 rc = mosquitto_tls_set(mosq, "ca/client/ca.crt", NULL, "ca/client/client.crt", "ca/client/client.key", NULL);
 if (rc) {
  fprintf (stderr, "set tls failed %d\n", rc);
  exit(-1);
 }

 mosquitto_connect_callback_set(mosq, connect_cb);
 mosquitto_log_callback_set(mosq, log_cb);
 mosquitto_subscribe_callback_set(mosq, subscribe_cb);
 mosquitto_unsubscribe_callback_set(mosq, unsubscribe_cb);
 mosquitto_message_callback_set(mosq, message_cb);
 mosquitto_disconnect_callback_set(mosq, disconnect_cb);

 rc = mosquitto_connect(mosq, MQTT_HOSTNAME, MQTT_PORT, 60);
 if (rc) {
  fprintf(stderr, "mosquitto_connect failed. %d\n", rc);
  exit(-1);
 }

 mosquitto_subscribe(mosq, NULL, MQTT_TOPIC, 1);

 do {
  rc = mosquitto_loop(mosq, 3000, 1);
  fprintf(stdout, "mosquitto_loop %d, msgs%llu\n",
   rc, brook_obj.msgs);
 } while(rc == 0 && brook_obj.msgs < 5);

 mosquitto_disconnect(mosq);
 mosquitto_destroy(mosq);
 mosquitto_lib_cleanup();

 return rc;
}

MQTT

MQ Telemetry Transport (MQTT)網路文章已經很多，也很完善，大家可以參考本文章後面的reference，這裡快速帶過幾個重點：
MQTT是一個輕量級的基於broker的Publish/Subscribe messaging protocol，旨在實現開放，簡單，輕量級和易於實現。
協議的特點包括：

• 提供一對多的訊息發布
• 三種QoS
  "At most once" - message丟失或重複可能發生。
  "At least once" - 確保message到達，但可能會發生重複。
  "Exactly once" - 確保message只送達一次。

MQTT Architecture(Publish/Subscribe with broker)

MQTT有三種主要的組成元件，分別為Publisher、Subscriber以及Broker。 Publisher為訊息的來源，它會將訊息(Topic)發送給Broker，而Subscriber向Broker註冊，表示他們想要接收某Topic訊息；因此當有某個Publisher對Broker發送Topic訊息時，只要是有對此Topic註冊的Subscriber，都會收到此則訊息。

Topic wildcards

Topic為UTF-8編碼字串，最長長度為32,767字元，Topic支援階層式命名方式，如："住家/客廳/溫度"，階層的分隔符號為"/"，所以前面這個Topic有三層架構，Topic可以透過萬用字元一次訂閱多個主題。但是這些萬用字元只能放在最後一層
"#"為Multi-level wildcard，可以包含零個以上的階層，如有人送出"a/b/c/d"，那以下訂閱都可以被match "a/b/c/d"，"#"，"a/#"，"a/b/#"，"a/b/c/#"，"+/b/c/#"，
"+"為Single-level wildcard，只能包含該層的Topic，如有人送出"a/b/c/d"，那以下訂閱都可以被match “a/b/c/d"，"+/b/c/d"，"a/+/c/d"，"a/+/+/d"，"+/+/+/+"，而以下這些事不能match的"a/b/c"，"b/+/c/d"，"+/+/+"

Deom the MQTT - mosquitto

請用apt-get install mosquitto mosquitto-clients安裝mosquitto套件
run the broker

brook@vista:~$ mosquitto -v
1511094611: mosquitto version 1.4.8 (build date Mon, 26 Jun 2017 09:31:02 +0100) starting
1511094611: Using default config.
1511094611: Opening ipv4 listen socket on port 1883.
1511094611: Opening ipv6 listen socket on port 1883.
1511094635: New connection from 127.0.0.1 on port 1883.
1511094635: New client connected from 127.0.0.1 as mosqsub/16408-jpr-Verit (c1, k60). 有人連上就會顯示
1511094635: Sending CONNACK to mosqsub/16408-jpr-Verit (0, 0)
1511094635: Received SUBSCRIBE from mosqsub/16408-jpr-Verit
1511094635:     /brook/L1 (QoS 0)
1511094635: mosqsub/16408-jpr-Verit 0 /brook/L1
1511094635: Sending SUBACK to mosqsub/16408-jpr-Verit
1511094659: New connection from 127.0.0.1 on port 1883.
1511094659: New client connected from 127.0.0.1 as mosqpub/16687-jpr-Verit (c1, k60).
1511094659: Sending CONNACK to mosqpub/16687-jpr-Verit (0, 0)
1511094659: Received PUBLISH from mosqpub/16687-jpr-Verit (d0, q0, r0, m0, '/brook/L1', ... (11 bytes))
1511094659: Sending PUBLISH to mosqsub/16408-jpr-Verit (d0, q0, r0, m0, '/brook/L1', ... (11 bytes))
1511094659: Received DISCONNECT from mosqpub/16687-jpr-Verit
1511094659: Client mosqpub/16687-jpr-Verit disconnected.

向Broker註冊topic "/brook/L1"

brook@vista:~$ mosquitto_sub -h localhost -t '/brook/L1'
test for L1有人向Broker推送/brook/L1訊息就會顯示

向Broker推送topic "/brook/L1"的訊息

brook@vista:~$ mosquitto_pub -h localhost -t '/brook/L1' -m 'test for L1'

mosquitto - Broker log notes

brook@vista:~$ mosquitto -v
1511094635: New client connected from 127.0.0.1 as mosqsub/16408-jpr-Verit (c1, k60). 

mosquitto-1.4.8/src/read_handle_server.c
521 if(context->username){
522   _mosquitto_log_printf(NULL, MOSQ_LOG_NOTICE, 
                           "New client connected from %s as %s (c%d, k%d, u'%s').",
                            context->address, client_id, clean_session, 
                            context->keepalive, context->username);
523 }else{
524   _mosquitto_log_printf(NULL, MOSQ_LOG_NOTICE,
                           "New client connected from %s as %s (c%d, k%d).", 
                           context->address, client_id, clean_session,
                           context->keepalive);
525 }

1511094635: Sending CONNACK to mosqsub/16408-jpr-Verit (0, 0)
1511094635: Received SUBSCRIBE from mosqsub/16408-jpr-Verit
1511094635:     /brook/L1 (QoS 0)

man mqtt
QUALITY OF SERVICE
  MQTT defines three levels of Quality of Service (QoS). The QoS defines how hard the 
  broker/client will try to ensure that a message is received. Messages may be sent 
  at any QoS level, and clients may attempt to subscribe to topics at any QoS level.
  This means that the client chooses the maximum QoS it will receive. For example, 
  if a message is published at QoS 2 and a client is subscribed with QoS 0, the 
  message will be delivered to that client with QoS 0. If a second client is also 
  subscribed to the same topic, but with QoS 2, then it will receive the same message 
  but with QoS 2. For a second example, if a client is subscribed with QoS 2 and a 
  message is published on QoS 0, the client will receive it on QoS 0.

  Higher levels of QoS are more reliable, but involve higher latency and have higher bandwidth requirements.
    o 0: The broker/client will deliver the message once, with no confirmation.
    o 1: The broker/client will deliver the message at least once, with confirmation required.
    o 2: The broker/client will deliver the message exactly once by using a four step handshake.

1511094635: mosqsub/16408-jpr-Verit 0 /brook/L1
1511094635: Sending SUBACK to mosqsub/16408-jpr-Verit
1511094659: New connection from 127.0.0.1 on port 1883.
1511094659: New client connected from 127.0.0.1 as mosqpub/16687-jpr-Verit (c1, k60).
1511094659: Sending CONNACK to mosqpub/16687-jpr-Verit (0, 0)
1511094659: Received PUBLISH from mosqpub/16687-jpr-Verit (d0, q0, r0, m0, '/brook/L1', ... (11 bytes))

mosquitto-1.4.8/src/read_handle.c
217 _mosquitto_log_printf(NULL, MOSQ_LOG_DEBUG, 
                          "Received PUBLISH from %s (d%d, q%d, r%d, m%d, '%s', ... (%ld bytes))",
                          context->id, dup, qos, retain, mid, topic, (long)payloadlen);

1511094659: Sending PUBLISH to mosqsub/16408-jpr-Verit (d0, q0, r0, m0, '/brook/L1', ... (11 bytes))

mosquitto-1.4.8/lib/send_mosq.c
156 _mosquitto_log_printf(NULL, MOSQ_LOG_DEBUG, 
                          "Sending PUBLISH to %s (d%d, q%d, r%d, m%d, '%s', ... (%ld bytes))",
                          mosq->id, dup, qos, retain, mid, mapped_topic, (long)payloadlen);

1511094659: Received DISCONNECT from mosqpub/16687-jpr-Verit
1511094659: Client mosqpub/16687-jpr-Verit disconnected.

• MQTT V3.1 Protocol Specification
• MQTT教學（一）：認識MQTT
• MQTT(一)簡介
• MQTT(二)Message Type and Flows
• MQTT(三)CONNECT Message
• MQTT(四)PUBLISH Message
• MQTT(五)SUBSCRIBE Message
• MQTT(六)UNSUBSCRIBE Message And PINGREQ Message
• mosquitto簡介