diff --git a/examples/all-clusters-app/nxp/mw320/include/CHIPProjectConfig.h b/examples/all-clusters-app/nxp/mw320/include/CHIPProjectConfig.h index ff5a389db20a1c..952693439ea5a5 100644 --- a/examples/all-clusters-app/nxp/mw320/include/CHIPProjectConfig.h +++ b/examples/all-clusters-app/nxp/mw320/include/CHIPProjectConfig.h @@ -174,13 +174,6 @@ */ #define CHIP_CONFIG_EVENT_LOGGING_WDM_OFFLOAD 1 -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/examples/chef/efr32/include/CHIPProjectConfig.h b/examples/chef/efr32/include/CHIPProjectConfig.h index 1b74c802fd4f09..7bd7de17f4293e 100644 --- a/examples/chef/efr32/include/CHIPProjectConfig.h +++ b/examples/chef/efr32/include/CHIPProjectConfig.h @@ -94,13 +94,6 @@ */ #define CHIP_DEVICE_CONFIG_TEST_SERIAL_NUMBER "TEST_SN" -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/examples/light-switch-app/genio/include/CHIPProjectConfig.h b/examples/light-switch-app/genio/include/CHIPProjectConfig.h index 9dc6cad0065629..88176747684340 100644 --- a/examples/light-switch-app/genio/include/CHIPProjectConfig.h +++ b/examples/light-switch-app/genio/include/CHIPProjectConfig.h @@ -103,13 +103,6 @@ */ #define CHIP_DEVICE_CONFIG_TEST_SERIAL_NUMBER "TEST_SN" -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/examples/light-switch-app/silabs/SiWx917/include/CHIPProjectConfig.h b/examples/light-switch-app/silabs/SiWx917/include/CHIPProjectConfig.h index 1b74c802fd4f09..7bd7de17f4293e 100644 --- a/examples/light-switch-app/silabs/SiWx917/include/CHIPProjectConfig.h +++ b/examples/light-switch-app/silabs/SiWx917/include/CHIPProjectConfig.h @@ -94,13 +94,6 @@ */ #define CHIP_DEVICE_CONFIG_TEST_SERIAL_NUMBER "TEST_SN" -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/examples/light-switch-app/silabs/efr32/include/CHIPProjectConfig.h b/examples/light-switch-app/silabs/efr32/include/CHIPProjectConfig.h index 1b74c802fd4f09..7bd7de17f4293e 100644 --- a/examples/light-switch-app/silabs/efr32/include/CHIPProjectConfig.h +++ b/examples/light-switch-app/silabs/efr32/include/CHIPProjectConfig.h @@ -94,13 +94,6 @@ */ #define CHIP_DEVICE_CONFIG_TEST_SERIAL_NUMBER "TEST_SN" -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/examples/lighting-app/bouffalolab/bl702/CHIPProjectConfig.h b/examples/lighting-app/bouffalolab/bl702/CHIPProjectConfig.h index 868b4a6f9f40f9..23833bd5699f94 100644 --- a/examples/lighting-app/bouffalolab/bl702/CHIPProjectConfig.h +++ b/examples/lighting-app/bouffalolab/bl702/CHIPProjectConfig.h @@ -116,13 +116,6 @@ */ #define CHIP_DEVICE_CONFIG_TEST_SERIAL_NUMBER "TEST_SN" -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/examples/lighting-app/genio/include/CHIPProjectConfig.h b/examples/lighting-app/genio/include/CHIPProjectConfig.h index d9cd599ba8f3fb..7bb42a233fc0fa 100644 --- a/examples/lighting-app/genio/include/CHIPProjectConfig.h +++ b/examples/lighting-app/genio/include/CHIPProjectConfig.h @@ -97,13 +97,6 @@ */ #define CHIP_DEVICE_CONFIG_TEST_SERIAL_NUMBER "TEST_SN" -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/examples/lighting-app/infineon/psoc6/include/CHIPProjectConfig.h b/examples/lighting-app/infineon/psoc6/include/CHIPProjectConfig.h index a6354316e26de0..23a5963fb48f87 100644 --- a/examples/lighting-app/infineon/psoc6/include/CHIPProjectConfig.h +++ b/examples/lighting-app/infineon/psoc6/include/CHIPProjectConfig.h @@ -110,13 +110,6 @@ */ #define CHIP_DEVICE_CONFIG_TEST_SERIAL_NUMBER "TEST_SN" -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/examples/lighting-app/silabs/SiWx917/include/CHIPProjectConfig.h b/examples/lighting-app/silabs/SiWx917/include/CHIPProjectConfig.h index 4b3d8f571c9057..9131e8b89e4497 100644 --- a/examples/lighting-app/silabs/SiWx917/include/CHIPProjectConfig.h +++ b/examples/lighting-app/silabs/SiWx917/include/CHIPProjectConfig.h @@ -105,13 +105,6 @@ */ #define CHIP_DEVICE_CONFIG_TEST_SERIAL_NUMBER "TEST_SN" -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/examples/lighting-app/silabs/efr32/include/CHIPProjectConfig.h b/examples/lighting-app/silabs/efr32/include/CHIPProjectConfig.h index 1d3fefcce8232e..177c41672f9da9 100644 --- a/examples/lighting-app/silabs/efr32/include/CHIPProjectConfig.h +++ b/examples/lighting-app/silabs/efr32/include/CHIPProjectConfig.h @@ -94,13 +94,6 @@ */ #define CHIP_DEVICE_CONFIG_TEST_SERIAL_NUMBER "TEST_SN" -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/examples/lock-app/cc32xx/main/include/CHIPProjectConfig.h b/examples/lock-app/cc32xx/main/include/CHIPProjectConfig.h index ca62337985d252..bf6cd7696b4ad5 100644 --- a/examples/lock-app/cc32xx/main/include/CHIPProjectConfig.h +++ b/examples/lock-app/cc32xx/main/include/CHIPProjectConfig.h @@ -112,13 +112,6 @@ */ #define CHIP_DEVICE_CONFIG_ENABLE_CHIPOBLE 0 -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/examples/lock-app/genio/include/CHIPProjectConfig.h b/examples/lock-app/genio/include/CHIPProjectConfig.h index 25bb0732cdc547..20c49c739b4108 100644 --- a/examples/lock-app/genio/include/CHIPProjectConfig.h +++ b/examples/lock-app/genio/include/CHIPProjectConfig.h @@ -105,13 +105,6 @@ */ #define CHIP_DEVICE_CONFIG_TEST_SERIAL_NUMBER "TEST_SN" -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/examples/lock-app/silabs/SiWx917/include/CHIPProjectConfig.h b/examples/lock-app/silabs/SiWx917/include/CHIPProjectConfig.h index 9793e98ac9bc0a..9561c80fedd4a7 100644 --- a/examples/lock-app/silabs/SiWx917/include/CHIPProjectConfig.h +++ b/examples/lock-app/silabs/SiWx917/include/CHIPProjectConfig.h @@ -95,13 +95,6 @@ */ #define CHIP_DEVICE_CONFIG_TEST_SERIAL_NUMBER "TEST_SN" -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/examples/lock-app/silabs/efr32/include/CHIPProjectConfig.h b/examples/lock-app/silabs/efr32/include/CHIPProjectConfig.h index 9793e98ac9bc0a..9561c80fedd4a7 100644 --- a/examples/lock-app/silabs/efr32/include/CHIPProjectConfig.h +++ b/examples/lock-app/silabs/efr32/include/CHIPProjectConfig.h @@ -95,13 +95,6 @@ */ #define CHIP_DEVICE_CONFIG_TEST_SERIAL_NUMBER "TEST_SN" -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/examples/ota-requestor-app/genio/include/CHIPProjectConfig.h b/examples/ota-requestor-app/genio/include/CHIPProjectConfig.h index cf490ece051bed..70fd19acbc284d 100644 --- a/examples/ota-requestor-app/genio/include/CHIPProjectConfig.h +++ b/examples/ota-requestor-app/genio/include/CHIPProjectConfig.h @@ -105,13 +105,6 @@ */ #define CHIP_DEVICE_CONFIG_TEST_SERIAL_NUMBER "TEST_SN" -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/examples/persistent-storage/infineon/psoc6/include/CHIPProjectConfig.h b/examples/persistent-storage/infineon/psoc6/include/CHIPProjectConfig.h index b93e564d65042a..7c949a6ee9cdec 100644 --- a/examples/persistent-storage/infineon/psoc6/include/CHIPProjectConfig.h +++ b/examples/persistent-storage/infineon/psoc6/include/CHIPProjectConfig.h @@ -87,13 +87,6 @@ */ #define CHIP_DEVICE_CONFIG_TEST_SERIAL_NUMBER "TEST_SN" -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/examples/shell/genio/include/CHIPProjectConfig.h b/examples/shell/genio/include/CHIPProjectConfig.h index a5c27bc48cb994..9803c720557ab4 100644 --- a/examples/shell/genio/include/CHIPProjectConfig.h +++ b/examples/shell/genio/include/CHIPProjectConfig.h @@ -92,13 +92,6 @@ */ #define CHIP_DEVICE_CONFIG_TEST_SERIAL_NUMBER "TEST_SN" -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/examples/thermostat/genio/include/CHIPProjectConfig.h b/examples/thermostat/genio/include/CHIPProjectConfig.h index 5904b776cd601d..60f6220c85ba9d 100644 --- a/examples/thermostat/genio/include/CHIPProjectConfig.h +++ b/examples/thermostat/genio/include/CHIPProjectConfig.h @@ -113,13 +113,6 @@ */ #define CHIP_DEVICE_CONFIG_TEST_SERIAL_NUMBER "TEST_SN" -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/examples/thermostat/silabs/efr32/include/CHIPProjectConfig.h b/examples/thermostat/silabs/efr32/include/CHIPProjectConfig.h index 526cede60faa2a..abf9982a548b5c 100644 --- a/examples/thermostat/silabs/efr32/include/CHIPProjectConfig.h +++ b/examples/thermostat/silabs/efr32/include/CHIPProjectConfig.h @@ -102,13 +102,6 @@ */ #define CHIP_DEVICE_CONFIG_TEST_SERIAL_NUMBER "TEST_SN" -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/examples/window-app/silabs/SiWx917/include/CHIPProjectConfig.h b/examples/window-app/silabs/SiWx917/include/CHIPProjectConfig.h index 6a12dbc3794c8f..cb1464d4465a70 100644 --- a/examples/window-app/silabs/SiWx917/include/CHIPProjectConfig.h +++ b/examples/window-app/silabs/SiWx917/include/CHIPProjectConfig.h @@ -93,13 +93,6 @@ */ #define CHIP_DEVICE_CONFIG_TEST_SERIAL_NUMBER "TEST_SN" -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/examples/window-app/silabs/efr32/include/CHIPProjectConfig.h b/examples/window-app/silabs/efr32/include/CHIPProjectConfig.h index 6a12dbc3794c8f..cb1464d4465a70 100644 --- a/examples/window-app/silabs/efr32/include/CHIPProjectConfig.h +++ b/examples/window-app/silabs/efr32/include/CHIPProjectConfig.h @@ -93,13 +93,6 @@ */ #define CHIP_DEVICE_CONFIG_TEST_SERIAL_NUMBER "TEST_SN" -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE * diff --git a/src/app/EventLoggingTypes.h b/src/app/EventLoggingTypes.h index 58aa8edbfaaef4..3a2de1a6f4c974 100644 --- a/src/app/EventLoggingTypes.h +++ b/src/app/EventLoggingTypes.h @@ -101,7 +101,6 @@ struct Timestamp kEpoch }; Timestamp() {} - Timestamp(Type aType) : mType(aType) { mValue = 0; } Timestamp(Type aType, uint64_t aValue) : mType(aType), mValue(aValue) {} Timestamp(System::Clock::Timestamp aValue) : mType(Type::kSystem), mValue(aValue.count()) {} static Timestamp Epoch(System::Clock::Timestamp aValue) diff --git a/src/app/EventManagement.cpp b/src/app/EventManagement.cpp index 9fb66767ba7848..83197c75013662 100644 --- a/src/app/EventManagement.cpp +++ b/src/app/EventManagement.cpp @@ -83,7 +83,8 @@ struct CopyAndAdjustDeltaTimeContext void EventManagement::Init(Messaging::ExchangeManager * apExchangeManager, uint32_t aNumBuffers, CircularEventBuffer * apCircularEventBuffer, const LogStorageResources * const apLogStorageResources, - MonotonicallyIncreasingCounter * apEventNumberCounter) + MonotonicallyIncreasingCounter * apEventNumberCounter, + System::Clock::Milliseconds64 aMonotonicStartupTime) { CircularEventBuffer * current = nullptr; CircularEventBuffer * prev = nullptr; @@ -122,6 +123,8 @@ void EventManagement::Init(Messaging::ExchangeManager * apExchangeManager, uint3 mpEventBuffer = apCircularEventBuffer; mState = EventManagementStates::Idle; mBytesWritten = 0; + + mMonotonicStartupTime = aMonotonicStartupTime; } CHIP_ERROR EventManagement::CopyToNextBuffer(CircularEventBuffer * apEventBuffer) @@ -327,10 +330,12 @@ CHIP_ERROR EventManagement::ConstructEvent(EventLoadOutContext * apContext, Even void EventManagement::CreateEventManagement(Messaging::ExchangeManager * apExchangeManager, uint32_t aNumBuffers, CircularEventBuffer * apCircularEventBuffer, const LogStorageResources * const apLogStorageResources, - MonotonicallyIncreasingCounter * apEventNumberCounter) + MonotonicallyIncreasingCounter * apEventNumberCounter, + System::Clock::Milliseconds64 aMonotonicStartupTime) { - sInstance.Init(apExchangeManager, aNumBuffers, apCircularEventBuffer, apLogStorageResources, apEventNumberCounter); + sInstance.Init(apExchangeManager, aNumBuffers, apCircularEventBuffer, apLogStorageResources, apEventNumberCounter, + aMonotonicStartupTime); } /** @@ -365,12 +370,14 @@ CHIP_ERROR EventManagement::CopyAndAdjustDeltaTime(const TLVReader & aReader, si // Does not go on the wire. return CHIP_NO_ERROR; } - if ((aReader.GetTag() == TLV::ContextTag(to_underlying(EventDataIB::Tag::kSystemTimestamp))) && !(ctx->mpContext->mFirst)) + if ((aReader.GetTag() == TLV::ContextTag(to_underlying(EventDataIB::Tag::kSystemTimestamp))) && !(ctx->mpContext->mFirst) && + (ctx->mpContext->mCurrentTime.mType == ctx->mpContext->mPreviousTime.mType)) { return ctx->mpWriter->Put(TLV::ContextTag(to_underlying(EventDataIB::Tag::kDeltaSystemTimestamp)), ctx->mpContext->mCurrentTime.mValue - ctx->mpContext->mPreviousTime.mValue); } - if ((aReader.GetTag() == TLV::ContextTag(to_underlying(EventDataIB::Tag::kEpochTimestamp))) && !(ctx->mpContext->mFirst)) + if ((aReader.GetTag() == TLV::ContextTag(to_underlying(EventDataIB::Tag::kEpochTimestamp))) && !(ctx->mpContext->mFirst) && + (ctx->mpContext->mCurrentTime.mType == ctx->mpContext->mPreviousTime.mType)) { return ctx->mpWriter->Put(TLV::ContextTag(to_underlying(EventDataIB::Tag::kDeltaEpochTimestamp)), ctx->mpContext->mCurrentTime.mValue - ctx->mpContext->mPreviousTime.mValue); @@ -411,16 +418,18 @@ CHIP_ERROR EventManagement::LogEventPrivate(EventLoggingDelegate * apDelegate, c CircularEventBuffer * buffer = nullptr; EventLoadOutContext ctxt = EventLoadOutContext(writer, aEventOptions.mPriority, mLastEventNumber); EventOptions opts; -#if CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS & CHIP_SYSTEM_CONFIG_PLATFORM_PROVIDES_TIME Timestamp timestamp; - System::Clock::Timestamp utc_time; - + System::Clock::Milliseconds64 utc_time; err = System::SystemClock().GetClock_RealTimeMS(utc_time); - SuccessOrExit(err); - timestamp = Timestamp::Epoch(utc_time); -#else - Timestamp timestamp(System::SystemClock().GetMonotonicTimestamp()); -#endif + if (err == CHIP_NO_ERROR) + { + timestamp = Timestamp::Epoch(utc_time); + } + else + { + auto systemTimeMs = System::SystemClock().GetMonotonicMilliseconds64() - mMonotonicStartupTime; + timestamp = Timestamp::System(systemTimeMs); + } opts = EventOptions(timestamp); // Start the event container (anonymous structure) in the circular buffer diff --git a/src/app/EventManagement.h b/src/app/EventManagement.h index 55209418d7e71e..c00b624ab6f9bf 100644 --- a/src/app/EventManagement.h +++ b/src/app/EventManagement.h @@ -36,6 +36,7 @@ #include #include #include +#include /** * Events are stored in the LogStorageResources provided to @@ -218,10 +219,15 @@ class EventManagement * * @param[in] apEventNumberCounter A counter to use for event numbers. * + * @param[in] aMonotonicStartupTime Time we should consider as "monotonic + * time 0" for cases when we use + * system-time event timestamps. + * */ void Init(Messaging::ExchangeManager * apExchangeManager, uint32_t aNumBuffers, CircularEventBuffer * apCircularEventBuffer, const LogStorageResources * const apLogStorageResources, - MonotonicallyIncreasingCounter * apEventNumberCounter); + MonotonicallyIncreasingCounter * apEventNumberCounter, + System::Clock::Milliseconds64 aMonotonicStartupTime); static EventManagement & GetInstance(); @@ -245,12 +251,17 @@ class EventManagement * * @param[in] apEventNumberCounter A counter to use for event numbers. * + * @param[in] aMonotonicStartupTime Time we should consider as "monotonic + * time 0" for cases when we use + * system-time event timestamps. + * * @note This function must be called prior to the logging being used. */ - static void CreateEventManagement(Messaging::ExchangeManager * apExchangeManager, uint32_t aNumBuffers, - CircularEventBuffer * apCircularEventBuffer, - const LogStorageResources * const apLogStorageResources, - MonotonicallyIncreasingCounter * apEventNumberCounter); + static void + CreateEventManagement(Messaging::ExchangeManager * apExchangeManager, uint32_t aNumBuffers, + CircularEventBuffer * apCircularEventBuffer, const LogStorageResources * const apLogStorageResources, + MonotonicallyIncreasingCounter * apEventNumberCounter, + System::Clock::Milliseconds64 aMonotonicStartupTime = System::SystemClock().GetMonotonicMilliseconds64()); static void DestroyEventManagement(); @@ -386,11 +397,7 @@ class EventManagement int mFieldsToRead = 0; /* PriorityLevel and DeltaTime are there if that is not first event when putting events in report*/ -#if CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS & CHIP_SYSTEM_CONFIG_PLATFORM_PROVIDES_TIME - Timestamp mCurrentTime = Timestamp::System(System::Clock::kZero); -#else - Timestamp mCurrentTime = Timestamp::Epoch(System::Clock::kZero); -#endif + Timestamp mCurrentTime = Timestamp::System(System::Clock::kZero); PriorityLevel mPriority = PriorityLevel::First; ClusterId mClusterId = 0; EndpointId mEndpointId = 0; @@ -537,6 +544,8 @@ class EventManagement EventNumber mLastEventNumber = 0; ///< Last event Number vended Timestamp mLastEventTimestamp; ///< The timestamp of the last event in this buffer + + System::Clock::Milliseconds64 mMonotonicStartupTime; }; } // namespace app } // namespace chip diff --git a/src/app/server/Server.cpp b/src/app/server/Server.cpp index 72536f98504a68..b80c3ca8f45b11 100644 --- a/src/app/server/Server.cpp +++ b/src/app/server/Server.cpp @@ -235,7 +235,8 @@ CHIP_ERROR Server::Init(const ServerInitParams & initParams) }; chip::app::EventManagement::GetInstance().Init(&mExchangeMgr, CHIP_NUM_EVENT_LOGGING_BUFFERS, &sLoggingBuffer[0], - &logStorageResources[0], &sGlobalEventIdCounter); + &logStorageResources[0], &sGlobalEventIdCounter, + std::chrono::duration_cast(mInitTimestamp)); } #endif // CHIP_CONFIG_ENABLE_SERVER_IM_EVENT diff --git a/src/app/tests/BUILD.gn b/src/app/tests/BUILD.gn index cc509b5ba7c952..8e291bb904feb0 100644 --- a/src/app/tests/BUILD.gn +++ b/src/app/tests/BUILD.gn @@ -95,7 +95,7 @@ chip_test_suite("tests") { "TestCommandPathParams.cpp", "TestDataModelSerialization.cpp", "TestDefaultOTARequestorStorage.cpp", - "TestEventLogging.cpp", + "TestEventLoggingNoUTCTime.cpp", "TestEventOverflow.cpp", "TestEventPathParams.cpp", "TestFabricScopedEventLogging.cpp", @@ -126,6 +126,14 @@ chip_test_suite("tests") { test_sources += [ "TestClusterStateCache.cpp" ] } + # On NRF and fake platforms we do not have a realtime clock available, so + # TestEventLogging.cpp would be testing the same thing as + # TestEventLoggingNoUTCTime, but it's not set up to deal with the timestamps + # being that low. + if (chip_device_platform != "nrfconnect" && chip_device_platform != "fake") { + test_sources += [ "TestEventLogging.cpp" ] + } + cflags = [ "-Wconversion" ] public_deps = [ diff --git a/src/app/tests/TestEventLoggingNoUTCTime.cpp b/src/app/tests/TestEventLoggingNoUTCTime.cpp new file mode 100644 index 00000000000000..1530e58f8ac8d7 --- /dev/null +++ b/src/app/tests/TestEventLoggingNoUTCTime.cpp @@ -0,0 +1,387 @@ +/* + * Copyright (c) 2021-2023 Project CHIP Authors + * All rights reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +/** + * @file + * This file implements a test for CHIP Interaction Model Event logging + * + */ + +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include + +#include + +namespace { + +static const chip::ClusterId kLivenessClusterId = 0x00000022; +static const uint32_t kLivenessChangeEvent = 1; +static const chip::EndpointId kTestEndpointId1 = 2; +static const chip::EndpointId kTestEndpointId2 = 3; +static const chip::TLV::Tag kLivenessDeviceStatus = chip::TLV::ContextTag(1); + +static uint8_t gDebugEventBuffer[128]; +static uint8_t gInfoEventBuffer[128]; +static uint8_t gCritEventBuffer[128]; +static chip::app::CircularEventBuffer gCircularEventBuffer[3]; + +class MockClock : public chip::System::Clock::ClockBase +{ +public: + MockClock(chip::System::Clock::ClockBase & aRealClock) : mRealClock(aRealClock) + { + chip::System::Clock::Internal::SetSystemClockForTesting(this); + } + + ~MockClock() { chip::System::Clock::Internal::SetSystemClockForTesting(&mRealClock); } + + chip::System::Clock::Microseconds64 GetMonotonicMicroseconds64() override { return mRealClock.GetMonotonicMicroseconds64(); } + chip::System::Clock::Milliseconds64 GetMonotonicMilliseconds64() override { return mRealClock.GetMonotonicMilliseconds64(); } + + CHIP_ERROR GetClock_RealTime(chip::System::Clock::Microseconds64 & aCurTime) override { return CHIP_ERROR_NOT_IMPLEMENTED; } + CHIP_ERROR GetClock_RealTimeMS(chip::System::Clock::Milliseconds64 & aCurTime) override { return CHIP_ERROR_NOT_IMPLEMENTED; } + CHIP_ERROR SetClock_RealTime(chip::System::Clock::Microseconds64 aNewCurTime) override { return CHIP_ERROR_NOT_IMPLEMENTED; } + +private: + chip::System::Clock::ClockBase & mRealClock; +}; + +class TestContext : public chip::Test::AppContext +{ +public: + static int Initialize(void * context) + { + if (AppContext::Initialize(context) != SUCCESS) + return FAILURE; + + auto * ctx = static_cast(context); + + if (ctx->mEventCounter.Init(0) != CHIP_NO_ERROR) + { + return FAILURE; + } + + ctx->mClock.Emplace(chip::System::SystemClock()); + + chip::app::LogStorageResources logStorageResources[] = { + { &gDebugEventBuffer[0], sizeof(gDebugEventBuffer), chip::app::PriorityLevel::Debug }, + { &gInfoEventBuffer[0], sizeof(gInfoEventBuffer), chip::app::PriorityLevel::Info }, + { &gCritEventBuffer[0], sizeof(gCritEventBuffer), chip::app::PriorityLevel::Critical }, + }; + + chip::app::EventManagement::CreateEventManagement(&ctx->GetExchangeManager(), + sizeof(logStorageResources) / sizeof(logStorageResources[0]), + gCircularEventBuffer, logStorageResources, &ctx->mEventCounter); + + return SUCCESS; + } + + static int Finalize(void * context) + { + chip::app::EventManagement::DestroyEventManagement(); + + auto * ctx = static_cast(context); + + ctx->mClock.ClearValue(); + + if (AppContext::Finalize(context) != SUCCESS) + return FAILURE; + + return SUCCESS; + } + +private: + chip::MonotonicallyIncreasingCounter mEventCounter; + chip::Optional mClock; +}; + +void ENFORCE_FORMAT(1, 2) SimpleDumpWriter(const char * aFormat, ...) +{ + va_list args; + + va_start(args, aFormat); + + vprintf(aFormat, args); + + va_end(args); +} + +void PrintEventLog() +{ + chip::TLV::TLVReader reader; + chip::app::CircularEventBufferWrapper bufWrapper; + chip::app::EventManagement::GetInstance().GetEventReader(reader, chip::app::PriorityLevel::Critical, &bufWrapper); + chip::TLV::Debug::Dump(reader, SimpleDumpWriter); +} + +static void CheckLogState(nlTestSuite * apSuite, chip::app::EventManagement & aLogMgmt, size_t expectedMinNumEvents, + size_t expectedMaxNumEvents, chip::app::PriorityLevel aPriority) +{ + CHIP_ERROR err; + chip::TLV::TLVReader reader; + size_t elementCount; + chip::app::CircularEventBufferWrapper bufWrapper; + err = aLogMgmt.GetEventReader(reader, aPriority, &bufWrapper); + NL_TEST_ASSERT(apSuite, err == CHIP_NO_ERROR); + + err = chip::TLV::Utilities::Count(reader, elementCount, false); + NL_TEST_ASSERT(apSuite, err == CHIP_NO_ERROR); + + NL_TEST_ASSERT(apSuite, elementCount >= expectedMinNumEvents); + NL_TEST_ASSERT(apSuite, elementCount <= expectedMaxNumEvents); + printf("elementCount vs [expectedMinNumEvents, expectedMaxNumEvents] : %u vs [%u, %u] \n", + static_cast(elementCount), static_cast(expectedMinNumEvents), + static_cast(expectedMaxNumEvents)); +} + +static void CheckLogState(nlTestSuite * apSuite, chip::app::EventManagement & aLogMgmt, size_t expectedNumEvents, + chip::app::PriorityLevel aPriority) +{ + CheckLogState(apSuite, aLogMgmt, expectedNumEvents, expectedNumEvents, aPriority); +} + +static void CheckLogReadOut(nlTestSuite * apSuite, chip::app::EventManagement & alogMgmt, chip::EventNumber startingEventNumber, + size_t expectedNumEvents, chip::app::ObjectList * clusterInfo) +{ + CHIP_ERROR err; + chip::TLV::TLVReader reader; + chip::TLV::TLVWriter writer; + size_t eventCount = 0; + + chip::Platform::ScopedMemoryBuffer backingStore; + VerifyOrDie(backingStore.Alloc(1024)); + + size_t totalNumElements; + writer.Init(backingStore.Get(), 1024); + err = alogMgmt.FetchEventsSince(writer, clusterInfo, startingEventNumber, eventCount, chip::Access::SubjectDescriptor{}); + NL_TEST_ASSERT(apSuite, err == CHIP_NO_ERROR || err == CHIP_END_OF_TLV); + + reader.Init(backingStore.Get(), writer.GetLengthWritten()); + + err = chip::TLV::Utilities::Count(reader, totalNumElements, false); + NL_TEST_ASSERT(apSuite, err == CHIP_NO_ERROR); + + printf("totalNumElements vs expectedNumEvents vs eventCount : %u vs %u vs %u \n", static_cast(totalNumElements), + static_cast(expectedNumEvents), static_cast(eventCount)); + NL_TEST_ASSERT(apSuite, totalNumElements == expectedNumEvents && totalNumElements == eventCount); + reader.Init(backingStore.Get(), writer.GetLengthWritten()); + chip::TLV::Debug::Dump(reader, SimpleDumpWriter); +} + +class TestEventGenerator : public chip::app::EventLoggingDelegate +{ +public: + CHIP_ERROR WriteEvent(chip::TLV::TLVWriter & aWriter) + { + 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; } + +private: + int32_t mStatus; +}; + +static void CheckLogEventWithEvictToNextBuffer(nlTestSuite * apSuite, void * apContext) +{ + CHIP_ERROR err = CHIP_NO_ERROR; + chip::EventNumber eid1, eid2, eid3, eid4, eid5, eid6; + chip::app::EventOptions options1; + chip::app::EventOptions options2; + TestEventGenerator testEventGenerator; + + options1.mPath = { kTestEndpointId1, kLivenessClusterId, kLivenessChangeEvent }; + options1.mPriority = chip::app::PriorityLevel::Info; + options2.mPath = { kTestEndpointId2, kLivenessClusterId, kLivenessChangeEvent }; + options2.mPriority = chip::app::PriorityLevel::Info; + chip::app::EventManagement & logMgmt = chip::app::EventManagement::GetInstance(); + testEventGenerator.SetStatus(0); + err = logMgmt.LogEvent(&testEventGenerator, options1, eid1); + NL_TEST_ASSERT(apSuite, err == CHIP_NO_ERROR); + CheckLogState(apSuite, logMgmt, 1, chip::app::PriorityLevel::Debug); + CheckLogState(apSuite, logMgmt, 1, chip::app::PriorityLevel::Info); + testEventGenerator.SetStatus(1); + err = logMgmt.LogEvent(&testEventGenerator, options1, eid2); + NL_TEST_ASSERT(apSuite, err == CHIP_NO_ERROR); + CheckLogState(apSuite, logMgmt, 2, chip::app::PriorityLevel::Debug); + CheckLogState(apSuite, logMgmt, 2, chip::app::PriorityLevel::Info); + testEventGenerator.SetStatus(0); + err = logMgmt.LogEvent(&testEventGenerator, options1, eid3); + NL_TEST_ASSERT(apSuite, err == CHIP_NO_ERROR); + CheckLogState(apSuite, logMgmt, 3, chip::app::PriorityLevel::Debug); + CheckLogState(apSuite, logMgmt, 3, chip::app::PriorityLevel::Info); + // Start to copy info event to next buffer since current debug buffer is full and info event is higher priority + testEventGenerator.SetStatus(1); + err = logMgmt.LogEvent(&testEventGenerator, options2, eid4); + NL_TEST_ASSERT(apSuite, err == CHIP_NO_ERROR); + // At this point depending on timing and hence event sizes we might have + // either 3 or 4 events in the Debug buffer. + CheckLogState(apSuite, logMgmt, 3, 4, chip::app::PriorityLevel::Debug); + CheckLogState(apSuite, logMgmt, 4, chip::app::PriorityLevel::Info); + + testEventGenerator.SetStatus(0); + err = logMgmt.LogEvent(&testEventGenerator, options2, eid5); + NL_TEST_ASSERT(apSuite, err == CHIP_NO_ERROR); + CheckLogState(apSuite, logMgmt, 3, 4, chip::app::PriorityLevel::Debug); + CheckLogState(apSuite, logMgmt, 5, chip::app::PriorityLevel::Info); + + testEventGenerator.SetStatus(1); + err = logMgmt.LogEvent(&testEventGenerator, options2, eid6); + NL_TEST_ASSERT(apSuite, err == CHIP_NO_ERROR); + CheckLogState(apSuite, logMgmt, 3, 4, chip::app::PriorityLevel::Debug); + CheckLogState(apSuite, logMgmt, 6, chip::app::PriorityLevel::Info); + + PrintEventLog(); + + NL_TEST_ASSERT(apSuite, (eid1 + 1) == eid2); + NL_TEST_ASSERT(apSuite, (eid2 + 1) == eid3); + NL_TEST_ASSERT(apSuite, (eid3 + 1) == eid4); + NL_TEST_ASSERT(apSuite, (eid4 + 1) == eid5); + NL_TEST_ASSERT(apSuite, (eid5 + 1) == eid6); + + chip::app::ObjectList paths[2]; + + paths[0].mValue.mEndpointId = kTestEndpointId1; + paths[0].mValue.mClusterId = kLivenessClusterId; + + paths[1].mValue.mEndpointId = kTestEndpointId2; + paths[1].mValue.mClusterId = kLivenessClusterId; + paths[1].mValue.mEventId = kLivenessChangeEvent; + + // interested paths are path list, expect to retrieve all events for each particular interested path + CheckLogReadOut(apSuite, logMgmt, 0, 3, &paths[0]); + CheckLogReadOut(apSuite, logMgmt, 1, 2, &paths[0]); + CheckLogReadOut(apSuite, logMgmt, 2, 1, &paths[0]); + CheckLogReadOut(apSuite, logMgmt, 3, 3, &paths[1]); + CheckLogReadOut(apSuite, logMgmt, 4, 2, &paths[1]); + CheckLogReadOut(apSuite, logMgmt, 5, 1, &paths[1]); + + paths[0].mpNext = &paths[1]; + // interested paths are path list, expect to retrieve all events for those interested paths + CheckLogReadOut(apSuite, logMgmt, 0, 6, paths); + + chip::app::ObjectList pathsWithWildcard[2]; + paths[0].mValue.mEndpointId = kTestEndpointId1; + paths[0].mValue.mClusterId = kLivenessClusterId; + + // second path is wildcard path at default, expect to retrieve all events + CheckLogReadOut(apSuite, logMgmt, 0, 6, &pathsWithWildcard[1]); + + paths[0].mpNext = &paths[1]; + // first path is not wildcard, second path is wildcard path at default, expect to retrieve all events + CheckLogReadOut(apSuite, logMgmt, 0, 6, pathsWithWildcard); +} + +static void CheckLogEventWithDiscardLowEvent(nlTestSuite * apSuite, void * apContext) +{ + CHIP_ERROR err = CHIP_NO_ERROR; + chip::EventNumber eid1, eid2, eid3, eid4, eid5, eid6; + chip::app::EventOptions options; + options.mPath = { kTestEndpointId1, kLivenessClusterId, kLivenessChangeEvent }; + options.mPriority = chip::app::PriorityLevel::Debug; + TestEventGenerator testEventGenerator; + + chip::app::EventManagement & logMgmt = chip::app::EventManagement::GetInstance(); + CheckLogState(apSuite, logMgmt, 3, 4, chip::app::PriorityLevel::Debug); + CheckLogState(apSuite, logMgmt, 6, chip::app::PriorityLevel::Info); + + testEventGenerator.SetStatus(0); + err = logMgmt.LogEvent(&testEventGenerator, options, eid1); + NL_TEST_ASSERT(apSuite, err == CHIP_NO_ERROR); + // At this point depending on timing and hence event sizes we might have + // either 3 or 4 events in the DEBUG buffer. We never have more than 4 + // events in the Info buffer. + CheckLogState(apSuite, logMgmt, 3, 4, chip::app::PriorityLevel::Debug); + CheckLogState(apSuite, logMgmt, 6, 7, chip::app::PriorityLevel::Info); + testEventGenerator.SetStatus(1); + err = logMgmt.LogEvent(&testEventGenerator, options, eid2); + NL_TEST_ASSERT(apSuite, err == CHIP_NO_ERROR); + CheckLogState(apSuite, logMgmt, 3, 4, chip::app::PriorityLevel::Debug); + CheckLogState(apSuite, logMgmt, 6, 8, chip::app::PriorityLevel::Info); + testEventGenerator.SetStatus(0); + err = logMgmt.LogEvent(&testEventGenerator, options, eid3); + NL_TEST_ASSERT(apSuite, err == CHIP_NO_ERROR); + CheckLogState(apSuite, logMgmt, 3, 4, chip::app::PriorityLevel::Debug); + CheckLogState(apSuite, logMgmt, 6, 8, chip::app::PriorityLevel::Info); + // Start to drop off debug event since debug event can only be saved in debug buffer + testEventGenerator.SetStatus(1); + err = logMgmt.LogEvent(&testEventGenerator, options, eid4); + NL_TEST_ASSERT(apSuite, err == CHIP_NO_ERROR); + CheckLogState(apSuite, logMgmt, 3, 4, chip::app::PriorityLevel::Debug); + CheckLogState(apSuite, logMgmt, 6, 8, chip::app::PriorityLevel::Info); + + testEventGenerator.SetStatus(0); + err = logMgmt.LogEvent(&testEventGenerator, options, eid5); + NL_TEST_ASSERT(apSuite, err == CHIP_NO_ERROR); + CheckLogState(apSuite, logMgmt, 3, 4, chip::app::PriorityLevel::Debug); + CheckLogState(apSuite, logMgmt, 6, 8, chip::app::PriorityLevel::Info); + + testEventGenerator.SetStatus(1); + err = logMgmt.LogEvent(&testEventGenerator, options, eid6); + NL_TEST_ASSERT(apSuite, err == CHIP_NO_ERROR); + CheckLogState(apSuite, logMgmt, 3, 4, chip::app::PriorityLevel::Debug); + CheckLogState(apSuite, logMgmt, 6, 8, chip::app::PriorityLevel::Info); +} +/** + * Test Suite. It lists all the test functions. + */ + +const nlTest sTests[] = { NL_TEST_DEF("CheckLogEventWithEvictToNextBufferNoUTCTime", CheckLogEventWithEvictToNextBuffer), + NL_TEST_DEF("CheckLogEventWithDiscardLowEventNoUTCTime", CheckLogEventWithDiscardLowEvent), + NL_TEST_SENTINEL() }; + +// clang-format off +nlTestSuite sSuite = +{ + "EventLogging", + &sTests[0], + TestContext::Initialize, + TestContext::Finalize +}; +// clang-format on + +} // namespace + +int TestEventLoggingNoUTCTime() +{ + return chip::ExecuteTestsWithContext(&sSuite); +} + +CHIP_REGISTER_TEST_SUITE(TestEventLoggingNoUTCTime) diff --git a/src/lib/core/CHIPEventLoggingConfig.h b/src/lib/core/CHIPEventLoggingConfig.h index 006b92f5b77cfb..1967728730a8e7 100644 --- a/src/lib/core/CHIPEventLoggingConfig.h +++ b/src/lib/core/CHIPEventLoggingConfig.h @@ -59,16 +59,6 @@ #define CHIP_CONFIG_EVENT_LOGGING_MAXIMUM_UPLOAD_SECONDS 86400 #endif -/** - * @def CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * @brief - * By default, don't record UTC timestamps. - */ -#ifndef CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 0 -#endif - /** * @def CHIP_CONFIG_EVENT_LOGGING_EXTERNAL_EVENT_SUPPORT * diff --git a/src/test_driver/efr32/include/CHIPProjectConfig.h b/src/test_driver/efr32/include/CHIPProjectConfig.h index 451292ff519b7b..2c3645e1f556d4 100644 --- a/src/test_driver/efr32/include/CHIPProjectConfig.h +++ b/src/test_driver/efr32/include/CHIPProjectConfig.h @@ -80,13 +80,6 @@ */ #define CHIP_DEVICE_CONFIG_USE_TEST_SERIAL_NUMBER "DUMMY_SN" -/** - * CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS - * - * Enable recording UTC timestamps. - */ -#define CHIP_CONFIG_EVENT_LOGGING_UTC_TIMESTAMPS 1 - /** * CHIP_DEVICE_CONFIG_EVENT_LOGGING_DEBUG_BUFFER_SIZE *