jclark / rpi-cm4-ptp-guide

Guide to using the hardware PTP support in the Raspberry Pi CM4
MIT License
81 stars 10 forks source link

Not working with TimeBeat M8F #6

Open kondou opened 1 year ago

kondou commented 1 year ago

Thank you very much for providing good instruction.

Recently, I received Timebeat CM4 module and configured as described. It looks working, but the result of 'phc_ctl eth0 cmp' is far from -37 second after booting the OS. This looks fixed by setting 'phc_ctl eth0 "set;" adj 37'. So, setting PHC clock needs to be done while booting the system.

Or, am I missing something?

jclark commented 1 year ago

Thanks for filing an issue!

After booting the OS, the PHC will be zero, corresponding to the time 1970-01-01.

Using the setup in this repo, the PHC is set by ts2phc.service when it starts up, which should be triggered when the OS detects that the network cable is plugged into the CM4.

I'm not sure what is going wrong in your case. What output do you get from

systemctl status ts2phc.service

?

I have a TimeBeat module on the way and am looking forward to trying it out. Do you have the M10S or the M8F version?

kondou commented 1 year ago

Okay. Here is what I just did. Sorry for lengthy message, I hope you will see what is happening here. It would be okay without setting PHC clock explicitly, but that would take too much time, I suspect... I have M8F version, by the way.

root@gm1:/home/kondou# reboot Connection to 192.168.2.11 closed by remote host. Connection to 192.168.2.11 closed. kondou@dantegw:~$ ping 192.168.2.11 PING 192.168.2.11 (192.168.2.11) 56(84) bytes of data. 64 bytes from 192.168.2.11: icmp_seq=13 ttl=64 time=0.340 ms 64 bytes from 192.168.2.11: icmp_seq=14 ttl=64 time=0.222 ms ^C --- 192.168.2.11 ping statistics --- 14 packets transmitted, 2 received, 85% packet loss, time 13553ms rtt min/avg/max/mdev = 0.222/0.281/0.340/0.059 ms

kondou@dantegw:~$ ssh 192.168.2.11 Linux gm1 5.15.61-v8+ #1579 SMP PREEMPT Fri Aug 26 11:16:44 BST 2022 aarch64

