Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[SL-ONLY] Initial SilabsTracing object #106

Merged
merged 5 commits into from
Nov 19, 2024
Merged
Show file tree
Hide file tree
Changes from 3 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 8 additions & 0 deletions src/platform/silabs/Logging.cpp
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
/* See Project CHIP LICENSE file for licensing information. */
#include <platform/logging/LogV.h>
#include <platform/silabs/Logging.h>

#include <lib/core/CHIPConfig.h>
#include <platform/CHIPDeviceConfig.h>
Expand Down Expand Up @@ -200,6 +201,13 @@ extern "C" void silabsLog(const char * aFormat, ...)
va_end(v);
}

#ifdef SILABS_LOG_ENABLED
bool isLogInitialized()
{
return sLogInitialized;
}
#endif // SILABS_LOG_ENABLED

namespace chip {
namespace DeviceLayer {

Expand Down
21 changes: 21 additions & 0 deletions src/platform/silabs/Logging.h
Original file line number Diff line number Diff line change
@@ -0,0 +1,21 @@
/*
*
* Copyright (c) 2024 Silabs.
* 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.
*/

#pragma once

bool isLogInitialized(void);
16 changes: 16 additions & 0 deletions src/platform/silabs/tracing/BUILD.gn
lpbeliveau-silabs marked this conversation as resolved.
Show resolved Hide resolved
Original file line number Diff line number Diff line change
@@ -0,0 +1,16 @@
import("//build_overrides/build.gni")
import("//build_overrides/chip.gni")

static_library("SilabsTracing") {
lpbeliveau-silabs marked this conversation as resolved.
Show resolved Hide resolved
sources = [
"SilabsTracing.cpp",
"SilabsTracing.h",
]

deps = [
"${chip_root}/src/lib/core",
"${chip_root}/src/lib/support",
"${chip_root}/src/platform",
"${chip_root}/src/system",
]
}
277 changes: 277 additions & 0 deletions src/platform/silabs/tracing/SilabsTracing.cpp
Original file line number Diff line number Diff line change
@@ -0,0 +1,277 @@
#include "SilabsTracing.h"
#include <cstring>
#include <lib/support/CodeUtils.h>
#include <lib/support/PersistentData.h>

#if !CONFIG_BUILD_FOR_HOST_UNIT_TEST
#include <Logging.h> // for isLogInitialized
#endif

// The following functions needs to be implemented by the application to allows logging or storing the traces /
// metrics. If the application does not implement them, the traces will simply be ignored.
bool __attribute__((weak)) isLogInitialized()
{
return false;
}

namespace chip {
namespace Tracing {
namespace Silabs {

// TODO add string mapping to log the operation names and types

static constexpr size_t kPersistentTimeTrackerBufferMax = SERIALIZED_TIME_TRACKERS_SIZE_BYTES;
lpbeliveau-silabs marked this conversation as resolved.
Show resolved Hide resolved

struct TimeTrackerStorage : public TimeTracker, PersistentData<kPersistentTimeTrackerBufferMax>
{
// TODO implement the Persistent Array class and use it here for logging the watermark array
};

SilabsTracer SilabsTracer::sInstance;

SilabsTracer::SilabsTracer()
{
VerifyOrDie(Init() == CHIP_NO_ERROR);
lpbeliveau-silabs marked this conversation as resolved.
Show resolved Hide resolved
}

void SilabsTracer::TraceBufferClear()
{
// Clear the time tracker list
while (mTimeTrackerList.head != nullptr)
{
mTimeTrackerList.Remove(0);
}
mBufferedTrackerCount = 0;
}

CHIP_ERROR SilabsTracer::Init()
{
TraceBufferClear();

// Initialize the time trackers
memset(mTimeTrackers, 0, sizeof(mTimeTrackers));
memset(mWatermarks, 0, sizeof(mWatermarks));

return CHIP_NO_ERROR;
}

CHIP_ERROR SilabsTracer::StartWatermarksStorage(PersistentStorageDelegate * storage)
lpbeliveau-silabs marked this conversation as resolved.
Show resolved Hide resolved
{
VerifyOrReturnError(nullptr != storage, CHIP_ERROR_INCORRECT_STATE);
mStorage = storage;
return CHIP_NO_ERROR;
}

void SilabsTracer::TimeTraceBegin(TimeTraceOperation aOperation)
{
// Log the start time of the operation
auto & tracker = mTimeTrackers[static_cast<size_t>(aOperation)];
tracker.mStartTime = System::SystemClock().GetMonotonicTimestamp();
tracker.mOperation = aOperation;
tracker.mType = OperationType::kBegin;
tracker.mError = CHIP_NO_ERROR;

auto & watermark = mWatermarks[static_cast<size_t>(aOperation)];
watermark.mTotalCount++;

OutputTrace(tracker);
}

void SilabsTracer::TimeTraceEnd(TimeTraceOperation aOperation, CHIP_ERROR error)
{
auto & tracker = mTimeTrackers[static_cast<size_t>(aOperation)];
tracker.mEndTime = System::SystemClock().GetMonotonicTimestamp();
tracker.mType = OperationType::kEnd;
tracker.mError = error;

if (error == CHIP_NO_ERROR)
{
// Calculate the duration and update the time tracker
auto duration = tracker.mEndTime - tracker.mStartTime;

auto & watermark = mWatermarks[static_cast<size_t>(aOperation)];
watermark.mSuccessfullCount++;
watermark.mMovingAverage = System::Clock::Milliseconds32(
(watermark.mMovingAverage.count() * (watermark.mSuccessfullCount - 1) + duration.count()) /
watermark.mSuccessfullCount);

if (duration > watermark.mMaxTimeMs)
{
watermark.mMaxTimeMs = System::Clock::Milliseconds32(duration);
}

if (watermark.mMinTimeMs.count() == 0 || duration < watermark.mMinTimeMs)
{
watermark.mMinTimeMs = System::Clock::Milliseconds32(duration);
}

if (duration > watermark.mMovingAverage)
{
watermark.mCountAboveAvg++;
}
}

OutputTrace(tracker);
}

void SilabsTracer::TimeTraceInstant(TimeTraceOperation aOperation, CHIP_ERROR error)
{
auto & tracker = mTimeTrackers[static_cast<size_t>(aOperation)];
tracker.mStartTime = System::SystemClock().GetMonotonicTimestamp();
tracker.mEndTime = tracker.mStartTime;
tracker.mOperation = aOperation;
tracker.mType = OperationType::kInstant;
tracker.mError = error;
OutputTrace(tracker);
}

CHIP_ERROR SilabsTracer::OutputTimeTracker(const TimeTracker & tracker)
{
VerifyOrReturnError(isLogInitialized(), CHIP_ERROR_UNINITIALIZED);
ChipLogProgress(DeviceLayer,
"TimeTracker - StartTime: %" PRIu32 ", EndTime: %" PRIu32 ", Operation: %" PRIu8 ", Type: %" PRIu8
", Error: %" CHIP_ERROR_FORMAT,
tracker.mStartTime.count(), tracker.mEndTime.count(), static_cast<uint8_t>(tracker.mOperation),
static_cast<uint8_t>(tracker.mType), tracker.mError.Format());
return CHIP_NO_ERROR;
}

CHIP_ERROR SilabsTracer::OutputTrace(const TimeTracker & tracker)
{
// We allow error here as we want to buffer even if the logs are currently uninitialized
OutputTimeTracker(tracker);

if (mBufferedTrackerCount < kMaxBufferedTraces - 1)
{
mTimeTrackerList.Insert(tracker);
mBufferedTrackerCount++;
}
else
{
// Save a tracker with 0xFFFF to indicate that the buffer is full
TimeTracker resourceExhaustedTracker = tracker;
lpbeliveau-silabs marked this conversation as resolved.
Show resolved Hide resolved
resourceExhaustedTracker.mStartTime = System::SystemClock().GetMonotonicTimestamp();
resourceExhaustedTracker.mEndTime = resourceExhaustedTracker.mStartTime;
resourceExhaustedTracker.mOperation = TimeTraceOperation::kNumTraces;
resourceExhaustedTracker.mType = OperationType::kInstant;
resourceExhaustedTracker.mError = CHIP_ERROR_BUFFER_TOO_SMALL;
mTimeTrackerList.Insert(resourceExhaustedTracker);
return CHIP_ERROR_BUFFER_TOO_SMALL;
}

return CHIP_NO_ERROR;
}

CHIP_ERROR SilabsTracer::OutputWaterMark(TimeTraceOperation aOperation)
{
size_t index = static_cast<size_t>(aOperation);
auto & watermark = mWatermarks[index];

VerifyOrReturnError(isLogInitialized(), CHIP_ERROR_UNINITIALIZED);
ChipLogProgress(DeviceLayer,
"Trace %zu: TotalCount=%" PRIu32 ", SuccessFullCount=%" PRIu32 ", MaxTime=%" PRIu32 ", MinTime=%" PRIu32
", AvgTime=%" PRIu32 ", CountAboveAvg=%" PRIu32 "",
index, watermark.mTotalCount, watermark.mSuccessfullCount, watermark.mMaxTimeMs.count(),
watermark.mMinTimeMs.count(), watermark.mMovingAverage.count(), watermark.mCountAboveAvg);

return CHIP_NO_ERROR;
}

CHIP_ERROR SilabsTracer::OutputAllWaterMarks()
{
for (size_t i = 0; i < kNumTraces; ++i)
{
CHIP_ERROR err = OutputWaterMark(static_cast<TimeTraceOperation>(i));
if (err != CHIP_NO_ERROR)
{
return err;
}
}
return CHIP_NO_ERROR;
}

CHIP_ERROR SilabsTracer::TraceBufferFlushAll()
lpbeliveau-silabs marked this conversation as resolved.
Show resolved Hide resolved
{
auto * current = mTimeTrackerList.head;
while (current != nullptr)
{
// We do not want to loose the traces if the logs are not initialized
ReturnErrorOnFailure(OutputTimeTracker(current->mValue));
current = current->mpNext;
}

TraceBufferClear();
return CHIP_NO_ERROR;
}

CHIP_ERROR SilabsTracer::TraceBufferFlushByOperation(TimeTraceOperation aOperation)
lpbeliveau-silabs marked this conversation as resolved.
Show resolved Hide resolved
{

auto * current = mTimeTrackerList.head;
auto * prev = static_cast<chip::SingleLinkedListNode<TimeTracker> *>(nullptr);
while (current != nullptr)
{
if (current->mValue.mOperation == aOperation)
{
ReturnErrorOnFailure(OutputTimeTracker(current->mValue));
if (prev == nullptr)
{
mTimeTrackerList.head = current->mpNext;
}
else
{
prev->mpNext = current->mpNext;
}
auto * temp = current;
current = current->mpNext;
free(temp);
mBufferedTrackerCount--;
}
else
{
prev = current;
current = current->mpNext;
}
}

return CHIP_NO_ERROR;
}

// Save the traces in the NVM
CHIP_ERROR SilabsTracer::SaveWatermarks()
{
VerifyOrReturnError(nullptr != mStorage, CHIP_ERROR_INCORRECT_STATE);
// TODO implement the save of the watermarks in the NVM
return CHIP_NO_ERROR;
}

CHIP_ERROR SilabsTracer::LoadWatermarks()
{
VerifyOrReturnError(nullptr != mStorage, CHIP_ERROR_INCORRECT_STATE);
// TODO implement the load of the watermarks from the NVM
return CHIP_NO_ERROR;
}

#if CONFIG_BUILD_FOR_HOST_UNIT_TEST
CHIP_ERROR SilabsTracer::GetTraceCount(size_t & count) const
{
count = mBufferedTrackerCount;
return CHIP_NO_ERROR;
}

CHIP_ERROR SilabsTracer::GetTraceByIndex(size_t index, const char *& trace) const
lpbeliveau-silabs marked this conversation as resolved.
Show resolved Hide resolved
{
auto * current = mTimeTrackerList.head;
for (size_t i = 0; i < index && current != nullptr; ++i)
{
current = current->mpNext;
}
VerifyOrReturnError(current != nullptr, CHIP_ERROR_INVALID_ARGUMENT);
trace = reinterpret_cast<const char *>(&current->mValue);
return CHIP_NO_ERROR;
}
#endif

} // namespace Silabs
} // namespace Tracing
} // namespace chip
Loading
Loading