Time value errors

Zeek
1

Noted what appear to be errors in the ntp.log file.

Using following command:

cat ntp.log | zeek-cut –d | less

af_packet::eno1 2019-12-18T17:44:39-0500 C7MULpTngYof10ymf 10.1.45.35 123 10.1.5.60 123 2 3 4 64.000000 0.000004 0.070786 0.113083 10.1.5.60 2019-12-18T17:43:35-0500 2019-12-18T17:43:35-0500 2019-12-18T17:43:35-0500 2019-12-18T17:44:39-0500 0

af_packet::eno1 2019-12-18T17:44:39-0500 C7MULpTngYof10ymf 10.1.45.35 123 10.1.5.60 123 3 4 3 64.000000 0.015625 0.069839 0.077545 23.239.26.89 2019-:zeek-cut: time value out-of-range: -586465861.545972

zeek-cut: time value out-of-range: -586465861.545972

12-18T17:42:18-0500 2019-12-18T17:44:39-0500 2019-12-18T17:44:39-0500 2019-12-18T17:44:39-0500 0

af_packet::eno1 2019-12-18T17:44:39-0500 C5GF2T1ozzCZptCbjf 10.1.204.212 123 10.1.5.180 123 3 3 15 64.000000 0.007812 0.000000 2.009995 0.0.0.0 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500 2019-12-18T17:44:46-0500 0

af_packet::eno1 2019-12-18T17:44:40-0500 CxaJ6KeJfxVcN8Fw2 10.1.201.150 123 10.1.5.180 123 3 3 15 64.000000 0.007812 0.000000 2.009995 0.0.0.0 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500 2019-12-18T17:44:48-0500 0

af_packet::eno1 2019-12-18T17:44:40-0500 C8dZCI37SuYRZB9L7g 10.1.13.61 123 10.1.5.60 123 3 3 4 64.000000 0.007812 0.069839 0.402298 60.5.1.10 2019-12-18T17:43:37-0500 2019-12-18T17:43:36-0500 2019-12-18T17:43:37-0500 2019-12-18T17:44:41-0500 0

af_packet::eno1 2019-12-18T17:44:41-0500 CBz4Ww4jjCjKgHYfwc 10.1.221.30 123 10.1.5.180 123 3 3 15 64.000000 0.007812 0.000000 2.009995 0.0.0.0 1969-12-31T19:zeek-cut: time value out-of-range: -1114760693.379112

zeek-cut: time value out-of-range: -1114760693.379112

zeek-cut: time value out-of-range: -1115340513.842638

:00:00-0500 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500 2019-12-18T17:44:44-0500 0

af_packet::eno1 2019-12-18T17:44:40-0500 C4akh61szBCsYCPJn6 10.1.223.28 123 10.1.5.180 123 3 3 15 64.000000 0.007812 0.000000 2.009995 0.0.0.0 1969-12-31T19:

Have not noticed these errors previously.

image001.png

2

If you run that without the -d option, what does the line containing negative times look like?

There should be 4 times at the end of each record: ref_time org_time rec_time xmt_time, knowing which one(s) have the out of range value would help. Something like

cat ntp.log |zeek-cut uid ref_time org_time rec_time xmt_time | fgrep – -

may help see them better.

image001.png

3

Bigger issue possibly. A lot of zero values

I check date/time on both zeek boxes and they are set correctly.

CPURlj0fxNnhawrQk 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500 2019-12-19T06:59:59-0500

CPURlj0fxNnhawrQk 0.000000 0.000000 0.000000 1576756799.000161

Even the transmit date on some of the records are 1969.

CQ2SXD4XyRGPpQCu9e 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500 2019-12-19T07:00:02-0500

CLpVPg3841dexUbAu6 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500

CLpVPg3841dexUbAu6 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500

CxTT3e4BKVjQ9ogjng 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500 2019-12-19T07:00:00-0500

CGFPn54Ff0m4cIkr5e 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500 2019-12-19T07:00:04-0500

CXMvpj1SJy4aBwQ81i 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500 1969-12-31T19:00:00-0500 2019-12-19T07:00:04-0500

CQ2SXD4XyRGPpQCu9e 0.000000 0.000000 0.000000 1576756802.000145

CLpVPg3841dexUbAu6 0.000000 0.000000 0.000000 0.000000

CLpVPg3841dexUbAu6 0.000000 0.000000 0.000000 0.000000

CxTT3e4BKVjQ9ogjng 0.000000 0.000000 0.000000 1576756800.889992

CGFPn54Ff0m4cIkr5e 0.000000 0.000000 0.000000 1576756804.000129

CXMvpj1SJy4aBwQ81i 0.000000 0.000000 0.000000 1576756804.000076

Should those fields have zero values? That is why they are being displayed as start of epoch.

4

That’s probably a smaller issue :slight_smile: it’s logging unknown or unset values as 0, when it should maybe just be optional fields that are logged as unset values… unfortunately with timestamps 0 gets turned into 1969… we can probably fix that in zeek-cut to not format 0 as a timestamp though.

5

Hi Scot,

If you try:

tcpdump -i your_interface udp port 123 –vv

you’ll see that sometimes there are zero values in ref time, orig time, etc. I don’t think it’s an issue with the analyzer and the NTP protocol does not require all timestamps fields to have a non-zero value.

Mauro