starlingx/ptp-notification-armada-app
Code Issues Proposed changes

[PTP] Fix duplicate notifications and correct GNSS state tracking

Browse Source 
Issue 1: Duplicate notifications were being delivered to clients when
subscribed to multiple services.

The implementation of multiple instance support revealed an issue where
there was no check present to only deliver notifications for matching
subscriptions, so a node subscribed to multiple services (ie. ptp lock
state and gnss lock state) would receive a copy of each individual
notification for each subscription present. The prior model assumed that
only a single subscription would exist for each node.

Fix: Added a check when building the list of subscribers to only deliver
on subscriptions that match the notification resource address.

Issue 2: GNSS reports locked when ts2phc is not running

Fix: Implemented a check to report a state change is ts2phc is not
running as this means that the NIC PHC will not be in sync.

This also includes an update to the state names for GNSS from
Locked/Holdover/Freerun to Synchronized and other additional states as
specified in the O-RAN Notification standard.

Test plan:
PASS: Build and deploy ptp-notification application
PASS: Duplicate notifications are not sent when multiple subscriptions
are present
PASS: v1 subscriptions unaffected
PASS: GNSS reports nofix when ts2phc is stopped

Story: 2010056
Task: 46423

Signed-off-by: Cole Walker <cole.walker@windriver.com>
Change-Id: Ie6735f80fd311f7ec5c593c76c917d31675c2dbd
This commit is contained in:
Cole Walker 2022-09-26 15:42:40 -04:00
parent f63dd6dc17
commit 34c945ed39
4 changed files with 187 additions and 173 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

304
notificationclient-base/docker/notificationclient-sidecar/notificationclientsdk/services/notification_handler.py
View File

@ -1,147 +1,157 @@
# #
# Copyright (c) 2021-2022 Wind River Systems, Inc. # Copyright (c) 2021-2022 Wind River Systems, Inc.
# #
# SPDX-License-Identifier: Apache-2.0 # SPDX-License-Identifier: Apache-2.0
# #
import json import json
import logging import logging
import multiprocessing as mp import multiprocessing as mp
import threading import threading
import time import time
from datetime import datetime, timezone from datetime import datetime, timezone
from notificationclientsdk.model.dto.subscription import SubscriptionInfoV1 from notificationclientsdk.model.dto.subscription import SubscriptionInfoV1
from notificationclientsdk.model.dto.subscription import SubscriptionInfoV2 from notificationclientsdk.model.dto.subscription import SubscriptionInfoV2
from notificationclientsdk.model.dto.resourcetype import ResourceType from notificationclientsdk.model.dto.resourcetype import ResourceType
from notificationclientsdk.repository.subscription_repo import SubscriptionRepo from notificationclientsdk.repository.subscription_repo import SubscriptionRepo
from notificationclientsdk.common.helpers import subscription_helper from notificationclientsdk.common.helpers import subscription_helper
from notificationclientsdk.common.helpers.nodeinfo_helper import NodeInfoHelper from notificationclientsdk.common.helpers.nodeinfo_helper import NodeInfoHelper
from notificationclientsdk.client.notificationservice import NotificationHandlerBase from notificationclientsdk.client.notificationservice import NotificationHandlerBase
LOG = logging.getLogger(__name__) LOG = logging.getLogger(__name__)
from notificationclientsdk.common.helpers import log_helper from notificationclientsdk.common.helpers import log_helper
log_helper.config_logger(LOG) log_helper.config_logger(LOG)
class NotificationHandler(NotificationHandlerBase): class NotificationHandler(NotificationHandlerBase):
def __init__(self): def __init__(self):
self.__supported_resource_types = (ResourceType.TypePTP,) self.__supported_resource_types = (ResourceType.TypePTP,)
self.__init_notification_channel() self.__init_notification_channel()
pass pass
def __init_notification_channel(self): def __init_notification_channel(self):
self.notification_lock = threading.Lock() self.notification_lock = threading.Lock()
self.notification_stat = {} self.notification_stat = {}
# def handle_notification_delivery(self, notification_info): # def handle_notification_delivery(self, notification_info):
def handle(self, notification_info): def handle(self, notification_info):
LOG.debug("start notification delivery") LOG.debug("start notification delivery")
subscription_repo = None subscription_repo = None
try: resource_address = None
self.notification_lock.acquire() try:
subscription_repo = SubscriptionRepo(autocommit=True) self.notification_lock.acquire()
resource_type = notification_info.get('ResourceType', None) subscription_repo = SubscriptionRepo(autocommit=True)
# Get nodename from resource address resource_type = notification_info.get('ResourceType', None)
if resource_type: # Get nodename from resource address
node_name = notification_info.get('ResourceQualifier', {}).get('NodeName', None) if resource_type:
if not resource_type: node_name = notification_info.get('ResourceQualifier', {}).get('NodeName', None)
raise Exception("abnormal notification@{0}".format(node_name)) if not resource_type:
if not resource_type in self.__supported_resource_types: raise Exception("abnormal notification@{0}".format(node_name))
raise Exception( if not resource_type in self.__supported_resource_types:
"notification with unsupported resource type:{0}".format(resource_type)) raise Exception(
this_delivery_time = notification_info['EventTimestamp'] "notification with unsupported resource type:{0}".format(resource_type))
else: this_delivery_time = notification_info['EventTimestamp']
parent_key = list(notification_info.keys())[0] # Get subscriptions from DB to deliver notification to
source = notification_info[parent_key].get('source', None) entries = subscription_repo.get(Status=1, ResourceType=resource_type)
values = notification_info[parent_key].get('data', {}).get('values', []) else:
resource_address = values[0].get('ResourceAddress', None) parent_key = list(notification_info.keys())[0]
this_delivery_time = notification_info[parent_key].get('time') source = notification_info[parent_key].get('source', None)
if not resource_address: values = notification_info[parent_key].get('data', {}).get('values', [])
raise Exception("No resource address in notification source".format(source)) resource_address = values[0].get('ResourceAddress', None)
_, node_name, _, _, _ = subscription_helper.parse_resource_address(resource_address) this_delivery_time = notification_info[parent_key].get('time')
if not resource_address:
entries = subscription_repo.get(Status=1) raise Exception("No resource address in notification source".format(source))
for entry in entries: _, node_name, _, _, _ = subscription_helper.parse_resource_address(resource_address)
subscriptionid = entry.SubscriptionId # Get subscriptions from DB to deliver notification to.
if entry.ResourceAddress: # Unable to filter on resource_address here because resource_address may contain
_, entry_node_name, _, _, _ = subscription_helper.parse_resource_address( # either an unknown node name (ie. controller-0) or a '/./' resulting in entries
entry.ResourceAddress) # being missed. Instead, filter these v2 subscriptions in the for loop below once
subscription_dto2 = SubscriptionInfoV2(entry) # the resource path has been obtained.
else: entries = subscription_repo.get(Status=1)
ResourceQualifierJson = entry.ResourceQualifierJson or '{}'
ResourceQualifier = json.loads(ResourceQualifierJson) for entry in entries:
# qualify by NodeName subscriptionid = entry.SubscriptionId
entry_node_name = ResourceQualifier.get('NodeName', None) if entry.ResourceAddress:
subscription_dto2 = SubscriptionInfoV1(entry) _, entry_node_name, entry_resource_path, _, _ = \
node_name_matched = NodeInfoHelper.match_node_name(entry_node_name, node_name) subscription_helper.parse_resource_address(entry.ResourceAddress)
if not node_name_matched: if entry_resource_path not in resource_address:
continue continue
subscription_dto2 = SubscriptionInfoV2(entry)
try: else:
last_delivery_time = self.__get_latest_delivery_timestamp(node_name, ResourceQualifierJson = entry.ResourceQualifierJson or '{}'
subscriptionid) ResourceQualifier = json.loads(ResourceQualifierJson)
if last_delivery_time and last_delivery_time >= this_delivery_time: # qualify by NodeName
# skip this entry since already delivered entry_node_name = ResourceQualifier.get('NodeName', None)
LOG.debug("Ignore the outdated notification for: {0}".format( subscription_dto2 = SubscriptionInfoV1(entry)
entry.SubscriptionId)) node_name_matched = NodeInfoHelper.match_node_name(entry_node_name, node_name)
continue if not node_name_matched:
continue
subscription_helper.notify(subscription_dto2, notification_info)
LOG.debug("notification is delivered successfully to {0}".format( try:
entry.SubscriptionId)) last_delivery_time = self.__get_latest_delivery_timestamp(node_name,
subscriptionid)
self.update_delivery_timestamp(node_name, subscriptionid, this_delivery_time) if last_delivery_time and last_delivery_time >= this_delivery_time:
# skip this entry since already delivered
except Exception as ex: LOG.debug("Ignore the outdated notification for: {0}".format(
LOG.warning("notification is not delivered to {0}:{1}".format( entry.SubscriptionId))
entry.SubscriptionId, str(ex))) continue
# proceed to next entry
continue subscription_helper.notify(subscription_dto2, notification_info)
finally: LOG.debug("notification is delivered successfully to {0}".format(
pass entry.SubscriptionId))
LOG.debug("Finished notification delivery")
return True self.update_delivery_timestamp(node_name, subscriptionid, this_delivery_time)
except Exception as ex:
LOG.warning("Failed to delivery notification:{0}".format(str(ex))) except Exception as ex:
return False LOG.warning("notification is not delivered to {0}:{1}".format(
finally: entry.SubscriptionId, str(ex)))
self.notification_lock.release() # proceed to next entry
if not subscription_repo: continue
del subscription_repo finally:
pass
def __get_latest_delivery_timestamp(self, node_name, subscriptionid): LOG.debug("Finished notification delivery")
last_delivery_stat = self.notification_stat.get(node_name, {}).get(subscriptionid, {}) return True
last_delivery_time = last_delivery_stat.get('EventTimestamp', None) except Exception as ex:
return last_delivery_time LOG.warning("Failed to delivery notification:{0}".format(str(ex)))
return False
def update_delivery_timestamp(self, node_name, subscriptionid, this_delivery_time): finally:
if not self.notification_stat.get(node_name, None): self.notification_lock.release()
self.notification_stat[node_name] = { if not subscription_repo:
subscriptionid: { del subscription_repo
'EventTimestamp': this_delivery_time
} def __get_latest_delivery_timestamp(self, node_name, subscriptionid):
} last_delivery_stat = self.notification_stat.get(node_name, {}).get(subscriptionid, {})
LOG.debug("delivery time @node: {0},subscription:{1} is added".format( last_delivery_time = last_delivery_stat.get('EventTimestamp', None)
node_name, subscriptionid)) return last_delivery_time
elif not self.notification_stat[node_name].get(subscriptionid, None):
self.notification_stat[node_name][subscriptionid] = { def update_delivery_timestamp(self, node_name, subscriptionid, this_delivery_time):
'EventTimestamp': this_delivery_time if not self.notification_stat.get(node_name, None):
} self.notification_stat[node_name] = {
LOG.debug("delivery time @node: {0},subscription:{1} is added".format( subscriptionid: {
node_name, subscriptionid)) 'EventTimestamp': this_delivery_time
else: }
last_delivery_stat = self.notification_stat.get(node_name, {}).get(subscriptionid, {}) }
last_delivery_time = last_delivery_stat.get('EventTimestamp', None) LOG.debug("delivery time @node: {0},subscription:{1} is added".format(
if (last_delivery_time and last_delivery_time >= this_delivery_time): node_name, subscriptionid))
return elif not self.notification_stat[node_name].get(subscriptionid, None):
last_delivery_stat['EventTimestamp'] = this_delivery_time self.notification_stat[node_name][subscriptionid] = {
LOG.debug("delivery time @node: {0},subscription:{1} is updated".format( 'EventTimestamp': this_delivery_time
node_name, subscriptionid)) }
LOG.debug("delivery time @node: {0},subscription:{1} is added".format(
node_name, subscriptionid))
else:
last_delivery_stat = self.notification_stat.get(node_name, {}).get(subscriptionid, {})
last_delivery_time = last_delivery_stat.get('EventTimestamp', None)
if (last_delivery_time and last_delivery_time >= this_delivery_time):
return
last_delivery_stat['EventTimestamp'] = this_delivery_time
LOG.debug("delivery time @node: {0},subscription:{1} is updated".format(
node_name, subscriptionid))

25
notificationservice-base/docker/ptptrackingfunction/trackingfunctionsdk/common/helpers/gnss_monitor.py
View File

@ -5,6 +5,7 @@
# #
import logging import logging
import datetime import datetime
import os.path
import re import re
from abc import ABC, abstractmethod from abc import ABC, abstractmethod
@ -71,6 +72,13 @@ class GnssMonitor(Observer):
self.set_gnss_status() self.set_gnss_status()
def set_gnss_status(self): def set_gnss_status(self):
# Check that ts2phc is running, else Freerun
if not os.path.isfile('/var/run/ts2phc-%s.pid' % self.ts2phc_service_name):
LOG.warning("TS2PHC instance %s is not running, reporting GNSS unlocked."
% self.ts2phc_service_name)
self._state = GnssState.Failure_Nofix
return
self.gnss_cgu_handler.read_cgu() self.gnss_cgu_handler.read_cgu()
self.gnss_cgu_handler.cgu_output_to_dict() self.gnss_cgu_handler.cgu_output_to_dict()
self.gnss_eec_state = self.gnss_eec_state = \ self.gnss_eec_state = self.gnss_eec_state = \
@ -79,9 +87,9 @@ class GnssMonitor(Observer):
LOG.debug("GNSS EEC Status is: %s" % self.gnss_eec_state) LOG.debug("GNSS EEC Status is: %s" % self.gnss_eec_state)
LOG.debug("GNSS PPS Status is: %s" % self.gnss_pps_state) LOG.debug("GNSS PPS Status is: %s" % self.gnss_pps_state)
if self.gnss_pps_state == 'locked_ho_ack' and self.gnss_eec_state == 'locked_ho_ack': if self.gnss_pps_state == 'locked_ho_ack' and self.gnss_eec_state == 'locked_ho_ack':
self._state = GnssState.Locked self._state = GnssState.Synchronized
else: else:
self._state = GnssState.Freerun self._state = GnssState.Failure_Nofix
LOG.debug("Set state GNSS to %s" % self._state) LOG.debug("Set state GNSS to %s" % self._state)
@ -93,18 +101,7 @@ class GnssMonitor(Observer):
self.set_gnss_status() self.set_gnss_status()
if self._state == constants.FREERUN_PHC_STATE: # determine if GNSS state has changed since the last check
if previous_sync_state in [constants.UNKNOWN_PHC_STATE, constants.FREERUN_PHC_STATE]:
self._state = constants.FREERUN_PHC_STATE
elif previous_sync_state == constants.LOCKED_PHC_STATE:
self._state = constants.HOLDOVER_PHC_STATE
elif previous_sync_state == constants.HOLDOVER_PHC_STATE and \
time_in_holdover < max_holdover_time:
self._state = constants.HOLDOVER_PHC_STATE
else:
self._state = constants.FREERUN_PHC_STATE
# determine if os clock sync state has changed since the last check
if self._state != previous_sync_state: if self._state != previous_sync_state:
new_event = True new_event = True
event_time = datetime.datetime.utcnow().timestamp() event_time = datetime.datetime.utcnow().timestamp()

13
notificationservice-base/docker/ptptrackingfunction/trackingfunctionsdk/model/dto/gnssstate.py
View File

@ -3,7 +3,14 @@ from wsme import types as wtypes
EnumGnssState = wtypes.Enum(str, 'Locked', 'Freerun', 'Holdover') EnumGnssState = wtypes.Enum(str, 'Locked', 'Freerun', 'Holdover')
class GnssState(object): class GnssState(object):
Locked = "Locked" # Not all states are implemented on some hardware
Freerun = "Freerun" Synchronized = "SYNCHRONIZED"
Holdover = "Holdover" Acquiring_Sync = "ACQUIRING-SYNC"
Antenna_Disconnected = "ANTENNA-DISCONNECTED"
Booting = "BOOTING"
Antenna_Short_Circuit = "ANTENNA-SHORT-CIRCUIT"
Failure_Multipath = "FAULURE-MULTIPATH"
Failure_Nofix = "FAILURE-NOFIX"
Failure_Low_SNR = "FAILURE-LOW-SNR"
Failure_PLL = "FAILURE-PLL"

18
notificationservice-base/docker/ptptrackingfunction/trackingfunctionsdk/services/daemon.py
View File

@ -119,7 +119,7 @@ class PtpWatcherDefault:
self.watcher.gnsstracker_context_lock.acquire() self.watcher.gnsstracker_context_lock.acquire()
if optional: if optional:
sync_state = self.watcher.gnsstracker_context[optional]. \ sync_state = self.watcher.gnsstracker_context[optional]. \
get('sync_state', GnssState.Freerun) get('sync_state', GnssState.Failure_Nofix)
last_event_time = self.watcher.gnsstracker_context[optional].get( last_event_time = self.watcher.gnsstracker_context[optional].get(
'last_event_time', 'last_event_time',
time.time()) time.time())
@ -130,7 +130,7 @@ class PtpWatcherDefault:
else: else:
for config in self.daemon_context['GNSS_INSTANCES']: for config in self.daemon_context['GNSS_INSTANCES']:
sync_state = self.watcher.gnsstracker_context[config] \ sync_state = self.watcher.gnsstracker_context[config] \
.get('sync_state', GnssState.Freerun) .get('sync_state', GnssState.Failure_Nofix)
last_event_time = self.watcher.gnsstracker_context[config].get( last_event_time = self.watcher.gnsstracker_context[config].get(
'last_event_time', 'last_event_time',
time.time()) time.time())
@ -272,7 +272,7 @@ class PtpWatcherDefault:
self.gnsstracker_context = {} self.gnsstracker_context = {}
for config in self.daemon_context['GNSS_INSTANCES']: for config in self.daemon_context['GNSS_INSTANCES']:
self.gnsstracker_context[config] = PtpWatcherDefault.DEFAULT_GNSSTRACKER_CONTEXT.copy() self.gnsstracker_context[config] = PtpWatcherDefault.DEFAULT_GNSSTRACKER_CONTEXT.copy()
self.gnsstracker_context[config]['sync_state'] = GnssState.Freerun self.gnsstracker_context[config]['sync_state'] = GnssState.Failure_Nofix
self.gnsstracker_context[config]['last_event_time'] = self.init_time self.gnsstracker_context[config]['last_event_time'] = self.init_time
self.gnsstracker_context_lock = threading.Lock() self.gnsstracker_context_lock = threading.Lock()
LOG.debug("gnsstracker_context: %s" % self.gnsstracker_context) LOG.debug("gnsstracker_context: %s" % self.gnsstracker_context)
@ -406,10 +406,10 @@ class PtpWatcherDefault:
LOG.debug("Getting overall sync state.") LOG.debug("Getting overall sync state.")
for gnss in self.observer_list: for gnss in self.observer_list:
if gnss._state == GnssState.Holdover or gnss._state == GnssState.Freerun: if gnss._state == constants.UNKNOWN_PHC_STATE or gnss._state == GnssState.Failure_Nofix:
gnss_state = GnssState.Freerun gnss_state = GnssState.Failure_Nofix
elif gnss._state == GnssState.Locked and gnss_state != GnssState.Freerun: elif gnss._state == GnssState.Synchronized and gnss_state != GnssState.Failure_Nofix:
gnss_state = GnssState.Locked gnss_state = GnssState.Synchronized
for ptp4l in self.ptp_monitor_list: for ptp4l in self.ptp_monitor_list:
_, read_state, _ = ptp4l.get_ptp_sync_state() _, read_state, _ = ptp4l.get_ptp_sync_state()
@ -421,8 +421,8 @@ class PtpWatcherDefault:
os_clock_state = self.os_clock_monitor.get_os_clock_state() os_clock_state = self.os_clock_monitor.get_os_clock_state()
if gnss_state is GnssState.Freerun or os_clock_state is OsClockState.Freerun or ptp_state \ if gnss_state is GnssState.Failure_Nofix or os_clock_state is OsClockState.Freerun or \
is PtpState.Freerun: ptp_state is PtpState.Freerun:
sync_state = OverallClockState.Freerun sync_state = OverallClockState.Freerun
else: else:
sync_state = OverallClockState.Locked sync_state = OverallClockState.Locked