Skip to content

Daemon is locked to non-existent PTP clock #87

@anthonio9

Description

@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

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions