Re: logging

2019-04-12 Thread Udo van den Heuvel via devel 
On 13-04-19 01:27, Hal Murray wrote:
> I haven't had time to look carefully at the CLOCK problems.  What sort of 
> hardware is that running on?

Fedora 29 on x86_64 with Garmin gps18x on rs232.

Udo

___
devel mailing list
devel@ntpsec.org
http://lists.ntpsec.org/mailman/listinfo/devel

Re: logging

2019-04-12 Thread Hal Murray via devel 


Gary said:
>> Somebody on 2600:1700:6731:6c0:f2de:f1ff:fe20:1bbe is sending you
>> packets that don't make sense.  Same for 68.75.8.147.
> Those two hit my hackathon server as well.  But the connection is a normal
> NTPv4 exchange on UDP. 

Depends on what you mean by "normal".  How much did you investigate?

>From my sample:
 6 Apr 07:44:56 ntpd[10742]: JUNK: M3 V4 0/23 1 4ef 48/ 0 0 020 from 
68.75.8.147
:36693, lng=80
 6 Apr 07:45:47 ntpd[10742]: JUNK: M3 V4 0/23 1 4ef 48/ 0 0 030 from 
68.75.8.147
:34025, lng=96
...
The packet lengths are growing in steps of 16 bytes.  The 48/ stuff prints out 
the next 4 bytes in hex.  So that would be extension type 0 with lengths of 20 
(hex), 30, ...  20 hex is 32 decimal.  32+48 for the basic NTP packet is 80 as 
reported.  So there is a type 0 extension with 32 bytes.  Doesn't seem normal 
to me.  I'd bet on probing for a bug.


-- 
These are my opinions.  I hate spam.



___
devel mailing list
devel@ntpsec.org
http://lists.ntpsec.org/mailman/listinfo/devel

Re: logging

2019-04-12 Thread Gary E. Miller via devel 
Yo Hal!

On Fri, 12 Apr 2019 16:27:18 -0700
Hal Murray via devel  wrote:

> Somebody on 2600:1700:6731:6c0:f2de:f1ff:fe20:1bbe is sending you
> packets that don't make sense.  Same for 68.75.8.147.

Those two hit my hackathon server as well.  But the connection is a
normal NTPv4 exchange on UDP.

RGDS
GARY
---
Gary E. Miller Rellim 109 NW Wilmington Ave., Suite E, Bend, OR 97703
g...@rellim.com  Tel:+1 541 382 8588

Veritas liberabit vos. -- Quid est veritas?
"If you can’t measure it, you can’t improve it." - Lord Kelvin


pgp1q3irxoSmI.pgp
Description: OpenPGP digital signature
___
devel mailing list
devel@ntpsec.org
http://lists.ntpsec.org/mailman/listinfo/devel

Re: logging

2019-04-12 Thread Hal Murray via devel 


The "JUNK" stuff is for debugging NTS.  The most important part is the length 
at the end.  It's rate limited so there shouldn't be any serious problems with 
clutter in the log file - just minor potential confusion like this.

Somebody on 2600:1700:6731:6c0:f2de:f1ff:fe20:1bbe is sending you packets that 
don't make sense.  Same for 68.75.8.147.


I haven't had time to look carefully at the CLOCK problems.  What sort of 
hardware is that running on?


-- 
These are my opinions.  I hate spam.



___
devel mailing list
devel@ntpsec.org
http://lists.ntpsec.org/mailman/listinfo/devel

logging

2019-04-12 Thread Udo van den Heuvel via devel 
Hello,

What to think about logging like this:

Apr 11 19:12:25 vr ntpd[3428]: JUNK: M3 V4 0/23 1 4ef 48/ 0 0 550 from
[2600:1700:6731:6c0:f2de:f1ff:fe20:1bbe]:38764, lng=1408
Apr 11 19:14:34 vr ntpd[3428]: JUNK: M3 V4 0/23 1 4ef 48/ 0 0 560 from
[2600:1700:6731:6c0:f2de:f1ff:fe20:1bbe]:38764, lng=1424
Apr 11 19:16:44 vr ntpd[3428]: JUNK: M3 V4 0/23 1 4ef 48/ 0 0 570 from
[2600:1700:6731:6c0:f2de:f1ff:fe20:1bbe]:38764, lng=1440
Apr 11 19:18:28 vr ntpd[3428]: JUNK: M3 V4 0/23 1 4ef 48/ 0 0 020 from
68.75.8.147:38764, lng=80
Apr 11 19:20:34 vr ntpd[3428]: JUNK: M3 V4 0/23 1 4ef 48/ 0 0 030 from
68.75.8.147:38764, lng=96
[many of these]

Should I worry? Change config?


On another box:

Apr 12 14:15:23 box.local ntpd[2093]: 2019-04-12T14:15:23 ntpd[2093]:
INIT: ntpd ntpsec-1.1.3 2019-04-07T11:49:43Z: Starting
Apr 12 14:15:23 box.local ntpd[2093]: 2019-04-12T14:15:23 ntpd[2093]:
INIT: Command line: /usr/sbin/ntpd -u ntp:ntp -g -N -p /var/run/ntpd.pid
-i /chroot/ntpd
Apr 12 14:15:28 box.local ntpd[2109]: PROTO: fd01:c0a8:a10:1::1 unlink
local addr ::1 -> 
Apr 12 14:15:33 box.local ntpd[2109]: IO: Listen normally on 4 eth0
192.168.110.60:123
Apr 12 14:15:33 box.local ntpd[2109]: IO: Listen normally on 5 eth0
[fd01:c0a8:a10:1::60]:123
Apr 12 14:15:33 box.local ntpd[2109]: IO: Listen normally on 6 eth0
[2001:981:a812:0:e2d5:5eef:fee3:6b35]:123
Apr 12 14:15:33 box.local ntpd[2109]: IO: Listen normally on 7 eth0
[fe80::e2d5:5eef:fee3:6b35%2]:123
Apr 12 14:32:16 box.local ntpd[2109]: CLOCK: ts_prev 1555072336 s +
595028760 ns, ts_min 1555072336 s + 595027293 ns
Apr 12 14:32:16 box.local ntpd[2109]: CLOCK: ts 1555072336 s + 595028760 ns
Apr 12 14:32:16 box.local ntpd[2109]: CLOCK: sys_fuzz 1816 nsec, prior
fuzz 0.01663
Apr 12 14:32:16 box.local ntpd[2109]: CLOCK: this fuzz -0.01626
Apr 12 14:32:16 box.local ntpd[2109]: CLOCK: prev get_systime
0xe05b03d0.9853b2dc is 0.6 later than 0xe05b03d0.9853b2c2
Apr 12 14:34:42 box.local ntpd[2109]: CLOCK: ts_prev 1555072482 s +
752318448 ns, ts_min 1555072482 s + 752317400 ns
Apr 12 14:34:42 box.local ntpd[2109]: CLOCK: ts 1555072482 s + 752318448 ns
Apr 12 14:34:42 box.local ntpd[2109]: CLOCK: sys_fuzz 1816 nsec, prior
fuzz 0.01758
Apr 12 14:34:42 box.local ntpd[2109]: CLOCK: this fuzz -0.01783
Apr 12 14:34:42 box.local ntpd[2109]: CLOCK: prev get_systime
0xe05b0462.c097de8e is 0.00677 later than 0xe05b0462.c097d332
Apr 12 14:34:57 box.local ntpd[2109]: CLOCK: ts_prev 1555072497 s +
745400752 ns, ts_min 1555072497 s + 745399215 ns
Apr 12 14:34:57 box.local ntpd[2109]: CLOCK: ts 1555072497 s + 745400752 ns
Apr 12 14:34:57 box.local ntpd[2109]: CLOCK: sys_fuzz 1816 nsec, prior
fuzz 0.01745
Apr 12 14:34:57 box.local ntpd[2109]: CLOCK: this fuzz -0.01718
Apr 12 14:34:57 box.local ntpd[2109]: CLOCK: prev get_systime
0xe05b0471.bed27a70 is 0.00109 later than 0xe05b0471.bed2789a
Apr 12 14:37:35 box.local ntpd[2109]: CLOCK: ts_prev 1555072655 s +
712154322 ns, ts_min 1555072655 s + 712153764 ns
Apr 12 14:37:35 box.local ntpd[2109]: CLOCK: ts 1555072655 s + 712154322 ns
Apr 12 14:37:35 box.local ntpd[2109]: CLOCK: sys_fuzz 1816 nsec, prior
fuzz 0.01594
Apr 12 14:37:35 box.local ntpd[2109]: CLOCK: this fuzz -0.01722
Apr 12 14:37:35 box.local ntpd[2109]: CLOCK: prev get_systime
0xe05b050f.b64fb1ce is 0.00942 later than 0xe05b050f.b64fa201
Apr 12 14:42:48 box.local ntpd[2109]: CLOCK: ts_prev 1555072968 s +
724550807 ns, ts_min 1555072968 s + 724549760 ns
Apr 12 14:42:48 box.local ntpd[2109]: CLOCK: ts 1555072968 s + 724550807 ns
Apr 12 14:42:48 box.local ntpd[2109]: CLOCK: sys_fuzz 1816 nsec, prior
fuzz 0.01230
Apr 12 14:42:48 box.local ntpd[2109]: CLOCK: this fuzz -0.01707
Apr 12 14:42:48 box.local ntpd[2109]: CLOCK: prev get_systime
0xe05b0648.b97c0dfd is 0.00073 later than 0xe05b0648.b97c0cc3
Apr 12 14:48:26 box.local ntpd[2109]: CLOCK: ts_prev 1555073306 s +
699738523 ns, ts_min 1555073306 s + 699737476 ns
Apr 12 14:48:26 box.local ntpd[2109]: CLOCK: ts 1555073306 s + 699738523 ns
Apr 12 14:48:26 box.local ntpd[2109]: CLOCK: sys_fuzz 1816 nsec, prior
fuzz 0.01798
Apr 12 14:48:26 box.local ntpd[2109]: CLOCK: this fuzz -0.01401
Apr 12 14:48:26 box.local ntpd[2109]: CLOCK: prev get_systime
0xe05b079a.b321fe7a is 0.00336 later than 0xe05b079a.b321f8d8
Apr 12 14:51:14 box.local ntpd[2109]: CLOCK: ts_prev 1555073474 s +
735160940 ns, ts_min 1555073474 s + 735160382 ns
Apr 12 14:51:14 box.local ntpd[2109]: CLOCK: ts 1555073474 s + 735160940 ns
Apr 12 14:51:14 box.local ntpd[2109]: CLOCK: sys_fuzz 1816 nsec, prior
fuzz 0.01322
Apr 12 14:51:14 box.local ntpd[2109]: CLOCK: this fuzz -0.01126
Apr 12 14:51:14 box.local ntpd[2109]: CLOCK: prev get_systime
0xe05b0842.bc33703a is 0.00074 later than 0xe05b0842.bc336efe
Apr 12 15:35:02 box.local ntpd[2109]: CLOCK: ts_prev 1555076102 s +
595269459 ns, ts_min 1555076102 s + 595268412 ns
Apr 12 15:35:02 box.local ntpd[2109]: CLOCK: ts 1555076102 s + 595269459 ns
Apr 12