Menu ▾ ▴

How to debug time not converging

Help
Robert McMahon
2020-01-07
2020-01-08

  • Robert McMahon

    Robert McMahon - 2020-01-07

    I'm running PTP master with a GPS disciplined OCXO. The PTP slave isn't converging as expected. They are directly connected over a 10G link.

    Snippit from ptpd stats where time 2020-01-07 01:13:30.760854 is suspicous

    The IBM article here that describes the fields suggests a huge increase in one-way delay. Not sure why this would occur. Is there a realtime sheduler mode or other suggested techniques for PTP to optimize this? I did configure CPU affinity. Maybe I should remove it.

    2020-01-07 01:13:19.476933, slv, 001132fffebeba60(unknown)/1,  0.000150639,  0.001595407, -0.001539000,  0.001714000, -136419.636000000, D, 00446, 0.000153913, 1222, 0.001781808, 100341, -145760, 5341,  0.001714000, -0.001539000
2020-01-07 01:13:19.680866, slv, 001132fffebeba60(unknown)/1,  0.000150639,  0.001562350, -0.001539000,  0.001713000, -136419.636000000, S, 00063, 0.000153913, 1222, 0.001781808, 100341, -145760, 5341,  0.001713000, -0.001539000
2020-01-07 01:13:20.680900, slv, 001132fffebeba60(unknown)/1,  0.000150639,  0.001548360, -0.001539000,  0.001685000, -134857.286000000, S, 00064, 0.000153913, 1222, 0.001781808, 100341, -145760, 5341,  0.001685000, -0.001539000
2020-01-07 01:13:20.954817, slv, 001132fffebeba60(unknown)/1,  0.000149471,  0.001548360, -0.001519000,  0.001685000, -133308.926000000, D, 00447, 0.000153913, 1222, 0.001781808, 100341, -145760, 5341,  0.001685000, -0.001519000
2020-01-07 01:13:21.680825, slv, 001132fffebeba60(unknown)/1,  0.000149471,  0.001495944, -0.001519000,  0.001607000, -133308.926000000, S, 00065, 0.000153913, 1222, 0.001781808, 100341, -145760, 5341,  0.001607000, -0.001519000
2020-01-07 01:13:21.732839, slv, 001132fffebeba60(unknown)/1,  0.000148068,  0.001495944, -0.001495000,  0.001607000, -131812.982000000, D, 00448, 0.000153913, 1222, 0.001781808, 100341, -145760, 5341,  0.001607000, -0.001495000
2020-01-07 01:13:22.680961, slv, 001132fffebeba60(unknown)/1,  0.000148068,  0.001471730, -0.001495000,  0.001634000, -131812.982000000, S, 00066, 0.000153913, 1222, 0.001781808, 100341, -145760, 5341,  0.001634000, -0.001495000
2020-01-07 01:13:22.900895, slv, 001132fffebeba60(unknown)/1,  0.000146756,  0.001471730, -0.001458000,  0.001634000, -130341.252000000, D, 00449, 0.000151936, 2476, 0.001534758, 50259, -133348, 2404,  0.001634000, -0.001458000
2020-01-07 01:13:23.584956, slv, 001132fffebeba60(unknown)/1,  0.000145803,  0.001471730, -0.001448000,  0.001634000, -130341.252000000, D, 00450, 0.000151936, 2476, 0.001534758, 50259, -133348, 2404,  0.001634000, -0.001448000
2020-01-07 01:13:23.680890, slv, 001132fffebeba60(unknown)/1,  0.000145803,  0.001459564, -0.001448000,  0.001579000, -130341.252000000, S, 00067, 0.000151936, 2476, 0.001534758, 50259, -133348, 2404,  0.001579000, -0.001448000
2020-01-07 01:13:24.680925, slv, 001132fffebeba60(unknown)/1,  0.000145803,  0.001440696, -0.001448000,  0.001594000, -128881.688000000, S, 00068, 0.000151936, 2476, 0.001534758, 50259, -133348, 2404,  0.001594000, -0.001448000
2020-01-07 01:13:25.066867, slv, 001132fffebeba60(unknown)/1,  0.000144856,  0.001440696, -0.001424000,  0.001594000, -127440.992000000, D, 00451, 0.000151936, 2476, 0.001534758, 50259, -133348, 2404,  0.001594000, -0.001424000
2020-01-07 01:13:25.294928, slv, 001132fffebeba60(unknown)/1,  0.000143809,  0.001440696, -0.001440000,  0.001594000, -127440.992000000, D, 00452, 0.000151936, 2476, 0.001534758, 50259, -133348, 2404,  0.001594000, -0.001440000
2020-01-07 01:13:25.680902, slv, 001132fffebeba60(unknown)/1,  0.000143809,  0.001447193, -0.001440000,  0.001590000, -127440.992000000, S, 00069, 0.000151936, 2476, 0.001534758, 50259, -133348, 2404,  0.001590000, -0.001440000
2020-01-07 01:13:25.856903, slv, 001132fffebeba60(unknown)/1,  0.000142748,  0.001447193, -0.001432000,  0.001590000, -125993.799000000, D, 00453, 0.000151936, 2476, 0.001534758, 50259, -133348, 2404,  0.001590000, -0.001432000
2020-01-07 01:13:26.680953, slv, 001132fffebeba60(unknown)/1,  0.000142748,  0.001454721, -0.001432000,  0.001606000, -125993.799000000, S, 00070, 0.000151936, 2476, 0.001534758, 50259, -133348, 2404,  0.001606000, -0.001432000
2020-01-07 01:13:27.148874, slv, 001132fffebeba60(unknown)/1,  0.000142038,  0.001454721, -0.001372000,  0.001606000, -124539.078000000, D, 00454, 0.000151936, 2476, 0.001534758, 50259, -133348, 2404,  0.001606000, -0.001372000
2020-01-07 01:13:27.626891, slv, 001132fffebeba60(unknown)/1,  0.000141588,  0.001454721, -0.001387000,  0.001606000, -124539.078000000, D, 00455, 0.000151936, 2476, 0.001534758, 50259, -133348, 2404,  0.001606000, -0.001387000
2020-01-07 01:13:27.678840, slv, 001132fffebeba60(unknown)/1,  0.000141588,  0.001413332, -0.001387000,  0.001505000, -124539.078000000, S, 00071, 0.000151936, 2476, 0.001534758, 50259, -133348, 2404,  0.001505000, -0.001387000
2020-01-07 01:13:28.436818, slv, 001132fffebeba60(unknown)/1,  0.000140825,  0.001413332, -0.001353000,  0.001505000, -123125.746000000, D, 00456, 0.000148206, 4662, 0.001488930, 60019, -129672, 4460,  0.001505000, -0.001353000
2020-01-07 01:13:28.680898, slv, 001132fffebeba60(unknown)/1,  0.000140825,  0.001379293, -0.001353000,  0.001536000, -123125.746000000, S, 00072, 0.000148206, 4662, 0.001488930, 60019, -129672, 4460,  0.001536000, -0.001353000
2020-01-07 01:13:29.678865, slv, 001132fffebeba60(unknown)/1,  0.000140825,  0.001385174, -0.001353000,  0.001516000, -121746.453000000, S, 00073, 0.000148206, 4662, 0.001488930, 60019, -129672, 4460,  0.001516000, -0.001353000
2020-01-07 01:13:30.678873, slv, 001132fffebeba60(unknown)/1,  0.000140825,  0.001374674, -0.001353000,  0.001515000, -120361.279000000, S, 00074, 0.000148206, 4662, 0.001488930, 60019, -129672, 4460,  0.001515000, -0.001353000
2020-01-07 01:13:30.760854, slv, 001132fffebeba60(unknown)/1,  0.006960363,  0.001374674,  1.744698000,  0.001515000, -118986.605000000, D, 00458, 0.000148206, 4662, 0.001488930, 60019, -129672, 4460,  0.001515000,  1.744698000
2020-01-07 01:13:31.678920, slv, 001132fffebeba60(unknown)/1,  0.006960363, -0.002040094,  1.744698000,  0.001506000, -118986.605000000, S, 00075, 0.000148206, 4662, 0.001488930, 60019, -129672, 4460,  0.001506000,  1.744698000
2020-01-07 01:13:32.334941, slv, 001132fffebeba60(unknown)/1,  0.013672783, -0.002040094, -0.001498000,  0.001506000, -121026.699000000, D, 00459, 0.000148206, 4662, 0.001488930, 60019, -129672, 4460,  0.001506000, -0.001498000
2020-01-07 01:13:32.680911, slv, 001132fffebeba60(unknown)/1,  0.013672783, -0.008663572, -0.001498000,  0.001800000, -121026.699000000, S, 00076, 0.000148206, 4662, 0.001488930, 60019, -129672, 4460,  0.001800000, -0.001498000
2020-01-07 01:13:32.852903, slv, 001132fffebeba60(unknown)/1,  0.013459540, -0.008663572, -0.001707000,  0.001800000, -129690.271000000, D, 00460, 0.006924657, 6766050, -0.001312905, 4367830, -122362, 4221,  0.001800000, -0.001707000
2020-01-07 01:13:33.282931, slv, 001132fffebeba60(unknown)/1,  0.013459540, -0.008663572, -0.001934000,  0.001800000, -129690.271000000, D, 00461, 0.006924657, 6766050, -0.001312905, 4367830, -122362, 4221,  0.001800000, -0.001934000
2020-01-07 01:13:33.680916, slv, 001132fffebeba60(unknown)/1,  0.013459540, -0.011516661, -0.001934000,  0.002299000, -129690.271000000, S, 00077, 0.006924657, 6766050, -0.001312905, 4367830, -122362, 4221,  0.002299000, -0.001934000
2020-01-07 01:13:34.364933, slv, 001132fffebeba60(unknown)/1,  0.013459540, -0.011516661, -0.002452000,  0.002299000, -141206.932000000, D, 00462, 0.006924657, 6766050, -0.001312905, 4367830, -122362, 4221,  0.002299000, -0.002452000
2020-01-07 01:13:34.680891, slv, 001132fffebeba60(unknown)/1,  0.013459540, -0.010910040, -0.002452000,  0.002800000, -141206.932000000, S, 00078, 0.006924657, 6766050, -0.001312905, 4367830, -122362, 4221,  0.002800000, -0.002452000
2020-01-07 01:13:35.680941, slv, 001132fffebeba60(unknown)/1,  0.013459540, -0.010407540, -0.002452000,  0.003304000, -152116.972000000, S, 00079, 0.006924657, 6766050, -0.001312905, 4367830, -122362, 4221,  0.003304000, -0.002452000
2020-01-07 01:13:36.584928, slv, 001132fffebeba60(unknown)/1,  0.013459540, -0.010407540, -0.003595000,  0.003304000, -162524.512000000, D, 00464, 0.006924657, 6766050, -0.001312905, 4367830, -122362, 4221,  0.003304000, -0.003595000
2020-01-07 01:13:36.682893, slv, 001132fffebeba60(unknown)/1,  0.013459540, -0.009913040, -0.003595000,  0.003789000, -162524.512000000, S, 00080, 0.006924657, 6766050, -0.001312905, 4367830, -122362, 4221,  0.003789000, -0.003595000
     

    Last edit: Robert McMahon 2020-01-07

    • Robert McMahon

      Robert McMahon - 2020-01-08

      I installed another GPS OCXO then used iperf multicast to measure one-way delay. It seems good suggesting this isn't a network issue.

      These are fedora 30 machines. uname -r gives 5.3.16-200.fc30.x86_64

      [rjmcmahon@localhost iperf2-code]$ src/iperf -s -u -B 224.0.1.129 -e -i 10
