search

raspberrypi / linux

Kernel source tree for Raspberry Pi-provided kernel builds. Issues unrelated to the linux kernel should be posted on the community forum at https://forums.raspberrypi.com/
Other
11.15k stars 5k forks source link

PTP hardware timestamping appears broken on Pi 5 #5904

Open dsseng opened 9 months ago

dsseng commented 9 months ago

Describe the bug

Apparently hardware timestamping is somehow broken and applications don't get timestamps delivered.

Steps to reproduce the behaviour

Run ptp4l in hardware timestamping mode. It will have timestamp errors. Also reproducible with statime when PHC is enabled.

Device (s)

Raspberry Pi 5

System

Raspberry Pi reference 2023-12-11 Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, 2acf7afcba7d11500313a7b93bb55a2aae20b2d6, stage2

2024/01/24 12:16:01 Copyright (c) 2012 Broadcom version 1aeae380 (release) (embedded)

Linux helios 6.6.13-v8-16k+ #1724 SMP PREEMPT Mon Jan 22 13:14:14 GMT 2024 aarch64 GNU/Linux

Same happens on 6.1 kernel series

Logs

Hardware timestamping (sudo ptp4l -i eth0 -l 7 -m -q -s):

``` p4l[1215.045]: port 0 (/var/run/ptp4lro): INITIALIZING to LISTENING on INIT_COMPLETE ptp4l[1215.045]: port 1 (eth0): received link status notification ptp4l[1215.045]: interface index 2 is up ptp4l[1215.605]: port 1 (eth0): setting asCapable ptp4l[1215.606]: port 1 (eth0): received SYNC without timestamp ptp4l[1216.606]: port 1 (eth0): received SYNC without timestamp ptp4l[1216.606]: port 1 (eth0): new foreign master f8e43b.fffe.a6665f-1 ptp4l[1217.606]: port 1 (eth0): received SYNC without timestamp ptp4l[1218.606]: port 1 (eth0): received SYNC without timestamp ptp4l[1219.606]: port 1 (eth0): received SYNC without timestamp ptp4l[1220.606]: port 1 (eth0): received SYNC without timestamp ptp4l[1220.606]: selected best master clock f8e43b.fffe.a6665f ptp4l[1220.606]: foreign master not using PTP timescale ptp4l[1220.606]: port 1 (eth0): LISTENING to UNCALIBRATED on RS_SLAVE ptp4l[1221.606]: port 1 (eth0): received SYNC without timestamp ptp4l[1221.606]: port 1 (eth0): have FOLLOW_UP 13, expecting SYNC but got FOLLOW_UP 14, dropping ptp4l[1222.589]: port 1 (eth0): delay timeout ptp4l[1222.606]: port 1 (eth0): received SYNC without timestamp ptp4l[1222.606]: port 1 (eth0): have FOLLOW_UP 14, expecting SYNC but got FOLLOW_UP 15, dropping ptp4l[1222.767]: port 1 (eth0): delay timeout ptp4l[1223.206]: port 1 (eth0): delay timeout ptp4l[1223.606]: port 1 (eth0): received SYNC without timestamp ptp4l[1223.606]: port 1 (eth0): have FOLLOW_UP 15, expecting SYNC but got FOLLOW_UP 16, dropping ptp4l[1224.249]: port 1 (eth0): delay timeout ptp4l[1224.606]: port 1 (eth0): received SYNC without timestamp ptp4l[1224.606]: port 1 (eth0): have FOLLOW_UP 16, expecting SYNC but got FOLLOW_UP 17, dropping ptp4l[1225.156]: port 1 (eth0): delay timeout ptp4l[1225.607]: port 1 (eth0): received SYNC without timestamp ptp4l[1225.607]: port 1 (eth0): have FOLLOW_UP 17, expecting SYNC but got FOLLOW_UP 18, dropping ptp4l[1226.411]: port 1 (eth0): delay timeout ptp4l[1226.606]: port 1 (eth0): received SYNC without timestamp ptp4l[1226.606]: port 1 (eth0): have FOLLOW_UP 18, expecting SYNC but got FOLLOW_UP 19, dropping ptp4l[1226.700]: port 1 (eth0): delay timeout ptp4l[1227.607]: port 1 (eth0): received SYNC without timestamp ptp4l[1227.607]: port 1 (eth0): have FOLLOW_UP 19, expecting SYNC but got FOLLOW_UP 20, dropping ptp4l[1227.989]: port 1 (eth0): delay timeout ptp4l[1228.149]: port 1 (eth0): delay timeout ```

