实用设计分享：千万行日志，如何获取指定时间戳之后的n行日志？

后端性能优化 Golang 设计

一、背景描述

1.为什么会想到做这个场景？这个场景有什么意义？

我们的项目主要是作为集团的基础服务，提供业务可观测支撑的。在大概一年前，我们项目接到了上游同学的需求，想要查看业务异常时候的日志。

首先说一下业务场景，由于我们是基础服务，从资源供给的角度来讲，我们没有办法，全量采集所有上层业务的日志。原因：

上游业务不可控。
业务量庞大。
数据日志庞大。
基础存储无法支撑。

2.我们当时是如何考虑和设计的？

针对这个场景，我们想到了对 OpenTelemetry 仓库的，Filelog receiver 进行二次开发。

原始的Filelog receiver，只支持从文件最开始，或者文件最末尾采集后续的所有日志，启动后无法停止，会对我们的存储造成很大冲击，而且业务侧不可控。

因此，我们提出了 ondemand 方式，即按需采集。当上游同学通过我们的平台发起日志查询时，平台会发起采集请求，经过中间链路，通知我们的 Filelog receiver 进行一定时间的日志采集，比如 10min，而后进行停止。

但是，我们虽然做了二次开发，保障了我们存储服务的压力，但还是有很显著的问题：

我们的采集，是从用户的触发时间点开始采集的。
而用户想要查询日志的需求，一定是业务发生了一些错误，才会去有查询日志的行为。

没错，我们的日志采集是滞后的，对于用户来讲，采集的大概率是无效的日志。

也因此，我们一直将这个需求给搁置了。

二、切入点的突破

在技术上，我个人是比较喜欢专研的。针对之前的这个问题，一直放在心上，有啥新思路或者想法，都会想着尝试去做一做。

由于现在工作的特殊性，每天下班回家，都有时间保持刷算法，刷到现在，慢慢的感受到，算法本身就是各类问题解决方法的抽象的集合，所以平时也会想着把学到的算法应用到业务的优化中。

针对上述的业务场景，我预设了条件：如果能够知道当前日志文件的日志行数，如果能够很快的查询到第n条日志行，那么可以运用二分查找，很容易的就可以查到大于等于某个时间戳的日志行。问题就直接被拆解了。

但很遗憾，针对文件日志条目查询和查询第n行日志，没有找到很有效的方式。因为文件的存储，本身是一些字节流数据，它没有行的概念，操作系统对文件的存储，也没有这样的标志，文件行的识别，本质上是通过特殊字符 '\n' 或者 '\r\n' 等标记的。所以，我无法做到通过调用某些API，实现O(1)的复杂度，直接获取结果。

于是，我尝试使用 Golang 原生的 api，进行上述数据的获取测试。得到了进一步的突破：

通过 bufio.Scanner()，扫描 1.5GB 的数据，千万行代码，只需要 数百毫秒 就可以做到。

三、数据测试

测试数据准备：千万行级别日志，大小1GB+。

du -sh pkg/file-process/log1 
1.5G    pkg/file-process/log1

cat pkg/file-process/log1|wc -l
11601560

日志时间格式：符合klog日志标准。如：

E0424 23:27:27.690467 xxxxxxxxxxxxxxxxxxxxx

1. 文件行统计

通过 bufio.Scanner() 实现 O(n) 复杂度的文件扫描。

func countFile(filepath string) (int, error) {
	file, err := os.Open(filepath)
	if err != nil {
		return 0, err
	}
	defer file.Close()
	// 使用scanner，逐行扫描
	sc := bufio.NewScanner(file)
	lineCount := 0
	for sc.Scan() {
		lineCount++
	}
	return lineCount, nil
}

验证：

func main() {
	filepath := `./pkg/file-process/log1`
	start := time.Now()
	count, err := countFile(filepath)
	fmt.Println(count, err, time.Since(start))
}

go run pkg/file-process/main.go
11601561 <nil> 478.404125ms

2. 转化日志行的时间戳

日志参考标准：

E0424 23:27:27.690467 xxxxxxxxxxxxxxxxxxxxx

func parseTime(msg string) (time.Time, error) {
	// 取前21个字符，舍弃第一个字符
	timeStr := msg[:21][1:]
	// 0424 23:27:27.690467
	// 0424
	datePart := timeStr[:4]
	// 23:27:27.690467
	timePart := timeStr[5:]
	now := time.Now()
	currentYear := now.Year()
	currentMonth := now.Month()
	// 提取月份和日期
	month, _ := strconv.Atoi(datePart[:2])
	day, _ := strconv.Atoi(datePart[2:])
	// 决定年份
	var year int
	if month > int(currentMonth) {
		year = currentYear - 1
	} else {
		year = currentYear
	}
	// 加载东八区时区
	location, err := time.LoadLocation("Asia/Shanghai")
	if err != nil {
		return time.Time{}, err
	}
	// 创建时间
	dateStr := fmt.Sprintf("%04d-%02d-%02d %s", year, month, day, timePart)
	parsedTime, err := time.ParseInLocation("2006-01-02 15:04:05.000000", dateStr, location)
	if err != nil {
		return time.Time{}, err
	}
	return parsedTime, nil
}

测试：

func main() {
	fmt.Println(parseTime("E0424 23:27:27.690467 xxxxxxxxxxxxxxxxxxxxx"))
}

 go run pkg/file-process/main.go