------------------------------------------------------------
Server listening on UDP port 5001 with pid 16757
Joining multicast group  224.0.1.129
Receiving 1470 byte datagrams
UDP buffer size:  208 KByte (default)
------------------------------------------------------------
[  3] local 224.0.1.129 port 5001 connected with 192.168.1.10 port 58250
[ ID] Interval        Transfer     Bandwidth        Jitter   Lost/Total  Latency avg/min/max/stdev PPS  inP NetPwr
[  3] 0.00-10.00 sec  1.40 MBytes  1.18 Mbits/sec   0.019 ms    0/  999 (0%)  0.122/ 0.048/ 0.171/ 0.021 ms  100 pps  0 pkts 1202.34
[  3] 10.00-20.00 sec  1.40 MBytes  1.18 Mbits/sec   0.019 ms    0/ 1001 (0%)  0.103/ 0.055/ 0.160/ 0.025 ms  100 pps  0 pkts 1431.47
[  3] 20.00-30.00 sec  1.40 MBytes  1.17 Mbits/sec   0.014 ms    0/  999 (0%)  0.106/ 0.059/ 0.153/ 0.022 ms  100 pps  0 pkts 1380.01
[  3] 30.00-40.00 sec  1.40 MBytes  1.18 Mbits/sec   0.014 ms    0/ 1000 (0%)  0.109/ 0.045/ 0.169/ 0.023 ms  100 pps  0 pkts 1352.46
[  3] 40.00-50.00 sec  1.40 MBytes  1.18 Mbits/sec   0.015 ms    0/ 1001 (0%)  0.116/ 0.055/ 0.158/ 0.020 ms  100 pps  0 pkts 1269.63
[  3] 50.00-60.00 sec  1.40 MBytes  1.18 Mbits/sec   0.007 ms    0/ 1000 (0%)  0.113/ 0.043/ 0.153/ 0.021 ms  100 pps  0 pkts 1304.29
[  3] 60.00-60.01 sec  1.44 KBytes  1.18 Mbits/sec   0.007 ms    0/    1 (0%)  0.180/ 0.084/ 0.096/ 0.000 ms  100 pps  0 pkts 821.18
[  3] 0.00-60.01 sec  8.41 MBytes  1.18 Mbits/sec   0.007 ms    0/ 6001 (0%)  0.111/ 0.043/ 0.171/ 0.023 ms  100 pps  0 pkts 1319.92


[rjmcmahon@localhost iperf2-code]$ src/iperf -c 224.0.1.129 -u -b 100p -t 60 
------------------------------------------------------------
Client connecting to 224.0.1.129, UDP port 5001
Sending 1470 byte datagrams, IPG target: 10000.00 us
Setting multicast TTL to 1
UDP buffer size:  208 KByte (default)
------------------------------------------------------------
[  3] local 192.168.1.10 port 58250 connected with 224.0.1.129 port 5001
[ ID] Interval       Transfer     Bandwidth
[  3]  0.0- 0.0 sec  8.41 MBytes  -nan bits/sec
[  3] Sent 0 datagrams
       

Log in to post a comment.