Software timestamping (sudo ptp4l -i eth0 -l 7 -m -q -s -S):

``` ptp4l[1352.508]: port 0 (/var/run/ptp4lro): INITIALIZING to LISTENING on INIT_COMPLETE ptp4l[1352.508]: port 1 (eth0): received link status notification ptp4l[1352.508]: interface index 2 is up ptp4l[1352.618]: port 1 (eth0): setting asCapable ptp4l[1352.618]: port 1 (eth0): new foreign master f8e43b.fffe.a6665f-1 ptp4l[1356.618]: selected best master clock f8e43b.fffe.a6665f ptp4l[1356.618]: foreign master not using PTP timescale ptp4l[1356.618]: port 1 (eth0): LISTENING to UNCALIBRATED on RS_SLAVE ptp4l[1356.736]: port 1 (eth0): delay timeout ptp4l[1357.619]: port 1 (eth0): have FOLLOW_UP 149, expecting FOLLOW_UP but got SYNC 150, dropping ptp4l[1358.433]: port 1 (eth0): delay timeout ptp4l[1358.435]: delay filtered 699375 raw 699375 ptp4l[1358.619]: master offset 13075711 s0 freq -31579 path delay 699375 ptp4l[1358.727]: port 1 (eth0): delay timeout ptp4l[1358.729]: delay filtered 703069 raw 706763 ptp4l[1359.619]: master offset 13139396 s0 freq -31579 path delay 703069 ptp4l[1360.619]: master offset 12997246 s0 freq -31579 path delay 703069 ```

Additional context

I am currently going to do additional tests like https://github.com/torvalds/linux/blob/master/tools/testing/selftests/net/timestamping.c to surely isolate the issue.

pelwell commented 9 months ago

The Pi 5 PHY does not support hardware timestamping.

dsseng commented 9 months ago

What? I've seen (perhaps 3rd party) reviews about it supporting PTP hardware timestamping. Cadence GEM MACs support PTP (unsure about the PHY support). Perhaps this should be reopened to properly detect hardware timestamping support in the GEM/macb driver. However PHC itself should be kept as we tested it to be functional and properly adjustable even with userspace timestamping.

P33M commented 9 months ago

Works on my machine(s)? CM4+CM4IO plugged into a dumb switch with a Pi 5. CM4 assumes master role, Pi 5 syncs to master.

