PTP Timing Pod Debugging

Use the following commands for PTP timing pod debugging:

• Timing Controller

  • Create a log in timing-controller:

    capv@cp1-control-plane-9hkmf [ ~ ]$ kubectl exec -it -n tca-system timing-controller-daemon-4bbpk   -c timing-controller -- bash
    root [ / ]#

  • Retrieve a timing-controller log:

    capv@cp1-control-plane-9hkmf [ ~ ]$ kubectl logs  timing-controller-daemon-4bbpk -n tca-system  -c timing-controller --tail 100
    
    2023-08-18 21:06:19 : [INFO] - ts2phc[960135.641]: adding tstamp 1692392816.000000000 to clock /dev/ptp0
    2023-08-18 21:06:19 : [INFO] - ts2phc[960135.641]: nmea delay: 60724382 ns
    2023-08-18 21:06:19 : [INFO] - ts2phc[960135.641]: /dev/ptp0 offset          0 s2 freq      +0
    2023-08-18 21:06:19 : [INFO] - ts2phc[960135.701]: nmea sentence: GNRMC,210619.00,A,4724.40421,N,12011.28046,W,0.005,,180823,,,A,V
    2023-08-18 21:06:19 : [INFO] - phc2sys[960136.107]: CLOCK_REALTIME phc offset        -5 s2 freq  -26818 delay   2254
    2023-08-18 21:06:20 : [INFO] - ts2phc[960136.641]: nmea delay: 60672681 ns
    2023-08-18 21:06:20 : [INFO] - ts2phc[960136.641]: adding tstamp 1692392817.000000000 to clock /dev/ptp0
    2023-08-18 21:06:20 : [INFO] - ts2phc[960136.641]: nmea delay: 60672681 ns
    2023-08-18 21:06:20 : [INFO] - ts2phc[960136.641]: /dev/ptp0 offset          0 s2 freq      +0
    2023-08-18 21:06:20 : [INFO] - ts2phc[960136.706]: nmea sentence: GNRMC,210620.00,A,4724.40422,N,12011.28046,W,0.005,,180823,,,A,V
    2023-08-18 21:06:20 : [INFO] - phc2sys[960137.107]: CLOCK_REALTIME phc offset        15 s2 freq  -26800 delay   2075
    2023-08-18 21:06:21 : [INFO] - ts2phc[960137.641]: nmea delay: 65652333 ns
    2023-08-18 21:06:21 : [INFO] - ts2phc[960137.641]: adding tstamp 1692392818.000000000 to clock /dev/ptp0
    2023-08-18 21:06:21 : [INFO] - ts2phc[960137.641]: nmea delay: 65652333 ns
    2023-08-18 21:06:21 : [INFO] - ts2phc[960137.641]: /dev/ptp0 offset          0 s2 freq      +0
    2023-08-18 21:06:21 : [INFO] - ts2phc[960137.713]: nmea sentence: GNRMC,210621.00,A,4724.40423,N,12011.28045,W,0.005,,180823,,,A,V
    2023-08-18 21:06:21 : [INFO] - phc2sys[960138.107]: CLOCK_REALTIME phc offset         2 s2 freq  -26808 delay   2175
    2023-08-18 21:06:22 : [INFO] - ts2phc[960138.641]: nmea delay: 72263342 ns
    2023-08-18 21:06:22 : [INFO] - ts2phc[960138.641]: adding tstamp 1692392819.000000000 to clock /dev/ptp0
    2023-08-18 21:06:22 : [INFO] - ts2phc[960138.641]: nmea delay: 72263342 ns
    2023-08-18 21:06:22 : [INFO] - ts2phc[960138.641]: /dev/ptp0 offset          0 s2 freq      +0
    2023-08-18 21:06:22 : [INFO] - ts2phc[960138.711]: nmea sentence: GNRMC,210622.00,A,4724.40423,N,12011.28045,W,0.006,,180823,,,A,V
    2023-08-18 21:06:22 : [INFO] - phc2sys[960139.107]: CLOCK_REALTIME phc offset         5 s2 freq  -26805 delay   1892
    2023-08-18 21:06:23 : [INFO] - ts2phc[960139.641]: nmea delay: 69753073 ns
    2023-08-18 21:06:23 : [INFO] - ts2phc[960139.641]: adding tstamp 1692392820.000000000 to clock /dev/ptp0
    2023-08-18 21:06:23 : [INFO] - ts2phc[960139.641]: nmea delay: 69753073 ns
    2023-08-18 21:06:23 : [INFO] - ts2phc[960139.641]: /dev/ptp0 offset          0 s2 freq      +0
    2023-08-18 21:06:23 : [INFO] - ts2phc[960139.710]: nmea sentence: GNRMC,210623.00,A,4724.40424,N,12011.28045,W,0.006,,180823,,,A,V
    2023-08-18 21:06:23 : [INFO] - phc2sys[960140.108]: CLOCK_REALTIME phc offset       -34 s2 freq  -26842 delay   2284
    2023-08-18 21:06:24 : [INFO] - ts2phc[960140.641]: nmea delay: 69259015 ns
    2023-08-18 21:06:24 : [INFO] - ts2phc[960140.641]: adding tstamp 1692392821.000000000 to clock /dev/ptp0
    2023-08-18 21:06:24 : [INFO] - ts2phc[960140.641]: nmea delay: 69259015 ns
    2023-08-18 21:06:24 : [INFO] - ts2phc[960140.641]: /dev/ptp0 offset          0 s2 freq      +0
    2023-08-18 21:06:24 : [INFO] - ts2phc[960140.703]: nmea sentence: GNRMC,210624.00,A,4724.40425,N,12011.28044,W,0.006,,180823,,,A,V
    2023-08-18 21:06:24 : [INFO] - phc2sys[960141.108]: CLOCK_REALTIME phc offset        -1 s2 freq  -26819 delay   2223
    2023-08-18 21:06:25 : [INFO] - ts2phc[960141.641]: nmea delay: 61893763 ns
    2023-08-18 21:06:25 : [INFO] - ts2phc[960141.641]: adding tstamp 1692392822.000000000 to clock /dev/ptp0
    2023-08-18 21:06:25 : [INFO] - ts2phc[960141.641]: nmea delay: 61893763 ns
    2023-08-18 21:06:25 : [INFO] - ts2phc[960141.641]: /dev/ptp0 offset          0 s2 freq      +0
    2023-08-18 21:06:25 : [INFO] - ts2phc[960141.703]: nmea sentence: GNRMC,210625.00,A,4724.40425,N,12011.28044,W,0.006,,180823,,,A,V
    2023-08-18 21:06:25 : [INFO] - phc2sys[960142.108]: CLOCK_REALTIME phc offset        69 s2 freq  -26750 delay   1981
    2023-08-18 21:06:26 : [INFO] - ts2phc[960142.641]: nmea delay: 61823078 ns
    2023-08-18 21:06:26 : [INFO] - ts2phc[960142.641]: adding tstamp 1692392823.000000000 to clock /dev/ptp0
    2023-08-18 21:06:26 : [INFO] - ts2phc[960142.641]: nmea delay: 61823078 ns
    2023-08-18 21:06:26 : [INFO] - ts2phc[960142.641]: /dev/ptp0 offset          0 s2 freq      +0
    2023-08-18 21:06:26 : [INFO] - ts2phc[960142.702]: nmea sentence: GNRMC,210626.00,A,4724.40426,N,12011.28044,W,0.006,,180823,,,A,V
    2023-08-18 21:06:26 : [INFO] - phc2sys[960143.109]: CLOCK_REALTIME phc offset        -6 s2 freq  -26804 delay   2177
    2023-08-18 21:06:27 : [INFO] - ts2phc[960143.641]: nmea delay: 60756599 ns
    2023-08-18 21:06:27 : [INFO] - ts2phc[960143.641]: adding tstamp 1692392824.000000000 to clock /dev/ptp0
    2023-08-18 21:06:27 : [INFO] - ts2phc[960143.641]: nmea delay: 60756599 ns
    2023-08-18 21:06:27 : [INFO] - ts2phc[960143.641]: /dev/ptp0 offset          0 s2 freq      +0
    2023-08-18 21:06:27 : [INFO] - ts2phc[960143.703]: nmea sentence: GNRMC,210627.00,A,4724.40426,N,12011.28044,W,0.006,,180823,,,A,V
    2023-08-18 21:06:27 : [INFO] - phc2sys[960144.109]: CLOCK_REALTIME phc offset       -66 s2 freq  -26866 delay   2251
    2023-08-18 21:06:28 : [INFO] - ts2phc[960144.641]: nmea delay: 61897090 ns
    2023-08-18 21:06:28 : [INFO] - ts2phc[960144.641]: adding tstamp 1692392825.000000000 to clock /dev/ptp0
    2023-08-18 21:06:28 : [INFO] - ts2phc[960144.641]: nmea delay: 61897090 ns
    2023-08-18 21:06:28 : [INFO] - ts2phc[960144.641]: /dev/ptp0 offset          0 s2 freq      +0
    2023-08-18 21:06:28 : [INFO] - ts2phc[960144.701]: nmea sentence: GNRMC,210628.00,A,4724.40427,N,12011.28044,W,0.006,,180823,,,A,V
    2023-08-18 21:06:28 : [INFO] - phc2sys[960145.109]: CLOCK_REALTIME phc offset        -1 s2 freq  -26821 delay   2267
    2023-08-18 21:06:29 : [INFO] - ts2phc[960145.641]: nmea delay: 60656082 ns
    2023-08-18 21:06:29 : [INFO] - ts2phc[960145.641]: adding tstamp 1692392826.000000000 to clock /dev/ptp0
    2023-08-18 21:06:29 : [INFO] - ts2phc[960145.641]: nmea delay: 60656082 ns
    2023-08-18 21:06:29 : [INFO] - ts2phc[960145.641]: /dev/ptp0 offset          0 s2 freq      +0
    2023-08-18 21:06:29 : [INFO] - ts2phc[960145.701]: nmea sentence: GNRMC,210629.00,A,4724.40427,N,12011.28045,W,0.006,,180823,,,A,V
    2023-08-18 21:06:29 : [INFO] - phc2sys[960146.109]: CLOCK_REALTIME phc offset        17 s2 freq  -26803 delay   2251
    2023-08-18 21:06:30 : [INFO] - ts2phc[960146.641]: nmea delay: 60651670 ns
    2023-08-18 21:06:30 : [INFO] - ts2phc[960146.641]: adding tstamp 1692392827.000000000 to clock /dev/ptp0
    2023-08-18 21:06:30 : [INFO] - ts2phc[960146.641]: nmea delay: 60651670 ns
    2023-08-18 21:06:30 : [INFO] - ts2phc[960146.641]: /dev/ptp0 offset          0 s2 freq      +0
    2023-08-18 21:06:30 : [INFO] - ts2phc[960146.701]: nmea sentence: GNRMC,210630.00,A,4724.40428,N,12011.28045,W,0.006,,180823,,,A,V
    2023-08-18 21:06:30 : [INFO] - phc2sys[960147.109]: CLOCK_REALTIME phc offset        25 s2 freq  -26790 delay   1903
    2023-08-18 21:06:31 : [INFO] - ts2phc[960147.641]: nmea delay: 60650280 ns
    2023-08-18 21:06:31 : [INFO] - ts2phc[960147.641]: adding tstamp 1692392828.000000000 to clock /dev/ptp0
    2023-08-18 21:06:31 : [INFO] - ts2phc[960147.641]: nmea delay: 60650280 ns
    2023-08-18 21:06:31 : [INFO] - ts2phc[960147.641]: /dev/ptp0 offset          0 s2 freq      +0
    2023-08-18 21:06:31 : [INFO] - ts2phc[960147.703]: nmea sentence: GNRMC,210631.00,A,4724.40428,N,12011.28045,W,0.006,,180823,,,A,V
    2023-08-18 21:06:31 : [INFO] - phc2sys[960148.110]: CLOCK_REALTIME phc offset        22 s2 freq  -26785 delay   2316
    2023-08-18 21:06:32 : [INFO] - ts2phc[960148.641]: nmea delay: 61874751 ns
    2023-08-18 21:06:32 : [INFO] - ts2phc[960148.641]: adding tstamp 1692392829.000000000 to clock /dev/ptp0
    2023-08-18 21:06:32 : [INFO] - ts2phc[960148.641]: nmea delay: 61874751 ns
    2023-08-18 21:06:32 : [INFO] - ts2phc[960148.641]: /dev/ptp0 offset          0 s2 freq      +0
    2023-08-18 21:06:32 : [INFO] - ts2phc[960148.701]: nmea sentence: GNRMC,210632.00,A,4724.40428,N,12011.28046,W,0.006,,180823,,,A,V
    2023-08-18 21:06:32 : [INFO] - phc2sys[960149.110]: CLOCK_REALTIME phc offset       -23 s2 freq  -26824 delay   2292
    2023-08-18 21:06:33 : [INFO] - ts2phc[960149.641]: nmea delay: 60654409 ns
    2023-08-18 21:06:33 : [INFO] - ts2phc[960149.641]: adding tstamp 1692392830.000000000 to clock /dev/ptp0
    2023-08-18 21:06:33 : [INFO] - ts2phc[960149.641]: nmea delay: 60654409 ns
    2023-08-18 21:06:33 : [INFO] - ts2phc[960149.641]: /dev/ptp0 offset          0 s2 freq      +0
    2023-08-18 21:06:33 : [INFO] - ts2phc[960149.703]: nmea sentence: GNRMC,210633.00,A,4724.40428,N,12011.28047,W,0.006,,180823,,,A,V
    2023-08-18 21:06:33 : [INFO] - phc2sys[960150.110]: CLOCK_REALTIME phc offset        17 s2 freq  -26791 delay   1902
    2023-08-18 21:06:34 : [INFO] - ts2phc[960150.641]: nmea delay: 61798355 ns
    2023-08-18 21:06:34 : [INFO] - ts2phc[960150.641]: adding tstamp 1692392831.000000000 to clock /dev/ptp0
    2023-08-18 21:06:34 : [INFO] - ts2phc[960150.641]: nmea delay: 61798355 ns
    2023-08-18 21:06:34 : [INFO] - ts2phc[960150.641]: /dev/ptp0 offset          0 s2 freq      +0
    2023-08-18 21:06:34 : [INFO] - ts2phc[960150.702]: nmea sentence: GNRMC,210634.00,A,4724.40428,N,12011.28048,W,0.006,,180823,,,A,V
    2023-08-18 21:06:34 : [INFO] - phc2sys[960151.110]: CLOCK_REALTIME phc offset       -32 s2 freq  -26835 delay   2235
    2023-08-18 21:06:35 : [INFO] - ts2phc[960151.641]: nmea delay: 60731575 ns
    2023-08-18 21:06:35 : [INFO] - ts2phc[960151.641]: adding tstamp 1692392832.000000000 to clock /dev/ptp0
    2023-08-18 21:06:35 : [INFO] - ts2phc[960151.641]: nmea delay: 60731575 ns
    2023-08-18 21:06:35 : [INFO] - ts2phc[960151.641]: /dev/ptp0 offset          0 s2 freq      +0
    2023-08-18 21:06:35 : [INFO] - ts2phc[960151.701]: nmea sentence: GNRMC,210635.00,A,4724.40427,N,12011.28049,W,0.005,,180823,,,A,V
    capv@cp1-control-plane-9hkmf [ ~ ]$

