syslog分析

我们使用的事busybox中的syslog,当通过/etc/inittab启动ttyS0::respawn:/sbin/syslogd -n -m 0时，表示syslogd使用ttyS0作为标准输入输出。
# syslogd -h
syslogd: invalid option -- h
BusyBox v1.14.1 (2012-03-01 11:13:19 HKT) multi-call binary

Usage: syslogd [OPTION]...

System logging utility.
Note that this version of syslogd ignores /etc/syslog.conf.

Options:
        -n              Run in foreground
        -O FILE         Log to given file (default=/var/log/messages)
        -l n            Set local log level
        -S              Smaller logging output
        -s SIZE         Max size (KB) before rotate (default=200KB, 0=off)
        -b NUM          Number of rotated logs to keep (default=1, max=99, 0=purge)
        -R HOST[:PORT]  Log to IP or hostname on PORT (default PORT=514/UDP)
        -L              Log locally and via network (default is network only if -R)

int syslogd_main(int argc UNUSED_PARAM, char **argv)
{
    char OPTION_DECL;
    int opts;

    INIT_G();
#if ENABLE_FEATURE_REMOTE_LOG
    G.last_dns_resolve = monotonic_sec() - DNS_WAIT_SEC - 1;
#endif

    /* do normal option parsing */
    opt_complementary = "=0"; /* no non-option params */
    opts = getopt32(argv, OPTION_STR, OPTION_PARAM);
#ifdef SYSLOGD_MARK // SYSLOGD_MARK没有定义，所以-m选项其实没作用
    if (opts & OPT_mark) // -m
        G.markInterval = xatou_range(opt_m, 0, INT_MAX/60) * 60;
#endif
    //if (opts & OPT_nofork) // -n
    //if (opts & OPT_outfile) // -O
    if (opts & OPT_loglevel) // -l
        G.logLevel = xatou_range(opt_l, 1, 8);
    //if (opts & OPT_small) // -S
#if ENABLE_FEATURE_ROTATE_LOGFILE
    if (opts & OPT_filesize) // -s
        G.logFileSize = xatou_range(opt_s, 0, INT_MAX/1024) * 1024;
    if (opts & OPT_rotatecnt) // -b
        G.logFileRotate = xatou_range(opt_b, 0, 99);
#endif
#if ENABLE_FEATURE_IPC_SYSLOG
    if (opt_C) // -Cn
        G.shm_size = xatoul_range(opt_C, 4, INT_MAX/1024) * 1024;
#endif

//因为ENABLE_FEATURE_REMOTE_LOG为1，但我们没有使用-R选项，所以需要把消息记录到本地文件
    /* If they have not specified remote logging, then log locally */
    if (ENABLE_FEATURE_REMOTE_LOG && !(opts & OPT_remotelog)) // -R
        option_mask32 |= OPT_locallog;

    /* Store away localhost's name before the fork */
    G.hostname = safe_gethostname();//获得主机名，此时名称为ECB
    *strchrnul(G.hostname, '.') = '\0';

    if (!(opts & OPT_nofork)) {//有-n选项，所以此条件为false
        bb_daemonize_or_rexec(DAEMON_CHDIR_ROOT, argv);
    }
    umask(0);
    write_pidfile("/var/run/syslogd.pid");
    do_syslogd();
    /* return EXIT_SUCCESS; */
}

void record_signo(int signo)
{
    bb_got_signal = signo;
}