pi@raspberrypi:~$ sudo ptp4l -i eth0 -l 7 -q -m -q -s
ptp4l[13637.903]: config item (null).assume_two_step is 0
ptp4l[13637.903]: config item (null).check_fup_sync is 0
ptp4l[13637.903]: config item (null).tx_timestamp_timeout is 1
ptp4l[13637.903]: config item (null).hwts_filter is 0
ptp4l[13637.903]: config item (null).clock_servo is 0
ptp4l[13637.903]: config item (null).clock_type is 32768
ptp4l[13637.903]: config item (null).clock_servo is 0
ptp4l[13637.903]: config item (null).clockClass is 248
ptp4l[13637.903]: config item (null).clockAccuracy is 254
ptp4l[13637.903]: config item (null).offsetScaledLogVariance is 65535
ptp4l[13637.903]: config item (null).productDescription is ';;'
ptp4l[13637.903]: config item (null).revisionData is ';;'
ptp4l[13637.903]: config item (null).userDescription is ''
ptp4l[13637.903]: config item (null).manufacturerIdentity is '00:00:00'
ptp4l[13637.903]: config item (null).domainNumber is 0
ptp4l[13637.903]: config item (null).slaveOnly is 1
ptp4l[13637.903]: config item (null).gmCapable is 1
ptp4l[13637.903]: config item (null).gmCapable is 1
ptp4l[13637.903]: config item (null).G.8275.defaultDS.localPriority is 128
ptp4l[13637.903]: config item (null).maxStepsRemoved is 255
ptp4l[13637.903]: config item (null).time_stamping is 1
ptp4l[13637.903]: config item (null).twoStepFlag is 1
ptp4l[13637.903]: config item (null).twoStepFlag is 1
ptp4l[13637.903]: config item (null).time_stamping is 1
ptp4l[13637.903]: config item (null).priority1 is 128
ptp4l[13637.903]: config item (null).priority2 is 128
ptp4l[13637.903]: interface index 2 is up
ptp4l[13637.903]: config item (null).free_running is 0
ptp4l[13637.903]: selected /dev/ptp0 as PTP clock
ptp4l[13637.903]: config item (null).clockIdentity is '000000.0000.000000'
ptp4l[13637.903]: config item (null).uds_address is '/var/run/ptp4l'
ptp4l[13637.903]: section item /var/run/ptp4l.announceReceiptTimeout now 0
ptp4l[13637.903]: section item /var/run/ptp4l.delay_mechanism now 0
ptp4l[13637.903]: section item /var/run/ptp4l.network_transport now 0
ptp4l[13637.903]: section item /var/run/ptp4l.delay_filter_length now 1
ptp4l[13637.903]: config item (null).free_running is 0
ptp4l[13637.903]: config item (null).freq_est_interval is 1
ptp4l[13637.903]: config item (null).write_phase_mode is 0
ptp4l[13637.903]: config item (null).gmCapable is 1
ptp4l[13637.903]: config item (null).kernel_leap is 1
ptp4l[13637.903]: config item (null).utc_offset is 37
ptp4l[13637.903]: config item (null).timeSource is 160
ptp4l[13637.903]: config item (null).pi_proportional_const is 0.000000
ptp4l[13637.903]: config item (null).pi_integral_const is 0.000000
ptp4l[13637.903]: config item (null).pi_proportional_scale is 0.000000
ptp4l[13637.903]: config item (null).pi_proportional_exponent is -0.300000
ptp4l[13637.903]: config item (null).pi_proportional_norm_max is 0.700000
ptp4l[13637.903]: config item (null).pi_integral_scale is 0.000000
ptp4l[13637.903]: config item (null).pi_integral_exponent is 0.400000
ptp4l[13637.903]: config item (null).pi_integral_norm_max is 0.300000
ptp4l[13637.903]: config item (null).step_threshold is 0.000000
ptp4l[13637.903]: config item (null).first_step_threshold is 0.000020
ptp4l[13637.903]: config item (null).max_frequency is 900000000
ptp4l[13637.903]: config item (null).servo_offset_threshold is 0
ptp4l[13637.903]: config item (null).servo_num_offset_values is 10
ptp4l[13637.903]: config item (null).dataset_comparison is 0
ptp4l[13637.903]: config item (null).tsproc_mode is 0
ptp4l[13637.903]: config item (null).delay_filter is 1
ptp4l[13637.903]: config item (null).delay_filter_length is 10
ptp4l[13637.903]: config item (null).initial_delay is 0
ptp4l[13637.903]: config item (null).summary_interval is 0
ptp4l[13637.903]: config item (null).sanity_freq_limit is 200000000
ptp4l[13637.903]: PI servo: sync interval 1.000 kp 0.700 ki 0.300000
ptp4l[13637.903]: config item /var/run/ptp4l.boundary_clock_jbod is 0
ptp4l[13637.903]: config item /var/run/ptp4l.network_transport is 0
ptp4l[13637.903]: config item /var/run/ptp4l.masterOnly is 0
ptp4l[13637.903]: config item /var/run/ptp4l.BMCA is 0
ptp4l[13637.903]: config item /var/run/ptp4l.delayAsymmetry is 0
ptp4l[13637.903]: config item /var/run/ptp4l.follow_up_info is 0
ptp4l[13637.903]: config item /var/run/ptp4l.freq_est_interval is 1
ptp4l[13637.903]: config item /var/run/ptp4l.msg_interval_request is 0
ptp4l[13637.903]: config item /var/run/ptp4l.net_sync_monitor is 0
ptp4l[13637.903]: config item /var/run/ptp4l.path_trace_enabled is 0
ptp4l[13637.903]: config item /var/run/ptp4l.tc_spanning_tree is 0
ptp4l[13637.903]: config item /var/run/ptp4l.ingressLatency is 0
ptp4l[13637.903]: config item /var/run/ptp4l.egressLatency is 0
ptp4l[13637.903]: config item /var/run/ptp4l.delay_mechanism is 0
ptp4l[13637.903]: config item /var/run/ptp4l.hybrid_e2e is 0
ptp4l[13637.903]: config item /var/run/ptp4l.fault_badpeernet_interval is 16
ptp4l[13637.903]: config item /var/run/ptp4l.fault_reset_interval is 4
ptp4l[13637.903]: config item /var/run/ptp4l.tsproc_mode is 0
ptp4l[13637.903]: config item /var/run/ptp4l.delay_filter is 1
ptp4l[13637.903]: config item /var/run/ptp4l.delay_filter_length is 1
ptp4l[13637.903]: config item (null).slave_event_monitor is ''
ptp4l[13637.903]: config item eth0.boundary_clock_jbod is 0
ptp4l[13637.903]: config item eth0.network_transport is 1
ptp4l[13637.903]: config item eth0.masterOnly is 0
ptp4l[13637.903]: config item eth0.BMCA is 0
ptp4l[13637.903]: config item eth0.delayAsymmetry is 0
ptp4l[13637.903]: config item eth0.follow_up_info is 0
ptp4l[13637.903]: config item eth0.freq_est_interval is 1
ptp4l[13637.903]: config item eth0.msg_interval_request is 0
ptp4l[13637.903]: config item eth0.net_sync_monitor is 0
ptp4l[13637.903]: config item eth0.path_trace_enabled is 0
ptp4l[13637.903]: config item eth0.tc_spanning_tree is 0
ptp4l[13637.903]: config item eth0.ingressLatency is 0
ptp4l[13637.903]: config item eth0.egressLatency is 0
ptp4l[13637.903]: config item eth0.delay_mechanism is 1
ptp4l[13637.903]: config item eth0.unicast_master_table is 0
ptp4l[13637.903]: config item eth0.unicast_listen is 0
ptp4l[13637.903]: config item eth0.hybrid_e2e is 0
ptp4l[13637.903]: config item eth0.fault_badpeernet_interval is 16
ptp4l[13637.903]: config item eth0.fault_reset_interval is 4
ptp4l[13637.903]: config item eth0.tsproc_mode is 0
ptp4l[13637.903]: config item eth0.delay_filter is 1
ptp4l[13637.903]: config item eth0.delay_filter_length is 10
ptp4l[13637.903]: config item eth0.logMinDelayReqInterval is 0
ptp4l[13637.903]: config item eth0.logAnnounceInterval is 1
ptp4l[13637.903]: config item eth0.inhibit_announce is 0
ptp4l[13637.903]: config item eth0.ignore_source_id is 0
ptp4l[13637.903]: config item eth0.announceReceiptTimeout is 3
ptp4l[13637.903]: config item eth0.syncReceiptTimeout is 0
ptp4l[13637.903]: config item eth0.transportSpecific is 0
ptp4l[13637.903]: config item eth0.ignore_transport_specific is 0
ptp4l[13637.903]: config item eth0.G.8275.portDS.localPriority is 128
ptp4l[13637.903]: config item eth0.logSyncInterval is 0
ptp4l[13637.903]: config item eth0.operLogSyncInterval is 0
ptp4l[13637.903]: config item eth0.logMinPdelayReqInterval is 0
ptp4l[13637.903]: config item eth0.operLogPdelayReqInterval is 0
ptp4l[13637.903]: config item eth0.neighborPropDelayThresh is 20000000
ptp4l[13637.903]: config item eth0.min_neighbor_prop_delay is -20000000
ptp4l[13637.903]: config item eth0.asCapable is 1
ptp4l[13637.903]: config item eth0.inhibit_delay_req is 0
ptp4l[13637.903]: config item eth0.udp_ttl is 1
ptp4l[13637.904]: config item (null).dscp_event is 0
ptp4l[13637.904]: config item (null).dscp_general is 0
ptp4l[13637.904]: port 1: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[13637.904]: config item /var/run/ptp4l.logMinDelayReqInterval is 0
ptp4l[13637.904]: config item /var/run/ptp4l.logAnnounceInterval is 1
ptp4l[13637.904]: config item /var/run/ptp4l.inhibit_announce is 0
ptp4l[13637.904]: config item /var/run/ptp4l.ignore_source_id is 0
ptp4l[13637.904]: config item /var/run/ptp4l.announceReceiptTimeout is 0
ptp4l[13637.904]: config item /var/run/ptp4l.syncReceiptTimeout is 0
ptp4l[13637.904]: config item /var/run/ptp4l.transportSpecific is 0
ptp4l[13637.904]: config item /var/run/ptp4l.ignore_transport_specific is 0
ptp4l[13637.904]: config item /var/run/ptp4l.G.8275.portDS.localPriority is 128
ptp4l[13637.904]: config item /var/run/ptp4l.logSyncInterval is 0
ptp4l[13637.904]: config item /var/run/ptp4l.operLogSyncInterval is 0
ptp4l[13637.904]: config item /var/run/ptp4l.logMinPdelayReqInterval is 0
ptp4l[13637.904]: config item /var/run/ptp4l.operLogPdelayReqInterval is 0
ptp4l[13637.904]: config item /var/run/ptp4l.neighborPropDelayThresh is 20000000
ptp4l[13637.904]: config item /var/run/ptp4l.min_neighbor_prop_delay is -20000000
ptp4l[13637.904]: config item /var/run/ptp4l.asCapable is 1
ptp4l[13637.904]: config item /var/run/ptp4l.inhibit_delay_req is 0
ptp4l[13637.904]: config item (null).uds_address is '/var/run/ptp4l'
ptp4l[13637.904]: port 0: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[13637.904]: port 1: received link status notification
ptp4l[13637.904]: interface index 2 is up
ptp4l[13645.611]: port 1: announce timeout
ptp4l[13645.611]: config item eth0.udp_ttl is 1
ptp4l[13645.612]: config item (null).dscp_event is 0
ptp4l[13645.612]: config item (null).dscp_general is 0
ptp4l[13645.612]: selected local clock d83add.fffe.7bc6ba as best master
ptp4l[13647.571]: port 1: received link status notification
ptp4l[13649.708]: port 1: setting asCapable
ptp4l[13649.708]: port 1: new foreign master b827eb.fffe.379f04-1
ptp4l[13653.115]: port 1: announce timeout
ptp4l[13653.115]: config item eth0.udp_ttl is 1
ptp4l[13653.115]: config item (null).dscp_event is 0
ptp4l[13653.115]: config item (null).dscp_general is 0
ptp4l[13653.115]: selected local clock d83add.fffe.7bc6ba as best master
ptp4l[13653.709]: selected best master clock b827eb.fffe.379f04
ptp4l[13653.709]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[13654.664]: port 1: delay timeout
ptp4l[13655.232]: port 1: delay timeout
ptp4l[13655.233]: delay   filtered      32766   raw      32766
ptp4l[13655.709]: master offset    -207368 s0 freq  -55511 path delay     32766
ptp4l[13656.709]: master offset    -212656 s1 freq  -60798 path delay     32766
ptp4l[13656.864]: port 1: delay timeout
ptp4l[13657.710]: master offset       7859 s2 freq  -52939 path delay     32766
ptp4l[13657.710]: port 1: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
ptp4l[13657.907]: port 1: delay timeout
ptp4l[13657.907]: delay   filtered      34117   raw      35468
ptp4l[13657.993]: port 1: delay timeout
ptp4l[13657.993]: delay   filtered      35468   raw      36740
ptp4l[13658.245]: port 1: delay timeout
ptp4l[13658.246]: delay   filtered      36104   raw      36922
ptp4l[13658.710]: master offset       1022 s2 freq  -57419 path delay     36104
ptp4l[13659.710]: master offset      -2447 s2 freq  -60581 path delay     36104
ptp4l[13659.941]: port 1: delay timeout
ptp4l[13659.942]: delay   filtered      35468   raw      33249
ptp4l[13660.235]: port 1: delay timeout
ptp4l[13660.235]: delay   filtered      34664   raw      33860
ptp4l[13660.710]: master offset       4692 s2 freq  -54176 path delay     34664
ptp4l[13660.767]: port 1: delay timeout
ptp4l[13660.767]: delay   filtered      34677   raw      34677
ptp4l[13661.592]: port 1: delay timeout
ptp4l[13661.592]: delay   filtered      35072   raw      35589
ptp4l[13661.710]: master offset      -1452 s2 freq  -58913 path delay     35072
ptp4l[13662.711]: master offset       5393 s2 freq  -52503 path delay     35072
ptp4l[13663.477]: port 1: delay timeout
ptp4l[13663.478]: delay   filtered      35468   raw      38094
ptp4l[13663.712]: master offset       -866 s2 freq  -57144 path delay     35468
ptp4l[13664.314]: port 1: delay timeout
ptp4l[13664.314]: delay   filtered      35416   raw      35365
ptp4l[13664.401]: port 1: delay timeout
ptp4l[13664.401]: delay   filtered      35416   raw      33737
ptp4l[13664.711]: master offset       -139 s2 freq  -56677 path delay     35416
ptp4l[13665.711]: master offset      -2685 s2 freq  -59265 path delay     35416
ptp4l[13665.938]: port 1: delay timeout
ptp4l[13665.938]: delay   filtered      35058   raw      34752
ptp4l[13666.014]: port 1: delay timeout
ptp4l[13666.014]: delay   filtered      34714   raw      34021
ptp4l[13666.711]: master offset       2808 s2 freq  -54577 path delay     34714
ptp4l[13667.559]: port 1: delay timeout
ptp4l[13667.560]: delay   filtered      34714   raw      36832
ptp4l[13667.711]: master offset      -2181 s2 freq  -58724 path delay     34714
ptp4l[13668.712]: master offset      -1636 s2 freq  -58833 path delay     34714
ptp4l[13668.786]: port 1: delay timeout
ptp4l[13668.786]: delay   filtered      34714   raw      34554
ptp4l[13669.712]: master offset       1542 s2 freq  -56146 path delay     34714
ptp4l[13670.649]: port 1: delay timeout
ptp4l[13670.649]: delay   filtered      34944   raw      35136
ptp4l[13670.712]: master offset       1377 s2 freq  -55848 path delay     34944
ptp4l[13671.712]: master offset      -1329 s2 freq  -58141 path delay     34944
ptp4l[13671.936]: port 1: delay timeout
ptp4l[13671.936]: delay   filtered      34944   raw      34705
P33M commented 9 months ago