2025-04-24 23:27:27.690467 +0800 CST <nil>

3. 获取文件的第n行日志

// 从0开始
func getNthLog(n int, filepath string) string {
	file, err := os.Open(filepath)
	if err != nil {
		return ""
	}
	defer file.Close()
	sc := bufio.NewScanner(file)
	lineCnt := -1
	for sc.Scan() {
		lineCnt++
		if lineCnt == n {
			return sc.Text()
		}
	}
	return ""
}

测试：

func main() {
	filepath := "./pkg/file-process/log1"
	fmt.Println(getNthLog(0, filepath))
}

go run pkg/file-process/main.go
I0424 22:21:38.901831       xxxxxxxxxxxxxxxxxxxxxxxx

4. 使用二分查找获取大于等于目标时间戳的最小行

通过 Golang 原生 api 实现二分查找下界查询，需要注意：行数从0开始统计，如果返回行数 n == totalCnt, 表示没查到目标行。

func getObjLineAfterTimestamp(totalCnt int, timestamp time.Time, filepath string) int {
	return sort.Search(totalCnt, func(i int) bool {
		// 获取第i行日志
		msg := getNthLog(i, filepath)
		curTime, err := parseTime(msg)
		if err != nil {
			log.Printf("parse time err: %s", err.Error())
			return false
		}
		return curTime.Equal(timestamp) || curTime.After(timestamp)
	})
}

验证：

func main() {
	filepath := "./pkg/file-process/log1"
	// 2. 通过二分查找, 获取 >= t 时间的最小代码行
	location, _ := time.LoadLocation("Asia/Shanghai")
	t, _ := time.ParseInLocation("2006-01-02 15:04:05.000000", "2025-04-24 22:21:38.998831", location)
	fmt.Println(t)
	objLine := getObjLineAfterTimestamp(11601561, t, filepath)
	fmt.Println(objLine)
}

go run pkg/file-process/main.go
2025-04-24 22:21:38.998831 +0800 CST
309

5. 获取二分查找得到的目标行之后的n行日志

func getNLogFromStartline(start, n int, filepath string) []string {
	file, err := os.Open(filepath)
	if err != nil {
		return nil
	}
	defer file.Close()
	sc := bufio.NewScanner(file)
	obj := -1
	for sc.Scan() {
		obj++
		if obj == start {
			break
		}
	}
	ans := make([]string, 0, n)
	ans = append(ans, sc.Text())
	for sc.Scan() {
		if len(ans) == n {
			break
		}
		ans = append(ans, sc.Text())
	}
	return ans
}

验证：

func main() {
	filepath := "./pkg/file-process/log1"
	// 2. 通过二分查找, 获取 >= t 时间的最小代码行
	logs := getNLogFromStartline(309, 1000, filepath)
	fmt.Println(len(logs))
}

go run pkg/file-process/main.go
1000

6. 多组用例，整体时延测试

func GetNLogAfterTime(filepath string, t time.Time, n int) ([]string, error) {
	// 1. 获取文件行数
	lineCnt, err := countFile(filepath)
	if err != nil {
		return nil, err
	}
	// 2. 通过二分查找, 获取 >= t 时间的最小代码行
	objLine := getObjLineAfterTimestamp(lineCnt, t, filepath)
	// 没有符合条件的日志
	if objLine == lineCnt {
		return nil, nil
	}
	// 3. 从objLine开始，读取n行日志返回, 不够n行则全部返回
	return getNLogFromStartline(objLine, n, filepath), nil
}

测试：

func main() {
	filepath := "./pkg/file-process/log1"
	t1, _ := parseTime("I0424 22:42:38.314337")
	now := time.Now()
	logs, err := GetNLogAfterTime(filepath, t1, 1000000)
	duration := time.Since(now)
	fmt.Println(len(logs), err, duration)
}

go run pkg/file-process/main.go
1000000 <nil> 1.176719625s

按上述实现，在千万行数据里面，找到某个目标时间戳之后的百万行数据，只需要1.x s。实现了十分可观的性能！

补充：

读者可以使用如下代码，构造日志。

package main

import (
	"flag"

	"k8s.io/klog/v2"
)

func main() {
	klog.InitFlags(nil)
	defer klog.Flush() // 确保程序结束时将缓存日志刷入文件

	logFile := "./log"
	flag.Set("logtostderr", "false")
	flag.Set("log_file", logFile)

	flag.Parse()
	for i := 0; i < 1e7; i++ {
		klog.Info("xxx")
	}
}

klog打印时，会打印一些额外的信息，由于代码里面没有特殊判断，可能会误识别，建议删除文件开头信息，

Log file created at: 2025/04/24 17:36:11
Running on machine: U-L2M7XGNF-2325
Binary: Built with gc go1.18 for darwin/arm64
Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg

以及文件末尾一些空行信息。

四、补充说明

上述用例二分实现使用的是Golang sort包下面的二分查找api，对于查询有序数据下界来说极其便利。

而我们在获取第n行数据时，由于每次都需要从0开始扫描，如果数据不存在的话，我们的扫描次数会很多，导致时延升高到十几秒。

针对这一点可以做如下优化：scanner 复用。对于以扫描的n行数据，做记忆化存储：进行复用。