The programs included with the Debian GNU/Linux system are free software; the exact distribution terms for each program are described in the individual files in /usr/share/doc/*/copyright.

Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent permitted by applicable law. Last login: Fri Feb 3 07:20:24 2023 from 192.168.2.1 kondou@gm1:~ $ sudo -s root@gm1:/home/kondou# date Fri 3 Feb 07:27:18 JST 2023 root@gm1:/home/kondou# systemctl status ts2phc.service 〓〓〓 ts2phc.service - Synchronize PTP hardware clock (PHC) to external time stamp signal Loaded: loaded (/etc/systemd/system/ts2phc.service; disabled; vendor preset: enabled) Active: active (running) since Fri 2023-02-03 07:27:02 JST; 22s ago Docs: man:ts2phc Process: 515 ExecStartPre=/usr/sbin/phc_ctl -Q $EXTTS_IFACE set; adj $UTC_OFFSET (code=exited, status=0/SUCCESS) Main PID: 519 (ts2phc) Tasks: 2 (limit: 4164) CPU: 33ms CGroup: /system.slice/ts2phc.service 〓〓〓〓〓〓519 /usr/sbin/ts2phc -s nmea -c eth0 -l 6 --clock_servo pi --step_threshold 0.1 --tx_timestamp_timeout 100 --ts2phc.nmea_serialport /dev/ttyAMA0 --leapfile /usr/share/zoneinfo/leap-seconds.list

Feb 03 07:27:02 gm1 systemd[1]: Starting Synchronize PTP hardware clock (PHC) to external time stamp signal... Feb 03 07:27:02 gm1 phc_ctl[515]: [10.967] set clock time to 1675376822.017835715 or Fri Feb 3 07:27:02 2023 Feb 03 07:27:02 gm1 phc_ctl[515]: [10.971] adjusted clock by 37.000000 seconds Feb 03 07:27:02 gm1 systemd[1]: Started Synchronize PTP hardware clock (PHC) to external time stamp signal. root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[49.212]: offset from CLOCK_REALTIME is -15947724539ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[54.851]: offset from CLOCK_REALTIME is -15947687956ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[58.211]: offset from CLOCK_REALTIME is -15947665594ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[64.260]: offset from CLOCK_REALTIME is -15947625607ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[66.244]: offset from CLOCK_REALTIME is -15947612656ns

root@gm1:/home/kondou# chronyc tracking Reference ID : CAB567D4 (sv1.localdomain1.com) Stratum : 3 Ref time (UTC) : Thu Feb 02 22:27:53 2023 System time : 0.000000382 seconds fast of NTP time Last offset : -0.000654100 seconds RMS offset : 0.000654100 seconds Frequency : 18.127 ppm fast Residual freq : -2.872 ppm Skew : 0.013 ppm Root delay : 0.007505206 seconds Root dispersion : 0.012451026 seconds Update interval : 1.6 seconds Leap status : Normal root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[122.549]: offset from CLOCK_REALTIME is -15947082109ns

root@gm1:/home/kondou# phc_ctl eth0 "set;" adj 37 phc_ctl[138.120]: set clock time to 1675376970.219411377 or Fri Feb 3 07:29:30 2023

phc_ctl[138.122]: adjusted clock by 37.000000 seconds root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[142.830]: offset from CLOCK_REALTIME is -36997723505ns

root@gm1:/home/kondou# chronyc tracking Reference ID : 2D203726 (ipv4.ntp3.rbauman.com) Stratum : 3 Ref time (UTC) : Thu Feb 02 22:28:57 2023 System time : 0.000546066 seconds slow of NTP time Last offset : -0.000954265 seconds RMS offset : 0.000954265 seconds Frequency : 18.127 ppm fast Residual freq : -21.136 ppm Skew : 0.013 ppm Root delay : 0.010386736 seconds Root dispersion : 0.002710132 seconds Update interval : 64.5 seconds Leap status : Normal root@gm1:/home/kondou# chronyc tracking Reference ID : 2D203726 (ipv4.ntp3.rbauman.com) Stratum : 3 Ref time (UTC) : Thu Feb 02 22:28:57 2023 System time : 0.000502001 seconds slow of NTP time Last offset : -0.000954265 seconds RMS offset : 0.000954265 seconds Frequency : 18.127 ppm fast Residual freq : -21.136 ppm Skew : 0.013 ppm Root delay : 0.010386736 seconds Root dispersion : 0.002811650 seconds Update interval : 64.5 seconds Leap status : Normal root@gm1:/home/kondou# chronyc tracking Reference ID : 2D203726 (ipv4.ntp3.rbauman.com) Stratum : 3 Ref time (UTC) : Thu Feb 02 22:28:57 2023 System time : 0.000438319 seconds slow of NTP time Last offset : -0.000954265 seconds RMS offset : 0.000954265 seconds Frequency : 18.127 ppm fast Residual freq : -21.136 ppm Skew : 0.013 ppm Root delay : 0.010386736 seconds Root dispersion : 0.002958361 seconds Update interval : 64.5 seconds Leap status : Normal root@gm1:/home/kondou# chronyc tracking Reference ID : 2D203726 (ipv4.ntp3.rbauman.com) Stratum : 3 Ref time (UTC) : Thu Feb 02 22:28:57 2023 System time : 0.000408015 seconds slow of NTP time Last offset : -0.000954265 seconds RMS offset : 0.000954265 seconds Frequency : 18.127 ppm fast Residual freq : -21.136 ppm Skew : 0.013 ppm Root delay : 0.010386736 seconds Root dispersion : 0.003028175 seconds Update interval : 64.5 seconds Leap status : Normal root@gm1:/home/kondou# chronyc tracking Reference ID : 2D203726 (ipv4.ntp3.rbauman.com) Stratum : 3 Ref time (UTC) : Thu Feb 02 22:28:57 2023 System time : 0.000372787 seconds slow of NTP time Last offset : -0.000954265 seconds RMS offset : 0.000954265 seconds Frequency : 18.127 ppm fast Residual freq : -21.136 ppm Skew : 0.013 ppm Root delay : 0.010386736 seconds Root dispersion : 0.003109335 seconds Update interval : 64.5 seconds Leap status : Normal root@gm1:/home/kondou# chronyc tracking Reference ID : 2D203726 (ipv4.ntp3.rbauman.com) Stratum : 3 Ref time (UTC) : Thu Feb 02 22:30:02 2023 System time : 0.000474165 seconds fast of NTP time Last offset : +0.000806450 seconds RMS offset : 0.000940529 seconds Frequency : 18.127 ppm fast Residual freq : -4.263 ppm Skew : 0.016 ppm Root delay : 0.007762916 seconds Root dispersion : 0.001391380 seconds Update interval : 64.7 seconds Leap status : Normal root@gm1:/home/kondou# chronyc tracking Reference ID : 2D203726 (ipv4.ntp3.rbauman.com) Stratum : 3 Ref time (UTC) : Thu Feb 02 22:30:02 2023 System time : 0.000459162 seconds fast of NTP time Last offset : +0.000806450 seconds RMS offset : 0.000940529 seconds Frequency : 18.127 ppm fast Residual freq : -4.263 ppm Skew : 0.016 ppm Root delay : 0.007762916 seconds Root dispersion : 0.001410013 seconds Update interval : 64.7 seconds Leap status : Normal root@gm1:/home/kondou# chronyc tracking Reference ID : 2D203726 (ipv4.ntp3.rbauman.com) Stratum : 3 Ref time (UTC) : Thu Feb 02 22:30:02 2023 System time : 0.000442438 seconds fast of NTP time Last offset : +0.000806450 seconds RMS offset : 0.000940529 seconds Frequency : 18.127 ppm fast Residual freq : -4.263 ppm Skew : 0.016 ppm Root delay : 0.007762916 seconds Root dispersion : 0.001430784 seconds Update interval : 64.7 seconds Leap status : Normal root@gm1:/home/kondou# chronyc tracking Reference ID : 2D203726 (ipv4.ntp3.rbauman.com) Stratum : 3 Ref time (UTC) : Thu Feb 02 22:30:02 2023 System time : 0.000429587 seconds fast of NTP time Last offset : +0.000806450 seconds RMS offset : 0.000940529 seconds Frequency : 18.127 ppm fast Residual freq : -4.263 ppm Skew : 0.016 ppm Root delay : 0.007762916 seconds Root dispersion : 0.001446745 seconds Update interval : 64.7 seconds Leap status : Normal root@gm1:/home/kondou# chronyc tracking Reference ID : 2D203726 (ipv4.ntp3.rbauman.com) Stratum : 3 Ref time (UTC) : Thu Feb 02 22:30:02 2023 System time : 0.000416732 seconds fast of NTP time Last offset : +0.000806450 seconds RMS offset : 0.000940529 seconds Frequency : 18.127 ppm fast Residual freq : -4.263 ppm Skew : 0.016 ppm Root delay : 0.007762916 seconds Root dispersion : 0.001462709 seconds Update interval : 64.7 seconds Leap status : Normal root@gm1:/home/kondou# chronyc tracking Reference ID : 2D203726 (ipv4.ntp3.rbauman.com) Stratum : 3 Ref time (UTC) : Thu Feb 02 22:30:02 2023 System time : 0.000395242 seconds fast of NTP time Last offset : +0.000806450 seconds RMS offset : 0.000940529 seconds Frequency : 18.127 ppm fast Residual freq : -4.263 ppm Skew : 0.016 ppm Root delay : 0.007762916 seconds Root dispersion : 0.001489399 seconds Update interval : 64.7 seconds Leap status : Normal root@gm1:/home/kondou# chronyc tracking Reference ID : 2D203726 (ipv4.ntp3.rbauman.com) Stratum : 3 Ref time (UTC) : Thu Feb 02 22:30:02 2023 System time : 0.000368176 seconds fast of NTP time Last offset : +0.000806450 seconds RMS offset : 0.000940529 seconds Frequency : 18.127 ppm fast Residual freq : -4.263 ppm Skew : 0.016 ppm Root delay : 0.007762916 seconds Root dispersion : 0.001523014 seconds Update interval : 64.7 seconds Leap status : Normal root@gm1:/home/kondou# chronyc tracking Reference ID : 2D203726 (ipv4.ntp3.rbauman.com) Stratum : 3 Ref time (UTC) : Thu Feb 02 22:30:02 2023 System time : 0.000354839 seconds fast of NTP time Last offset : +0.000806450 seconds RMS offset : 0.000940529 seconds Frequency : 18.127 ppm fast Residual freq : -4.263 ppm Skew : 0.016 ppm Root delay : 0.007762916 seconds Root dispersion : 0.001539577 seconds Update interval : 64.7 seconds Leap status : Normal root@gm1:/home/kondou# chronyc tracking Reference ID : 2D203726 (ipv4.ntp3.rbauman.com) Stratum : 3 Ref time (UTC) : Thu Feb 02 22:30:02 2023 System time : 0.000339514 seconds fast of NTP time Last offset : +0.000806450 seconds RMS offset : 0.000940529 seconds Frequency : 18.127 ppm fast Residual freq : -4.263 ppm Skew : 0.016 ppm Root delay : 0.007762916 seconds Root dispersion : 0.001558610 seconds Update interval : 64.7 seconds Leap status : Normal root@gm1:/home/kondou# chronyc tracking Reference ID : 2D203726 (ipv4.ntp3.rbauman.com) Stratum : 3 Ref time (UTC) : Thu Feb 02 22:30:02 2023 System time : 0.000328291 seconds fast of NTP time Last offset : +0.000806450 seconds RMS offset : 0.000940529 seconds Frequency : 18.127 ppm fast Residual freq : -4.263 ppm Skew : 0.016 ppm Root delay : 0.007762916 seconds Root dispersion : 0.001572548 seconds Update interval : 64.7 seconds Leap status : Normal root@gm1:/home/kondou# chronyc tracking Reference ID : 2D203726 (ipv4.ntp3.rbauman.com) Stratum : 3 Ref time (UTC) : Thu Feb 02 22:30:02 2023 System time : 0.000309726 seconds fast of NTP time Last offset : +0.000806450 seconds RMS offset : 0.000940529 seconds Frequency : 18.127 ppm fast Residual freq : -4.263 ppm Skew : 0.016 ppm Root delay : 0.007762916 seconds Root dispersion : 0.001595606 seconds Update interval : 64.7 seconds Leap status : Normal root@gm1:/home/kondou# chronyc tracking Reference ID : 53484D30 (SHM0) Stratum : 1 Ref time (UTC) : Thu Feb 02 22:30:42 2023 System time : 0.000009456 seconds slow of NTP time Last offset : +0.002526680 seconds RMS offset : 0.001197726 seconds Frequency : 18.142 ppm fast Residual freq : +6.594 ppm Skew : 0.329 ppm Root delay : 0.000000001 seconds Root dispersion : 0.000026967 seconds Update interval : 40.2 seconds Leap status : Normal root@gm1:/home/kondou#

jclark commented 1 year ago

Something is not working, but it is nothing to do with not setting the PHC clock when booting.

This line

 ExecStartPre=/usr/sbin/phc_ctl -Q $EXTTS_IFACE set; adj $UTC_OFFSET (code=exited, status=0/SUCCESS)

shows that phc_ctl eth0 "set;" adj 37 was already done.

The result of phc_ctl eth0 cmp is -15947082109ns which is about 16 seconds. I checked ipv4.ntp2.rbauman.com and that is giving the correct time. So it looks like ts2phc is setting the PHC to a time that is wrong by about 21 seconds.

Doing phc_ctl eth0 "set;" adj 37 manually won't help. It will just obscure the problem.

When you do

(stty 9600 -echo -icrnl; cat) </dev/ttyAMA0

are the NMEA sentences showing the correct time?

I suggest you set

LOG_LEVEL=7

in /etc/default/ptp4l-gm, reboot and then look at the logs (/var/log/syslog).

I have an M8F due to be delivered today. That might give me more insight on what is going wrong for you.

Another thing you could try is to connect U-center to the M8F as described here: https://github.com/jclark/rpi-cm4-ptp-guide/blob/main/gps-config.md#u-blox

kondou commented 1 year ago

My apologies. I totally forgot to install a battery for RTC. And phc_ctl eth0 "set;" adj 37 again fixed that situation because chronyd has updated system clock accordingly when it was done. Now phc_ctl eth0 cmp shows almost -37 sec even after just rebooted.

But I still see unstable situation even after a battery is installed. Seeing from its behavior, chronyd somewhat changes the system clock if it refers to NTP server among internet.

This shows the situation. chronyd is disabled when rebooted.

root@gm1:/home/kondou# reboot Connection to 192.168.2.11 closed by remote host. Connection to 192.168.2.11 closed. kondou@dantegw:~$ ping 192.168.2.11 PING 192.168.2.11 (192.168.2.11) 56(84) bytes of data. 64 bytes from 192.168.2.11: icmp_seq=23 ttl=64 time=0.379 ms ^C --- 192.168.2.11 ping statistics --- 23 packets transmitted, 1 received, 95% packet loss, time 22846ms rtt min/avg/max/mdev = 0.379/0.379/0.379/0.000 ms

kondou@dantegw:~$ ssh 192.168.2.11 Linux gm1 5.15.61-v8+ #1579 SMP PREEMPT Fri Aug 26 11:16:44 BST 2022 aarch64

The programs included with the Debian GNU/Linux system are free software; the exact distribution terms for each program are described in the individual files in /usr/share/doc/*/copyright.

Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent permitted by applicable law. Last login: Fri Feb 3 21:31:53 2023 from 192.168.2.1 kondou@gm1:~ $ sudo -s root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[22.963]: offset from CLOCK_REALTIME is -36997820884ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[25.460]: offset from CLOCK_REALTIME is -36997761141ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[27.471]: offset from CLOCK_REALTIME is -36997713250ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[32.124]: offset from CLOCK_REALTIME is -36997600993ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[33.470]: offset from CLOCK_REALTIME is -36997568588ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[34.829]: offset from CLOCK_REALTIME is -36997536001ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[35.917]: offset from CLOCK_REALTIME is -36997509999ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[37.245]: offset from CLOCK_REALTIME is -36997477695ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[38.838]: offset from CLOCK_REALTIME is -36997439687ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[40.241]: offset from CLOCK_REALTIME is -36997405532ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[41.504]: offset from CLOCK_REALTIME is -36997375110ns