static void do_syslogd(void)
{
    int sock_fd;
#if ENABLE_FEATURE_SYSLOGD_DUP
    int last_sz = -1;
    char *last_buf;
    char *recvbuf = G.recvbuf;
#else
#define recvbuf (G.recvbuf)
#endif

    /* Set up signal handlers (so that they interrupt read()) */
    signal_no_SA_RESTART_empty_mask(SIGTERM, record_signo);//设置信号处理函数
    signal_no_SA_RESTART_empty_mask(SIGINT, record_signo);
    //signal_no_SA_RESTART_empty_mask(SIGQUIT, record_signo);
    signal(SIGHUP, SIG_IGN);
#ifdef SYSLOGD_MARK
    signal(SIGALRM, do_mark);
    alarm(G.markInterval);
#endif
    sock_fd = create_socket();创建UNIX套接字

//ENABLE_FEATURE_IPC_SYSLOG为0
    if (ENABLE_FEATURE_IPC_SYSLOG && (option_mask32 & OPT_circularlog)) {
        ipcsyslog_init();
    }

    timestamp_and_log_internal("syslogd started: BusyBox v" BB_VER);

    while (!bb_got_signal) {
        ssize_t sz;

#if ENABLE_FEATURE_SYSLOGD_DUP
        last_buf = recvbuf;
        if (recvbuf == G.recvbuf)
            recvbuf = G.recvbuf + MAX_READ;
        else
            recvbuf = G.recvbuf;
#endif
 read_again:
        sz = read(sock_fd, recvbuf, MAX_READ - 1);//从unix sock读取需要记录的信息
        if (sz < 0) {
            if (!bb_got_signal)
                bb_perror_msg("read from /dev/log");
            break;
        }

        /* Drop trailing '\n' and NULs (typically there is one NUL) */
        while (1) {
            if (sz == 0)
                goto read_again;
            /* man 3 syslog says: "A trailing newline is added when needed".
             * However, neither glibc nor uclibc do this:
             * syslog(prio, "test")   sends "test\0" to /dev/log,
             * syslog(prio, "test\n") sends "test\n\0".
             * IOW: newline is passed verbatim!
             * I take it to mean that it's syslogd's job
             * to make those look identical in the log files. */
            if (recvbuf[sz-1] != '\0' && recvbuf[sz-1] != '\n')
                break;
            sz--;
        }
#if ENABLE_FEATURE_SYSLOGD_DUP
        if ((option_mask32 & OPT_dup) && (sz == last_sz))
            if (memcmp(last_buf, recvbuf, sz) == 0)
                continue;
        last_sz = sz;
#endif
#if ENABLE_FEATURE_REMOTE_LOG
        /* We are not modifying log messages in any way before send */
        /* Remote site cannot trust _us_ anyway and need to do validation again */
        if (G.remoteAddrStr) {
            if (-1 == G.remoteFD) {
                G.remoteFD = try_to_resolve_remote();
                if (-1 == G.remoteFD)
                    goto no_luck;
            }
            /* Stock syslogd sends it '\n'-terminated
             * over network, mimic that */
            recvbuf[sz] = '\n';
            /* send message to remote logger, ignore possible error */
            /* TODO: on some errors, close and set G.remoteFD to -1
             * so that DNS resolution and connect is retried? */
            sendto(G.remoteFD, recvbuf, sz+1, MSG_DONTWAIT,
                    &G.remoteAddr->u.sa, G.remoteAddr->len);
 no_luck: ;
        }
#endif
        if (!ENABLE_FEATURE_REMOTE_LOG || (option_mask32 & OPT_locallog)) {
            recvbuf[sz] = '\0'; /* ensure it *is* NUL terminated */
            split_escape_and_log(recvbuf, sz);//把消息记录到/var/log/message
        }
    } /* while (!bb_got_signal) */

    timestamp_and_log_internal("syslogd exiting");
    puts("syslogd exiting");
    if (ENABLE_FEATURE_IPC_SYSLOG)
        ipcsyslog_cleanup();
    kill_myself_with_sig(bb_got_signal);
#undef recvbuf
}

//需要记录的消息格式一般如：<0>hello
static void split_escape_and_log(char *tmpbuf, int len)
{
    char *p = tmpbuf;

    tmpbuf += len;
    while (p < tmpbuf) {
        char c;
        char *q = G.parsebuf;
        int pri = (LOG_USER | LOG_NOTICE);//设置默认优先级

        if (*p == '<') {//如果有优先级，则先获得消息优先级
            /* Parse the magic priority number */
            pri = bb_strtou(p + 1, &p, 10);
            if (*p == '>')
                p++;
            if (pri & ~(LOG_FACMASK | LOG_PRIMASK))
                pri = (LOG_USER | LOG_NOTICE);
        }

        while ((c = *p++)) {//拷贝消息内容
            if (c == '\n')
                c = ' ';
            if (!(c & ~0x1f) && c != '\t') {
                *q++ = '^';
                c += '@'; /* ^@, ^A, ^B... */
            }
            *q++ = c;
        }
        *q = '\0';

        /* Now log it */
        if (LOG_PRI(pri) < G.logLevel)//消息优先级高于G.logLevel，则记录此消息到log文件
            timestamp_and_log(pri, G.parsebuf, q - G.parsebuf);
    }
}

