Skip to content

Commit 984f6ee

Browse files
lpbeliveau-silabslpbeliveau-silabs
committed
Initial tracing and test, need to compile from CSA and then to move tests out of src/platformtests
Initial Silabs Tracing object and unit tests. Next step: create silabs matter tracing backend object and integrate in our Base App / main
1 parent 6cf10d7 commit 984f6ee

File tree

7 files changed

+850
-0
lines changed

7 files changed

+850
-0
lines changed

‎examples/platform/silabs/silabs_utils.h

+2
Original file line numberDiff line numberDiff line change
@@ -24,6 +24,8 @@
2424
extern "C" {
2525
#endif
2626

27+
bool isLogInitialized(void);
28+
2729
void silabsInitLog(void);
2830

2931
void silabsLog(const char * aFormat, ...);

‎src/platform/silabs/Logging.cpp

+7
Original file line numberDiff line numberDiff line change
@@ -200,6 +200,13 @@ extern "C" void silabsLog(const char * aFormat, ...)
200200
va_end(v);
201201
}
202202

203+
#ifdef SILABS_LOG_ENABLED
204+
extern bool isLogInitialized()
205+
{
206+
return sLogInitialized;
207+
}
208+
#endif // SILABS_LOG_ENABLED
209+
203210
namespace chip {
204211
namespace DeviceLayer {
205212

‎src/platform/silabs/tracing/BUILD.gn

+16
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,16 @@
1+
import("//build_overrides/build.gni")
2+
import("//build_overrides/chip.gni")
3+
4+
static_library("SilabsTracing") {
5+
sources = [
6+
"SilabsTracing.cpp",
7+
"SilabsTracing.h",
8+
]
9+
10+
deps = [
11+
"${chip_root}/src/lib/core",
12+
"${chip_root}/src/lib/support",
13+
"${chip_root}/src/platform",
14+
"${chip_root}/src/system",
15+
]
16+
}

‎src/platform/silabs/tracing/SilabsTracing.cpp

+164
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,164 @@
1+
#include "SilabsTracing.h"
2+
#include <cstring>
3+
#include <lib/support/CodeUtils.h>
4+
#include <lib/support/PersistentData.h>
5+
6+
#if !CONFIG_BUILD_FOR_HOST_UNIT_TEST
7+
#include <silabs_utils.h> // for isLogInitialized
8+
#endif
9+
10+
// The following functions needs to be implemented by the application to allows logging or storing the traces /
11+
// metrics. If the application does not implement them, the traces will simply be ignored.
12+
bool __attribute__((weak)) isLogInitialized()
13+
{
14+
return false;
15+
}
16+
17+
namespace chip {
18+
namespace Tracing {
19+
namespace Silabs {
20+
21+
static constexpr size_t kPersistentTimeTrackerBufferMax = SERIALIZED_TIME_TRACKERS_SIZE_BYTES;
22+
23+
struct TimeTrackerStorage : public TimeTracker, PersistentData<kPersistentTimeTrackerBufferMax>
24+
{
25+
// TODO implement the Persistent Array class and use it here for logging the watermark array
26+
};
27+
28+
SilabsTracer SilabsTracer::sInstance;
29+
30+
SilabsTracer::SilabsTracer()
31+
{
32+
Init();
33+
}
34+
35+
void SilabsTracer::Init()
36+
{
37+
// Initialize the trace buffer and time trackers
38+
memset(mTraceBuffer, 0, sizeof(mTraceBuffer));
39+
memset(mWatermark, 0, sizeof(mWatermark));
40+
}
41+
42+
CHIP_ERROR SilabsTracer::StartTraceStorage(PersistentStorageDelegate * storage)
43+
{
44+
VerifyOrReturnError(nullptr != storage, CHIP_ERROR_INCORRECT_STATE);
45+
mStorage = storage;
46+
return CHIP_NO_ERROR;
47+
}
48+
49+
void SilabsTracer::TimeTraceBegin(TimeTraceOperation aOperation)
50+
{
51+
// Log the start time of the operation
52+
auto & tracker = mWatermark[static_cast<size_t>(aOperation)];
53+
tracker.mTotalCount++;
54+
tracker.mStartTime = System::SystemClock().GetMonotonicTimestamp();
55+
}
56+
57+
void SilabsTracer::TimeTraceEnd(TimeTraceOperation aOperation, CHIP_ERROR error)
58+
{
59+
if (error != CHIP_NO_ERROR)
60+
{
61+
// Log the error, no need to update the watermark for now as we can get the error count from the
62+
// total count - successfull count. We might want to have a separate count for errors in the future.
63+
TimeTraceInstant(aOperation);
64+
return;
65+
}
66+
67+
// Calculate the duration and update the time tracker
68+
auto & tracker = mWatermark[static_cast<size_t>(aOperation)];
69+
tracker.mEndTime = System::SystemClock().GetMonotonicTimestamp();
70+
auto duration = (tracker.mEndTime - tracker.mStartTime).count();
71+
72+
tracker.mTotalDuration += System::Clock::Milliseconds64(duration);
73+
74+
if (duration > tracker.mMaxTimeMs.count())
75+
{
76+
tracker.mMaxTimeMs = System::Clock::Milliseconds32(duration);
77+
}
78+
79+
if (tracker.mMinTimeMs.count() == 0 || duration < tracker.mMinTimeMs.count())
80+
{
81+
tracker.mMinTimeMs = System::Clock::Milliseconds32(duration);
82+
}
83+
84+
tracker.mSuccessfullCount++;
85+
tracker.mMovingAverage = System::Clock::Milliseconds32(tracker.mTotalDuration.count() / tracker.mSuccessfullCount);
86+
if (duration > tracker.mMovingAverage.count())
87+
{
88+
tracker.mCountAboveAvg++;
89+
}
90+
}
91+
92+
void SilabsTracer::TimeTraceInstant(TimeTraceOperation aOperation, CHIP_ERROR error)
93+
{
94+
if (CHIP_NO_ERROR == error)
95+
{
96+
// Will be used to implement count for instant events that do not require watermarks such as failures and others
97+
// For now, just log in that order the timestamp and the operation
98+
ChipLogProgress(DeviceLayer, "Time: %llu, Instant Trace: %u, ", System::SystemClock().GetMonotonicTimestamp().count(),
99+
static_cast<uint8_t>(aOperation));
100+
}
101+
else
102+
{
103+
// Log the error with timestamp and operation
104+
ChipLogError(DeviceLayer, "Time: %llu, Instant Trace: %u, Error: %" CHIP_ERROR_FORMAT,
105+
System::SystemClock().GetMonotonicTimestamp().count(), static_cast<uint8_t>(aOperation), error.Format());
106+
}
107+
}
108+
109+
void SilabsTracer::OutputTraces()
110+
{
111+
if (isLogInitialized())
112+
{
113+
// Output the traces from the buffer
114+
for (size_t i = 0; i < kNumTraces; ++i)
115+
{
116+
auto & tracker = mWatermark[i];
117+
ChipLogProgress(DeviceLayer,
118+
"Trace %zu: TotalCount=%u, SuccessFullCount=%u, MaxTime=%u, MinTime=%u, AvgTime=%u, CountAboveAvg=%u",
119+
i, tracker.mTotalCount, tracker.mSuccessfullCount, tracker.mMaxTimeMs.count(),
120+
tracker.mMinTimeMs.count(), tracker.mMovingAverage.count(), tracker.mCountAboveAvg);
121+
}
122+
}
123+
else
124+
{
125+
// Buffer the traces if logs are not initialized
126+
static size_t bufferIndex = 0;
127+
if (bufferIndex < kBufferedTracesNumber - 1)
128+
{
129+
for (size_t i = 0; i < kNumTraces; ++i)
130+
{
131+
auto & tracker = mWatermark[i];
132+
// TODO use c++ copy string
133+
snprintf(reinterpret_cast<char *>(mTraceBuffer[bufferIndex]), kBufferedTraceSize,
134+
"Trace %zu: TotalCount=%u, SuccessFullCount=%u, MaxTime=%u, MinTime=%u, AvgTime=%u, CountAboveAvg=%u", i,
135+
tracker.mTotalCount, tracker.mSuccessfullCount, tracker.mMaxTimeMs.count(), tracker.mMinTimeMs.count(),
136+
tracker.mMovingAverage.count(), tracker.mCountAboveAvg);
137+
bufferIndex++;
138+
}
139+
}
140+
else
141+
{
142+
snprintf(reinterpret_cast<char *>(mTraceBuffer[bufferIndex]), kBufferedTraceSize, "Buffer overflow: logs were lost");
143+
}
144+
}
145+
}
146+
147+
// Save the traces in the NVM
148+
CHIP_ERROR SilabsTracer::SaveWatermarks()
149+
{
150+
VerifyOrReturnError(nullptr != mStorage, CHIP_ERROR_INCORRECT_STATE);
151+
// TODO implement the save of the watermarks in the NVM
152+
return CHIP_NO_ERROR;
153+
}
154+
155+
CHIP_ERROR SilabsTracer::LoadWatermarks()
156+
{
157+
VerifyOrReturnError(nullptr != mStorage, CHIP_ERROR_INCORRECT_STATE);
158+
// TODO implement the load of the watermarks from the NVM
159+
return CHIP_NO_ERROR;
160+
}
161+
162+
} // namespace Silabs
163+
} // namespace Tracing
164+
} // namespace chip

‎src/platform/silabs/tracing/SilabsTracing.h

+131
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,131 @@
1+
/*
2+
* Copyright (c) 2024 Project CHIP Authors
3+
* All rights reserved.
4+
*
5+
* Licensed under the Apache License, Version 2.0 (the "License");
6+
* you may not use this file except in compliance with the License.
7+
* You may obtain a copy of the License at
8+
*
9+
* http://www.apache.org/licenses/LICENSE-2.0
10+
*
11+
* Unless required by applicable law or agreed to in writing, software
12+
* distributed under the License is distributed on an "AS IS" BASIS,
13+
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
14+
* See the License for the specific language governing permissions and
15+
* limitations under the License.
16+
*/
17+
#pragma once
18+
19+
// #include "silabs_utils.h"
20+
#include <cstddef>
21+
#include <lib/core/CHIPError.h>
22+
#include <lib/core/CHIPPersistentStorageDelegate.h>
23+
#include <stdint.h>
24+
#include <system/SystemClock.h>
25+
26+
#ifndef SERIALIZED_TIME_TRACKERS_SIZE_BYTES
27+
// Default size, watermarks store 6 uint32_t, which is 24 bytes
28+
// We currently have 19 operations to track, so 19 * 24 = 456 bytes
29+
// 512 bytes should be enough including the serialization overhead
30+
#define SERIALIZED_TIME_TRACKERS_SIZE_BYTES 512
31+
#endif
32+
33+
namespace chip {
34+
namespace Tracing {
35+
namespace Silabs {
36+
37+
// Enum for the different operation to trace
38+
enum class TimeTraceOperation : uint8_t
39+
{
40+
kSpake2p,
41+
kPake1,
42+
kPake2,
43+
kPake3,
44+
kOperationalCredentials,
45+
kAttestationVerification,
46+
kCSR,
47+
kNOC,
48+
kTransportLayer,
49+
kTransportSetup,
50+
kFindOperational,
51+
kCaseSession,
52+
kSigma1,
53+
kSigma2,
54+
kSigma3,
55+
kOTA,
56+
kBootup,
57+
kSilabsInit,
58+
kMatterInit,
59+
kNumTraces,
60+
};
61+
62+
struct TimeTracker
63+
{
64+
// Temporary values
65+
System::Clock::Milliseconds64 mStartTime;
66+
System::Clock::Milliseconds64 mEndTime;
67+
System::Clock::Milliseconds64 mTotalDuration;
68+
69+
// Values that will be stored in the NVM
70+
System::Clock::Milliseconds32 mMovingAverage; // Successful operation average time
71+
System::Clock::Milliseconds32 mMaxTimeMs; // Successful operation max time
72+
System::Clock::Milliseconds32 mMinTimeMs; // Successful operation min time
73+
uint32_t mTotalCount; // Total number of times the operation was initiated
74+
uint32_t mSuccessfullCount; // Number of times the operation was completed without error
75+
uint32_t mCountAboveAvg; // Number of times the operation was above the average time
76+
};
77+
78+
// This class instantiates a buffer to store the traces before logs are enabled.
79+
//
80+
class SilabsTracer
81+
{
82+
static constexpr size_t kNumTraces = static_cast<size_t>(TimeTraceOperation::kNumTraces);
83+
static constexpr size_t kBufferedTracesNumber = 64;
84+
static constexpr size_t kBufferedTraceSize = 128;
85+
86+
public:
87+
static SilabsTracer & Instance() { return sInstance; }
88+
89+
void Init();
90+
91+
CHIP_ERROR StartTraceStorage(PersistentStorageDelegate * storage);
92+
93+
void TimeTraceBegin(TimeTraceOperation aOperation);
94+
void TimeTraceEnd(TimeTraceOperation aOperation, CHIP_ERROR error = CHIP_NO_ERROR);
95+
void TimeTraceInstant(TimeTraceOperation aOperation, CHIP_ERROR error = CHIP_NO_ERROR);
96+
97+
// This Either Logs the traces or stores them in a buffer
98+
void OutputTraces();
99+
100+
// prevent copy constructor and assignment operator
101+
SilabsTracer(SilabsTracer const &) = delete;
102+
SilabsTracer & operator=(SilabsTracer const &) = delete;
103+
104+
// Methods to get the time trackers metrics values
105+
TimeTracker GetTimeTracker(TimeTraceOperation aOperation) { return mWatermark[static_cast<size_t>(aOperation)]; }
106+
107+
// Method to save the time trackers in the NVM, this will likely be time consuming and should not be called frequently
108+
CHIP_ERROR SaveWatermarks();
109+
110+
// Method to load the time trackers from the NVM, this will be called after the initialization so the bootup watermarks need to
111+
// be added to the loaded values
112+
CHIP_ERROR LoadWatermarks();
113+
114+
private:
115+
// Singleton class with a static instance
116+
static SilabsTracer sInstance;
117+
118+
SilabsTracer();
119+
120+
// Buffer to store the traces
121+
uint8_t mTraceBuffer[kBufferedTracesNumber][kBufferedTraceSize];
122+
123+
// Time trackers for each operation
124+
TimeTracker mWatermark[kNumTraces];
125+
126+
PersistentStorageDelegate * mStorage = nullptr;
127+
};
128+
129+
} // namespace Silabs
130+
} // namespace Tracing
131+
} // namespace chip

‎src/platform/tests/BUILD.gn

+3
Original file line numberDiff line numberDiff line change
@@ -92,6 +92,9 @@ if (chip_device_platform != "none" && chip_device_platform != "fake") {
9292
if (chip_device_platform == "linux") {
9393
test_sources += [ "TestConnectivityMgr.cpp" ]
9494
}
95+
96+
test_sources += [ "TestSilabsTracing.cpp" ]
97+
public_deps += [ "${chip_root}/src/platform/silabs/tracing:SilabsTracing" ]
9598
}
9699
} else {
97100
import("${chip_root}/build/chip/chip_test_group.gni")

0 commit comments

Comments
 (0)