root@gm1:/home/kondou# systemctl enable chrony Synchronizing state of chrony.service with SysV service script with /lib/systemd/systemd-sysv-install. Executing: /lib/systemd/systemd-sysv-install enable chrony Created symlink /etc/systemd/system/chronyd.service 〓〓〓 /lib/systemd/system/chrony.service. Created symlink /etc/systemd/system/multi-user.target.wants/chrony.service 〓〓〓 /lib/systemd/system/chrony.service. root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[65.591]: offset from CLOCK_REALTIME is -36996793636ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[67.798]: offset from CLOCK_REALTIME is -36996740574ns

root@gm1:/home/kondou# systemctl start chrony root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[89.621]: offset from CLOCK_REALTIME is -36996261995ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[91.237]: offset from CLOCK_REALTIME is -36996261579ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[92.357]: offset from CLOCK_REALTIME is -36996261391ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[93.455]: offset from CLOCK_REALTIME is -36996261358ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[94.510]: offset from CLOCK_REALTIME is -38811604951ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[95.816]: offset from CLOCK_REALTIME is -38811579105ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[97.264]: offset from CLOCK_REALTIME is -38811527487ns

root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[98.519]: offset from CLOCK_REALTIME is -38811484251ns

root@gm1:/home/kondou# chronyc tracking Reference ID : B929F32B (ntp.ixo.no) Stratum : 3 Ref time (UTC) : Fri Feb 03 12:38:01 2023 System time : 0.000000014 seconds fast of NTP time Last offset : -0.000339364 seconds RMS offset : 0.000339364 seconds Frequency : 23.917 ppm fast Residual freq : +724.349 ppm Skew : 4.314 ppm Root delay : 0.258580953 seconds Root dispersion : 0.012708534 seconds Update interval : 1.1 seconds Leap status : Normal root@gm1:/home/kondou#