The MAC driver registers the ptp device in this case, not the PHY driver. What is your server configuration? I see you have 

ptp4l[1220.606]: selected best master clock f8e43b.fffe.a6665f 
ptp4l[1220.606]: foreign master not using PTP timescale

in the log.

dsseng commented 9 months ago

Both ptp4l and statime (with all 4 combinations of these two on the either side) produce the same: missing RX timestamps. The server is a PC with USB NIC using software (kernel) timestamping.

@P33M what are your kernel and ptp4l versions?

P33M commented 9 months ago

Pi 5: 

pi@raspberrypi:~$ uname -a
Linux raspberrypi 6.6.13-v8-16k+ #14 SMP PREEMPT Wed Jan 24 16:31:17 GMT 2024 aarch64 GNU/Linux
pi@raspberrypi:~$ ptp4l -v
3.1.1

Local kernel build, but reflects latest rpi-update.

CM4:

pi@raspberrypi:~$ uname -a
Linux raspberrypi 6.1.63-v8+ #1700 SMP PREEMPT Thu Nov 23 14:10:01 GMT 2023 aarch64 GNU/Linux
pi@raspberrypi:~$ ptp4l -v
3.1

Interestingly, if I swap CM4 to slave mode and the Pi 5 assumes master role then the CM4 reports sync errors similar to yours.