• Message Container

  • Create a log in messaging-container:

    capv@cp1-control-plane-9hkmf [ ~ ]$ kubectl exec -it -n tca-system timing-controller-daemon-4bbpk   -c rabbitmq -- bash
    root@np-h1404-857d84dcfd-r4h8f:/#

  • Retrieve a message-container log:

    capv@cp1-control-plane-9hkmf [ ~ ]$ kubectl logs  timing-controller-daemon-4bbpk -n tca-system  -c rabbitmq --tail 100
    
    2023-08-18 20:01:04.178 [info] <0.272.0> Running boot step rabbit_sysmon_minder defined by app rabbit
    2023-08-18 20:01:04.178 [info] <0.272.0> Running boot step rabbit_epmd_monitor defined by app rabbit
    2023-08-18 20:01:04.184 [info] <0.646.0> epmd monitor knows us, inter-node communication (distribution) port: 25672
    2023-08-18 20:01:04.184 [info] <0.272.0> Running boot step guid_generator defined by app rabbit
    2023-08-18 20:01:04.185 [info] <0.272.0> Running boot step rabbit_node_monitor defined by app rabbit
    2023-08-18 20:01:04.185 [info] <0.650.0> Starting rabbit_node_monitor
    2023-08-18 20:01:04.185 [info] <0.272.0> Running boot step delegate_sup defined by app rabbit
    2023-08-18 20:01:04.185 [info] <0.272.0> Running boot step rabbit_memory_monitor defined by app rabbit
    2023-08-18 20:01:04.186 [info] <0.272.0> Running boot step core_initialized defined by app rabbit
    2023-08-18 20:01:04.186 [info] <0.272.0> Running boot step upgrade_queues defined by app rabbit
    2023-08-18 20:01:04.209 [info] <0.272.0> message_store upgrades: 1 to apply
    2023-08-18 20:01:04.209 [info] <0.272.0> message_store upgrades: Applying rabbit_variable_queue:move_messages_to_vhost_store
    2023-08-18 20:01:04.209 [info] <0.272.0> message_store upgrades: No durable queues found. Skipping message store migration
    2023-08-18 20:01:04.209 [info] <0.272.0> message_store upgrades: Removing the old message store data
    2023-08-18 20:01:04.210 [info] <0.272.0> message_store upgrades: All upgrades applied successfully
    2023-08-18 20:01:04.233 [info] <0.272.0> Running boot step channel_tracking defined by app rabbit
    2023-08-18 20:01:04.234 [info] <0.272.0> Setting up a table for channel tracking on this node: 'tracked_channel_on_node_rabbit@np-h1404-857d84dcfd-r4h8f'
    2023-08-18 20:01:04.247 [info] <0.272.0> Setting up a table for channel tracking on this node: 'tracked_channel_table_per_user_on_node_rabbit@np-h1404-857d84dcfd-r4h8f'
    2023-08-18 20:01:04.247 [info] <0.272.0> Running boot step rabbit_channel_tracking_handler defined by app rabbit
    2023-08-18 20:01:04.247 [info] <0.272.0> Running boot step connection_tracking defined by app rabbit
    2023-08-18 20:01:04.248 [info] <0.272.0> Setting up a table for connection tracking on this node: 'tracked_connection_on_node_rabbit@np-h1404-857d84dcfd-r4h8f'
    2023-08-18 20:01:04.249 [info] <0.272.0> Setting up a table for per-vhost connection counting on this node: 'tracked_connection_per_vhost_on_node_rabbit@np-h1404-857d84dcfd-r4h8f'
    2023-08-18 20:01:04.250 [info] <0.272.0> Setting up a table for per-user connection counting on this node: 'tracked_connection_table_per_user_on_node_rabbit@np-h1404-857d84dcfd-r4h8f'
    2023-08-18 20:01:04.250 [info] <0.272.0> Running boot step rabbit_connection_tracking_handler defined by app rabbit
    2023-08-18 20:01:04.250 [info] <0.272.0> Running boot step rabbit_exchange_parameters defined by app rabbit
    2023-08-18 20:01:04.250 [info] <0.272.0> Running boot step rabbit_mirror_queue_misc defined by app rabbit
    2023-08-18 20:01:04.251 [info] <0.272.0> Running boot step rabbit_policies defined by app rabbit
    2023-08-18 20:01:04.252 [info] <0.272.0> Running boot step rabbit_policy defined by app rabbit
    2023-08-18 20:01:04.252 [info] <0.272.0> Running boot step rabbit_queue_location_validator defined by app rabbit
    2023-08-18 20:01:04.252 [info] <0.272.0> Running boot step rabbit_quorum_memory_manager defined by app rabbit
    2023-08-18 20:01:04.252 [info] <0.272.0> Running boot step rabbit_vhost_limit defined by app rabbit
    2023-08-18 20:01:04.252 [info] <0.272.0> Running boot step rabbit_mgmt_reset_handler defined by app rabbitmq_management
    2023-08-18 20:01:04.252 [info] <0.272.0> Running boot step rabbit_mgmt_db_handler defined by app rabbitmq_management_agent
    2023-08-18 20:01:04.252 [info] <0.272.0> Management plugin: using rates mode 'basic'
    2023-08-18 20:01:04.252 [info] <0.272.0> Running boot step recovery defined by app rabbit
    2023-08-18 20:01:04.253 [info] <0.272.0> Running boot step empty_db_check defined by app rabbit
    2023-08-18 20:01:04.253 [info] <0.272.0> Will seed default virtual host and user...
    2023-08-18 20:01:04.253 [info] <0.272.0> Adding vhost '/' (description: 'Default virtual host')
    2023-08-18 20:01:04.257 [info] <0.709.0> Making sure data directory '/var/lib/rabbitmq/mnesia/rabbit@np-h1404-857d84dcfd-r4h8f/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L' for vhost '/' exists
    2023-08-18 20:01:04.258 [info] <0.709.0> Starting message stores for vhost '/'
    2023-08-18 20:01:04.258 [info] <0.713.0> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_transient": using rabbit_msg_store_ets_index to provide index
    2023-08-18 20:01:04.259 [info] <0.709.0> Started message store of type transient for vhost '/'
    2023-08-18 20:01:04.259 [info] <0.717.0> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent": using rabbit_msg_store_ets_index to provide index
    2023-08-18 20:01:04.260 [warning] <0.717.0> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent": rebuilding indices from scratch
    2023-08-18 20:01:04.260 [info] <0.709.0> Started message store of type persistent for vhost '/'
    2023-08-18 20:01:04.262 [info] <0.272.0> Created user 'admin'
    2023-08-18 20:01:04.262 [info] <0.272.0> Successfully set user tags for user 'admin' to [administrator]
    2023-08-18 20:01:04.263 [info] <0.272.0> Successfully set permissions for 'admin' in virtual host '/' to '.*', '.*', '.*'
    2023-08-18 20:01:04.263 [info] <0.272.0> Running boot step rabbit_looking_glass defined by app rabbit
    2023-08-18 20:01:04.263 [info] <0.272.0> Running boot step rabbit_core_metrics_gc defined by app rabbit
    2023-08-18 20:01:04.263 [info] <0.272.0> Running boot step background_gc defined by app rabbit
    2023-08-18 20:01:04.263 [info] <0.272.0> Running boot step routing_ready defined by app rabbit
    2023-08-18 20:01:04.263 [info] <0.272.0> Running boot step pre_flight defined by app rabbit
    2023-08-18 20:01:04.263 [info] <0.272.0> Running boot step notify_cluster defined by app rabbit
    2023-08-18 20:01:04.263 [info] <0.272.0> Running boot step networking defined by app rabbit
    2023-08-18 20:01:04.263 [info] <0.272.0> Running boot step definition_import_worker_pool defined by app rabbit
    2023-08-18 20:01:04.263 [info] <0.346.0> Starting worker pool 'definition_import_pool' with 32 processes in it
    2023-08-18 20:01:04.264 [info] <0.272.0> Running boot step cluster_name defined by app rabbit
    2023-08-18 20:01:04.264 [info] <0.272.0> Initialising internal cluster ID to 'rabbitmq-cluster-id-HwVkJ6ew0m44eBT-PTkTWA'
    2023-08-18 20:01:04.265 [info] <0.272.0> Running boot step direct_client defined by app rabbit
    2023-08-18 20:01:04.265 [info] <0.272.0> Running boot step rabbit_management_load_definitions defined by app rabbitmq_management
    2023-08-18 20:01:04.265 [info] <0.778.0> Resetting node maintenance status
    2023-08-18 20:01:04.265 [info] <0.44.0> Application rabbit started on node 'rabbit@np-h1404-857d84dcfd-r4h8f'
    2023-08-18 20:01:04.279 [info] <0.44.0> Application rabbitmq_management_agent started on node 'rabbit@np-h1404-857d84dcfd-r4h8f'
    2023-08-18 20:01:04.279 [info] <0.44.0> Application cowlib started on node 'rabbit@np-h1404-857d84dcfd-r4h8f'
    2023-08-18 20:01:04.280 [info] <0.44.0> Application cowboy started on node 'rabbit@np-h1404-857d84dcfd-r4h8f'
    2023-08-18 20:01:04.280 [info] <0.44.0> Application rabbitmq_web_dispatch started on node 'rabbit@np-h1404-857d84dcfd-r4h8f'
    2023-08-18 20:01:04.280 [info] <0.44.0> Application amqp_client started on node 'rabbit@np-h1404-857d84dcfd-r4h8f'
    2023-08-18 20:01:04.309 [info] <0.837.0> Management plugin: HTTP (non-TLS) listener started on port 15672
    2023-08-18 20:01:04.310 [info] <0.943.0> Statistics database started.
    2023-08-18 20:01:04.310 [info] <0.942.0> Starting worker pool 'management_worker_pool' with 3 processes in it
    2023-08-18 20:01:04.310 [info] <0.44.0> Application rabbitmq_management started on node 'rabbit@np-h1404-857d84dcfd-r4h8f'
    2023-08-18 20:01:04.334 [info] <0.44.0> Application prometheus started on node 'rabbit@np-h1404-857d84dcfd-r4h8f'
    2023-08-18 20:01:04.341 [info] <0.956.0> Prometheus metrics: HTTP (non-TLS) listener started on port 15692
    2023-08-18 20:01:04.341 [info] <0.778.0> Ready to start client connection listeners
    2023-08-18 20:01:04.341 [info] <0.44.0> Application rabbitmq_prometheus started on node 'rabbit@np-h1404-857d84dcfd-r4h8f'
    2023-08-18 20:01:04.343 [info] <0.1075.0> started TCP listener on [::]:5672
     completed with 4 plugins.
    2023-08-18 20:01:04.482 [info] <0.778.0> Server startup complete; 4 plugins started.
     * rabbitmq_prometheus
     * rabbitmq_management
     * rabbitmq_web_dispatch
     * rabbitmq_management_agent
    2023-08-18 20:01:04.482 [info] <0.778.0> Resetting node maintenance status
    2023-08-18 20:01:04.542 [info] <0.1078.0> accepting AMQP connection <0.1078.0> (100.96.2.3:59630 -> 10.208.70.111:5672)
    2023-08-18 20:01:04.544 [info] <0.1078.0> Connection <0.1078.0> (100.96.2.3:59630 -> 10.208.70.111:5672) has a client-provided name: pecan:12:cee93d46-5b72-466c-a133-410d95a204e6
    2023-08-18 20:01:04.545 [info] <0.1078.0> connection <0.1078.0> (100.96.2.3:59630 -> 10.208.70.111:5672 - pecan:12:cee93d46-5b72-466c-a133-410d95a204e6): user 'admin' authenticated and granted access to vhost '/'
    2023-08-18 20:01:06.217 [info] <0.1111.0> accepting AMQP connection <0.1111.0> (127.0.0.1:40874 -> 127.0.0.1:5672)
    2023-08-18 20:01:06.220 [info] <0.1114.0> accepting AMQP connection <0.1114.0> (127.0.0.1:40880 -> 127.0.0.1:5672)
    2023-08-18 20:01:06.220 [info] <0.1111.0> Connection <0.1111.0> (127.0.0.1:40874 -> 127.0.0.1:5672) has a client-provided name: run-ptpmonitorfunction.py:10287:5ae8d4fe-7cca-4065-bf0b-27031570b0f8
    2023-08-18 20:01:06.221 [info] <0.1114.0> Connection <0.1114.0> (127.0.0.1:40880 -> 127.0.0.1:5672) has a client-provided name: run-ptpmonitorfunction.py:10287:b9e0c5d8-33bc-414d-8eca-9bfee41217f1
    2023-08-18 20:01:06.221 [info] <0.1111.0> connection <0.1111.0> (127.0.0.1:40874 -> 127.0.0.1:5672 - run-ptpmonitorfunction.py:10287:5ae8d4fe-7cca-4065-bf0b-27031570b0f8): user 'admin' authenticated and granted access to vhost '/'
    2023-08-18 20:01:06.221 [info] <0.1114.0> connection <0.1114.0> (127.0.0.1:40880 -> 127.0.0.1:5672 - run-ptpmonitorfunction.py:10287:b9e0c5d8-33bc-414d-8eca-9bfee41217f1): user 'admin' authenticated and granted access to vhost '/'
    2023-08-18 20:01:06.230 [info] <0.1111.0> closing AMQP connection <0.1111.0> (127.0.0.1:40874 -> 127.0.0.1:5672 - run-ptpmonitorfunction.py:10287:5ae8d4fe-7cca-4065-bf0b-27031570b0f8, vhost: '/', user: 'admin')
    2023-08-18 20:01:06.230 [info] <0.1147.0> Closing all channels from connection '<<"127.0.0.1:40874 -> 127.0.0.1:5672">>' because it has been closed
    2023-08-18 20:01:06.233 [info] <0.1150.0> accepting AMQP connection <0.1150.0> (127.0.0.1:40882 -> 127.0.0.1:5672)
    2023-08-18 20:01:06.234 [info] <0.1150.0> Connection <0.1150.0> (127.0.0.1:40882 -> 127.0.0.1:5672) has a client-provided name: run-ptpmonitorfunction.py:10287:86647513-3b1d-415e-ba07-d5fa5f6ead82
    2023-08-18 20:01:06.235 [info] <0.1150.0> connection <0.1150.0> (127.0.0.1:40882 -> 127.0.0.1:5672 - run-ptpmonitorfunction.py:10287:86647513-3b1d-415e-ba07-d5fa5f6ead82): user 'admin' authenticated and granted access to vhost '/'
    2023-08-18 20:01:06.253 [info] <0.1150.0> closing AMQP connection <0.1150.0> (127.0.0.1:40882 -> 127.0.0.1:5672 - run-ptpmonitorfunction.py:10287:86647513-3b1d-415e-ba07-d5fa5f6ead82, vhost: '/', user: 'admin')
    2023-08-18 20:01:06.254 [info] <0.1171.0> Closing all channels from connection '<<"127.0.0.1:40882 -> 127.0.0.1:5672">>' because it has been closed
    capv@cp1-control-plane-9hkmf [ ~ ]$

