Incorrect timestamp in v9 capture

[bbayles]

I am trying to use nfdump to read a NetFlow feed from Meraki devices. I am using nfcapd with -T all to receive the data feed.

When I use nfdump to read the file I get an incorrect timestamp. It seems to be fixed to 1451164051, or 2015-12-26 15:07:31:

$ nfdump -r local_cap.nf -b -q
2015-12-26 15:07:31.296     0.000 TCP       192.168.5.25:445   <->       10.10.1.13:57377        6       10      530      638     2
2015-12-26 15:07:31.296     0.000 TCP       192.168.5.25:445   <->       10.10.1.11:42433        3        5      265      319     1
2015-12-26 15:07:31.296     0.000 TCP       192.168.5.25:445   <->       10.10.1.11:42439        6       10      530      638     2
2015-12-26 15:07:31.296     0.000 TCP       192.168.5.25:445   <->       10.10.1.14:59302        6       10      530      638     2
2015-12-26 15:07:31.296     0.000 TCP       192.168.5.25:445   <->       10.10.1.13:57380        6       10      530      638     2
2015-12-26 15:07:31.296     0.000 TCP       192.168.5.25:445   <->       10.10.1.12:36507        3        5      265      319     1

Wireshark's CFlow dissector can properly interpret the timestamp:

I have attached a small excerpt of the nfcapd-generated file and also a PCAP file with a sample packet: v9-export.zip

I would expect nfdump to show the timestamp like Wireshark.

[bbayles]

Some clarification:

• The incorrect timestamp is produced by nfcapd; it can be seen in a hex dump of the save file.
• That timestamp seems to be a function of the SysUptime shown in my screenshot above. The Timestamp plus the (negative) SysUptime produces the incorrect value shown.

[chendrickson14]

I am running into similar issues with Nagios Network Analyzer and Fortinet Firewalls. If I need to provide any further information, please let me know.

[cosidius]

Fortinet is fixed in version 5.2.5 bug id 275897

Was caused by not resetting all timers when they wrapped. Not a nfdump problem when using Fortigate.

[chendrickson14]

I am using FortiOS version 5.2.6 at this point in time and I am still experiencing the issue. Do you happen to know if it came back in newer versions past 5.2.5?

[cosidius]

RFC 3954 terms definition: #########################

LAST_SWITCHED : sysUptime in msec at which the last packet of this Flow was switched (page 19) FIRST_SWITCHED : sysUptime in msec at which the first packet of this Flow was switched (page 19) sysUpTime: Time in milliseconds since this device was first booted. (page 9)

All three timers are depended of each other. When sysUpTime wraps after <50 days the rfc states that you exports all current flows and reset all counters else you will get a skew in time between them. Most noteble is that it will look like you switched the packet in the future. This was the problem seen in Fortigate prior to version 5.2.5 If this problem still exist I dont know. I have only a uptime of 23 days after my update to 5.2.6

sysUpTime in netflow are not the same as sys uptime of the operating system.

The timers are unsigned integers when exported form fortigate so they never have a negative value as decoded by wireshark.

Calculate when the packet was first seen in this flow? ((CurrentSecs * 1000) - sysUpTime) + FIRST_SWITCHED = epoch timestamp in milliseconds

Calculate when the packet was last seen in this flow? ((CurrentSecs * 1000) - sysUpTime) + LAST_SWITCHED = epoch timestamp in milliseconds

[TR0X]

Hi,

have the same problem as above, but our timestamps in the .pcap file are correct. Any ideas what could be wrong?

I really appreciate any help you can provide.

[cosidius]

I do not have the problem in Fortigate 1500D v5.2.6,build711 (GA) and decoding it with the nfdump 1.6.14

[TR0X]

Our source is a Cisco product and doesn't matter in that case, 'cause the timestamp in the pcap files is correct. Any ideas?

[cosidius]

Sorry I cant help you there. I run a Cisco 6509E and Fortigate and I have never seen that problem from Cisco when decoded by nfdump.

[phaag]

It looks like some exporters whatever flavors do not send correct or no time stamps at all. Be aware that the sysuptime mentioned in the first post of bbayles shows the device sysuptime and has nothing to do with the start/end time of the flows. These are simply missing in your v9-export.zip which you also can see in wireshark: It is therefore an exporter issue for not sending proper time records. The elements

define NF9_LAST_SWITCHED 21

define NF9_FIRST_SWITCHED 22

are missing in the stream

[bbayles]

I agree with you that the input file could include these data, but that hardly justifies showing incorrect timestamps in the nfudmp output, yes?

[phaag]

Processing the file results in:

Flow Record:
  Flags        =              0x06 FLOW, Unsampled
  export sysid =                 1
  size         =                88
  first        =                 0 [1970-01-01 01:00:00]
  last         =                 0 [1970-01-01 01:00:00]
  msec_first   =                 0
  msec_last    =                 0
  src addr     =      192.168.5.25
  dst addr     =        10.10.1.12
  src port     =               445
  dst port     =             40024
  fwd status   =                 0
  tcp flags    =              0x00 ......
  proto        =                 6 TCP  
  (src)tos     =                 0
  (in)packets  =                 1
  (in)bytes    =                60
  out packets  =                 0
  out bytes    =                 0
  ip router    =       192.168.5.3
  engine type  =                 0
  engine ID    =                 0

The time is set to 0 and therefore the time results in 1970-01-01 01:00:00. Although, you are correct, that this time is incorrect, one should recognize the missing timestamps. If I missed something, let me know.