ptp4l[4256.733]: port 0: INITIALIZING to LISTENING on INIT_COMPLETE
ptp4l[4256.733]: port 1: received link status notification
ptp4l[4256.733]: interface index 2 is up
ptp4l[4262.613]: port 1: announce timeout
ptp4l[4262.613]: config item eth0.udp_ttl is 1
ptp4l[4262.614]: config item (null).dscp_event is 0
ptp4l[4262.614]: config item (null).dscp_general is 0
ptp4l[4262.614]: selected local clock b827eb.fffe.379f04 as best master
ptp4l[4270.365]: port 1: announce timeout
ptp4l[4270.365]: config item eth0.udp_ttl is 1
ptp4l[4270.366]: config item (null).dscp_event is 0
ptp4l[4270.366]: config item (null).dscp_general is 0
ptp4l[4270.366]: selected local clock b827eb.fffe.379f04 as best master
ptp4l[4270.570]: port 1: setting asCapable
ptp4l[4270.570]: port 1: new foreign master d83add.fffe.7bc6ba-1
ptp4l[4274.570]: selected best master clock d83add.fffe.7bc6ba
ptp4l[4274.570]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[4275.564]: port 1: delay timeout
ptp4l[4275.724]: port 1: delay timeout
ptp4l[4275.985]: port 1: delay timeout
ptp4l[4276.569]: port 1: have SYNC 4, expecting FOLLOW_UP but got SYNC 5, dropping
ptp4l[4277.125]: port 1: delay timeout
ptp4l[4277.569]: port 1: have SYNC 5, expecting FOLLOW_UP but got SYNC 6, dropping
ptp4l[4277.797]: port 1: delay timeout
ptp4l[4277.801]: port 1: delay timeout
ptp4l[4278.569]: port 1: have SYNC 6, expecting FOLLOW_UP but got SYNC 7, dropping
ptp4l[4279.325]: port 1: delay timeout
ptp4l[4279.569]: port 1: have SYNC 7, expecting FOLLOW_UP but got SYNC 8, dropping
ptp4l[4280.569]: port 1: have SYNC 8, expecting FOLLOW_UP but got SYNC 9, dropping
ptp4l[4280.687]: port 1: delay timeout
ptp4l[4281.569]: port 1: have SYNC 9, expecting FOLLOW_UP but got SYNC 10, dropping
ptp4l[4282.429]: port 1: delay timeout
ptp4l[4282.430]: delay   filtered      34295   raw      34295
ptp4l[4283.569]: port 1: have SYNC 11, expecting FOLLOW_UP but got SYNC 12, dropping
ptp4l[4283.857]: port 1: delay timeout
ptp4l[4283.858]: delay   filtered      35490   raw      36686