static void timestamp_and_log(int pri, char *msg, int len)
{
    char *timestamp;
    time_t now;

    if (len < 16 || msg[3] != ' ' || msg[6] != ' '
     || msg[9] != ':' || msg[12] != ':' || msg[15] != ' '
    ) {
        time(&now);//获得系统时间
        timestamp = ctime(&now) + 4; /* skip day of week */
    } else {
        now = 0;
        timestamp = msg;
        msg += 16;
    }
    timestamp[15] = '\0';

    if (option_mask32 & OPT_small)//无-S选项
        sprintf(G.printbuf, "%s %s\n", timestamp, msg);
    else {
        char res[20];
        parse_fac_prio_20(pri, res);//吧优先级转换为可读的fac和prio
        sprintf(G.printbuf, "%s %.64s %s %s\n", timestamp, G.hostname, res, msg);//记录消息的格式：时间戳+主机名+可读的fac.prio+消息，如：Jan  1 00:00:05 ECB syslog.info syslogd started: BusyBox v1.14.1
    }

    /* Log message locally (to file or shared mem) */
    log_locally(now, G.printbuf);//把消息保存到的文件
}

{
    const CODE *c_pri, *c_fac;

    if (pri != 0) {
        c_fac = facilitynames;
        while (c_fac->c_name) {
            if (c_fac->c_val != (LOG_FAC(pri) << 3)) {
                c_fac++;
                continue;
            }
            /* facility is found, look for prio */
            c_pri = prioritynames;
            while (c_pri->c_name) {
                if (c_pri->c_val != LOG_PRI(pri)) {
                    c_pri++;
                    continue;
                }
                snprintf(res20, 20, "%s.%s",
                        c_fac->c_name, c_pri->c_name);
                return;
            }
            /* prio not found, bail out */
            break;
        }
        snprintf(res20, 20, "<%d>", pri);
    }
}

static void log_locally(time_t now, char *msg)
{
#ifdef SYSLOGD_WRLOCK
    struct flock fl;
#endif
    int len = strlen(msg);

#if ENABLE_FEATURE_IPC_SYSLOG
    if ((option_mask32 & OPT_circularlog) && G.shbuf) {
        log_to_shmem(msg, len);
        return;
    }
#endif
    if (G.logFD >= 0) {//如果已经打开
        /* Reopen log file every second. This allows admin
         * to delete the file and not worry about restarting us.
         * This costs almost nothing since it happens
         * _at most_ once a second.
         */
        if (!now)
            now = time(NULL);
        if (G.last_log_time != now) {
            G.last_log_time = now;
            close(G.logFD);
            goto reopen;
        }
    } else {
 reopen:第一次默认打开/var/log/message文件
        G.logFD = open(G.logFilePath, O_WRONLY | O_CREAT
                    | O_NOCTTY | O_APPEND | O_NONBLOCK,
                    0666);
        if (G.logFD < 0) {
            /* cannot open logfile? - print to /dev/console then */
            int fd = device_open(DEV_CONSOLE, O_WRONLY | O_NOCTTY | O_NONBLOCK);
            if (fd < 0)
                fd = 2; /* then stderr, dammit */
            full_write(fd, msg, len);
            if (fd != 2)
                close(fd);
            return;
        }
#if ENABLE_FEATURE_ROTATE_LOGFILE
        {
            struct stat statf;
            G.isRegular = (fstat(G.logFD, &statf) == 0 && S_ISREG(statf.st_mode));
            /* bug (mostly harmless): can wrap around if file > 4gb */
            G.curFileSize = statf.st_size;
        }
#endif
    }

#ifdef SYSLOGD_WRLOCK
    fl.l_whence = SEEK_SET;
    fl.l_start = 0;
    fl.l_len = 1;
    fl.l_type = F_WRLCK;
    fcntl(G.logFD, F_SETLKW, &fl);
#endif

#if ENABLE_FEATURE_ROTATE_LOGFILE
    if (G.logFileSize && G.isRegular && G.curFileSize > G.logFileSize) {
        if (G.logFileRotate) { /* always 0..99 */
            int i = strlen(G.logFilePath) + 3 + 1;
            char oldFile[i];
            char newFile[i];
            i = G.logFileRotate - 1;
            /* rename: f.8 -> f.9; f.7 -> f.8; ... */
            while (1) {
                sprintf(newFile, "%s.%d", G.logFilePath, i);
                if (i == 0) break;
                sprintf(oldFile, "%s.%d", G.logFilePath, --i);
                /* ignore errors - file might be missing */
                rename(oldFile, newFile);
            }
            /* newFile == "f.0" now */
            rename(G.logFilePath, newFile);
#ifdef SYSLOGD_WRLOCK
            fl.l_type = F_UNLCK;
            fcntl(G.logFD, F_SETLKW, &fl);
#endif
            close(G.logFD);
            goto reopen;
        }
        ftruncate(G.logFD, 0);
    }
    G.curFileSize +=
#endif
            full_write(G.logFD, msg, len);//记录消息到文件
#ifdef SYSLOGD_WRLOCK
    fl.l_type = F_UNLCK;
    fcntl(G.logFD, F_SETLKW, &fl);
#endif
}