jclark commented 1 year ago

We will need to look at the log, as I suggested in my earlier reply. Also output from chronyc sources.

kondou commented 1 year ago

This is the entire syslog since from OS started. I have no idea where to look into... syslog.zip

jclark commented 1 year ago

The problem is that ts2phc is not getting any time pulses from the M8F. Try using testptp to check that you can get pulses.

kondou commented 1 year ago

No time stamp comes up (testptp waits forever after the last line...) I thought I've seen something last night...

root@gm1:/home/kondou# ./testptp -d /dev/ptp0 -L 0,1 set pin function okay root@gm1:/home/kondou# ./testptp -d /dev/ptp0 -e 5 external time stamp request okay

kondou commented 1 year ago

After the previous comment, I left it over the night, and just tried again. Now I can see, but it sometimes looks like not every second, which I'm not sure if it's ok or not... Forgot to mention, I stopped ptp4l and chrony before executing testptp.

root@gm1:/home/kondou# ./testptp -d /dev/ptp0 -e 5 external time stamp request okay event index 0 at 1675463011.993058017 event index 0 at 1675463009.022286768 event index 0 at 1675463010.022280368 event index 0 at 1675463012.022267560 event index 0 at 1675463013.022261160 root@gm1:/home/kondou# ./testptp -d /dev/ptp0 -e 5 external time stamp request okay event index 0 at 1675463029.022158696 event index 0 at 1675463031.022145880 event index 0 at 1675463032.022139472 event index 0 at 1675463032.998480072 event index 0 at 1675463033.998473672 root@gm1:/home/kondou# ./testptp -d /dev/ptp0 -e 5 external time stamp request okay event index 0 at 1675463036.998454448 event index 0 at 1675463037.998448032 event index 0 at 1675463038.998441624 event index 0 at 1675463040.914668783 event index 0 at 1675463041.816227798 root@gm1:/home/kondou# ./testptp -d /dev/ptp0 -e 5 external time stamp request okay event index 0 at 1675463046.324022856 event index 0 at 1675463047.225581865 event index 0 at 1675463048.127140866 event index 0 at 1675463049.028699875 event index 0 at 1675463049.930258890 root@gm1:/home/kondou#