The MAC supports both one-step and two-step timestamping. It appears that the Pi 4 is expecting two-step but the Pi 5 is transmitting one-step frames.

dsseng commented 9 months ago

I'll try a bit more and could maybe also do a 3.1.1 linuxptp build (it's missing some of the features I use)

dsseng commented 9 months ago

ptp4l from Git v3.1.1 exhibits the same behavior. Current kernel: 6.1.0-rpi8-rpi-2712

If PC with software timestamps is client and Pi is server it shows received DELAY_REQ without timestamp unless I disable HW timestamping on the Pi 5.

davidv1992 commented 8 months ago

I have played around a bit with the hardware timestamping available on the PI 5 and there are definitely a few strange things going on which suggest to me there are some driver and/or kernel bugs involved.

When looking at IPv4 ptp packets, when configuring the driver to timestamp only layer 4 v2 ptp packets (passing HWTSTAMP_FILTER_PTP_V2_L4_EVENT to the SIOCSHWTSTAMP ioctl), some received packets are not properly timestamped. However, when enabling the HWTSTAMP_FILTER_ALL filter (which is according to ethool -T the only filter that is supported, and hence what HWTSTAMP_FILTER_PTP_V2_L4_EVENT should be upgraded to) send timestamps for delay requests are suddenly not properly timestamped.

