撮合引擎开发:日志输出

2019-12-09 12:42:28 浏览数 (1)

欢迎关注「Keegan小钢」公众号获取更多文章


价值超5万的撮合引擎:开篇

价值超5万的撮合引擎:MVP版本

撮合引擎开发:数据结构设计

撮合引擎开发:对接黑箱

撮合引擎开发:解密黑箱流程

撮合引擎开发:流程的代码实现

撮合引擎开发:缓存和MQ


日志需求

我们都知道日志在一个程序中有着重要的作用,撮合引擎也同样需要一个完善的日志输出功能,以方便调试和查询数据。

对一个撮合引擎来说,需要输出的日志主要有以下几类:

1.程序启动的日志,包括连接 Redis 成功的日志、Web 服务启动成功的日志;2.接口请求和响应数据的日志;3.启动了某引擎的日志;4.关闭了某引擎的日志;5.订单被添加到 orderBook 的日志;6.成交记录的日志;7.撤单结果的日志。

另外,撮合引擎产生的日志会非常多,所以还应该做日志分割,按日期分割是最常用的日志分割方式,所以我们也同样将不同日期的日志分割到不同日志文件保存。

实现思路

首先,我们都知道日志是有分级别的,多的比如 log4j 定义了 8 种级别的日志。不过,最常用的就 4 种级别,优先级从低到高分别为:DEBUG、INFO、WARN、ERROR。一般,不同环境会设置不同的日志级别,如 DEBUG 级别一般只在开发和测试环境才设置,生产环境则会设置为 INFO 或更高级别。当设置为高级别时,低级别的日志消息是不会打印出来的。那为了打印不同级别的日志消息,可以提供不同级别的打印函数,比如提供 log.Debug()、log.Info() 等函数。

其次,日志需要输出到文件保存,因此,就需要指定文件保存的目录、文件名和文件对象。一般,保存的文件目录和运行程序应该放在一起,所以,指定的文件目录最好是相对路径。

另外,文件还要根据日期做分割,即不同日期的日志消息要保存到不同的日志文件,那么,自然要记录下当前日志的日期。以及需要定时监控,当检测到最新日期跟当前日志的日期相比已经跨日了,说明需要进行日志分割了,那就将当前的日志文件进行备份,并创建新文件用来保存新日期的日志消息。

最后,日志消息写入文件的话,那就少不了耗时的 I/O 操作,如果用同步方式写日志,无疑会减低撮合性能,因此,最好选用异步方式写日志,可以用带缓冲的通道实现。

代码实现

我重新自定义了一个 log 包,并创建了 log.go 文件,所有代码都写在该文件中。

第一步,先定义几种日志等级,直接定义成枚举类型,如下:

代码语言:javascript复制
type LEVEL byte

const (
    DEBUG LEVEL = iota
    INFO
    WARN
    ERROR
)

第二步,定义日志的结构体,其包含的字段比较多,如下:

代码语言:javascript复制
type FileLogger struct {
    fileDir        string         // 日志文件保存的目录
    fileName       string         // 日志文件名(无需包含日期和扩展名)
    prefix         string         // 日志消息的前缀
    logLevel       LEVEL          // 日志等级
    logFile        *os.File       // 日志文件
    date           *time.Time     // 日志当前日期
    lg             *log.Logger    // 系统日志对象
    mu             *sync.RWMutex  // 读写锁,在进行日志分割和日志写入时需要锁住
    logChan        chan string    // 日志消息通道,以实现异步写日志
    stopTickerChan chan bool      // 停止定时器的通道
}

第三步,为了能将日志应用到程序中任何地方,就需要定义一个全局的日志对象,并要对该日志对象进行初始化。初始化操作有一点复杂,我们先来看代码:

代码语言:javascript复制
const DATE_FORMAT = "2006-01-02"

var fileLog *FileLogger

func Init(fileDir, fileName, prefix, level string) error {
    CloseLogger()

    f := &FileLogger{
        fileDir:       fileDir,
        fileName:      fileName,
        prefix:        prefix,
        mu:            new(sync.RWMutex),
        logChan:       make(chan string, 5000),
        stopTikerChan: make(chan bool, 1),
    }

    switch strings.ToUpper(level) {
    case "DEBUG":
        f.logLevel = DEBUG
    case "WARN":
        f.logLevel = WARN
    case "ERROR":
        f.logLevel = ERROR
    default:
        f.logLevel = INFO
    }

    t, _ := time.Parse(DATE_FORMAT, time.Now().Format(DATE_FORMAT))
    f.date = &t

    f.isExistOrCreateFileDir()

    fullFileName := filepath.Join(f.fileDir, f.fileName ".log")
    file, err := os.OpenFile(fullFileName, os.O_RDWR|os.O_APPEND|os.O_CREATE, 0666)
    if err != nil {
        return err
    }
    f.logFile = file

    f.lg = log.New(f.logFile, prefix, log.LstdFlags|log.Lmicroseconds)

    go f.logWriter()
    go f.fileMonitor()

    fileLogger = f

    return nil
}

这个初始化的逻辑有点多,我来进行拆分讲解。首先,第一步,调用了 CloseLogger() 函数,该函数主要是关闭文件、关闭通道等操作。为了停止一个不断循环的 goroutine,关闭通道是一个常用的方案,这在之前的文章也有说过。那么,由于初始化函数可以会被调用多次,以实现配置的变更,那如果不先结束旧的 goroutine ,那同样功能的 goroutine 将不止一个在同时运行,这无疑将会出问题。因此,需要先关闭 Logger,关闭 Logger 的代码如下:

代码语言:javascript复制
func CloseLogger() {
    if fileLogger != nil {
        fileLogger.stopTikerChan <- true
        close(fileLogger.stopTikerChan)
        close(fileLogger.logChan)
        fileLogger.lg = nil
        fileLogger.logFile.Close()
    }
}

关闭 Logger 之后,就是对一些字段的初始化赋值了,其中,f.date 设置为了当前日期,后面判断是否需要分割就以这个日期为条件。f.isExistOrCreateFileDir() 则会判断日志目录是否存在,如果不存在则会创建该目录。接着,将目录、设置的文件名和添加的 .log 文件扩展名拼接在一起,拼接出文件的完整名字并打开文件。之后就是用该文件来初始化系统日志对象 f.lg 了,将日志消息写入文件时其实就是调用该对象的 Output() 函数。后面启动了两个 goroutine:一个用来监听 logChan,实现将日志消息写入文件;一个用来定时监听文件是否需要分割,需要分割时则实现分割。

接着,我们就来看看这两个 goroutine 的实现:

代码语言:javascript复制
func (f *FileLogger) logWriter() {
    defer func() { recover() }()

    for {
        str, ok := <-f.logChan
        if !ok {
            return
        }

        f.mu.RLock()
        f.lg.Output(2, str)
        f.mu.RUnlock()
    }
}

func (f *FileLogger) fileMonitor() {
    defer func() { recover() }()
    ticker := time.NewTicker(30 * time.Second)
    defer ticker.Stop()
    for {
        select {
        case <-ticker.C:
            if f.isMustSplit() {
                if err := f.split(); err != nil {
                    Error("Log split error: %vn", err)
                }
            }
        case <-f.stopTikerChan:
            return
        }
    }
}

可以看到 logWriter() 循环从 logChan 通道读取日志消息,当通道被关闭则退出,否则就调用 f.lg.Output() 将日志输出。fileMonitor() 里则创建了一个每隔 30 秒发送一次的 ticker,当从 ticker.C 接收到数据之后,就判断是否需要分割,如果需要则调用分割函数 f.split()。而从 f.stopTikerChan 收到数据时,说明该定时器也要结束了。

接着,再来看看 isMustSplit()split() 函数了。isMustSplit() 非常简单,就两行代码,如下:

代码语言:javascript复制
func (f *FileLogger) isMustSplit() bool {
    t, _ := time.Parse(DATE_FORMAT, time.Now().Format(DATE_FORMAT))
    return t.After(f.date)
}

split() 则复杂些,首先对日志要先加写锁,避免分割时依然有日志写入,接着对当前的日志文件进行重命名备份,然后生成新文件用来记录新的日志消息,并将当前的全局日志对象指向新文件、新日期和新的系统日志对象。实现代码如下:

代码语言:javascript复制
func (f *FileLogger) split() error {
    f.mu.Lock()
    defer f.mu.Unlock()

    logFile := filepath.Join(f.fileDir, f.fileName)
    logFileBak := logFile   "-"   f.date.Format(DATE_FORMAT)   ".log"

    if f.logFile != nil {
        f.logFile.Close()
    }

    err := os.Rename(logFile, logFileBak)
    if err != nil {
        return err
    }

    t, _ := time.Parse(DATE_FORMAT, time.Now().Format(DATE_FORMAT))
    f.date = &t

    f.logFile, err = os.OpenFile(logFile, os.O_RDWR|os.O_APPEND|os.O_CREATE, 0666)
    if err != nil {
        return err
    }

    f.lg = log.New(f.logFile, f.prefix, log.LstdFlags|log.Lmicroseconds)

    return nil
}

最后,就剩下定义一些接收日志消息的函数了,实现都很简单,以 Info() 为例:

代码语言:javascript复制
func Info(format string, v ...interface{}) {
    _, file, line, _ := runtime.Caller(1)
    if fileLogger.logLevel <= INFO {
        fileLogger.logChan <- fmt.Sprintf("[%v:%v]", filepath.Base(file), line)   fmt.Sprintf("[INFO]" format, v...)
    }
}

Debug()、Warn()、Error() 等函数都类似的,照猫画虎即可。

至此,我们这个能够实现按日期分割日志文件的日志包就完成了,剩下的,就在对应需要添加日志输出的地方调用响应的日志等级函数即可。

小结

本小结的核心其实是增加了一个通用的日志包,该日志包不仅可以用在我们的撮合引擎,也能用于其他项目。如果再将其扩展,还可以改为按其他条件分割,比如按小时分割,或按文件大小分割。有兴趣的小伙伴可以自己去尝试一下。

今日的思考题:要实现接口的请求和响应数据进行统一的日志输出,有哪些方案?

0 人点赞