Daemon is locked to non-existent PTP clock

[anthonio9]

Following other issues related to the local PTP clock I managed to patch the ptp4l source code and run PTP clock locally on a rasbperrypi4 board. My current config is that receiver runs on the rpi4 (linux 5.4.72-44rt) and sender on my linux pc (kubuntu 20.04).
Just for testing purposes the PTP clock was turned off during the stream, but nothing happened, stream was still running properly, both daemons were locked onto the now non-existent PTP master clock running on rpi4. Why would that be, is it the expected behaviour?

After a restart of any of the daemons they both seem to remember the old PTP clock MAC address and are trying to lock onto it, but remain unlocked. Instead of expected 0-0-0-0-0-0-0-0 in the GMID row of PTP status figures the rpi4 MAC address (the address of non-existing PTP master). This time, it's not possible to run any streams, after all the daemons are unlocked.

My expectations were that soon (in a few seconds max) after the PTP is stopped, the audio stream would be broken as well, reflected by lack of any MAC address in the GMID value.

Below is the output of aes67-daemon running on kubuntu pc when it can't lock onto a PTP clock (because there's none in the network).

[0x00007ff92bfff700] [info]    http_server:: GET /api/ptp/status response 200
[2022-06-10 16:35:32.116216] [0x00007ff9495e8700] [info]    sap::announcement 12d2
[2022-06-10 16:35:32.116357] [0x00007ff9495e8700] [info]    session_manager:: next SAP announcements in 30 secs
[2022-06-10 16:35:33.116608] [0x00007ff9495e8700] [debug]   driver_handler:: sending command code 31 data len 0
[2022-06-10 16:35:33.116686] [0x00007ff9495e8700] [debug]   driver_handler:: command code 31 data len 0 sent
[2022-06-10 16:35:33.116747] [0x00007ff9495e8700] [debug]   driver_handler:: received cmd code 31 error 0 data len 2
[2022-06-10 16:35:33.116760] [0x00007ff9495e8700] [info]    driver_manager:: cmd GetPTPConfig done data len 2
[2022-06-10 16:35:33.116772] [0x00007ff9495e8700] [debug]   driver_manager:: PTP Domain 0 DSCP 48
[2022-06-10 16:35:33.116782] [0x00007ff9495e8700] [debug]   driver_handler:: sending command code 32 data len 0
[2022-06-10 16:35:33.116797] [0x00007ff9495e8700] [debug]   driver_handler:: command code 32 data len 0 sent
[2022-06-10 16:35:33.116823] [0x00007ff9495e8700] [debug]   driver_handler:: received cmd code 32 error 0 data len 16
[2022-06-10 16:35:33.116832] [0x00007ff9495e8700] [info]    driver_manager:: cmd GetPTPStatus done data len 16
[2022-06-10 16:35:33.116841] [0x00007ff9495e8700] [debug]   driver_manager:: PTP Status unlocked GMID 9799632673730289636 Jitter 0

EDIT:
I noticed that audio does stop if the clock is restarted while daemons are still running. Then PTP locking takes place during which audio stops, later once daemons are locked to the PTP master audio comes back. The confusing part is that there's no traces of unlocking in the logs or WebUI, which again I think should happen right after killing the ptp4l process.

./scripts/ptp_status.sh >> PTP locking
[2022-06-10 17:00:45.545528] [0x00007f60edffb700] [info]    http_server:: GET /api/ptp/status response 200
[2022-06-10 17:00:47.137078] [0x00007f6107b37700] [debug]   driver_handler:: sending command code 31 data len 0
[2022-06-10 17:00:47.137138] [0x00007f6107b37700] [debug]   driver_handler:: command code 31 data len 0 sent
[2022-06-10 17:00:47.137191] [0x00007f6107b37700] [debug]   driver_handler:: received cmd code 31 error 0 data len 2
[2022-06-10 17:00:47.137202] [0x00007f6107b37700] [info]    driver_manager:: cmd GetPTPConfig done data len 2
[2022-06-10 17:00:47.137211] [0x00007f6107b37700] [debug]   driver_manager:: PTP Domain 0 DSCP 48
[2022-06-10 17:00:47.137218] [0x00007f6107b37700] [debug]   driver_handler:: sending command code 32 data len 0
[2022-06-10 17:00:47.137230] [0x00007f6107b37700] [debug]   driver_handler:: command code 32 data len 0 sent
[2022-06-10 17:00:47.137251] [0x00007f6107b37700] [debug]   driver_handler:: received cmd code 32 error 0 data len 16
[2022-06-10 17:00:47.137261] [0x00007f6107b37700] [info]    driver_manager:: cmd GetPTPStatus done data len 16
[2022-06-10 17:00:47.137272] [0x00007f6107b37700] [debug]   driver_manager:: PTP Status locked GMID 9799632673730289636 Jitter 0
[2022-06-10 17:00:47.137286] [0x00007f6107b37700] [info]    session_manager:: new PTP clock status locked
[2022-06-10 17:00:47.137296] [0x00007f6107b37700] [debug]   driver_handler:: sending command code 5 data len 4
[2022-06-10 17:00:47.137308] [0x00007f6107b37700] [debug]   driver_handler:: command code 5 data len 4 sent
[2022-06-10 17:00:47.137329] [0x00007f6107b37700] [debug]   driver_handler:: received cmd code 5 error 0 data len 0
[2022-06-10 17:00:47.137337] [0x00007f6107b37700] [info]    driver_manager:: cmd SetSampleRate done data len 0
./scripts/ptp_status.sh >> PTP locked

[bondagit]

I am aware of the issue that is in the PTP slave handling part of the driver code.
You can checkout the driver branch daemon-issue-87 and try with the new driver.
The patch makes the PTP slave clock status change to unlocked if no announcement messages are received from the current master for more than 5 seconds .

[bondagit]

any update on this ?

[anthonio9]

Yes, just checked your update. It does work, thanks for help! I think we can close the issue now.