【原创】packetbeat 之“WARN Time in pcap went backwards: 0”警告问题

前端之家收集整理的这篇文章主要介绍了【原创】packetbeat 之“WARN Time in pcap went backwards: 0”警告问题前端之家小编觉得挺不错的,现在分享给大家,也给大家做个参考。

问题描述

在使用 packetbeat 进行数据包分析过程中,输出了以下几种数值:

➜  packetbeat git:(master) ✗ ./packetbeat -c ./packetbeat.yml -e -I redis_xxxx.pcap 2>&1 |grep "pcap went backwards"
...
2017/01/11 06:57:47.091832 sniffer.go:365: WARN Time in pcap went backwards: -2000
...
2017/01/11 06:57:47.189023 sniffer.go:365: WARN Time in pcap went backwards: -1000
...
2017/01/11 06:57:47.189238 sniffer.go:365: WARN Time in pcap went backwards: 0

源码分析

sniffer.go 中,找到如下代码

func (sniffer *SnifferSetup) Run() error {
        ...
		if sniffer.config.File != "" {  // 如果是读取的 pcap 文件
			if lastPktTime != nil && !sniffer.config.TopSpeed { // TopSpeed 对应 -t 选项
		        // 计算前后两个数据包的时间戳之差
				sleep := ci.Timestamp.Sub(*lastPktTime)
				if sleep > 0 {
					time.Sleep(sleep)
				} else {
				    // 发现时间戳有“回退”
					logp.Warn("Time in pcap went backwards: %d",sleep)
				}
			}
			_lastPktTime := ci.Timestamp
			lastPktTime = &_lastPktTime
			// 若没有设置 -t 选项,则使用当前系统时间作为包的时间戳
			if !sniffer.config.TopSpeed {
				ci.Timestamp = time.Now() // overwrite what we get from the pcap
			}
		}
		...
}

问题原因

相邻两个数据包之间的时间差,是基于包捕获时的时间戳计算得到的;当存在大量 TCP 重传情况时(如下图),则会出现时间戳相同的情况;当有乱序发生时,则会出现时间戳差值为负的情况;

该问题与是否使用 -t 选项没有直接关系;

解决办法

可以通过设置 -t 参数绕过此问题,因为此时不会输出相应的打印内容

补充试验

使用 -t 选项的情况:

...
2017/01/11 07:19:05.673469 logp.go:246: INFO Uptime: 523.788161ms

未使用 -t 选项的情况:

...
2017/01/11 07:20:27.991096 logp.go:246: INFO Uptime: 14.847278439s

经确认,使用 -t 选项的目的在于能够准确的按照包内容进行数据重放(包括时间延迟);

其他

在官方论坛上的讨论

猜你在找的Go相关文章