However, looking at ethernet packets, due to a bug I was configuring this also with HWTSTAMP_FILTER_PTP_V2_L4_EVENT, and there all ptp packets seem to get timestamped. So the upgrade process at least partially works. Not sure what is going on in the driver exactly but definitely some hardware timestamping bugs.

All this testing was done on the 6.1.0-rpi8-rpi-2712 kernel

davidv1992 commented 8 months ago

Further update: for ethernet packets, the send timestamping not working when using HWTSTAMP_FILTER_ALL also occurs for ptp over raw ethernet.

dsseng commented 8 months ago

Thanks for looking into this!

scottstanfield commented 8 months ago

I'm configuring a Raspberry Pi 5 with a ZED-F9T (via SparkFun GNSS over RS-232), hoping to use it for PTP hardware timestamping. Following this thread.

I also have a TimeBeat w/the CM4 sandwich to reference.

lmfses commented 7 months ago

I am running on RPI5, 6.6.20+rpt-rpi-2712

When enabling PTP with same config that I have on other x64 hosts, I started to receive these;

ptp4l[1546.963]: port 1: received SYNC without timestamp

I added the hwts_filter to "full" in the ptp4l config, which seems to have effect. The default for hwts_filter is "normal".

Not only are the SYNC without timestamps events gone, but chrony seems to accept the PTP now