jclark commented 1 year ago

If you're seeing at least some pulses, then we're making progress: at least the M8F is wired up right.

If you're not seeing every pulse, then the most common explanation is that there's another process (e.g. phc2sys) reading the clock. You can do ps ax | grep phc2sys to check that there aren't any processes running that shouldn't be.

If testptp is working and showing at least most pulses, and you can see the GPS output using cat, then ts2phc ought to work. Try starting the ts2phc service again: systemctl start ts2phc. If it doesn't work, try rebooting. If that doesn't work, attach the last part of the log, starting from the time when you rebooted (don't zip it).

kondou commented 1 year ago

Thank you very much for the suggestion. I was out all day today for planned work in the office. Just came back to my home, and I confirmed phc2sys was running.

root@gm1:/home/kondou# date Sat 4 Feb 20:33:18 JST 2023 root@gm1:/home/kondou# ps ax | grep phc2sys 517 ? Ss 0:04 /usr/sbin/phc2sys -s eth0 -E ntpshm -O -37 -N 1 -R 0.07 -l 7 2874 pts/0 S+ 0:00 grep phc2sys

I can also see the GPS output via cat (I assume (stty 9600 -echo -icrnl; cat) </dev/ttyAMA0), and starting ts2phc went well.

root@gm1:/home/kondou# systemctl start ts2phc root@gm1:/home/kondou# ps -ef | grep ts2phc root 519 1 0 Feb03 ? 00:03:01 /usr/sbin/ts2phc -s nmea -c eth0 -l 7 --clock_servo pi --step_threshold 0.1 --tx_timestamp_timeout 100 --ts2phc.nmea_serialport /dev/ttyAMA0 --leapfile /usr/share/zoneinfo/leap-seconds.list root 2899 1556 0 20:42 pts/0 00:00:00 grep ts2phc

But seeing from the time stamp labeled by ps it's been up and running...

kondou commented 1 year ago

After I wrote above comment, I rebooted the OS without power-off, then everything worked without any issue. So I thought it'd be ok at last. But, after I rebooted OS several times, I somehow could not do ssh and had to plug out and in the power cable for CM4 IO board to be able to login via ssh.

In this case, the issue comes up again. So, seeing from my situation, it seems that I need to wait for long time to get PPS after power source for M8F is started.

jclark commented 1 year ago

What sort of antenna do you have? How good a sky view does it have?

By default, I think most u-blox receivers only output a pulse when they have a GPS fix.

kondou commented 1 year ago

I've left `./testptp -d /dev/ptp0 -e 5' after CM4 IO board is powered on, and it took about 150 minutes to get PPS after the power is fed.

I use Beitian BT-345AJL2 as an antenna. Actually, it's not placed in a good sky view. It's within in my house and close to the south window. Tomorrow, I will place it in the veranda of my apartment, which is the best place I have. I hope placing good location would shorten GPS fix. Thank you very much for letting me know u-blox's behavior. That looks like explaining my situation.

Now, I rebooted OS, not power cycle. And I still see PPS is coming. In the previous message, I wrote it worked without any issue, but this time I still do not see the offset about -37, but 'phc_ctl[667.185]: offset from CLOCK_REALTIME is -34994674981ns` ts2phc is running. Do I have to wait more to see almost -37?

jclark commented 1 year ago

ts2phc needs a good-quality pulse, which you don't have if it's taken 150 minutes to get a PPS.

That kind of antenna needs a ground plane to work optimally (i.e. a bit of metal underneath it like this https://www.sparkfun.com/products/17519). You can probably improvise something.

See what happens if you locate the antenna with a sky-view, use a ground plane and reboot. Look at the logs (grep ts2phc /var/log/syslog) to see what's happening and use chronyc sources to see whether chrony is using the M8F.

kondou commented 1 year ago

Thank you very much for the suggestion.

I was trying to place the antenna at the best place, but I noticed there is no suitable route for the coaxial cable between antenna and CM4 IO board. I will try to confirm by bringing CM4 IO board in my veranda later, but I moved the antenna much closeer to the glass of the window instead. This improved much, and PPS comes up about 10 minutes later after power cycle.

But there is no log spewed by ts2phc after power cycle. And chronyd didn't use the M8F.

root@gm1:/home/kondou# chronyc sources MS Name/IP address Stratum Poll Reach LastRx Last sample =============================================================================== #x SHM0 0 0 0 13 -145ms[ -145ms] +/- 1000ns ^- y.ns.gin.ntt.net 2 7 377 36 +2462us[+2462us] +/- 76ms ^+ ipv4.ntp3.rbauman.com 2 7 377 101 +94us[ +63us] +/- 3859us ^- 133-32-27-253.west.xps.v> 2 7 377 41 -1278us[-1308us] +/- 15ms ^* mail1.marinecat.net 2 6 377 41 -1072us[-1101us] +/- 4699us

You might tell me it'd be meaningless, but I noticed systemctl restart ts2phc fixed this situation. cronyc sources showed chronyd was using the M8F.

root@gm1:/home/kondou# chronyc sources MS Name/IP address Stratum Poll Reach LastRx Last sample =============================================================================== #* SHM0 0 0 1 1 +774ns[+1038ns] +/- 1000ns ^- y.ns.gin.ntt.net 2 8 377 121 -1479us[-1478us] +/- 66ms ^- ipv4.ntp3.rbauman.com 2 8 377 55 -875us[ -874us] +/- 4444us ^- 133-32-27-253.west.xps.v> 2 8 377 127 -1091us[-1091us] +/- 13ms ^- mail1.marinecat.net 2 7 377 126 -951us[ -950us] +/- 4044us root@gm1:/home/kondou# phc_ctl eth0 cmp phc_ctl[2705.011]: offset from CLOCK_REALTIME is -36999999958ns

As for ground plate, that should work as a reflector, and I will use aluminum one, which should be also okay.

kondou commented 1 year ago

I noticed CM4 sometimes rebooted several times just after rebooted, and there's no meaningful messages related to this situation in syslog. Because of this, grep could not identify latest ts2phc messages in syslog which includes some corrupted data. Now I see ts2phc has (and had) been spewing messages like this by cat /var/log/syslog | tail -100 | grep ts2phc

I suspect some of OS data was broken by doing power cycle which caused this kind of unexpected and spontaneous reboot, and will do the cleanup OS installation after I come back from my job today.

Feb 6 07:45:59 gm1 ts2phc: [2330.959] nmea sentence: GNGSA,A,3,66,77,65,,,,,,,,,,3.46,1.54,3.10 Feb 6 07:45:59 gm1 ts2phc: [2331.026] nmea sentence: GPGSV,3,1,11,10,53,294,13,12,59,131,37,13,01,103,,15,28,110,28 Feb 6 07:45:59 gm1 ts2phc: [2331.093] nmea sentence: GPGSV,3,2,11,18,03,212,,19,02,059,,23,63,218,31,24,51,043,09 Feb 6 07:45:59 gm1 ts2phc: [2331.161] nmea sentence: GPGSV,3,3,11,25,45,178,33,28,08,251,20,32,27,306,08 Feb 6 07:45:59 gm1 ts2phc: [2331.228] nmea sentence: GLGSV,2,1,08,65,48,121,28,66,63,352,11,67,14,323,,72,00,134,07 Feb 6 07:45:59 gm1 ts2phc: [2331.295] nmea sentence: GLGSV,2,2,08,75,29,032,15,76,88,311,,77,37,217,18,83,00,335, Feb 6 07:45:59 gm1 ts2phc: [2331.346] nmea sentence: GNGLL,3537.87654,N,13946.77027,E,224559.00,A,A Feb 6 07:45:59 gm1 ts2phc: [2331.387] nmea sentence: GNZDA,224559.00,05,02,2023,00,00 Feb 6 07:46:00 gm1 ts2phc: [2331.708] nmea sentence: GNRMC,224600.00,A,3537.87655,N,13946.77027,E,0.018,,050223,,,A Feb 6 07:46:00 gm1 ts2phc: [2331.826] nmea sentence: GNGGA,224600.00,3537.87655,N,13946.77027,E,1,07,1.55,14.9,M,39.4,M,, Feb 6 07:46:00 gm1 ts2phc: [2331.876] nmea sentence: GNGSA,A,3,12,25,15,10,23,,,,,,,,3.38,1.55,3.00 Feb 6 07:46:00 gm1 ts2phc: [2331.927] nmea sentence: GNGSA,A,3,77,65,,,,,,,,,,,3.38,1.55,3.00 Feb 6 07:46:00 gm1 ts2phc: [2331.994] nmea sentence: GPGSV,3,1,11,10,53,294,13,12,59,131,37,13,01,103,,15,28,110,28 Feb 6 07:46:00 gm1 ts2phc: [2332.061] nmea sentence: GPGSV,3,2,11,18,03,212,,19,02,059,,23,63,218,30,24,51,043,09 Feb 6 07:46:00 gm1 ts2phc: [2332.129] nmea sentence: GPGSV,3,3,11,25,45,178,33,28,08,251,20,32,27,306,08 Feb 6 07:46:00 gm1 ts2phc: [2332.196] nmea sentence: GLGSV,2,1,08,65,48,121,29,66,63,352,08,67,14,323,,72,00,134,08 Feb 6 07:46:00 gm1 ts2phc: [2332.263] nmea sentence: GLGSV,2,2,08,75,29,032,13,76,88,311,,77,37,217,18,83,00,335, Feb 6 07:46:00 gm1 ts2phc: [2332.314] nmea sentence: GNGLL,3537.87655,N,13946.77027,E,224600.00,A,A Feb 6 07:46:00 gm1 ts2phc: [2332.353] nmea sentence: GNZDA,224600.00,05,02,2023,00,00 Feb 6 07:46:01 gm1 ts2phc: [2332.730] nmea sentence: GNRMC,224601.00,A,3537.87656,N,13946.77028,E,0.019,,050223,,,A Feb 6 07:46:01 gm1 ts2phc: [2332.848] nmea sentence: GNGGA,224601.00,3537.87656,N,13946.77028,E,1,07,1.56,14.9,M,39.4,M,, Feb 6 07:46:01 gm1 ts2phc: [2332.898] nmea sentence: GNGSA,A,3,12,25,15,10,23,,,,,,,,3.38,1.56,3.00 Feb 6 07:46:01 gm1 ts2phc: [2332.949] nmea sentence: GNGSA,A,3,77,65,,,,,,,,,,,3.38,1.56,3.00 Feb 6 07:46:01 gm1 ts2phc: [2333.016] nmea sentence: GPGSV,3,1,11,10,53,294,15,12,59,131,37,13,01,103,,15,28,110,28 Feb 6 07:46:01 gm1 ts2phc: [2333.083] nmea sentence: GPGSV,3,2,11,18,03,212,,19,02,059,,23,63,218,31,24,51,043,09 Feb 6 07:46:01 gm1 ts2phc: [2333.151] nmea sentence: GPGSV,3,3,11,25,45,178,33,28,08,251,20,32,27,306,09 Feb 6 07:46:01 gm1 ts2phc: [2333.218] nmea sentence: GLGSV,2,1,08,65,48,121,29,66,63,352,08,67,14,323,,72,00,134,11 Feb 6 07:46:01 gm1 ts2phc: [2333.285] nmea sentence: GLGSV,2,2,08,75,29,032,09,76,88,311,,77,37,217,18,83,00,335, Feb 6 07:46:01 gm1 ts2phc: [2333.336] nmea sentence: GNGLL,3537.87656,N,13946.77028,E,224601.00,A,A Feb 6 07:46:01 gm1 ts2phc: [2333.375] nmea sentence: GNZDA,224601.00,05,02,2023,00,00

kondou commented 1 year ago

Today, I've placed two antennae in the veranda at last, and managed to lay the coaxial cable via air conditioner's duct. Actually I have three sets of M8F, and the rest of M8F (called gm1) antenna, with which I started the test, was still stays at the same place.

gm1 has been up and running for over a week without any issue. As for unexpected reboot was caused by faulty IO board. I got the new IO board, and unexpected reboot never happens since then.

For gm2 and gm3, for which I placed the antenna, they look like working well seeing from the syslog like this. I'm still waiting for the material of the ground plate, but seeing from the situation, it looks working well without it.

Feb 18 21:49:49 gm3 phc2sys: [24.888] CLOCK_REALTIME phc offset 1324501 s0 freq +0 delay 67148 Feb 18 21:50:03 gm3 phc2sys: [39.175] CLOCK_REALTIME phc offset 1259793 s0 freq +0 delay 68055 Feb 18 21:50:17 gm3 phc2sys: [53.461] CLOCK_REALTIME phc offset -158875492 s0 freq +0 delay 67055 Feb 18 21:50:32 gm3 phc2sys: [67.748] CLOCK_REALTIME phc offset 162564493 s0 freq +0 delay 114481 Feb 18 21:50:46 gm3 phc2sys: [82.035] CLOCK_REALTIME phc offset 1158033 s0 freq +0 delay 67963 Feb 18 21:51:00 gm3 phc2sys: [96.322] CLOCK_REALTIME phc offset -1800022 s0 freq +0 delay 64744 Feb 18 21:51:15 gm3 phc2sys: [110.609] CLOCK_REALTIME phc offset -8125493 s0 freq +0 delay 74133 Feb 18 21:51:29 gm3 phc2sys: [124.896] CLOCK_REALTIME phc offset -9662382 s0 freq +0 delay 69752 Feb 18 21:51:43 gm3 phc2sys: [139.182] CLOCK_REALTIME phc offset -9739947 s0 freq +0 delay 39741 Feb 18 21:51:47 gm3 phc_ctl: [143.041] offset from CLOCK_REALTIME is -36999988028ns Feb 18 21:51:57 gm3 phc2sys: [153.469] CLOCK_REALTIME phc offset 18775 s0 freq +0 delay 68185 Feb 18 21:52:12 gm3 phc2sys: [167.756] CLOCK_REALTIME phc offset 31427 s0 freq +0 delay 68110 Feb 18 21:52:26 gm3 phc2sys: [182.043] CLOCK_REALTIME phc offset 42610 s0 freq +0 delay 67648 Feb 18 21:52:40 gm3 phc2sys: [196.330] CLOCK_REALTIME phc offset 8740 s0 freq +0 delay 69722 Feb 18 21:52:53 gm3 phc_ctl: [209.320] offset from CLOCK_REALTIME is -37000001235ns Feb 18 21:52:55 gm3 phc2sys: [210.617] CLOCK_REALTIME phc offset -1539 s0 freq +0 delay 67296 Feb 18 21:53:09 gm3 phc2sys: [224.903] CLOCK_REALTIME phc offset -1695 s0 freq +0 delay 66833 Feb 18 21:53:23 gm3 phc2sys: [239.190] CLOCK_REALTIME phc offset -2215 s0 freq +0 delay 67499 Feb 18 21:53:38 gm3 phc2sys: [253.477] CLOCK_REALTIME phc offset -3367 s0 freq +0 delay 72370 Feb 18 21:53:52 gm3 phc2sys: [267.764] CLOCK_REALTIME phc offset -1901 s0 freq +0 delay 67092 Feb 18 21:54:06 gm3 phc2sys: [282.051] CLOCK_REALTIME phc offset -1966 s0 freq +0 delay 66592 Feb 18 21:54:20 gm3 phc2sys: [296.338] CLOCK_REALTIME phc offset -1012 s0 freq +0 delay 67629 Feb 18 21:54:35 gm3 phc2sys: [310.625] CLOCK_REALTIME phc offset -3581 s0 freq +0 delay 80981 Feb 18 21:54:49 gm3 phc2sys: [324.911] CLOCK_REALTIME phc offset -1744 s0 freq +0 delay 70000 Feb 18 21:55:03 gm3 phc2sys: [339.198] CLOCK_REALTIME phc offset -2738 s0 freq +0 delay 67758 Feb 18 21:55:18 gm3 phc2sys: [353.485] CLOCK_REALTIME phc offset -2471 s0 freq +0 delay 67500 Feb 18 21:55:32 gm3 phc2sys: [367.772] CLOCK_REALTIME phc offset 277 s0 freq +0 delay 66388 Feb 18 21:55:46 gm3 phc2sys: [382.059] CLOCK_REALTIME phc offset 250 s0 freq +0 delay 66592 Feb 18 21:56:00 gm3 phc2sys: [396.346] CLOCK_REALTIME phc offset 74 s0 freq +0 delay 67222

I think it should be okay now. Thank you very much for your suggestion and support anyway.