• Monitor Container

  • Create a log in monitor-container:

    capv@cp1-control-plane-9hkmf [ ~ ]$ kubectl exec -it -n tca-system timing-controller-daemon-4bbpk   -c monitor -- bash[root@np-h1404-857d84dcfd-r4h8f opt]#

  • Retrieve a monitor-container log:

    capv@cp1-control-plane-9hkmf [ ~ ]$ kubectl logs  timing-controller-daemon-4bbpk -n tca-system  -c monitor
    
    2023-08-1820:00:57INFO     PTP notifications : DaemonsetController : initialized2023-08-1820:00:57INFO     PTP notifications : PtpNotifier : initialized2023-08-1820:00:57INFO     PTP Notifications: Holdover Period: 120.02023-08-1820:00:57INFO     PTP Notifications: Poll Frequency: 1.02023-08-1820:00:57INFO     PTP notifications : DaemonsetController : setup2023-08-1820:00:57INFO     PTP notifications : NotificationClient : initialization2023-08-1820:00:57INFO     PTP notifications : NotificationClientBase : initialization2023-08-1820:00:57INFO     PTP notifications : NotificationClient : start_transport called.2023-08-1820:00:57INFO     PTP notifications : NotificationClientBase : setup_transport called.2023-08-1820:00:57INFO     PTP notifications : NotificationClient : start_listener called.2023-08-1820:00:57INFO     PTP notifications : PtpNotificationEndpoint : initialization2023-08-1820:00:57INFO     PTP notifications : NotificationClientBase : setup_listener called.2023-08-1820:00:57INFO     PTP notifications : NotificationClientBase : listen called.2023-08-1820:00:57INFO     PTP Clock Class:: PrevClockClass:None ClockClass:248EventTime:1692388857.187062023-08-1820:00:57INFO     PTP notifications : PtpNotifier : newPTP clock class: {"id": "56fe7ea6-7c1f-4a74-85b9-52649aaac108", "specversion": "1.0", "source": "/sync/ptp-status/clock-class", "type": "event.sync.ptp-status.ptp-clock-class-change", "time": 1692388857.18706, "data": {"version": "1.0", "values": [{"data_type": "notification", "ResourceAddress": "np-h1404-857d84dcfd-r4h8f/sync/ptp-status/clock-class", "value_type": "metric", "value": "248"}]}}2023-08-1820:00:57INFO     PTP notifications : NotificationClient : initialization2023-08-1820:00:57INFO     PTP notifications : NotificationClientBase : initialization2023-08-1820:00:57INFO     PTP notifications : NotificationClient : start_transport called.2023-08-1820:00:57INFO     PTP notifications : NotificationClientBase : setup_transport called.2023-08-1820:00:57INFO     PTP notifications : NotificationClient : send_ptp_clock_class called.2023-08-1820:00:57INFO     PTP notifications : NotificationClientBase : cast called.

PMC Commands

• GET PARENT_DATA_SET: Verify clock class, GM identity, and so on.

  root [ / ]# pmc -u -b 0 -d 24 'GET PARENT_DATA_SET' -f /timing-service-config/ptp4l_nic1.conf
  sending: GET PARENT_DATA_SET
      000c29.fffe.208cbf-0 seq 0 RESPONSE MANAGEMENT PARENT_DATA_SET
          parentPortIdentity                    000c29.fffe.208cbf-0
          parentStats                           0
          observedParentOffsetScaledLogVariance 0xffff
          observedParentClockPhaseChangeRate    0x7fffffff
          grandmasterPriority1                  128
          gm.ClockClass                         6
          gm.ClockAccuracy                      0x21
          gm.OffsetScaledLogVariance            0x4e5d
          grandmasterPriority2                  128
          grandmasterIdentity                   000c29.fffe.208cbf

• GET PORT_DATA_SET: Verify that all the ports are listed and port state is correct.

  root [ / ]# pmc -u -b 0 -d 24 'GET PORT_DATA_SET' -f /timing-service-config/ptp4l_nic1.conf
  sending: GET PORT_DATA_SET
      000c29.fffe.208cbf-1 seq 0 RESPONSE MANAGEMENT PORT_DATA_SET
          portIdentity            000c29.fffe.208cbf-1
          portState               MASTER
          logMinDelayReqInterval  -4
          peerMeanPathDelay       0
          logAnnounceInterval     -3
          announceReceiptTimeout  3
          logSyncInterval         -4
          delayMechanism          1
          logMinPdelayReqInterval 0
          versionNumber           2
      000c29.fffe.208cbf-2 seq 0 RESPONSE MANAGEMENT PORT_DATA_SET
          portIdentity            000c29.fffe.208cbf-2
          portState               MASTER
          logMinDelayReqInterval  -4
          peerMeanPathDelay       0
          logAnnounceInterval     -3
          announceReceiptTimeout  3
          logSyncInterval         -4
          delayMechanism          1
          logMinPdelayReqInterval 0
          versionNumber           2

• GET TIME_PROPERTIES_DATA_SET: Verify the ptpTimescale, timeTracable, and frequencyTracable flags.

  root [ / ]# pmc -u -b 0 -d 24 'GET TIME_PROPERTIES_DATA_SET' -f /timing-service-config/ptp4l_nic1.conf
  sending: GET TIME_PROPERTIES_DATA_SET
      000c29.fffe.208cbf-0 seq 0 RESPONSE MANAGEMENT TIME_PROPERTIES_DATA_SET
          currentUtcOffset      37
          leap61                0
          leap59                0
          currentUtcOffsetValid 0
          ptpTimescale          1
          timeTraceable         1
          frequencyTraceable    1
          timeSource            0x20

• GET TIME_STATUS_NP: Verify that the output shows gmpresent:true and also lists gmIdentity.

  root [ / ]# pmc -u -b 0 -d 24 'GET TIME_STATUS_NP' -f /timing-service-config/ptp4l_nic1.conf
  sending: GET TIME_STATUS_NP
      000c29.fffe.208cbf-0 seq 0 RESPONSE MANAGEMENT TIME_STATUS_NP
          master_offset              0
          ingress_time               0
          cumulativeScaledRateOffset +0.000000000
          scaledLastGmPhaseChange    0
          gmTimeBaseIndicator        0
          lastGmPhaseChange          0x0000'0000000000000000.0000
          gmPresent                  false
          gmIdentity                 000c29.fffe.208cbf