Skip to content

Commit

Permalink
Hook server with IM EventManagment and adjust EventManagment
Browse files Browse the repository at this point in the history
  • Loading branch information
yunhanw-google committed Dec 7, 2021
1 parent 89eecc6 commit 114e03c
Show file tree
Hide file tree
Showing 22 changed files with 170 additions and 89 deletions.
16 changes: 16 additions & 0 deletions examples/all-clusters-app/all-clusters-common/all-clusters-app.zap
Original file line number Diff line number Diff line change
Expand Up @@ -15442,6 +15442,14 @@
"incoming": 1,
"outgoing": 0
},
{
"name": "TestEmitTestEventRequest",
"code": 20,
"mfgCode": null,
"source": "client",
"incoming": 1,
"outgoing": 0
},
{
"name": "TestSimpleOptionalArgumentRequest",
"code": 19,
Expand Down Expand Up @@ -15524,6 +15532,14 @@
"source": "server",
"incoming": 0,
"outgoing": 1
},
{
"name": "TestEmitTestEventResponse",
"code": 10,
"mfgCode": null,
"source": "server",
"incoming": 0,
"outgoing": 1
}
],
"attributes": [
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -132,13 +132,6 @@
*/
#define CHIP_CONFIG_EVENT_LOGGING_WDM_OFFLOAD 1

/**
* CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE
*
* A size, in bytes, of the individual debug event logging buffer.
*/
#define CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE (512)

/**
* CHIP_DEVICE_CONFIG_BLE_FAST_ADVERTISING_TIMEOUT
*
Expand Down
7 changes: 0 additions & 7 deletions examples/lock-app/nxp/k32w/k32w0/include/CHIPProjectConfig.h
Original file line number Diff line number Diff line change
Expand Up @@ -132,13 +132,6 @@
*/
#define CHIP_CONFIG_EVENT_LOGGING_WDM_OFFLOAD 1

/**
* CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE
*
* A size, in bytes, of the individual debug event logging buffer.
*/
#define CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE (512)

/**
* CHIP_DEVICE_CONFIG_BLE_FAST_ADVERTISING_TIMEOUT
*
Expand Down
6 changes: 3 additions & 3 deletions examples/shell/nxp/k32w/k32w0/include/CHIPProjectConfig.h
Original file line number Diff line number Diff line change
Expand Up @@ -133,11 +133,11 @@
#define CHIP_CONFIG_EVENT_LOGGING_WDM_OFFLOAD 1

/**
* CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE
* @def CHIP_CONFIG_ENABLE_SERVER_IM_EVENT
*
* A size, in bytes, of the individual debug event logging buffer.
* @brief Enable Interaction model Event support in server
*/
#define CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE (512)
#define CHIP_CONFIG_ENABLE_SERVER_IM_EVENT 0

/**
* CHIP_DEVICE_CONFIG_BLE_FAST_ADVERTISING_TIMEOUT
Expand Down
36 changes: 31 additions & 5 deletions src/app/EventLogging.h
Original file line number Diff line number Diff line change
Expand Up @@ -20,31 +20,57 @@

#include <app/ConcreteEventPath.h>
#include <app/EventLoggingDelegate.h>
#include <app/EventManagement.h>
#include <app/data-model/Encode.h>
#include <app/data-model/List.h> // So we can encode lists

namespace chip {
namespace app {

template <typename T>
class EventLogger : EventLoggingDelegate
class EventLogger : public EventLoggingDelegate
{
public:
EventLogger(const T & aEventData) : mEventData(aEventData){};
CHIP_ERROR WriteEvent(chip::TLV::TLVWriter & aWriter) final override { return mEventData.Encode(aWriter, TLV::AnonymousTag); }
CHIP_ERROR WriteEvent(chip::TLV::TLVWriter & aWriter) final override
{
return DataModel::Encode(aWriter, TLV::ContextTag(to_underlying(EventDataIB::Tag::kData)), mEventData);
}

private:
const T & mEventData;
};

/**
* @brief
* Log an event via a EventLoggingDelegate, with options.
*
* The EventLoggingDelegate writes the event metadata and calls the `apDelegate`
* with an TLV::TLVWriter reference so that the user code can emit
* the event data directly into the event log. This form of event
* logging minimizes memory consumption, as event data is serialized
* directly into the target buffer. The event data MUST contain
* context tags to be interpreted within the schema identified by
* `ClusterID` and `EventId`.
*
* @param[in] apDelegate The EventLoggingDelegate to serialize the event data
*
* @param[in] aEventOptions The options for the event metadata.
*
* @param[out] aEventNumber The event Number if the event was written to the
* log, 0 otherwise. The Event number is expected to monotonically increase.
*
* @return CHIP_ERROR CHIP Error Code
*/
template <typename T>
CHIP_ERROR LogEvent(const T & aEventData, EndpointId aEndpoint, EventOptions aEventOptions, EventNumber & aEventNumber)
{
EventLogger<T> eventData(aEventData);
ConcreteEventPath path(aEndpoint, aEventData.GetClusterId(), aEventData.GetEventId());
// log the actual event
aEventNumber = 0;
return CHIP_NO_ERROR;
EventManagement & logMgmt = chip::app::EventManagement::GetInstance();
aEventOptions.mPath = path;
aEventOptions.mPriority = aEventData.GetPriorityLevel();
return logMgmt.LogEvent(&eventData, aEventOptions, aEventNumber);
}

} // namespace app
Expand Down
21 changes: 6 additions & 15 deletions src/app/EventManagement.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -309,9 +309,7 @@ CHIP_ERROR EventManagement::CalculateEventSize(EventLoggingDelegate * apDelegate
CHIP_ERROR EventManagement::ConstructEvent(EventLoadOutContext * apContext, EventLoggingDelegate * apDelegate,
const EventOptions * apOptions)
{
TLV::TLVType dataContainerType;
uint64_t deltatime = 0;

VerifyOrReturnError(apContext->mCurrentEventNumber >= apContext->mStartingEventNumber, CHIP_NO_ERROR
/* no-op: don't write event, but advance current event Number */);

Expand Down Expand Up @@ -347,11 +345,8 @@ CHIP_ERROR EventManagement::ConstructEvent(EventLoadOutContext * apContext, Even

ReturnErrorOnFailure(eventDataIBBuilder.GetError());

ReturnErrorOnFailure(apContext->mWriter.StartContainer(ContextTag(chip::to_underlying(EventDataIB::Tag::kData)),
TLV::kTLVType_Structure, dataContainerType));
// Callback to write the EventData
ReturnErrorOnFailure(apDelegate->WriteEvent(apContext->mWriter));
ReturnErrorOnFailure(apContext->mWriter.EndContainer(dataContainerType));
eventDataIBBuilder.EndOfEventDataIB();
ReturnErrorOnFailure(eventDataIBBuilder.GetError());
eventReportBuilder.EndOfEventReportIB();
Expand Down Expand Up @@ -512,16 +507,13 @@ CHIP_ERROR EventManagement::LogEventPrivate(EventLoggingDelegate * apDelegate, E
opts = EventOptions(timestamp);
// Start the event container (anonymous structure) in the circular buffer
writer.Init(*mpEventBuffer);

// check whether the entry is to be logged or discarded silently
VerifyOrExit(aEventOptions.mPriority >= CHIP_CONFIG_EVENT_GLOBAL_PRIORITY, /* no-op */);

opts.mPriority = aEventOptions.mPriority;
// Create all event specific data
// Timestamp; encoded as a delta time

opts.mTimestamp = aEventOptions.mTimestamp;

if (GetPriorityBuffer(aEventOptions.mPriority)->GetFirstEventTimestamp() == 0)
{
GetPriorityBuffer(aEventOptions.mPriority)->UpdateFirstLastEventTime(opts.mTimestamp);
Expand Down Expand Up @@ -576,17 +568,16 @@ CHIP_ERROR EventManagement::LogEventPrivate(EventLoggingDelegate * apDelegate, E

#if CHIP_CONFIG_EVENT_LOGGING_VERBOSE_DEBUG_LOGS
ChipLogDetail(EventLogging,
"LogEvent event number: 0x" ChipLogFormatX64 " schema priority: %u cluster id: " ChipLogFormatMEI
" event id: 0x%" PRIx32 " %s timestamp: 0x" ChipLogFormatX64,
ChipLogValueX64(aEventNumber), static_cast<unsigned>(opts.mPriority), ChipLogValueMEI(opts.mPath.mClusterId),
opts.mPath.mEventId, opts.mTimestamp.mType == Timestamp::Type::kSystem ? "Sys" : "Epoch",
ChipLogValueX64(opts.mTimestamp.mValue));
"LogEvent event number: 0x" ChipLogFormatX64 " schema priority: %u, endpoint id: 0x%" PRIx16
" cluster id: " ChipLogFormatMEI " event id: 0x%" PRIx32 " %s timestamp: 0x" ChipLogFormatX64,
ChipLogValueX64(aEventNumber), static_cast<unsigned>(opts.mPriority), opts.mPath.mEndpointId,
ChipLogValueMEI(opts.mPath.mClusterId), opts.mPath.mEventId,
opts.mTimestamp.mType == Timestamp::Type::kSystem ? "Sys" : "Epoch", ChipLogValueX64(opts.mTimestamp.mValue));
#endif // CHIP_CONFIG_EVENT_LOGGING_VERBOSE_DEBUG_LOGS

if (opts.mUrgent == EventOptions::Type::kUrgent)
{
ConcreteEventPath path(opts.mPath.mEndpointId, opts.mPath.mClusterId, opts.mPath.mEventId);
err = InteractionModelEngine::GetInstance()->GetReportingEngine().ScheduleUrgentEventDelivery(path);
err = InteractionModelEngine::GetInstance()->GetReportingEngine().ScheduleUrgentEventDelivery(opts.mPath);
}
}

Expand Down
6 changes: 5 additions & 1 deletion src/app/clusters/test-cluster-server/test-cluster-server.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -449,10 +449,14 @@ bool emberAfTestClusterClusterTestEmitTestEventRequestCallback(
const Commands::TestEmitTestEventRequest::DecodableType & commandData)
{
Commands::TestEmitTestEventResponse::Type responseData;
Structs::SimpleStruct::Type arg4;
DataModel::List<const Structs::SimpleStruct::Type> arg5;
DataModel::List<const SimpleEnum> arg6;
EventOptions eventOptions;
Events::TestEvent::Type event{ commandData.arg1, commandData.arg2, commandData.arg3, commandData.arg4, arg5, arg6 };

// TODO: Add code to pull arg4, arg5 and arg6 from the arguments of the command
Events::TestEvent::Type event{ commandData.arg1, commandData.arg2, commandData.arg3, arg4, arg5, arg6 };

if (CHIP_NO_ERROR != LogEvent(event, commandPath.mEndpointId, eventOptions, responseData.value))
{
emberAfSendImmediateDefaultResponse(EMBER_ZCL_STATUS_FAILURE);
Expand Down
18 changes: 11 additions & 7 deletions src/app/server/Server.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -71,15 +71,16 @@ namespace chip {

Server Server::sServer;

#if CHIP_CONFIG_ENABLE_SERVER_IM_EVENT
#define CHIP_NUM_EVENT_LOGGING_BUFFERS 3
static uint8_t sCritEventBuffer[CHIP_DEVICE_CONFIG_EVENT_LOGGING_CRIT_BUFFER_SIZE];
static uint8_t sInfoEventBuffer[CHIP_DEVICE_CONFIG_EVENT_LOGGING_INFO_BUFFER_SIZE];
static uint8_t sDebugEventBuffer[CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE];
static uint8_t sCritEventBuffer[CHIP_DEVICE_CONFIG_EVENT_LOGGING_CRIT_BUFFER_SIZE];
static ::chip::PersistedCounter sCritEventIdCounter;
static ::chip::PersistedCounter sInfoEventIdCounter;
static ::chip::PersistedCounter sDebugEventIdCounter;

static ::chip::app::CircularEventBuffer sLoggingBuffer[CHIP_NUM_EVENT_LOGGING_BUFFERS];
#endif // CHIP_CONFIG_ENABLE_SERVER_IM_EVENT

CHIP_ERROR Server::Init(AppDelegate * delegate, uint16_t secureServicePort, uint16_t unsecureServicePort)
{
Expand Down Expand Up @@ -149,24 +150,27 @@ CHIP_ERROR Server::Init(AppDelegate * delegate, uint16_t secureServicePort, uint
err = chip::app::InteractionModelEngine::GetInstance()->Init(&mExchangeMgr, nullptr);
SuccessOrExit(err);

#if CHIP_CONFIG_ENABLE_SERVER_IM_EVENT
// Initialize event logging subsystem
{
::chip::Platform::PersistedStorage::Key debugEventIdCounterStorageKey = CHIP_DEVICE_CONFIG_PERSISTED_STORAGE_DEBUG_EIDC_KEY;
::chip::Platform::PersistedStorage::Key critEventIdCounterStorageKey = CHIP_DEVICE_CONFIG_PERSISTED_STORAGE_CRIT_EIDC_KEY;
::chip::Platform::PersistedStorage::Key infoEventIdCounterStorageKey = CHIP_DEVICE_CONFIG_PERSISTED_STORAGE_INFO_EIDC_KEY;
::chip::Platform::PersistedStorage::Key debugEventIdCounterStorageKey = CHIP_DEVICE_CONFIG_PERSISTED_STORAGE_DEBUG_EIDC_KEY;

::chip::app::LogStorageResources logStorageResources[] = {
{ &sCritEventBuffer[0], sizeof(sCritEventBuffer), &critEventIdCounterStorageKey,
CHIP_DEVICE_CONFIG_EVENT_ID_COUNTER_EPOCH, &sCritEventIdCounter, ::chip::app::PriorityLevel::Critical },
{ &sDebugEventBuffer[0], sizeof(sDebugEventBuffer), &debugEventIdCounterStorageKey,
CHIP_DEVICE_CONFIG_EVENT_ID_COUNTER_EPOCH, &sDebugEventIdCounter, ::chip::app::PriorityLevel::Debug },
{ &sInfoEventBuffer[0], sizeof(sInfoEventBuffer), &infoEventIdCounterStorageKey,
CHIP_DEVICE_CONFIG_EVENT_ID_COUNTER_EPOCH, &sInfoEventIdCounter, ::chip::app::PriorityLevel::Info },
{ &sDebugEventBuffer[0], sizeof(sDebugEventBuffer), &debugEventIdCounterStorageKey,
CHIP_DEVICE_CONFIG_EVENT_ID_COUNTER_EPOCH, &sDebugEventIdCounter, ::chip::app::PriorityLevel::Debug }
{ &sCritEventBuffer[0], sizeof(sCritEventBuffer), &critEventIdCounterStorageKey,
CHIP_DEVICE_CONFIG_EVENT_ID_COUNTER_EPOCH, &sCritEventIdCounter, ::chip::app::PriorityLevel::Critical }
};

chip::app::EventManagement::GetInstance().Init(&mExchangeMgr, CHIP_NUM_EVENT_LOGGING_BUFFERS, &sLoggingBuffer[0],
&logStorageResources[0]);
}
#endif // CHIP_CONFIG_ENABLE_SERVER_IM_EVENT

#if defined(CHIP_APP_USE_ECHO)
err = InitEchoHandler(&gExchangeMgr);
SuccessOrExit(err);
Expand Down
8 changes: 5 additions & 3 deletions src/app/tests/TestEventLogging.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -156,9 +156,11 @@ class TestEventGenerator : public chip::app::EventLoggingDelegate
public:
CHIP_ERROR WriteEvent(chip::TLV::TLVWriter & aWriter)
{
CHIP_ERROR err = CHIP_NO_ERROR;
err = aWriter.Put(kLivenessDeviceStatus, mStatus);
return err;
chip::TLV::TLVType dataContainerType;
ReturnErrorOnFailure(aWriter.StartContainer(chip::TLV::ContextTag(chip::to_underlying(chip::app::EventDataIB::Tag::kData)),
chip::TLV::kTLVType_Structure, dataContainerType));
ReturnErrorOnFailure(aWriter.Put(kLivenessDeviceStatus, mStatus));
return aWriter.EndContainer(dataContainerType);
}

void SetStatus(int32_t aStatus) { mStatus = aStatus; }
Expand Down
8 changes: 5 additions & 3 deletions src/app/tests/TestReadInteraction.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -94,9 +94,11 @@ class TestEventGenerator : public chip::app::EventLoggingDelegate
public:
CHIP_ERROR WriteEvent(chip::TLV::TLVWriter & aWriter)
{
CHIP_ERROR err = CHIP_NO_ERROR;
err = aWriter.Put(kTestEventTag, mStatus);
return err;
chip::TLV::TLVType dataContainerType;
ReturnErrorOnFailure(aWriter.StartContainer(chip::TLV::ContextTag(chip::to_underlying(chip::app::EventDataIB::Tag::kData)),
chip::TLV::kTLVType_Structure, dataContainerType));
ReturnErrorOnFailure(aWriter.Put(kTestEventTag, mStatus));
return aWriter.EndContainer(dataContainerType);
}

void SetStatus(int32_t aStatus) { mStatus = aStatus; }
Expand Down
8 changes: 5 additions & 3 deletions src/app/tests/integration/MockEvents.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -110,9 +110,11 @@ void LivenessEventGenerator::Generate(void)

CHIP_ERROR LivenessEventGenerator::WriteEvent(chip::TLV::TLVWriter & aWriter)
{
CHIP_ERROR err = CHIP_NO_ERROR;
err = aWriter.Put(kLivenessDeviceStatus, mStatus);
return err;
chip::TLV::TLVType dataContainerType;
ReturnErrorOnFailure(aWriter.StartContainer(chip::TLV::ContextTag(chip::to_underlying(chip::app::EventDataIB::Tag::kData)),
chip::TLV::kTLVType_Structure, dataContainerType));
ReturnErrorOnFailure(aWriter.Put(kLivenessDeviceStatus, mStatus));
return aWriter.EndContainer(dataContainerType);
}

chip::EventNumber LivenessEventGenerator::LogLiveness(chip::NodeId aNodeId, chip::EndpointId aEndpointId,
Expand Down
3 changes: 0 additions & 3 deletions src/app/zap-templates/zcl/data-model/chip/test-cluster.xml
Original file line number Diff line number Diff line change
Expand Up @@ -378,9 +378,6 @@ limitations under the License.
<arg name="arg1" type="INT8U"/>
<arg name="arg2" type="SimpleEnum"/>
<arg name="arg3" type="BOOLEAN"/>
<arg name="arg4" type="SimpleStruct"/>
<arg name="arg5" type="SimpleStruct" array="true"/>
<arg name="arg6" type="SimpleEnum" array="true"/>
</command>

<command source="server" code="0x00" name="TestSpecificResponse" optional="false" disableDefaultResponse="true">
Expand Down
32 changes: 11 additions & 21 deletions src/controller/python/chip/clusters/Attribute.py
Original file line number Diff line number Diff line change
Expand Up @@ -35,8 +35,8 @@

@unique
class EventTimestampType(Enum):
SYSTEM = 1
EPOCH = 2
SYSTEM = 0
EPOCH = 1


@unique
Expand Down Expand Up @@ -104,7 +104,7 @@ def __init__(self, EndpointId: int = None, Cluster=None, Event=None, ClusterId=N
self.EventId = EventId

def __str__(self) -> str:
return f"{self.EndpointId}/{self.EventId}/{self.EventId}"
return f"{self.EndpointId}/{self.ClusterId}/{self.EventId}"

def __hash__(self):
return str(self).__hash__()
Expand Down Expand Up @@ -187,6 +187,7 @@ class ValueDecodeFailure:
Reason: Exception = None


@dataclass
class EventReadResult(EventStatus):
Data: Any = None

Expand Down Expand Up @@ -278,7 +279,7 @@ def _BuildEventIndex():
for clusterName, obj in inspect.getmembers(sys.modules['chip.clusters.Objects']):
if ('chip.clusters.Objects' in str(obj)) and inspect.isclass(obj):
for objName, subclass in inspect.getmembers(obj):
if inspect.isclass(subclass) and (('Events') in str(subclass)):
if inspect.isclass(subclass) and (('Events' == objName)):
for eventName, event in inspect.getmembers(subclass):
if inspect.isclass(event):
base_classes = inspect.getmro(event)
Expand All @@ -288,7 +289,8 @@ def _BuildEventIndex():
value for value in base_classes if 'ClusterEventDescriptor' in str(value)]
if (matched == []):
continue

logging.error(
f"event iterate {event.cluster_id} and {event.event_id}")
_EventIndex[str(EventPath(ClusterId=event.cluster_id, EventId=event.event_id))] = eval(
'chip.clusters.Objects.' + clusterName + '.Events.' + eventName)

Expand Down Expand Up @@ -375,24 +377,12 @@ def _handleEventData(self, header: EventHeader, path: EventPath, data: bytes):
eventValue = ValueDecodeFailure(
tlvData, LookupError("event schema not found"))
else:
try:
eventValue = eventType(eventType.FromTLV(data))
except Exception as ex:
logging.error(
f"Error convering TLV to Cluster Object for path: Endpoint = {path.EndpointId}/Cluster = {path.ClusterId}/Event = {path.EventId}")
logging.error(
f"Failed Cluster Object: {str(eventType)}")
logging.error(ex)
eventValue = ValueDecodeFailure(
tlvData, ex)

# If we're in debug mode, raise the exception so that we can better debug what's happening.
if (builtins.enableDebugMode):
raise
eventValue = tlvData
header.Event = eventType

with self._resLock:
self._res['Events'].append[EventReadResult(
Header=header, Data=eventValue)]
self._res['Events'].append(EventReadResult(
Header=header, Status=chip.interaction_model.Status.Success, Data=eventValue))
except Exception as ex:
logging.exception(ex)

Expand Down
Loading

0 comments on commit 114e03c

Please sign in to comment.