# chronyc sources
MS Name/IP address         Stratum Poll Reach LastRx Last sample
===============================================================================
#* PTP0                          0   2   377     2  -1789ns[-4985ns] +/- 6551ns
by commented 6 months ago

Have you tried ptp4l.conf w/ network_transport L2?

gspreeth commented 4 months ago

I have a issue on the CM4 that seems related to a driver bug. I can setup a PTP master that syncs fine with pdelay mechanism using UDP (low nanosecond values) . but when switching to L2 then the pdelay timestamps are very inaccurate (60 to 80 microseconds or more with large jitter) this seems like it defaults to software timestamping for those packets.

ewaldc commented 1 month ago

It seems the CM4 can't timestamp TX packets that have the minor version set to a non-zero value. See here. I was struggling with a similar issue on the Realtek 8125. Compiling linuxptp 4.4 (instead of version 4.0 deliverd with Ubuntu Noble) and setting ptp_minor_version to 0 (new config parameter) helped to get rid of received DELAY_REQ without timestamp and could possibly also fix other ... without timestamp issues. Haven't tested on RPI though, just a suggestion...

fridtjof commented 1 month ago

I can confirm this as well with the Pi 5 - it refused to sync to another host, giving the mentioned "without timestamp" messages.

Setting ptp_minor_version to 0 on the other computer as @ewaldc mentioned made things work immediately, so the same issue seems to apply here as well(?).

Some versions and details:

Host:

Pi 5:

It seems the CM4 can't timestamp TX packets that have the minor version set to a non-zero value. See here.

@ewaldc that link seems to be broken

ewaldc commented 1 month ago

Link corrected, my mistake (working too late). Sorry for the inconvenience.