# Packetbeat: Something wired with "WARN Time in pcap went backwards"

**URL:** <https://discuss.elastic.co/t/packetbeat-something-wired-with-warn-time-in-pcap-went-backwards/72142>\
**Category:** Beats\
**Tags:** packetbeat\
**Created:** [January 19, 2017, 9:52am UTC](https://discuss.elastic.co/t/packetbeat-something-wired-with-warn-time-in-pcap-went-backwards/72142 "2017-01-19T09:52:09Z")\
**Posts on this page:** 4\
**Page:** 1

<div class="post-metadata">

**Author:** ![moooofly](https://avatars.discourse-cdn.com/v4/letter/m/d2c977/32.png) [@moooofly](https://discuss.elastic.co/u/moooofly)\
**Post date:** [January 19, 2017, 9:52am UTC](https://discuss.elastic.co/t/packetbeat-something-wired-with-warn-time-in-pcap-went-backwards/72142/1 "2017-01-19T09:52:09Z")

</div>

when analyzing pcap files, I always find outputs as follow:

```auto
➜ 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

```

after some source codes digging, I find something I can not understand.

```auto
func (sniffer *SnifferSetup) Run() error {
                ...
		if sniffer.config.File != "" {
			if lastPktTime != nil && !sniffer.config.TopSpeed { 
				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
			if !sniffer.config.TopSpeed {
				ci.Timestamp = time.Now() // overwrite what we get from the pcap
			}
		}

```

According to the code, if `-t` option not set, every packet in the pcap file will use current system time as timestamp. However, when computing time difference between two successive packets, the latter one use its real timestamp which is set on capturing. I think it is the root case why "backwards" happends, and I think it is a bug.

right now, when reading packets from pcap files, I always use `-t` option to avoid annoying "backwards" output.

Can someone tell me if I misunderstanding anything? Tks in advance.

---

<div class="post-metadata">

**Author:** ![steffens](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/steffens/32/79630_2.png) [@steffens](https://discuss.elastic.co/u/steffens)\
**Post date:** [January 19, 2017, 11:23am UTC](https://discuss.elastic.co/t/packetbeat-something-wired-with-warn-time-in-pcap-went-backwards/72142/2 "2017-01-19T11:23:33Z")

</div>

Have you checked your pcap?

Cleaning up the sample code a little it becomes:

```auto
	if sniffer.config.File != "" {
		if !sniffer.config.TopSpeed {
			pktTime := ci.Timestamp
			if lastPktTime != nil {
				sleep := pktTime.Sub(*lastPktTime)
				if sleep > 0 {
					time.Sleep(sleep)
				} else {
					logp.Warn("Time in pcap went backwards: %d", sleep)
				}
			}
			lastPktTime = &pktTime

			// overwrite what we get from the pcap
			ci.Timestamp = time.Now()
		}
	}

```

you're right, if topspeed is disabled, the system time is assigned to the packet. But the system time is assigned after the sleep. That is the sleep instruction indeed uses the delta timestamps between packets as available in the pcap file. This is done, so that replaying the pcap will be about as fast as the original traffic being recorded. That is, the warning seems to be correct to me.

---

<div class="post-metadata">

**Author:** ![moooofly](https://avatars.discourse-cdn.com/v4/letter/m/d2c977/32.png) [@moooofly](https://discuss.elastic.co/u/moooofly)\
**Post date:** [January 20, 2017, 4:21am UTC](https://discuss.elastic.co/t/packetbeat-something-wired-with-warn-time-in-pcap-went-backwards/72142/3 "2017-01-20T04:21:33Z")

</div>

yes, I get it, according to your advice, I checked my pcap file, the timestamps in it seem reasonable to me.

some snapshots here:

- Seconds since beginning of capture  
 ![](https://us1.discourse-cdn.com/elastic/original/2X/c/c1be18a6c5a3376f2882fe358f943c84387c5d6a.png)

- Date and time of day  
 ![](https://us1.discourse-cdn.com/elastic/original/2X/3/3897e3fd092d3b3bdfb1c030d9dd40e9310f2750.png)

From the snapshots, I find the reason why there are tens of thousands of "Time in pcap went backwards" warnings. It is the "**[TCP Retransmission]**" that results in this issue.

In my test, I get **15563** times of this warning info.

```auto
root@vagrant-ubuntu-trusty:/go/src/github.com/elastic/beats/packetbeat# ./packetbeat -c ./packetbeat.yml -e -I redis_xxx.pcap -E packetbeat.protocols.redis.ports=7101 2>&1 |grep "WARN Time in pcap went backwards" |wc -l
15563

```

The conclusion is

- the warning is correct.
- network situation is the real problem.

tks again.

---

<div class="post-metadata">

**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\
**Post date:** [February 17, 2017, 4:21am UTC](https://discuss.elastic.co/t/packetbeat-something-wired-with-warn-time-in-pcap-went-backwards/72142/4 "2017-02-17T04:21:36Z")

</div>

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.